RE: libpq debug log

From: "Iwata, Aya" <iwata(dot)aya(at)jp(dot)fujitsu(dot)com>
To: 'Tom Lane' <tgl(at)sss(dot)pgh(dot)pa(dot)us>, Robert Haas <robertmhaas(at)gmail(dot)com>, "Jacob Champion" <pchampion(at)pivotal(dot)io>, Jim Doty <jdoty(at)pivotal(dot)io>, "'raam(dot)soft(at)gmail(dot)com'" <raam(dot)soft(at)gmail(dot)com>
Cc: "Jamison, Kirk" <k(dot)jamison(at)jp(dot)fujitsu(dot)com>, "Nagaura, Ryohei" <nagaura(dot)ryohei(at)jp(dot)fujitsu(dot)com>, PostgreSQL mailing lists <pgsql-hackers(at)postgresql(dot)org>, "nagata(at)sraoss(dot)co(dot)jp" <nagata(at)sraoss(dot)co(dot)jp>, Haribabu Kommi <kommi(dot)haribabu(at)gmail(dot)com>, Peter Eisentraut <peter(dot)eisentraut(at)2ndquadrant(dot)com>, 'Kyotaro HORIGUCHI' <horiguchi(dot)kyotaro(at)lab(dot)ntt(dot)co(dot)jp>
Subject: RE: libpq debug log
Date: 2019-04-05 02:42:35
Message-ID: 71E660EB361DF14299875B198D4CE5423DF14F1C@g01jpexmbkw25
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

Hi,

> The basic idea being:
>
> - Each line is a whole message.
> - The line begins with <<< for a message received and >>> for a message sent.
> - Strings in single quotes are those sent/received as a fixed number of bytes.
> - Strings in double quotes are those sent/received as a string.
> - 4-byte integers are printed unadorned.
> - 2-byte integers are prefixed by #.
> - I guess 1-byte integers would need some other prefix, maybe @ or ##.

I created v1 patch to improve PQtrace(); output log message in one line.
Please find my attached patch.

Log output examples;

In current PQtrace log:

To backend> Msg Q
To backend> "SELECT pg_catalog.set_config('search_path', '', false)"
To backend> Msg complete, length 60

I changed like this:

2019-04-04 02:39:51.488 UTC > Query 59 "SELECT pg_catalog.set_config('search_path', '', false)"

In current PQtrace log:

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

I changed like this:

2019-04-04 02:39:51.489 UTC < RowDescription 35 #1 "set_config" 0 #0 25 #65535 -1 #0

> I would like to add timestamp per line and when command processing function
> start/end.
> I think it is useful to know the application process start/end for diagnosis.
> So I will implement like this;
>
> 2019-03-03 07:24:54.142 UTC PQgetResult start
> 2019-03-03 07:24:54.143 UTC < 'T' 35 1 "set_config" 0 #0 25 #65535 -1 #0
> 2019-03-03 07:24:54.144 UTC PQgetResult end
I would like to add this in next patch if there are not any disagreement.

Regards,
Aya Iwata

Attachment Content-Type Size
v1-0001-libpq-PQtrace-output_one_line.patch application/octet-stream 16.4 KB

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Stephen Frost 2019-04-05 02:59:25 Re: [PATCH v20] GSSAPI encryption support
Previous Message Imai, Yoshikazu 2019-04-05 01:54:23 RE: Speed up transaction completion faster after many relations are accessed in a transaction