Re: libpq debug log

On 2021-Mar-15, iwata(dot)aya(at)fujitsu(dot)com wrote:

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

I'm not sure I agree with this structural change. Yes, it is less
indentation, but these functions are all quite short and simple anyway.
But I don't disagree strongly with it either.

Four issues:
* There's no cross-check that the protocol message length word
corresponds to what we actually print. I think one easy way to
cross-check that would be to return the "count" from the type-specific
routines, and verify that it matches "length" in pqTraceOutputMessage.
(If the separate routines are removed and the code put back in one
giant switch, then the "count" is already available when the switch
ends.)

* If we have separate functions for each message type, then we can have
that function supply the message name by itself, rather than have the
separate protocol_message_type_f / _b arrays that print it.

* If we make each type-specific function print the message name, then we
need to make the same function print the message length, because it
comes after. So the function would have to receive the length (so
that it can be printed). But I think we should still have the
cross-check I mentioned in my first point occur in the main
pqTraceOutputMessage, not the type-specific function, for fear that we
will forget the cross-check in one of the functions and never realize
that we did.

* I would make the pqTraceOutputInt16() function and siblings advance
the cursor themselves, actually. I think something like this:
static int
pqTraceOutputInt16(const char *data, int *cursor, FILE *pfdebug)
{
uint16 tmp;
int result;

memcpy(&tmp, data + *cursor, 2);
*cursor += 2;
result = (int) pg_ntoh16(tmp);
fprintf(pfdebug, " #%d", result);

return result;
}
(So the caller has to pass the original "data" pointer, not
"data+cursor"). This means the caller no longer has to do "cursor+=N"
at each place. Also, you get rid of the moveStrCursor() which does
not look good.

Bikeshedding item:
* I'm not fond of the idea of prefixing "#" for 16bit ints and no
prefix for 32bit ints. Seems obscure and the output looks weird.
I would use a one-letter prefix for each type, "w" for 32-bit ints
(stands for "word") and "h" for 16-bit ints (stands for "half-word").
Message length goes unadorned. Then you'd have lines like this

2021-03-15 08:10:44.324296 < RowDescription 35 h1 "spcoptions" w1213 h5 w1009 h65535 w-1 h0
2021-03-15 08:10:44.324335 < DataRow 32 h1 w22 '{random_page_cost=3.0}'

* I don't like that pqTraceOutputS/H print nothing when !toServer. I
think they should complain.

--
Álvaro Herrera 39°49'30"S 73°17'W