Re: RFC: Logging plan of the running query

On 2026-07-14 16:07, Andrei Lepikhov wrote:
> On 13/07/2026 15:35, torikoshia wrote:
>> On 2026-07-13 08:28, Andrei Lepikhov wrote:
>>> So, it potentially makes sense to add a statistics field to the
>>> activity stat to
>>> let users know whether the logging (and how many signals, if replace
>>> flag with a
>>> counter) is awaiting execution.
>>
>> That might be useful for some users, but personally I feel that adding
>> a column to pg_stat_activity solely for pg_log_query_plan() might be
>> excessive.
>
> That part is just an idea. I think it might help if the activity
> statistics had
> a variable-length JSON field where the backend could write some rarely
> used flags.

I think it would be worth trying this if we can identify some other
candidates
for rarely used flags.

>>> Maybe it doesn't need to clean up the 'pending' flag at all if no
>>> query has been
>>> executed yet - the query might be under planning, and the EXPLAIN
>>> will be logged
>>> right at the beginning of execution.
>>
>> Without this cleanup, as the comment says, the plan could instead be
>> logged when a different query is subsequently executed in the same
>> session. I imagine users don't expect this behavior.
>
> Hmmm, asynchronous feature that explains an arbitrary part of the query
> - for
> example, some query inside an evaluated plpgsql function ... I think it
> is
> expected by design.

Even when execution moves to an outer or deeper QueryDesc in this way,
the LogQueryPlanPending flag remains set, so the plan is logged. [1]

The plan is not logged when there is no subsequent opportunity to call
ExecProcNode(), including in any outer or deeper QueryDesc, as in the
example using PREPARE that you showed in your previous message.

My concern is whether, without the pending flag, it would be
appropriate to log the plan of a different query subsequently
executed by the same backend.

For example, suppose a user calls pg_log_query_plan() expecting
the plan of query A to be logged, but there is no opportunity
to do so. If query B is then executed by the same backend one
hour later, the plan of query B would be logged at that point.
This does not seem like behavior that users would expect.
What do you think?

Personally, I still think it might be preferable to emit a log
message at the end of standard_ExecutorRun() indicating that
there was no opportunity to log the plan.

> Also, this feature prints the query, so there is no room for a
> mismatch. I think
> it should print queryId and let people identify specific EXPLAIN more
> easily -
> imagine GB-scale log with multiple explains.

Attached patch has changed it to print the query ID as well.

The default 'verbose' mode could
> also be helpful.

Regarding this point, the current default was chosen based on
the discussion[2].
I think the part of VERBOSE that helps identify the query is
primarily the query ID. If the query ID is included in the log
message, it may not be necessary to add VERBOSE for this purpose.

>
>>   +               ereport(LOG,
>>   +                               errmsg("query plan logging was
>> requested but
>> there was no opportunity to do it"));
>>   +               LogQueryPlanPending = false;
>>   +       }
>>    }
>>
>> What do you think about this approach?
>
> It reduces uncertainty but I think we can do more.
>
>>> In addition, I wonder why this code doesn't use standard planstate
>>> walker. It
>>> seems to me that something like the following should work:
>>
>> As discussed in [2], the set of nodes handled here slightly differs
>> from that handled by planstate_tree_walker_impl(), so I'd like
>> to confirm whether it is appropriate to use the standard walker here.
> As correctly mentioned in [2], we don't need any special processing for
> CTEScan.
> So, I think the planstate walker is a correct tool to pass the tree.

I confirmed that planstate_tree_walker() also handles the case I was
concerned about correctly, so attached patch changes the code to use it.

[1]
https://www.postgresql.org/message-id/c3cbd6ae775dff9603ce0d724bb7ea1b%40oss.nttdata.com
[2]
https://www.postgresql.org/message-id/57ee0cf0cf76b742b0144bd481c56b57%40oss.nttdata.com

--
Thanks,

--
Atsushi Torikoshi
Seconded from NTT DATA CORPORATION to SRA OSS K.K.