Re: libpq debug log - Mailing list pgsql-hackers

From Alvaro Herrera
Subject Re: libpq debug log
Date
Msg-id 20200916204155.GA28949@alvherre.pgsql
Whole thread Raw
In response to RE: libpq debug log  ("iwata.aya@fujitsu.com" <iwata.aya@fujitsu.com>)
Responses RE: libpq debug log  ("iwata.aya@fujitsu.com" <iwata.aya@fujitsu.com>)
Re: libpq debug log  (Kyotaro Horiguchi <horikyota.ntt@gmail.com>)
Re: libpq debug log  (Robert Haas <robertmhaas@gmail.com>)
List pgsql-hackers
Hello Aya Iwata,

I like this patch, and I think we should have it.  I have updated it, as
it had conflicts.

In 0002, I remove use of ftime(), because that function is obsolete.
However, with that change we lose printing of milliseconds in the trace
lines.  I think that's not great, but I also think we can live without
them until somebody gets motivated to write the code for that.  It seems
a little messy so I'd prefer to leave that for a subsequent commit.
(Maybe we can just use pg_strftime.)

Looking at the message type tables, I decided to get rid of the "bf"
table, which had only two bytes, and instead put CopyData and CopyDone
in the other two tables.  That seems simpler.  Also, the COMMAND_x_MAX
macros were a bit pointless; I just expanded at the only caller of each,
using lengthof().  And since the message type is unsigned, there's no
need to do "c >= 0" since it must always be true.

I added setlinebuf() to the debug file.  Works better than without,
because "tail -f /tmp/libpqtrace.log" works as you'd expect.

One thing that it might be good to do is to avoid creating the message
type tables as const but instead initialize them if and only if tracing
is enabled, on the first call.  I think that would not only save space
in the constant area of the library for the 99.99% of the cases where
tracing isn't used, but also make the initialization code be more
sensible (since presumably you wouldn't have to initialize all the
zeroes.)

Opinions?  I experimented by patching psql as below (not intended for
commit) and it looks good.  Only ErrorResponse prints the terminator as
a control character, or something:

2020-09-16 13:27:29.072 -03  < ErrorResponse 117 S "ERROR" V "ERROR" C "42704" M "no existe el slot de replicación
«foobar»"F "slot.c" L "408" R "ReplicationSlotAcquireInternal" ^@ 
 


diff --git a/src/bin/psql/startup.c b/src/bin/psql/startup.c
index 8232a0143b..01728ba8e8 100644
--- a/src/bin/psql/startup.c
+++ b/src/bin/psql/startup.c
@@ -301,6 +301,11 @@ main(int argc, char *argv[])
 
     psql_setup_cancel_handler();
 
+    {
+        FILE *trace = fopen("/tmp/libpqtrace.log", "a+");
+        PQtrace(pset.db, trace);
+    }
+
     PQsetNoticeProcessor(pset.db, NoticeProcessor, NULL);
 
     SyncVariables();

-- 
Álvaro Herrera                https://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Remote DBA, Training & Services

Attachment

pgsql-hackers by date:

Previous
From: Robert Haas
Date:
Subject: Re: [Patch] ALTER SYSTEM READ ONLY
Next
From: Daniel Gustafsson
Date:
Subject: Re: pgindent vs dtrace on macos