I'll give this another look tomorrow, but I wanted to pass along that I
prefer libpq-trace.{c,h} instead of libpq-logging. I also renamed
variable "pin" and pgindented. I don't have any major reservations
about this patch now, so I'll mark it ready-for-committer in case
somebody else wants to have a look before push.
(Not sure about the use of the word "forcely")
--
Álvaro Herrera 39°49'30"S 73°17'W
>From da0faf61ceb8e9cbc5894ca1e43b6f7fc477a835 Mon Sep 17 00:00:00 2001
From: Alvaro Herrera <[email protected]>
Date: Tue, 23 Feb 2021 22:17:51 -0300
Subject: [PATCH v20] Improve libpq tracing capabilities
Author: Aya Iwata
---
doc/src/sgml/libpq.sgml | 25 +-
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 | 18 +
src/interfaces/libpq/libpq-fe.h | 2 +
src/interfaces/libpq/libpq-int.h | 6 +
src/interfaces/libpq/libpq-trace.c | 638 ++++++++++++++++++++++++++++
src/interfaces/libpq/libpq-trace.h | 95 +++++
src/tools/pgindent/typedefs.list | 6 +
12 files changed, 823 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..3a1e368e0b 100644
--- a/doc/src/sgml/libpq.sgml
+++ b/doc/src/sgml/libpq.sgml
@@ -5907,7 +5907,8 @@ 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.
+ (Details of tracing contents appear in <xref linkend="protocol-message-formats"/>).
<synopsis>
void PQtrace(PGconn *conn, FILE *stream);
</synopsis>
@@ -5927,6 +5928,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 timestamp is not printed with each message. If set to 0 (default),tracing will be output with timestamp.
+ This function should 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..cdb65b48af 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)'
$(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)/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..e36a2348d9 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);
+ pqTraceLogBeMsgByte1(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);
+ pqTraceLogMsgString(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");
- }
+ pqTraceLogMsgnchar(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");
- }
-
+ pqTraceLogMsgnchar(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);
+ pqTraceLogBeMsgInt(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)
+ pqTraceLogFeMsg(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..90ce13eade 100644
--- a/src/interfaces/libpq/fe-protocol3.c
+++ b/src/interfaces/libpq/fe-protocol3.c
@@ -283,6 +283,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)
+ pqTraceForcelyCloseBeMsgLog(msgLength, conn);
}
else if (conn->result == NULL ||
conn->queryclass == PGQUERY_DESCRIBE)
@@ -357,6 +360,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)
+ pqTraceForcelyCloseBeMsgLog(msgLength, conn);
}
else
{
@@ -366,6 +372,9 @@ pqParseInput3(PGconn *conn)
pqSaveErrorResult(conn);
/* Discard the unexpected message */
conn->inCursor += msgLength;
+ /* Terminate a half-finished logging message */
+ if (conn->Pfdebug)
+ pqTraceForcelyCloseBeMsgLog(msgLength, conn);
}
break;
case 'G': /* Start Copy In */
@@ -393,6 +402,9 @@ pqParseInput3(PGconn *conn)
* early.
*/
conn->inCursor += msgLength;
+ /* Terminate a half-finished logging message */
+ if (conn->Pfdebug)
+ pqTraceForcelyCloseBeMsgLog(msgLength, conn);
break;
case 'c': /* Copy Done */
@@ -454,6 +466,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)
+ pqTraceForcelyCloseBeMsgLog(msgLength, conn);
}
/*
@@ -1620,6 +1635,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)
+ pqTraceForcelyCloseBeMsgLog(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..f0002ec51f 100644
--- a/src/interfaces/libpq/libpq-int.h
+++ b/src/interfaces/libpq/libpq-int.h
@@ -22,6 +22,7 @@
/* We assume libpq-fe.h has already been included. */
#include "libpq-events.h"
+#include "libpq-trace.h"
#include <time.h>
#ifndef WIN32
@@ -376,6 +377,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..821380bcf1
--- /dev/null
+++ b/src/interfaces/libpq/libpq-trace.c
@@ -0,0 +1,638 @@
+/*-------------------------------------------------------------------------
+ *
+ * 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 */
+};
+
+static bool pqTraceInit(PGconn *conn);
+static bool pqTraceMaybeBreakLine(int size, PGconn *conn);
+static void pqLogBinaryMsg(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 pqTraceLogFeMsg 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() is failed, do noting. */
+ 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 and reset the buffer. If print break line, return 1.
+ */
+static bool
+pqTraceMaybeBreakLine(int size, PGconn *conn)
+{
+ conn->be_msg->length -= size;
+ if (conn->be_msg->length <= 0)
+ {
+ fprintf(conn->Pfdebug, "\n");
+ pqTraceResetBeMsg(conn);
+ return 1;
+ }
+ else
+ {
+ fprintf(conn->Pfdebug, " ");
+ return 0;
+ }
+}
+
+/*
+ * pqTraceForcelyCloseBeMsgLog:
+ * If message is not completed, print a line break and reset.
+ */
+void
+pqTraceForcelyCloseBeMsgLog(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);
+ }
+ 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_in_buffer = 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. Used for PQtrace() purposes.
+ * Cribbed from setup_formatted_log_time, but much simpler.
+ */
+static char *
+pqLogFormatTimestamp(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));
+
+ return timestr;
+}
+
+/*
+ * pqTraceLogFeMsg
+ * Print accumulated frontend message pieces to the trace file.
+ */
+void
+pqTraceLogFeMsg(PGconn *conn, int msgLen)
+{
+ char timestr[FORMATTED_TS_LEN];
+ char *timestr_p = "";
+ const char *message_type;
+
+ if ((conn->traceFlags & PQTRACE_SUPPRESS_TIMESTAMPS) == 0)
+ timestr_p = pqLogFormatTimestamp(timestr, sizeof(timestr));
+
+ 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)
+ {
+ int message_addr;
+ uint32 result32;
+ int result;
+
+ message_addr = conn->fe_msg->fields[0].offset_in_buffer;
+ memcpy(&result32, conn->outBuffer + 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_p,
+ message_type,
+ msgLen);
+
+ for (int i = 0; i < conn->fe_msg->num_fields; i++)
+ {
+ int message_addr;
+ int length;
+ char v;
+
+ message_addr = conn->fe_msg->fields[i].offset_in_buffer;
+ length = conn->fe_msg->fields[i].length;
+
+ fprintf(conn->Pfdebug, " ");
+
+ switch (conn->fe_msg->fields[i].type)
+ {
+ case LOG_BYTE1:
+ v = *(conn->outBuffer + message_addr);
+
+ if (isprint(v))
+ fprintf(conn->Pfdebug, "%c", v);
+ else
+ fprintf(conn->Pfdebug, "\\x%02x", v);
+ break;
+
+ case LOG_STRING:
+ pqTraceLogMsgString(conn, conn->outBuffer + message_addr,
+ length, MSGDIR_FROM_FRONTEND);
+ break;
+
+ case LOG_NCHAR:
+ pqTraceLogMsgnchar(conn, conn->outBuffer + message_addr,
+ length, MSGDIR_FROM_FRONTEND);
+ break;
+
+ case LOG_INT16:
+ {
+ uint16 result16;
+
+ memcpy(&result16, conn->outBuffer + message_addr, length);
+ result16 = pg_ntoh16(result16);
+ fprintf(conn->Pfdebug, "#%d", result16);
+ break;
+ }
+
+ case LOG_INT32:
+ {
+ uint32 result32;
+
+ memcpy(&result32, conn->outBuffer + message_addr, length);
+ result32 = pg_ntoh32(result32);
+ fprintf(conn->Pfdebug, "%d", result32);
+ break;
+ }
+ }
+ }
+ conn->fe_msg->num_fields = 0;
+
+ fprintf(conn->Pfdebug, "\n");
+}
+
+/*
+ * pqTraceLogBeMsgByte1: output 1 char from-backend message to the log
+ */
+void
+pqTraceLogBeMsgByte1(PGconn *conn, char v)
+{
+ char timestr[FORMATTED_TS_LEN];
+ char *timestr_p = "";
+ bool logfinish = 0;
+
+ if (conn->be_msg->LogCursor >= conn->inCursor - conn->inStart)
+ return;
+ switch (conn->be_msg->state)
+ {
+ case LOG_FIRST_BYTE:
+ if ((conn->traceFlags & PQTRACE_SUPPRESS_TIMESTAMPS) == 0)
+ timestr_p = pqLogFormatTimestamp(timestr, sizeof(timestr));
+ fprintf(conn->Pfdebug, "%s\t<\t", timestr_p);
+ fprintf(conn->Pfdebug, "%s\t",
+ 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);
+ logfinish = pqTraceMaybeBreakLine(1, conn);
+ break;
+
+ default:
+ pqLogInvalidProtocol(conn, MSGDIR_FROM_BACKEND);
+ break;
+ }
+ if (!logfinish)
+ conn->be_msg->LogCursor = conn->inCursor - conn->inStart;
+}
+
+/*
+ * pqTraceLogBeMsgInt: output a 2- or 4-byte integer from-backend msg to the log
+ */
+void
+pqTraceLogBeMsgInt(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;
+}
+
+
+/*
+ * pqTraceLogMsgString: output a null-terminated string to the log
+ */
+void
+pqTraceLogMsgString(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);
+}
+
+/*
+ * pqLogBinaryMsg: output a string possibly consisting of non-printable
+ * characters. Hex representation is used for such chars; others are
+ * printed normally.
+ */
+static void
+pqLogBinaryMsg(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);
+}
+
+/*
+ * pqTraceLogMsgnchar: output a string of exactly len bytes message to the log
+ */
+void
+pqTraceLogMsgnchar(PGconn *conn, const char *v, int len, PGCommSource commsource)
+{
+ fprintf(conn->Pfdebug, "\'");
+ pqLogBinaryMsg(conn, v, len, commsource);
+ fprintf(conn->Pfdebug, "\'");
+ 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..ff3be37b77
--- /dev/null
+++ b/src/interfaces/libpq/libpq-trace.h
@@ -0,0 +1,95 @@
+/*-------------------------------------------------------------------------
+ *
+ * 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 backend */
+typedef enum PGLogState
+{
+ LOG_FIRST_BYTE, /* logging the first byte identifying 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 */
+ int LogCursor; /* next byte of logging */
+} pqBackendMessage;
+
+/* Messages from frontend */
+typedef enum
+{
+ LOG_BYTE1,
+ LOG_STRING,
+ LOG_NCHAR,
+ LOG_INT16,
+ LOG_INT32
+} PGLogMsgDataType;
+
+
+typedef struct pqFrontendMessageField
+{
+ PGLogMsgDataType type;
+ int offset_in_buffer;
+ 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 */
+
+extern void pqTraceLogBeMsgByte1(PGconn *conn, char v);
+extern void pqTraceLogBeMsgInt(PGconn *conn, int v, int length);
+extern void pqTraceLogMsgString(PGconn *conn, const char *v, int length,
+ PGCommSource commsource);
+extern void pqTraceLogMsgnchar(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 pqTraceLogFeMsg(PGconn *conn, int msgLen);
+extern void pqTraceForcelyCloseBeMsgLog(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
