public inbox for [email protected]help / color / mirror / Atom feed
Fix tracing of BackendKeyData and CancelRequest messages 3+ messages / 2 participants [nested] [flat]
* Fix tracing of BackendKeyData and CancelRequest messages @ 2026-07-03 09:42 Anthonin Bonnefoy <[email protected]> 0 siblings, 1 reply; 3+ messages in thread From: Anthonin Bonnefoy @ 2026-07-03 09:42 UTC (permalink / raw) To: pgsql-hackers Hi, BackendKeyData length was increased from 4 bytes to a variable sized length (up to 256 bytes) in a460251f0a. However, PQtrace still traces it as a 4 bytes key, leading to a "mismatched message length" warning message. The same issue impacts the tracing of CancelRequest. This shows the lack of coverage of tracing startup packets: libpq_pipeline only starts traces once the connection is established. There's also no way to test this with psql. The attached patchset fixes the traces BackendKeyData and CancelRequest, add the possibility of tracing any connection created by libpq, and add test coverage for the startup packets. It contains the following files: 0001: Fix tracing of BackendKeyData and CancelRequest messages 0002: Add PGTRACE env var in libpq to enable protocol tracing to the target file (or '-' for stdout). One limitation of this approach is that you should only have one connection writing to a trace file. If an application opens multiple connections to the same PGTRACE, each connection will open its own fd and erase others traces. But given this is to debug protocol messages, it sounds like an acceptable limitation. 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. 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. Regards, Anthonin Bonnefoy Attachments: [application/octet-stream] v1-0002-Add-PGTRACE-env-to-enable-protocol-tracing-in-lib.patch (7.6K, ../../CAO6_Xqo6gTv9=76H=k2qDRFU+KHuBiY2S=bQynEr6J8gS7L6xA@mail.gmail.com/2-v1-0002-Add-PGTRACE-env-to-enable-protocol-tracing-in-lib.patch) download | inline diff: From beff2f5d3568dbf44e63a14e6130c65880328112 Mon Sep 17 00:00:00 2001 From: Anthonin Bonnefoy <[email protected]> Date: Fri, 26 Jun 2026 11:06:16 +0200 Subject: Add PGTRACE env to enable protocol tracing in libpq Add 3 env vars, PGTRACE, PGTRACEAPPEND and PGTRACEFLAGS. When PGTRACE is set, PQtrace will be set when connection options are processed. This allows to trace protocol messages like startup messages and BackendKeyData. This also allows enabling protocol tracing on any application using libpq. --- doc/src/sgml/libpq.sgml | 70 +++++++++++++++++++++++++++++++ src/interfaces/libpq/fe-connect.c | 60 +++++++++++++++++++++++++- src/interfaces/libpq/libpq-int.h | 5 +++ 3 files changed, 134 insertions(+), 1 deletion(-) diff --git a/doc/src/sgml/libpq.sgml b/doc/src/sgml/libpq.sgml index 7d3c3bb66d8..4d4bd4ef559 100644 --- a/doc/src/sgml/libpq.sgml +++ b/doc/src/sgml/libpq.sgml @@ -2424,6 +2424,46 @@ postgresql://%2Fvar%2Flib%2Fpostgresql/dbname </listitem> </varlistentry> + <varlistentry id="libpq-connect-trace-file" xreflabel="trace_file"> + <term><literal>trace_file</literal></term> + <listitem> + <para> + If set, enables tracing of the client/server protocol exchange to + the named file. The special value <literal>-</literal> sends the + trace to <literal>stdout</literal>. Multiple connections using + the same trace file is currently not supported. + </para> + </listitem> + </varlistentry> + + <varlistentry id="libpq-connect-trace-flags" xreflabel="trace_flags"> + <term><literal>trace_flags</literal></term> + <listitem> + <para> + Specifies the trace flags applied when + <xref linkend="libpq-connect-trace-file"/> is set. The value is + an integer that is the bitwise OR of the flag values accepted by + <xref linkend="libpq-PQsetTraceFlags"/>: + <literal>1</literal> for <literal>PQTRACE_SUPPRESS_TIMESTAMPS</literal>, + <literal>2</literal> for <literal>PQTRACE_REGRESS_MODE</literal>. + The default is <literal>0</literal>. This option has no effect + unless <literal>trace_file</literal> is also set. + </para> + </listitem> + </varlistentry> + + <varlistentry id="libpq-connect-trace-file-append" xreflabel="trace_file_append"> + <term><literal>trace_file_append</literal></term> + <listitem> + <para> + If set to <literal>1</literal>, the trace file specified by <xref + linkend="libpq-connect-trace-file"/> will be opened in append mode. + With the default <literal>0</literal> value, the file will be opened in + write mode. This option has no effect unless + <literal>trace_file</literal> is also set. </para> + </listitem> + </varlistentry> + <varlistentry id="libpq-connect-load-balance-hosts" xreflabel="load_balance_hosts"> <term><literal>load_balance_hosts</literal></term> <listitem> @@ -9454,6 +9494,36 @@ myEventProc(PGEventId evtId, void *evtInfo, void *passThrough) linkend="libpq-connect-oauth-ca-file"/> connection parameter. </para> </listitem> + + <listitem> + <para> + <indexterm> + <primary><envar>PGTRACE</envar></primary> + </indexterm> + <envar>PGTRACE</envar> behaves the same as the <xref + linkend="libpq-connect-trace-file"/> connection parameter. + </para> + </listitem> + + <listitem> + <para> + <indexterm> + <primary><envar>PGTRACEFLAGS</envar></primary> + </indexterm> + <envar>PGTRACEFLAGS</envar> behaves the same as the <xref + linkend="libpq-connect-trace-flags"/> connection parameter. + </para> + </listitem> + + <listitem> + <para> + <indexterm> + <primary><envar>PGTRACEAPPEND</envar></primary> + </indexterm> + <envar>PGTRACEAPPEND</envar> behaves the same as the <xref + linkend="libpq-connect-trace-file-append"/> connection parameter. + </para> + </listitem> </itemizedlist> </para> diff --git a/src/interfaces/libpq/fe-connect.c b/src/interfaces/libpq/fe-connect.c index 38422becc48..d7f80f80631 100644 --- a/src/interfaces/libpq/fe-connect.c +++ b/src/interfaces/libpq/fe-connect.c @@ -385,6 +385,19 @@ static const internalPQconninfoOption PQconninfoOptions[] = { "Target-Session-Attrs", "", 15, /* sizeof("prefer-standby") = 15 */ offsetof(struct pg_conn, target_session_attrs)}, + {"trace_file", "PGTRACE", + NULL, NULL, + "Trace-File", "D", 64, + offsetof(struct pg_conn, trace_file_str)}, + + {"trace_file_append", "PGTRACEAPPEND", "0", NULL, + "Trace-File-Append", "", 1, + offsetof(struct pg_conn, trace_file_append)}, + + {"trace_flags", "PGTRACEFLAGS", NULL, NULL, + "Trace-Flags", "D", 1, + offsetof(struct pg_conn, trace_flags_str)}, + {"load_balance_hosts", "PGLOADBALANCEHOSTS", DefaultLoadBalanceHosts, NULL, "Load-Balance-Hosts", "", 8, /* sizeof("disable") = 8 */ @@ -1257,6 +1270,7 @@ bool pqConnectOptions2(PGconn *conn) { int i; + int trace_flags = 0; /* * Allocate memory for details about each host to which we might possibly @@ -2057,6 +2071,39 @@ pqConnectOptions2(PGconn *conn) conn->scram_client_key_len = len; } + /* If we already have an opened trace file, keep it */ + if (conn->trace_file_str && conn->trace_file == NULL) + { + if (strcmp(conn->trace_file_str, "-") == 0) + conn->trace_file = stdout; + else + { + char *mode = (conn->trace_file_append && conn->trace_file_append[0] == '1') ? "a" : "w"; + + conn->trace_file = fopen(conn->trace_file_str, mode); + } + if (conn->trace_file == NULL) + { + libpq_append_conn_error(conn, "could not open trace file \"%s\": %m", conn->trace_file_str); + return false; + } + /* Make it line-buffered */ + if (conn->trace_file != stdout) + setvbuf(conn->trace_file, NULL, PG_IOLBF, 0); + PQtrace(conn, conn->trace_file); + + if (conn->trace_flags_str) + { + if (!pqParseIntParam(conn->trace_flags_str, &trace_flags, conn, + "trace_flags")) + { + return false; + } + } + + PQsetTraceFlags(conn, trace_flags); + } + if (conn->scram_server_key) { int len; @@ -5043,6 +5090,7 @@ pqMakeEmptyPGconn(void) conn->sock = PGINVALID_SOCKET; conn->altsock = PGINVALID_SOCKET; conn->Pfdebug = NULL; + conn->trace_file = NULL; /* * We try to send at least 8K at a time, which is the usual size of pipe @@ -5164,7 +5212,17 @@ freePGconn(PGconn *conn) free(conn->oauth_client_secret); free(conn->oauth_ca_file); free(conn->oauth_scope); - /* Note that conn->Pfdebug is not ours to close or free */ + free(conn->trace_file_str); + free(conn->trace_file_append); + free(conn->trace_flags_str); + + /* + * Note that conn->Pfdebug is not ours to close or free if provided + * externally. If tracing was enabled through PGTRACE, conn->Pfdebug will + * be set to conn->trace_file, so closing conn->trace_file is enough. + */ + if (conn->trace_file && conn->trace_file != stdout) + fclose(conn->trace_file); free(conn->events); pqReleaseConnHosts(conn); free(conn->connip); diff --git a/src/interfaces/libpq/libpq-int.h b/src/interfaces/libpq/libpq-int.h index 461b39620c3..573a64c54a8 100644 --- a/src/interfaces/libpq/libpq-int.h +++ b/src/interfaces/libpq/libpq-int.h @@ -449,6 +449,11 @@ struct pg_conn char *oauth_ca_file; /* CA file path */ bool oauth_want_retry; /* should we retry on failure? */ + FILE *trace_file; + char *trace_file_str; + char *trace_file_append; /* Trace opened in append mode (0 or 1) */ + char *trace_flags_str; + /* Optional file to write trace info to */ FILE *Pfdebug; int traceFlags; -- 2.54.0 [application/octet-stream] v1-0004-Test-tracing-of-cancel-requests.patch (5.3K, ../../CAO6_Xqo6gTv9=76H=k2qDRFU+KHuBiY2S=bQynEr6J8gS7L6xA@mail.gmail.com/3-v1-0004-Test-tracing-of-cancel-requests.patch) download | inline diff: From 4de7e463713c8c15c128e703caf11033e85221dd Mon Sep 17 00:00:00 2001 From: Anthonin Bonnefoy <[email protected]> Date: Thu, 2 Jul 2026 14:58:42 +0200 Subject: Test tracing of cancel requests Enable PGTRACE for cancel test of libpq_pipeline to test the tracing of cancel requests. PGTRACEAPPEND needs to be enabled as cancel requests are sent from a new connection, and we want to append the new traced requests to the existing trace file. The main connection and monitor connection are PQuntraced to avoid having multiple connections writing to the same trace file. --- .../modules/libpq_pipeline/libpq_pipeline.c | 11 +++++ .../libpq_pipeline/t/001_libpq_pipeline.pl | 8 +++- .../libpq_pipeline/traces/cancel.trace | 45 +++++++++++++++++++ 3 files changed, 63 insertions(+), 1 deletion(-) create mode 100644 src/test/modules/libpq_pipeline/traces/cancel.trace diff --git a/src/test/modules/libpq_pipeline/libpq_pipeline.c b/src/test/modules/libpq_pipeline/libpq_pipeline.c index e7526e46d46..e75fad13443 100644 --- a/src/test/modules/libpq_pipeline/libpq_pipeline.c +++ b/src/test/modules/libpq_pipeline/libpq_pipeline.c @@ -300,11 +300,22 @@ test_cancel(PGconn *conn) if (PQsetnonblocking(conn, 1) != 0) pg_fatal("failed to set nonblocking mode: %s", PQerrorMessage(conn)); + /* + * We need to avoid having multiple processes writing in the same trace, + * and we want to trace the cancel request, so untrace the main connection + */ + PQuntrace(conn); + /* * Make a separate connection to the database to monitor the query on the * main connection. */ monitorConn = copy_connection(conn); + + /* + * Also untrace the connection to leave trace file to cancel requests + */ + PQuntrace(monitorConn); Assert(PQstatus(monitorConn) == CONNECTION_OK); /* test PQcancel */ diff --git a/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl b/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl index 31cd1795f55..c5d8edd343e 100644 --- a/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl +++ b/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl @@ -39,7 +39,7 @@ for my $testname (@tests) my $cmptrace = grep(/^$testname$/, qw(simple_pipeline nosync multi_pipelines prepared singlerow pipeline_abort pipeline_idle transaction - disallowed_in_pipeline)) > 0; + disallowed_in_pipeline cancel)) > 0; # For a bunch of tests, generate a libpq trace file too. my $traceout = @@ -47,12 +47,18 @@ for my $testname (@tests) local $ENV{PGTRACE}; local $ENV{PGTRACEFLAGS}; + local $ENV{PGTRACEAPPEND}; if ($cmptrace) { $ENV{PGTRACE} = $traceout; + # Set trace flags to PQTRACE_SUPPRESS_TIMESTAMPS | PQTRACE_REGRESS_MODE $ENV{PGTRACEFLAGS} = 3; + # cancel test opens new connections to send the cancel requests. Enable + # append mode to avoid clearing the file with every new connection. + $ENV{PGTRACEAPPEND} = 1 if $testname eq 'cancel'; } else { delete $ENV{PGTRACE}; + delete $ENV{PGTRACEFLAGS}; } # Execute the test using the latest protocol version. diff --git a/src/test/modules/libpq_pipeline/traces/cancel.trace b/src/test/modules/libpq_pipeline/traces/cancel.trace new file mode 100644 index 00000000000..b6bd5c915e7 --- /dev/null +++ b/src/test/modules/libpq_pipeline/traces/cancel.trace @@ -0,0 +1,45 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 44 CancelRequest 1234 5678 NNNN 'BBBB' +F 44 CancelRequest 1234 5678 NNNN 'BBBB' +F 44 CancelRequest 1234 5678 NNNN 'BBBB' -- 2.54.0 [application/octet-stream] v1-0001-Fix-tracing-of-BackendKeyData-and-CancelRequest.patch (2.3K, ../../CAO6_Xqo6gTv9=76H=k2qDRFU+KHuBiY2S=bQynEr6J8gS7L6xA@mail.gmail.com/4-v1-0001-Fix-tracing-of-BackendKeyData-and-CancelRequest.patch) download | inline diff: From 0d6d1b6134e50233ba543acf2885a021dfd16bb4 Mon Sep 17 00:00:00 2001 From: Anthonin Bonnefoy <[email protected]> Date: Fri, 26 Jun 2026 10:37:32 +0200 Subject: Fix tracing of BackendKeyData and CancelRequest BackendKeyData length was increased from 4 bytes to a variable-length length (up to 256 bytes) in a460251f0a. However, pqTrace still traces it as a 4 bytes key, leading to a "mismatched message length" warning message. The same issue impacts the tracing of CancelRequest. This patch fixes the issue by using pqTraceOutputNchar instead of pqTraceOutputInt32 in both cases. --- src/interfaces/libpq/fe-trace.c | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/interfaces/libpq/fe-trace.c b/src/interfaces/libpq/fe-trace.c index c348b08c39b..aa2637e4f1e 100644 --- a/src/interfaces/libpq/fe-trace.c +++ b/src/interfaces/libpq/fe-trace.c @@ -452,11 +452,11 @@ pqTraceOutput_CopyOutResponse(FILE *f, const char *message, int *cursor) } static void -pqTraceOutput_BackendKeyData(FILE *f, const char *message, int *cursor, bool regress) +pqTraceOutput_BackendKeyData(FILE *f, const char *message, int len, int *cursor, bool regress) { fprintf(f, "BackendKeyData\t"); pqTraceOutputInt32(f, message, cursor, regress); - pqTraceOutputInt32(f, message, cursor, regress); + pqTraceOutputNchar(f, len, message, cursor, regress); } static void @@ -762,7 +762,7 @@ pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer) /* No message content */ break; case PqMsg_BackendKeyData: - pqTraceOutput_BackendKeyData(conn->Pfdebug, message, &logCursor, regress); + pqTraceOutput_BackendKeyData(conn->Pfdebug, message, conn->be_cancel_key_len, &logCursor, regress); break; case PqMsg_NoData: fprintf(conn->Pfdebug, "NoData"); @@ -876,7 +876,7 @@ pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message) pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, regress); - pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, regress); + pqTraceOutputNchar(conn->Pfdebug, conn->be_cancel_key_len, message, &logCursor, regress); } else if (version == NEGOTIATE_SSL_CODE) { -- 2.54.0 [application/octet-stream] v1-0003-Add-trace-of-startup-packets-in-libpq_pipeline-te.patch (21.8K, ../../CAO6_Xqo6gTv9=76H=k2qDRFU+KHuBiY2S=bQynEr6J8gS7L6xA@mail.gmail.com/5-v1-0003-Add-trace-of-startup-packets-in-libpq_pipeline-te.patch) download | inline diff: From 5d643700b432574aba0e77836989779043e983d0 Mon Sep 17 00:00:00 2001 From: Anthonin Bonnefoy <[email protected]> Date: Fri, 26 Jun 2026 14:32:00 +0200 Subject: Add trace of startup packets in libpq_pipeline tests The current way to enable tracing in libpq_pipeline only set PQtrace after the connection is created, missing the trace of the startup packets. This patch replaces it by the PGTRACE env var, enabling PQtrace before the first packet is sent and thus tracing all protocol messages. With the additional traced messages, additional regress masking is necessary for StartupMessage and ParameterStatus. The parameter values can be different depending on the test environment, so both the value and the message length needs to be masked. --- src/interfaces/libpq/fe-trace.c | 52 ++++++++++++++----- .../modules/libpq_pipeline/libpq_pipeline.c | 32 +----------- .../libpq_pipeline/t/001_libpq_pipeline.pl | 8 ++- .../traces/disallowed_in_pipeline.trace | 24 +++++++++ .../traces/multi_pipelines.trace | 24 +++++++++ .../libpq_pipeline/traces/nosync.trace | 24 +++++++++ .../traces/pipeline_abort.trace | 24 +++++++++ .../libpq_pipeline/traces/pipeline_idle.trace | 24 +++++++++ .../libpq_pipeline/traces/prepared.trace | 24 +++++++++ .../traces/simple_pipeline.trace | 24 +++++++++ .../libpq_pipeline/traces/singlerow.trace | 24 +++++++++ .../libpq_pipeline/traces/transaction.trace | 24 +++++++++ 12 files changed, 264 insertions(+), 44 deletions(-) diff --git a/src/interfaces/libpq/fe-trace.c b/src/interfaces/libpq/fe-trace.c index aa2637e4f1e..f4ae22796a6 100644 --- a/src/interfaces/libpq/fe-trace.c +++ b/src/interfaces/libpq/fe-trace.c @@ -536,11 +536,11 @@ pqTraceOutput_Authentication(FILE *f, const char *message, int *cursor, } static void -pqTraceOutput_ParameterStatus(FILE *f, const char *message, int *cursor) +pqTraceOutput_ParameterStatus(FILE *f, const char *message, int *cursor, bool regress) { fprintf(f, "ParameterStatus\t"); pqTraceOutputString(f, message, cursor, false); - pqTraceOutputString(f, message, cursor, false); + pqTraceOutputString(f, message, cursor, regress); } static void @@ -645,12 +645,16 @@ pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer) logCursor += 4; /* - * In regress mode, suppress the length of ErrorResponse and - * NoticeResponse. The F (file name), L (line number) and R (routine + * In regress mode, suppress the length of ErrorResponse, NoticeResponse + * and ParameterStatus. The F (file name), L (line number) and R (routine * name) fields can change as server code is modified, and if their - * lengths differ from the originals, that would break tests. + * lengths differ from the originals, that would break tests. For + * ParameterStatus, the size changes depending on the parameters' value, + * whose values depend on the test environment. */ - if (regress && !toServer && (id == PqMsg_ErrorResponse || id == PqMsg_NoticeResponse)) + if (regress && !toServer && (id == PqMsg_ErrorResponse + || id == PqMsg_NoticeResponse + || id == PqMsg_ParameterStatus)) fprintf(conn->Pfdebug, "%s\tNN\t", prefix); else fprintf(conn->Pfdebug, "%s\t%d\t", prefix, length); @@ -791,7 +795,7 @@ pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer) if (toServer) fprintf(conn->Pfdebug, "Sync"); /* no message content */ else - pqTraceOutput_ParameterStatus(conn->Pfdebug, message, &logCursor); + pqTraceOutput_ParameterStatus(conn->Pfdebug, message, &logCursor, regress); break; case PqMsg_ParameterDescription: pqTraceOutput_ParameterDescription(conn->Pfdebug, message, &logCursor, regress); @@ -859,17 +863,27 @@ pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message) length = (int) pg_ntoh32(length); logCursor += 4; - fprintf(conn->Pfdebug, "F\t%d\t", length); - if (length < 8) { - fprintf(conn->Pfdebug, "Unknown message\n"); + fprintf(conn->Pfdebug, "F\t%d\tUnknown message\n", length); return; } memcpy(&version, message + logCursor, 4); version = (int) pg_ntoh32(version); + /* + * In regress, suppress the length of StartupMessage. The parameter values + * depend on the test environment, so the test may break depending on + * where it's executed. + */ + if (regress && (version != CANCEL_REQUEST_CODE + && version != NEGOTIATE_SSL_CODE + && version != NEGOTIATE_GSS_CODE)) + fprintf(conn->Pfdebug, "F\tNN\t"); + else + fprintf(conn->Pfdebug, "F\t%d\t", length); + if (version == CANCEL_REQUEST_CODE && length >= 16) { fprintf(conn->Pfdebug, "CancelRequest\t"); @@ -897,13 +911,27 @@ pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message) pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); while (message[logCursor] != '\0') { - /* XXX should we suppress anything in regress mode? */ - pqTraceOutputString(conn->Pfdebug, message, &logCursor, false); pqTraceOutputString(conn->Pfdebug, message, &logCursor, false); + pqTraceOutputString(conn->Pfdebug, message, &logCursor, regress); } + + /* + * Startup messages end with a trailing terminator, advance our cursor + * to include it + */ + logCursor++; } fputc('\n', conn->Pfdebug); + + /* + * Verify the printing routine did it right. There's no one-byte message + * identifier here, so logCursor should match the length + */ + if (logCursor != length) + fprintf(conn->Pfdebug, + "mismatched message length: consumed %d, expected %d\n", + logCursor, length); } /* diff --git a/src/test/modules/libpq_pipeline/libpq_pipeline.c b/src/test/modules/libpq_pipeline/libpq_pipeline.c index 1660a68955e..e7526e46d46 100644 --- a/src/test/modules/libpq_pipeline/libpq_pipeline.c +++ b/src/test/modules/libpq_pipeline/libpq_pipeline.c @@ -31,10 +31,6 @@ static bool process_result(PGconn *conn, PGresult *res, int results, static const char *const progname = "libpq_pipeline"; -/* Options and defaults */ -static char *tracefile = NULL; /* path to PQtrace() file */ - - #ifdef DEBUG_OUTPUT #define pg_debug(...) do { fprintf(stderr, __VA_ARGS__); } while (0) #else @@ -2109,7 +2105,6 @@ usage(const char *progname) fprintf(stderr, " %s [OPTION] tests\n", progname); fprintf(stderr, " %s [OPTION] TESTNAME [CONNINFO]\n", progname); fprintf(stderr, "\nOptions:\n"); - fprintf(stderr, " -t TRACEFILE generate a libpq trace to TRACEFILE\n"); fprintf(stderr, " -r NUMROWS use NUMROWS as the test size\n"); } @@ -2136,13 +2131,12 @@ main(int argc, char **argv) { const char *conninfo = ""; PGconn *conn; - FILE *trace = NULL; char *testname; int numrows = 10000; PGresult *res; int c; - while ((c = getopt(argc, argv, "r:t:")) != -1) + while ((c = getopt(argc, argv, "r:")) != -1) { switch (c) { @@ -2156,9 +2150,6 @@ main(int argc, char **argv) exit(1); } break; - case 't': /* trace file */ - tracefile = pg_strdup(optarg); - break; } } @@ -2203,24 +2194,6 @@ main(int argc, char **argv) pg_fatal("failed to set \"debug_parallel_query\": %s", PQerrorMessage(conn)); PQclear(res); - /* Set the trace file, if requested */ - if (tracefile != NULL) - { - if (strcmp(tracefile, "-") == 0) - trace = stdout; - else - trace = fopen(tracefile, "w"); - if (trace == NULL) - pg_fatal("could not open file \"%s\": %m", tracefile); - - /* Make it line-buffered */ - setvbuf(trace, NULL, PG_IOLBF, 0); - - PQtrace(conn, trace); - PQsetTraceFlags(conn, - PQTRACE_SUPPRESS_TIMESTAMPS | PQTRACE_REGRESS_MODE); - } - if (strcmp(testname, "cancel") == 0) test_cancel(conn); else if (strcmp(testname, "disallowed_in_pipeline") == 0) @@ -2256,8 +2229,5 @@ main(int argc, char **argv) /* close the connection to the database and cleanup */ PQfinish(conn); - if (trace && trace != stdout) - fclose(trace); - return 0; } diff --git a/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl b/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl index c74fda8aa37..31cd1795f55 100644 --- a/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl +++ b/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl @@ -44,9 +44,15 @@ for my $testname (@tests) # For a bunch of tests, generate a libpq trace file too. my $traceout = "$PostgreSQL::Test::Utils::tmp_check/traces/$testname.trace"; + + local $ENV{PGTRACE}; + local $ENV{PGTRACEFLAGS}; if ($cmptrace) { - push @extraargs, "-t" => $traceout; + $ENV{PGTRACE} = $traceout; + $ENV{PGTRACEFLAGS} = 3; + } else { + delete $ENV{PGTRACE}; } # Execute the test using the latest protocol version. diff --git a/src/test/modules/libpq_pipeline/traces/disallowed_in_pipeline.trace b/src/test/modules/libpq_pipeline/traces/disallowed_in_pipeline.trace index dd6df03f1ed..1859e228cdb 100644 --- a/src/test/modules/libpq_pipeline/traces/disallowed_in_pipeline.trace +++ b/src/test/modules/libpq_pipeline/traces/disallowed_in_pipeline.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 13 Query "SELECT 1" B 33 RowDescription 1 "?column?" NNNN 0 NNNN 4 -1 0 B 11 DataRow 1 1 '1' diff --git a/src/test/modules/libpq_pipeline/traces/multi_pipelines.trace b/src/test/modules/libpq_pipeline/traces/multi_pipelines.trace index 1ee21f61dce..99b621bac21 100644 --- a/src/test/modules/libpq_pipeline/traces/multi_pipelines.trace +++ b/src/test/modules/libpq_pipeline/traces/multi_pipelines.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 21 Parse "" "SELECT $1" 1 NNNN F 19 Bind "" "" 0 1 1 '1' 1 0 F 6 Describe P "" diff --git a/src/test/modules/libpq_pipeline/traces/nosync.trace b/src/test/modules/libpq_pipeline/traces/nosync.trace index d99aac649db..f3ce2b1ed0b 100644 --- a/src/test/modules/libpq_pipeline/traces/nosync.trace +++ b/src/test/modules/libpq_pipeline/traces/nosync.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 34 Parse "" "SELECT repeat('xyzxz', 12)" 0 F 14 Bind "" "" 0 0 1 0 F 6 Describe P "" diff --git a/src/test/modules/libpq_pipeline/traces/pipeline_abort.trace b/src/test/modules/libpq_pipeline/traces/pipeline_abort.trace index 3e5007d13b2..5e27a6dbe2f 100644 --- a/src/test/modules/libpq_pipeline/traces/pipeline_abort.trace +++ b/src/test/modules/libpq_pipeline/traces/pipeline_abort.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 42 Query "DROP TABLE IF EXISTS pq_pipeline_demo" B NN NoticeResponse S "NOTICE" V "NOTICE" C "00000" M "table "pq_pipeline_demo" does not exist, skipping" F "SSSS" L "SSSS" R "SSSS" \x00 B 15 CommandComplete "DROP TABLE" diff --git a/src/test/modules/libpq_pipeline/traces/pipeline_idle.trace b/src/test/modules/libpq_pipeline/traces/pipeline_idle.trace index 83ee415b03e..4c5215c0096 100644 --- a/src/test/modules/libpq_pipeline/traces/pipeline_idle.trace +++ b/src/test/modules/libpq_pipeline/traces/pipeline_idle.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 16 Parse "" "SELECT 1" 0 F 14 Bind "" "" 0 0 1 0 F 6 Describe P "" diff --git a/src/test/modules/libpq_pipeline/traces/prepared.trace b/src/test/modules/libpq_pipeline/traces/prepared.trace index aeb5de109e0..3cd16969144 100644 --- a/src/test/modules/libpq_pipeline/traces/prepared.trace +++ b/src/test/modules/libpq_pipeline/traces/prepared.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 68 Parse "select_one" "SELECT $1, '42', $1::numeric, interval '1 sec'" 1 NNNN F 16 Describe S "select_one" F 4 Sync diff --git a/src/test/modules/libpq_pipeline/traces/simple_pipeline.trace b/src/test/modules/libpq_pipeline/traces/simple_pipeline.trace index 5c94749bc1e..4f38387f6ca 100644 --- a/src/test/modules/libpq_pipeline/traces/simple_pipeline.trace +++ b/src/test/modules/libpq_pipeline/traces/simple_pipeline.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 21 Parse "" "SELECT $1" 1 NNNN F 19 Bind "" "" 0 1 1 '1' 1 0 F 6 Describe P "" diff --git a/src/test/modules/libpq_pipeline/traces/singlerow.trace b/src/test/modules/libpq_pipeline/traces/singlerow.trace index 029cd66581d..d918d2aa896 100644 --- a/src/test/modules/libpq_pipeline/traces/singlerow.trace +++ b/src/test/modules/libpq_pipeline/traces/singlerow.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 38 Parse "" "SELECT generate_series(42, $1)" 0 F 20 Bind "" "" 0 1 2 '44' 1 0 F 6 Describe P "" diff --git a/src/test/modules/libpq_pipeline/traces/transaction.trace b/src/test/modules/libpq_pipeline/traces/transaction.trace index 1dcc2373c0b..9b79ae96237 100644 --- a/src/test/modules/libpq_pipeline/traces/transaction.trace +++ b/src/test/modules/libpq_pipeline/traces/transaction.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 79 Query "DROP TABLE IF EXISTS pq_pipeline_tst;CREATE TABLE pq_pipeline_tst (id int)" B NN NoticeResponse S "NOTICE" V "NOTICE" C "00000" M "table "pq_pipeline_tst" does not exist, skipping" F "SSSS" L "SSSS" R "SSSS" \x00 B 15 CommandComplete "DROP TABLE" -- 2.54.0 ^ permalink raw reply [nested|flat] 3+ messages in thread
* Re: Fix tracing of BackendKeyData and CancelRequest messages @ 2026-07-03 12:10 Heikki Linnakangas <[email protected]> parent: Anthonin Bonnefoy <[email protected]> 0 siblings, 1 reply; 3+ messages in thread From: Heikki Linnakangas @ 2026-07-03 12:10 UTC (permalink / raw) To: Anthonin Bonnefoy <[email protected]>; pgsql-hackers On 03/07/2026 12:42, Anthonin Bonnefoy wrote: > BackendKeyData length was increased from 4 bytes to a variable sized > length (up to 256 bytes) in a460251f0a. However, PQtrace still traces > it as a 4 bytes key, leading to a "mismatched message length" warning > message. The same issue impacts the tracing of CancelRequest. > > This shows the lack of coverage of tracing startup packets: > libpq_pipeline only starts traces once the connection is established. > There's also no way to test this with psql. > > The attached patchset fixes the traces BackendKeyData and > CancelRequest, add the possibility of tracing any connection created > by libpq, and add test coverage for the startup packets. It contains > the following files: > > 0001: Fix tracing of BackendKeyData and CancelRequest messages > @@ -762,7 +762,7 @@ pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer) > /* No message content */ > break; > case PqMsg_BackendKeyData: > - pqTraceOutput_BackendKeyData(conn->Pfdebug, message, &logCursor, regress); > + pqTraceOutput_BackendKeyData(conn->Pfdebug, message, conn->be_cancel_key_len, &logCursor, regress); > break; > case PqMsg_NoData: > fprintf(conn->Pfdebug, "NoData"); This should use the 'length' parsed from the message, instead of relying on conn->be_cancel_key_len. Same in pqTraceOutputNoTypeByteMessage(). I changed that, and committed and backpatched. Thanks! I did not look closely at the rest of the patches, but more test coverage sounds like a good idea. Some quick comments just based on the descriptions though: > 0002: Add PGTRACE env var in libpq to enable protocol tracing to the > target file (or '-' for stdout). One limitation of this approach is > that you should only have one connection writing to a trace file. If > an application opens multiple connections to the same PGTRACE, each > connection will open its own fd and erase others traces. But given > this is to debug protocol messages, it sounds like an acceptable > limitation. 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. > 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()? > 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. 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. - Heikki ^ permalink raw reply [nested|flat] 3+ messages in thread
* Re: Fix tracing of BackendKeyData and CancelRequest messages @ 2026-07-08 15:38 Anthonin Bonnefoy <[email protected]> parent: Heikki Linnakangas <[email protected]> 0 siblings, 0 replies; 3+ messages in thread From: Anthonin Bonnefoy @ 2026-07-08 15:38 UTC (permalink / raw) To: Heikki Linnakangas <[email protected]>; +Cc: pgsql-hackers Hi, Thanks for the review! On Fri, Jul 3, 2026 at 2:10 PM Heikki Linnakangas <[email protected]> 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 Attachments: [application/octet-stream] v2-0001-Print-cancel-key-as-a-hex-string-in-trace.patch (2.4K, ../../CAO6_XqrFWe9W=iRCS+nqEN1UBTPnMWh=FEpVpOgjgac0BWYZLA@mail.gmail.com/2-v2-0001-Print-cancel-key-as-a-hex-string-in-trace.patch) download | inline diff: From 005292954be8270e1eff3828e0418c7c090c8254 Mon Sep 17 00:00:00 2001 From: Anthonin Bonnefoy <[email protected]> Date: Tue, 7 Jul 2026 08:15:38 +0200 Subject: Print cancel key as a hex string in trace Currently, cancel key is printed with pqTraceOutputNchar, which print printable char as char, and the rest as hex. As cancel key is just random bytes, there's not much meaning to print them as chars. This patch introduces a new pqTraceOutputNbyte to print bytes using only hex. --- src/interfaces/libpq/fe-trace.c | 31 +++++++++++++++++++++++++++++-- 1 file changed, 29 insertions(+), 2 deletions(-) diff --git a/src/interfaces/libpq/fe-trace.c b/src/interfaces/libpq/fe-trace.c index 2901fa5b451..741be09bdd3 100644 --- a/src/interfaces/libpq/fe-trace.c +++ b/src/interfaces/libpq/fe-trace.c @@ -223,6 +223,33 @@ pqTraceOutputNchar(FILE *pfdebug, int len, const char *data, int *cursor, bool s *cursor += len; } +/* + * pqTraceOutputNbyte: output bytes in hexadecimal of exactly len bytes to the log + * + * If 'suppress' is true, print a literal 'BBBB' instead of the actual bytes. + */ +static void +pqTraceOutputNbyte(FILE *pfdebug, int len, const char *data, int *cursor, bool suppress) +{ + int i; + const char *v = data + *cursor; + + if (suppress) + { + fprintf(pfdebug, " 'BBBB'"); + *cursor += len; + return; + } + + fprintf(pfdebug, " \'"); + + for (i = 0; i < len; ++i) + fprintf(pfdebug, "\\x%02x", (unsigned char) v[i]); + + fprintf(pfdebug, "\'"); + *cursor += len; +} + /* * Output functions by protocol message type */ @@ -457,7 +484,7 @@ pqTraceOutput_BackendKeyData(FILE *f, const char *message, int *cursor, int leng { fprintf(f, "BackendKeyData\t"); pqTraceOutputInt32(f, message, cursor, regress); - pqTraceOutputNchar(f, length - *cursor + 1, message, cursor, regress); + pqTraceOutputNbyte(f, length - *cursor + 1, message, cursor, regress); } static void @@ -878,7 +905,7 @@ pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message) pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, regress); - pqTraceOutputNchar(conn->Pfdebug, length - logCursor, message, + pqTraceOutputNbyte(conn->Pfdebug, length - logCursor, message, &logCursor, regress); } else if (version == NEGOTIATE_SSL_CODE) -- 2.54.0 [application/octet-stream] v2-0004-Add-PGTRACE-env-to-enable-protocol-tracing-in-lib.patch (7.4K, ../../CAO6_XqrFWe9W=iRCS+nqEN1UBTPnMWh=FEpVpOgjgac0BWYZLA@mail.gmail.com/3-v2-0004-Add-PGTRACE-env-to-enable-protocol-tracing-in-lib.patch) download | inline diff: From 061ab76370e7d050f107f85b344ac7095d7252b9 Mon Sep 17 00:00:00 2001 From: Anthonin Bonnefoy <[email protected]> Date: Fri, 26 Jun 2026 11:06:16 +0200 Subject: Add PGTRACE env to enable protocol tracing in libpq Add 2 env vars, PGTRACE and PGTRACEFLAGS. When PGTRACE is set, PQtrace will be set when connection options are processed. This allows to trace protocol messages like startup messages and BackendKeyData. This also allows enabling protocol tracing on any application using libpq. When a cancel connection is created with PQcancelCreate, we copy tracing fd and trace flags to allow the cancel requests to be traced. Since writes to the trace_file are now done line by line, we can share a fd between the source connection and the cancel connection. --- doc/src/sgml/libpq.sgml | 48 +++++++++++++++++++++++ src/interfaces/libpq/fe-cancel.c | 6 +++ src/interfaces/libpq/fe-connect.c | 65 ++++++++++++++++++++++++++++++- src/interfaces/libpq/libpq-int.h | 4 ++ 4 files changed, 122 insertions(+), 1 deletion(-) diff --git a/doc/src/sgml/libpq.sgml b/doc/src/sgml/libpq.sgml index 7d3c3bb66d8..b2157860a40 100644 --- a/doc/src/sgml/libpq.sgml +++ b/doc/src/sgml/libpq.sgml @@ -2424,6 +2424,34 @@ postgresql://%2Fvar%2Flib%2Fpostgresql/dbname </listitem> </varlistentry> + <varlistentry id="libpq-connect-trace-file" xreflabel="trace_file"> + <term><literal>trace_file</literal></term> + <listitem> + <para> + If set, enables tracing of the client/server protocol exchange to + the named file. The special value <literal>-</literal> sends the + trace to <literal>stdout</literal>. Multiple connections using + the same trace file is currently not supported. + </para> + </listitem> + </varlistentry> + + <varlistentry id="libpq-connect-trace-flags" xreflabel="trace_flags"> + <term><literal>trace_flags</literal></term> + <listitem> + <para> + Specifies the trace flags applied when + <xref linkend="libpq-connect-trace-file"/> is set. The value is + an integer that is the bitwise OR of the flag values accepted by + <xref linkend="libpq-PQsetTraceFlags"/>: + <literal>1</literal> for <literal>PQTRACE_SUPPRESS_TIMESTAMPS</literal>, + <literal>2</literal> for <literal>PQTRACE_REGRESS_MODE</literal>. + The default is <literal>0</literal>. This option has no effect + unless <literal>trace_file</literal> is also set. + </para> + </listitem> + </varlistentry> + <varlistentry id="libpq-connect-load-balance-hosts" xreflabel="load_balance_hosts"> <term><literal>load_balance_hosts</literal></term> <listitem> @@ -9454,6 +9482,26 @@ myEventProc(PGEventId evtId, void *evtInfo, void *passThrough) linkend="libpq-connect-oauth-ca-file"/> connection parameter. </para> </listitem> + + <listitem> + <para> + <indexterm> + <primary><envar>PGTRACE</envar></primary> + </indexterm> + <envar>PGTRACE</envar> behaves the same as the <xref + linkend="libpq-connect-trace-file"/> connection parameter. + </para> + </listitem> + + <listitem> + <para> + <indexterm> + <primary><envar>PGTRACEFLAGS</envar></primary> + </indexterm> + <envar>PGTRACEFLAGS</envar> behaves the same as the <xref + linkend="libpq-connect-trace-flags"/> connection parameter. + </para> + </listitem> </itemizedlist> </para> diff --git a/src/interfaces/libpq/fe-cancel.c b/src/interfaces/libpq/fe-cancel.c index 4b5945979c4..c213ac4c08f 100644 --- a/src/interfaces/libpq/fe-cancel.c +++ b/src/interfaces/libpq/fe-cancel.c @@ -98,6 +98,12 @@ PQcancelCreate(PGconn *conn) */ cancelConn->cancelRequest = true; + /* + * Copy Pfdebug and trace flags from the original connection. + */ + cancelConn->Pfdebug = conn->Pfdebug; + cancelConn->traceFlags = conn->traceFlags; + if (!pqCopyPGconn(conn, cancelConn)) return (PGcancelConn *) cancelConn; diff --git a/src/interfaces/libpq/fe-connect.c b/src/interfaces/libpq/fe-connect.c index 38422becc48..4c1f8597ddf 100644 --- a/src/interfaces/libpq/fe-connect.c +++ b/src/interfaces/libpq/fe-connect.c @@ -385,6 +385,15 @@ static const internalPQconninfoOption PQconninfoOptions[] = { "Target-Session-Attrs", "", 15, /* sizeof("prefer-standby") = 15 */ offsetof(struct pg_conn, target_session_attrs)}, + {"trace_file", "PGTRACE", + NULL, NULL, + "Trace-File", "D", 64, + offsetof(struct pg_conn, trace_file_str)}, + + {"trace_flags", "PGTRACEFLAGS", NULL, NULL, + "Trace-Flags", "D", 1, + offsetof(struct pg_conn, trace_flags_str)}, + {"load_balance_hosts", "PGLOADBALANCEHOSTS", DefaultLoadBalanceHosts, NULL, "Load-Balance-Hosts", "", 8, /* sizeof("disable") = 8 */ @@ -1257,6 +1266,7 @@ bool pqConnectOptions2(PGconn *conn) { int i; + int trace_flags = 0; /* * Allocate memory for details about each host to which we might possibly @@ -2057,6 +2067,44 @@ pqConnectOptions2(PGconn *conn) conn->scram_client_key_len = len; } + /* + * If the connection already has a Pfdebug opened, use it + */ + if (conn->trace_file_str && !conn->Pfdebug) + { + if (strcmp(conn->trace_file_str, "-") == 0) + { + conn->trace_file = stdout; + } + + /* + * If the connection is created for a cancel request, and trace_file + * is not stdout, don't try to trace it as the source connection has + * already an opened fd on this trace file + */ + else if (!conn->cancelRequest) + { + conn->trace_file = fopen(conn->trace_file_str, "w"); + if (conn->trace_file == NULL) + { + libpq_append_conn_error(conn, "could not open trace file \"%s\": %m", conn->trace_file_str); + return false; + } + /* Make it line-buffered */ + setvbuf(conn->trace_file, NULL, PG_IOLBF, 0); + } + PQtrace(conn, conn->trace_file); + + if (conn->trace_flags_str) + { + if (!pqParseIntParam(conn->trace_flags_str, &trace_flags, conn, + "trace_flags")) + return false; + } + + PQsetTraceFlags(conn, trace_flags); + } + if (conn->scram_server_key) { int len; @@ -5043,6 +5091,7 @@ pqMakeEmptyPGconn(void) conn->sock = PGINVALID_SOCKET; conn->altsock = PGINVALID_SOCKET; conn->Pfdebug = NULL; + conn->trace_file = NULL; /* * We try to send at least 8K at a time, which is the usual size of pipe @@ -5164,7 +5213,21 @@ freePGconn(PGconn *conn) free(conn->oauth_client_secret); free(conn->oauth_ca_file); free(conn->oauth_scope); - /* Note that conn->Pfdebug is not ours to close or free */ + free(conn->trace_file_str); + free(conn->trace_flags_str); + + /* Untrace the connection to flush Pfdebug */ + PQuntrace(conn); + + /* + * Note that conn->Pfdebug is not ours to close or free if provided + * externally. However, if tracing was enabled through PGTRACE, we need to + * close conn->trace_file. + */ + if (conn->trace_file && conn->trace_file != stdout) + { + fclose(conn->trace_file); + } free(conn->events); pqReleaseConnHosts(conn); free(conn->connip); diff --git a/src/interfaces/libpq/libpq-int.h b/src/interfaces/libpq/libpq-int.h index 3f921207a14..8c926483b43 100644 --- a/src/interfaces/libpq/libpq-int.h +++ b/src/interfaces/libpq/libpq-int.h @@ -449,6 +449,10 @@ struct pg_conn char *oauth_ca_file; /* CA file path */ bool oauth_want_retry; /* should we retry on failure? */ + FILE *trace_file; + char *trace_file_str; + char *trace_flags_str; + /* Optional file to write trace info to */ FILE *Pfdebug; int traceFlags; -- 2.54.0 [application/octet-stream] v2-0005-Add-trace-of-startup-packets-in-libpq_pipeline-te.patch (17.6K, ../../CAO6_XqrFWe9W=iRCS+nqEN1UBTPnMWh=FEpVpOgjgac0BWYZLA@mail.gmail.com/4-v2-0005-Add-trace-of-startup-packets-in-libpq_pipeline-te.patch) download | inline diff: From 2d90df5f4f008e5b80de79fd56b5fcd126ca2525 Mon Sep 17 00:00:00 2001 From: Anthonin Bonnefoy <[email protected]> Date: Fri, 26 Jun 2026 14:32:00 +0200 Subject: Add trace of startup packets in libpq_pipeline tests The current way to enable tracing in libpq_pipeline only set PQtrace after the connection is created, missing the trace of the startup packets. This patch replaces it by the trace_file connection parameter, enabling PQtrace before the first packet is sent and thus tracing all protocol messages. --- .../modules/libpq_pipeline/libpq_pipeline.c | 32 +------------------ .../libpq_pipeline/t/001_libpq_pipeline.pl | 9 +++++- .../traces/disallowed_in_pipeline.trace | 24 ++++++++++++++ .../traces/multi_pipelines.trace | 24 ++++++++++++++ .../libpq_pipeline/traces/nosync.trace | 24 ++++++++++++++ .../traces/pipeline_abort.trace | 24 ++++++++++++++ .../libpq_pipeline/traces/pipeline_idle.trace | 24 ++++++++++++++ .../libpq_pipeline/traces/prepared.trace | 24 ++++++++++++++ .../traces/simple_pipeline.trace | 24 ++++++++++++++ .../libpq_pipeline/traces/singlerow.trace | 24 ++++++++++++++ .../libpq_pipeline/traces/transaction.trace | 24 ++++++++++++++ 11 files changed, 225 insertions(+), 32 deletions(-) diff --git a/src/test/modules/libpq_pipeline/libpq_pipeline.c b/src/test/modules/libpq_pipeline/libpq_pipeline.c index 1660a68955e..e7526e46d46 100644 --- a/src/test/modules/libpq_pipeline/libpq_pipeline.c +++ b/src/test/modules/libpq_pipeline/libpq_pipeline.c @@ -31,10 +31,6 @@ static bool process_result(PGconn *conn, PGresult *res, int results, static const char *const progname = "libpq_pipeline"; -/* Options and defaults */ -static char *tracefile = NULL; /* path to PQtrace() file */ - - #ifdef DEBUG_OUTPUT #define pg_debug(...) do { fprintf(stderr, __VA_ARGS__); } while (0) #else @@ -2109,7 +2105,6 @@ usage(const char *progname) fprintf(stderr, " %s [OPTION] tests\n", progname); fprintf(stderr, " %s [OPTION] TESTNAME [CONNINFO]\n", progname); fprintf(stderr, "\nOptions:\n"); - fprintf(stderr, " -t TRACEFILE generate a libpq trace to TRACEFILE\n"); fprintf(stderr, " -r NUMROWS use NUMROWS as the test size\n"); } @@ -2136,13 +2131,12 @@ main(int argc, char **argv) { const char *conninfo = ""; PGconn *conn; - FILE *trace = NULL; char *testname; int numrows = 10000; PGresult *res; int c; - while ((c = getopt(argc, argv, "r:t:")) != -1) + while ((c = getopt(argc, argv, "r:")) != -1) { switch (c) { @@ -2156,9 +2150,6 @@ main(int argc, char **argv) exit(1); } break; - case 't': /* trace file */ - tracefile = pg_strdup(optarg); - break; } } @@ -2203,24 +2194,6 @@ main(int argc, char **argv) pg_fatal("failed to set \"debug_parallel_query\": %s", PQerrorMessage(conn)); PQclear(res); - /* Set the trace file, if requested */ - if (tracefile != NULL) - { - if (strcmp(tracefile, "-") == 0) - trace = stdout; - else - trace = fopen(tracefile, "w"); - if (trace == NULL) - pg_fatal("could not open file \"%s\": %m", tracefile); - - /* Make it line-buffered */ - setvbuf(trace, NULL, PG_IOLBF, 0); - - PQtrace(conn, trace); - PQsetTraceFlags(conn, - PQTRACE_SUPPRESS_TIMESTAMPS | PQTRACE_REGRESS_MODE); - } - if (strcmp(testname, "cancel") == 0) test_cancel(conn); else if (strcmp(testname, "disallowed_in_pipeline") == 0) @@ -2256,8 +2229,5 @@ main(int argc, char **argv) /* close the connection to the database and cleanup */ PQfinish(conn); - if (trace && trace != stdout) - fclose(trace); - return 0; } diff --git a/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl b/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl index c74fda8aa37..76816d6c343 100644 --- a/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl +++ b/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl @@ -44,9 +44,16 @@ for my $testname (@tests) # For a bunch of tests, generate a libpq trace file too. my $traceout = "$PostgreSQL::Test::Utils::tmp_check/traces/$testname.trace"; + + local $ENV{PGTRACE}; + local $ENV{PGTRACEFLAGS}; if ($cmptrace) { - push @extraargs, "-t" => $traceout; + $ENV{PGTRACE} = $traceout; + # Set trace flags to PQTRACE_SUPPRESS_TIMESTAMPS | PQTRACE_REGRESS_MODE + $ENV{PGTRACEFLAGS} = 3; + } else { + delete $ENV{PGTRACE}; } # Execute the test using the latest protocol version. diff --git a/src/test/modules/libpq_pipeline/traces/disallowed_in_pipeline.trace b/src/test/modules/libpq_pipeline/traces/disallowed_in_pipeline.trace index dd6df03f1ed..1859e228cdb 100644 --- a/src/test/modules/libpq_pipeline/traces/disallowed_in_pipeline.trace +++ b/src/test/modules/libpq_pipeline/traces/disallowed_in_pipeline.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 13 Query "SELECT 1" B 33 RowDescription 1 "?column?" NNNN 0 NNNN 4 -1 0 B 11 DataRow 1 1 '1' diff --git a/src/test/modules/libpq_pipeline/traces/multi_pipelines.trace b/src/test/modules/libpq_pipeline/traces/multi_pipelines.trace index 1ee21f61dce..99b621bac21 100644 --- a/src/test/modules/libpq_pipeline/traces/multi_pipelines.trace +++ b/src/test/modules/libpq_pipeline/traces/multi_pipelines.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 21 Parse "" "SELECT $1" 1 NNNN F 19 Bind "" "" 0 1 1 '1' 1 0 F 6 Describe P "" diff --git a/src/test/modules/libpq_pipeline/traces/nosync.trace b/src/test/modules/libpq_pipeline/traces/nosync.trace index d99aac649db..f3ce2b1ed0b 100644 --- a/src/test/modules/libpq_pipeline/traces/nosync.trace +++ b/src/test/modules/libpq_pipeline/traces/nosync.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 34 Parse "" "SELECT repeat('xyzxz', 12)" 0 F 14 Bind "" "" 0 0 1 0 F 6 Describe P "" diff --git a/src/test/modules/libpq_pipeline/traces/pipeline_abort.trace b/src/test/modules/libpq_pipeline/traces/pipeline_abort.trace index 3e5007d13b2..5e27a6dbe2f 100644 --- a/src/test/modules/libpq_pipeline/traces/pipeline_abort.trace +++ b/src/test/modules/libpq_pipeline/traces/pipeline_abort.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 42 Query "DROP TABLE IF EXISTS pq_pipeline_demo" B NN NoticeResponse S "NOTICE" V "NOTICE" C "00000" M "table "pq_pipeline_demo" does not exist, skipping" F "SSSS" L "SSSS" R "SSSS" \x00 B 15 CommandComplete "DROP TABLE" diff --git a/src/test/modules/libpq_pipeline/traces/pipeline_idle.trace b/src/test/modules/libpq_pipeline/traces/pipeline_idle.trace index 83ee415b03e..4c5215c0096 100644 --- a/src/test/modules/libpq_pipeline/traces/pipeline_idle.trace +++ b/src/test/modules/libpq_pipeline/traces/pipeline_idle.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 16 Parse "" "SELECT 1" 0 F 14 Bind "" "" 0 0 1 0 F 6 Describe P "" diff --git a/src/test/modules/libpq_pipeline/traces/prepared.trace b/src/test/modules/libpq_pipeline/traces/prepared.trace index aeb5de109e0..3cd16969144 100644 --- a/src/test/modules/libpq_pipeline/traces/prepared.trace +++ b/src/test/modules/libpq_pipeline/traces/prepared.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 68 Parse "select_one" "SELECT $1, '42', $1::numeric, interval '1 sec'" 1 NNNN F 16 Describe S "select_one" F 4 Sync diff --git a/src/test/modules/libpq_pipeline/traces/simple_pipeline.trace b/src/test/modules/libpq_pipeline/traces/simple_pipeline.trace index 5c94749bc1e..4f38387f6ca 100644 --- a/src/test/modules/libpq_pipeline/traces/simple_pipeline.trace +++ b/src/test/modules/libpq_pipeline/traces/simple_pipeline.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 21 Parse "" "SELECT $1" 1 NNNN F 19 Bind "" "" 0 1 1 '1' 1 0 F 6 Describe P "" diff --git a/src/test/modules/libpq_pipeline/traces/singlerow.trace b/src/test/modules/libpq_pipeline/traces/singlerow.trace index 029cd66581d..d918d2aa896 100644 --- a/src/test/modules/libpq_pipeline/traces/singlerow.trace +++ b/src/test/modules/libpq_pipeline/traces/singlerow.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 38 Parse "" "SELECT generate_series(42, $1)" 0 F 20 Bind "" "" 0 1 2 '44' 1 0 F 6 Describe P "" diff --git a/src/test/modules/libpq_pipeline/traces/transaction.trace b/src/test/modules/libpq_pipeline/traces/transaction.trace index 1dcc2373c0b..9b79ae96237 100644 --- a/src/test/modules/libpq_pipeline/traces/transaction.trace +++ b/src/test/modules/libpq_pipeline/traces/transaction.trace @@ -1,3 +1,27 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I F 79 Query "DROP TABLE IF EXISTS pq_pipeline_tst;CREATE TABLE pq_pipeline_tst (id int)" B NN NoticeResponse S "NOTICE" V "NOTICE" C "00000" M "table "pq_pipeline_tst" does not exist, skipping" F "SSSS" L "SSSS" R "SSSS" \x00 B 15 CommandComplete "DROP TABLE" -- 2.54.0 [application/octet-stream] v2-0002-Add-more-regress-masks-in-pqtrace.patch (4.8K, ../../CAO6_XqrFWe9W=iRCS+nqEN1UBTPnMWh=FEpVpOgjgac0BWYZLA@mail.gmail.com/5-v2-0002-Add-more-regress-masks-in-pqtrace.patch) download | inline diff: From 7f36381318cbafaa97f43d88a13c3b67125bec79 Mon Sep 17 00:00:00 2001 From: Anthonin Bonnefoy <[email protected]> Date: Wed, 8 Jul 2026 10:19:22 +0200 Subject: Add more regress masks in pqtrace Tracing ParameterStatus or StartupMessage will write parameter values like username, which is very likely to change depending on the test environment. This patch adds additional regress masking, hiding the parameter values and the packet length of ParameterStatus and StartupMessage to allow tests to compare traces capturing such messages. Additionally, a "mismatched length" warning was added to pqTraceOutputNoTypeByteMessage, to mirror what's done in pqTraceOutputMessage. --- src/interfaces/libpq/fe-trace.c | 52 +++++++++++++++++++++++++-------- 1 file changed, 40 insertions(+), 12 deletions(-) diff --git a/src/interfaces/libpq/fe-trace.c b/src/interfaces/libpq/fe-trace.c index 741be09bdd3..e136c77e6b0 100644 --- a/src/interfaces/libpq/fe-trace.c +++ b/src/interfaces/libpq/fe-trace.c @@ -564,11 +564,11 @@ pqTraceOutput_Authentication(FILE *f, const char *message, int *cursor, } static void -pqTraceOutput_ParameterStatus(FILE *f, const char *message, int *cursor) +pqTraceOutput_ParameterStatus(FILE *f, const char *message, int *cursor, bool regress) { fprintf(f, "ParameterStatus\t"); pqTraceOutputString(f, message, cursor, false); - pqTraceOutputString(f, message, cursor, false); + pqTraceOutputString(f, message, cursor, regress); } static void @@ -673,12 +673,16 @@ pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer) logCursor += 4; /* - * In regress mode, suppress the length of ErrorResponse and - * NoticeResponse. The F (file name), L (line number) and R (routine + * In regress mode, suppress the length of ErrorResponse, NoticeResponse + * and ParameterStatus. The F (file name), L (line number) and R (routine * name) fields can change as server code is modified, and if their - * lengths differ from the originals, that would break tests. + * lengths differ from the originals, that would break tests. For + * ParameterStatus, the size changes depending on the parameters' value, + * whose values depend on the test environment. */ - if (regress && !toServer && (id == PqMsg_ErrorResponse || id == PqMsg_NoticeResponse)) + if (regress && !toServer && (id == PqMsg_ErrorResponse + || id == PqMsg_NoticeResponse + || id == PqMsg_ParameterStatus)) fprintf(conn->Pfdebug, "%s\tNN\t", prefix); else fprintf(conn->Pfdebug, "%s\t%d\t", prefix, length); @@ -820,7 +824,7 @@ pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer) if (toServer) fprintf(conn->Pfdebug, "Sync"); /* no message content */ else - pqTraceOutput_ParameterStatus(conn->Pfdebug, message, &logCursor); + pqTraceOutput_ParameterStatus(conn->Pfdebug, message, &logCursor, regress); break; case PqMsg_ParameterDescription: pqTraceOutput_ParameterDescription(conn->Pfdebug, message, &logCursor, regress); @@ -888,17 +892,27 @@ pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message) length = (int) pg_ntoh32(length); logCursor += 4; - fprintf(conn->Pfdebug, "F\t%d\t", length); - if (length < 8) { - fprintf(conn->Pfdebug, "Unknown message\n"); + fprintf(conn->Pfdebug, "F\t%d\tUnknown message\n", length); return; } memcpy(&version, message + logCursor, 4); version = (int) pg_ntoh32(version); + /* + * In regress, suppress the length of StartupMessage. The parameter values + * depend on the test environment, so the test may break depending on + * where it's executed. + */ + if (regress && (version != CANCEL_REQUEST_CODE + && version != NEGOTIATE_SSL_CODE + && version != NEGOTIATE_GSS_CODE)) + fprintf(conn->Pfdebug, "F\tNN\t"); + else + fprintf(conn->Pfdebug, "F\t%d\t", length); + if (version == CANCEL_REQUEST_CODE && length >= 16) { fprintf(conn->Pfdebug, "CancelRequest\t"); @@ -927,13 +941,27 @@ pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message) pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); while (message[logCursor] != '\0') { - /* XXX should we suppress anything in regress mode? */ - pqTraceOutputString(conn->Pfdebug, message, &logCursor, false); pqTraceOutputString(conn->Pfdebug, message, &logCursor, false); + pqTraceOutputString(conn->Pfdebug, message, &logCursor, regress); } + + /* + * Startup messages end with a trailing terminator, advance our cursor + * to include it + */ + logCursor++; } fputc('\n', conn->Pfdebug); + + /* + * Verify the printing routine did it right. There's no one-byte message + * identifier here, so logCursor should match the length + */ + if (logCursor != length) + fprintf(conn->Pfdebug, + "mismatched message length: consumed %d, expected %d\n", + logCursor, length); } /* -- 2.54.0 [application/octet-stream] v2-0003-Make-pqtrace-write-line-atomically.patch (38.7K, ../../CAO6_XqrFWe9W=iRCS+nqEN1UBTPnMWh=FEpVpOgjgac0BWYZLA@mail.gmail.com/6-v2-0003-Make-pqtrace-write-line-atomically.patch) download | inline diff: From 834363b5a3951fb8e641f3b2bac55d2b01ff84a2 Mon Sep 17 00:00:00 2001 From: Anthonin Bonnefoy <[email protected]> Date: Wed, 8 Jul 2026 08:39:07 +0200 Subject: Make pqtrace write line atomically Currently, pqtrace writes are done by doing multiple fprintf per line to the Pfdebug fd. This prevents multiple connections from writing on the same Pfdebug, as they may be writing on the same line at the same time. This commit changes fe-trace.c to buffer each line in a PQExpBuffer, and write a line in Pfdebug in a single fprintf. This will allow cancel connections to reuse the source connection's Pfdebug to trace the cancel request. --- src/interfaces/libpq/fe-trace.c | 513 +++++++++++++++++--------------- 1 file changed, 265 insertions(+), 248 deletions(-) diff --git a/src/interfaces/libpq/fe-trace.c b/src/interfaces/libpq/fe-trace.c index e136c77e6b0..eeda6bc3d85 100644 --- a/src/interfaces/libpq/fe-trace.c +++ b/src/interfaces/libpq/fe-trace.c @@ -104,7 +104,7 @@ pqTraceFormatTimestamp(char *timestr, size_t ts_len) * pqTraceOutputByte1: output a 1-char message to the log */ static void -pqTraceOutputByte1(FILE *pfdebug, const char *data, int *cursor) +pqTraceOutputByte1(PQExpBuffer buf, const char *data, int *cursor) { const char *v = data + *cursor; @@ -113,9 +113,9 @@ pqTraceOutputByte1(FILE *pfdebug, const char *data, int *cursor) * that completes ErrorResponse and NoticeResponse messages. */ if (!isprint((unsigned char) *v)) - fprintf(pfdebug, " \\x%02x", (unsigned char) *v); + appendPQExpBuffer(buf, " \\x%02x", (unsigned char) *v); else - fprintf(pfdebug, " %c", *v); + appendPQExpBuffer(buf, " %c", *v); *cursor += 1; } @@ -123,7 +123,7 @@ pqTraceOutputByte1(FILE *pfdebug, const char *data, int *cursor) * pqTraceOutputInt16: output a 2-byte integer message to the log */ static int -pqTraceOutputInt16(FILE *pfdebug, const char *data, int *cursor) +pqTraceOutputInt16(PQExpBuffer buf, const char *data, int *cursor) { uint16 tmp; int result; @@ -131,7 +131,7 @@ pqTraceOutputInt16(FILE *pfdebug, const char *data, int *cursor) memcpy(&tmp, data + *cursor, 2); *cursor += 2; result = (int) pg_ntoh16(tmp); - fprintf(pfdebug, " %d", result); + appendPQExpBuffer(buf, " %d", result); return result; } @@ -142,7 +142,7 @@ pqTraceOutputInt16(FILE *pfdebug, const char *data, int *cursor) * If 'suppress' is true, print a literal NNNN instead of the actual number. */ static int -pqTraceOutputInt32(FILE *pfdebug, const char *data, int *cursor, bool suppress) +pqTraceOutputInt32(PQExpBuffer buf, const char *data, int *cursor, bool suppress) { int result; @@ -150,9 +150,9 @@ pqTraceOutputInt32(FILE *pfdebug, const char *data, int *cursor, bool suppress) *cursor += 4; result = (int) pg_ntoh32(result); if (suppress) - fprintf(pfdebug, " NNNN"); + appendPQExpBufferStr(buf, " NNNN"); else - fprintf(pfdebug, " %d", result); + appendPQExpBuffer(buf, " %d", result); return result; } @@ -163,24 +163,21 @@ pqTraceOutputInt32(FILE *pfdebug, const char *data, int *cursor, bool suppress) * If 'suppress' is true, print a literal "SSSS" instead of the actual string. */ static void -pqTraceOutputString(FILE *pfdebug, const char *data, int *cursor, bool suppress) +pqTraceOutputString(PQExpBuffer buf, const char *data, int *cursor, bool suppress) { - int len; - if (suppress) { - fprintf(pfdebug, " \"SSSS\""); + appendPQExpBufferStr(buf, " \"SSSS\""); *cursor += strlen(data + *cursor) + 1; } else { - len = fprintf(pfdebug, " \"%s\"", data + *cursor); + appendPQExpBuffer(buf, " \"%s\"", data + *cursor); /* - * This is a null-terminated string. So add 1 after subtracting 3 - * which is the double quotes and space length from len. + * This is a null-terminated string. So add 1. */ - *cursor += (len - 3 + 1); + *cursor += strlen(data + *cursor) + 1; } } @@ -190,7 +187,7 @@ pqTraceOutputString(FILE *pfdebug, const char *data, int *cursor, bool suppress) * If 'suppress' is true, print a literal 'BBBB' instead of the actual bytes. */ static void -pqTraceOutputNchar(FILE *pfdebug, int len, const char *data, int *cursor, bool suppress) +pqTraceOutputNchar(PQExpBuffer buf, int len, const char *data, int *cursor, bool suppress) { int i, next; /* first char not yet printed */ @@ -198,12 +195,12 @@ pqTraceOutputNchar(FILE *pfdebug, int len, const char *data, int *cursor, bool s if (suppress) { - fprintf(pfdebug, " 'BBBB'"); + appendPQExpBufferStr(buf, " 'BBBB'"); *cursor += len; return; } - fprintf(pfdebug, " \'"); + appendPQExpBufferStr(buf, " \'"); for (next = i = 0; i < len; ++i) { @@ -211,15 +208,15 @@ pqTraceOutputNchar(FILE *pfdebug, int len, const char *data, int *cursor, bool s continue; else { - fwrite(v + next, 1, i - next, pfdebug); - fprintf(pfdebug, "\\x%02x", (unsigned char) v[i]); + appendBinaryPQExpBuffer(buf, v + next, i - next); + appendPQExpBuffer(buf, "\\x%02x", (unsigned char) v[i]); next = i + 1; } } if (next < len) - fwrite(v + next, 1, len - next, pfdebug); + appendBinaryPQExpBuffer(buf, v + next, len - next); - fprintf(pfdebug, "\'"); + appendPQExpBufferStr(buf, "\'"); *cursor += len; } @@ -229,24 +226,24 @@ pqTraceOutputNchar(FILE *pfdebug, int len, const char *data, int *cursor, bool s * If 'suppress' is true, print a literal 'BBBB' instead of the actual bytes. */ static void -pqTraceOutputNbyte(FILE *pfdebug, int len, const char *data, int *cursor, bool suppress) +pqTraceOutputNbyte(PQExpBuffer buf, int len, const char *data, int *cursor, bool suppress) { int i; const char *v = data + *cursor; if (suppress) { - fprintf(pfdebug, " 'BBBB'"); + appendPQExpBufferStr(buf, " 'BBBB'"); *cursor += len; return; } - fprintf(pfdebug, " \'"); + appendPQExpBufferStr(buf, " \'"); for (i = 0; i < len; ++i) - fprintf(pfdebug, "\\x%02x", (unsigned char) v[i]); + appendPQExpBuffer(buf, "\\x%02x", (unsigned char) v[i]); - fprintf(pfdebug, "\'"); + appendPQExpBufferStr(buf, "\'"); *cursor += len; } @@ -255,261 +252,261 @@ pqTraceOutputNbyte(FILE *pfdebug, int len, const char *data, int *cursor, bool s */ static void -pqTraceOutput_NotificationResponse(FILE *f, const char *message, int *cursor, bool regress) +pqTraceOutput_NotificationResponse(PQExpBuffer buf, const char *message, int *cursor, bool regress) { - fprintf(f, "NotificationResponse\t"); - pqTraceOutputInt32(f, message, cursor, regress); - pqTraceOutputString(f, message, cursor, false); - pqTraceOutputString(f, message, cursor, false); + appendPQExpBufferStr(buf, "NotificationResponse\t"); + pqTraceOutputInt32(buf, message, cursor, regress); + pqTraceOutputString(buf, message, cursor, false); + pqTraceOutputString(buf, message, cursor, false); } static void -pqTraceOutput_Bind(FILE *f, const char *message, int *cursor) +pqTraceOutput_Bind(PQExpBuffer buf, const char *message, int *cursor) { int nparams; - fprintf(f, "Bind\t"); - pqTraceOutputString(f, message, cursor, false); - pqTraceOutputString(f, message, cursor, false); - nparams = pqTraceOutputInt16(f, message, cursor); + appendPQExpBufferStr(buf, "Bind\t"); + pqTraceOutputString(buf, message, cursor, false); + pqTraceOutputString(buf, message, cursor, false); + nparams = pqTraceOutputInt16(buf, message, cursor); for (int i = 0; i < nparams; i++) - pqTraceOutputInt16(f, message, cursor); + pqTraceOutputInt16(buf, message, cursor); - nparams = pqTraceOutputInt16(f, message, cursor); + nparams = pqTraceOutputInt16(buf, message, cursor); for (int i = 0; i < nparams; i++) { int nbytes; - nbytes = pqTraceOutputInt32(f, message, cursor, false); + nbytes = pqTraceOutputInt32(buf, message, cursor, false); if (nbytes == -1) continue; - pqTraceOutputNchar(f, nbytes, message, cursor, false); + pqTraceOutputNchar(buf, nbytes, message, cursor, false); } - nparams = pqTraceOutputInt16(f, message, cursor); + nparams = pqTraceOutputInt16(buf, message, cursor); for (int i = 0; i < nparams; i++) - pqTraceOutputInt16(f, message, cursor); + pqTraceOutputInt16(buf, message, cursor); } static void -pqTraceOutput_Close(FILE *f, const char *message, int *cursor) +pqTraceOutput_Close(PQExpBuffer buf, const char *message, int *cursor) { - fprintf(f, "Close\t"); - pqTraceOutputByte1(f, message, cursor); - pqTraceOutputString(f, message, cursor, false); + appendPQExpBufferStr(buf, "Close\t"); + pqTraceOutputByte1(buf, message, cursor); + pqTraceOutputString(buf, message, cursor, false); } static void -pqTraceOutput_CommandComplete(FILE *f, const char *message, int *cursor) +pqTraceOutput_CommandComplete(PQExpBuffer buf, const char *message, int *cursor) { - fprintf(f, "CommandComplete\t"); - pqTraceOutputString(f, message, cursor, false); + appendPQExpBufferStr(buf, "CommandComplete\t"); + pqTraceOutputString(buf, message, cursor, false); } static void -pqTraceOutput_CopyData(FILE *f, const char *message, int *cursor, int length, +pqTraceOutput_CopyData(PQExpBuffer buf, const char *message, int *cursor, int length, bool suppress) { - fprintf(f, "CopyData\t"); - pqTraceOutputNchar(f, length - *cursor + 1, message, cursor, suppress); + appendPQExpBufferStr(buf, "CopyData\t"); + pqTraceOutputNchar(buf, length - *cursor + 1, message, cursor, suppress); } static void -pqTraceOutput_DataRow(FILE *f, const char *message, int *cursor) +pqTraceOutput_DataRow(PQExpBuffer buf, const char *message, int *cursor) { int nfields; int len; int i; - fprintf(f, "DataRow\t"); - nfields = pqTraceOutputInt16(f, message, cursor); + appendPQExpBufferStr(buf, "DataRow\t"); + nfields = pqTraceOutputInt16(buf, message, cursor); for (i = 0; i < nfields; i++) { - len = pqTraceOutputInt32(f, message, cursor, false); + len = pqTraceOutputInt32(buf, message, cursor, false); if (len == -1) continue; - pqTraceOutputNchar(f, len, message, cursor, false); + pqTraceOutputNchar(buf, len, message, cursor, false); } } static void -pqTraceOutput_Describe(FILE *f, const char *message, int *cursor) +pqTraceOutput_Describe(PQExpBuffer buf, const char *message, int *cursor) { - fprintf(f, "Describe\t"); - pqTraceOutputByte1(f, message, cursor); - pqTraceOutputString(f, message, cursor, false); + appendPQExpBufferStr(buf, "Describe\t"); + pqTraceOutputByte1(buf, message, cursor); + pqTraceOutputString(buf, message, cursor, false); } /* shared code NoticeResponse / ErrorResponse */ static void -pqTraceOutputNR(FILE *f, const char *type, const char *message, int *cursor, +pqTraceOutputNR(PQExpBuffer buf, const char *type, const char *message, int *cursor, bool regress) { - fprintf(f, "%s\t", type); + appendPQExpBuffer(buf, "%s\t", type); for (;;) { char field; bool suppress; - pqTraceOutputByte1(f, message, cursor); + pqTraceOutputByte1(buf, message, cursor); field = message[*cursor - 1]; if (field == '\0') break; suppress = regress && (field == 'L' || field == 'F' || field == 'R'); - pqTraceOutputString(f, message, cursor, suppress); + pqTraceOutputString(buf, message, cursor, suppress); } } static void -pqTraceOutput_ErrorResponse(FILE *f, const char *message, int *cursor, bool regress) +pqTraceOutput_ErrorResponse(PQExpBuffer buf, const char *message, int *cursor, bool regress) { - pqTraceOutputNR(f, "ErrorResponse", message, cursor, regress); + pqTraceOutputNR(buf, "ErrorResponse", message, cursor, regress); } static void -pqTraceOutput_NoticeResponse(FILE *f, const char *message, int *cursor, bool regress) +pqTraceOutput_NoticeResponse(PQExpBuffer buf, const char *message, int *cursor, bool regress) { - pqTraceOutputNR(f, "NoticeResponse", message, cursor, regress); + pqTraceOutputNR(buf, "NoticeResponse", message, cursor, regress); } static void -pqTraceOutput_Execute(FILE *f, const char *message, int *cursor, bool regress) +pqTraceOutput_Execute(PQExpBuffer buf, const char *message, int *cursor, bool regress) { - fprintf(f, "Execute\t"); - pqTraceOutputString(f, message, cursor, false); - pqTraceOutputInt32(f, message, cursor, false); + appendPQExpBufferStr(buf, "Execute\t"); + pqTraceOutputString(buf, message, cursor, false); + pqTraceOutputInt32(buf, message, cursor, false); } static void -pqTraceOutput_CopyFail(FILE *f, const char *message, int *cursor) +pqTraceOutput_CopyFail(PQExpBuffer buf, const char *message, int *cursor) { - fprintf(f, "CopyFail\t"); - pqTraceOutputString(f, message, cursor, false); + appendPQExpBufferStr(buf, "CopyFail\t"); + pqTraceOutputString(buf, message, cursor, false); } static void -pqTraceOutput_GSSResponse(FILE *f, const char *message, int *cursor, +pqTraceOutput_GSSResponse(PQExpBuffer buf, const char *message, int *cursor, int length, bool regress) { - fprintf(f, "GSSResponse\t"); - pqTraceOutputNchar(f, length - *cursor + 1, message, cursor, regress); + appendPQExpBufferStr(buf, "GSSResponse\t"); + pqTraceOutputNchar(buf, length - *cursor + 1, message, cursor, regress); } static void -pqTraceOutput_PasswordMessage(FILE *f, const char *message, int *cursor) +pqTraceOutput_PasswordMessage(PQExpBuffer buf, const char *message, int *cursor) { - fprintf(f, "PasswordMessage\t"); - pqTraceOutputString(f, message, cursor, false); + appendPQExpBufferStr(buf, "PasswordMessage\t"); + pqTraceOutputString(buf, message, cursor, false); } static void -pqTraceOutput_SASLInitialResponse(FILE *f, const char *message, int *cursor, +pqTraceOutput_SASLInitialResponse(PQExpBuffer buf, const char *message, int *cursor, bool regress) { int initialResponse; - fprintf(f, "SASLInitialResponse\t"); - pqTraceOutputString(f, message, cursor, false); - initialResponse = pqTraceOutputInt32(f, message, cursor, false); + appendPQExpBufferStr(buf, "SASLInitialResponse\t"); + pqTraceOutputString(buf, message, cursor, false); + initialResponse = pqTraceOutputInt32(buf, message, cursor, false); if (initialResponse != -1) - pqTraceOutputNchar(f, initialResponse, message, cursor, regress); + pqTraceOutputNchar(buf, initialResponse, message, cursor, regress); } static void -pqTraceOutput_SASLResponse(FILE *f, const char *message, int *cursor, +pqTraceOutput_SASLResponse(PQExpBuffer buf, const char *message, int *cursor, int length, bool regress) { - fprintf(f, "SASLResponse\t"); - pqTraceOutputNchar(f, length - *cursor + 1, message, cursor, regress); + appendPQExpBufferStr(buf, "SASLResponse\t"); + pqTraceOutputNchar(buf, length - *cursor + 1, message, cursor, regress); } static void -pqTraceOutput_FunctionCall(FILE *f, const char *message, int *cursor, bool regress) +pqTraceOutput_FunctionCall(PQExpBuffer buf, const char *message, int *cursor, bool regress) { int nfields; int nbytes; - fprintf(f, "FunctionCall\t"); - pqTraceOutputInt32(f, message, cursor, regress); - nfields = pqTraceOutputInt16(f, message, cursor); + appendPQExpBufferStr(buf, "FunctionCall\t"); + pqTraceOutputInt32(buf, message, cursor, regress); + nfields = pqTraceOutputInt16(buf, message, cursor); for (int i = 0; i < nfields; i++) - pqTraceOutputInt16(f, message, cursor); + pqTraceOutputInt16(buf, message, cursor); - nfields = pqTraceOutputInt16(f, message, cursor); + nfields = pqTraceOutputInt16(buf, message, cursor); for (int i = 0; i < nfields; i++) { - nbytes = pqTraceOutputInt32(f, message, cursor, false); + nbytes = pqTraceOutputInt32(buf, message, cursor, false); if (nbytes == -1) continue; - pqTraceOutputNchar(f, nbytes, message, cursor, false); + pqTraceOutputNchar(buf, nbytes, message, cursor, false); } - pqTraceOutputInt16(f, message, cursor); + pqTraceOutputInt16(buf, message, cursor); } static void -pqTraceOutput_CopyInResponse(FILE *f, const char *message, int *cursor) +pqTraceOutput_CopyInResponse(PQExpBuffer buf, const char *message, int *cursor) { int nfields; - fprintf(f, "CopyInResponse\t"); - pqTraceOutputByte1(f, message, cursor); - nfields = pqTraceOutputInt16(f, message, cursor); + appendPQExpBufferStr(buf, "CopyInResponse\t"); + pqTraceOutputByte1(buf, message, cursor); + nfields = pqTraceOutputInt16(buf, message, cursor); for (int i = 0; i < nfields; i++) - pqTraceOutputInt16(f, message, cursor); + pqTraceOutputInt16(buf, message, cursor); } static void -pqTraceOutput_CopyOutResponse(FILE *f, const char *message, int *cursor) +pqTraceOutput_CopyOutResponse(PQExpBuffer buf, const char *message, int *cursor) { int nfields; - fprintf(f, "CopyOutResponse\t"); - pqTraceOutputByte1(f, message, cursor); - nfields = pqTraceOutputInt16(f, message, cursor); + appendPQExpBufferStr(buf, "CopyOutResponse\t"); + pqTraceOutputByte1(buf, message, cursor); + nfields = pqTraceOutputInt16(buf, message, cursor); for (int i = 0; i < nfields; i++) - pqTraceOutputInt16(f, message, cursor); + pqTraceOutputInt16(buf, message, cursor); } static void -pqTraceOutput_BackendKeyData(FILE *f, const char *message, int *cursor, int length, +pqTraceOutput_BackendKeyData(PQExpBuffer buf, const char *message, int *cursor, int length, bool regress) { - fprintf(f, "BackendKeyData\t"); - pqTraceOutputInt32(f, message, cursor, regress); - pqTraceOutputNbyte(f, length - *cursor + 1, message, cursor, regress); + appendPQExpBufferStr(buf, "BackendKeyData\t"); + pqTraceOutputInt32(buf, message, cursor, regress); + pqTraceOutputNbyte(buf, length - *cursor + 1, message, cursor, regress); } static void -pqTraceOutput_Parse(FILE *f, const char *message, int *cursor, bool regress) +pqTraceOutput_Parse(PQExpBuffer buf, const char *message, int *cursor, bool regress) { int nparams; - fprintf(f, "Parse\t"); - pqTraceOutputString(f, message, cursor, false); - pqTraceOutputString(f, message, cursor, false); - nparams = pqTraceOutputInt16(f, message, cursor); + appendPQExpBufferStr(buf, "Parse\t"); + pqTraceOutputString(buf, message, cursor, false); + pqTraceOutputString(buf, message, cursor, false); + nparams = pqTraceOutputInt16(buf, message, cursor); for (int i = 0; i < nparams; i++) - pqTraceOutputInt32(f, message, cursor, regress); + pqTraceOutputInt32(buf, message, cursor, regress); } static void -pqTraceOutput_Query(FILE *f, const char *message, int *cursor) +pqTraceOutput_Query(PQExpBuffer buf, const char *message, int *cursor) { - fprintf(f, "Query\t"); - pqTraceOutputString(f, message, cursor, false); + appendPQExpBufferStr(buf, "Query\t"); + pqTraceOutputString(buf, message, cursor, false); } static void -pqTraceOutput_Authentication(FILE *f, const char *message, int *cursor, +pqTraceOutput_Authentication(PQExpBuffer buf, const char *message, int *cursor, int length, bool suppress) { int authType = 0; @@ -520,129 +517,129 @@ pqTraceOutput_Authentication(FILE *f, const char *message, int *cursor, switch (authType) { case AUTH_REQ_OK: - fprintf(f, "AuthenticationOk"); + appendPQExpBufferStr(buf, "AuthenticationOk"); break; /* AUTH_REQ_KRB4 not supported */ /* AUTH_REQ_KRB5 not supported */ case AUTH_REQ_PASSWORD: - fprintf(f, "AuthenticationCleartextPassword"); + appendPQExpBufferStr(buf, "AuthenticationCleartextPassword"); break; /* AUTH_REQ_CRYPT not supported */ case AUTH_REQ_MD5: - fprintf(f, "AuthenticationMD5Password"); + appendPQExpBufferStr(buf, "AuthenticationMD5Password"); break; case AUTH_REQ_GSS: - fprintf(f, "AuthenticationGSS"); + appendPQExpBufferStr(buf, "AuthenticationGSS"); break; case AUTH_REQ_GSS_CONT: - fprintf(f, "AuthenticationGSSContinue\t"); - pqTraceOutputNchar(f, length - *cursor + 1, message, cursor, + appendPQExpBufferStr(buf, "AuthenticationGSSContinue\t"); + pqTraceOutputNchar(buf, length - *cursor + 1, message, cursor, suppress); break; case AUTH_REQ_SSPI: - fprintf(f, "AuthenticationSSPI"); + appendPQExpBufferStr(buf, "AuthenticationSSPI"); break; case AUTH_REQ_SASL: - fprintf(f, "AuthenticationSASL\t"); + appendPQExpBufferStr(buf, "AuthenticationSASL\t"); while (message[*cursor] != '\0') - pqTraceOutputString(f, message, cursor, false); - pqTraceOutputString(f, message, cursor, false); + pqTraceOutputString(buf, message, cursor, false); + pqTraceOutputString(buf, message, cursor, false); break; case AUTH_REQ_SASL_CONT: - fprintf(f, "AuthenticationSASLContinue\t"); - pqTraceOutputNchar(f, length - *cursor + 1, message, cursor, + appendPQExpBufferStr(buf, "AuthenticationSASLContinue\t"); + pqTraceOutputNchar(buf, length - *cursor + 1, message, cursor, suppress); break; case AUTH_REQ_SASL_FIN: - fprintf(f, "AuthenticationSASLFinal\t"); - pqTraceOutputNchar(f, length - *cursor + 1, message, cursor, + appendPQExpBufferStr(buf, "AuthenticationSASLFinal\t"); + pqTraceOutputNchar(buf, length - *cursor + 1, message, cursor, suppress); break; default: - fprintf(f, "Unknown authentication message %d", authType); + appendPQExpBuffer(buf, "Unknown authentication message %d", authType); } } static void -pqTraceOutput_ParameterStatus(FILE *f, const char *message, int *cursor, bool regress) +pqTraceOutput_ParameterStatus(PQExpBuffer buf, const char *message, int *cursor, bool regress) { - fprintf(f, "ParameterStatus\t"); - pqTraceOutputString(f, message, cursor, false); - pqTraceOutputString(f, message, cursor, regress); + appendPQExpBufferStr(buf, "ParameterStatus\t"); + pqTraceOutputString(buf, message, cursor, false); + pqTraceOutputString(buf, message, cursor, regress); } static void -pqTraceOutput_ParameterDescription(FILE *f, const char *message, int *cursor, bool regress) +pqTraceOutput_ParameterDescription(PQExpBuffer buf, const char *message, int *cursor, bool regress) { int nfields; - fprintf(f, "ParameterDescription\t"); - nfields = pqTraceOutputInt16(f, message, cursor); + appendPQExpBufferStr(buf, "ParameterDescription\t"); + nfields = pqTraceOutputInt16(buf, message, cursor); for (int i = 0; i < nfields; i++) - pqTraceOutputInt32(f, message, cursor, regress); + pqTraceOutputInt32(buf, message, cursor, regress); } static void -pqTraceOutput_RowDescription(FILE *f, const char *message, int *cursor, bool regress) +pqTraceOutput_RowDescription(PQExpBuffer buf, const char *message, int *cursor, bool regress) { int nfields; - fprintf(f, "RowDescription\t"); - nfields = pqTraceOutputInt16(f, message, cursor); + appendPQExpBufferStr(buf, "RowDescription\t"); + nfields = pqTraceOutputInt16(buf, message, cursor); for (int i = 0; i < nfields; i++) { - pqTraceOutputString(f, message, cursor, false); - pqTraceOutputInt32(f, message, cursor, regress); - pqTraceOutputInt16(f, message, cursor); - pqTraceOutputInt32(f, message, cursor, regress); - pqTraceOutputInt16(f, message, cursor); - pqTraceOutputInt32(f, message, cursor, false); - pqTraceOutputInt16(f, message, cursor); + pqTraceOutputString(buf, message, cursor, false); + pqTraceOutputInt32(buf, message, cursor, regress); + pqTraceOutputInt16(buf, message, cursor); + pqTraceOutputInt32(buf, message, cursor, regress); + pqTraceOutputInt16(buf, message, cursor); + pqTraceOutputInt32(buf, message, cursor, false); + pqTraceOutputInt16(buf, message, cursor); } } static void -pqTraceOutput_NegotiateProtocolVersion(FILE *f, const char *message, int *cursor) +pqTraceOutput_NegotiateProtocolVersion(PQExpBuffer buf, const char *message, int *cursor) { int nparams; - fprintf(f, "NegotiateProtocolVersion\t"); - pqTraceOutputInt32(f, message, cursor, false); - nparams = pqTraceOutputInt32(f, message, cursor, false); + appendPQExpBufferStr(buf, "NegotiateProtocolVersion\t"); + pqTraceOutputInt32(buf, message, cursor, false); + nparams = pqTraceOutputInt32(buf, message, cursor, false); for (int i = 0; i < nparams; i++) { - pqTraceOutputString(f, message, cursor, false); + pqTraceOutputString(buf, message, cursor, false); } } static void -pqTraceOutput_FunctionCallResponse(FILE *f, const char *message, int *cursor) +pqTraceOutput_FunctionCallResponse(PQExpBuffer buf, const char *message, int *cursor) { int len; - fprintf(f, "FunctionCallResponse\t"); - len = pqTraceOutputInt32(f, message, cursor, false); + appendPQExpBufferStr(buf, "FunctionCallResponse\t"); + len = pqTraceOutputInt32(buf, message, cursor, false); if (len != -1) - pqTraceOutputNchar(f, len, message, cursor, false); + pqTraceOutputNchar(buf, len, message, cursor, false); } static void -pqTraceOutput_CopyBothResponse(FILE *f, const char *message, int *cursor, int length) +pqTraceOutput_CopyBothResponse(PQExpBuffer buf, const char *message, int *cursor, int length) { - fprintf(f, "CopyBothResponse\t"); - pqTraceOutputByte1(f, message, cursor); + appendPQExpBufferStr(buf, "CopyBothResponse\t"); + pqTraceOutputByte1(buf, message, cursor); while (length > *cursor) - pqTraceOutputInt16(f, message, cursor); + pqTraceOutputInt16(buf, message, cursor); } static void -pqTraceOutput_ReadyForQuery(FILE *f, const char *message, int *cursor) +pqTraceOutput_ReadyForQuery(PQExpBuffer buf, const char *message, int *cursor) { - fprintf(f, "ReadyForQuery\t"); - pqTraceOutputByte1(f, message, cursor); + appendPQExpBufferStr(buf, "ReadyForQuery\t"); + pqTraceOutputByte1(buf, message, cursor); } /* @@ -656,13 +653,16 @@ pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer) char *prefix = toServer ? "F" : "B"; int logCursor = 0; bool regress; + PQExpBufferData buf; + + initPQExpBuffer(&buf); if ((conn->traceFlags & PQTRACE_SUPPRESS_TIMESTAMPS) == 0) { char timestr[128]; pqTraceFormatTimestamp(timestr, sizeof(timestr)); - fprintf(conn->Pfdebug, "%s\t", timestr); + appendPQExpBuffer(&buf, "%s\t", timestr); } regress = (conn->traceFlags & PQTRACE_REGRESS_MODE) != 0; @@ -683,64 +683,64 @@ pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer) if (regress && !toServer && (id == PqMsg_ErrorResponse || id == PqMsg_NoticeResponse || id == PqMsg_ParameterStatus)) - fprintf(conn->Pfdebug, "%s\tNN\t", prefix); + appendPQExpBuffer(&buf, "%s\tNN\t", prefix); else - fprintf(conn->Pfdebug, "%s\t%d\t", prefix, length); + appendPQExpBuffer(&buf, "%s\t%d\t", prefix, length); switch (id) { case PqMsg_ParseComplete: - fprintf(conn->Pfdebug, "ParseComplete"); + appendPQExpBufferStr(&buf, "ParseComplete"); /* No message content */ break; case PqMsg_BindComplete: - fprintf(conn->Pfdebug, "BindComplete"); + appendPQExpBufferStr(&buf, "BindComplete"); /* No message content */ break; case PqMsg_CloseComplete: - fprintf(conn->Pfdebug, "CloseComplete"); + appendPQExpBufferStr(&buf, "CloseComplete"); /* No message content */ break; case PqMsg_NotificationResponse: - pqTraceOutput_NotificationResponse(conn->Pfdebug, message, &logCursor, regress); + pqTraceOutput_NotificationResponse(&buf, message, &logCursor, regress); break; case PqMsg_Bind: - pqTraceOutput_Bind(conn->Pfdebug, message, &logCursor); + pqTraceOutput_Bind(&buf, message, &logCursor); break; case PqMsg_CopyDone: - fprintf(conn->Pfdebug, "CopyDone"); + appendPQExpBufferStr(&buf, "CopyDone"); /* No message content */ break; case PqMsg_CommandComplete: /* Close(F) and CommandComplete(B) use the same identifier. */ Assert(PqMsg_Close == PqMsg_CommandComplete); if (toServer) - pqTraceOutput_Close(conn->Pfdebug, message, &logCursor); + pqTraceOutput_Close(&buf, message, &logCursor); else - pqTraceOutput_CommandComplete(conn->Pfdebug, message, &logCursor); + pqTraceOutput_CommandComplete(&buf, message, &logCursor); break; case PqMsg_CopyData: - pqTraceOutput_CopyData(conn->Pfdebug, message, &logCursor, + pqTraceOutput_CopyData(&buf, message, &logCursor, length, regress); break; case PqMsg_Describe: /* Describe(F) and DataRow(B) use the same identifier. */ Assert(PqMsg_Describe == PqMsg_DataRow); if (toServer) - pqTraceOutput_Describe(conn->Pfdebug, message, &logCursor); + pqTraceOutput_Describe(&buf, message, &logCursor); else - pqTraceOutput_DataRow(conn->Pfdebug, message, &logCursor); + pqTraceOutput_DataRow(&buf, message, &logCursor); break; case PqMsg_Execute: /* Execute(F) and ErrorResponse(B) use the same identifier. */ Assert(PqMsg_Execute == PqMsg_ErrorResponse); if (toServer) - pqTraceOutput_Execute(conn->Pfdebug, message, &logCursor, regress); + pqTraceOutput_Execute(&buf, message, &logCursor, regress); else - pqTraceOutput_ErrorResponse(conn->Pfdebug, message, &logCursor, regress); + pqTraceOutput_ErrorResponse(&buf, message, &logCursor, regress); break; case PqMsg_CopyFail: - pqTraceOutput_CopyFail(conn->Pfdebug, message, &logCursor); + pqTraceOutput_CopyFail(&buf, message, &logCursor); break; case PqMsg_GSSResponse: Assert(PqMsg_GSSResponse == PqMsg_PasswordMessage); @@ -754,106 +754,106 @@ pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer) switch (conn->current_auth_response) { case AUTH_RESPONSE_GSS: - pqTraceOutput_GSSResponse(conn->Pfdebug, message, + pqTraceOutput_GSSResponse(&buf, message, &logCursor, length, regress); break; case AUTH_RESPONSE_PASSWORD: - pqTraceOutput_PasswordMessage(conn->Pfdebug, message, + pqTraceOutput_PasswordMessage(&buf, message, &logCursor); break; case AUTH_RESPONSE_SASL_INITIAL: - pqTraceOutput_SASLInitialResponse(conn->Pfdebug, message, + pqTraceOutput_SASLInitialResponse(&buf, message, &logCursor, regress); break; case AUTH_RESPONSE_SASL: - pqTraceOutput_SASLResponse(conn->Pfdebug, message, + pqTraceOutput_SASLResponse(&buf, message, &logCursor, length, regress); break; default: - fprintf(conn->Pfdebug, "UnknownAuthenticationResponse"); + appendPQExpBufferStr(&buf, "UnknownAuthenticationResponse"); break; } conn->current_auth_response = '\0'; break; case PqMsg_FunctionCall: - pqTraceOutput_FunctionCall(conn->Pfdebug, message, &logCursor, regress); + pqTraceOutput_FunctionCall(&buf, message, &logCursor, regress); break; case PqMsg_CopyInResponse: - pqTraceOutput_CopyInResponse(conn->Pfdebug, message, &logCursor); + pqTraceOutput_CopyInResponse(&buf, message, &logCursor); break; case PqMsg_Flush: /* Flush(F) and CopyOutResponse(B) use the same identifier */ Assert(PqMsg_CopyOutResponse == PqMsg_Flush); if (toServer) - fprintf(conn->Pfdebug, "Flush"); /* no message content */ + appendPQExpBufferStr(&buf, "Flush"); /* no message content */ else - pqTraceOutput_CopyOutResponse(conn->Pfdebug, message, &logCursor); + pqTraceOutput_CopyOutResponse(&buf, message, &logCursor); break; case PqMsg_EmptyQueryResponse: - fprintf(conn->Pfdebug, "EmptyQueryResponse"); + appendPQExpBufferStr(&buf, "EmptyQueryResponse"); /* No message content */ break; case PqMsg_BackendKeyData: - pqTraceOutput_BackendKeyData(conn->Pfdebug, message, &logCursor, + pqTraceOutput_BackendKeyData(&buf, message, &logCursor, length, regress); break; case PqMsg_NoData: - fprintf(conn->Pfdebug, "NoData"); + appendPQExpBufferStr(&buf, "NoData"); /* No message content */ break; case PqMsg_NoticeResponse: - pqTraceOutput_NoticeResponse(conn->Pfdebug, message, &logCursor, regress); + pqTraceOutput_NoticeResponse(&buf, message, &logCursor, regress); break; case PqMsg_Parse: - pqTraceOutput_Parse(conn->Pfdebug, message, &logCursor, regress); + pqTraceOutput_Parse(&buf, message, &logCursor, regress); break; case PqMsg_Query: - pqTraceOutput_Query(conn->Pfdebug, message, &logCursor); + pqTraceOutput_Query(&buf, message, &logCursor); break; case PqMsg_AuthenticationRequest: - pqTraceOutput_Authentication(conn->Pfdebug, message, &logCursor, + pqTraceOutput_Authentication(&buf, message, &logCursor, length, regress); break; case PqMsg_PortalSuspended: - fprintf(conn->Pfdebug, "PortalSuspended"); + appendPQExpBufferStr(&buf, "PortalSuspended"); /* No message content */ break; case PqMsg_Sync: /* ParameterStatus(B) and Sync(F) use the same identifier */ Assert(PqMsg_ParameterStatus == PqMsg_Sync); if (toServer) - fprintf(conn->Pfdebug, "Sync"); /* no message content */ + appendPQExpBufferStr(&buf, "Sync"); /* no message content */ else - pqTraceOutput_ParameterStatus(conn->Pfdebug, message, &logCursor, regress); + pqTraceOutput_ParameterStatus(&buf, message, &logCursor, regress); break; case PqMsg_ParameterDescription: - pqTraceOutput_ParameterDescription(conn->Pfdebug, message, &logCursor, regress); + pqTraceOutput_ParameterDescription(&buf, message, &logCursor, regress); break; case PqMsg_RowDescription: - pqTraceOutput_RowDescription(conn->Pfdebug, message, &logCursor, regress); + pqTraceOutput_RowDescription(&buf, message, &logCursor, regress); break; case PqMsg_NegotiateProtocolVersion: - pqTraceOutput_NegotiateProtocolVersion(conn->Pfdebug, message, &logCursor); + pqTraceOutput_NegotiateProtocolVersion(&buf, message, &logCursor); break; case PqMsg_FunctionCallResponse: - pqTraceOutput_FunctionCallResponse(conn->Pfdebug, message, &logCursor); + pqTraceOutput_FunctionCallResponse(&buf, message, &logCursor); break; case PqMsg_CopyBothResponse: - pqTraceOutput_CopyBothResponse(conn->Pfdebug, message, &logCursor, length); + pqTraceOutput_CopyBothResponse(&buf, message, &logCursor, length); break; case PqMsg_Terminate: - fprintf(conn->Pfdebug, "Terminate"); + appendPQExpBufferStr(&buf, "Terminate"); /* No message content */ break; case PqMsg_ReadyForQuery: - pqTraceOutput_ReadyForQuery(conn->Pfdebug, message, &logCursor); + pqTraceOutput_ReadyForQuery(&buf, message, &logCursor); break; default: - fprintf(conn->Pfdebug, "Unknown message: %02x", id); + appendPQExpBuffer(&buf, "Unknown message: %02x", id); break; } - fputc('\n', conn->Pfdebug); + appendPQExpBufferChar(&buf, '\n'); /* * Verify the printing routine did it right. Note that the one-byte @@ -861,9 +861,12 @@ pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer) * include it. */ if (logCursor - 1 != length) - fprintf(conn->Pfdebug, - "mismatched message length: consumed %d, expected %d\n", - logCursor - 1, length); + appendPQExpBuffer(&buf, + "mismatched message length: consumed %d, expected %d\n", + logCursor - 1, length); + + fprintf(conn->Pfdebug, "%s", buf.data); + termPQExpBuffer(&buf); } /* @@ -877,7 +880,9 @@ pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message) int version; bool regress; int logCursor = 0; + PQExpBufferData buf; + initPQExpBuffer(&buf); regress = (conn->traceFlags & PQTRACE_REGRESS_MODE) != 0; if ((conn->traceFlags & PQTRACE_SUPPRESS_TIMESTAMPS) == 0) @@ -885,7 +890,7 @@ pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message) char timestr[128]; pqTraceFormatTimestamp(timestr, sizeof(timestr)); - fprintf(conn->Pfdebug, "%s\t", timestr); + appendPQExpBuffer(&buf, "%s\t", timestr); } memcpy(&length, message + logCursor, 4); @@ -894,7 +899,9 @@ pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message) if (length < 8) { - fprintf(conn->Pfdebug, "F\t%d\tUnknown message\n", length); + appendPQExpBuffer(&buf, "F\t%d\tUnknown message\n", length); + fprintf(conn->Pfdebug, "%s", buf.data); + termPQExpBuffer(&buf); return; } @@ -909,40 +916,40 @@ pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message) if (regress && (version != CANCEL_REQUEST_CODE && version != NEGOTIATE_SSL_CODE && version != NEGOTIATE_GSS_CODE)) - fprintf(conn->Pfdebug, "F\tNN\t"); + appendPQExpBufferStr(&buf, "F\tNN\t"); else - fprintf(conn->Pfdebug, "F\t%d\t", length); + appendPQExpBuffer(&buf, "F\t%d\t", length); if (version == CANCEL_REQUEST_CODE && length >= 16) { - fprintf(conn->Pfdebug, "CancelRequest\t"); - pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); - pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); - pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, regress); - pqTraceOutputNbyte(conn->Pfdebug, length - logCursor, message, + appendPQExpBufferStr(&buf, "CancelRequest\t"); + pqTraceOutputInt16(&buf, message, &logCursor); + pqTraceOutputInt16(&buf, message, &logCursor); + pqTraceOutputInt32(&buf, message, &logCursor, regress); + pqTraceOutputNbyte(&buf, length - logCursor, message, &logCursor, regress); } else if (version == NEGOTIATE_SSL_CODE) { - fprintf(conn->Pfdebug, "SSLRequest\t"); - pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); - pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); + appendPQExpBufferStr(&buf, "SSLRequest\t"); + pqTraceOutputInt16(&buf, message, &logCursor); + pqTraceOutputInt16(&buf, message, &logCursor); } else if (version == NEGOTIATE_GSS_CODE) { - fprintf(conn->Pfdebug, "GSSENCRequest\t"); - pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); - pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); + appendPQExpBufferStr(&buf, "GSSENCRequest\t"); + pqTraceOutputInt16(&buf, message, &logCursor); + pqTraceOutputInt16(&buf, message, &logCursor); } else { - fprintf(conn->Pfdebug, "StartupMessage\t"); - pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); - pqTraceOutputInt16(conn->Pfdebug, message, &logCursor); + appendPQExpBufferStr(&buf, "StartupMessage\t"); + pqTraceOutputInt16(&buf, message, &logCursor); + pqTraceOutputInt16(&buf, message, &logCursor); while (message[logCursor] != '\0') { - pqTraceOutputString(conn->Pfdebug, message, &logCursor, false); - pqTraceOutputString(conn->Pfdebug, message, &logCursor, regress); + pqTraceOutputString(&buf, message, &logCursor, false); + pqTraceOutputString(&buf, message, &logCursor, regress); } /* @@ -952,16 +959,19 @@ pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message) logCursor++; } - fputc('\n', conn->Pfdebug); + appendPQExpBufferChar(&buf, '\n'); /* * Verify the printing routine did it right. There's no one-byte message * identifier here, so logCursor should match the length */ if (logCursor != length) - fprintf(conn->Pfdebug, - "mismatched message length: consumed %d, expected %d\n", - logCursor, length); + appendPQExpBuffer(&buf, + "mismatched message length: consumed %d, expected %d\n", + logCursor, length); + + fprintf(conn->Pfdebug, "%s", buf.data); + termPQExpBuffer(&buf); } /* @@ -973,13 +983,20 @@ void pqTraceOutputCharResponse(PGconn *conn, const char *responseType, char response) { + PQExpBufferData buf; + + initPQExpBuffer(&buf); + if ((conn->traceFlags & PQTRACE_SUPPRESS_TIMESTAMPS) == 0) { char timestr[128]; pqTraceFormatTimestamp(timestr, sizeof(timestr)); - fprintf(conn->Pfdebug, "%s\t", timestr); + appendPQExpBuffer(&buf, "%s\t", timestr); } - fprintf(conn->Pfdebug, "B\t1\t%s\t %c\n", responseType, response); + appendPQExpBuffer(&buf, "B\t1\t%s\t %c\n", responseType, response); + + fprintf(conn->Pfdebug, "%s", buf.data); + termPQExpBuffer(&buf); } -- 2.54.0 [application/octet-stream] v2-0006-Test-trace-of-cancel-requests.patch (6.2K, ../../CAO6_XqrFWe9W=iRCS+nqEN1UBTPnMWh=FEpVpOgjgac0BWYZLA@mail.gmail.com/7-v2-0006-Test-trace-of-cancel-requests.patch) download | inline diff: From 22c8aa2583a63340402934522009b8586a9b94cc Mon Sep 17 00:00:00 2001 From: Anthonin Bonnefoy <[email protected]> Date: Wed, 8 Jul 2026 14:26:58 +0200 Subject: Test trace of cancel requests Enable trace for cancel test of libpq_pipeline. Cancel requests generated with PQcancel are not traced as the signal-safe function doesn't use the normal message construction functions. --- .../modules/libpq_pipeline/libpq_pipeline.c | 17 +++- .../libpq_pipeline/t/001_libpq_pipeline.pl | 2 +- .../libpq_pipeline/traces/cancel.trace | 88 +++++++++++++++++++ 3 files changed, 105 insertions(+), 2 deletions(-) create mode 100644 src/test/modules/libpq_pipeline/traces/cancel.trace diff --git a/src/test/modules/libpq_pipeline/libpq_pipeline.c b/src/test/modules/libpq_pipeline/libpq_pipeline.c index e7526e46d46..9448bde9328 100644 --- a/src/test/modules/libpq_pipeline/libpq_pipeline.c +++ b/src/test/modules/libpq_pipeline/libpq_pipeline.c @@ -264,6 +264,12 @@ copy_connection(PGconn *conn) { if (opt->val) { + /* + * We don't want the copied connection to have tracing enabled, so + * skip the trace_file parameter + */ + if (strcmp(opt->keyword, "trace_file") == 0) + continue; keywords[i] = opt->keyword; vals[i] = opt->val; i++; @@ -294,6 +300,7 @@ test_cancel(PGconn *conn) PGcancelConn *cancelConn; PGconn *monitorConn; char errorbuf[256]; + char *pgtrace; fprintf(stderr, "test cancellations... "); @@ -302,10 +309,18 @@ test_cancel(PGconn *conn) /* * Make a separate connection to the database to monitor the query on the - * main connection. + * main connection. Tracing needs to be disabled for this connection. */ + pgtrace = getenv("PGTRACE"); + if (pgtrace != NULL) + { + pgtrace = pg_strdup(pgtrace); + unsetenv("PGTRACE"); + } monitorConn = copy_connection(conn); Assert(PQstatus(monitorConn) == CONNECTION_OK); + if (pgtrace != NULL) + setenv("PGTRACE", pgtrace, 1); /* test PQcancel */ send_cancellable_query(conn, monitorConn); diff --git a/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl b/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl index 76816d6c343..8ae4a3aea2b 100644 --- a/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl +++ b/src/test/modules/libpq_pipeline/t/001_libpq_pipeline.pl @@ -39,7 +39,7 @@ for my $testname (@tests) my $cmptrace = grep(/^$testname$/, qw(simple_pipeline nosync multi_pipelines prepared singlerow pipeline_abort pipeline_idle transaction - disallowed_in_pipeline)) > 0; + disallowed_in_pipeline cancel)) > 0; # For a bunch of tests, generate a libpq trace file too. my $traceout = diff --git a/src/test/modules/libpq_pipeline/traces/cancel.trace b/src/test/modules/libpq_pipeline/traces/cancel.trace new file mode 100644 index 00000000000..829ca7c192e --- /dev/null +++ b/src/test/modules/libpq_pipeline/traces/cancel.trace @@ -0,0 +1,88 @@ +F NN StartupMessage 3 2 "user" "SSSS" "database" "SSSS" "application_name" "SSSS" +B NN ParameterStatus "IntervalStyle" "SSSS" +B NN ParameterStatus "search_path" "SSSS" +B NN ParameterStatus "is_superuser" "SSSS" +B NN ParameterStatus "standard_conforming_strings" "SSSS" +B NN ParameterStatus "session_authorization" "SSSS" +B NN ParameterStatus "client_encoding" "SSSS" +B NN ParameterStatus "server_version" "SSSS" +B NN ParameterStatus "server_encoding" "SSSS" +B NN ParameterStatus "in_hot_standby" "SSSS" +B NN ParameterStatus "integer_datetimes" "SSSS" +B NN ParameterStatus "TimeZone" "SSSS" +B NN ParameterStatus "application_name" "SSSS" +B NN ParameterStatus "default_transaction_read_only" "SSSS" +B NN ParameterStatus "scram_iterations" "SSSS" +B NN ParameterStatus "DateStyle" "SSSS" +B 40 BackendKeyData NNNN 'BBBB' +B 5 ReadyForQuery I +F 27 Query "SET lc_messages TO "C"" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 35 Query "SET debug_parallel_query = off" +B 8 CommandComplete "SET" +B 5 ReadyForQuery I +F 31 Parse "" "SELECT pg_sleep($1)" 1 NNNN +F 21 Bind "" "" 0 1 3 '180' 1 0 +F 6 Describe P "" +F 9 Execute "" 0 +F 4 Sync +B 4 ParseComplete +B 4 BindComplete +B 33 RowDescription 1 "pg_sleep" NNNN 0 NNNN 4 -1 0 +B NN ErrorResponse S "ERROR" V "ERROR" C "57014" M "canceling statement due to user request" F "SSSS" L "SSSS" R "SSSS" \x00 +B 5 ReadyForQuery I +F 31 Parse "" "SELECT pg_sleep($1)" 1 NNNN +F 21 Bind "" "" 0 1 3 '180' 1 0 +F 6 Describe P "" +F 9 Execute "" 0 +F 4 Sync +B 4 ParseComplete +B 4 BindComplete +B 33 RowDescription 1 "pg_sleep" NNNN 0 NNNN 4 -1 0 +B NN ErrorResponse S "ERROR" V "ERROR" C "57014" M "canceling statement due to user request" F "SSSS" L "SSSS" R "SSSS" \x00 +B 5 ReadyForQuery I +F 31 Parse "" "SELECT pg_sleep($1)" 1 NNNN +F 21 Bind "" "" 0 1 3 '180' 1 0 +F 6 Describe P "" +F 9 Execute "" 0 +F 4 Sync +B 4 ParseComplete +B 4 BindComplete +B 33 RowDescription 1 "pg_sleep" NNNN 0 NNNN 4 -1 0 +B NN ErrorResponse S "ERROR" V "ERROR" C "57014" M "canceling statement due to user request" F "SSSS" L "SSSS" R "SSSS" \x00 +B 5 ReadyForQuery I +F 31 Parse "" "SELECT pg_sleep($1)" 1 NNNN +F 21 Bind "" "" 0 1 3 '180' 1 0 +F 6 Describe P "" +F 9 Execute "" 0 +F 4 Sync +F 44 CancelRequest 1234 5678 NNNN 'BBBB' +B 4 ParseComplete +B 4 BindComplete +B 33 RowDescription 1 "pg_sleep" NNNN 0 NNNN 4 -1 0 +B NN ErrorResponse S "ERROR" V "ERROR" C "57014" M "canceling statement due to user request" F "SSSS" L "SSSS" R "SSSS" \x00 +B 5 ReadyForQuery I +F 31 Parse "" "SELECT pg_sleep($1)" 1 NNNN +F 21 Bind "" "" 0 1 3 '180' 1 0 +F 6 Describe P "" +F 9 Execute "" 0 +F 4 Sync +F 44 CancelRequest 1234 5678 NNNN 'BBBB' +B 4 ParseComplete +B 4 BindComplete +B 33 RowDescription 1 "pg_sleep" NNNN 0 NNNN 4 -1 0 +B NN ErrorResponse S "ERROR" V "ERROR" C "57014" M "canceling statement due to user request" F "SSSS" L "SSSS" R "SSSS" \x00 +B 5 ReadyForQuery I +F 31 Parse "" "SELECT pg_sleep($1)" 1 NNNN +F 21 Bind "" "" 0 1 3 '180' 1 0 +F 6 Describe P "" +F 9 Execute "" 0 +F 4 Sync +F 44 CancelRequest 1234 5678 NNNN 'BBBB' +B 4 ParseComplete +B 4 BindComplete +B 33 RowDescription 1 "pg_sleep" NNNN 0 NNNN 4 -1 0 +B NN ErrorResponse S "ERROR" V "ERROR" C "57014" M "canceling statement due to user request" F "SSSS" L "SSSS" R "SSSS" \x00 +B 5 ReadyForQuery I +F 4 Terminate -- 2.54.0 ^ permalink raw reply [nested|flat] 3+ messages in thread
end of thread, other threads:[~2026-07-08 15:38 UTC | newest] Thread overview: 3+ messages (download: mbox mbox.gz follow: Atom feed) -- links below jump to the message on this page -- 2026-07-03 09:42 Fix tracing of BackendKeyData and CancelRequest messages Anthonin Bonnefoy <[email protected]> 2026-07-03 12:10 ` Heikki Linnakangas <[email protected]> 2026-07-08 15:38 ` Anthonin Bonnefoy <[email protected]>
This inbox is served by agora; see mirroring instructions for how to clone and mirror all data and code used for this inbox