Re: libpq debug log - Mailing list pgsql-hackers

From Haribabu Kommi
Subject Re: libpq debug log
Date
Msg-id CAJrrPGcFMhPL=MFKpOEvFrRmcvQdC=AWqi_7w46Fxi7maLF7XA@mail.gmail.com
Whole thread Raw
In response to RE: libpq debug log  ("Iwata, Aya" <iwata.aya@jp.fujitsu.com>)
Responses RE: libpq debug log
List pgsql-hackers

On Tue, Oct 30, 2018 at 8:38 PM Iwata, Aya <iwata.aya@jp.fujitsu.com> wrote:
Hi,

I create a first libpq trace log patch.

In this patch,
- All message that PQtrace() gets are output to the libpq trace log file
  (I maybe select more effective message in the future patch)
- Trace log output style is changed slightly from previously proposed

This patch not include documentation,
but you can see parameter detail and how to use it by looking at my previous e-mail.

 If get the trace log, set PGLOGDIR/logdir and PGLOGSIZE/logsize.
 These parameters are set in the environment variable or the connection service
 file.
 - logdir or PGLOGDIR : directory where log file written
 - logsize or PGLOGSIZE : maximum log size(M). When the log file size exceeds to
 PGLOGSIZE, the log is output to another file.

 The log file name is determined as follow.
 libpq-%ProcessID-%Y-%m-%d_%H%M%S.log

Trace log example;
Start :  2018/10/30 08:02:24.433                                        ... time(a)
Query: SELECT pg_catalog.set_config('search_path', '', false)
To backend> Msg Q
To backend> "SELECT pg_catalog.set_config('search_path', '', false)"
To backend> Msg complete, length 60
Start sending message to backend:  2018/10/30 08:02:24.433              ... time(b)
End sending message to backend:  2018/10/30 08:02:24.433                ... time(c)
Start receiving message from backend:  2018/10/30 08:02:24.434  ... time(d)
End receiving message from backend:  2018/10/30 08:02:24.434    ... time(e)
From backend> T
From backend (#4)> 35
From backend (#2)> 1
From backend> "set_config"
From backend (#4)> 0
From backend (#2)> 0
From backend (#4)> 25
From backend (#2)> 65535
From backend (#4)> -1
From backend (#2)> 0
From backend> D
From backend (#4)> 10
From backend (#2)> 1
From backend (#4)> 0
From backend> C
From backend (#4)> 13
From backend> "SELECT 1"
From backend> Z
From backend (#4)> 5
From backend> Z
From backend (#4)> 5
From backend> I
End :  2018/10/30 08:02:24.435                                  ... time(f)

From time(a) to time(b): time for libpq processing
From time(b) to time(c): time for traffic
From time(c) to time(d): time for backend processing
From time(d) to time(e): time for traffic
From time(e) to time(f): time for libpq processing

Thanks for the patch.

I have some comments related to the trace output that is getting
printed. The amount of log it is generating may not be understood
to many of the application developers. IMO, this should print
only the necessary information that can understood by any one
by default and full log with more configuration?

Regards,
Haribabu Kommi
Fujitsu Australia

pgsql-hackers by date:

Previous
From: Haribabu Kommi
Date:
Subject: Re: Libpq support to connect to standby server as priority
Next
From: David Rowley
Date:
Subject: Re: PostgreSQL Limits and lack of documentation about them.