Re: libpq debug log

At Tue, 9 Feb 2021 02:26:25 +0000, "tsunakawa.takay@fujitsu.com" <tsunakawa.takay@fujitsu.com> wrote in 
> From: Iwata, Aya/岩田 彩 <iwata.aya@fujitsu.com>
> > I update the patch.
> > I modified code according to review comments of Tsunakawa san and
> > Horiguchi san.
> 
> 
> I confirmed that all the previous feedback was reflected.  Here are some minor comments:
> 
> 
> (45)
>  void PQtrace(PGconn *conn, FILE *stream);
>  </synopsis>
>       </para>
>  
> +     <para>
> +      Calls <function>PQtraceEx</function> to output with or without a timestamp
> +      using <literal>flags</literal>.
> +     </para>
> +
> +     <para>
> +      <literal>flags</literal> contains flag bits describing the operating mode
> +      of tracing.  If (<literal>flags</literal> contains <literal>PQTRACE_SUPPRESS_TIMESTAMPS</literal>),
> +      then timestamp is not printed with each message.
> 
> The description of PQtrace() should be written independent of PQtraceEx().  It is an unnecessary implementation
detailto the user that PQtrace() calls PQtraceEx() internally.  Plus, a separate entry for PQtraceEx() needs to be
added.

This looks like a fusion of PQtrace and PQtraceEX. By the way, the
timestamp flag is needed at log emittion. So we can change the state
anytime.

PQtrace(conn, of);
PQtraceSetFlags(conn, PQTRACE_SUPPRESS_TIMESTAMPS);
<logging without timestamps>
PQtraceSetFlags(conn, 0);
<logging with timestamps>
..


> (46)
> 
> If skipLogging is intended for use with backend -> frontend messages only, shouldn't it be placed in conn->b_msg?

The name skipLogging is somewhat obscure. The flag doesn't inhibit all
logs from being emitted.  It seems like it represents how far bytes
the logging mechanism consumed for the limited cases. Thus, I think it
can be a cursor variable like inCursor.

If we have conn->be_msg->inLogged, for example, pqGetc and
pqLogMessageByte1() are written as the follows.

pqGetc(char *result, PGconn *conn)
{
    if (conn->inCursor >= conn->inEnd)
        return EOF;

    *result = conn->inBuffer[conn->inCursor++];

    if (conn->Pfdebug)
        pqLogMessageByte1(conn, *result);

    return 0;
}

pqLogMessageByte1(...)
{
   switch()
   {
     case LOG_FIRST_BYTE:
       /* No point in logging already logged bytes */
       if (conn->be_msg->inLogged >= conn->inCursor)
         return;
   ...
   }
   conn->be_msg->inLogged = conn->inCursor;
}

(pqCheckInBufferSpace needs to adjust inLogged.)

I'm not sure this is easier to read than the skipLogging.

> (47)
> +    /* Deallocate FE/BE message tracking memory. */
> +    if (conn->fe_msg &&
> +        /*
> +         * If fields is allocated the initial size, we reuse it next time,
> +         * because it would be allocated same size and the size is not big.
> +         */
> +            conn->fe_msg->max_fields != DEF_FE_MSGFIELDS)
> 
> I'm not completely sure if other places interpose a block comment like this between if/for/while conditions, but I
thinkit's better to put the comment before if.
 

(s/is/are/)

Agreed. At least it doesn't look good.

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center