Thread

  1. RE: libpq debug log

    Aya Iwata (Fujitsu) <iwata.aya@fujitsu.com> — 2020-10-07T11:52:15Z

    Hi Alvaro san, 
    
    Thank you for your update :)
    
    > 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:
    I check code, changes and email. I agree with all of this. 
    I will review code, feature and performance if it is needed more closely. 
    (I'll start it next week.)
    
    Regards,
    Aya Iwata
    
    > -----Original Message-----
    > From: Alvaro Herrera <alvherre@2ndquadrant.com>
    > Sent: Thursday, September 17, 2020 5:42 AM
    > To: Iwata, Aya/岩田 彩 <iwata.aya@fujitsu.com>
    > Cc: pgsql-hackers@postgresql.org; tgl@sss.pgh.pa.us;
    > robertmhaas@gmail.com; pchampion@pivotal.io; jdoty@pivotal.io;
    > raam.soft@gmail.com; Nagaura, Ryohei/永浦 良平
    > <nagaura.ryohei@fujitsu.com>; nagata@sraoss.co.jp;
    > peter.eisentraut@2ndquadrant.com; 'Kyotaro HORIGUCHI'
    > <horiguchi.kyotaro@lab.ntt.co.jp>; Jamison, Kirk/ジャミソン カーク
    > <k.jamison@fujitsu.com>
    > Subject: Re: libpq debug log
    > 
    > 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