On 2021-08-20 01:12, Fujii Masao wrote:
On 2021/08/11 21:14, torikoshia wrote:
As far as I looked into, pg_log_current_plan() can call InstrEndLoop()
through ExplainNode().
I added a flag to ExplainState to avoid calling InstrEndLoop() when
ExplainNode() is called from pg_log_current_plan().
Thanks for updating the patch!
I tried to test the patch again and encountered two issues.
Thanks for finding these issues!
(1)
The following WITH RECURSIVE query failed with the error
"ERROR: failed to find plan for CTE sg" when I ran
pg_log_current_query_plan() against the backend executing that query.
Is this a bug?
create table graph0( f int, t int, label text );
insert into graph0 values (1, 2, 'arc 1 -> 2'),(1, 3, 'arc 1 ->
3'),(2, 3, 'arc 2 -> 3'),(1, 4, 'arc 1 -> 4'),(4, 5, 'arc 4 -> 5');
with recursive search_graph(f, t, label, i) as (
select *, 1||pg_sleep(1)::text from graph0 g
union distinct
select g.*,1||pg_sleep(1)::text
from graph0 g, search_graph sg
where g.f = sg.t
) search breadth first by f, t set seq
select * from search_graph order by seq;
This ERROR occurred without applying the patch and just calling
EXPLAIN(VERBOSE) to CTE with SEARCH BREADTH FIRST.
I'm going to make another thread to discuss it.
(2)
When I ran pg_log_current_query_plan() while "make installcheck" test
was running, I got the following assertion failure.
TRAP: FailedAssertion("!IsPageLockHeld || (locktag->locktag_type ==
LOCKTAG_RELATION_EXTEND)", File: "lock.c", Line: 894, PID: 61512)
0 postgres 0x000000010ec23557
ExceptionalCondition + 231
1 postgres 0x000000010e9eff15
LockAcquireExtended + 1461
2 postgres 0x000000010e9ed14d
LockRelationOid + 61
3 postgres 0x000000010e41251b
relation_open + 91
4 postgres 0x000000010e509679 table_open +
25
5 postgres 0x000000010ebf9462
SearchCatCacheMiss + 274
6 postgres 0x000000010ebf5979
SearchCatCacheInternal + 761
7 postgres 0x000000010ebf566c
SearchCatCache + 60
8 postgres 0x000000010ec1a9e0
SearchSysCache + 144
9 postgres 0x000000010ec1ae03
SearchSysCacheExists + 51
10 postgres 0x000000010e58ce35
TypeIsVisible + 437
11 postgres 0x000000010ea98e4c
format_type_extended + 1964
12 postgres 0x000000010ea9900e
format_type_with_typemod + 30
13 postgres 0x000000010eb78d76
get_const_expr + 742
14 postgres 0x000000010eb79bc8
get_rule_expr + 232
15 postgres 0x000000010eb8140f
get_func_expr + 1247
16 postgres 0x000000010eb79dcd
get_rule_expr + 749
17 postgres 0x000000010eb81688
get_rule_expr_paren + 136
18 postgres 0x000000010eb7bf38
get_rule_expr + 9304
19 postgres 0x000000010eb72ad5
deparse_expression_pretty + 149
20 postgres 0x000000010eb73463
deparse_expression + 83
21 postgres 0x000000010e68eaf1
show_plan_tlist + 353
22 postgres 0x000000010e68adaf ExplainNode
+ 4991
23 postgres 0x000000010e688b4b
ExplainPrintPlan + 283
24 postgres 0x000000010e68e1aa
ProcessLogCurrentPlanInterrupt + 266
25 postgres 0x000000010ea133bb
ProcessInterrupts + 3435
26 postgres 0x000000010e738c97
vacuum_delay_point + 55
27 postgres 0x000000010e42bb4b
ginInsertCleanup + 1531
28 postgres 0x000000010e42d418
gin_clean_pending_list + 776
29 postgres 0x000000010e74955a
ExecInterpExpr + 2522
30 postgres 0x000000010e7487e2
ExecInterpExprStillValid + 82
31 postgres 0x000000010e7ae83b
ExecEvalExprSwitchContext + 59
32 postgres 0x000000010e7ae7be ExecProject
+ 78
33 postgres 0x000000010e7ae4e9 ExecResult +
345
34 postgres 0x000000010e764e42
ExecProcNodeFirst + 82
35 postgres 0x000000010e75ccb2 ExecProcNode
+ 50
36 postgres 0x000000010e758301 ExecutePlan
+ 193
37 postgres 0x000000010e7581d1
standard_ExecutorRun + 609
38 auto_explain.so 0x000000010f1df3a7
explain_ExecutorRun + 247
39 postgres 0x000000010e757f3b ExecutorRun
+ 91
40 postgres 0x000000010ea1cb49
PortalRunSelect + 313
41 postgres 0x000000010ea1c4dd PortalRun +
861
42 postgres 0x000000010ea17474
exec_simple_query + 1540
43 postgres 0x000000010ea164d4 PostgresMain
+ 2580
44 postgres 0x000000010e91d159 BackendRun +
89
45 postgres 0x000000010e91c6a5
BackendStartup + 565
46 postgres 0x000000010e91b3fe ServerLoop +
638
47 postgres 0x000000010e918b9d
PostmasterMain + 6717
48 postgres 0x000000010e7efd43 main + 819
49 libdyld.dylib 0x00007fff6a46e3d5 start + 1
50 ??? 0x0000000000000003 0x0 + 3
LOG: server process (PID 61512) was terminated by signal 6: Abort
trap: 6
DETAIL: Failed process was running: select
gin_clean_pending_list('t_gin_test_tbl_i_j_idx') is not null;
As far as I understand, since explaining plans can acquire heavyweight
lock for example to get column names, when page lock is held at the time
of the interrupt, this assertion error occurs.
The attached patch tries to avoid this by checking each LocalLock entry
and when finding even one, giving up logging the plan.
Thoughts?
Regards,
--
Atsushi Torikoshi
NTT DATA CORPORATION
From 26356efb094ac25b11fe65df93f11c64ad136723 Mon Sep 17 00:00:00 2001
From: Atsushi Torikoshi <torikos...@oss.nttdata.com>
Date: Mon, 6 Sep 2021 14:18:51 +0900
Subject: [PATCH v8] Add function to log the untruncated query string and its
plan for the query currently running on the backend with the specified
process ID.
Currently, we have to wait for the query execution to finish
before we check its plan. This is not so convenient when
investigating long-running queries on production environments
where we cannot use debuggers.
To improve this situation, this patch adds
pg_log_current_query_plan() function that requests to log the
plan of the specified backend process.
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.
On receipt of the request, at the next CHECK_FOR_INTERRUPTS(),
the target backend logs its plan at LOG_SERVER_ONLY level, so
that these plans will appear in the server log but not be sent
to the client.
Since some codes, tests and comments of
pg_log_current_query_plan() are the same with
pg_log_backend_memory_contexts(), this patch also refactors
them to make them common.
Reviewed-by: Bharath Rupireddy, Fujii Masao, Dilip Kumar, Masahiro Ikeda
---
doc/src/sgml/func.sgml | 46 ++++++++
src/backend/commands/explain.c | 117 ++++++++++++++++++-
src/backend/executor/execMain.c | 10 ++
src/backend/storage/ipc/procsignal.c | 4 +
src/backend/storage/ipc/signalfuncs.c | 61 ++++++++++
src/backend/tcop/postgres.c | 7 ++
src/backend/utils/adt/mcxtfuncs.c | 54 +--------
src/backend/utils/init/globals.c | 1 +
src/include/catalog/pg_proc.dat | 6 +
src/include/commands/explain.h | 3 +
src/include/miscadmin.h | 1 +
src/include/storage/procsignal.h | 1 +
src/include/storage/signalfuncs.h | 22 ++++
src/include/tcop/pquery.h | 1 +
src/test/regress/expected/misc_functions.out | 16 ++-
src/test/regress/sql/misc_functions.sql | 12 +-
16 files changed, 303 insertions(+), 59 deletions(-)
create mode 100644 src/include/storage/signalfuncs.h
diff --git a/doc/src/sgml/func.sgml b/doc/src/sgml/func.sgml
index 78812b2dbe..13b44b42cb 100644
--- a/doc/src/sgml/func.sgml
+++ b/doc/src/sgml/func.sgml
@@ -25281,6 +25281,27 @@ SELECT collation for ('foo' COLLATE "de_DE");
</para></entry>
</row>
+ <row>
+ <entry role="func_table_entry"><para role="func_signature">
+ <indexterm>
+ <primary>pg_log_current_query_plan</primary>
+ </indexterm>
+ <function>pg_log_current_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 along with the untruncated
+ query string.
+ They 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"/>.
+ Only superusers can request to log plan of the running query.
+ </para></entry>
+ </row>
+
<row>
<entry role="func_table_entry"><para role="func_signature">
<indexterm>
@@ -25394,6 +25415,31 @@ LOG: Grand total: 1651920 bytes in 201 blocks; 622360 free (88 chunks); 1029560
because it may generate a large number of log messages.
</para>
+ <para>
+ <function>pg_log_current_query_plan</function> can be used
+ to log the plan of a backend process. For example:
+<programlisting>
+postgres=# SELECT pg_log_current_query_plan(201116);
+ pg_log_current_query_plan
+---------------------------
+ t
+(1 row)
+</programlisting>
+The format of the query plan is the same as when <literal>VERBOSE</literal>,
+<literal>COSTS</literal>, <literal>SETTINGS</literal> and
+<literal>FORMAT TEXT</literal> are used in the <command>EXPLAIN</command>
+command. For example:
+<screen>
+LOG: plan of the query running on backend with PID 17793 is:
+ Query Text: SELECT * FROM pgbench_accounts;
+ Seq Scan on public.pgbench_accounts (cost=0.00..52787.00 rows=2000000 width=97)
+ Output: aid, bid, abalance, filler
+ Settings: work_mem = '1MB'
+</screen>
+ Note that nested statements (statements executed inside a function) are not
+ considered for logging. Only the deepest nesting query's plan is logged.
+ </para>
+
</sect2>
<sect2 id="functions-admin-backup">
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index 10644dfac4..f528301cc5 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -21,6 +21,7 @@
#include "executor/nodeHash.h"
#include "foreign/fdwapi.h"
#include "jit/jit.h"
+#include "miscadmin.h"
#include "nodes/extensible.h"
#include "nodes/makefuncs.h"
#include "nodes/nodeFuncs.h"
@@ -28,6 +29,9 @@
#include "parser/parsetree.h"
#include "rewrite/rewriteHandler.h"
#include "storage/bufmgr.h"
+#include "storage/procarray.h"
+#include "storage/signalfuncs.h"
+#include "tcop/pquery.h"
#include "tcop/tcopprot.h"
#include "utils/builtins.h"
#include "utils/guc_tables.h"
@@ -40,7 +44,6 @@
#include "utils/typcache.h"
#include "utils/xml.h"
-
/* Hook for plugins to get control in ExplainOneQuery() */
ExplainOneQuery_hook_type ExplainOneQuery_hook = NULL;
@@ -1594,6 +1597,9 @@ 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 ...
+ * This cleanup should not be done when the query has already been
+ * executed, 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
@@ -1601,7 +1607,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->running)
InstrEndLoop(planstate->instrument);
if (es->analyze &&
@@ -4922,3 +4928,110 @@ escape_yaml(StringInfo buf, const char *str)
{
escape_json(buf, str);
}
+
+/*
+ * HandleLogCurrentPlanInterrupt
+ * Handle receipt of an interrupt indicating logging the plan of
+ * the currently running query.
+ *
+ * All the actual work is deferred to ProcessLogCurrentPlanInterrupt(),
+ * because we cannot safely emit a log message inside the signal handler.
+ */
+void
+HandleLogCurrentPlanInterrupt(void)
+{
+ InterruptPending = true;
+ LogCurrentPlanPending = true;
+ /* latch will be set by procsignal_sigusr1_handler */
+}
+
+/*
+ * ProcessLogCurrentPlanInterrupt
+ * Perform logging the plan of the currently running query on this
+ * backend process.
+ *
+ * Any backend that participates in ProcSignal signaling must arrange to call
+ * this function if we see LogCurrentPlanPending set.
+ * It is called from CHECK_FOR_INTERRUPTS(), which is enough because the target
+ * process for logging plan is a backend.
+ */
+void
+ProcessLogCurrentPlanInterrupt(void)
+{
+ ExplainState *es;
+ HASH_SEQ_STATUS status;
+ LOCALLOCK *locallock;
+ LogCurrentPlanPending = false;
+
+ if (ActiveQueryDesc == NULL)
+ {
+ ereport(LOG_SERVER_ONLY,
+ (errmsg("backend with PID %d is not running a query",
+ MyProcPid)));
+ return;
+ }
+
+ /*
+ * Ensure no page lock is held on this process.
+ *
+ * If page lock is held at the time of the interrupt, we can't acquire any
+ * other heavyweight lock, which might be necessary for explaining the plan
+ * when retrieving column names.
+ *
+ * This may be overkill, but since page locks are held for a short duration
+ * we check all the LocalLock entries and when finding even one, give up
+ * logging the plan.
+ */
+ hash_seq_init(&status, GetLockMethodLocalHash());
+ while ((locallock = (LOCALLOCK *) hash_seq_search(&status)) != NULL)
+ {
+ if (LOCALLOCK_LOCKTAG(*locallock) == LOCKTAG_PAGE)
+ {
+ ereport(LOG_SERVER_ONLY,
+ (errmsg("backend with PID %d is now holding a page lock. Try again",
+ MyProcPid)));
+ hash_seq_term(&status);
+ return;
+ }
+ }
+
+ es = NewExplainState();
+
+ es->format = EXPLAIN_FORMAT_TEXT;
+ es->settings = true;
+ es->verbose = true;
+ es->running = true;
+
+ ExplainBeginOutput(es);
+ ExplainQueryText(es, ActiveQueryDesc);
+ ExplainPrintPlan(es, ActiveQueryDesc);
+ if (es->costs)
+ ExplainPrintJITSummary(es, ActiveQueryDesc);
+ 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';
+
+ ereport(LOG_SERVER_ONLY,
+ (errmsg("plan of the query running on backend with PID %d is:\n%s",
+ MyProcPid, es->str->data),
+ errhidestmt(true),
+ errhidecontext(true)));
+}
+
+/*
+ * pg_log_current_query_plan
+ * Signal a backend process to log the query plan of the running query.
+ */
+Datum
+pg_log_current_query_plan(PG_FUNCTION_ARGS)
+{
+ pid_t pid;
+ bool result;
+
+ pid = PG_GETARG_INT32(0);
+ result = SendProcSignalForLogInfo(pid, PROCSIG_LOG_CURRENT_PLAN);
+
+ PG_RETURN_BOOL(result);
+}
diff --git a/src/backend/executor/execMain.c b/src/backend/executor/execMain.c
index b3ce4bae53..c74aa1d04e 100644
--- a/src/backend/executor/execMain.c
+++ b/src/backend/executor/execMain.c
@@ -76,6 +76,9 @@ ExecutorEnd_hook_type ExecutorEnd_hook = NULL;
/* Hook for plugin to get control in ExecCheckRTPerms() */
ExecutorCheckPerms_hook_type ExecutorCheckPerms_hook = NULL;
+/* Currently executing query's QueryDesc */
+QueryDesc *ActiveQueryDesc = NULL;
+
/* decls for local routines only used within this module */
static void InitPlan(QueryDesc *queryDesc, int eflags);
static void CheckValidRowMarkRel(Relation rel, RowMarkType markType);
@@ -299,10 +302,17 @@ ExecutorRun(QueryDesc *queryDesc,
ScanDirection direction, uint64 count,
bool execute_once)
{
+ QueryDesc *save_ActiveQueryDesc;
+
+ save_ActiveQueryDesc = ActiveQueryDesc;
+ ActiveQueryDesc = queryDesc;
+
if (ExecutorRun_hook)
(*ExecutorRun_hook) (queryDesc, direction, count, execute_once);
else
standard_ExecutorRun(queryDesc, direction, count, execute_once);
+
+ ActiveQueryDesc = save_ActiveQueryDesc;
}
void
diff --git a/src/backend/storage/ipc/procsignal.c b/src/backend/storage/ipc/procsignal.c
index defb75aa26..9b9653544a 100644
--- a/src/backend/storage/ipc/procsignal.c
+++ b/src/backend/storage/ipc/procsignal.c
@@ -20,6 +20,7 @@
#include "access/parallel.h"
#include "port/pg_bitutils.h"
#include "commands/async.h"
+#include "commands/explain.h"
#include "miscadmin.h"
#include "pgstat.h"
#include "replication/walsender.h"
@@ -661,6 +662,9 @@ procsignal_sigusr1_handler(SIGNAL_ARGS)
if (CheckProcSignal(PROCSIG_LOG_MEMORY_CONTEXT))
HandleLogMemoryContextInterrupt();
+ if (CheckProcSignal(PROCSIG_LOG_CURRENT_PLAN))
+ HandleLogCurrentPlanInterrupt();
+
if (CheckProcSignal(PROCSIG_RECOVERY_CONFLICT_DATABASE))
RecoveryConflictInterrupt(PROCSIG_RECOVERY_CONFLICT_DATABASE);
diff --git a/src/backend/storage/ipc/signalfuncs.c b/src/backend/storage/ipc/signalfuncs.c
index de69d60e79..1aad120791 100644
--- a/src/backend/storage/ipc/signalfuncs.c
+++ b/src/backend/storage/ipc/signalfuncs.c
@@ -23,6 +23,7 @@
#include "storage/pmsignal.h"
#include "storage/proc.h"
#include "storage/procarray.h"
+#include "storage/signalfuncs.h"
#include "utils/acl.h"
#include "utils/builtins.h"
@@ -298,3 +299,63 @@ pg_rotate_logfile_v2(PG_FUNCTION_ARGS)
SendPostmasterSignal(PMSIGNAL_ROTATE_LOGFILE);
PG_RETURN_BOOL(true);
}
+
+/*
+ * Signal a backend process to log its information.
+ *
+ * Only superusers are allowed to signal to log information 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.
+ *
+ * On receipt of this signal, a backend sets the flag in the signal
+ * handler, which causes the next CHECK_FOR_INTERRUPTS() to log the
+ * information.
+ */
+bool
+SendProcSignalForLogInfo(pid_t pid, ProcSignalReason reason)
+{
+ PGPROC *proc;
+
+ Assert(reason == PROCSIG_LOG_MEMORY_CONTEXT ||
+ reason == PROCSIG_LOG_CURRENT_PLAN);
+
+ /* Only allow superusers to log information. */
+ if (!superuser())
+ ereport(ERROR,
+ (errcode(ERRCODE_INSUFFICIENT_PRIVILEGE),
+ errmsg("must be a superuser to log information about specified process")));
+
+ proc = BackendPidGetProc(pid);
+
+ /*
+ * BackendPidGetProc returns NULL if the pid isn't valid; but by the time
+ * we reach kill(), a process for which we get a valid proc here might
+ * have terminated on its own. There's no way to acquire a lock on an
+ * arbitrary process to prevent that. But since this mechanism is usually
+ * used to below purposes, it might end its own first and the information
+ * is not logged is not a problem.
+ * - debug a backend running and consuming lots of memory
+ * - look into the plan of the long running query
+ */
+ 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 server process", pid)));
+ return false;
+ }
+
+ if (SendProcSignal(pid, reason, proc->backendId) < 0)
+ {
+ /* Again, just a warning to allow loops */
+ ereport(WARNING,
+ (errmsg("could not send signal to process %d: %m", pid)));
+ return false;
+ }
+
+ return true;
+}
diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c
index 58b5960e27..8b8808db8f 100644
--- a/src/backend/tcop/postgres.c
+++ b/src/backend/tcop/postgres.c
@@ -41,6 +41,7 @@
#include "access/xact.h"
#include "catalog/pg_type.h"
#include "commands/async.h"
+#include "commands/explain.h"
#include "commands/prepare.h"
#include "executor/spi.h"
#include "jit/jit.h"
@@ -3366,6 +3367,9 @@ ProcessInterrupts(void)
if (LogMemoryContextPending)
ProcessLogMemoryContextInterrupt();
+
+ if (LogCurrentPlanPending)
+ ProcessLogCurrentPlanInterrupt();
}
@@ -4278,6 +4282,9 @@ PostgresMain(int argc, char *argv[],
/* We don't have a transaction command open anymore */
xact_started = false;
+ /* We have no running query */
+ ActiveQueryDesc = NULL;
+
/*
* If an error occurred while we were reading a message from the
* client, we have potentially lost track of where the previous
diff --git a/src/backend/utils/adt/mcxtfuncs.c b/src/backend/utils/adt/mcxtfuncs.c
index 0d52613bc3..304f36bda0 100644
--- a/src/backend/utils/adt/mcxtfuncs.c
+++ b/src/backend/utils/adt/mcxtfuncs.c
@@ -18,8 +18,8 @@
#include "funcapi.h"
#include "miscadmin.h"
#include "mb/pg_wchar.h"
-#include "storage/proc.h"
#include "storage/procarray.h"
+#include "storage/signalfuncs.h"
#include "utils/builtins.h"
/* ----------
@@ -161,57 +161,15 @@ pg_get_backend_memory_contexts(PG_FUNCTION_ARGS)
/*
* pg_log_backend_memory_contexts
* Signal a backend process to log its memory contexts.
- *
- * Only superusers are allowed to signal to log the memory contexts
- * 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.
- *
- * On receipt of this signal, a backend sets the flag in the signal
- * handler, which causes the next CHECK_FOR_INTERRUPTS() to log the
- * memory contexts.
*/
Datum
pg_log_backend_memory_contexts(PG_FUNCTION_ARGS)
{
- int pid = PG_GETARG_INT32(0);
- PGPROC *proc;
-
- /* Only allow superusers to log memory contexts. */
- if (!superuser())
- ereport(ERROR,
- (errcode(ERRCODE_INSUFFICIENT_PRIVILEGE),
- errmsg("must be a superuser to log memory contexts")));
-
- proc = BackendPidGetProc(pid);
-
- /*
- * BackendPidGetProc returns NULL if the pid isn't valid; but by the time
- * we reach kill(), a process for which we get a valid proc here might
- * have terminated on its own. There's no way to acquire a lock on an
- * arbitrary process to prevent that. But since this mechanism is usually
- * used to debug a backend running and consuming lots of memory, that it
- * might end on its own first and its memory contexts are not logged is
- * not a problem.
- */
- 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 server process", pid)));
- PG_RETURN_BOOL(false);
- }
+ pid_t pid;
+ bool result;
- if (SendProcSignal(pid, PROCSIG_LOG_MEMORY_CONTEXT, proc->backendId) < 0)
- {
- /* Again, just a warning to allow loops */
- ereport(WARNING,
- (errmsg("could not send signal to process %d: %m", pid)));
- PG_RETURN_BOOL(false);
- }
+ pid = PG_GETARG_INT32(0);
+ result = SendProcSignalForLogInfo(pid, PROCSIG_LOG_MEMORY_CONTEXT);
- PG_RETURN_BOOL(true);
+ PG_RETURN_BOOL(result);
}
diff --git a/src/backend/utils/init/globals.c b/src/backend/utils/init/globals.c
index 381d9e548d..126ed10362 100644
--- a/src/backend/utils/init/globals.c
+++ b/src/backend/utils/init/globals.c
@@ -36,6 +36,7 @@ volatile sig_atomic_t IdleInTransactionSessionTimeoutPending = false;
volatile sig_atomic_t IdleSessionTimeoutPending = false;
volatile sig_atomic_t ProcSignalBarrierPending = false;
volatile sig_atomic_t LogMemoryContextPending = false;
+volatile sig_atomic_t LogCurrentPlanPending = false;
volatile uint32 InterruptHoldoffCount = 0;
volatile uint32 QueryCancelHoldoffCount = 0;
volatile uint32 CritSectionCount = 0;
diff --git a/src/include/catalog/pg_proc.dat b/src/include/catalog/pg_proc.dat
index c07b2c6a55..6b4ef16d81 100644
--- a/src/include/catalog/pg_proc.dat
+++ b/src/include/catalog/pg_proc.dat
@@ -8038,6 +8038,12 @@
prorettype => 'bool', proargtypes => 'int4',
prosrc => 'pg_log_backend_memory_contexts' },
+# logging plan of the running query on the specified backend
+{ oid => '4544', descr => 'log plan of the running query on the specified backend',
+ proname => 'pg_log_current_query_plan',
+ provolatile => 'v', prorettype => 'bool',
+ proargtypes => 'int4', prosrc => 'pg_log_current_query_plan' },
+
# non-persistent series generator
{ oid => '1066', descr => 'non-persistent series generator',
proname => 'generate_series', prorows => '1000',
diff --git a/src/include/commands/explain.h b/src/include/commands/explain.h
index e94d9e49cf..7c2dce7cdf 100644
--- a/src/include/commands/explain.h
+++ b/src/include/commands/explain.h
@@ -59,6 +59,7 @@ typedef struct ExplainState
bool hide_workers; /* set if we find an invisible Gather */
/* state related to the current plan node */
ExplainWorkersState *workers_state; /* needed if parallel plan */
+ bool running; /* whether target query is already running */
} ExplainState;
/* Hook for plugins to get control in ExplainOneQuery() */
@@ -124,4 +125,6 @@ extern void ExplainOpenGroup(const char *objtype, const char *labelname,
extern void ExplainCloseGroup(const char *objtype, const char *labelname,
bool labeled, ExplainState *es);
+extern void HandleLogCurrentPlanInterrupt(void);
+extern void ProcessLogCurrentPlanInterrupt(void);
#endif /* EXPLAIN_H */
diff --git a/src/include/miscadmin.h b/src/include/miscadmin.h
index 2e2e9a364a..097ebaa96d 100644
--- a/src/include/miscadmin.h
+++ b/src/include/miscadmin.h
@@ -94,6 +94,7 @@ extern PGDLLIMPORT volatile sig_atomic_t IdleInTransactionSessionTimeoutPending;
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 LogCurrentPlanPending;
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 eec186be2e..c1a7218d69 100644
--- a/src/include/storage/procsignal.h
+++ b/src/include/storage/procsignal.h
@@ -35,6 +35,7 @@ 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_CURRENT_PLAN, /* ask backend to log plan of the current query */
/* Recovery conflict reasons */
PROCSIG_RECOVERY_CONFLICT_DATABASE,
diff --git a/src/include/storage/signalfuncs.h b/src/include/storage/signalfuncs.h
new file mode 100644
index 0000000000..5f6b124372
--- /dev/null
+++ b/src/include/storage/signalfuncs.h
@@ -0,0 +1,22 @@
+/*-------------------------------------------------------------------------
+ *
+ * signalfuncs.h
+ * Functions for signaling backends
+ *
+ *
+ * Portions Copyright (c) 1996-2021, PostgreSQL Global Development Group
+ * Portions Copyright (c) 1994, Regents of the University of California
+ *
+ * src/include/storage/signalfuncs.h
+ *
+ *-------------------------------------------------------------------------
+ */
+#ifndef PROCSIGNALFUNC_H
+#define PROCSIGNALFUNC_H
+
+/*
+ * prototypes for functions in signalfuncs.c
+ */
+extern bool SendProcSignalForLogInfo(pid_t pid, ProcSignalReason reason);
+
+#endif /* PROCSIGNALFUNC_H */
diff --git a/src/include/tcop/pquery.h b/src/include/tcop/pquery.h
index 2318f04ff0..d37a5eb837 100644
--- a/src/include/tcop/pquery.h
+++ b/src/include/tcop/pquery.h
@@ -21,6 +21,7 @@ struct PlannedStmt; /* avoid including plannodes.h here */
extern PGDLLIMPORT Portal ActivePortal;
+extern PGDLLIMPORT QueryDesc *ActiveQueryDesc;
extern PortalStrategy ChoosePortalStrategy(List *stmts);
diff --git a/src/test/regress/expected/misc_functions.out b/src/test/regress/expected/misc_functions.out
index e845042d38..98017f83a9 100644
--- a/src/test/regress/expected/misc_functions.out
+++ b/src/test/regress/expected/misc_functions.out
@@ -134,18 +134,26 @@ LINE 1: SELECT num_nulls();
^
HINT: No function matches the given name and argument types. You might need to add explicit type casts.
--
--- pg_log_backend_memory_contexts()
+-- Test logging functions
--
--- Memory contexts are logged and they are not returned to the function.
--- Furthermore, their contents can vary depending on the timing. However,
+-- These functions return true if the specified backend is successfully
+-- signaled, otherwise false. Upon receiving the signal, the backend
+-- will log the information to the server log.
+-- Although their contents can vary depending on the timing,
-- we can at least verify that the code doesn't fail.
--
-SELECT * FROM pg_log_backend_memory_contexts(pg_backend_pid());
+SELECT pg_log_backend_memory_contexts(pg_backend_pid());
pg_log_backend_memory_contexts
--------------------------------
t
(1 row)
+SELECT pg_log_current_query_plan(pg_backend_pid());
+ pg_log_current_query_plan
+---------------------------
+ t
+(1 row)
+
--
-- Test some built-in SRFs
--
diff --git a/src/test/regress/sql/misc_functions.sql b/src/test/regress/sql/misc_functions.sql
index a398349afc..979a418e8e 100644
--- a/src/test/regress/sql/misc_functions.sql
+++ b/src/test/regress/sql/misc_functions.sql
@@ -29,15 +29,17 @@ SELECT num_nulls(VARIADIC '{}'::int[]);
-- should fail, one or more arguments is required
SELECT num_nonnulls();
SELECT num_nulls();
-
--
--- pg_log_backend_memory_contexts()
+-- Test logging functions
--
--- Memory contexts are logged and they are not returned to the function.
--- Furthermore, their contents can vary depending on the timing. However,
+-- These functions return true if the specified backend is successfully
+-- signaled, otherwise false. Upon receiving the signal, the backend
+-- will log the information to the server log.
+-- Although their contents can vary depending on the timing,
-- we can at least verify that the code doesn't fail.
--
-SELECT * FROM pg_log_backend_memory_contexts(pg_backend_pid());
+SELECT pg_log_backend_memory_contexts(pg_backend_pid());
+SELECT pg_log_current_query_plan(pg_backend_pid());
--
-- Test some built-in SRFs
base-commit: 0bd305ee1d427ef29f5fa4fa20567e3b3f5ff792
--
2.27.0
