From a874cf35382c5c40db914e4500f3755f61fa29d1 Mon Sep 17 00:00:00 2001 From: Jelte Fennema-Nio Date: Thu, 13 Jun 2024 19:35:43 +0200 Subject: [PATCH v3 6/8] libpq: Trace all messages received from the server Not all messages that libpq received from the server would be sent through our message tracing logic. This fixes that by introducing pqParseDone which makes it a lot harder to forget about doing so. The messages that we now newly send through our tracing logic are: - CopyData (received by COPY TO STDOUT) - Authentication requests - NegotiateProtocolVersion - Some ErrorResponse messages during connection startup - ReadyForQuery when received after a FunctionCall message Author: Jelte Fennema-Nio Discussion: https://postgr.es/m/CAGECzQSoPHtZ4xe0raJ6FYSEiPPS+YWXBhOGo+Y1YecLgknF3g@mail.gmail.com --- src/interfaces/libpq/fe-auth.c | 21 +++++++++++++++++++++ src/interfaces/libpq/fe-connect.c | 13 +++++++++---- src/interfaces/libpq/fe-misc.c | 15 +++++++++++++++ src/interfaces/libpq/fe-protocol3.c | 29 +++++++---------------------- src/interfaces/libpq/libpq-int.h | 1 + 5 files changed, 53 insertions(+), 26 deletions(-) diff --git a/src/interfaces/libpq/fe-auth.c b/src/interfaces/libpq/fe-auth.c index 4da07c1f98..5c8f404463 100644 --- a/src/interfaces/libpq/fe-auth.c +++ b/src/interfaces/libpq/fe-auth.c @@ -94,6 +94,10 @@ pg_GSS_continue(PGconn *conn, int payloadlen) ginbuf.value = NULL; } + /* finished parsing, trace server-to-client message */ + if (conn->Pfdebug) + pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false); + /* Only try to acquire credentials if GSS delegation isn't disabled. */ if (!pg_GSS_have_cred_cache(&conn->gcred)) conn->gcred = GSS_C_NO_CREDENTIAL; @@ -258,6 +262,10 @@ pg_SSPI_continue(PGconn *conn, int payloadlen) InBuffers[0].BufferType = SECBUFFER_TOKEN; } + /* finished parsing, trace server-to-client message */ + if (conn->Pfdebug) + pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false); + OutBuffers[0].pvBuffer = NULL; OutBuffers[0].BufferType = SECBUFFER_TOKEN; OutBuffers[0].cbBuffer = 0; @@ -563,6 +571,10 @@ pg_SASL_init(PGconn *conn, int payloadlen) } } + /* finished parsing, trace server-to-client message */ + if (conn->Pfdebug) + pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false); + Assert(conn->sasl); /* @@ -651,6 +663,11 @@ pg_SASL_continue(PGconn *conn, int payloadlen, bool final) free(challenge); return STATUS_ERROR; } + + /* finished parsing, trace server-to-client message */ + if (conn->Pfdebug) + pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false); + /* For safety and convenience, ensure the buffer is NULL-terminated. */ challenge[payloadlen] = '\0'; @@ -716,6 +733,10 @@ pg_password_sendauth(PGconn *conn, const char *password, AuthRequest areq) return STATUS_ERROR; /* shouldn't happen */ } + /* finished parsing, trace server-to-client message */ + if (conn->Pfdebug) + pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false); + /* Encrypt the password if needed. */ switch (areq) diff --git a/src/interfaces/libpq/fe-connect.c b/src/interfaces/libpq/fe-connect.c index f7ece66b69..6d110a605c 100644 --- a/src/interfaces/libpq/fe-connect.c +++ b/src/interfaces/libpq/fe-connect.c @@ -3799,7 +3799,7 @@ keep_going: /* We will come back to here until there is return PGRES_POLLING_READING; } /* OK, we read the message; mark data consumed */ - conn->inStart = conn->inCursor; + pqParseDone(conn, conn->inCursor); /* * Before 7.2, the postmaster didn't always end its @@ -3849,7 +3849,7 @@ keep_going: /* We will come back to here until there is goto error_return; } /* OK, we read the message; mark data consumed */ - conn->inStart = conn->inCursor; + pqParseDone(conn, conn->inCursor); /* * If error is "cannot connect now", try the next host if @@ -3878,7 +3878,7 @@ keep_going: /* We will come back to here until there is goto error_return; } /* OK, we read the message; mark data consumed */ - conn->inStart = conn->inCursor; + pqParseDone(conn, conn->inCursor); goto error_return; } @@ -3903,7 +3903,12 @@ keep_going: /* We will come back to here until there is */ res = pg_fe_sendauth(areq, msgLength, conn); - /* OK, we have processed the message; mark data consumed */ + /* + * OK, we have processed the message; mark data consumed. We + * don't call pqParseDone here because we already traced this + * message inside pg_fe_sendauth (since we need to trace it + * before sending the response). + */ conn->inStart = conn->inCursor; if (res != STATUS_OK) diff --git a/src/interfaces/libpq/fe-misc.c b/src/interfaces/libpq/fe-misc.c index f235bfbb41..928a47162d 100644 --- a/src/interfaces/libpq/fe-misc.c +++ b/src/interfaces/libpq/fe-misc.c @@ -435,6 +435,21 @@ pqCheckInBufferSpace(size_t bytes_needed, PGconn *conn) return EOF; } +/* + * pqParseDone: after a server-to-client message has successfully + * been parsed, advance conn->inStart to account for it. + */ +void +pqParseDone(PGconn *conn, int newInStart) +{ + /* trace server-to-client message */ + if (conn->Pfdebug) + pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false); + + /* Mark message as done */ + conn->inStart = newInStart; +} + /* * pqPutMsgStart: begin construction of a message to the server * diff --git a/src/interfaces/libpq/fe-protocol3.c b/src/interfaces/libpq/fe-protocol3.c index 3170d484f0..5d88777e9d 100644 --- a/src/interfaces/libpq/fe-protocol3.c +++ b/src/interfaces/libpq/fe-protocol3.c @@ -454,12 +454,8 @@ pqParseInput3(PGconn *conn) /* Successfully consumed this message */ if (conn->inCursor == conn->inStart + 5 + msgLength) { - /* trace server-to-client message */ - if (conn->Pfdebug) - pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false); - /* Normal case: parsing agrees with specified length */ - conn->inStart = conn->inCursor; + pqParseDone(conn, conn->inCursor); } else { @@ -1728,12 +1724,7 @@ getCopyDataMessage(PGconn *conn) return -1; } - /* trace server-to-client message */ - if (conn->Pfdebug) - pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false); - - /* Drop the processed message and loop around for another */ - conn->inStart = conn->inCursor; + pqParseDone(conn, conn->inCursor); } } @@ -1791,13 +1782,13 @@ pqGetCopyData3(PGconn *conn, char **buffer, int async) (*buffer)[msgLength] = '\0'; /* Add terminating null */ /* Mark message consumed */ - conn->inStart = conn->inCursor + msgLength; + pqParseDone(conn, conn->inCursor + msgLength); return msgLength; } /* Empty, so drop it and loop around for another */ - conn->inStart = conn->inCursor; + pqParseDone(conn, conn->inCursor); } } @@ -2168,8 +2159,8 @@ pqFunctionCall3(PGconn *conn, Oid fnid, case 'Z': /* backend is ready for new query */ if (getReadyForQuery(conn)) continue; - /* consume the message and exit */ - conn->inStart += 5 + msgLength; + + pqParseDone(conn, conn->inStart + 5 + msgLength); /* * If we already have a result object (probably an error), use @@ -2208,13 +2199,7 @@ pqFunctionCall3(PGconn *conn, Oid fnid, return pqPrepareAsyncResult(conn); } - /* trace server-to-client message */ - if (conn->Pfdebug) - pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false); - - /* Completed this message, keep going */ - /* trust the specified message length as what to skip */ - conn->inStart += 5 + msgLength; + pqParseDone(conn, conn->inStart + 5 + msgLength); needInput = false; } diff --git a/src/interfaces/libpq/libpq-int.h b/src/interfaces/libpq/libpq-int.h index bca3284041..bd3088c91d 100644 --- a/src/interfaces/libpq/libpq-int.h +++ b/src/interfaces/libpq/libpq-int.h @@ -753,6 +753,7 @@ extern PGresult *pqFunctionCall3(PGconn *conn, Oid fnid, */ extern int pqCheckOutBufferSpace(size_t bytes_needed, PGconn *conn); extern int pqCheckInBufferSpace(size_t bytes_needed, PGconn *conn); +extern void pqParseDone(PGconn *conn, int newInStart); extern int pqGetc(char *result, PGconn *conn); extern int pqPutc(char c, PGconn *conn); extern int pqGets(PQExpBuffer buf, PGconn *conn); -- 2.39.2