RE: libpq debug log - Mailing list pgsql-hackers

HI all,

I update the patch.
I modified code according to review comments of Tsunakawa san and Horiguchi san.

And I fixed some bugs.

> This patch should address the following:
> 1. fix 3 bugs
>   1.1 -1 output in "Query" message

The cause of this bug is that it call in pqFlush() function before flushing.
The purpose of calling pqLogFrontendMsg() here is to log the data that was in the buffer but not logged before
flushing.
The second argument of pqLogFrontendMsg() is message length, but we can't find it in pqFlush(). 
Therefor,  -1 was set here as a second argument and it was logged.
I thought about keeping the length as fields, but from the output Kirk san tried, this doesn't seem to happen.
Also, the message from the frontend to the backend calls pqPutMsgEnd () in advance, so the message should already be
logged.
So I deleted this call.

>   1.2 two message output in "ReadyForQuery" message

In the pqParseInput3 (), when the state becomes PGASYNC_IDLE, it returns to the caller. 
After that,  pqParseInput3 () is called again and protocol message and length are output again by calling pqGetc(),
pqGetInt().
 
To limit this, set the skipLogging flag when the status become PGASYNC_IDLE and fixed to skip the next pqGetc(),
pqGetInt().

>   1.3 "StartupMessage" output as " UnknownMessage "

I moved the code that handles the output of "SSLRequest", "StartupMessage", etc. 
to pqLogFrontendMsg() which is the function that outputs the front-end message.


> 2. creating new file for new tracing functions

I create new files libpq-logging.c and libpq-logging.h

> From: Tsunakawa, Takayuki/綱川 貴之 <tsunakawa.takay@fujitsu.com>
> Sent: Wednesday, February 3, 2021 10:27 AM

> (39)
> +      of tracing.  If (<literal>flags</literal> &
> <literal>PQTRACE_OUTPUT_TIMESTAMPS</literal>) is
> +      true, then timestamp is not printed with each message.
> 
> The flag name (OUTPUT) and its description (not printed) doesn't match.

I changed flag name to PQTRACE_SUPPRESS_TIMESTAMPS.

> 
> I think you can use less programmatical expression like "If
> <literal>flags</literal> contains
> <literal>PQTRACE_OUTPUT_TIMESTAMPS</literal>".
I fixed.

> (40)
> diff --git a/src/interfaces/libpq/exports.txt b/src/interfaces/libpq/exports.txt
> +PQtraceEx                 180
> \ No newline at end of file
> 
> What's the second line?  Isn't the file missing an empty line at the end?

I delete it.


> (41)
> +void
> +PQtraceEx(PGconn *conn, FILE *debug_port, int flags) {
> +    if (conn == NULL)
> +        return;
> ...
> +    if (!debug_port)
> +        return;
> 
> The if should better be as follows to match the style of existing surrounding
> code.
> 
> +    if (debug_port == NULL)

I fixed it.

> (42)
> +pqLogFormatTimestamp(char *timestr, Size ts_len)
> 
> I think you should use int or size_t instead of Size here, because other libpq
> code uses them.  int should be enough.  If the compiler gives warnings,
> prepend "(int)" before sizeof() at call sites.

I fixed it.

 
> (43)
> +    /* append microseconds */
> +    sprintf(timestr + strlen(timestr), ".%06d", (int) (tval.tv_usec /
> +1000));
> 
> "/ 1000" should be removed.

I removed it.
 
> (44)
> +    if ((conn->traceFlags & PQTRACE_OUTPUT_TIMESTAMPS) == 0)
> +        timestr_p = pqLogFormatTimestamp(timestr,
> sizeof(timestr));
> 
> == 0 should be removed.

I left it, referring Horiguchi san's comment.

Regards,
Aya Iwata