While working on my patchset for protocol changes I realized that the StartupMessage/SSLRequest/GSSENCRequest was not shown correctly in the tracing output of libpq. With this change these messages are now shown correctly in the tracing output.
To test you can add a PQreset(conn) call to the start of the test_cancel function in src/test/modules/libpq_pipeline/libpq_pipeline.c. And then run: ninja -C build all install-quiet && build/src/test/modules/libpq_pipeline/libpq_pipeline cancel 'port=5432' -t test.trace And then look at the top of test.trace
From 6fe11a1656e3bc85608e3d883848e42cd765e553 Mon Sep 17 00:00:00 2001 From: Jelte Fennema-Nio <jelte.fennema@microsoft.com> Date: Wed, 5 Jun 2024 12:07:09 +0200 Subject: [PATCH v1] libpq: Trace StartupMessage/SSLRequest/GSSENCRequest correctly These messages would previously be logged in the tracing output as: Unknown message: length %d With this commit their type and contents are now correctly listed. --- src/interfaces/libpq/fe-trace.c | 47 ++++++++++++++++++++++++--------- 1 file changed, 35 insertions(+), 12 deletions(-) diff --git a/src/interfaces/libpq/fe-trace.c b/src/interfaces/libpq/fe-trace.c index d7a61ec9cc1..cb9648e5ceb 100644 --- a/src/interfaces/libpq/fe-trace.c +++ b/src/interfaces/libpq/fe-trace.c @@ -697,6 +697,7 @@ pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message) { int length; int logCursor = 0; + int version = 0; if ((conn->traceFlags & PQTRACE_SUPPRESS_TIMESTAMPS) == 0) { @@ -712,19 +713,41 @@ pqTraceOutputNoTypeByteMessage(PGconn *conn, const char *message) fprintf(conn->Pfdebug, "F\t%d\t", length); - switch (length) + if (length < 8) { - case 16: /* CancelRequest */ - fprintf(conn->Pfdebug, "CancelRequest\t"); - pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, false); - pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, false); - pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, false); - break; - case 8: /* GSSENCRequest or SSLRequest */ - /* These messages do not reach here. */ - default: - fprintf(conn->Pfdebug, "Unknown message: length is %d", length); - break; + fprintf(conn->Pfdebug, "Unknown message: length is %d\n", length); + return; + } + + memcpy(&version, message + logCursor, 4); + version = (int) pg_ntoh32(version); + + if (version == CANCEL_REQUEST_CODE) + { + fprintf(conn->Pfdebug, "CancelRequest\t"); + pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, false); + pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, false); + pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, false); + } + else if (version == NEGOTIATE_SSL_CODE) + { + fprintf(conn->Pfdebug, "SSLRequest\t"); + pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, false); + } + else if (version == NEGOTIATE_GSS_CODE) + { + fprintf(conn->Pfdebug, "GSSENCRequest\t"); + pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, false); + } + else + { + fprintf(conn->Pfdebug, "StartupMessage\t"); + pqTraceOutputInt32(conn->Pfdebug, message, &logCursor, false); + while (message[logCursor] != '\0') + { + pqTraceOutputString(conn->Pfdebug, message, &logCursor, false); + pqTraceOutputString(conn->Pfdebug, message, &logCursor, false); + } } fputc('\n', conn->Pfdebug); base-commit: 7b71e5bbccd6c86bc12ba0124e7282cfb3aa3226 -- 2.34.1