RE: libpq debug log - Mailing list pgsql-hackers

From Iwata, Aya
Subject RE: libpq debug log
Date
Msg-id 71E660EB361DF14299875B198D4CE5423DE4A154@g01jpexmbkw25
Whole thread Raw
In response to Re: libpq debug log  (Yugo Nagata <nagata@sraoss.co.jp>)
Responses Re: libpq debug log
Re: libpq debug log
List pgsql-hackers
> > I'm going to propose libpq debug log for analysis of queries on the application
> side.
> > I think that it is useful to determine whether the cause is on the application
> side or the server side when a slow query occurs.
> 
> Do you mean you want to monitor the protocol message exchange at the client
> side to analyze performance issues, right?  Actually, this might be useful to
> determin where is the problem, for example, the client application, the backend
> PostgreSQL, or somewhere in the network.
> 
> Such logging can be implemented in the application, but if libpq provides the
> standard way, it would be helpful to resolve a problem without modifying the
> application code.

Since I'd like to monitor the information the server and the client exchange,
I think monitoring protocol messages is good.

When a slow query is occurs, we check this client side trace log.
The purpose of this log acquisition I thought is to identify where is the problem: 
server side, application side or traffic. 
And if the problem is in application side, checking the trace log to identify what is the problem.

> > The provided information is "date and time" at which execution of processing
> is started, "query", "application side processing", which is picked up
> information from PQtrace(), and "connection id", which is for uniquely
> identifying the connection.
> 
> I couldn't image how this is like. Could you show us a sample of log lines in
> your head?

I am roughly thinking as follows;

...
START : 2018/09/03 18:16:35.357 CONNECTION(1)
STATUS : Connection
SEND MESSAGE : 2018/09/03 18:16:35.358
<information send to backend...>
RECEIVE MESSAGE : 2018/09/03 18:16:35.359
<information receive from backend...>
END : 2018/09/03 18:16:35.360
...
START : 2018/09/03 18:16:35.357 CONNECTION(1)
QUERY : DECLARE myportal CURSOR FOR select * from pg_database
SEND MESSAGE : 2018/09/03 18:16:35.358
<information send to backend...>
RECEIVE MESSAGE : 2018/09/03 18:16:35.359
<information receive from backend...>
END : 2018/09/03 18:16:35.360
...

> > To collect the log, set the connection string or environment variable.
> > - logdir or PGLOGDIR : directory where log file written
> > - logsize or PGLOGSIZE : maximum log size
> 
> How we can specify the log file name?  What should happen if a file size exceeds
> to PGLOGSIZE?

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

When the log file size exceeds to PGLOGSIZE, the log is output to another file.

Regards,
Aya Iwata



pgsql-hackers by date:

Previous
From: Michael Paquier
Date:
Subject: Re: Loaded footgun open_datasync on Windows
Next
From: Andres Freund
Date:
Subject: Re: Pluggable Storage - Andres's take