Re: libpq debug log

From: Alvaro Herrera <alvherre(at)2ndquadrant(dot)com>
To: "iwata(dot)aya(at)fujitsu(dot)com" <iwata(dot)aya(at)fujitsu(dot)com>
Cc: "pgsql-hackers(at)postgresql(dot)org" <pgsql-hackers(at)postgresql(dot)org>, "tgl(at)sss(dot)pgh(dot)pa(dot)us" <tgl(at)sss(dot)pgh(dot)pa(dot)us>, "robertmhaas(at)gmail(dot)com" <robertmhaas(at)gmail(dot)com>, "pchampion(at)pivotal(dot)io" <pchampion(at)pivotal(dot)io>, "jdoty(at)pivotal(dot)io" <jdoty(at)pivotal(dot)io>, "raam(dot)soft(at)gmail(dot)com" <raam(dot)soft(at)gmail(dot)com>, "nagaura(dot)ryohei(at)fujitsu(dot)com" <nagaura(dot)ryohei(at)fujitsu(dot)com>, "nagata(at)sraoss(dot)co(dot)jp" <nagata(at)sraoss(dot)co(dot)jp>, "peter(dot)eisentraut(at)2ndquadrant(dot)com" <peter(dot)eisentraut(at)2ndquadrant(dot)com>, 'Kyotaro HORIGUCHI' <horiguchi(dot)kyotaro(at)lab(dot)ntt(dot)co(dot)jp>, "k(dot)jamison(at)fujitsu(dot)com" <k(dot)jamison(at)fujitsu(dot)com>
Subject: Re: libpq debug log
Date: 2020-09-16 20:41:55
Message-ID: 20200916204155.GA28949@alvherre.pgsql
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: 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 Content-Type Size
v8-0001-libpq-trace-v8.patch text/x-diff 22.0 KB
v8-0002-Remove-use-of-obsolete-ftime.patch text/x-diff 3.0 KB

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Daniel Gustafsson 2020-09-16 21:17:46 Re: pgindent vs dtrace on macos
Previous Message Robert Haas 2020-09-16 19:33:53 Re: [Patch] ALTER SYSTEM READ ONLY