Re: libpq debug log

Haribabu Kommi <kommi.haribabu@gmail.com>

From: Haribabu Kommi <kommi.haribabu@gmail.com>
To: iwata.aya@jp.fujitsu.com
Cc: Pg Hackers <pgsql-hackers@postgresql.org>, nagata@sraoss.co.jp, Peter Eisentraut <peter.eisentraut@2ndquadrant.com>, Tom Lane <tgl@sss.pgh.pa.us>
Date: 2018-11-13T07:16:04Z
Lists: 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

Commits

  1. Rename PQtraceSetFlags() to PQsetTraceFlags().

  2. Suppress length of Notice/Error msgs in PQtrace regress mode

  3. Strip file names reported in error messages on Windows, too.

  4. Fix setvbuf()-induced crash in libpq_pipeline

  5. libpq_pipeline: Must strdup(optarg) to avoid crash

  6. Remove setvbuf() call from PQtrace()

  7. Initialize conn->Pfdebug to NULL when creating a connection

  8. Disable force_parallel_mode in libpq_pipeline

  9. libpq_pipeline: add PQtrace() support and tests

  10. Improve PQtrace() output format

  11. Re-simplify management of inStart in pqParseInput3's subroutines.