Re: libpq debug log

From: Tom Lane <tgl(at)sss(dot)pgh(dot)pa(dot)us>
To: "tsunakawa(dot)takay(at)fujitsu(dot)com" <tsunakawa(dot)takay(at)fujitsu(dot)com>
Cc: "iwata(dot)aya(at)fujitsu(dot)com" <iwata(dot)aya(at)fujitsu(dot)com>, "k(dot)jamison(at)fujitsu(dot)com" <k(dot)jamison(at)fujitsu(dot)com>, "'Kyotaro Horiguchi'" <horikyota(dot)ntt(at)gmail(dot)com>, "alvherre(at)alvh(dot)no-ip(dot)org" <alvherre(at)alvh(dot)no-ip(dot)org>, "pgsql-hackers(at)lists(dot)postgresql(dot)org" <pgsql-hackers(at)lists(dot)postgresql(dot)org>
Subject: Re: libpq debug log
Date: 2021-03-04 23:03:43
Message-ID: 1425287.1614899023@sss.pgh.pa.us
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

"tsunakawa(dot)takay(at)fujitsu(dot)com" <tsunakawa(dot)takay(at)fujitsu(dot)com> writes:
> From: Kyotaro Horiguchi <horikyota(dot)ntt(at)gmail(dot)com>
>> Using (inCursor - inStart) as logCursor doesn't work correctly if tracing state
>> desyncs. Once desync happens inStart can be moved at the timing that the
>> tracing code doesn't expect. This requires (as I mentioned upthread)
>> pqReadData to actively reset logCursor, though.
>>
>> logCursor should move when bytes are fed to the tracing functoins even when
>> theyare the last bytes of a message.

> Hmm, sharp and nice insight. I'd like Iwata-san and Kirk to consider this, including Horiguchi-san's previous mails.

I took a quick look through the v22 patch, and TBH I don't like much of
anything at all about the proposed architecture. It's retained most
of the flavor of the way it was done before, which was a hangover from
the old process-on-the-fly scheme.

I think the right way to do this, now that we've killed off v2 protocol
support, is to rely on the fact that libpq fully buffers both incoming
and outgoing messages. We should nuke every last bit of the existing
code that intersperses tracing logic with normal message decoding and
construction, and instead have two tracing entry points:

(1) Log a received message. This is called as soon as we know (from
the length word) that we have the whole message available, and it's
just passed a pointer into the input buffer. It should examine the
input message for itself and print the details.

(2) Log a message-to-be-sent. Again, call it as soon as we've constructed
a complete message in the output buffer, and let it examine and print
that message for itself.

Both of these pieces of logic could be written directly from the protocol
specification, without any interaction with the main libpq code paths,
which would be a Good Thing IMO. The current intertwined approach is
somewhere between useless and counterproductive if you're in need of
tracing down a libpq bug. (In other words, I'm suggesting that the
apparent need for duplicate logic would be good not bad, and indeed that
it'd be best to write the tracing logic without consulting the existing
libpq code at all.)

This would, I think, also eliminate the need for extra storage to hold
info about bits of the message, which IMO is a pretty significant
downside of the proposed design. The printing logic would just print
directly to Pfdebug; it wouldn't have to accumulate anything, and so
it wouldn't have the out-of-memory failure modes that this patch has.
You could also get rid of messy stuff like pqTraceForciblyCloseBeMsg.

Lastly, this'd reduce the overhead the tracing functionality imposes
on normal usage to about nil. Admittedly, all those "if (Pfdebug)"
tests probably don't cost that much execution-wise, but they cost
something. Making only one such test per sent or received message
has to be better.

regards, tom lane

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Tom Lane 2021-03-04 23:06:08 Re: SPI return
Previous Message Daniel Gustafsson 2021-03-04 22:54:17 Re: Disallow SSL compression?