I tweaked this code a little bit more. I didn't like that libpq-trace.h was
exposing all the internal details of the API to the world; and I liked it even
less that libpq-int.h had to include the file, exposing everything everywhere.
I added some forward struct declarations in libpq-int.h to avoid including
libpq-trace.h in it; and I also moved a few of the definitions from
libpq-trace.h to the .c file. We didn't really need them to be exposed outside
the .c file. In the makefile, libpq-trace.h was being installed in the wrong
place -- I changed so that it goes to includedir_internal, like libpq-int.h.
The function pqLogFormatTimestamp was returning a pointer to where it printed
things. But that was pointless, because the buffer is caller supplied, so the
caller knows full well where the output is. There's no gain in functionality,
so I made it return void.
I added a description of the output format to the documentation.
I renamed a lot of functions, so that it looks more like a consistent API.
pqTraceMaybeBreakLine() says it returns bool, but it was using "return 1/0"
rather than actual bools. That's poor style.
The only thing we're missing here is some coverage. Right now, nothing in the
source tree calls this at all, so if we break it, we'll never know. I think we
should introduce src/test/modules/test_pqtrace or something like that.
v22 attached.
From 918a674b93938e23d6982273e500d6caa59b6079 Mon Sep 17 00:00:00 2001
From: Alvaro Herrera <alvhe...@alvh.no-ip.org>
Date: Thu, 25 Feb 2021 14:32:00 -0300
Subject: [PATCH v22] Improve libpq tracing capabilities
Author: Aya Iwata
---
doc/src/sgml/libpq.sgml | 40 +-
src/interfaces/libpq/Makefile | 3 +
src/interfaces/libpq/exports.txt | 1 +
src/interfaces/libpq/fe-connect.c | 25 +-
src/interfaces/libpq/fe-exec.c | 4 -
src/interfaces/libpq/fe-misc.c | 59 ++-
src/interfaces/libpq/fe-protocol3.c | 19 +
src/interfaces/libpq/libpq-fe.h | 2 +
src/interfaces/libpq/libpq-int.h | 9 +
src/interfaces/libpq/libpq-trace.c | 689 ++++++++++++++++++++++++++++
src/interfaces/libpq/libpq-trace.h | 58 +++
src/tools/pgindent/typedefs.list | 6 +
12 files changed, 856 insertions(+), 59 deletions(-)
create mode 100644 src/interfaces/libpq/libpq-trace.c
create mode 100644 src/interfaces/libpq/libpq-trace.h
diff --git a/doc/src/sgml/libpq.sgml b/doc/src/sgml/libpq.sgml
index 5e25f20843..adec5b4b82 100644
--- a/doc/src/sgml/libpq.sgml
+++ b/doc/src/sgml/libpq.sgml
@@ -5907,12 +5907,28 @@ PGContextVisibility PQsetErrorContextVisibility(PGconn *conn, PGContextVisibilit
<listitem>
<para>
- Enables tracing of the client/server communication to a debugging file stream.
+ Enables tracing of the client/server communication to a debugging file
+ stream.
+ Only available when protocol version 3 or higher is used.
<synopsis>
void PQtrace(PGconn *conn, FILE *stream);
</synopsis>
</para>
+ <para>
+ Each line consists of: an optional timestamp, a direction indicator
+ (<literal>></literal> for messages from client to server,
+ and <literal><</literal> for messages from server to client),
+ message type, message length, and message contents.
+ Protocol strings are enclosed in double quotes, while strings used as data
+ values are enclosed in single quotes. Non-printable chars are printed as
+ hexadecimal escapes.
+ For numerical quantities, 16-bit values are preceded with <literal>#</literal>
+ and 32-bit values are printed without a prefix.
+ Further message-type-specific detail can be found in
+ <xref linkend="protocol-message-formats"/>.
+ </para>
+
<note>
<para>
On Windows, if the <application>libpq</application> library and an application are
@@ -5927,6 +5943,28 @@ void PQtrace(PGconn *conn, FILE *stream);
</listitem>
</varlistentry>
+ <varlistentry id="libpq-PQtraceSetFlags">
+ <term><function>PQtraceSetFlags</function><indexterm><primary>PQtraceSetFlags</primary></indexterm></term>
+
+ <listitem>
+ <para>
+ Controls the tracing behavior of client/server communication.
+<synopsis>
+void PQtraceSetFlags(PGconn *conn, int flags);
+</synopsis>
+ </para>
+
+ <para>
+ <literal>flags</literal> contains flag bits describing the operating mode
+ of tracing.
+ If <literal>flags</literal> contains <literal>PQTRACE_SUPPRESS_TIMESTAMPS</literal>,
+ then the timestamp is not included when printing each message.
+ This function must be called after calling <function>PQtrace</function>.
+ </para>
+
+ </listitem>
+ </varlistentry>
+
<varlistentry id="libpq-PQuntrace">
<term><function>PQuntrace</function><indexterm><primary>PQuntrace</primary></indexterm></term>
diff --git a/src/interfaces/libpq/Makefile b/src/interfaces/libpq/Makefile
index f74677eaf9..5a690be83f 100644
--- a/src/interfaces/libpq/Makefile
+++ b/src/interfaces/libpq/Makefile
@@ -42,6 +42,7 @@ OBJS = \
fe-secure.o \
legacy-pqsignal.o \
libpq-events.o \
+ libpq-trace.o \
pqexpbuffer.o \
fe-auth.o
@@ -114,6 +115,7 @@ install: all installdirs install-lib
$(INSTALL_DATA) $(srcdir)/libpq-fe.h '$(DESTDIR)$(includedir)'
$(INSTALL_DATA) $(srcdir)/libpq-events.h '$(DESTDIR)$(includedir)'
$(INSTALL_DATA) $(srcdir)/libpq-int.h '$(DESTDIR)$(includedir_internal)'
+ $(INSTALL_DATA) $(srcdir)/libpq-trace.h '$(DESTDIR)$(includedir_internal)'
$(INSTALL_DATA) $(srcdir)/pqexpbuffer.h '$(DESTDIR)$(includedir_internal)'
$(INSTALL_DATA) $(srcdir)/pg_service.conf.sample '$(DESTDIR)$(datadir)/pg_service.conf.sample'
@@ -127,6 +129,7 @@ uninstall: uninstall-lib
rm -f '$(DESTDIR)$(includedir)/libpq-fe.h'
rm -f '$(DESTDIR)$(includedir)/libpq-events.h'
rm -f '$(DESTDIR)$(includedir_internal)/libpq-int.h'
+ rm -f '$(DESTDIR)$(includedir_internal)/libpq-trace.h'
rm -f '$(DESTDIR)$(includedir_internal)/pqexpbuffer.h'
rm -f '$(DESTDIR)$(datadir)/pg_service.conf.sample'
diff --git a/src/interfaces/libpq/exports.txt b/src/interfaces/libpq/exports.txt
index bbc1f90481..09f11114a6 100644
--- a/src/interfaces/libpq/exports.txt
+++ b/src/interfaces/libpq/exports.txt
@@ -179,3 +179,4 @@ PQgetgssctx 176
PQsetSSLKeyPassHook_OpenSSL 177
PQgetSSLKeyPassHook_OpenSSL 178
PQdefaultSSLKeyPassHook_OpenSSL 179
+PQtraceSetFlags 180
diff --git a/src/interfaces/libpq/fe-connect.c b/src/interfaces/libpq/fe-connect.c
index db71fea169..9bf2f0d0b6 100644
--- a/src/interfaces/libpq/fe-connect.c
+++ b/src/interfaces/libpq/fe-connect.c
@@ -4021,6 +4021,10 @@ freePGconn(PGconn *conn)
if (conn->connip)
free(conn->connip);
/* Note that conn->Pfdebug is not ours to close or free */
+ if (conn->be_msg)
+ free(conn->be_msg);
+ if (conn->fe_msg)
+ free(conn->fe_msg);
if (conn->last_query)
free(conn->last_query);
if (conn->write_err_msg)
@@ -6766,27 +6770,6 @@ PQsetErrorContextVisibility(PGconn *conn, PGContextVisibility show_context)
return old;
}
-void
-PQtrace(PGconn *conn, FILE *debug_port)
-{
- if (conn == NULL)
- return;
- PQuntrace(conn);
- conn->Pfdebug = debug_port;
-}
-
-void
-PQuntrace(PGconn *conn)
-{
- if (conn == NULL)
- return;
- if (conn->Pfdebug)
- {
- fflush(conn->Pfdebug);
- conn->Pfdebug = NULL;
- }
-}
-
PQnoticeReceiver
PQsetNoticeReceiver(PGconn *conn, PQnoticeReceiver proc, void *arg)
{
diff --git a/src/interfaces/libpq/fe-exec.c b/src/interfaces/libpq/fe-exec.c
index e730753387..e8503aabc7 100644
--- a/src/interfaces/libpq/fe-exec.c
+++ b/src/interfaces/libpq/fe-exec.c
@@ -966,10 +966,6 @@ pqSaveParameterStatus(PGconn *conn, const char *name, const char *value)
pgParameterStatus *pstatus;
pgParameterStatus *prev;
- if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "pqSaveParameterStatus: '%s' = '%s'\n",
- name, value);
-
/*
* Forget any old information about the parameter
*/
diff --git a/src/interfaces/libpq/fe-misc.c b/src/interfaces/libpq/fe-misc.c
index 2bfb6acd89..49067daebd 100644
--- a/src/interfaces/libpq/fe-misc.c
+++ b/src/interfaces/libpq/fe-misc.c
@@ -49,6 +49,7 @@
#include "libpq-fe.h"
#include "libpq-int.h"
+#include "libpq-trace.h"
#include "mb/pg_wchar.h"
#include "pg_config_paths.h"
#include "port/pg_bswap.h"
@@ -85,7 +86,7 @@ pqGetc(char *result, PGconn *conn)
*result = conn->inBuffer[conn->inCursor++];
if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "From backend> %c\n", *result);
+ pqTraceOutputBeByte1(conn, *result);
return 0;
}
@@ -101,7 +102,7 @@ pqPutc(char c, PGconn *conn)
return EOF;
if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "To backend> %c\n", c);
+ pqTraceStoreFeMsg(conn, LOG_BYTE1, 1);
return 0;
}
@@ -139,8 +140,7 @@ pqGets_internal(PQExpBuffer buf, PGconn *conn, bool resetbuffer)
conn->inCursor = ++inCursor;
if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "From backend> \"%s\"\n",
- buf->data);
+ pqTraceOutputString(conn, buf->data, buf->len + 1, MSGDIR_FROM_BACKEND);
return 0;
}
@@ -164,11 +164,13 @@ pqGets_append(PQExpBuffer buf, PGconn *conn)
int
pqPuts(const char *s, PGconn *conn)
{
- if (pqPutMsgBytes(s, strlen(s) + 1, conn))
+ int length = strlen(s) + 1;
+
+ if (pqPutMsgBytes(s, length, conn))
return EOF;
if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "To backend> \"%s\"\n", s);
+ pqTraceStoreFeMsg(conn, LOG_STRING, length);
return 0;
}
@@ -189,11 +191,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");
- }
+ pqTraceOutputNchar(conn, s, len, MSGDIR_FROM_BACKEND);
return 0;
}
@@ -213,12 +211,8 @@ 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");
- }
-
+ pqTraceOutputNchar(conn, conn->inBuffer + conn->inCursor, len,
+ MSGDIR_FROM_BACKEND);
conn->inCursor += len;
return 0;
@@ -235,11 +229,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");
- }
+ pqTraceStoreFeMsg(conn, LOG_NCHAR, len);
return 0;
}
@@ -279,7 +269,7 @@ pqGetInt(int *result, size_t bytes, PGconn *conn)
}
if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "From backend (#%lu)> %d\n", (unsigned long) bytes, *result);
+ pqTraceOutputBeInt(conn, *result, (unsigned int) bytes);
return 0;
}
@@ -294,15 +284,18 @@ pqPutInt(int value, size_t bytes, PGconn *conn)
{
uint16 tmp2;
uint32 tmp4;
+ PGLogMsgDataType type;
switch (bytes)
{
case 2:
+ type = LOG_INT16;
tmp2 = pg_hton16((uint16) value);
if (pqPutMsgBytes((const char *) &tmp2, 2, conn))
return EOF;
break;
case 4:
+ type = LOG_INT32;
tmp4 = pg_hton32((uint32) value);
if (pqPutMsgBytes((const char *) &tmp4, 4, conn))
return EOF;
@@ -315,7 +308,7 @@ pqPutInt(int value, size_t bytes, PGconn *conn)
}
if (conn->Pfdebug)
- fprintf(conn->Pfdebug, "To backend (%lu#)> %d\n", (unsigned long) bytes, value);
+ pqTraceStoreFeMsg(conn, type, (unsigned int) bytes);
return 0;
}
@@ -535,8 +528,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 : ' ');
+ pqTraceSetFeMsgType(conn, msg_type);
return 0;
}
@@ -572,15 +564,14 @@ pqPutMsgBytes(const void *buf, size_t len, PGconn *conn)
int
pqPutMsgEnd(PGconn *conn)
{
- if (conn->Pfdebug)
- 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)
+ pqTraceOutputFeMsg(conn, msgLen);
+
msgLen = pg_hton32(msgLen);
memcpy(conn->outBuffer + conn->outMsgStart, &msgLen, 4);
}
@@ -1011,11 +1002,13 @@ pqSendSome(PGconn *conn, int len)
int
pqFlush(PGconn *conn)
{
- if (conn->Pfdebug)
- fflush(conn->Pfdebug);
-
if (conn->outCount > 0)
+ {
+ if (conn->Pfdebug)
+ fflush(conn->Pfdebug);
+
return pqSendSome(conn, conn->outCount);
+ }
return 0;
}
diff --git a/src/interfaces/libpq/fe-protocol3.c b/src/interfaces/libpq/fe-protocol3.c
index e4ee9d69d2..76a65b0302 100644
--- a/src/interfaces/libpq/fe-protocol3.c
+++ b/src/interfaces/libpq/fe-protocol3.c
@@ -28,6 +28,7 @@
#include "libpq-fe.h"
#include "libpq-int.h"
+#include "libpq-trace.h"
#include "mb/pg_wchar.h"
#include "port/pg_bswap.h"
@@ -283,6 +284,9 @@ pqParseInput3(PGconn *conn)
* the data till we get to the end of the query.
*/
conn->inCursor += msgLength;
+ /* Terminate a half-finished logging message */
+ if (conn->Pfdebug)
+ pqTraceForciblyCloseBeMsg(msgLength, conn);
}
else if (conn->result == NULL ||
conn->queryclass == PGQUERY_DESCRIBE)
@@ -357,6 +361,9 @@ pqParseInput3(PGconn *conn)
* tuples till we get to the end of the query.
*/
conn->inCursor += msgLength;
+ /* Terminate a half-finished logging message */
+ if (conn->Pfdebug)
+ pqTraceForciblyCloseBeMsg(msgLength, conn);
}
else
{
@@ -366,6 +373,9 @@ pqParseInput3(PGconn *conn)
pqSaveErrorResult(conn);
/* Discard the unexpected message */
conn->inCursor += msgLength;
+ /* Terminate a half-finished logging message */
+ if (conn->Pfdebug)
+ pqTraceForciblyCloseBeMsg(msgLength, conn);
}
break;
case 'G': /* Start Copy In */
@@ -393,6 +403,9 @@ pqParseInput3(PGconn *conn)
* early.
*/
conn->inCursor += msgLength;
+ /* Terminate a half-finished logging message */
+ if (conn->Pfdebug)
+ pqTraceForciblyCloseBeMsg(msgLength, conn);
break;
case 'c': /* Copy Done */
@@ -454,6 +467,9 @@ handleSyncLoss(PGconn *conn, char id, int msgLength)
/* flush input data since we're giving up on processing it */
pqDropConnection(conn, true);
conn->status = CONNECTION_BAD; /* No more connection to backend */
+ /* Terminate a half-finished logging message */
+ if (conn->Pfdebug)
+ pqTraceForciblyCloseBeMsg(msgLength, conn);
}
/*
@@ -1620,6 +1636,9 @@ getCopyDataMessage(PGconn *conn)
return 0;
break;
case 'd': /* Copy Data, pass it back to caller */
+ /* Terminate a half-finished logging message */
+ if (conn->Pfdebug)
+ pqTraceForciblyCloseBeMsg(msgLength, conn);
return msgLength;
case 'c':
diff --git a/src/interfaces/libpq/libpq-fe.h b/src/interfaces/libpq/libpq-fe.h
index effe0ccf85..cdbaa2a987 100644
--- a/src/interfaces/libpq/libpq-fe.h
+++ b/src/interfaces/libpq/libpq-fe.h
@@ -363,7 +363,9 @@ extern PGContextVisibility PQsetErrorContextVisibility(PGconn *conn,
PGContextVisibility show_context);
/* Enable/disable tracing */
+#define PQTRACE_SUPPRESS_TIMESTAMPS 1
extern void PQtrace(PGconn *conn, FILE *debug_port);
+extern void PQtraceSetFlags(PGconn *conn, int flags);
extern void PQuntrace(PGconn *conn);
/* Override default notice handling routines */
diff --git a/src/interfaces/libpq/libpq-int.h b/src/interfaces/libpq/libpq-int.h
index ce36aabd25..9ff6e5569d 100644
--- a/src/interfaces/libpq/libpq-int.h
+++ b/src/interfaces/libpq/libpq-int.h
@@ -317,6 +317,10 @@ typedef struct pg_conn_host
* found in password file. */
} pg_conn_host;
+/* forward declarations */
+struct pqBackendMessage;
+struct pqFrontendMessage;
+
/*
* PGconn stores all the state data associated with a single connection
* to a backend.
@@ -376,6 +380,11 @@ struct pg_conn
/* Optional file to write trace info to */
FILE *Pfdebug;
+ int traceFlags;
+
+ /* pending protocol trace messages */
+ struct pqBackendMessage *be_msg;
+ struct pqFrontendMessage *fe_msg;
/* Callback procedures for notice message processing */
PGNoticeHooks noticeHooks;
diff --git a/src/interfaces/libpq/libpq-trace.c b/src/interfaces/libpq/libpq-trace.c
new file mode 100644
index 0000000000..f774ad062a
--- /dev/null
+++ b/src/interfaces/libpq/libpq-trace.c
@@ -0,0 +1,689 @@
+/*-------------------------------------------------------------------------
+ *
+ * libpq-trace.c
+ * functions for libpq protocol tracing
+ *
+ * Portions Copyright (c) 1996-2021, PostgreSQL Global Development Group
+ * Portions Copyright (c) 1994, Regents of the University of California
+ *
+ * IDENTIFICATION
+ * src/interfaces/libpq/libpq-trace.c
+ *
+ *-------------------------------------------------------------------------
+ */
+
+#include "postgres_fe.h"
+
+#include <limits.h>
+#include <time.h>
+
+#ifdef WIN32
+#include "win32.h"
+#else
+#include <unistd.h>
+#include <sys/time.h>
+#endif
+
+#include "libpq-fe.h"
+#include "libpq-int.h"
+#include "libpq-trace.h"
+#include "pgtime.h"
+#include "port/pg_bswap.h"
+
+/*
+ * 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, 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 */
+ "ParseComplete", /* 1 */
+ "BindComplete", /* 2 */
+ "CloseComplete", /* 3 */
+ 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, 0, /* \x34 ... \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, /* \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 */
+};
+
+/* Messages from backend */
+typedef enum PGLogState
+{
+ LOG_FIRST_BYTE, /* logging the message type byte */
+ LOG_LENGTH, /* logging protocol message length */
+ LOG_CONTENTS /* logging protocol message contents */
+} PGLogState;
+
+/*
+ * Messages received from backend are printed to the trace file as soon as
+ * processed from the server.
+ */
+typedef struct pqBackendMessage
+{
+ PGLogState state; /* state of logging message state machine */
+ char command; /* protocol message type */
+ int length; /* protocol message length */
+ int logCursor; /* next byte of logging */
+} pqBackendMessage;
+
+/*
+ * Frontend messages are accumulated as individual fields that each is a
+ * pointer into conn->outBuffer.
+ */
+typedef struct pqFrontendMessageField
+{
+ PGLogMsgDataType type;
+ int offset;
+ int length;
+} pqFrontendMessageField;
+
+typedef struct pqFrontendMessage
+{
+ char msg_type;
+ int num_fields; /* array used size */
+ int max_fields; /* array allocated size */
+ pqFrontendMessageField fields[FLEXIBLE_ARRAY_MEMBER];
+} pqFrontendMessage;
+
+#define DEF_FE_MSGFIELDS 256 /* initial fields allocation quantum */
+
+#define FORMATTED_TS_LEN 128 /* formatted timestamp length */
+
+
+static bool pqTraceInit(PGconn *conn);
+static bool pqTraceMaybeBreakLine(int size, PGconn *conn);
+static void pqTraceOutputBinary(PGconn *conn, const char *v, int length,
+ PGCommSource commsource);
+static const char *pqGetProtocolMsgType(unsigned char c,
+ PGCommSource commsource);
+
+/* -------------------------
+ * FE/BE trace support
+ *
+ * We accumulate frontend message pieces in an array as the libpq code writes
+ * them, and log the complete message when pqTraceOutputFeMsg is called.
+ * For backend, we print the pieces as soon as we receive them from the server.
+ * -------------------------
+ */
+
+void
+PQtrace(PGconn *conn, FILE *debug_port)
+{
+ if (conn == NULL)
+ return;
+ /* Protocol 2.0 does not support tracing. */
+ if (PG_PROTOCOL_MAJOR(conn->pversion) < 3)
+ return;
+ PQuntrace(conn);
+ if (debug_port == NULL)
+ return;
+ if (pqTraceInit(conn))
+ {
+ setvbuf(debug_port, NULL, _IOLBF, 0);
+ conn->Pfdebug = debug_port;
+ }
+ else
+ {
+ fprintf(debug_port, "Failed to initialize trace support: out of memory\n");
+ fflush(debug_port);
+ conn->Pfdebug = NULL;
+ }
+}
+
+void
+PQuntrace(PGconn *conn)
+{
+ if (conn == NULL)
+ return;
+ if (conn->Pfdebug)
+ {
+ fflush(conn->Pfdebug);
+ conn->Pfdebug = NULL;
+ }
+
+ /*
+ * Deallocate FE/BE message tracking memory. If the fe_msg allocation is
+ * of the initial size, reuse it next time.
+ */
+ if (conn->fe_msg &&
+ conn->fe_msg->max_fields != DEF_FE_MSGFIELDS)
+ {
+ free(conn->fe_msg);
+ conn->fe_msg = NULL;
+ }
+ if (conn->be_msg)
+ {
+ free(conn->be_msg);
+ conn->be_msg = NULL;
+ }
+ conn->traceFlags = 0;
+}
+
+void
+PQtraceSetFlags(PGconn *conn, int flags)
+{
+ if (conn == NULL)
+ return;
+ /* Protocol 2.0 is not supported. */
+ if (PG_PROTOCOL_MAJOR(conn->pversion) < 3)
+ return;
+ /* If PQtrace() failed, do nothing. */
+ if (conn->be_msg == NULL || conn->fe_msg == NULL || conn->Pfdebug == NULL)
+ return;
+ conn->traceFlags = flags;
+}
+
+/*
+ * Set up state so that we can trace. NB -- this might be called multiple
+ * times in a process; make sure it's idempotent.
+ */
+static bool
+pqTraceInit(PGconn *conn)
+{
+ conn->traceFlags = 0;
+
+ if (conn->be_msg == NULL)
+ {
+ conn->be_msg = malloc(sizeof(pqBackendMessage));
+ if (conn->be_msg == NULL)
+ return false;
+ }
+
+ if (conn->fe_msg == NULL)
+ {
+ conn->fe_msg = malloc(offsetof(pqFrontendMessage, fields) +
+ DEF_FE_MSGFIELDS * sizeof(pqFrontendMessageField));
+ if (conn->fe_msg == NULL)
+ {
+ free(conn->be_msg);
+ /* NULL out for the case that fe_msg malloc fails */
+ conn->be_msg = NULL;
+ return false;
+ }
+ conn->fe_msg->max_fields = DEF_FE_MSGFIELDS;
+ }
+
+ conn->fe_msg->num_fields = 0;
+ conn->be_msg->state = LOG_FIRST_BYTE;
+ conn->be_msg->length = 0;
+ conn->be_msg->command = '\0';
+ conn->be_msg->logCursor = 0;
+
+ return true;
+}
+
+/*
+ * pqGetProtocolMsgType:
+ * Get a protocol type from first byte identifier
+ */
+static const char *
+pqGetProtocolMsgType(unsigned char c, PGCommSource commsource)
+{
+ if (commsource == MSGDIR_FROM_BACKEND &&
+ c < lengthof(protocol_message_type_b) &&
+ protocol_message_type_b[c] != NULL)
+ return protocol_message_type_b[c];
+
+ if (commsource == MSGDIR_FROM_FRONTEND &&
+ c < lengthof(protocol_message_type_f) &&
+ protocol_message_type_f[c] != NULL)
+ return protocol_message_type_f[c];
+
+ return "UnknownMessage";
+}
+
+/* pqTraceResetBeMsg: Initialize backend message */
+static void
+pqTraceResetBeMsg(PGconn *conn)
+{
+ conn->be_msg->state = LOG_FIRST_BYTE;
+ conn->be_msg->length = 0;
+ conn->be_msg->logCursor = 0;
+}
+
+/* pqLogInvalidProtocol: Print that the protocol message is invalid */
+static void
+pqLogInvalidProtocol(PGconn *conn, PGCommSource commsource)
+{
+ fprintf(conn->Pfdebug,
+ "%s\t:::Invalid Protocol\n",
+ commsource == MSGDIR_FROM_BACKEND ? "<" : ">");
+ conn->be_msg->state = LOG_FIRST_BYTE;
+}
+
+/*
+ * pqTraceMaybeBreakLine:
+ * Check whether the backend message is complete. If so, print a line
+ * break, reset the buffer, and return true. If there's still more
+ * in the backend message, print a blank and return false.
+ */
+static bool
+pqTraceMaybeBreakLine(int size, PGconn *conn)
+{
+ Assert(conn->be_msg->length > 0);
+
+ conn->be_msg->length -= size;
+ if (conn->be_msg->length <= 0)
+ {
+ fprintf(conn->Pfdebug, "\n");
+ pqTraceResetBeMsg(conn);
+ return true;
+ }
+ else
+ {
+ fprintf(conn->Pfdebug, " ");
+ return false;
+ }
+}
+
+/*
+ * pqTraceForciblyCloseBeMsg
+ * Print a newline and reset backend message state.
+ *
+ * To be used when dealing with various errors.
+ */
+void
+pqTraceForciblyCloseBeMsg(int size, PGconn *conn)
+{
+ fprintf(conn->Pfdebug, "\n");
+ pqTraceResetBeMsg(conn);
+}
+
+void
+pqTraceSetFeMsgType(PGconn *conn, char type)
+{
+ conn->fe_msg->msg_type = type;
+}
+
+/*
+ * pqTraceStoreFeMsg
+ * Keep track of a from-frontend message that was just written to the
+ * output buffer.
+ *
+ * Frontend messages are constructed piece by piece, and the message length
+ * is determined at the end, but sent to the server first; so for tracing
+ * purposes we store everything in memory and print to the trace file when
+ * the message is complete.
+ */
+void
+pqTraceStoreFeMsg(PGconn *conn, PGLogMsgDataType type, int length)
+{
+ /* realloc if we've exceeded available space */
+ if (conn->fe_msg->num_fields >= conn->fe_msg->max_fields)
+ {
+ if (conn->fe_msg->max_fields > INT_MAX)
+ {
+ fprintf(conn->Pfdebug, "abandoning trace: field message overflow\n");
+ PQuntrace(conn);
+ }
+ conn->fe_msg =
+ realloc(conn->fe_msg,
+ offsetof(pqFrontendMessage, fields) +
+ 2 * conn->fe_msg->max_fields * sizeof(pqFrontendMessageField));
+ if (conn->fe_msg == NULL)
+ {
+ fprintf(conn->Pfdebug, "abandoning trace: out of memory\n");
+ PQuntrace(conn);
+ return;
+ }
+ conn->fe_msg->max_fields *= 2;
+ }
+
+ conn->fe_msg->fields[conn->fe_msg->num_fields].type = type;
+ conn->fe_msg->fields[conn->fe_msg->num_fields].offset = conn->outMsgEnd - length;
+ conn->fe_msg->fields[conn->fe_msg->num_fields].length = length;
+ conn->fe_msg->num_fields++;
+}
+
+/*
+ * Print the current time, with microseconds, into a caller-supplied
+ * buffer.
+ * Cribbed from setup_formatted_log_time, but much simpler.
+ */
+static void
+pqTraceFormatTimestamp(char *timestr, size_t ts_len)
+{
+ struct timeval tval;
+ pg_time_t stamp_time;
+
+ gettimeofday(&tval, NULL);
+ stamp_time = (pg_time_t) tval.tv_sec;
+
+ strftime(timestr, ts_len,
+ "%Y-%m-%d %H:%M:%S",
+ localtime(&stamp_time));
+ /* append microseconds */
+ sprintf(timestr + strlen(timestr), ".%06d", (int) (tval.tv_usec));
+}
+
+/*
+ * pqTraceOutputFeMsg
+ * Print accumulated frontend message pieces to the trace file.
+ */
+void
+pqTraceOutputFeMsg(PGconn *conn, int msgLen)
+{
+ char timestr[FORMATTED_TS_LEN];
+ const char *message_type;
+
+ if ((conn->traceFlags & PQTRACE_SUPPRESS_TIMESTAMPS) == 0)
+ pqTraceFormatTimestamp(timestr, sizeof(timestr));
+ else
+ timestr[0] = '\0';
+
+ if (conn->fe_msg->msg_type == '\0')
+ {
+ /*
+ * We delayed printing message type for special messages; they are
+ * complete now, so print them.
+ */
+ if (conn->fe_msg->num_fields > 0)
+ {
+ char *message_addr;
+ uint32 result32;
+ int result;
+
+ message_addr = conn->outBuffer + conn->fe_msg->fields[0].offset;
+ memcpy(&result32, message_addr, 4);
+ result = (int) pg_ntoh32(result32);
+
+ if (result == NEGOTIATE_SSL_CODE)
+ message_type = "SSLRequest";
+ else if (result == NEGOTIATE_GSS_CODE)
+ message_type = "GSSRequest";
+ else
+ message_type = "StartupMessage";
+ }
+ else
+ message_type = "UnknownMessage";
+ }
+ else
+ message_type =
+ pqGetProtocolMsgType(conn->fe_msg->msg_type, MSGDIR_FROM_FRONTEND);
+
+ fprintf(conn->Pfdebug, "%s\t>\t%s\t%d",
+ timestr,
+ message_type,
+ msgLen);
+
+ for (int i = 0; i < conn->fe_msg->num_fields; i++)
+ {
+ char *message_addr;
+ int length;
+
+ message_addr = conn->outBuffer + conn->fe_msg->fields[i].offset;
+ length = conn->fe_msg->fields[i].length;
+
+ fprintf(conn->Pfdebug, " ");
+
+ switch (conn->fe_msg->fields[i].type)
+ {
+ case LOG_BYTE1:
+ if (isprint(*message_addr))
+ fprintf(conn->Pfdebug, "%c", *message_addr);
+ else
+ fprintf(conn->Pfdebug, "\\x%02x", *message_addr);
+ break;
+
+ case LOG_STRING:
+ pqTraceOutputString(conn, message_addr,
+ length, MSGDIR_FROM_FRONTEND);
+ break;
+
+ case LOG_NCHAR:
+ pqTraceOutputNchar(conn, message_addr,
+ length, MSGDIR_FROM_FRONTEND);
+ break;
+
+ case LOG_INT16:
+ {
+ uint16 result16;
+
+ memcpy(&result16, message_addr, length);
+ result16 = pg_ntoh16(result16);
+ fprintf(conn->Pfdebug, "#%d", result16);
+ break;
+ }
+
+ case LOG_INT32:
+ {
+ uint32 result32;
+
+ memcpy(&result32, message_addr, length);
+ result32 = pg_ntoh32(result32);
+ fprintf(conn->Pfdebug, "%d", result32);
+ break;
+ }
+ }
+ }
+ conn->fe_msg->num_fields = 0;
+
+ fprintf(conn->Pfdebug, "\n");
+}
+
+/*
+ * pqTraceOutputBeByte1: output 1 char from-backend message to the log
+ */
+void
+pqTraceOutputBeByte1(PGconn *conn, char v)
+{
+ if (conn->be_msg->logCursor >= conn->inCursor - conn->inStart)
+ return;
+ switch (conn->be_msg->state)
+ {
+ case LOG_FIRST_BYTE:
+ {
+ char timestr[FORMATTED_TS_LEN];
+
+ if ((conn->traceFlags & PQTRACE_SUPPRESS_TIMESTAMPS) == 0)
+ pqTraceFormatTimestamp(timestr, sizeof(timestr));
+ else
+ timestr[0] = '\0';
+ fprintf(conn->Pfdebug, "%s\t<\t%s\t", timestr,
+ pqGetProtocolMsgType((unsigned char) v,
+ MSGDIR_FROM_BACKEND));
+ /* Next, log the message length */
+ conn->be_msg->state = LOG_LENGTH;
+ conn->be_msg->command = v;
+ break;
+ }
+
+ case LOG_CONTENTS:
+
+ /*
+ * Show non-printable data in hex format, including the
+ * terminating \0 that completes ErrorResponse and NoticeResponse
+ * messages.
+ */
+ if (!isprint(v))
+ fprintf(conn->Pfdebug, "\\x%02x", v);
+ else
+ fprintf(conn->Pfdebug, "%c", v);
+
+ if (!pqTraceMaybeBreakLine(1, conn))
+ conn->be_msg->logCursor = conn->inCursor - conn->inStart;
+ break;
+
+ default:
+ pqLogInvalidProtocol(conn, MSGDIR_FROM_BACKEND);
+ break;
+ }
+}
+
+/*
+ * pqTraceOutputBeInt: output a 2- or 4-byte integer from-backend msg to the log
+ */
+void
+pqTraceOutputBeInt(PGconn *conn, int v, int length)
+{
+ char *prefix = length == 4 ? "" : "#";
+ bool logfinish = 0;
+
+ if (conn->be_msg->logCursor >= conn->inCursor - conn->inStart)
+ return;
+
+ switch (conn->be_msg->state)
+ {
+ 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;
+ logfinish = pqTraceMaybeBreakLine(0, conn);
+ break;
+
+ case LOG_CONTENTS:
+ fprintf(conn->Pfdebug, "%s%d", prefix, v);
+ logfinish = pqTraceMaybeBreakLine(length, conn);
+ break;
+
+ default:
+ pqLogInvalidProtocol(conn, MSGDIR_FROM_BACKEND);
+ break;
+ }
+ if (!logfinish)
+ conn->be_msg->logCursor = conn->inCursor - conn->inStart;
+}
+
+
+/*
+ * pqTraceOutputString: output a null-terminated string to the log
+ */
+void
+pqTraceOutputString(PGconn *conn, const char *v, int length, PGCommSource source)
+{
+ if (source == MSGDIR_FROM_BACKEND && conn->be_msg->state != LOG_CONTENTS)
+ {
+ pqLogInvalidProtocol(conn, MSGDIR_FROM_BACKEND);
+ return;
+ }
+
+ fprintf(conn->Pfdebug, "\"%s\"", v);
+ if (source == MSGDIR_FROM_BACKEND)
+ pqTraceMaybeBreakLine(length, conn);
+}
+
+/*
+ * pqTraceOutputBinary: output a string possibly consisting of
+ * non-printable characters. Hex representation is used for such
+ * chars; others are printed normally.
+ *
+ * XXX this probably doesn't do a great job with multibyte chars, but then we
+ * don't know what is text and what encoding it'd be in.
+ */
+static void
+pqTraceOutputBinary(PGconn *conn, const char *v, int length, PGCommSource source)
+{
+ int i,
+ next; /* first char not yet printed */
+
+ if (source == MSGDIR_FROM_BACKEND && conn->be_msg->state != LOG_CONTENTS)
+ {
+ pqLogInvalidProtocol(conn, MSGDIR_FROM_BACKEND);
+ return;
+ }
+
+ for (next = i = 0; i < length; ++i)
+ {
+ if (isprint(v[i]))
+ continue;
+ else
+ {
+ fwrite(v + next, 1, i - next, conn->Pfdebug);
+ fprintf(conn->Pfdebug, "\\x%02x", v[i]);
+ next = i + 1;
+ }
+ }
+ if (next < length)
+ fwrite(v + next, 1, length - next, conn->Pfdebug);
+}
+
+/*
+ * pqTraceOutputNchar: output a string of exactly len bytes message to the log
+ */
+void
+pqTraceOutputNchar(PGconn *conn, const char *v, int len, PGCommSource commsource)
+{
+ fprintf(conn->Pfdebug, "\'");
+ pqTraceOutputBinary(conn, v, len, commsource);
+ fprintf(conn->Pfdebug, "\'");
+ if (commsource == MSGDIR_FROM_BACKEND)
+ pqTraceMaybeBreakLine(len, conn);
+}
diff --git a/src/interfaces/libpq/libpq-trace.h b/src/interfaces/libpq/libpq-trace.h
new file mode 100644
index 0000000000..f1e1e6ffb2
--- /dev/null
+++ b/src/interfaces/libpq/libpq-trace.h
@@ -0,0 +1,58 @@
+/*-------------------------------------------------------------------------
+ *
+ * libpq-trace.h
+ * This file contains definitions for structures and
+ * externs for functions used by libpq protocol tracing.
+ *
+ * Portions Copyright (c) 1996-2021, PostgreSQL Global Development Group
+ * Portions Copyright (c) 1994, Regents of the University of California
+ *
+ * src/interfaces/libpq/libpq-trace.h
+ *
+ *-------------------------------------------------------------------------
+ */
+
+#ifndef LIBPQ_TRACE_H
+#define LIBPQ_TRACE_H
+
+#include "libpq-fe.h"
+#include "libpq-int.h"
+
+#ifdef __cplusplus
+extern "C"
+{
+#endif
+
+/* Log message source */
+typedef enum
+{
+ MSGDIR_FROM_BACKEND,
+ MSGDIR_FROM_FRONTEND
+} PGCommSource;
+
+/* Messages from frontend */
+typedef enum
+{
+ LOG_BYTE1,
+ LOG_STRING,
+ LOG_NCHAR,
+ LOG_INT16,
+ LOG_INT32
+} PGLogMsgDataType;
+
+extern void pqTraceOutputBeByte1(PGconn *conn, char v);
+extern void pqTraceOutputBeInt(PGconn *conn, int v, int length);
+extern void pqTraceOutputString(PGconn *conn, const char *v, int length,
+ PGCommSource commsource);
+extern void pqTraceOutputNchar(PGconn *conn, const char *v, int length,
+ PGCommSource commsource);
+extern void pqTraceSetFeMsgType(PGconn *conn, char type);
+extern void pqTraceStoreFeMsg(PGconn *conn, PGLogMsgDataType type, int length);
+extern void pqTraceOutputFeMsg(PGconn *conn, int msgLen);
+extern void pqTraceForciblyCloseBeMsg(int size, PGconn *conn);
+
+#ifdef __cplusplus
+}
+#endif
+
+#endif /* LIBPQ_TRACE_H */
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index bab4f3adb3..fad9029ac5 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -1523,6 +1523,7 @@ PGAlignedXLogBlock
PGAsyncStatusType
PGCALL2
PGChecksummablePage
+PGCommSource
PGContextVisibility
PGEvent
PGEventConnDestroy
@@ -1538,6 +1539,8 @@ PGFileType
PGFunction
PGLZ_HistEntry
PGLZ_Strategy
+PGLogMsgDataType
+PGLogState
PGMessageField
PGModuleMagicFunction
PGNoticeHooks
@@ -3273,6 +3276,9 @@ pointer
polymorphic_actuals
pos_trgm
post_parse_analyze_hook_type
+pqBackendMessage
+pqFrontendMessage
+pqFrontendMessageField
pqbool
pqsigfunc
printQueryOpt
--
2.20.1
