🌐 AI搜索 & 代理 主页
Skip to content

Commit b8b3f86

Browse files
alvherrealvherre
committed
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 commit tries to fix that by introducing a new function pqParseDone which make it 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 <postgres@jeltef.nl> Discussion: https://postgr.es/m/CAGECzQSoPHtZ4xe0raJ6FYSEiPPS+YWXBhOGo+Y1YecLgknF3g@mail.gmail.com
1 parent 6be39d7 commit b8b3f86

File tree

6 files changed

+124
-31
lines changed

6 files changed

+124
-31
lines changed

‎src/interfaces/libpq/fe-auth.c‎

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -94,6 +94,10 @@ pg_GSS_continue(PGconn *conn, int payloadlen)
9494
ginbuf.value = NULL;
9595
}
9696

97+
/* finished parsing, trace server-to-client message */
98+
if (conn->Pfdebug)
99+
pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false);
100+
97101
/* Only try to acquire credentials if GSS delegation isn't disabled. */
98102
if (!pg_GSS_have_cred_cache(&conn->gcred))
99103
conn->gcred = GSS_C_NO_CREDENTIAL;
@@ -258,6 +262,10 @@ pg_SSPI_continue(PGconn *conn, int payloadlen)
258262
InBuffers[0].BufferType = SECBUFFER_TOKEN;
259263
}
260264

265+
/* finished parsing, trace server-to-client message */
266+
if (conn->Pfdebug)
267+
pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false);
268+
261269
OutBuffers[0].pvBuffer = NULL;
262270
OutBuffers[0].BufferType = SECBUFFER_TOKEN;
263271
OutBuffers[0].cbBuffer = 0;
@@ -563,6 +571,10 @@ pg_SASL_init(PGconn *conn, int payloadlen)
563571
}
564572
}
565573

574+
/* finished parsing, trace server-to-client message */
575+
if (conn->Pfdebug)
576+
pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false);
577+
566578
Assert(conn->sasl);
567579

568580
/*
@@ -651,6 +663,11 @@ pg_SASL_continue(PGconn *conn, int payloadlen, bool final)
651663
free(challenge);
652664
return STATUS_ERROR;
653665
}
666+
667+
/* finished parsing, trace server-to-client message */
668+
if (conn->Pfdebug)
669+
pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false);
670+
654671
/* For safety and convenience, ensure the buffer is NULL-terminated. */
655672
challenge[payloadlen] = '\0';
656673

@@ -716,6 +733,10 @@ pg_password_sendauth(PGconn *conn, const char *password, AuthRequest areq)
716733
return STATUS_ERROR; /* shouldn't happen */
717734
}
718735

736+
/* finished parsing, trace server-to-client message */
737+
if (conn->Pfdebug)
738+
pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false);
739+
719740
/* Encrypt the password if needed. */
720741

721742
switch (areq)

‎src/interfaces/libpq/fe-connect.c‎

Lines changed: 8 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -3797,7 +3797,7 @@ PQconnectPoll(PGconn *conn)
37973797
return PGRES_POLLING_READING;
37983798
}
37993799
/* OK, we read the message; mark data consumed */
3800-
conn->inStart = conn->inCursor;
3800+
pqParseDone(conn, conn->inCursor);
38013801

38023802
/*
38033803
* Before 7.2, the postmaster didn't always end its
@@ -3847,7 +3847,7 @@ PQconnectPoll(PGconn *conn)
38473847
goto error_return;
38483848
}
38493849
/* OK, we read the message; mark data consumed */
3850-
conn->inStart = conn->inCursor;
3850+
pqParseDone(conn, conn->inCursor);
38513851

38523852
/*
38533853
* If error is "cannot connect now", try the next host if
@@ -3876,7 +3876,7 @@ PQconnectPoll(PGconn *conn)
38763876
goto error_return;
38773877
}
38783878
/* OK, we read the message; mark data consumed */
3879-
conn->inStart = conn->inCursor;
3879+
pqParseDone(conn, conn->inCursor);
38803880
goto error_return;
38813881
}
38823882

@@ -3901,7 +3901,11 @@ PQconnectPoll(PGconn *conn)
39013901
*/
39023902
res = pg_fe_sendauth(areq, msgLength, conn);
39033903

3904-
/* OK, we have processed the message; mark data consumed */
3904+
/*
3905+
* OK, we have processed the message; mark data consumed. We
3906+
* don't call pqParseDone here because we already traced this
3907+
* message inside pg_fe_sendauth.
3908+
*/
39053909
conn->inStart = conn->inCursor;
39063910

39073911
if (res != STATUS_OK)

‎src/interfaces/libpq/fe-misc.c‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -435,6 +435,21 @@ pqCheckInBufferSpace(size_t bytes_needed, PGconn *conn)
435435
return EOF;
436436
}
437437

438+
/*
439+
* pqParseDone: after a server-to-client message has successfully
440+
* been parsed, advance conn->inStart to account for it.
441+
*/
442+
void
443+
pqParseDone(PGconn *conn, int newInStart)
444+
{
445+
/* trace server-to-client message */
446+
if (conn->Pfdebug)
447+
pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false);
448+
449+
/* Mark message as done */
450+
conn->inStart = newInStart;
451+
}
452+
438453
/*
439454
* pqPutMsgStart: begin construction of a message to the server
440455
*

‎src/interfaces/libpq/fe-protocol3.c‎

Lines changed: 16 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -454,12 +454,8 @@ pqParseInput3(PGconn *conn)
454454
/* Successfully consumed this message */
455455
if (conn->inCursor == conn->inStart + 5 + msgLength)
456456
{
457-
/* trace server-to-client message */
458-
if (conn->Pfdebug)
459-
pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false);
460-
461457
/* Normal case: parsing agrees with specified length */
462-
conn->inStart = conn->inCursor;
458+
pqParseDone(conn, conn->inCursor);
463459
}
464460
else
465461
{
@@ -1728,12 +1724,8 @@ getCopyDataMessage(PGconn *conn)
17281724
return -1;
17291725
}
17301726

1731-
/* trace server-to-client message */
1732-
if (conn->Pfdebug)
1733-
pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false);
1734-
17351727
/* Drop the processed message and loop around for another */
1736-
conn->inStart = conn->inCursor;
1728+
pqParseDone(conn, conn->inCursor);
17371729
}
17381730
}
17391731

@@ -1791,13 +1783,13 @@ pqGetCopyData3(PGconn *conn, char **buffer, int async)
17911783
(*buffer)[msgLength] = '\0'; /* Add terminating null */
17921784

17931785
/* Mark message consumed */
1794-
conn->inStart = conn->inCursor + msgLength;
1786+
pqParseDone(conn, conn->inCursor + msgLength);
17951787

17961788
return msgLength;
17971789
}
17981790

17991791
/* Empty, so drop it and loop around for another */
1800-
conn->inStart = conn->inCursor;
1792+
pqParseDone(conn, conn->inCursor);
18011793
}
18021794
}
18031795

@@ -2168,8 +2160,9 @@ pqFunctionCall3(PGconn *conn, Oid fnid,
21682160
case 'Z': /* backend is ready for new query */
21692161
if (getReadyForQuery(conn))
21702162
continue;
2171-
/* consume the message and exit */
2172-
conn->inStart += 5 + msgLength;
2163+
2164+
/* consume the message */
2165+
pqParseDone(conn, conn->inStart + 5 + msgLength);
21732166

21742167
/*
21752168
* If we already have a result object (probably an error), use
@@ -2194,6 +2187,7 @@ pqFunctionCall3(PGconn *conn, Oid fnid,
21942187
pqSaveErrorResult(conn);
21952188
}
21962189
}
2190+
/* and we're out */
21972191
return pqPrepareAsyncResult(conn);
21982192
case 'S': /* parameter status */
21992193
if (getParameterStatus(conn))
@@ -2203,18 +2197,18 @@ pqFunctionCall3(PGconn *conn, Oid fnid,
22032197
/* The backend violates the protocol. */
22042198
libpq_append_conn_error(conn, "protocol error: id=0x%x", id);
22052199
pqSaveErrorResult(conn);
2206-
/* trust the specified message length as what to skip */
2200+
2201+
/*
2202+
* We can't call parsing done due to the protocol violation
2203+
* (so message tracing wouldn't work), but trust the specified
2204+
* message length as what to skip.
2205+
*/
22072206
conn->inStart += 5 + msgLength;
22082207
return pqPrepareAsyncResult(conn);
22092208
}
22102209

2211-
/* trace server-to-client message */
2212-
if (conn->Pfdebug)
2213-
pqTraceOutputMessage(conn, conn->inBuffer + conn->inStart, false);
2214-
2215-
/* Completed this message, keep going */
2216-
/* trust the specified message length as what to skip */
2217-
conn->inStart += 5 + msgLength;
2210+
/* Completed parsing this message, keep going */
2211+
pqParseDone(conn, conn->inStart + 5 + msgLength);
22182212
needInput = false;
22192213
}
22202214

‎src/interfaces/libpq/fe-trace.c‎

Lines changed: 63 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -280,6 +280,14 @@ pqTraceOutput_CommandComplete(FILE *f, const char *message, int *cursor)
280280
pqTraceOutputString(f, message, cursor, false);
281281
}
282282

283+
static void
284+
pqTraceOutput_CopyData(FILE *f, const char *message, int *cursor, int length,
285+
bool suppress)
286+
{
287+
fprintf(f, "CopyData\t");
288+
pqTraceOutputNchar(f, length - *cursor + 1, message, cursor, suppress);
289+
}
290+
283291
static void
284292
pqTraceOutput_DataRow(FILE *f, const char *message, int *cursor)
285293
{
@@ -472,10 +480,58 @@ pqTraceOutput_Query(FILE *f, const char *message, int *cursor)
472480
}
473481

474482
static void
475-
pqTraceOutput_Authentication(FILE *f, const char *message, int *cursor)
483+
pqTraceOutput_Authentication(FILE *f, const char *message, int *cursor,
484+
int length, bool suppress)
476485
{
477-
fprintf(f, "Authentication\t");
478-
pqTraceOutputInt32(f, message, cursor, false);
486+
int authType = 0;
487+
488+
memcpy(&authType, message + *cursor, 4);
489+
authType = (int) pg_ntoh32(authType);
490+
*cursor += 4;
491+
switch (authType)
492+
{
493+
case AUTH_REQ_OK:
494+
fprintf(f, "AuthenticationOk");
495+
break;
496+
/* AUTH_REQ_KRB4 not supported */
497+
/* AUTH_REQ_KRB5 not supported */
498+
case AUTH_REQ_PASSWORD:
499+
fprintf(f, "AuthenticationCleartextPassword");
500+
break;
501+
/* AUTH_REQ_CRYPT not supported */
502+
case AUTH_REQ_MD5:
503+
fprintf(f, "AuthenticationMD5Password");
504+
break;
505+
case AUTH_REQ_GSS:
506+
fprintf(f, "AuthenticationGSS");
507+
break;
508+
case AUTH_REQ_GSS_CONT:
509+
fprintf(f, "AuthenticationGSSContinue\t");
510+
pqTraceOutputNchar(f, length - *cursor + 1, message, cursor,
511+
suppress);
512+
break;
513+
case AUTH_REQ_SSPI:
514+
fprintf(f, "AuthenticationSSPI");
515+
break;
516+
case AUTH_REQ_SASL:
517+
fprintf(f, "AuthenticationSASL\t");
518+
while (message[*cursor] != '\0')
519+
pqTraceOutputString(f, message, cursor, false);
520+
pqTraceOutputString(f, message, cursor, false);
521+
break;
522+
case AUTH_REQ_SASL_CONT:
523+
fprintf(f, "AuthenticationSASLContinue\t");
524+
pqTraceOutputNchar(f, length - *cursor + 1, message, cursor,
525+
suppress);
526+
break;
527+
case AUTH_REQ_SASL_FIN:
528+
fprintf(f, "AuthenticationSASLFinal\t");
529+
pqTraceOutputNchar(f, length - *cursor + 1, message, cursor,
530+
suppress);
531+
break;
532+
default:
533+
fprintf(f, "Unknown authentication message %d", authType);
534+
}
479535
}
480536

481537
static void
@@ -625,7 +681,8 @@ pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer)
625681
pqTraceOutput_CommandComplete(conn->Pfdebug, message, &logCursor);
626682
break;
627683
case PqMsg_CopyData:
628-
/* Drop COPY data to reduce the overhead of logging. */
684+
pqTraceOutput_CopyData(conn->Pfdebug, message, &logCursor,
685+
length, regress);
629686
break;
630687
case PqMsg_Describe:
631688
/* Describe(F) and DataRow(B) use the same identifier. */
@@ -714,7 +771,8 @@ pqTraceOutputMessage(PGconn *conn, const char *message, bool toServer)
714771
pqTraceOutput_Query(conn->Pfdebug, message, &logCursor);
715772
break;
716773
case PqMsg_AuthenticationRequest:
717-
pqTraceOutput_Authentication(conn->Pfdebug, message, &logCursor);
774+
pqTraceOutput_Authentication(conn->Pfdebug, message, &logCursor,
775+
length, regress);
718776
break;
719777
case PqMsg_PortalSuspended:
720778
fprintf(conn->Pfdebug, "PortalSuspended");

‎src/interfaces/libpq/libpq-int.h‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -753,6 +753,7 @@ extern PGresult *pqFunctionCall3(PGconn *conn, Oid fnid,
753753
*/
754754
extern int pqCheckOutBufferSpace(size_t bytes_needed, PGconn *conn);
755755
extern int pqCheckInBufferSpace(size_t bytes_needed, PGconn *conn);
756+
extern void pqParseDone(PGconn *conn, int newInStart);
756757
extern int pqGetc(char *result, PGconn *conn);
757758
extern int pqPutc(char c, PGconn *conn);
758759
extern int pqGets(PQExpBuffer buf, PGconn *conn);

0 commit comments

Comments
 (0)