Re: libpq debug log

On Mon, Mar 4, 2019 at 3:13 AM Iwata, Aya <iwata.aya@jp.fujitsu.com> wrote:
> 2. Prepare "output level". There are 3 type of levels;
>         - TRADITIONAL   :  if set, outputs protocol messages
>         - LEVEL1                :  if set, outputs phase and time
>         - LEVEL2                :  if set, outputs both info TRADITIONAL and LEVEL1

I am not impressed by this proposal.  I think what we should be
focusing on here is how to clearly display the contents of a message.
I think we should be looking for a way to display each message on a
single line in a way that indicates the data types of the constituent
fields.  For example, here's a DataRow message as output by PQtrace
today:

From backend> D
From backend (#4)> 42
From backend (#2)> 4
From backend (#4)> 6
From backend (6)> public
From backend (#4)> 4
From backend (4)> tab1
From backend (#4)> 5
From backend (5)> table
From backend (#4)> 5
From backend (5)> rhaas

What I'd like to see for a case like this is something like:

<<< 'D' 42 #4 6 'public' 4 'tab1' 5 'table' 5 'rhaas'

And here's a RowDescription message today:

From backend> T
From backend (#4)> 101
From backend (#2)> 4
From backend> "Schema"
From backend (#4)> 2615
From backend (#2)> 2
From backend (#4)> 19
From backend (#2)> 64
From backend (#4)> -1
From backend (#2)> 0
From backend> "Name"
From backend (#4)> 1259
From backend (#2)> 2
From backend (#4)> 19
From backend (#2)> 64
From backend (#4)> -1
From backend (#2)> 0
From backend> "Type"
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> "Owner"
From backend (#4)> 0
From backend (#2)> 0
From backend (#4)> 19
From backend (#2)> 64
From backend (#4)> -1
From backend (#2)> 0

And I propose that it should look like this:

<<< 'T' 101 4 "Schema" 2615 #2 19 #64 -1 #0 "Name" 1259 #2 19 #64 -1
#0 "Owner" 0 #0 19 #64 -1 #0

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 ##.

Now if we want to timestamp those lines too, that'd be fine:

2019-03-04 21:33:39.338 EST <<< 'T' 101 4 "Schema" 2615 #2 19 #64 -1
#0 "Name" 1259 #2 19 #64 -1 #0 "Owner" 0 #0 19 #64 -1 #0
2019-03-04 21:33:39.342 EST <<< 'D' 42 #4 6 'public' 4 'tab1' 5
'table' 5 'rhaas'

But I still don't really see a need for different levels or whatever.
I mean, you either want a dump of all of the protocol traffic, or you
don't, I think.  Or maybe I am confused as to what the goal of all
this really is.

-- 
Robert Haas
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company