Re: libpq debug log

At Wed, 10 Mar 2021 10:31:27 -0300, "'alvherre(at)alvh(dot)no-ip(dot)org'" <alvherre(at)alvh(dot)no-ip(dot)org> wrote in
> On 2021-Mar-10, iwata(dot)aya(at)fujitsu(dot)com wrote:
>
> > Hi all,
> >
> > Following all reviewer's advice, I have created a new patch.
> >
> > In this patch, I add only two tracing entry points; I call pqTraceOutputMsg(PGconn conn, int msgCursor, PGCommSource commsource) in pqParseInput3 () and pqPutMsgEnd () to output log.
> > The argument contains message first byte offset called msgCursor because it is simpler to specify the buffer pointer in the caller.
> >
> > In pqTraceOutputMsg(), the content common to all protocol messages (first timestamp, < or >, first 1 byte, and length) are output first and after that each protocol message contents is output. I referred to pqParseInput3 () , fe-exec.c and documentation page for that part.
> >
> > This fix almost eliminates if(conn->Pfdebug) that was built into the code for other features.
>
> This certainly looks much better! Thanks for getting it done so
> quickly.
>
> I didn't review the code super closely. I do see a compiler warning:

+1 for the thanks for the quick work. I have some random comments
after a quick look on it.

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().

The output functions copy message bytes into local variable but the
same effect can be obtained by just casing via typed pointer type.

uint32 tmp4;
..
memcpy(&tmp4, buf + *cursor, 4);
result = (int) pg_ntoh32(tmp4);

can be written as

result = pg_ntoh32(* (uint32 *) (buf + *cursor));

I think we can get rid of copying in the output functions for String
and Bytes in different ways.

Now that we can manage our own reading pointer within
pqTraceOutputMsg(), the per-type-output functions can work only on the
reading pointer instead of buffer pointer and cursor, and length.
*I*'d want to make the output functions move the reading pointer by
themseves. pqTradeOutputMsg can be as simplified as the follows doing
this. End-of-message pointer may be useful to check read-overrunning
on the message buffer.

switch (id) {
case 'R':
pqTraceOutputInt32(&p, endptr, conn->Pfdebug);
fputc('\n', conn->Pfdebug);
break;
case 'K':
pqTraceOutputInt32(&p, endptr, conn->Pfdebug));
pqTraceOutputInt32(&p, endptr, conn->Pfdebug));
...

+ char *prefix = commsource == MSGDIR_FROM_BACKEND ? "<" : ">";
+ int LogEnd = commsource == MSGDIR_FROM_BACKEND ? conn->inCursor : conn->outMsgEnd;
+ char *logBuffer = commsource == MSGDIR_FROM_BACKEND ? conn->inBuffer
..
+ if (commsource == MSGDIR_FROM_BACKEND)
+ id = logBuffer[LogCursor++];

Repeated usage of the ternaly operator on the same condition makes
code hard-to-read. It is simpler to consolidate them into one if-else
statement.

+ result = (int) pg_ntoh32(result32);
+ if (result == NEGOTIATE_SSL_CODE)

Maybe I'm missing something, but the above doesn't seem working. I
didn't see such message when making a SSL connection.

+ /* 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?

regards.

--
Kyotaro Horiguchi
NTT Open Source Software Center