RE: libpq debug log

Alvaro san, Tom san Horiguchi san, Tsunakawa san and Kirk san,

Thank you very much for review and advice.

> > Works for me.
>
> Pushed that. I think we're now waiting on Iwata-san to finish a new version of
> the tracing patch.
Thank you very much Alvaro san and Tom san. Your patch and code change makes my work more smoothly.
And I am sorry for attaching not-good-work patch. fixsegv.patch help my implementation.

I update this patch to v25. I fix function arguments and something which are pointed out by reviewers.

I create protocol message reading function for each protocol message type. (Ex. pqTraceOutputB() read Bind message)
This makes the nesting shallower and makes the code easier to read.
Each data type output functions(Ex. pqTraceOutputString() ) are called from each protocol message type function.
Cursor operation is performed in each protocol message type function.

Like Kirk san, I share `make check` results. As far as I can see, tracing works well.
I compare this result with current master branch trace log. It does not miss/add any protocol message.
And Thank you Kirk san for your share of make check result and previous patch!

```
2021-03-15 08:10:44.288999 > Terminate 4
2021-03-15 08:10:44.317959 > Query 155 "CREATE TABLESPACE regress_tblspacewith LOCATION '/home/iwata/pgsql/postgres/src/test/regress/testtablespace' WITH (some_nonexistent_parameter = true);"
2021-03-15 08:10:44.319121 < ErrorResponse 124 S "ERROR" V "ERROR" C "22023" M "unrecognized parameter "some_nonexistent_parameter"" F "reloptions.c" L "1447" R "parseRelOptionsInternal" \x00
2021-03-15 08:10:44.319161 < ReadyForQuery 5 I
2021-03-15 08:10:44.319221 > Query 144 "CREATE TABLESPACE regress_tblspacewith LOCATION '/home/iwata/pgsql/postgres/src/test/regress/testtablespace' WITH (random_page_cost = 3.0);"
2021-03-15 08:10:44.320889 < CommandComplete 22 "CREATE TABLESPACE"
2021-03-15 08:10:44.320922 < ReadyForQuery 5 I
2021-03-15 08:10:44.320979 > Query 81 "SELECT spcoptions FROM pg_tablespace WHERE spcname = 'regress_tblspacewith';"
2021-03-15 08:10:44.324296 < RowDescription 35 #1 "spcoptions" 1213 #5 1009 #65535 -1 #0
2021-03-15 08:10:44.324335 < DataRow 32 #1 22 '{random_page_cost=3.0}'
2021-03-15 08:10:44.324347 < CommandComplete 13 "SELECT 1"
2021-03-15 08:10:44.324388 < ReadyForQuery 5 I
2021-03-15 08:10:44.324516 > Query 42 "DROP TABLESPACE regress_tblspacewith;"
2021-03-15 08:10:44.325423 < CommandComplete 20 "DROP TABLESPACE"
2021-03-15 08:10:44.325453 < ReadyForQuery 5 I
```

> From: Tsunakawa, Takayuki/綱川 貴之 <tsunakawa(dot)takay(at)fujitsu(dot)com>
> Sent: Friday, March 5, 2021 3:17 PM
...
>
> void pqLogMessage(PGconn *conn, const char *message, bool toServer);

Thank you Tsunakawa san. In v25 patch, I fixed qTraceOutputMessag() function to this style.
I am sorry changing arguments in previous patch. That was my misunderstanding.

> From: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>
> Sent: Thursday, March 11, 2021 6:33 AM
...
> There are still some cowboy advancements of inStart in the functions
> concerned with COPY processing, but it doesn't look like there's much to be
> done about that. Those spots will need their own trace calls.

I called pqTraceOutputMessage() from pqParseInput3(), COPY process and pqFunctionCall3(). pqFunctionCall3() is called by PQfn().
I found that there is protocol message id switch(). So I call the tracing function there.

> From: Kyotaro Horiguchi <horikyota(dot)ntt(at)gmail(dot)com>
> Sent: Thursday, March 11, 2021 10:20 AM

Thank you Horiguchi san. Your keen review suggestions and detailed advice. It is very helpful for updating my patch.

> The individual per-type-output functions are designed to fit to the
> corresponding pqGet*() functions. On the other hand, now that we read the
> message bytes knowing the exact format in advance as you did in
> pqTraceOutputMsg(). So the complexity exist in the functions can be
> eliminated by separating them into more type specific output functions. For
> example, pqTraceOutputInt() is far simplified by spliting it into
> pqTraceOutputInt16() and -32().
Yes, I refer to pqGet functions. To make data type output function more simpler,
I separate output int function to pqTraceOutputInt16 and -32.

> I think we can get rid of copying in the output functions for String and Bytes in
> different ways.
I remove memcpy call from String and Bytes output function.
These functions just pass *message to fprintf().

> + /* Protocol 2.0 does not support tracing. */
> + if (PG_PROTOCOL_MAJOR(conn->pversion) < 3)
> + return;
>
> We can write that message out into tracing file.
>
> +void
> +PQtraceSetFlags(PGconn *conn, int flags) {
> + if (conn == NULL)
> + return;
> + /* Protocol 2.0 is not supported. */
> + if (PG_PROTOCOL_MAJOR(conn->pversion) < 3)
> + return;
> + /* If PQtrace() failed, do nothing. */
> + if (conn->Pfdebug == NULL)
> + return;
> + conn->traceFlags = flags;
>
> Pfdebug is always NULL for V2 protocol there, so it can be an assertion?

Protocol v2.0 is not supported anymore. So I just remove code following;
> + /* Protocol 2.0 is not supported. */
> + if (PG_PROTOCOL_MAJOR(conn->pversion) < 3)
I checked the libpq code to see if I could make this decision.
Code to check whether protocol version is 3 or less It had been removed from various place.

> From: Kyotaro Horiguchi <horikyota(dot)ntt(at)gmail(dot)com>
> Sent: Thursday, March 11, 2021 12:03 PM
...

> At Wed, 10 Mar 2021 20:38:20 -0500, Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us> wrote in
> > Kyotaro Horiguchi <horikyota(dot)ntt(at)gmail(dot)com> writes:
> > > Maybe I'm missing something, but the above doesn't seem working. I
> > > didn't see such message when making a SSL connection.
> >
> > As far as that goes, I don't see any point in trying to trace
> > connection-related messages, because there is no way to enable tracing
> > on a connection before it's created.
>
> Yeah, agreed. In the previous version tracing functions are called during
> protocol negotiation but that no longer happenes.
I see. Thank you for your advice.
I remove these code from pqTraceOutputMessage() function.

> From: Kyotaro Horiguchi <horikyota(dot)ntt(at)gmail(dot)com>
> Sent: Thursday, March 11, 2021 1:31 PM
...
> > Yes, that would work (if p is a pointer), but I think memcpy() is enough like
> pqGetInt() does.
>
> On second thought, memcpy onto a local variable doesn't harm. I agreed to
> you.

I am not change pqTraceOutputInt16(). But pqTraceOutputInt32() change like this;
+ memcpy(&result, data, 4);
+ result = (int) pg_ntoh32(result);

Regards,
Aya Iwata