On 2025-09-25 01:34, Robert Haas wrote:
On Fri, Sep 19, 2025 at 8:42 AM torikoshia <[email protected]>
wrote:
> Yes, it seems as though we should set a flag to prevent reentrancy
> here -- if we are already in the code path where we log the query
> plan, we shouldn't accept an interrupt telling us to log the query
> plan. I haven't looked at the updated patch so maybe that's not
> necessary for some reason, but in general reentrancy is a concern with
> features of this type.
Agreed. In the attached patch added a flag.
This doesn't look safe. If we error out of the section where the flag
is set to true, it will remain true forever.
Ugh.. Updated the patch to reset the flag even when an error occurs,
using PG_FINALLY(), similar to [1].
[1]
https://www.postgresql.org/message-id/27da56de-17c4-4af2-8032-3c58ae0c7b00%40oss.nttdata.com
So I think it would be fine to remove the PID from
pg_log_backend_memory_contexts()’s log message when this patch is
merged.
Let's leave the PID in there for now for consistency with the existing
message. We can discuss changing it at another time.
Agreed.
To detect “when the current (sub)transaction is (sub)aborted,”
attached
patch uses IsTransactionState().
With that, the logging code is not executed when the transaction state
is anything other than TRANS_INPROGRESS, and in some cases this works
as
expected.
On the other hand, when calling pg_log_query_plan() repeatedly during
make installcheck, I still encountered cases where segfaults occurred.
Specifically, this seems to happen when, after a (sub)abort, the next
query starts in the same session and a CFI() occurs after
StartTransaction() has been executed but before Executor() runs. In
that case, the transaction state has already been changed to
TRANS_INPROGRESS by StartTransaction(), but the QueryDesc from the
aborted transaction is still present, which causes the problem.
To address this, attached patch initializes QueryDesc within
CleanupTransaction().
Since this function already resets various members of
CurrentTransactionState, I feel it’s not so unreasonable to initialize
QueryDesc there as well.
Does this approach make sense, or is it problematic?
Hmm, I think it looks quite odd. I believe it's quite intentional that
the very last thing that CleanupTransaction does is reset s->state, so
I don't think we should be doing this after that. But also, this leads
to an odd inconsistency between CleanupTransaction and
CleanupSubTransaction.
Make sense.
What I'm wondering is whether we should instead
reset s->queryDesc inside AbortTransaction() and
AbortSubTransaction(). Perhaps if we do that, then we don't need an
InTransactionState() test elsewhere. What do you think?
Resetting QueryDesc in AbortTransaction() and AbortSubTransaction() was
what we did in an earlier version of the patch (before v46), so that
doesn’t feel strange to me.
Updated the patch and confirmed that we can still log the parent’s plan
in cases where subtransactions continuously abort, following the same
steps as [2].
[2]
https://www.postgresql.org/message-id/6143f00af4bfdba95a85cf866f4acb41%40oss.nttdata.com
\> > > Changed it to the following query:
> >
> > WITH t AS MATERIALIZED (SELECT pg_log_query_plan(pg_backend_pid()))
> > SELECT * FROM t;
>
> I don't see why that wouldn't have a race condition?
The idea is that (1) pg_log_query_plan() in the WITH clause wraps
ExecProcNode, and then (2) SELECT * FROM t invokes ExecProcNode, which
causes the plan to be logged. I think that’s what currently happens
on
HEAD.
When you mention a "race condition", do you mean that if the timing of
the wrapping in step (1) -- that is, when CFI() is called -- changes
in
the future, then the logging might not work?
I don't think we're guaranteed that the signal is delivered instantly,
so it seems possible to me that (1) would happen after (2).
True, but I haven’t found a reliable way to trigger actual logging
within a single backend query.
I was also considering using an isolation test and injection points,
like in the attached PoC patch. The main steps are:
In session1, set an injection point to wait during query execution.
In session1, run a query that waits at the injection point.
In session2, call pg_log_query_plan().
In session2, wake up session1.
However, as you pointed out, since the signals are not guaranteed to be
delivered instantly, I’m worried that the query could complete before
the signal is delivered, causing test instability.
Additionally, for a similar function that logs information via signal
delivery, pg_log_backend_memory_contexts(), the existing tests only
verify that the function succeeds and that permission checks work as
described in the comment below; I'm a bit concerned that this might be
overkill.
-- pg_log_backend_memory_contexts()
--
-- Memory contexts are logged and they are not returned to the
function.
-- Furthermore, their contents can vary depending on the timing.
However,
-- we can at least verify that the code doesn't fail, and that the
-- permissions are set properly.
If we align with that test strategy, just executing SELECT
pg_log_query_plan(pg_backend_pid()) and verifying that it succeeds would
be enough.
However, unlike pg_log_backend_memory_contexts(), this function doesn’t
log anything for this query. I’m not sure if that’s acceptable.
I’d appreciate any thoughts or suggestions on what kind of test coverage
would be appropriate here.
BTW I haven’t looked into this in detail yet, but I’m a little curious
whether the absence of T_CteScan in functions like
planstate_tree_walker_impl() is intentional.
I don't think that function needs any special handling for T_CteScan.
planstate_tree_walker_impl() and other functions need special handling
for cases where a node has children that are not in the lefttree,
righttree, initPlan list, or subPlan list; but a CteScan has no extra
Plan pointer:
typedef struct CteScan
{
Scan scan;
/* ID of init SubPlan for CTE */
int ctePlanId;
/* ID of Param representing CTE output */
int cteParam;
} CteScan;
Thanks for looking into this! understood.
--
Regards,
--
Atsushi Torikoshi
Seconded from NTT DATA Japan Corporation to SRA OSS K.K.
From 3089479df3bd3c3e4d996b1e20d4ebfd67aa82c4 Mon Sep 17 00:00:00 2001
From: Atsushi Torikoshi <[email protected]>
Date: Wed, 1 Oct 2025 17:50:28 +0900
Subject: [PATCH v49] Add function to log the plan of the currently running
query
Currently, we have to wait for the query execution to finish
to know its plan either using EXPLAIN ANALYZE or auto_explain.
This is not so convenient, for example when investigating
long-running queries on production environments.
To improve this situation, this patch adds pg_log_query_plan()
function that requests to log the plan of the currently
executing query.
On receipt of the request, ExecProcNodes of the current plan
node and its subsidiary nodes are wrapped with
ExecProcNodeFirst, which implelements logging query plan.
When executor executes the one of the wrapped nodes, the
query plan is logged.
Our initial idea was to send a signal to the target backend
process, which invokes EXPLAIN logic at the next
CHECK_FOR_INTERRUPTS() call. However, we realized during
prototyping that EXPLAIN is complex and may not be safely
executed at arbitrary interrupt points.
By default, only superusers are allowed to request to log the
plans because allowing any users to issue this request at an
unbounded rate would cause lots of log messages and which can
lead to denial of service.
Todo: Consider removing the PID from the log output of
pg_log_backend_memory_contexts() and pg_log_query_plan().
For detail, see the discussion:
https://www.postgresql.org/message-id/CA%2BTgmoY81r7npTS34N_5MLA_u6ghfor5HoSaar53veXUYu1OxQ%40mail.gmail.com
---
contrib/auto_explain/auto_explain.c | 24 +--
doc/src/sgml/func/func-admin.sgml | 24 +++
src/backend/access/transam/xact.c | 34 ++++
src/backend/catalog/system_functions.sql | 2 +
src/backend/commands/Makefile | 1 +
src/backend/commands/dynamic_explain.c | 183 +++++++++++++++++++
src/backend/commands/explain.c | 38 +++-
src/backend/commands/meson.build | 1 +
src/backend/executor/execMain.c | 17 ++
src/backend/executor/execProcnode.c | 123 ++++++++++++-
src/backend/storage/ipc/procsignal.c | 4 +
src/backend/tcop/postgres.c | 4 +
src/backend/utils/init/globals.c | 2 +
src/include/access/xact.h | 3 +
src/include/catalog/pg_proc.dat | 6 +
src/include/commands/dynamic_explain.h | 25 +++
src/include/commands/explain.h | 9 +-
src/include/commands/explain_state.h | 1 +
src/include/executor/executor.h | 1 +
src/include/miscadmin.h | 1 +
src/include/storage/procsignal.h | 2 +
src/test/regress/expected/misc_functions.out | 42 +++++
src/test/regress/sql/misc_functions.sql | 31 ++++
23 files changed, 544 insertions(+), 34 deletions(-)
create mode 100644 src/backend/commands/dynamic_explain.c
create mode 100644 src/include/commands/dynamic_explain.h
diff --git a/contrib/auto_explain/auto_explain.c b/contrib/auto_explain/auto_explain.c
index 1f4badb4928..6c4217c9d1f 100644
--- a/contrib/auto_explain/auto_explain.c
+++ b/contrib/auto_explain/auto_explain.c
@@ -15,6 +15,7 @@
#include <limits.h>
#include "access/parallel.h"
+#include "commands/dynamic_explain.h"
#include "commands/explain.h"
#include "commands/explain_format.h"
#include "commands/explain_state.h"
@@ -404,26 +405,9 @@ explain_ExecutorEnd(QueryDesc *queryDesc)
es->format = auto_explain_log_format;
es->settings = auto_explain_log_settings;
- ExplainBeginOutput(es);
- ExplainQueryText(es, queryDesc);
- ExplainQueryParameters(es, queryDesc->params, auto_explain_log_parameter_max_length);
- ExplainPrintPlan(es, queryDesc);
- if (es->analyze && auto_explain_log_triggers)
- ExplainPrintTriggers(es, queryDesc);
- if (es->costs)
- ExplainPrintJITSummary(es, queryDesc);
- ExplainEndOutput(es);
-
- /* Remove last line break */
- if (es->str->len > 0 && es->str->data[es->str->len - 1] == '\n')
- es->str->data[--es->str->len] = '\0';
-
- /* Fix JSON to output an object */
- if (auto_explain_log_format == EXPLAIN_FORMAT_JSON)
- {
- es->str->data[0] = '{';
- es->str->data[es->str->len - 1] = '}';
- }
+ ExplainStringAssemble(es, queryDesc, auto_explain_log_format,
+ auto_explain_log_triggers,
+ auto_explain_log_parameter_max_length);
/*
* Note: we rely on the existing logging of context or
diff --git a/doc/src/sgml/func/func-admin.sgml b/doc/src/sgml/func/func-admin.sgml
index 1b465bc8ba7..66bfb5ab4df 100644
--- a/doc/src/sgml/func/func-admin.sgml
+++ b/doc/src/sgml/func/func-admin.sgml
@@ -184,6 +184,30 @@
</para></entry>
</row>
+ <row>
+ <entry role="func_table_entry"><para role="func_signature">
+ <indexterm>
+ <primary>pg_log_query_plan</primary>
+ </indexterm>
+ <function>pg_log_query_plan</function> ( <parameter>pid</parameter> <type>integer</type> )
+ <returnvalue>boolean</returnvalue>
+ </para>
+ <para>
+ Requests to log the plan of the query currently running on the
+ backend with specified process ID.
+ It will be logged at <literal>LOG</literal> message level and
+ will appear in the server log based on the log
+ configuration set (See <xref linkend="runtime-config-logging"/>
+ for more information), but will not be sent to the client
+ regardless of <xref linkend="guc-client-min-messages"/>.
+ </para>
+ <para>
+ This function is restricted to superusers by default, but other
+ users can be granted EXECUTE to run the function.
+ </para></entry>
+ </row>
+
+
<row>
<entry role="func_table_entry"><para role="func_signature">
<indexterm>
diff --git a/src/backend/access/transam/xact.c b/src/backend/access/transam/xact.c
index 2cf3d4e92b7..56c3c196f45 100644
--- a/src/backend/access/transam/xact.c
+++ b/src/backend/access/transam/xact.c
@@ -36,6 +36,7 @@
#include "catalog/pg_enum.h"
#include "catalog/storage.h"
#include "commands/async.h"
+#include "commands/dynamic_explain.h"
#include "commands/tablecmds.h"
#include "commands/trigger.h"
#include "common/pg_prng.h"
@@ -215,6 +216,7 @@ typedef struct TransactionStateData
bool parallelChildXact; /* is any parent transaction parallel? */
bool chain; /* start a new block after this one */
bool topXidLogged; /* for a subxact: is top-level XID logged? */
+ QueryDesc *queryDesc; /* my current QueryDesc */
struct TransactionStateData *parent; /* back link to parent */
} TransactionStateData;
@@ -248,6 +250,7 @@ static TransactionStateData TopTransactionStateData = {
.state = TRANS_DEFAULT,
.blockState = TBLOCK_DEFAULT,
.topXidLogged = false,
+ .queryDesc = NULL,
};
/*
@@ -933,6 +936,27 @@ GetCurrentTransactionNestLevel(void)
return s->nestingLevel;
}
+/*
+ * SetCurrentQueryDesc
+ */
+void
+SetCurrentQueryDesc(QueryDesc *queryDesc)
+{
+ TransactionState s = CurrentTransactionState;
+
+ s->queryDesc = queryDesc;
+}
+
+/*
+ * GetCurrentQueryDesc
+ */
+QueryDesc *
+GetCurrentQueryDesc(void)
+{
+ TransactionState s = CurrentTransactionState;
+
+ return s->queryDesc;
+}
/*
* TransactionIdIsCurrentTransactionId
@@ -2916,6 +2940,9 @@ AbortTransaction(void)
/* Reset snapshot export state. */
SnapBuildResetExportedSnapshotState();
+ /* Reset current query plan state used for logging. */
+ SetCurrentQueryDesc(NULL);
+
/*
* If this xact has started any unfinished parallel operation, clean up
* its workers and exit parallel mode. Don't warn about leaked resources.
@@ -5308,6 +5335,13 @@ AbortSubTransaction(void)
/* Reset logical streaming state. */
ResetLogicalStreamingState();
+ /*
+ * Reset current query plan state used for logging. Note that even after
+ * this reset, it's still possible to obtain the parent transaction's
+ * query plans, since they are preserved in standard_ExecutorRun().
+ */
+ SetCurrentQueryDesc(NULL);
+
/*
* No need for SnapBuildResetExportedSnapshotState() here, snapshot
* exports are not supported in subtransactions.
diff --git a/src/backend/catalog/system_functions.sql b/src/backend/catalog/system_functions.sql
index 2d946d6d9e9..67beafcc82c 100644
--- a/src/backend/catalog/system_functions.sql
+++ b/src/backend/catalog/system_functions.sql
@@ -782,6 +782,8 @@ REVOKE EXECUTE ON FUNCTION pg_ls_logicalmapdir() FROM PUBLIC;
REVOKE EXECUTE ON FUNCTION pg_ls_replslotdir(text) FROM PUBLIC;
+REVOKE EXECUTE ON FUNCTION pg_log_query_plan(integer) FROM PUBLIC;
+
--
-- We also set up some things as accessible to standard roles.
--
diff --git a/src/backend/commands/Makefile b/src/backend/commands/Makefile
index cb2fbdc7c60..5e83907eb17 100644
--- a/src/backend/commands/Makefile
+++ b/src/backend/commands/Makefile
@@ -32,6 +32,7 @@ OBJS = \
define.o \
discard.o \
dropcmds.o \
+ dynamic_explain.o \
event_trigger.o \
explain.o \
explain_dr.o \
diff --git a/src/backend/commands/dynamic_explain.c b/src/backend/commands/dynamic_explain.c
new file mode 100644
index 00000000000..b21a51aafe4
--- /dev/null
+++ b/src/backend/commands/dynamic_explain.c
@@ -0,0 +1,183 @@
+/*-------------------------------------------------------------------------
+ *
+ * dynamic_explain.c
+ * Explain query plans during execution
+ *
+ * Portions Copyright (c) 1996-2025, PostgreSQL Global Development Group
+ * Portions Copyright (c) 1994-5, Regents of the University of California
+ *
+ * IDENTIFICATION
+ * src/backend/commands/dynamic_explain.c
+ *
+ *-------------------------------------------------------------------------
+ */
+#include "postgres.h"
+
+#include "access/xact.h"
+#include "commands/dynamic_explain.h"
+#include "commands/explain.h"
+#include "commands/explain_format.h"
+#include "commands/explain_state.h"
+#include "miscadmin.h"
+#include "storage/proc.h"
+#include "storage/procarray.h"
+#include "utils/backend_status.h"
+
+/* Is plan node wrapping for query plan logging currently in progress? */
+static bool WrapNodesInProgress = false;
+
+/*
+ * Handle receipt of an interrupt indicating logging the plan of the currently
+ * running query.
+ *
+ * All the actual work is deferred to ProcessLogQueryPlanInterrupt(),
+ * because we cannot safely emit a log message inside the signal handler.
+ */
+void
+HandleLogQueryPlanInterrupt(void)
+{
+ InterruptPending = true;
+ LogQueryPlanPending = true;
+ /* latch will be set by procsignal_sigusr1_handler */
+}
+
+/*
+ * Actual plan logging function.
+ */
+void
+LogQueryPlan(void)
+{
+ ExplainState *es;
+ MemoryContext cxt;
+ MemoryContext old_cxt;
+ QueryDesc *queryDesc;
+
+ cxt = AllocSetContextCreate(CurrentMemoryContext,
+ "log_query_plan temporary context",
+ ALLOCSET_DEFAULT_SIZES);
+
+ old_cxt = MemoryContextSwitchTo(cxt);
+
+ es = NewExplainState();
+
+ es->format = EXPLAIN_FORMAT_TEXT;
+ es->settings = true;
+ es->verbose = true;
+ es->signaled = true;
+
+ /*
+ * Current QueryDesc is valid only during standard_ExecutorRun. However,
+ * ExecProcNode can be called afterward(i.e., ExecPostprocessPlan). To
+ * handle the case, check whether we have QueryDesc now.
+ */
+ queryDesc = GetCurrentQueryDesc();
+
+ if (queryDesc == NULL)
+ {
+ LogQueryPlanPending = false;
+ return;
+ }
+
+ ExplainStringAssemble(es, queryDesc, es->format, 0, -1);
+
+ ereport(LOG_SERVER_ONLY,
+ errmsg("query and its plan running on backend with PID %d are:\n%s",
+ MyProcPid, es->str->data));
+
+ MemoryContextSwitchTo(old_cxt);
+ MemoryContextDelete(cxt);
+
+ LogQueryPlanPending = false;
+}
+
+/*
+ * Process the request for logging query plan at CHECK_FOR_INTERRUPTS().
+ *
+ * Since executing EXPLAIN-related code at an arbitrary CHECK_FOR_INTERRUPTS()
+ * point is potentially unsafe, this function just wraps the nodes of
+ * ExecProcNode with ExecProcNodeFirst, which logs query plan if requested.
+ * This way ensures that EXPLAIN-related code is executed only during
+ * ExecProcNodeFirst, where it is considered safe.
+ */
+void
+ProcessLogQueryPlanInterrupt(void)
+{
+ QueryDesc *querydesc = GetCurrentQueryDesc();
+
+ /* If current query has already finished, we can do nothing but exit */
+ if (querydesc == NULL)
+ {
+ LogQueryPlanPending = false;
+ return;
+ }
+
+ /*
+ * Exit immediately if wrapping plan is already in progress. This prevents
+ * recursive calls, which could occur if logging is requested repeatedly and
+ * rapidly, potentially leading to infinite recursion and crash.
+ */
+ if (WrapNodesInProgress)
+ return;
+
+ WrapNodesInProgress = true;
+
+ PG_TRY();
+ {
+ /*
+ * Wrap ExecProcNodes with ExecProcNodeFirst, which logs query plan
+ * when LogQueryPlanPending is true.
+ */
+ ExecSetExecProcNodeRecurse(querydesc->planstate);
+ }
+ PG_FINALLY();
+ {
+ WrapNodesInProgress = false;
+ }
+ PG_END_TRY();
+}
+
+/*
+ * Signal a backend process to log the query plan of the running query.
+ *
+ * By default, only superusers are allowed to signal to log the plan because
+ * allowing any users to issue this request at an unbounded rate would
+ * cause lots of log messages and which can lead to denial of service.
+ * Additional roles can be permitted with GRANT.
+ */
+Datum
+pg_log_query_plan(PG_FUNCTION_ARGS)
+{
+ int pid = PG_GETARG_INT32(0);
+ PGPROC *proc;
+ PgBackendStatus *be_status;
+
+ proc = BackendPidGetProc(pid);
+
+ if (proc == NULL)
+ {
+ /*
+ * This is just a warning so a loop-through-resultset will not abort
+ * if one backend terminated on its own during the run.
+ */
+ ereport(WARNING,
+ (errmsg("PID %d is not a PostgreSQL backend process", pid)));
+ PG_RETURN_BOOL(false);
+ }
+
+ be_status = pgstat_get_beentry_by_proc_number(proc->vxid.procNumber);
+ if (be_status->st_backendType != B_BACKEND)
+ {
+ ereport(WARNING,
+ (errmsg("PID %d is not a PostgreSQL client backend process", pid)));
+ PG_RETURN_BOOL(false);
+ }
+
+ if (SendProcSignal(pid, PROCSIG_LOG_QUERY_PLAN, proc->vxid.procNumber) < 0)
+ {
+ ereport(WARNING,
+ (errmsg("could not send signal to process %d: %m", pid)));
+ PG_RETURN_BOOL(false);
+ }
+
+ PG_RETURN_BOOL(true);
+}
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 207f86f1d39..92f02260e38 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -1085,6 +1085,37 @@ ExplainQueryParameters(ExplainState *es, ParamListInfo params, int maxlen)
ExplainPropertyText("Query Parameters", str, es);
}
+/*
+ * ExplainStringAssemble -
+ * Assemble es->str for logging according to specified options and format
+ */
+
+void
+ExplainStringAssemble(ExplainState *es, QueryDesc *queryDesc, int logFormat,
+ bool logTriggers, int logParameterMaxLength)
+{
+ ExplainBeginOutput(es);
+ ExplainQueryText(es, queryDesc);
+ ExplainQueryParameters(es, queryDesc->params, logParameterMaxLength);
+ ExplainPrintPlan(es, queryDesc);
+ if (es->analyze && logTriggers)
+ ExplainPrintTriggers(es, queryDesc);
+ if (es->costs)
+ ExplainPrintJITSummary(es, queryDesc);
+ ExplainEndOutput(es);
+
+ /* Remove last line break */
+ if (es->str->len > 0 && es->str->data[es->str->len - 1] == '\n')
+ es->str->data[--es->str->len] = '\0';
+
+ /* Fix JSON to output an object */
+ if (logFormat == EXPLAIN_FORMAT_JSON)
+ {
+ es->str->data[0] = '{';
+ es->str->data[es->str->len - 1] = '}';
+ }
+}
+
/*
* report_triggers -
* report execution stats for a single relation's triggers
@@ -1820,7 +1851,10 @@ ExplainNode(PlanState *planstate, List *ancestors,
/*
* We have to forcibly clean up the instrumentation state because we
- * haven't done ExecutorEnd yet. This is pretty grotty ...
+ * haven't done ExecutorEnd yet. This is pretty grotty ... This cleanup
+ * should not be done when the query has already been executed and explain
+ * has been requested by signal, as the target query may use
+ * instrumentation and clean itself up.
*
* Note: contrib/auto_explain could cause instrumentation to be set up
* even though we didn't ask for it here. Be careful not to print any
@@ -1828,7 +1862,7 @@ ExplainNode(PlanState *planstate, List *ancestors,
* InstrEndLoop call anyway, if possible, to reduce the number of cases
* auto_explain has to contend with.
*/
- if (planstate->instrument)
+ if (planstate->instrument && !es->signaled)
InstrEndLoop(planstate->instrument);
if (es->analyze &&
diff --git a/src/backend/commands/meson.build b/src/backend/commands/meson.build
index dd4cde41d32..4a64b8e9d09 100644
--- a/src/backend/commands/meson.build
+++ b/src/backend/commands/meson.build
@@ -20,6 +20,7 @@ backend_sources += files(
'define.c',
'discard.c',
'dropcmds.c',
+ 'dynamic_explain.c',
'event_trigger.c',
'explain.c',
'explain_dr.c',
diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index 831c55ce787..df5b55ae64d 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -43,6 +43,7 @@
#include "access/xact.h"
#include "catalog/namespace.h"
#include "catalog/partition.h"
+#include "commands/dynamic_explain.h"
#include "commands/matview.h"
#include "commands/trigger.h"
#include "executor/executor.h"
@@ -312,6 +313,7 @@ standard_ExecutorRun(QueryDesc *queryDesc,
DestReceiver *dest;
bool sendTuples;
MemoryContext oldcontext;
+ QueryDesc *oldQueryDesc;
/* sanity checks */
Assert(queryDesc != NULL);
@@ -324,6 +326,13 @@ standard_ExecutorRun(QueryDesc *queryDesc,
/* caller must ensure the query's snapshot is active */
Assert(GetActiveSnapshot() == estate->es_snapshot);
+ /*
+ * Save current QueryDesc here to enable retrieval of the currently
+ * running queryDesc for nested queries.
+ */
+ oldQueryDesc = GetCurrentQueryDesc();
+ SetCurrentQueryDesc(queryDesc);
+
/*
* Switch into per-query memory context
*/
@@ -386,6 +395,14 @@ standard_ExecutorRun(QueryDesc *queryDesc,
InstrStopNode(queryDesc->totaltime, estate->es_processed);
MemoryContextSwitchTo(oldcontext);
+ SetCurrentQueryDesc(oldQueryDesc);
+
+ /*
+ * Ensure LogQueryPlanPending is initialized in case there was no time for
+ * logging the plan. Othewise plan will be logged at the next query
+ * execution on the same session.
+ */
+ LogQueryPlanPending = false;
}
/* ----------------------------------------------------------------
diff --git a/src/backend/executor/execProcnode.c b/src/backend/executor/execProcnode.c
index f5f9cfbeead..bf1e26b7af1 100644
--- a/src/backend/executor/execProcnode.c
+++ b/src/backend/executor/execProcnode.c
@@ -72,6 +72,7 @@
*/
#include "postgres.h"
+#include "commands/dynamic_explain.h"
#include "executor/executor.h"
#include "executor/nodeAgg.h"
#include "executor/nodeAppend.h"
@@ -431,9 +432,10 @@ ExecSetExecProcNode(PlanState *node, ExecProcNodeMtd function)
{
/*
* Add a wrapper around the ExecProcNode callback that checks stack depth
- * during the first execution and maybe adds an instrumentation wrapper.
- * When the callback is changed after execution has already begun that
- * means we'll superfluously execute ExecProcNodeFirst, but that seems ok.
+ * and query logging request during the execution and maybe adds an
+ * instrumentation wrapper. When the callback is changed after execution
+ * has already begun that means we'll superfluously execute
+ * ExecProcNodeFirst, but that seems ok.
*/
node->ExecProcNodeReal = function;
node->ExecProcNode = ExecProcNodeFirst;
@@ -441,27 +443,43 @@ ExecSetExecProcNode(PlanState *node, ExecProcNodeMtd function)
/*
- * ExecProcNode wrapper that performs some one-time checks, before calling
+ * ExecProcNode wrapper that performs some extra checks, before calling
* the relevant node method (possibly via an instrumentation wrapper).
+ *
+ * Normally, this is just invoked once for the first call to any given node,
+ * and thereafter we arrange to call ExecProcNodeInstr or the relevant node
+ * method directly. However, it's legal to reset node->ExecProcNode back to
+ * this function at any time, and we do that whenever the query plan might
+ * need to be printed, so that we only incur the cost of checking for that
+ * case when required.
*/
static TupleTableSlot *
ExecProcNodeFirst(PlanState *node)
{
/*
- * Perform stack depth check during the first execution of the node. We
- * only do so the first time round because it turns out to not be cheap on
- * some common architectures (eg. x86). This relies on the assumption
- * that ExecProcNode calls for a given plan node will always be made at
- * roughly the same stack depth.
+ * Perform a stack depth check. We don't want to do this all the time
+ * because it turns out to not be cheap on some common architectures (eg.
+ * x86). This relies on the assumption that ExecProcNode calls for a
+ * given plan node will always be made at roughly the same stack depth.
*/
check_stack_depth();
+ /*
+ * If we have been asked to print the query plan, do that now. We dare not
+ * try to do this directly from CHECK_FOR_INTERRUPTS() because we don't
+ * really know what the executor state is at that point, but we assume
+ * that when entering a node the state will be sufficiently consistent
+ * that trying to print the plan makes sense.
+ */
+ if (LogQueryPlanPending)
+ LogQueryPlan();
+
/*
* If instrumentation is required, change the wrapper to one that just
* does instrumentation. Otherwise we can dispense with all wrappers and
* have ExecProcNode() directly call the relevant function from now on.
*/
- if (node->instrument)
+ else if (node->instrument)
node->ExecProcNode = ExecProcNodeInstr;
else
node->ExecProcNode = node->ExecProcNodeReal;
@@ -546,6 +564,91 @@ MultiExecProcNode(PlanState *node)
return result;
}
+/*
+ * Wrap array of PlanState ExecProcNode with ExecProcNodeFirst.
+ */
+static void
+ExecSetExecProcNodeArray(PlanState **planstates, int nplans)
+{
+ int i;
+
+ for (i = 0; i < nplans; i++)
+ ExecSetExecProcNodeRecurse(planstates[i]);
+}
+
+/*
+ * Wrap CustomScanState children's ExecProcNode with ExecProcNodeFirst.
+ */
+static void
+CSSChildExecSetExecProcNodeArray(CustomScanState *css)
+{
+ ListCell *cell;
+
+ foreach(cell, css->custom_ps)
+ ExecSetExecProcNodeRecurse((PlanState *) lfirst(cell));
+}
+
+/*
+ * Recursively wrap all the underlying ExecProcNode with ExecProcNodeFirst.
+ *
+ * Recursion is usually necessary because the next ExecProcNode() call may be
+ * invoked not only through the current node, but also via lefttree, righttree,
+ * subPlan, or other special child plans.
+ */
+void
+ExecSetExecProcNodeRecurse(PlanState *ps)
+{
+ ExecSetExecProcNode(ps, ps->ExecProcNodeReal);
+
+ if (ps->lefttree != NULL)
+ ExecSetExecProcNodeRecurse(ps->lefttree);
+ if (ps->righttree != NULL)
+ ExecSetExecProcNodeRecurse(ps->righttree);
+ if (ps->subPlan != NULL)
+ {
+ ListCell *l;
+
+ foreach(l, ps->subPlan)
+ {
+ SubPlanState *sstate = (SubPlanState *) lfirst(l);
+
+ ExecSetExecProcNodeRecurse(sstate->planstate);
+ }
+ }
+
+ /* special child plans */
+ switch (nodeTag(ps->plan))
+ {
+ case T_Append:
+ ExecSetExecProcNodeArray(((AppendState *) ps)->appendplans,
+ ((AppendState *) ps)->as_nplans);
+ break;
+ case T_MergeAppend:
+ ExecSetExecProcNodeArray(((MergeAppendState *) ps)->mergeplans,
+ ((MergeAppendState *) ps)->ms_nplans);
+ break;
+ case T_BitmapAnd:
+ ExecSetExecProcNodeArray(((BitmapAndState *) ps)->bitmapplans,
+ ((BitmapAndState *) ps)->nplans);
+ break;
+ case T_BitmapOr:
+ ExecSetExecProcNodeArray(((BitmapOrState *) ps)->bitmapplans,
+ ((BitmapOrState *) ps)->nplans);
+ break;
+ case T_SubqueryScan:
+ ExecSetExecProcNodeRecurse(((SubqueryScanState *) ps)->subplan);
+ break;
+ case T_CteScan:
+ ExecSetExecProcNodeRecurse(((CteScanState *) ps)->cteplanstate);
+ break;
+ case T_CustomScan:
+ CSSChildExecSetExecProcNodeArray((CustomScanState *) ps);
+ break;
+ default:
+ break;
+ }
+}
+
/* ----------------------------------------------------------------
* ExecEndNode
diff --git a/src/backend/storage/ipc/procsignal.c b/src/backend/storage/ipc/procsignal.c
index 087821311cc..07fcac7f0bc 100644
--- a/src/backend/storage/ipc/procsignal.c
+++ b/src/backend/storage/ipc/procsignal.c
@@ -19,6 +19,7 @@
#include "access/parallel.h"
#include "commands/async.h"
+#include "commands/dynamic_explain.h"
#include "miscadmin.h"
#include "pgstat.h"
#include "port/pg_bitutils.h"
@@ -691,6 +692,9 @@ procsignal_sigusr1_handler(SIGNAL_ARGS)
if (CheckProcSignal(PROCSIG_LOG_MEMORY_CONTEXT))
HandleLogMemoryContextInterrupt();
+ if (CheckProcSignal(PROCSIG_LOG_QUERY_PLAN))
+ HandleLogQueryPlanInterrupt();
+
if (CheckProcSignal(PROCSIG_PARALLEL_APPLY_MESSAGE))
HandleParallelApplyMessageInterrupt();
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index d356830f756..c5a5cd47c8f 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -37,6 +37,7 @@
#include "catalog/pg_type.h"
#include "commands/async.h"
#include "commands/event_trigger.h"
+#include "commands/dynamic_explain.h"
#include "commands/prepare.h"
#include "common/pg_prng.h"
#include "jit/jit.h"
@@ -3538,6 +3539,9 @@ ProcessInterrupts(void)
if (LogMemoryContextPending)
ProcessLogMemoryContextInterrupt();
+ if (LogQueryPlanPending)
+ ProcessLogQueryPlanInterrupt();
+
if (ParallelApplyMessagePending)
ProcessParallelApplyMessages();
}
diff --git a/src/backend/utils/init/globals.c b/src/backend/utils/init/globals.c
index d31cb45a058..927ccda0307 100644
--- a/src/backend/utils/init/globals.c
+++ b/src/backend/utils/init/globals.c
@@ -40,6 +40,8 @@ volatile sig_atomic_t IdleSessionTimeoutPending = false;
volatile sig_atomic_t ProcSignalBarrierPending = false;
volatile sig_atomic_t LogMemoryContextPending = false;
volatile sig_atomic_t IdleStatsUpdateTimeoutPending = false;
+volatile sig_atomic_t LogQueryPlanPending = false;
+
volatile uint32 InterruptHoldoffCount = 0;
volatile uint32 QueryCancelHoldoffCount = 0;
volatile uint32 CritSectionCount = 0;
diff --git a/src/include/access/xact.h b/src/include/access/xact.h
index 4528e51829e..3c6e3b7f2ce 100644
--- a/src/include/access/xact.h
+++ b/src/include/access/xact.h
@@ -432,6 +432,7 @@ typedef struct xl_xact_parsed_abort
TimestampTz origin_timestamp;
} xl_xact_parsed_abort;
+typedef struct QueryDesc QueryDesc;
/* ----------------
* extern definitions
@@ -458,6 +459,8 @@ extern TimestampTz GetCurrentStatementStartTimestamp(void);
extern TimestampTz GetCurrentTransactionStopTimestamp(void);
extern void SetCurrentStatementStartTimestamp(void);
extern int GetCurrentTransactionNestLevel(void);
+QueryDesc *GetCurrentQueryDesc(void);
+void SetCurrentQueryDesc(QueryDesc *queryDesc);
extern bool TransactionIdIsCurrentTransactionId(TransactionId xid);
extern void CommandCounterIncrement(void);
extern void ForceSyncCommit(void);
diff --git a/src/include/catalog/pg_proc.dat b/src/include/catalog/pg_proc.dat
index 01eba3b5a19..6cbfa0af91f 100644
--- a/src/include/catalog/pg_proc.dat
+++ b/src/include/catalog/pg_proc.dat
@@ -8609,6 +8609,12 @@
prorettype => 'bool', proargtypes => 'int4',
prosrc => 'pg_log_backend_memory_contexts' },
+# logging plan of the running query on the specified backend
+{ oid => '8000', descr => 'log plan of the running query on the specified backend',
+ proname => 'pg_log_query_plan',
+ provolatile => 'v', prorettype => 'bool',
+ proargtypes => 'int4', prosrc => 'pg_log_query_plan' },
+
# non-persistent series generator
{ oid => '1066', descr => 'non-persistent series generator',
proname => 'generate_series', prorows => '1000',
diff --git a/src/include/commands/dynamic_explain.h b/src/include/commands/dynamic_explain.h
new file mode 100644
index 00000000000..83a9e27deef
--- /dev/null
+++ b/src/include/commands/dynamic_explain.h
@@ -0,0 +1,25 @@
+/*-------------------------------------------------------------------------
+ *
+ * dynamic_explain.h
+ * prototypes for dynamic_explain.c
+ *
+ * Portions Copyright (c) 1996-2025, PostgreSQL Global Development Group
+ * Portions Copyright (c) 1994-5, Regents of the University of California
+ *
+ * src/include/commands/dynamic_explain.h
+ *
+ *-------------------------------------------------------------------------
+ */
+#ifndef DYNAMIC_EXPLAIN_H
+#define DYNAMIC_EXPLAIN_H
+
+#include "executor/executor.h"
+#include "commands/explain_state.h"
+
+extern void HandleLogQueryPlanInterrupt(void);
+extern void ProcessLogQueryPlanInterrupt(void);
+extern TupleTableSlot *ExecProcNodeWithExplain(PlanState *ps);
+extern void LogQueryPlan(void);
+extern Datum pg_log_query_plan(PG_FUNCTION_ARGS);
+
+#endif /* DYNAMIC_EXPLAIN_H */
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index 6e51d50efc7..0dc160fa7b4 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -70,8 +70,10 @@ extern void ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into,
const BufferUsage *bufusage,
const MemoryContextCounters *mem_counters);
-extern void ExplainPrintPlan(ExplainState *es, QueryDesc *queryDesc);
-extern void ExplainPrintTriggers(ExplainState *es,
+extern void ExplainPrintPlan(struct ExplainState *es, QueryDesc *queryDesc);
+extern void ExplainPrintTriggers(struct ExplainState *es, QueryDesc *queryDesc);
+extern void ExplainPrintPlan(struct ExplainState *es, QueryDesc *queryDesc);
+extern void ExplainPrintTriggers(struct ExplainState *es,
QueryDesc *queryDesc);
extern void ExplainPrintJITSummary(ExplainState *es,
@@ -80,5 +82,8 @@ extern void ExplainPrintJITSummary(ExplainState *es,
extern void ExplainQueryText(ExplainState *es, QueryDesc *queryDesc);
extern void ExplainQueryParameters(ExplainState *es,
ParamListInfo params, int maxlen);
+extern void ExplainStringAssemble(struct ExplainState *es, QueryDesc *queryDesc,
+ int logFormat, bool logTriggers,
+ int logParameterMaxLength);
#endif /* EXPLAIN_H */
diff --git a/src/include/commands/explain_state.h b/src/include/commands/explain_state.h
index ba073b86918..bf40fdabff5 100644
--- a/src/include/commands/explain_state.h
+++ b/src/include/commands/explain_state.h
@@ -71,6 +71,7 @@ typedef struct ExplainState
* entry */
/* state related to the current plan node */
ExplainWorkersState *workers_state; /* needed if parallel plan */
+ bool signaled; /* whether explain is called by signal */
/* extensions */
void **extension_state;
int extension_state_allocated;
diff --git a/src/include/executor/executor.h b/src/include/executor/executor.h
index 3248e78cd28..c66df11e71a 100644
--- a/src/include/executor/executor.h
+++ b/src/include/executor/executor.h
@@ -295,6 +295,7 @@ extern void EvalPlanQualEnd(EPQState *epqstate);
extern PlanState *ExecInitNode(Plan *node, EState *estate, int eflags);
extern void ExecSetExecProcNode(PlanState *node, ExecProcNodeMtd function);
extern Node *MultiExecProcNode(PlanState *node);
+extern void ExecSetExecProcNodeRecurse(PlanState *ps);
extern void ExecEndNode(PlanState *node);
extern void ExecShutdownNode(PlanState *node);
extern void ExecSetTupleBound(int64 tuples_needed, PlanState *child_node);
diff --git a/src/include/miscadmin.h b/src/include/miscadmin.h
index 1bef98471c3..22b945e918c 100644
--- a/src/include/miscadmin.h
+++ b/src/include/miscadmin.h
@@ -96,6 +96,7 @@ extern PGDLLIMPORT volatile sig_atomic_t IdleSessionTimeoutPending;
extern PGDLLIMPORT volatile sig_atomic_t ProcSignalBarrierPending;
extern PGDLLIMPORT volatile sig_atomic_t LogMemoryContextPending;
extern PGDLLIMPORT volatile sig_atomic_t IdleStatsUpdateTimeoutPending;
+extern PGDLLIMPORT volatile sig_atomic_t LogQueryPlanPending;
extern PGDLLIMPORT volatile sig_atomic_t CheckClientConnectionPending;
extern PGDLLIMPORT volatile sig_atomic_t ClientConnectionLost;
diff --git a/src/include/storage/procsignal.h b/src/include/storage/procsignal.h
index afeeb1ca019..ea26242c868 100644
--- a/src/include/storage/procsignal.h
+++ b/src/include/storage/procsignal.h
@@ -35,6 +35,8 @@ typedef enum
PROCSIG_WALSND_INIT_STOPPING, /* ask walsenders to prepare for shutdown */
PROCSIG_BARRIER, /* global barrier interrupt */
PROCSIG_LOG_MEMORY_CONTEXT, /* ask backend to log the memory contexts */
+ PROCSIG_LOG_QUERY_PLAN, /* ask backend to log plan of the current
+ * query */
PROCSIG_PARALLEL_APPLY_MESSAGE, /* Message from parallel apply workers */
/* Recovery conflict reasons */
diff --git a/src/test/regress/expected/misc_functions.out b/src/test/regress/expected/misc_functions.out
index 36164a99c83..53fef3f9ee3 100644
--- a/src/test/regress/expected/misc_functions.out
+++ b/src/test/regress/expected/misc_functions.out
@@ -366,6 +366,48 @@ REVOKE EXECUTE ON FUNCTION pg_log_backend_memory_contexts(integer)
FROM regress_log_memory;
DROP ROLE regress_log_memory;
--
+-- pg_log_query_plan()
+--
+-- Plans are logged and they are not returned to the function.
+-- Furthermore, their contents can vary depending on the optimizer. However,
+-- we can at least verify that the code doesn't fail, and that the
+-- permissions are set properly.
+WITH t AS MATERIALIZED (SELECT pg_log_query_plan(pg_backend_pid()))
+ SELECT * FROM t;
+ pg_log_query_plan
+-------------------
+ t
+(1 row)
+
+CREATE ROLE regress_log_plan;
+SELECT has_function_privilege('regress_log_plan',
+ 'pg_log_query_plan(integer)', 'EXECUTE'); -- no
+ has_function_privilege
+------------------------
+ f
+(1 row)
+
+GRANT EXECUTE ON FUNCTION pg_log_query_plan(integer)
+ TO regress_log_plan;
+SELECT has_function_privilege('regress_log_plan',
+ 'pg_log_query_plan(integer)', 'EXECUTE'); -- yes
+ has_function_privilege
+------------------------
+ t
+(1 row)
+
+SET ROLE regress_log_plan;
+SELECT pg_log_query_plan(pg_backend_pid());
+ pg_log_query_plan
+-------------------
+ t
+(1 row)
+
+RESET ROLE;
+REVOKE EXECUTE ON FUNCTION pg_log_query_plan(integer)
+ FROM regress_log_plan;
+DROP ROLE regress_log_plan;
+--
-- Test some built-in SRFs
--
-- The outputs of these are variable, so we can't just print their results
diff --git a/src/test/regress/sql/misc_functions.sql b/src/test/regress/sql/misc_functions.sql
index 23792c4132a..693b54b8316 100644
--- a/src/test/regress/sql/misc_functions.sql
+++ b/src/test/regress/sql/misc_functions.sql
@@ -143,6 +143,37 @@ REVOKE EXECUTE ON FUNCTION pg_log_backend_memory_contexts(integer)
DROP ROLE regress_log_memory;
+--
+-- pg_log_query_plan()
+--
+-- Plans are logged and they are not returned to the function.
+-- Furthermore, their contents can vary depending on the optimizer. However,
+-- we can at least verify that the code doesn't fail, and that the
+-- permissions are set properly.
+
+WITH t AS MATERIALIZED (SELECT pg_log_query_plan(pg_backend_pid()))
+ SELECT * FROM t;
+
+CREATE ROLE regress_log_plan;
+
+SELECT has_function_privilege('regress_log_plan',
+ 'pg_log_query_plan(integer)', 'EXECUTE'); -- no
+
+GRANT EXECUTE ON FUNCTION pg_log_query_plan(integer)
+ TO regress_log_plan;
+
+SELECT has_function_privilege('regress_log_plan',
+ 'pg_log_query_plan(integer)', 'EXECUTE'); -- yes
+
+SET ROLE regress_log_plan;
+SELECT pg_log_query_plan(pg_backend_pid());
+RESET ROLE;
+
+REVOKE EXECUTE ON FUNCTION pg_log_query_plan(integer)
+ FROM regress_log_plan;
+
+DROP ROLE regress_log_plan;
+
--
-- Test some built-in SRFs
--
--
2.48.1
diff --git a/src/backend/commands/dynamic_explain.c b/src/backend/commands/dynamic_explain.c
index b21a51aafe4..41951966838 100644
--- a/src/backend/commands/dynamic_explain.c
+++ b/src/backend/commands/dynamic_explain.c
@@ -22,6 +22,7 @@
#include "storage/proc.h"
#include "storage/procarray.h"
#include "utils/backend_status.h"
+#include "utils/injection_point.h"
/* Is plan node wrapping for query plan logging currently in progress? */
static bool WrapNodesInProgress = false;
@@ -80,6 +81,8 @@ LogQueryPlan(void)
ExplainStringAssemble(es, queryDesc, es->format, 0, -1);
+ INJECTION_POINT("logging-query-plan", NULL);
+
ereport(LOG_SERVER_ONLY,
errmsg("query and its plan running on backend with PID %d are:\n%s",
MyProcPid, es->str->data));
diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index df5b55ae64d..db792e97c4b 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -59,6 +59,7 @@
#include "tcop/utility.h"
#include "utils/acl.h"
#include "utils/backend_status.h"
+#include "utils/injection_point.h"
#include "utils/lsyscache.h"
#include "utils/partcache.h"
#include "utils/rls.h"
@@ -333,6 +334,8 @@ standard_ExecutorRun(QueryDesc *queryDesc,
oldQueryDesc = GetCurrentQueryDesc();
SetCurrentQueryDesc(queryDesc);
+ INJECTION_POINT("standard-executor-run", NULL);
+
/*
* Switch into per-query memory context
*/
diff --git a/src/test/isolation/expected/pg_log_query_plan.out b/src/test/isolation/expected/pg_log_query_plan.out
new file mode 100644
index 00000000000..2d126785c18
--- /dev/null
+++ b/src/test/isolation/expected/pg_log_query_plan.out
@@ -0,0 +1,36 @@
+Parsed test spec with 2 sessions
+
+starting permutation: query1 logreq2 wakeup2 detach2
+injection_points_attach
+-----------------------
+
+(1 row)
+
+step query1: SELECT COUNT(*) FROM foo; <waiting ...>
+step logreq2: SELECT pg_log_query_plan(pid) FROM pg_stat_activity WHERE backend_type = 'client backend';
+pg_log_query_plan
+-----------------
+t
+t
+t
+(3 rows)
+
+step wakeup2: SELECT injection_points_wakeup('standard-executor-run');
+injection_points_wakeup
+-----------------------
+
+(1 row)
+
+s1: NOTICE: notice triggered for injection point logging-query-plan
+step query1: <... completed>
+count
+-----
+ 100
+(1 row)
+
+step detach2: SELECT injection_points_detach('standard-executor-run');
+injection_points_detach
+-----------------------
+
+(1 row)
+
diff --git a/src/test/isolation/specs/pg_log_query_plan.spec b/src/test/isolation/specs/pg_log_query_plan.spec
new file mode 100644
index 00000000000..11c344d9fdd
--- /dev/null
+++ b/src/test/isolation/specs/pg_log_query_plan.spec
@@ -0,0 +1,27 @@
+# pg_log_query_plan() test
+
+setup
+{
+ CREATE EXTENSION injection_points;
+ CREATE TABLE foo AS SELECT generate_series(1,100);
+}
+teardown
+{
+ DROP EXTENSION injection_points;
+ DROP TABLE foo;
+}
+
+session s1
+setup {
+ SELECT injection_points_set_local();
+ SELECT injection_points_attach('logging-query-plan', 'notice');
+ SELECT injection_points_attach('standard-executor-run', 'wait');
+}
+step query1 { SELECT COUNT(*) FROM foo; }
+
+session s2
+step logreq2 { SELECT pg_log_query_plan(pid) FROM pg_stat_activity WHERE backend_type = 'client backend'; }
+step wakeup2 { SELECT injection_points_wakeup('standard-executor-run'); }
+step detach2 { SELECT injection_points_detach('standard-executor-run'); }
+
+permutation query1 logreq2 wakeup2 detach2
