v10-0001-libpq-trace.patch
application/octet-stream
Filename: v10-0001-libpq-trace.patch
Type: application/octet-stream
Part: 0
Message:
RE: libpq debug log
diff --git a/doc/src/sgml/libpq.sgml b/doc/src/sgml/libpq.sgml
index 67c5d4c..0068854 100644
--- a/doc/src/sgml/libpq.sgml
+++ b/doc/src/sgml/libpq.sgml
@@ -5859,6 +5859,7 @@ PGContextVisibility PQsetErrorContextVisibility(PGconn *conn, PGContextVisibilit
<listitem>
<para>
Enables tracing of the client/server communication to a debugging file stream.
+ (Details of tracing contents appear in <xref linkend="protocol-message-formats"/>).
<synopsis>
void PQtrace(PGconn *conn, FILE *stream);
</synopsis>
diff --git a/src/interfaces/libpq/fe-connect.c b/src/interfaces/libpq/fe-connect.c
index 7d04d36..30cab94 100644
--- a/src/interfaces/libpq/fe-connect.c
+++ b/src/interfaces/libpq/fe-connect.c
@@ -6809,7 +6809,17 @@ PQtrace(PGconn *conn, FILE *debug_port)
if (conn == NULL)
return;
PQuntrace(conn);
- conn->Pfdebug = debug_port;
+ if (pqTraceInit(conn))
+ {
+ conn->Pfdebug = debug_port;
+ setlinebuf(conn->Pfdebug);
+ }
+ else
+ {
+ /* XXX report ENOMEM? */
+ fprintf(conn->Pfdebug, "Failed to initialize trace support\n");
+ fflush(conn->Pfdebug);
+ }
}
void
diff --git a/src/interfaces/libpq/fe-misc.c b/src/interfaces/libpq/fe-misc.c
index 4ffc7f3..ff4c989 100644
--- a/src/interfaces/libpq/fe-misc.c
+++ b/src/interfaces/libpq/fe-misc.c
@@ -53,11 +53,154 @@
#include "pg_config_paths.h"
#include "port/pg_bswap.h"
+/* Log message source */
+typedef enum
+{
+ FROM_BACKEND,
+ FROM_FRONTEND
+} PGCommSource;
+
+/* Messages from backend */
+typedef enum PGLogState
+{
+ LOG_FIRST_BYTE, /* logging the first byte identifing the
+ * protocol message type */
+ LOG_LENGTH, /* logging protocol message length */
+ LOG_CONTENTS /* logging protocol message contents */
+} PGLogState;
+
+typedef struct pqBackendMessage
+{
+ PGLogState state; /* state of logging message state machine */
+ int length; /* protocol message length */
+ char command; /* first one byte of protocol message */
+} pqBackendMessage;
+
+/* Messages from frontend */
+#define MAX_FRONTEND_MSGS 1024
+typedef enum
+{
+ LOG_BYTE1,
+ LOG_STRING,
+ LOG_NCHAR,
+ LOG_INT16,
+ LOG_INT32
+} PGLogMsgDataType;
+
+typedef struct pqFrontendMessage
+{
+ PGLogMsgDataType type;
+ int message_addr;
+ int message_length;
+} pqFrontendMessage;
+
+/*
+ * protocol message types:
+ *
+ * protocol_message_type_b[]: message types sent by a backend
+ * protocol_message_type_f[]: message types sent by a frontend
+ */
+static const char *const protocol_message_type_b[] = {
+ 0, /* 0 */
+ "ParseComplete", /* 1 */
+ "BindComplete", /* 2 */
+ "CloseComplete", /* 3 */
+ 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, /* \x04 ... \x0f */
+ 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, /* \x10 ... \x1f */
+ 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, /* \x20 ... \x2f */
+ 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, /* \x30 ... \x3f */
+ 0, /* @ */
+ "NotificationResponse", /* A */
+ 0, /* B */
+ "CommandComplete", /* C */
+ "DataRow", /* D */
+ "ErrorResponse", /* E */
+ 0, /* F */
+ "CopyInResponse", /* G */
+ "CopyOutResponse", /* H */
+ "EmptyQueryResponse", /* I */
+ 0, /* J */
+ "BackendKeyData", /* K */
+ 0, /* L */
+ 0, /* M */
+ "NoticeResponse", /* N */
+ 0, /* O */
+ 0, /* P */
+ 0, /* Q */
+ "Authentication", /* R */
+ "ParameterStatus", /* S */
+ "RowDescription", /* T */
+ 0, /* U */
+ "FunctionCallResponse", /* V */
+ "CopyBothResponse", /* W */
+ 0, /* X */
+ 0, /* Y */
+ "ReadyForQuery", /* Z */
+ 0, 0, 0, 0, 0, /* \x5b ... \x5f */
+ 0, /* ` */
+ 0, /* a */
+ 0, /* b */
+ "CopyDone", /* c */
+ "CopyData", /* d */
+ 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, /* \x65 ... \0x6d */
+ "NoData", /* n */
+ 0, /* o */
+ 0, /* p */
+ 0, /* q */
+ 0, /* r */
+ "PortalSuspended", /* s */
+ "ParameterDescription", /* t */
+ 0, /* u */
+ "NegotiateProtocolVersion", /* v */
+};
+
+static const char *const protocol_message_type_f[] = {
+ 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, /* \x00 ... \x0f */
+ 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, /* \x10 ... \x1f */
+ 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, /* \x20 ... \x2f */
+ 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, /* \x30 ... \x3f */
+ 0, /* @ */
+ 0, /* A */
+ "Bind", /* B */
+ "Close", /* C */
+ "Describe", /* D */
+ "Execute", /* E */
+ "FunctionCall", /* F */
+ 0, /* G */
+ "Flush", /* H */
+ 0, 0, 0, 0, 0, 0, 0, /* I ... O */
+ "Parse", /* P */
+ "Query", /* Q */
+ 0, /* R */
+ "Sync", /* S */
+ 0, 0, 0, 0, /* T ... W */
+ "Terminate", /* X */
+ 0, 0, 0, 0, 0, 0, 0, /* \x59 ... \x5f */
+ 0, /* ` */
+ 0, /* a */
+ 0, /* b */
+ "CopyDone", /* c */
+ "CopyData", /* d */
+ 0, /* e */
+ "CopyFail", /* f */
+ 0, 0, 0, 0, 0, 0, 0, 0, 0, /* g ... o */
+ "AuthenticationResponse", /* p */
+};
+
static int pqPutMsgBytes(const void *buf, size_t len, PGconn *conn);
static int pqSendSome(PGconn *conn, int len);
static int pqSocketCheck(PGconn *conn, int forRead, int forWrite,
time_t end_time);
static int pqSocketPoll(int sock, int forRead, int forWrite, time_t end_time);
+static void pqStoreFrontendMsg(PGconn *conn, PGLogMsgDataType type, int length);
+static void pqLogFrontendMsg(PGconn *conn);
+static void pqLogMsgByte1(PGconn *conn, char v, PGCommSource commsource);
+static void pqLogMsgInt(PGconn *conn, int v, int length, PGCommSource commsource);
+static void pqLogMsgString(PGconn *conn, const char *v, int length,
+ PGCommSource commsource);
+static void pqLogMsgnchar(PGconn *conn, const char *v, int length,
+ PGCommSource commsource);
+
/*
* PQlibVersion: return the libpq version number
@@ -85,7 +228,7 @@ pqGetc(char *result, PGconn *conn)
*result = conn->inBuffer[conn->inCursor++];
if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "From backend> %c\n", *result);
+ pqLogMsgByte1(conn, *result, FROM_BACKEND);
return 0;
}
@@ -101,7 +244,7 @@ pqPutc(char c, PGconn *conn)
return EOF;
if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "To backend> %c\n", c);
+ pqStoreFrontendMsg(conn, LOG_BYTE1, 1);
return 0;
}
@@ -139,8 +282,7 @@ pqGets_internal(PQExpBuffer buf, PGconn *conn, bool resetbuffer)
conn->inCursor = ++inCursor;
if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "From backend> \"%s\"\n",
- buf->data);
+ pqLogMsgString(conn, buf->data, buf->len + 1, FROM_BACKEND);
return 0;
}
@@ -168,7 +310,7 @@ pqPuts(const char *s, PGconn *conn)
return EOF;
if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "To backend> \"%s\"\n", s);
+ pqStoreFrontendMsg(conn, LOG_STRING, strlen(s) + 1);
return 0;
}
@@ -189,11 +331,7 @@ pqGetnchar(char *s, size_t len, PGconn *conn)
conn->inCursor += len;
if (conn->Pfdebug)
- {
- fprintf(conn->Pfdebug, "From backend (%lu)> ", (unsigned long) len);
- fwrite(s, 1, len, conn->Pfdebug);
- fprintf(conn->Pfdebug, "\n");
- }
+ pqLogMsgnchar(conn, s, len, FROM_BACKEND);
return 0;
}
@@ -213,11 +351,7 @@ pqSkipnchar(size_t len, PGconn *conn)
return EOF;
if (conn->Pfdebug)
- {
- fprintf(conn->Pfdebug, "From backend (%lu)> ", (unsigned long) len);
- fwrite(conn->inBuffer + conn->inCursor, 1, len, conn->Pfdebug);
- fprintf(conn->Pfdebug, "\n");
- }
+ pqLogMsgnchar(conn, conn->inBuffer + conn->inCursor, len, FROM_BACKEND);
conn->inCursor += len;
@@ -235,11 +369,7 @@ pqPutnchar(const char *s, size_t len, PGconn *conn)
return EOF;
if (conn->Pfdebug)
- {
- fprintf(conn->Pfdebug, "To backend> ");
- fwrite(s, 1, len, conn->Pfdebug);
- fprintf(conn->Pfdebug, "\n");
- }
+ pqStoreFrontendMsg(conn, LOG_NCHAR, len);
return 0;
}
@@ -279,7 +409,7 @@ pqGetInt(int *result, size_t bytes, PGconn *conn)
}
if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "From backend (#%lu)> %d\n", (unsigned long) bytes, *result);
+ pqLogMsgInt(conn, *result, (unsigned int) bytes, FROM_BACKEND);
return 0;
}
@@ -301,11 +431,15 @@ pqPutInt(int value, size_t bytes, PGconn *conn)
tmp2 = pg_hton16((uint16) value);
if (pqPutMsgBytes((const char *) &tmp2, 2, conn))
return EOF;
+ if (conn->Pfdebug)
+ pqStoreFrontendMsg(conn, LOG_INT16, 2);
break;
case 4:
tmp4 = pg_hton32((uint32) value);
if (pqPutMsgBytes((const char *) &tmp4, 4, conn))
return EOF;
+ if (conn->Pfdebug)
+ pqStoreFrontendMsg(conn, LOG_INT32, 4);
break;
default:
pqInternalNotice(&conn->noticeHooks,
@@ -313,10 +447,6 @@ pqPutInt(int value, size_t bytes, PGconn *conn)
(unsigned long) bytes);
return EOF;
}
-
- if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "To backend (%lu#)> %d\n", (unsigned long) bytes, value);
-
return 0;
}
@@ -535,8 +665,7 @@ pqPutMsgStart(char msg_type, bool force_len, PGconn *conn)
/* length word, if needed, will be filled in by pqPutMsgEnd */
if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "To backend> Msg %c\n",
- msg_type ? msg_type : ' ');
+ pqLogMsgByte1(conn, msg_type, FROM_FRONTEND);
return 0;
}
@@ -572,15 +701,23 @@ pqPutMsgBytes(const void *buf, size_t len, PGconn *conn)
int
pqPutMsgEnd(PGconn *conn)
{
- if (conn->Pfdebug)
+ if (conn->Pfdebug && PG_PROTOCOL_MAJOR(conn->pversion) < 3)
+ {
fprintf(conn->Pfdebug, "To backend> Msg complete, length %u\n",
conn->outMsgEnd - conn->outCount);
+ }
/* Fill in length word if needed */
if (conn->outMsgStart >= 0)
{
uint32 msgLen = conn->outMsgEnd - conn->outMsgStart;
+ if (conn->Pfdebug)
+ {
+ pqLogMsgInt(conn, (int) msgLen, 4, FROM_FRONTEND);
+ pqLogFrontendMsg(conn);
+ }
+
msgLen = pg_hton32(msgLen);
memcpy(conn->outBuffer + conn->outMsgStart, &msgLen, 4);
}
@@ -600,6 +737,389 @@ pqPutMsgEnd(PGconn *conn)
return 0;
}
+/* -------------------------
+ * FE/BE trace support
+ *
+ * We accumulate frontend message pieces in an array as the libpq code writes
+ * them, and log the complete message when pqLogFrontendMsg is called.
+ * For backend, we print the pieces as soon as we receive them from the server.
+ * -------------------------
+ */
+
+/*
+ * Set up state so that we can trace. NB -- this might be called mutiple
+ * times in a process; make sure it's idempotent. We don't release memory
+ * on PQuntrace(), as that would be useless.
+ */
+bool
+pqTraceInit(PGconn *conn)
+{
+ /* already done? */
+ if (conn->be_msg != NULL)
+ {
+ conn->n_fe_msgs = 0;
+ conn->be_msg->state = LOG_FIRST_BYTE;
+ conn->be_msg->length = 0;
+ return true;
+ }
+
+ conn->be_msg = malloc(sizeof(pqBackendMessage));
+ if (conn->be_msg == NULL)
+ return false;
+ conn->be_msg->state = LOG_FIRST_BYTE;
+ conn->be_msg->length = 0;
+
+ conn->fe_msg = malloc(MAX_FRONTEND_MSGS * sizeof(pqFrontendMessage));
+ if (conn->fe_msg == NULL)
+ {
+ free(conn->be_msg);
+ return false;
+ }
+ conn->n_fe_msgs = 0;
+
+ return true;
+}
+
+/*
+ * pqGetProtocolMsgType:
+ * Get a protocol type from first byte identifier
+ */
+static const char *
+pqGetProtocolMsgType(unsigned char c, PGCommSource commsource)
+{
+ if (commsource == FROM_BACKEND && c < lengthof(protocol_message_type_b))
+ return protocol_message_type_b[c];
+ else if (commsource == FROM_FRONTEND && c < lengthof(protocol_message_type_f))
+ return protocol_message_type_f[c];
+ else
+ return "UnknownCommand";
+}
+
+/* pqTraceResetBeMsg: Initialize backend message */
+static void
+pqTraceResetBeMsg(PGconn *conn)
+{
+ conn->be_msg->state = LOG_FIRST_BYTE;
+ conn->be_msg->length = 0;
+}
+
+/* pqLogInvalidProtocol: Print that the protocol message is invalid */
+static void
+pqLogInvalidProtocol(PGconn *conn)
+{
+ fprintf(conn->Pfdebug, ":::Invalid Protocol\n");
+ conn->be_msg->state = LOG_FIRST_BYTE;
+}
+
+/*
+ * pqTraceMaybeBreakLine:
+ * Check whether the backend message is complete. If so, print a line
+ * break and reset the buffer.
+ */
+void
+pqTraceMaybeBreakLine(int size, PGconn *conn)
+{
+ conn->be_msg->length -= size;
+ if (conn->be_msg->length <= 0)
+ {
+ fprintf(conn->Pfdebug, "\n");
+ pqTraceResetBeMsg(conn);
+ }
+ else
+ fprintf(conn->Pfdebug, " ");
+}
+
+/*
+ * pqStoreFrontendMsg
+ * Store message sent by frontend for later display.
+ *
+ * In protocol v2, we immediately print each message as we receive it.
+ * (XXX why?)
+ * In protocol v3, we store the messages and print them all as a single
+ * line when we get the message-end.
+ *
+ * XXX -- ??
+ * Message length is added at the last if message is sent by the frontend.
+ * To arrange the log output format, frontend message contents are stored in the list.
+ */
+static void
+pqStoreFrontendMsg(PGconn *conn, PGLogMsgDataType type, int length)
+{
+ char message;
+ uint16 result16 = 0;
+ uint32 result32 = 0;
+ int result = 0;
+
+ if (PG_PROTOCOL_MAJOR(conn->pversion) >= 3)
+ {
+ conn->fe_msg[conn->n_fe_msgs].type = type;
+ conn->fe_msg[conn->n_fe_msgs].message_addr = conn->outMsgEnd - length;
+ conn->fe_msg[conn->n_fe_msgs].message_length = length;
+ conn->n_fe_msgs++;
+ /* make sure not to overrun the buffer when a message is too large */
+ if (conn->n_fe_msgs >= MAX_FRONTEND_MSGS)
+ pqLogFrontendMsg(conn);
+ }
+ else
+ {
+ /* Output one content per line in older protocol version */
+ switch (type)
+ {
+ case LOG_BYTE1:
+ memcpy(&message, conn->outBuffer + conn->outMsgEnd - length, length);
+ fprintf(conn->Pfdebug, "To backend> %c\n", message);
+ break;
+
+ case LOG_STRING:
+ memcpy(&message, conn->outBuffer + conn->outMsgEnd - length, length);
+ fprintf(conn->Pfdebug, "To backend> \"%c\"\n", message);
+ break;
+
+ case LOG_NCHAR:
+ fprintf(conn->Pfdebug, "To backend (%d)> ", length);
+ fwrite(conn->outBuffer + conn->outMsgEnd - length, 1, length, conn->Pfdebug);
+ fprintf(conn->Pfdebug, "\n");
+ break;
+
+ case LOG_INT16:
+ memcpy(&result16, conn->outBuffer + conn->outMsgEnd - length, length);
+ result = (int) pg_ntoh16(result16);
+ fprintf(conn->Pfdebug, "To backend (#%d)> %c\n", length, result);
+ break;
+
+ case LOG_INT32:
+ memcpy(&result32, conn->outBuffer + conn->outMsgEnd - length, length);
+ result = (int) pg_ntoh32(result32);
+ fprintf(conn->Pfdebug, "To backend (#%d)> %c\n", length, result);
+ break;
+ }
+ }
+}
+
+/*
+ * pqLogFrontendMsg
+ * Print accumulated frontend message pieces to the trace file.
+ */
+static void
+pqLogFrontendMsg(PGconn *conn)
+{
+ int i;
+ int message_addr;
+ int length;
+ char message;
+ uint16 result16 = 0;
+ uint32 result32 = 0;
+ int result = 0;
+
+ for (i = 0; i < conn->n_fe_msgs; i++)
+ {
+ message_addr = conn->fe_msg[i].message_addr;
+ length = conn->fe_msg[i].message_length;
+
+ switch (conn->fe_msg[i].type)
+ {
+ case LOG_BYTE1:
+ memcpy(&message, conn->outBuffer + message_addr, length);
+ pqLogMsgByte1(conn, message, FROM_FRONTEND);
+ break;
+
+ case LOG_STRING:
+ pqLogMsgString(conn, conn->outBuffer + message_addr,
+ length, FROM_FRONTEND);
+ break;
+
+ case LOG_NCHAR:
+ pqLogMsgnchar(conn, conn->outBuffer + message_addr,
+ length, FROM_FRONTEND);
+ break;
+
+ case LOG_INT16:
+ memcpy(&result16, conn->outBuffer + message_addr, length);
+ result = (int) pg_ntoh16(result16);
+ pqLogMsgInt(conn, result, length, FROM_FRONTEND);
+ break;
+
+ case LOG_INT32:
+ memcpy(&result32, conn->outBuffer + message_addr, length);
+ result = (int) pg_ntoh32(result32);
+ pqLogMsgInt(conn, result, length, FROM_FRONTEND);
+ break;
+ }
+ }
+ conn->n_fe_msgs = 0;
+}
+
+/*
+ * pqLogMsgByte1: output 1 char message to the log
+ */
+static void
+pqLogMsgByte1(PGconn *conn, char v, PGCommSource commsource)
+{
+ char *message_source = commsource == FROM_BACKEND ? "<" : ">";
+ time_t currtime;
+ struct tm *tmp;
+ char timestr[128];
+
+ if (PG_PROTOCOL_MAJOR(conn->pversion) >= 3)
+ {
+ switch (conn->be_msg->state)
+ {
+ case LOG_FIRST_BYTE:
+ currtime = time(NULL);
+ tmp = localtime(&currtime);
+ strftime(timestr, sizeof(timestr), "%Y-%m-%d %H:%M:%S %Z", tmp);
+
+ fprintf(conn->Pfdebug, "%s %s ", timestr, message_source);
+ /* If there is no first 1 byte protocol message, return */
+ if (v == '\0')
+ return;
+
+ fprintf(conn->Pfdebug, "%s ",
+ pqGetProtocolMsgType((unsigned char) v, commsource));
+ /* Next, log the message length */
+ conn->be_msg->state = LOG_LENGTH;
+ conn->be_msg->command = v;
+ break;
+
+ case LOG_CONTENTS:
+ /* Suppresses printing terminating zero byte */
+ if (v == '\0')
+ fprintf(conn->Pfdebug, "0");
+ else
+ fprintf(conn->Pfdebug, "%c", v);
+ pqTraceMaybeBreakLine(sizeof(v), conn);
+ break;
+
+ default:
+ pqLogInvalidProtocol(conn);
+ break;
+ }
+ }
+ else
+ fprintf(conn->Pfdebug, "FROM backend> %c\n", v);
+
+ return;
+}
+
+/*
+ * pqLogMsgInt: output a 2 or 4 bytes integer message to the log
+ */
+static void
+pqLogMsgInt(PGconn *conn, int v, int length, PGCommSource commsource)
+{
+ char *prefix = length == 4 ? "" : "#";
+ char *message_type = 0;
+ uint32 result32 = 0;
+ int result = 0;
+ int message_addr;
+
+ if (PG_PROTOCOL_MAJOR(conn->pversion) >= 3)
+ {
+ switch (conn->be_msg->state)
+ {
+ case LOG_FIRST_BYTE:
+
+ /*
+ * Output message type here for protocol messages that do not
+ * have the first byte.
+ */
+ if (conn->n_fe_msgs > 0)
+ {
+ message_addr = conn->fe_msg[0].message_addr;
+ memcpy(&result32, conn->outBuffer + message_addr, 4);
+ result = (int) pg_ntoh32(result32);
+
+ if (result == NEGOTIATE_SSL_CODE)
+ message_type = "SSLRequest";
+ else
+ message_type = "StartupMessage";
+ }
+ else
+ message_type = "UnknownCommand";
+ fprintf(conn->Pfdebug, "%s ", message_type);
+ conn->be_msg->state = LOG_LENGTH;
+ break;
+
+ case LOG_LENGTH:
+ fprintf(conn->Pfdebug, "%d", v);
+ conn->be_msg->length = v - length;
+ /* Next, log the message contents */
+ conn->be_msg->state = LOG_CONTENTS;
+ pqTraceMaybeBreakLine(0, conn);
+ break;
+
+ case LOG_CONTENTS:
+ fprintf(conn->Pfdebug, "%s%d", prefix, v);
+ pqTraceMaybeBreakLine(length, conn);
+ break;
+
+ default:
+ pqLogInvalidProtocol(conn);
+ break;
+ }
+ }
+ else
+ fprintf(conn->Pfdebug, "To backend (#%d)> %d\n", length, v);
+}
+
+
+/*
+ * pqLogMsgString: output a null-terminated string to the log
+ */
+static void
+pqLogMsgString(PGconn *conn, const char *v, int length, PGCommSource commsource)
+{
+ if (length < 0)
+ length = strlen(v) + 1;
+
+ if (PG_PROTOCOL_MAJOR(conn->pversion) >= 3)
+ {
+ switch (conn->be_msg->state)
+ {
+ case LOG_CONTENTS:
+ fprintf(conn->Pfdebug, "\"%s\"", v);
+ pqTraceMaybeBreakLine(length, conn);
+ break;
+
+ default:
+ pqLogInvalidProtocol(conn);
+ break;
+ }
+ }
+ else
+ fprintf(conn->Pfdebug, "To backend> \"%s\"\n", v);
+}
+
+/*
+ * pqLogMsgnchar: output a string of exactly len bytes message to the log
+ */
+static void
+pqLogMsgnchar(PGconn *conn, const char *v, int length, PGCommSource commsource)
+{
+ if (PG_PROTOCOL_MAJOR(conn->pversion) >= 3)
+ {
+ switch (conn->be_msg->state)
+ {
+ case LOG_CONTENTS:
+ fprintf(conn->Pfdebug, "\'");
+ fwrite(v, 1, length, conn->Pfdebug);
+ fprintf(conn->Pfdebug, "\'");
+ pqTraceMaybeBreakLine(length, conn);
+ break;
+
+ default:
+ pqLogInvalidProtocol(conn);
+ break;
+ }
+ }
+ else
+ {
+ fprintf(conn->Pfdebug, "From backend (%d)> ", length);
+ fwrite(v, 1, length, conn->Pfdebug);
+ fprintf(conn->Pfdebug, "\n");
+ }
+}
+
/* ----------
* pqReadData: read more data, if any is available
* Possible return values:
@@ -1011,8 +1531,16 @@ pqSendSome(PGconn *conn, int len)
int
pqFlush(PGconn *conn)
{
+ /*
+ * There could be unsent trace messages pointing to the output area; may be
+ * overwritten after this. So we need to send stuff to the trace file
+ * before flushing the libpq buffer.
+ */
if (conn->Pfdebug)
+ {
+ pqLogFrontendMsg(conn);
fflush(conn->Pfdebug);
+ }
if (conn->outCount > 0)
return pqSendSome(conn, conn->outCount);
diff --git a/src/interfaces/libpq/fe-protocol3.c b/src/interfaces/libpq/fe-protocol3.c
index 1696525..1d4fa78 100644
--- a/src/interfaces/libpq/fe-protocol3.c
+++ b/src/interfaces/libpq/fe-protocol3.c
@@ -123,6 +123,9 @@ pqParseInput3(PGconn *conn)
*/
handleSyncLoss(conn, id, msgLength);
}
+ /* Terminate a half-finished logging message */
+ if (conn->Pfdebug)
+ pqTraceMaybeBreakLine(msgLength, conn);
return;
}
@@ -156,7 +159,12 @@ pqParseInput3(PGconn *conn)
{
/* If not IDLE state, just wait ... */
if (conn->asyncStatus != PGASYNC_IDLE)
+ {
+ /* Terminate a half-finished logging message */
+ if (conn->Pfdebug)
+ pqTraceMaybeBreakLine(msgLength, conn);
return;
+ }
/*
* Unexpected message in IDLE state; need to recover somehow.
diff --git a/src/interfaces/libpq/libpq-int.h b/src/interfaces/libpq/libpq-int.h
index 1de91ae..bc38fcf 100644
--- a/src/interfaces/libpq/libpq-int.h
+++ b/src/interfaces/libpq/libpq-int.h
@@ -155,6 +155,14 @@ typedef struct
void *noticeProcArg;
} PGNoticeHooks;
+/*
+ * Logging
+ */
+
+/* Forward declarations */
+struct pqBackendMessage;
+struct pqFrontendMessage;
+
typedef struct PGEvent
{
PGEventProc proc; /* the function to call on events */
@@ -376,6 +384,11 @@ struct pg_conn
/* Optional file to write trace info to */
FILE *Pfdebug;
+ /* unwritten protocol traces */
+ struct pqBackendMessage *be_msg;
+ struct pqFrontendMessage *fe_msg;
+ int n_fe_msgs;
+
/* Callback procedures for notice message processing */
PGNoticeHooks noticeHooks;
@@ -668,6 +681,8 @@ extern int pqPutInt(int value, size_t bytes, PGconn *conn);
extern int pqPutMsgStart(char msg_type, bool force_len, PGconn *conn);
extern int pqPutMsgEnd(PGconn *conn);
extern int pqReadData(PGconn *conn);
+extern bool pqTraceInit(PGconn *conn);
+extern void pqTraceMaybeBreakLine(int size, PGconn *conn); /* XXX dubious */
extern int pqFlush(PGconn *conn);
extern int pqWait(int forRead, int forWrite, PGconn *conn);
extern int pqWaitTimed(int forRead, int forWrite, PGconn *conn,
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index a9dca71..54de754 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -1506,6 +1506,7 @@ PGAlignedXLogBlock
PGAsyncStatusType
PGCALL2
PGChecksummablePage
+PGCommSource
PGContextVisibility
PGEvent
PGEventConnDestroy
@@ -1521,6 +1522,8 @@ PGFileType
PGFunction
PGLZ_HistEntry
PGLZ_Strategy
+PGLogMsgDataType
+PGLogState
PGMessageField
PGModuleMagicFunction
PGNoticeHooks
@@ -3253,6 +3256,8 @@ pointer
polymorphic_actuals
pos_trgm
post_parse_analyze_hook_type
+pqBackendMessage
+pqFrontendMessage
pqbool
pqsigfunc
printQueryOpt