Re: RFC: Logging plan of the running query

From: Ashutosh Bapat <ashutosh(dot)bapat(dot)oss(at)gmail(dot)com>
To: torikoshia <torikoshia(at)oss(dot)nttdata(dot)com>
Cc: Étienne BERSAC <etienne(dot)bersac(at)dalibo(dot)com>, Andres Freund <andres(at)anarazel(dot)de>, jtc331(at)gmail(dot)com, pgsql-hackers(at)lists(dot)postgresql(dot)org
Subject: Re: RFC: Logging plan of the running query
Date: 2023-11-09 07:11:49
Message-ID: CAExHW5utSXjEMh6BWBPEe3Ks70T12VcGZqR8YH1owhZoROv4fw@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

On Thu, Nov 9, 2023 at 12:03 PM torikoshia <torikoshia(at)oss(dot)nttdata(dot)com> wrote:
> >>
> >> 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.
>
> This was discussed in previous threads[1] and we thought it'd be useful
> but since it needed some extra works, we stopped widening the scope.
>
> >
> > I think we can start with what auto_explain is doing. Always print the
> > plan of the outermost query; the query found in pg_stat_activity. In a
> > later version we might find a way to print plans of all the queries in
> > the stack and do so in a readable manner.
>
> Agreed there are cases printing plan of the outermost query is more
> useful.
>

I am fine printing the plan of the outermost query. This will help
many cases. Printing plans of the whole query stack can be added as an
add on later.

> >
> > This makes tracking activeQueryDesc a bit tricky. My guess is that the
> > outermost query's descriptor will be available through ActivePortal
> > most of the time. But there are cases when ExecutorRun is called by
> > passing a queryDesc directly. So may be there are some cases where
> > that's not true.
>
> Yeah, actually the original version of the patch got the plan from
> ActivePortal, but it failed logging plan when the query was something
> like this[2]:
>
> DO $$
> BEGIN
> PERFORM pg_sleep(100);
> END$$;

References [1] and [2] are not listed in your email.

Is that because there was no ActivePortal created or the ActivePortal
pointed to DO block instead of PERFORM pg_sleep?

>
> > 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.
>
> I think it can be useful.
> I'm wondering if we can add this after the first patch for this feature
> is committed.

With the current patches, it will print the query from a parallel
backend. If that's not desirable we should prohibit that case at
least.

--
Best Wishes,
Ashutosh Bapat

In response to

Responses

Browse pgsql-hackers by date

  From Date Subject
Next Message Ashutosh Bapat 2023-11-09 07:15:01 Re: Infinite Interval
Previous Message Michael Paquier 2023-11-09 07:08:38 Re: A recent message added to pg_upgade