Re: libpq debug log

At Mon, 8 Feb 2021 14:57:47 +0000, "iwata.aya@fujitsu.com" <iwata.aya@fujitsu.com> wrote in 
> I update the patch.
> I modified code according to review comments of Tsunakawa san and Horiguchi san.
> 
> And I fixed some bugs.

Thanks for the new version.

+typedef enum
+{
+	MSGDIR_FROM_BACKEND,
+	MSGDIR_FROM_FRONTEND
+} PGCommSource;

This is halfly exposed to other part of libpq. Specifically only
MSGDIR_FROM_BACKEND is used in fe-misc.c and only for
pgLogMessageString and pqLogMessagenchar. I would suggest to hide this
enum from fe-misc.c.

Looking into pqLogMessageString,

+pqLogMessageString(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;	/* XXX ??? */
+	}
+
+	fprintf(conn->Pfdebug, "\"%s\"", v);
+	if (source == MSGDIR_FROM_BACKEND)
+		pqTraceMaybeBreakLine(length, conn);
+}

The only part that shared by both be and fe is the fprintf().  I think
it can be naturally split into separate functions for backend and
frontend messages.

Looking into pqLogMessagenchar,

+/*
+ * pqLogMessagenchar: output a string of exactly len bytes message to the log
+ */
+void
+pqLogMessagenchar(PGconn *conn, const char *v, int len, PGCommSource commsource)
+{
+	fprintf(conn->Pfdebug, "\'");
+	pqLogBinaryMsg(conn, v, len, commsource);
+	fprintf(conn->Pfdebug, "\'");
+	pqTraceMaybeBreakLine(len, conn);
+}

+static void
+pqLogBinaryMsg(PGconn *conn, const char *v, int length, PGCommSource source)
+{
+	int			i,
+				pin;
+
+	if (source == MSGDIR_FROM_BACKEND && conn->be_msg->state != LOG_CONTENTS)
+	{
+		pqLogInvalidProtocol(conn, MSGDIR_FROM_BACKEND);
+		return;	/* XXX ??? */

# What is this???

+	}
    .. shared part
+}

pqLogMessagenchar is the sole caller of pqLogBinaryMsg. So we can
refactor the two functions and have pqLogMessagenchar_for_be and
_for_fe without a fear of the side effect to other callers.  (The
names are discussed below.)


+typedef enum PGLogState
+{

This is libpq-logging.c internal type. It is not needed to be exposed.



+extern void pqTraceForcelyBreakLine(int size, PGconn *conn);
+extern void pqStoreFrontendMsg(PGconn *conn, PGLogMsgDataType type, int length)+extern void pqStoreFeMsgStart(PGconn *conn, char type);
+extern void pqLogFrontendMsg(PGconn *conn, int msgLen);
+extern void pqLogMessageByte1(PGconn *conn, char v);
+extern void pqLogMessageInt(PGconn *conn, int v, int length);
+extern void pqLogMessageString(PGconn *conn, const char *v, int length,
+							   PGCommSource commsource);
+extern void pqLogMessagenchar(PGconn *conn, const char *v, int length,
+							  PGCommSource commsource);

The API functions looks like randomly/inconsistently named and
designed.  I think that API should be in more structurally designed.

The comments about individual function names follow.

+/*
+ * pqTraceForcelyBreakLine:
+ * 		If message is not completed, print a line break and reset.
+ */
+void
+pqTraceForcelyBreakLine(int size, PGconn *conn)
+{
+	fprintf(conn->Pfdebug, "\n");
+	pqTraceResetBeMsg(conn);
+}

Differently from the comment, this function doesn't work in a
conditional way nor in a forceful way. It is just putting a new line
and resetting the backend message variables.  I would name this as
pqTrace(Finish|Close)BeMsgLog().

+/*
+ * pqStoreFrontendMsg
+ *		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
+pqStoreFrontendMsg(PGconn *conn, PGLogMsgDataType type, int length)
+{

I would name this as pqTrace(Store/Append)FeMsg().


+void
+pqStoreFeMsgStart(PGconn *conn, char type)
+{
+	conn->fe_msg->msg_type = type;
+}

The name says that "stores the message "start"". But it actually
stores the message type. I would name this as
pqTraceSetFeMsgType(). Or in contrast to pqTraceFinishBeMsgLog, this
can be named as pqTrace(Start|Begin|Init)BeMsgLog().


+ * pqLogFrontendMsg
+ *		Print accumulated frontend message pieces to the trace file.
+ */
+void
+pqLogFrontendMsg(PGconn *conn, int msgLen)

I would name this as pqTraceEmitFeMsgLog().


+ * pqLogMessageByte1: output 1 char from-backend message to the log
+ * pqLogMessageInt: output a 2- or 4-byte integer from-backend msg to the log

I would name this as pqTraceEmitBeByteLog(), pqTraceEmitBeIntLog()
respectively.

+ * pqLogMessageString: output a null-terminated string to the log

This function is used for both directions. pqTraceEmitStringLog(). If it is split into fe and be parts, they would be pqTraceEmit(Be|Fe)StringLog().


+ * pqLogMessagenchar: output a string of exactly len bytes message to the log

This logs a byte sequence in hexadecimals. I would name that as
pqTraceEmitBytesLog(). Or pqTraceEmit(Be|Fe)BytesLog().



...I finish once here.

Is there any thoughts? Optinions on the namings?

regards.

-- 
Kyotaro Horiguchi
NTT Open Source Software Center