RE: libpq debug log - Mailing list pgsql-hackers

Hi Horiguchi san and Tsunakawa san,

Thank you for you review.

I update patch to v28.  In this patch, I removed array.
And I fixed some code according to Horiguchi san and Tsunakawa san review comment.

> From: Tsunakawa, Takayuki/綱川 貴之 <tsunakawa.takay@fujitsu.com>
> Sent: Thursday, March 18, 2021 12:38 PM
> I sort of think so to remove the big arrays.  But to minimize duplicate code, I
> think the code structure will look like:
>
>     fprintf(timestamp, length);
>     switch (type)
>     {
>         case '?':
>             pqTraceOutput?(...);
>         break;
>         case '?':
>             /* No message content */
>             fprintf("message_type_name");
>         break;
>     }
>
> void
> pqTraceOutput?(...)
> {
>     fprintf("message_type_name");
>     print message content;
> }

The code follows above format.
And I changed .sgml documentation;
- Changed order of message length and type
- Removed byte-16 and byte-32 explanation because I removed # output in previous patch.

Output style is following;

```
2021-03-18 08:59:36.141660  <   5   ReadyForQuery I
2021-03-18 08:59:36.141723  >   4   Terminate
2021-03-18 08:59:36.173263  >   155 Query "CREATE TABLESPACE regress_tblspacewith LOCATION
'/home/iwata/pgsql/postgres/src/test/regress/testtablespace'WITH (some_nonexistent_parameter = true);" 
2021-03-18 08:59:36.174439  <   124 ErrorResponse S "ERROR" V "ERROR" C "22023" M "unrecognized parameter
"some_nonexistent_parameter""F "reloptions.c" L "1456" R "parseRelOptionsInternal" \x00 "Z" 
2021-03-18 08:59:36.174483  <   5   ReadyForQuery I
2021-03-18 08:59:36.174545  >   144 Query "CREATE TABLESPACE regress_tblspacewith LOCATION
'/home/iwata/pgsql/postgres/src/test/regress/testtablespace'WITH (random_page_cost = 3.0);" 
2021-03-18 08:59:36.176155  <   22  CommandComplete "CREATE TABLESPACE"
2021-03-18 08:59:36.176190  <   5   ReadyForQuery I
2021-03-18 08:59:36.176243  >   81  Query "SELECT spcoptions FROM pg_tablespace WHERE spcname =
'regress_tblspacewith';"                                                      
2021-03-18 08:59:36.179286  <   35  RowDescription 1 "spcoptions" 1213 5 1009 65535 -1 0
2021-03-18 08:59:36.179326  <   32  DataRow 1 22 '{random_page_cost=3.0}'
2021-03-18 08:59:36.179339  <   13  CommandComplete "SELECT 1"
2021-03-18 08:59:36.179349  <   5   ReadyForQuery I
2021-03-18 08:59:36.179504  >   42  Query "DROP TABLESPACE regress_tblspacewith;"
2021-03-18 08:59:36.180400  <   20  CommandComplete "DROP TABLESPACE"
2021-03-18 08:59:36.180432  <   5   ReadyForQuery I
```


> -----Original Message-----
> From: Kyotaro Horiguchi <horikyota.ntt@gmail.com>
> Sent: Thursday, March 18, 2021 5:30 PM
>
> At Thu, 18 Mar 2021 07:34:36 +0000, "tsunakawa.takay@fujitsu.com"
> <tsunakawa.takay@fujitsu.com> wrote in
> > From: Iwata, Aya/岩田 彩 <iwata.aya@fujitsu.com>
> > > > Yes, precisely, 2 bytes for the double quotes needs to be
> > > > subtracted as
> > > > follows:
> > > >
> > > >     len = fprintf(...);
> > > >     *cursor += (len - 2);
> > >
> > > Thank you for your advice. I changed pqTraceOutputString set cursor
> > > to fprintf return -2.
> > > And I removed cursor movement from that function.
> >
> > Ouch, not 2 but 3, to include a single whitespace at the beginning.
> >
> > The rest looks good.  I hope we're almost at the finish line.
>
> Maybe.

String is end by '\0'. So (len -2) is OK.
However it seems like mistake because fprintf output string and 3 characters.
So I added explanation here and changed (len -2) to (len -3 +1).
I think it is OK because I found similar style in ecpg code.

> > + pqTraceOutputR(const char *message, FILE *f) {
> > +     int    cursor = 0;
> > +
> > +     pqTraceOutputInt32(message, &cursor, f);
> >
> > I don't understand the reason for spliting message and &cursor here.
> >
> > + pqTraceOutputR(const char *message, FILE *f) {
> > +     char *p = message;
> > +
> > +     pqTraceOutputInt32(&p, f);
> >
> > works well.
>
> Yes, that would also work.  But I like the separate cursor + fixed starting
> point here, probably because it's sometimes confusing to see the pointer
> value changed inside functions.  (And a pointer itself is an allergy for some
> people, not to mention a pointer to ointer...)  Also, libpq uses cursors for
> network I/O buffers.  So, I think the patch can be as it is now.

I think pass message and cursor is better. Because it is easy to understand and
The moving cursor style is used when libpq execute protocol message.
So I didn't make this change.

> +/* RowDescription */
> +static void
> +pqTraceOutputT(const char *message, int end, FILE *f) {
> +    int    cursor = 0;
> +    int nfields;
> +    int    i;
> +
> +    nfields = pqTraceOutputInt16(message, &cursor, f);
> +
> +    for (i = 0; i < nfields; i++)
> +    {
> +        pqTraceOutputString(message, &cursor, end, f);
> +        pqTraceOutputInt32(message, &cursor, f);
> +        pqTraceOutputInt16(message, &cursor, f);
> +        pqTraceOutputInt32(message, &cursor, f);
> +        pqTraceOutputInt16(message, &cursor, f);
> +        pqTraceOutputInt32(message, &cursor, f);
> +        pqTraceOutputInt16(message, &cursor, f);
> +    }
> +}
>
> I didn't looked closer, but lookong the usage of the variable "end", something's
> wrong in the function.

I removed end from the function.
pqTraceOutputString no longer use message end cursor.



Regards,
Aya Iwata