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 files changed, 16 insertions, 22 deletions

diff --git a/src/interfaces/libpq/fe-protocol3.c b/src/interfaces/libpq/fe-protocol3.c
index 3170d484f02..8c5ac1729f0 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,8 @@ 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 +1783,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 +2160,9 @@ 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;
+
+				/* consume the message */
+				pqParseDone(conn, conn->inStart + 5 + msgLength);
 
 				/*
 				 * If we already have a result object (probably an error), use
@@ -2194,6 +2187,7 @@ pqFunctionCall3(PGconn *conn, Oid fnid,
 						pqSaveErrorResult(conn);
 					}
 				}
+				/* and we're out */
 				return pqPrepareAsyncResult(conn);
 			case 'S':			/* parameter status */
 				if (getParameterStatus(conn))
@@ -2203,18 +2197,18 @@ pqFunctionCall3(PGconn *conn, Oid fnid,
 				/* The backend violates the protocol. */
 				libpq_append_conn_error(conn, "protocol error: id=0x%x", id);
 				pqSaveErrorResult(conn);
-				/* trust the specified message length as what to skip */
+
+				/*
+				 * We can't call parsing done due to the protocol violation
+				 * (so message tracing wouldn't work), but trust the specified
+				 * message length as what to skip.
+				 */
 				conn->inStart += 5 + msgLength;
 				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;
+		/* Completed parsing this message, keep going */
+		pqParseDone(conn, conn->inStart + 5 + msgLength);
 		needInput = false;
 	}