Re: RFC: Logging plan of the running query

Ashutosh Bapat <ashutosh.bapat.oss@gmail.com>

From: Ashutosh Bapat <ashutosh.bapat.oss@gmail.com>
To: Étienne BERSAC <etienne.bersac@dalibo.com>, torikoshia <torikoshia@oss.nttdata.com>
Cc: Andres Freund <andres@anarazel.de>, jtc331@gmail.com, pgsql-hackers@lists.postgresql.org
Date: 2023-11-03T14:01:14Z
Lists: pgsql-hackers

Commits

Same data as JSON: GET /api/v1/messages/:b64id/commits the thread's linked commits as JSON, with link sources. API reference →
  1. ecpg: Catch zero-length Unicode identifiers correctly

  2. Improve warning message in pg_signal_backend()

  3. Add assert to ensure that page locks don't participate in deadlock cycle.

I have following questions related to the functionality. (Please point
me to the relevant discussion if this has been already discussed.)

1. When a backend is running nested queries, we will see the plan of
the innermost query. That query may not be the actual culprit if the
user query is running slowly. E.g a query being run as part of inner
side nested loop when the nested loop itself is the bottleneck. I
think it will be useful to print plans of all the whole query stack.

2. When a query is running in parallel worker do we want to print that
query? It may or may not be interesting given the situation. If the
overall plan itself is faulty, output of the parallel worker query is
not useful. If the plan is fine but a given worker's leg is running
slowly it may be interesting.

As a side note, you may want to fix the indentation in
ExplainAssembleLogOutput().

On Fri, Oct 27, 2023 at 6:24 PM Étienne BERSAC
<etienne.bersac@dalibo.com> wrote:
>
> > Hi,
> >
>
> > If we use client log message, that message is shown on the target
> > process whose pid is specified by the parameter of
> > pg_log_query_plan():
> >
> >    (pid:1000)=# select pg_sleep(60);
> >    (pid:1001)=# select pg_log_query_plan(1000);
> >    (pid:1000)=# LOG:  query plan running on backend with PID 1000 is:
> >                 Query Text: select pg_sleep(1000);
> >                 Result  (cost=0.00..0.01 rows=1 width=4)
> >                   Output: pg_sleep('1000'::double precision)
> >
> > I think this is not an expected behavior and we set elevel to
> > LOG_SERVER_ONLY.
>
>
> Makes sens. Thanks.

-- 
Best Wishes,
Ashutosh Bapat