Re: Fix tracing of BackendKeyData and CancelRequest messages

Hi,

Thanks for the review!

On Fri, Jul 3, 2026 at 2:10 PM Heikki Linnakangas <hlinnaka(at)iki(dot)fi> wrote:
> While testing just the first patch, I noticed that PQcancel() doesn't do
> the tracing even if it was enabled in the main connection, which made it
> a little hard to test. I didn't try this patch, but I hope it fixes that
> problem too.

Yeah, as PQcancel is signal-safe, it doesn't go through the normal
message construction, and thus is not traced. I've done an attempt to
fix that, but that requires a new flag that's enabled in the signal
handler, and then trying to generate the trace for the cancel request
after that, and it isn't great.
Given there's an active thread to get rid of PQcancel calls[0], maybe
it's not worth it to add more logic to the signal handler and PQcancel
to trace those cancel requests?

> > 0003: Replace libpq_pipeline PQtrace calls by PGTRACE, adding tracing
> > of startup messages, with some additional regress masking. I've also
> > added a warning message to report mismatch length similar to what's
> > done in pqTraceOutputMessage.
>
> Could you achieve the same by calling PQtrace() earlier? Perhaps switch
> to PQconnectStart() interface, and call PQtrace() right after
> PQconnectStart()?

That could be doable. However, another benefit of the PGTRACE approach
is to make tracing available in psql and make testing protocol changes
easier. With this, it should be possible to add a regression suite
using trace outputs that doesn't depend on the libpq_pipeline module.
I've also been trying to implement libpq compression, and my current
way to check the packet content is Wireshark which isn't very
practical. Which is why I've been looking into using PQtrace with psql
to make testing easier (and how I've stumbled on the BackendKeyData
issue).

> > 0004: Add tracing of cancel requests in libpq_pipeline test. Calling
> > PQuntrace on the main and monitor connections was necessary to allow
> > the cancel connections to append the cancel messages without conflict.
>
> Seems unrelated to pipelining, so perhaps this should go somewhere else.
> Then again, we already crossed that bridge when we added the
> "protocol_version" test there, which is also unrelated to pipelining.
> Maybe we should rename the test module, or add some comments noting that
> it's not just for pipelining anymore.

Given the module seems focused on testing the libpq API itself rather
than pipeline, would renaming it to test_libpq be good?

> As a side note, I find the output from pqTraceOutputNchar() awkward for
> things like the cancel key, which is raw binary bytes:
>
> > BackendKeyData 711421 'm[\x80\x95\xd6\x81{I\x8b\x04>\xab\x7fwMG\xda!\xc1\xb8\xa7\x8d\xb0.\xcd\xaa\x15\x9c\x0f\xd2\xe8\x1b'
>
> We don't need to invest too much in making the trace output pretty, but
> I think it would make sense to print that as a hex string.

Agreed. I've created a pqTraceOutputNbyte function to print a hex
string and use it for BackendKeyData and CancelRequest.

The new updated patchset has now:

0001: Create the pqTraceOutputNbyte and use it for BackendKeyData and
CancelRequest to print the backend key as hex string

0002: Additional regress masking for StartupMessage and ParameterValue

0003: Make pqtrace write line atomically. Instead of writing a line in
multiple fprintf, a line is now buffered in a PQExpBuffer and written
in a single fprintf. This is needed for 0004 and the tracing of cancel
requests.

0004: Add the PGTRACE var env to libpq. The previous version didn't
handle cancel requests correctly, as the cancel connection would open
a new fd to the trace file, truncating it while the source connection
was using it.
Now, PQcancelCreate copies the Pfdebug to the cancelConn to use it
when the cancel request is sent. As the lines are now written to
Pfdebug atomically, the source connection and cancel connection can
share the same Pfdebug.
This does make the assumption that the source connection outlives the
cancel connection to keep the Pfdebug fd opened.

0005: Switch libpq_pipeline to use PGTRACE and add the additional
startup messages to the traces

0006: Enable tracing of the cancel test in libpq_pipeline.

[0]: https://www.postgresql.org/message-id/flat/DEY0N7FS8NCU.1F7QXGG37MQ09%40jeltef.nl

Regards,
Anthonin Bonnefoy