From 016415802a21216b5c7eefa67a6a4f244b8b4042 Mon Sep 17 00:00:00 2001 From: Mohamed Ali Date: Fri, 15 May 2026 15:10:31 -0700 Subject: [PATCH v5] Add NESTED_STATEMENTS option to EXPLAIN Add a new EXPLAIN option, NESTED_STATEMENTS, that captures and displays execution plans for SQL statements executed inside server-side functions and procedures. Works with any procedural language that uses SPI (Server Programming Interface) to execute SQL -- including PL/pgSQL, PL/Perl, PL/Tcl, and PL/Python. Provides similar functionality to auto_explain's log_nested_statements parameter but as a core EXPLAIN option requiring no extension or GUC configuration. Features: - NESTED_STATEMENTS boolean option (requires ANALYZE) - Captures nested SQL via executor hooks (Start/Run/Finish/End) - Works with any PL language using SPI (tested: PL/pgSQL, PL/Tcl, PL/Perl) - Displays plan text, query text, nesting level, and execution time - Start-time (chronological) ordering: statements displayed in the order they started executing, with sequential numbering. Parents appear before their children for intuitive top-down reading. - SHOW_NESTED integer option to limit displayed plans (0 = summary only) - Nested Statements Summary with total count, max depth, and timing - Per-statement execution time with percentage (level-1 statements only; deeper levels show absolute time since their time is already included in their level-1 parent's inclusive time) - Total Nested Time sums only level-1 statement times to avoid double-counting when multi-level nesting is present - Trigger detection via GetMyTriggerDepth(): detects both BEFORE and AFTER triggers, annotates with (trigger) in output - Separate Total Trigger Time tracking (all trigger levels, shown as % of nested time) - Works directly on DML with triggers (no function wrapper needed) - Reveals trigger activity inside functions (unreachable by built-in trigger reporting which only covers the top-level statement) - Inherits parent EXPLAIN options: VERBOSE, COSTS, BUFFERS, WAL, IO, TIMING, SETTINGS, FORMAT (MEMORY not applicable -- planning is handled by SPI internally) - Valid structured output for JSON/XML/YAML: single parseable document with nested plans as structured sub-objects in a "Nested Plans" array, "Execution Time Percentage" inside Query object for level-1 statements, and "Nested Statements Summary" as a structured object - SECURITY DEFINER protection: nested plans hidden from unprivileged users inside SECURITY DEFINER functions. Only superusers and pg_read_all_stats members can see them. NOTICE emitted when hidden. - Error-safe: PG_TRY/PG_FINALLY ensures hook cleanup on errors (hook installation inside PG_TRY for OOM safety) - Reentrancy guard: nested EXPLAIN(NESTED_STATEMENTS) silently disabled with DEBUG1 log message for troubleshooting - Dedicated memory context: no leaks, freed in PG_FINALLY - NOTICE emitted when >1000 nested statements captured without SHOW_NESTED (warns about per-row SQL function volume) - Safe with parallel queries (hooks are leader-only, same as auto_explain) trigger.c changes: - Add GetMyTriggerDepth() getter function for MyTriggerDepth - Refactor pg_trigger_depth() SQL function to use the getter Documentation updated with parameter descriptions, notes on SPI-based language support, trigger detection, level-1 timing semantics, per-row function volume warning, MEMORY/SETTINGS behavior, SECURITY DEFINER protection, start-time ordering, structured format examples, and examples. --- doc/src/sgml/ref/explain.sgml | 313 ++++++++ src/backend/commands/explain.c | 1075 +++++++++++++++++++++++++- src/backend/commands/explain_state.c | 25 + src/backend/commands/trigger.c | 18 +- src/include/commands/explain_state.h | 2 + src/include/commands/trigger.h | 2 + 6 files changed, 1399 insertions(+), 36 deletions(-) diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml index e95e19081e1..474695a3a7e 100644 --- a/doc/src/sgml/ref/explain.sgml +++ b/doc/src/sgml/ref/explain.sgml @@ -47,6 +47,8 @@ EXPLAIN [ ( option [, ...] ) ] boolean ] MEMORY [ boolean ] IO [ boolean ] + NESTED_STATEMENTS [ boolean ] + SHOW_NESTED integer FORMAT { TEXT | XML | JSON | YAML } @@ -310,6 +312,66 @@ ROLLBACK; + + NESTED_STATEMENTS + + + Include execution plans for SQL statements executed inside + server-side functions and procedures. Any function written in + PL/pgSQL, PL/Perl, PL/Tcl, PL/Python, or any other procedural + language that executes SQL through the Server Programming Interface + (SPI) will have its internal queries captured and displayed after + the main query plan. + + + Each nested statement is shown with a sequential number, its nesting + level, the query text, the complete execution plan, and its execution + time. The nesting level reflects the executor call stack depth: + statements in a function called via PERFORM or + SELECT ... INTO run at a deeper level than the + caller, while statements in a function called via expression assignment + (e.g., result := func()) run at the same level as + the caller. Statements fired by triggers (both + BEFORE and AFTER) are + automatically detected and annotated with + (trigger) in the output. Nested statements that + fire triggers also show trigger timing information in their plan. + When VERBOSE is enabled, each nested statement + includes its Query Identifier for correlation + with pg_stat_statements. + + + This option also works directly on DML statements + (INSERT, UPDATE, + DELETE) that fire triggers, revealing the + execution plans of trigger-fired statements without needing to + wrap the query in a function. + A summary section is included after the nested plans showing + total statement count, execution time breakdown, and the slowest + statement (controlled by the SUMMARY option). + This parameter may only be used when ANALYZE is also + enabled. It defaults to FALSE. + + + + + + SHOW_NESTED + + + Limit the number of nested statement plans displayed in the output. + When specified, only the first N nested + plans are shown, but all statements are still captured internally + for the summary statistics. Use SHOW_NESTED 0 + to display only the summary without any individual plans. + This is useful for complex functions with many nested statements + where the full output would be too large. + This parameter may only be used when NESTED_STATEMENTS + is also enabled. When not specified, all nested plans are displayed. + + + + FORMAT @@ -391,6 +453,87 @@ ROLLBACK; execution, and on machines that have relatively slow operating system calls for obtaining the time of day. + + + When NESTED_STATEMENTS is enabled, the options + VERBOSE, COSTS, + BUFFERS, WAL, + TIMING, IO, + and FORMAT + are inherited by the nested statement plans. + The MEMORY option is not inherited because it + reports planning memory usage, and nested statement planning is + handled internally by SPI before the execution hooks capture the plan. + Each nested statement shows its execution time when + SUMMARY is enabled. Level-1 statements (those + directly inside the called function) also show a percentage of total + nested time. Deeper-level statements show only absolute time because + their time is already included in their level-1 parent's reported time. + Nested statements are displayed in chronological order (by start time) + and numbered sequentially. + When using structured output formats (JSON, XML, YAML), each nested + plan is emitted as a structured object matching the main plan format. + The Execution Time Percentage field appears inside + the Query object next to Execution Time + for level-1 non-trigger statements. + + + + A summary section controlled by SUMMARY shows: + total statement count, maximum nesting depth, total nested execution + time (as percentage of main execution time), total trigger time + (as percentage of nested time), and the slowest statement. + Total nested time sums only level-1 statement times to avoid + double-counting when deeper levels are present (since level-1 + times already include their children's execution time). + Use SHOW_NESTED 0 to display only the summary. + + + + Statements fired by triggers (both BEFORE and + AFTER) are annotated with + (trigger) in the output header. Their time is + tracked separately as Total Trigger Time and + excluded from Total Nested Time. Nested + statements that fire triggers also show + Trigger lines (name, time, call count) in their + plan output, matching the main query's trigger reporting format. + + + + When a function uses dynamic SQL via EXECUTE, + the Query Text field shows the actual executed + SQL string, not the PL/pgSQL source expression. + When VERBOSE is enabled and + compute_query_id is active, each nested statement + shows its Query Identifier, which can be used to + look up the statement in + pg_stat_statements. + + + + Nested statements inside SECURITY DEFINER functions + are hidden from unprivileged users. When the effective user differs + from the session user (indicating a SECURITY DEFINER + context), nested statement capture is skipped entirely unless the + session user is a superuser or holds the + pg_read_all_stats role. A + NOTICE is emitted explaining why nested plans are + not shown. This prevents unprivileged users from inspecting query + text and plan details of functions whose internals they should not + see. + + + + For queries that call functions per-row (e.g., + SELECT func(id) FROM large_table), each function + invocation generates a separate nested statement capture. Use + SHOW_NESTED to limit the number of plans displayed + while still collecting accurate summary statistics for all executions. + A NOTICE is emitted when more than 1000 nested + statements are captured without SHOW_NESTED being + set. + @@ -575,6 +718,176 @@ EXPLAIN (GENERIC_PLAN) GROUP BY foo; + + + To display execution plans for nested statements within a function: + + +EXPLAIN (ANALYZE, NESTED_STATEMENTS) SELECT my_function(); + + QUERY PLAN +------------------------------------------------------------- + Result (cost=0.00..0.26 rows=1 width=4) (actual time=1.234..1.235 rows=1.00 loops=1) + Planning Time: 0.050 ms + Execution Time: 1.300 ms + + Nested Plans: + + Nested Statement #1 (level 1): + Query Text: SELECT count(*) FROM products + Aggregate (cost=11.75..11.76 rows=1 width=8) (actual time=0.200..0.201 rows=1.00 loops=1) + -> Seq Scan on products (cost=0.00..11.00 rows=500 width=0) (actual time=0.010..0.150 rows=500.00 loops=1) + Execution Time: 0.201 ms (20.1%) + + Nested Statement #2 (level 1): + Query Text: UPDATE products SET price = price * 1.10 WHERE category = 'Electronics' + Update on products (cost=0.00..12.50 rows=0 width=0) (actual time=0.800..0.800 rows=0.00 loops=1) + -> Seq Scan on products (cost=0.00..12.50 rows=50 width=10) (actual time=0.050..0.100 rows=50.00 loops=1) + Filter: (category = 'Electronics'::text) + Rows Removed by Filter: 450 + Execution Time: 0.800 ms (79.9%) + + Nested Statements Summary: + Total: 2 statements, max depth 1 + Total Execution Time: 1.300 ms + Total Nested Time: 1.001 ms (77.0% of total time) + Slowest Statement: #2 (0.800 ms, 79.9%) + + + This shows the main query plan followed by the execution plans for + each SQL statement executed inside my_function(). + + + + When triggers are involved, trigger-fired statements are annotated + and the parent statement shows trigger timing: + + +EXPLAIN (ANALYZE, NESTED_STATEMENTS, COSTS OFF) +UPDATE orders SET status = 'done' WHERE id = 1; + + QUERY PLAN +------------------------------------------------------------- + Update on orders (actual time=0.050..0.050 rows=0.00 loops=1) + -> Index Scan using orders_pkey on orders (...) + Trigger audit_trigger: time=0.522 calls=1 + Execution Time: 0.600 ms + + Nested Plans: + + Nested Statement #1 (level 1, trigger): + Query Text: INSERT INTO audit_log VALUES (NEW.id, 'status changed') + Insert on audit_log (actual time=0.010..0.010 rows=0.00 loops=1) + -> Result (actual time=0.001..0.001 rows=1.00 loops=1) + Execution Time: 0.011 ms + + Nested Statements Summary: + Total: 1 statements (0 direct, 1 trigger-fired), max depth 1 + Total Execution Time: 0.600 ms + Total Trigger Time: 0.011 ms + Slowest Statement: #1 (0.011 ms) + + + + + Use SHOW_NESTED to limit the number of plans displayed + when a function executes many statements: + + +EXPLAIN (ANALYZE, NESTED_STATEMENTS, SHOW_NESTED 1) SELECT my_function(); + + QUERY PLAN +------------------------------------------------------------- + Result (cost=0.00..0.26 rows=1 width=4) (actual time=1.234..1.235 rows=1.00 loops=1) + Planning Time: 0.050 ms + Execution Time: 1.300 ms + + Nested Plans (showing 1 of 2): + + Nested Statement #1 (level 1): + Query Text: SELECT count(*) FROM products + Aggregate (cost=11.75..11.76 rows=1 width=8) (actual time=0.200..0.201 rows=1.00 loops=1) + -> Seq Scan on products (cost=0.00..11.00 rows=500 width=0) (actual time=0.010..0.150 rows=500.00 loops=1) + Execution Time: 0.201 ms (20.1%) + + Nested Statements Summary: + Total: 2 statements, max depth 1 + Total Execution Time: 1.300 ms + Total Nested Time: 1.001 ms (77.0% of total time) + Slowest Statement: #2 (0.800 ms, 79.9%) + + + Only the first plan is shown, but the summary still reflects all + statements. Use SHOW_NESTED 0 to display only + the summary without any individual plans. + + + + With JSON format, the main plan is emitted as a complete JSON document, + followed by each nested statement's plan as a separate JSON document: + + +EXPLAIN (ANALYZE, NESTED_STATEMENTS, FORMAT JSON) SELECT my_function(); + + QUERY PLAN +------------------------------------------------------------- +[ + { + "Plan": { + "Node Type": "Result", + "Actual Startup Time": 1.234, + "Actual Total Time": 1.235, + "Actual Rows": 1, + "Actual Loops": 1 + }, + "Planning Time": 0.050, + "Execution Time": 1.300, + "Nested Plans": [ + { + "Statement Number": 1, + "Nesting Level": 1, + "Is Trigger": false, + "Query Text": "SELECT count(*) FROM products", + "Query": { + "Plan": { + "Node Type": "Aggregate", + "Plans": [{"Node Type": "Seq Scan", "Relation Name": "products"}] + }, + "Execution Time": 0.201, + "Execution Time Percentage": 20.1 + } + }, + { + "Statement Number": 2, + "Nesting Level": 1, + "Is Trigger": false, + "Query Text": "UPDATE products SET price = price * 1.10 WHERE ...", + "Query": { + "Plan": { + "Node Type": "ModifyTable", + "Operation": "Update", + "Plans": [{"Node Type": "Seq Scan", "Relation Name": "products"}] + }, + "Execution Time": 0.800, + "Execution Time Percentage": 79.9 + } + } + ], + "Nested Statements Summary": { + "Total Statements": 2, + "Direct Statements": 2, + "Trigger-Fired Statements": 0, + "Max Depth": 1, + "Total Execution Time": 1.300, + "Total Nested Time": 1.001, + "Slowest Statement Number": 2, + "Slowest Statement Time": 0.800 + } + } +] + + + diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 112c17b0d64..3392fceae34 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -23,6 +23,11 @@ #include "commands/explain_format.h" #include "commands/explain_state.h" #include "commands/prepare.h" +#include "commands/trigger.h" +#include "executor/executor.h" +#include "miscadmin.h" +#include "catalog/pg_authid_d.h" +#include "utils/acl.h" #include "foreign/fdwapi.h" #include "jit/jit.h" #include "libpq/pqformat.h" @@ -58,6 +63,71 @@ explain_get_index_name_hook_type explain_get_index_name_hook = NULL; explain_per_plan_hook_type explain_per_plan_hook = NULL; explain_per_node_hook_type explain_per_node_hook = NULL; +/* + * The following statics hold state for the current EXPLAIN (NESTED_STATEMENTS) + * execution. They are backend-local (not shared memory), safe for + * single-backend use. If EXPLAIN is ever parallelized, these would need + * to become per-worker structures or use shared memory. + */ + +/* Nested statements tracking for EXPLAIN (NESTED_STATEMENTS) */ +typedef struct NestedPlanInfo +{ + int statement_num; + int nesting_level; + char *query_text; + char *plan_text; + double exec_time_ms; /* execution time in ms, -1 if unavailable */ + bool is_trigger; /* true if fired by a trigger */ + instr_time start_time; /* when ExecutorStart was called */ + struct NestedPlanInfo *next; +} NestedPlanInfo; + +static int nested_exec_level = 0; +static bool nested_tracking_active = false; +static ExplainState *nested_parent_es = NULL; +static int nested_stmt_count = 0; +static int nested_total_count = 0; +static int nested_max_depth = 0; +static double nested_total_time = 0.0; +static double nested_slowest_time = 0.0; +static int nested_slowest_num = 0; +static double nested_main_exec_time = 0.0; +static double nested_trigger_time = 0.0; +static int nested_trigger_count = 0; +static NestedPlanInfo *nested_plans_head = NULL; +static NestedPlanInfo *nested_plans_tail = NULL; +static MemoryContext nested_memcxt = NULL; +static int nested_secdef_skipped = 0; /* statements skipped due to SECURITY DEFINER */ + +/* + * Stack of start timestamps for nested statements. Pushed in + * ExecutorStart, popped in ExecutorEnd. Used for start-time ordering. + */ +#define NESTED_MAX_DEPTH 128 +static instr_time nested_start_stack[NESTED_MAX_DEPTH]; +static int nested_start_stack_depth = 0; + +/* Threshold for emitting a NOTICE about high nested statement counts */ +#define NESTED_STMT_NOTICE_THRESHOLD 1000 + +/* Saved executor hook values for nested statements */ +static ExecutorStart_hook_type prev_ExecutorStart_hook = NULL; +static ExecutorRun_hook_type prev_ExecutorRun_hook = NULL; +static ExecutorFinish_hook_type prev_ExecutorFinish_hook = NULL; +static ExecutorEnd_hook_type prev_ExecutorEnd_hook = NULL; + +static void nested_ExecutorStart(QueryDesc *queryDesc, int eflags); +static void nested_ExecutorRun(QueryDesc *queryDesc, ScanDirection direction, + uint64 count); +static void nested_ExecutorFinish(QueryDesc *queryDesc); +static void nested_ExecutorEnd(QueryDesc *queryDesc); +static NestedPlanInfo *nested_plans_sort_by_start_time(NestedPlanInfo *head); +static NestedPlanInfo *nested_plans_merge(NestedPlanInfo *a, NestedPlanInfo *b); +static void ExplainPrintNestedPlans(ExplainState *es); +static void ExplainInstallNestedHooks(ExplainState *es); +static void ExplainRemoveNestedHooks(void); + /* * Various places within need to convert bytes to kilobytes. Round these up * to the next whole kilobyte. @@ -206,49 +276,71 @@ ExplainQuery(ParseState *pstate, ExplainStmt *stmt, */ rewritten = QueryRewrite(castNode(Query, stmt->query)); - /* emit opening boilerplate */ - ExplainBeginOutput(es); - - if (rewritten == NIL) + PG_TRY(); { - /* - * In the case of an INSTEAD NOTHING, tell at least that. But in - * non-text format, the output is delimited, so this isn't necessary. - */ - if (es->format == EXPLAIN_FORMAT_TEXT) - appendStringInfoString(es->str, "Query rewrites to nothing\n"); - } - else - { - ListCell *l; + /* Install nested statement hooks if requested — inside PG_TRY so + * PG_FINALLY cleanup is guaranteed if allocation fails. */ + if (es->nested_statements) + ExplainInstallNestedHooks(es); - /* Explain every plan */ - foreach(l, rewritten) + /* emit opening boilerplate */ + ExplainBeginOutput(es); + + if (rewritten == NIL) { - ExplainOneQuery(lfirst_node(Query, l), - CURSOR_OPT_PARALLEL_OK, NULL, es, - pstate, params); + /* + * In the case of an INSTEAD NOTHING, tell at least that. But in + * non-text format, the output is delimited, so this isn't necessary. + */ + if (es->format == EXPLAIN_FORMAT_TEXT) + appendStringInfoString(es->str, "Query rewrites to nothing\n"); + } + else + { + ListCell *l; + + /* Explain every plan */ + foreach(l, rewritten) + { + ExplainOneQuery(lfirst_node(Query, l), + CURSOR_OPT_PARALLEL_OK, NULL, es, + pstate, params); - /* Separate plans with an appropriate separator */ - if (lnext(rewritten, l) != NULL) - ExplainSeparatePlans(es); + /* Separate plans with an appropriate separator */ + if (lnext(rewritten, l) != NULL) + ExplainSeparatePlans(es); + } } - } - /* emit closing boilerplate */ - ExplainEndOutput(es); - Assert(es->indent == 0); + /* emit closing boilerplate */ + ExplainEndOutput(es); + Assert(es->indent == 0); - /* output tuples */ - tstate = begin_tup_output_tupdesc(dest, ExplainResultDesc(stmt), - &TTSOpsVirtual); - if (es->format == EXPLAIN_FORMAT_TEXT) - do_text_output_multiline(tstate, es->str->data); - else - do_text_output_oneline(tstate, es->str->data); - end_tup_output(tstate); + /* output tuples */ + tstate = begin_tup_output_tupdesc(dest, ExplainResultDesc(stmt), + &TTSOpsVirtual); + if (es->format == EXPLAIN_FORMAT_TEXT) + do_text_output_multiline(tstate, es->str->data); + else + do_text_output_oneline(tstate, es->str->data); + end_tup_output(tstate); - pfree(es->str->data); + pfree(es->str->data); + } + PG_FINALLY(); + { + /* Always clean up nested statement hooks and memory */ + if (es->nested_statements) + { + ExplainRemoveNestedHooks(); + if (nested_memcxt) + { + MemoryContextDelete(nested_memcxt); + nested_memcxt = NULL; + } + } + } + PG_END_TRY(); } /* @@ -686,6 +778,15 @@ ExplainOnePlan(PlannedStmt *plannedstmt, IntoClause *into, ExplainState *es, ExplainPropertyFloat("Execution Time", "ms", 1000.0 * totaltime, 3, es); + /* Store main execution time for nested statements percentage calculation */ + if (es->nested_statements && nested_tracking_active) + nested_main_exec_time = 1000.0 * totaltime; + + /* Print nested statement plans inside the Query group so that + * structured formats (JSON/XML/YAML) produce a valid document. */ + if (es->nested_statements) + ExplainPrintNestedPlans(es); + ExplainCloseGroup("Query", NULL, true, es); } @@ -5322,3 +5423,907 @@ ExplainFlushWorkersState(ExplainState *es) pfree(wstate->worker_state_save); pfree(wstate); } + +/* + * ExplainInstallNestedHooks - install executor hooks for nested statement + * tracking. + * + * This sets up hooks to intercept ExecutorStart, ExecutorRun, + * ExecutorFinish, and ExecutorEnd calls so we can track nesting depth + * and capture plans for nested statements. + */ +static void +ExplainInstallNestedHooks(ExplainState *es) +{ + /* + * Guard against reentrancy: if we're already tracking nested statements + * (e.g., a function executes EXPLAIN (NESTED_STATEMENTS) internally), + * skip hook installation to avoid corrupting the outer EXPLAIN's state. + */ + if (nested_tracking_active) + { + elog(DEBUG1, "NESTED_STATEMENTS disabled: already active (reentrancy)"); + es->nested_statements = false; + return; + } + + nested_tracking_active = true; + nested_exec_level = 0; + nested_stmt_count = 0; + nested_total_count = 0; + nested_max_depth = 0; + nested_total_time = 0.0; + nested_slowest_time = 0.0; + nested_slowest_num = 0; + nested_main_exec_time = 0.0; + nested_trigger_time = 0.0; + nested_trigger_count = 0; + nested_plans_head = NULL; + nested_plans_tail = NULL; + nested_start_stack_depth = 0; + nested_secdef_skipped = 0; + nested_parent_es = es; + + /* + * Create a dedicated memory context for captured plan text. This ensures + * all allocations can be freed at once in the PG_FINALLY cleanup, whether + * the EXPLAIN succeeds or errors out. + */ + nested_memcxt = AllocSetContextCreate(CurrentMemoryContext, + "Nested EXPLAIN plans", + ALLOCSET_DEFAULT_SIZES); + + /* Save and install hooks */ + prev_ExecutorStart_hook = ExecutorStart_hook; + ExecutorStart_hook = nested_ExecutorStart; + prev_ExecutorRun_hook = ExecutorRun_hook; + ExecutorRun_hook = nested_ExecutorRun; + prev_ExecutorFinish_hook = ExecutorFinish_hook; + ExecutorFinish_hook = nested_ExecutorFinish; + prev_ExecutorEnd_hook = ExecutorEnd_hook; + ExecutorEnd_hook = nested_ExecutorEnd; +} + +/* + * ExplainRemoveNestedHooks - restore previous executor hooks. + */ +static void +ExplainRemoveNestedHooks(void) +{ + ExecutorStart_hook = prev_ExecutorStart_hook; + ExecutorRun_hook = prev_ExecutorRun_hook; + ExecutorFinish_hook = prev_ExecutorFinish_hook; + ExecutorEnd_hook = prev_ExecutorEnd_hook; + + prev_ExecutorStart_hook = NULL; + prev_ExecutorRun_hook = NULL; + prev_ExecutorFinish_hook = NULL; + prev_ExecutorEnd_hook = NULL; + + nested_tracking_active = false; + nested_parent_es = NULL; +} + +/* + * nested_ExecutorStart - ExecutorStart hook for nested statement tracking. + * + * When we're inside a nested execution (nesting_level > 0), enable + * instrumentation so we can capture actual execution statistics. + */ +static void +nested_ExecutorStart(QueryDesc *queryDesc, int eflags) +{ + if (nested_tracking_active && nested_exec_level > 0 && + (eflags & EXEC_FLAG_EXPLAIN_ONLY) == 0) + { + /* Enable per-node instrumentation for nested statements */ + if (nested_parent_es->timing) + queryDesc->instrument_options |= INSTRUMENT_TIMER; + else + queryDesc->instrument_options |= INSTRUMENT_ROWS; + if (nested_parent_es->buffers) + queryDesc->instrument_options |= INSTRUMENT_BUFFERS; + if (nested_parent_es->wal) + queryDesc->instrument_options |= INSTRUMENT_WAL; + if (nested_parent_es->io) + queryDesc->instrument_options |= INSTRUMENT_IO; + + /* Enable query-level instrumentation for execution time tracking */ + queryDesc->query_instr_options |= INSTRUMENT_TIMER; + + /* Record start time for start-time ordering */ + if (nested_start_stack_depth < NESTED_MAX_DEPTH) + { + INSTR_TIME_SET_CURRENT(nested_start_stack[nested_start_stack_depth]); + nested_start_stack_depth++; + } + } + + if (prev_ExecutorStart_hook) + prev_ExecutorStart_hook(queryDesc, eflags); + else + standard_ExecutorStart(queryDesc, eflags); +} + +/* + * nested_ExecutorRun - ExecutorRun hook for nested statement tracking. + * + * Track nesting depth so we know when we're inside a nested execution. + */ +static void +nested_ExecutorRun(QueryDesc *queryDesc, ScanDirection direction, uint64 count) +{ + nested_exec_level++; + PG_TRY(); + { + if (prev_ExecutorRun_hook) + prev_ExecutorRun_hook(queryDesc, direction, count); + else + standard_ExecutorRun(queryDesc, direction, count); + } + PG_FINALLY(); + { + nested_exec_level--; + } + PG_END_TRY(); +} + +/* + * nested_ExecutorFinish - ExecutorFinish hook for nested statement tracking. + * + * Track nesting depth through ExecutorFinish as well, since some statements + * (e.g., those with AFTER triggers) do work here. + */ +static void +nested_ExecutorFinish(QueryDesc *queryDesc) +{ + nested_exec_level++; + PG_TRY(); + { + if (prev_ExecutorFinish_hook) + prev_ExecutorFinish_hook(queryDesc); + else + standard_ExecutorFinish(queryDesc); + } + PG_FINALLY(); + { + nested_exec_level--; + } + PG_END_TRY(); +} + +/* + * nested_ExecutorEnd - ExecutorEnd hook for nested statement tracking. + * + * When a nested statement finishes execution, capture its plan text + * for later display. Uses GetMyTriggerDepth() to detect whether the + * statement was fired by a trigger (both BEFORE and AFTER). + */ +static void +nested_ExecutorEnd(QueryDesc *queryDesc) +{ + if (nested_tracking_active && + nested_exec_level > 0 && + nested_parent_es != NULL && + queryDesc->plannedstmt != NULL && + queryDesc->instrument_options != 0) + { + double stmt_time = -1.0; + bool is_trigger = (GetMyTriggerDepth() > 0); + + /* + * SECURITY DEFINER protection: if the current effective user + * differs from the session user (i.e., we're inside a SECURITY + * DEFINER function), skip capture entirely unless the session + * user holds pg_read_all_stats privileges. This prevents + * unprivileged users from seeing query text and plan details + * of functions they can execute but whose internals they + * should not inspect. Consistent with pg_stat_statements' + * query text visibility model. + */ + if (GetUserId() != GetSessionUserId() && + !has_privs_of_role(GetSessionUserId(), ROLE_PG_READ_ALL_STATS)) + { + nested_secdef_skipped++; + /* Pop start time stack to maintain balance (was pushed in ExecutorStart) */ + if (nested_start_stack_depth > 0) + nested_start_stack_depth--; + goto skip_capture; + } + + nested_total_count++; + if (is_trigger) + nested_trigger_count++; + + /* Track timing for summary (always, even if not displaying) */ + if (queryDesc->query_instr) + { + stmt_time = INSTR_TIME_GET_MILLISEC(queryDesc->query_instr->total); + if (is_trigger) + { + /* + * Sum ALL trigger statements into Total Trigger Time + * regardless of level. This shows total trigger overhead + * even when triggers fire at deeper levels. + */ + nested_trigger_time += stmt_time; + } + else if (nested_exec_level == 1) + { + /* + * Only sum level-1 direct statements into Total Nested Time. + * Level-1 statements already include deeper levels' time + * (inclusive timing), so summing all levels would + * double-count. + */ + nested_total_time += stmt_time; + } + /* Track slowest statement across ALL levels and types */ + if (stmt_time > nested_slowest_time) + { + nested_slowest_time = stmt_time; + nested_slowest_num = nested_total_count; + } + } + + /* Track max depth */ + if (nested_exec_level > nested_max_depth) + nested_max_depth = nested_exec_level; + + /* + * Pop start time from stack. Must happen regardless of whether + * we capture the plan (SHOW_NESTED limit), since we always push + * in ExecutorStart. + */ + { + instr_time stmt_start_time; + + if (nested_start_stack_depth > 0) + { + nested_start_stack_depth--; + stmt_start_time = nested_start_stack[nested_start_stack_depth]; + } + else + INSTR_TIME_SET_ZERO(stmt_start_time); + + /* + * Only capture plan text if under the display limit. + * show_nested < 0 means show all (no limit). + */ + if (nested_parent_es->show_nested < 0 || + nested_stmt_count < nested_parent_es->show_nested) + { + MemoryContext oldcxt; + NestedPlanInfo *plan_info; + ExplainState *nes; + + nested_stmt_count++; + + /* + * Switch to the dedicated memory context so the captured plan + * text survives until we print it. + */ + oldcxt = MemoryContextSwitchTo(nested_memcxt); + + /* Build an ExplainState to format this nested plan */ + nes = NewExplainState(); + nes->analyze = true; + nes->verbose = nested_parent_es->verbose; + nes->costs = nested_parent_es->costs; + nes->buffers = nested_parent_es->buffers; + nes->wal = nested_parent_es->wal; + nes->timing = nested_parent_es->timing; + nes->io = nested_parent_es->io; + nes->settings = nested_parent_es->settings; + nes->summary = false; + nes->format = nested_parent_es->format; + + ExplainBeginOutput(nes); + ExplainOpenGroup("Query", NULL, true, nes); + ExplainPrintPlan(nes, queryDesc); + + /* Print trigger info for this nested statement (matches + * what top-level EXPLAIN does for the main query) */ + if (nes->analyze) + ExplainPrintTriggers(nes, queryDesc); + + /* Add Execution Time inside structured output for non-TEXT */ + if (nes->format != EXPLAIN_FORMAT_TEXT && + queryDesc->query_instr && + nested_parent_es->summary) + ExplainPropertyFloat("Execution Time", "ms", stmt_time, 3, nes); + + ExplainCloseGroup("Query", NULL, true, nes); + ExplainEndOutput(nes); + + /* Remove trailing newline if present */ + if (nes->str->len > 0 && nes->str->data[nes->str->len - 1] == '\n') + nes->str->data[--nes->str->len] = '\0'; + + /* Allocate and fill the plan info node */ + plan_info = (NestedPlanInfo *) palloc(sizeof(NestedPlanInfo)); + plan_info->statement_num = nested_total_count; + plan_info->nesting_level = nested_exec_level; + plan_info->query_text = queryDesc->sourceText ? + pstrdup(queryDesc->sourceText) : pstrdup(""); + plan_info->plan_text = pstrdup(nes->str->data); + plan_info->exec_time_ms = stmt_time; + plan_info->is_trigger = is_trigger; + plan_info->start_time = stmt_start_time; + plan_info->next = NULL; + + /* Append to the linked list */ + if (nested_plans_tail == NULL) + { + nested_plans_head = plan_info; + nested_plans_tail = plan_info; + } + else + { + nested_plans_tail->next = plan_info; + nested_plans_tail = plan_info; + } + + MemoryContextSwitchTo(oldcxt); + } + } /* end of stmt_start_time scope */ + } + +skip_capture: + if (prev_ExecutorEnd_hook) + prev_ExecutorEnd_hook(queryDesc); + else + standard_ExecutorEnd(queryDesc); +} + +/* + * Sort nested plans linked list by start time (chronological order). + * Uses merge sort for O(n log n) on linked lists. + */ +static NestedPlanInfo * +nested_plans_merge(NestedPlanInfo *a, NestedPlanInfo *b) +{ + NestedPlanInfo dummy; + NestedPlanInfo *tail = &dummy; + + dummy.next = NULL; + while (a && b) + { + if (INSTR_TIME_GET_DOUBLE(a->start_time) <= + INSTR_TIME_GET_DOUBLE(b->start_time)) + { + tail->next = a; + a = a->next; + } + else + { + tail->next = b; + b = b->next; + } + tail = tail->next; + } + tail->next = a ? a : b; + return dummy.next; +} + +static NestedPlanInfo * +nested_plans_sort_by_start_time(NestedPlanInfo *head) +{ + NestedPlanInfo *slow; + NestedPlanInfo *fast; + NestedPlanInfo *mid; + + if (!head || !head->next) + return head; + + /* Split list in half */ + slow = head; + fast = head->next; + while (fast && fast->next) + { + slow = slow->next; + fast = fast->next->next; + } + mid = slow->next; + slow->next = NULL; + + return nested_plans_merge( + nested_plans_sort_by_start_time(head), + nested_plans_sort_by_start_time(mid)); +} + +/* + * ExplainPrintNestedPlans - print collected nested statement plans. + * + * This is called after the main query plan has been printed, to append + * the nested statement plans to the EXPLAIN output. + * Statements are sorted by start time for chronological ordering. + */ +static void +ExplainPrintNestedPlans(ExplainState *es) +{ + NestedPlanInfo *info; + + if (nested_plans_head == NULL && nested_total_count == 0) + { + /* If statements were skipped due to SECURITY DEFINER, inform user */ + if (nested_secdef_skipped > 0) + ereport(NOTICE, + (errmsg("nested statements hidden: executed inside SECURITY DEFINER function"), + errhint("Only superusers and roles with pg_read_all_stats can view nested plans inside SECURITY DEFINER functions."))); + return; + } + + /* Sort by start time for chronological (top-down) ordering */ + nested_plans_head = nested_plans_sort_by_start_time(nested_plans_head); + + /* Renumber statements sequentially after sorting so display numbers + * match the on-screen order (1, 2, 3...) instead of completion order. + * Also find the slowest among displayed statements for the summary. + * When list is empty (SHOW_NESTED 0), keep original nested_slowest_num. */ + if (nested_plans_head != NULL) + { + int display_num = 1; + double max_time = 0.0; + + for (info = nested_plans_head; info != NULL; info = info->next) + { + info->statement_num = display_num; + if (info->exec_time_ms > max_time) + { + max_time = info->exec_time_ms; + nested_slowest_num = display_num; + } + display_num++; + } + } + + if (es->format == EXPLAIN_FORMAT_TEXT) + { + appendStringInfoChar(es->str, '\n'); + if (nested_total_count > nested_stmt_count) + appendStringInfo(es->str, "Nested Plans (showing %d of %d):\n", + nested_stmt_count, nested_total_count); + else + appendStringInfoString(es->str, "Nested Plans:\n"); + + for (info = nested_plans_head; info != NULL; info = info->next) + { + appendStringInfoChar(es->str, '\n'); + if (info->is_trigger) + appendStringInfo(es->str, " Nested Statement #%d (level %d, trigger):\n", + info->statement_num, info->nesting_level); + else + appendStringInfo(es->str, " Nested Statement #%d (level %d):\n", + info->statement_num, info->nesting_level); + appendStringInfo(es->str, " Query Text: %s\n", info->query_text); + + /* Indent the plan text */ + { + char *line; + char *plan_copy = pstrdup(info->plan_text); + char *saveptr = NULL; + + for (line = strtok_r(plan_copy, "\n", &saveptr); + line != NULL; + line = strtok_r(NULL, "\n", &saveptr)) + { + appendStringInfo(es->str, " %s\n", line); + } + pfree(plan_copy); + } + + /* Print execution time (and percentage of total nested time + * for level-1 statements) if summary is enabled */ + if (info->exec_time_ms >= 0 && es->summary) + { + if (info->is_trigger) + { + /* Trigger time is included in parent's time; + * header already shows "(trigger)" annotation */ + appendStringInfo(es->str, " Execution Time: %.3f ms\n", + info->exec_time_ms); + } + else if (info->nesting_level == 1 && nested_total_time > 0) + { + /* + * Only level-1 statements show percentage, since + * Total Nested Time sums only level-1 times. + * Deeper statements show absolute time only (their + * time is already included in their level-1 parent). + */ + double pct = (info->exec_time_ms / nested_total_time) * 100.0; + appendStringInfo(es->str, " Execution Time: %.3f ms (%.1f%%)\n", + info->exec_time_ms, pct); + } + else + appendStringInfo(es->str, " Execution Time: %.3f ms\n", + info->exec_time_ms); + } + } + } + else + { + /* For structured formats (JSON, XML, YAML) — emit nested plans + * as a proper array within the Query group */ + ExplainOpenGroup("Nested Plans", "Nested Plans", false, es); + + for (info = nested_plans_head; info != NULL; info = info->next) + { + ExplainOpenGroup("Nested Statement", NULL, true, es); + + ExplainPropertyInteger("Statement Number", NULL, + info->statement_num, es); + ExplainPropertyInteger("Nesting Level", NULL, + info->nesting_level, es); + ExplainPropertyBool("Is Trigger", info->is_trigger, es); + ExplainPropertyText("Query Text", info->query_text, es); + + /* Execution time and percentage are injected into the Query + * sub-object below, next to the standard "Execution Time" + * field, so they appear together like TEXT format. */ + + /* Embed the nested plan as a proper sub-object by injecting + * the raw JSON/XML/YAML directly into the output buffer. + * For level-1 non-trigger statements, inject "Execution Time + * Percentage" into the plan text so it appears next to + * "Execution Time" inside the Query object. */ + if (info->plan_text) + { + /* Inject percentage into plan_text for structured formats. + * Allocate in nested_memcxt so cleanup is automatic. */ + if (!info->is_trigger && info->nesting_level == 1 && + nested_total_time > 0 && info->exec_time_ms >= 0) + { + double pct = (info->exec_time_ms / nested_total_time) * 100.0; + MemoryContext oldcxt = MemoryContextSwitchTo(nested_memcxt); + + if (es->format == EXPLAIN_FORMAT_JSON) + { + /* Find "Execution Time": and append percentage after it */ + char *et = strstr(info->plan_text, "\"Execution Time\":"); + if (et) + { + /* Find end of the number (next \n or ,) */ + char *numstart = et + strlen("\"Execution Time\":"); + char *numend = numstart; + while (*numend && *numend != '\n' && *numend != ',') + numend++; + + /* Build new string with percentage inserted */ + { + StringInfoData newbuf; + initStringInfo(&newbuf); + appendBinaryStringInfo(&newbuf, info->plan_text, + numend - info->plan_text); + appendStringInfo(&newbuf, + ",\n \"Execution Time Percentage\": %.1f", + pct); + appendStringInfoString(&newbuf, numend); + pfree(info->plan_text); + info->plan_text = newbuf.data; + } + } + } + else if (es->format == EXPLAIN_FORMAT_XML) + { + /* Find and insert percentage element after it */ + char *et_end = strstr(info->plan_text, ""); + if (et_end) + { + StringInfoData newbuf; + char *after; + + et_end += strlen(""); + after = et_end; + + initStringInfo(&newbuf); + appendBinaryStringInfo(&newbuf, info->plan_text, + after - info->plan_text); + appendStringInfo(&newbuf, + "\n %.1f", + pct); + appendStringInfoString(&newbuf, after); + pfree(info->plan_text); + info->plan_text = newbuf.data; + } + } + else if (es->format == EXPLAIN_FORMAT_YAML) + { + /* Find "Execution Time:" line and append percentage after it */ + char *et = strstr(info->plan_text, "Execution Time:"); + if (et) + { + StringInfoData newbuf; + /* Find end of line */ + char *eol = et; + while (*eol && *eol != '\n') + eol++; + + initStringInfo(&newbuf); + appendBinaryStringInfo(&newbuf, info->plan_text, + eol - info->plan_text); + appendStringInfo(&newbuf, + "\n Execution Time Percentage: %.1f", + pct); + appendStringInfoString(&newbuf, eol); + pfree(info->plan_text); + info->plan_text = newbuf.data; + } + } + + MemoryContextSwitchTo(oldcxt); + } + + if (es->format == EXPLAIN_FORMAT_JSON) + { + char *p = info->plan_text; + char *end; + + /* The plan_text is "[{\n ...}]" from ExplainBeginOutput/ + * ExplainEndOutput. Strip the outer [] to get the raw + * object, then inject it as the value of "Plan". */ + + /* Skip leading [ and whitespace */ + while (*p == '[' || *p == '\n' || *p == ' ') + p++; + /* Find trailing ] and trim */ + end = p + strlen(p) - 1; + while (end > p && (*end == ']' || *end == '\n' || *end == ' ')) + end--; + *(end + 1) = '\0'; + + /* Emit comma if needed, then "Query": */ + if (linitial_int(es->grouping_stack) != 0) + appendStringInfoChar(es->str, ','); + else + linitial_int(es->grouping_stack) = 1; + appendStringInfoChar(es->str, '\n'); + appendStringInfoSpaces(es->str, 2 * es->indent); + appendStringInfoString(es->str, "\"Query\": "); + appendStringInfoString(es->str, p); + } + else if (es->format == EXPLAIN_FORMAT_XML) + { + /* For XML: strip outer ... wrapper + * and inject the ... content with proper + * indentation to match the surrounding elements. */ + char *qstart = strstr(info->plan_text, ""); + + if (qstart) + { + char *qend = strstr(info->plan_text, ""); + + if (qend) + { + char saved; + char *line; + char *next; + char *content; + int xml_indent = es->indent * 2; + int orig_indent; + char *p; + + qend += strlen(""); + saved = *qend; + *qend = '\0'; + + /* Determine original base indent (spaces before ) */ + orig_indent = 0; + p = qstart; + while (p > info->plan_text && *(p - 1) == ' ') + { + p--; + orig_indent++; + } + + /* Re-indent each line preserving relative structure. + * Use indent+1 to nest inside the Nested-Statement group, + * matching the level of sibling elements like Query-Text. */ + content = pstrdup(qstart); + *qend = saved; + + for (line = content; line && *line; line = next) + { + int line_indent = 0; + int new_indent; + + next = strchr(line, '\n'); + if (next) + { + *next = '\0'; + next++; + } + /* Count leading spaces */ + while (line[line_indent] == ' ') + line_indent++; + /* Skip empty lines */ + if (line[line_indent] == '\0') + { + appendStringInfoChar(es->str, '\n'); + continue; + } + /* Apply new indent: target + (original relative) */ + new_indent = xml_indent + 2 + (line_indent - orig_indent); + if (new_indent < 0) + new_indent = 0; + appendStringInfoSpaces(es->str, new_indent); + appendStringInfoString(es->str, line + line_indent); + appendStringInfoChar(es->str, '\n'); + } + pfree(content); + } + else + ExplainPropertyText("Plan Text", info->plan_text, es); + } + else + ExplainPropertyText("Plan Text", info->plan_text, es); + } + else + { + /* YAML: emit "Query:" key and re-indent plan text + * to nest it properly under the statement entry. */ + int yaml_indent = es->indent * 2; + char *line; + char *next; + char *plan_copy; + + appendStringInfoChar(es->str, '\n'); + appendStringInfoSpaces(es->str, yaml_indent); + appendStringInfoString(es->str, "Query:\n"); + + /* Re-indent each line of plan_text */ + plan_copy = pstrdup(info->plan_text); + for (line = plan_copy; line && *line; line = next) + { + next = strchr(line, '\n'); + if (next) + { + *next = '\0'; + next++; + } + /* Skip empty lines */ + if (*line == '\0') + { + appendStringInfoChar(es->str, '\n'); + continue; + } + appendStringInfoSpaces(es->str, yaml_indent + 2); + appendStringInfoString(es->str, line); + appendStringInfoChar(es->str, '\n'); + } + pfree(plan_copy); + } + } + + ExplainCloseGroup("Nested Statement", NULL, true, es); + } + + ExplainCloseGroup("Nested Plans", "Nested Plans", false, es); + } + + /* Print summary if enabled */ + if (es->summary && nested_total_count > 0) + { + int direct_count = nested_total_count - nested_trigger_count; + + if (es->format == EXPLAIN_FORMAT_TEXT) + { + appendStringInfoChar(es->str, '\n'); + appendStringInfoString(es->str, "Nested Statements Summary:\n"); + + if (nested_trigger_count > 0) + appendStringInfo(es->str, " Total: %d statements (%d direct, %d trigger-fired), max depth %d\n", + nested_total_count, direct_count, + nested_trigger_count, nested_max_depth); + else + appendStringInfo(es->str, " Total: %d statements, max depth %d\n", + nested_total_count, nested_max_depth); + + if (nested_main_exec_time > 0) + appendStringInfo(es->str, " Total Execution Time: %.3f ms\n", + nested_main_exec_time); + + if (nested_total_time > 0) + { + if (nested_main_exec_time > 0) + { + double pct = (nested_total_time / nested_main_exec_time) * 100.0; + appendStringInfo(es->str, " Total Nested Time: %.3f ms (%.1f%% of total time)\n", + nested_total_time, pct); + } + else + appendStringInfo(es->str, " Total Nested Time: %.3f ms\n", + nested_total_time); + } + + if (nested_trigger_time > 0) + { + if (nested_total_time > 0) + { + double pct = (nested_trigger_time / nested_total_time) * 100.0; + appendStringInfo(es->str, " Total Trigger Time: %.3f ms (%.1f%% of nested time)\n", + nested_trigger_time, pct); + } + else + appendStringInfo(es->str, " Total Trigger Time: %.3f ms\n", + nested_trigger_time); + } + + if (nested_slowest_num > 0) + { + if (nested_plans_head == NULL) + { + /* SHOW_NESTED 0: no plans displayed, omit #N */ + if (nested_total_time > 0) + { + double pct = (nested_slowest_time / nested_total_time) * 100.0; + appendStringInfo(es->str, " Slowest Statement: %.3f ms (%.1f%%)\n", + nested_slowest_time, pct); + } + else + appendStringInfo(es->str, " Slowest Statement: %.3f ms\n", + nested_slowest_time); + } + else if (nested_total_time > 0) + { + double pct = (nested_slowest_time / nested_total_time) * 100.0; + appendStringInfo(es->str, " Slowest Statement: #%d (%.3f ms, %.1f%%)\n", + nested_slowest_num, nested_slowest_time, pct); + } + else + appendStringInfo(es->str, " Slowest Statement: #%d (%.3f ms)\n", + nested_slowest_num, nested_slowest_time); + } + } + else + { + /* Structured summary for JSON/XML/YAML */ + ExplainOpenGroup("Nested Statements Summary", "Nested Statements Summary", + true, es); + ExplainPropertyInteger("Total Statements", NULL, + nested_total_count, es); + ExplainPropertyInteger("Direct Statements", NULL, + direct_count, es); + ExplainPropertyInteger("Trigger-Fired Statements", NULL, + nested_trigger_count, es); + ExplainPropertyInteger("Max Depth", NULL, + nested_max_depth, es); + if (nested_main_exec_time > 0) + ExplainPropertyFloat("Total Execution Time", "ms", + nested_main_exec_time, 3, es); + if (nested_total_time > 0) + ExplainPropertyFloat("Total Nested Time", "ms", + nested_total_time, 3, es); + if (nested_trigger_time > 0) + ExplainPropertyFloat("Total Trigger Time", "ms", + nested_trigger_time, 3, es); + if (nested_slowest_num > 0) + { + ExplainPropertyInteger("Slowest Statement Number", NULL, + nested_slowest_num, es); + ExplainPropertyFloat("Slowest Statement Time", "ms", + nested_slowest_time, 3, es); + } + ExplainCloseGroup("Nested Statements Summary", "Nested Statements Summary", + true, es); + } + } + + /* Warn if high volume of nested statements and no SHOW_NESTED limit set */ + if (nested_total_count > NESTED_STMT_NOTICE_THRESHOLD && + es->show_nested < 0) + { + ereport(NOTICE, + (errmsg("%d nested statements captured" + " (per-row SQL function calls can produce high counts)", + nested_total_count), + errhint("Use SHOW_NESTED 0 for summary only, " + "or SHOW_NESTED N to display the first N plans."))); + } + + /* No need to free individual items — MemoryContextDelete in PG_FINALLY + * will free everything in nested_memcxt at once. */ + nested_plans_head = NULL; + nested_plans_tail = NULL; +} diff --git a/src/backend/commands/explain_state.c b/src/backend/commands/explain_state.c index a0ee0a664be..73bce1b350c 100644 --- a/src/backend/commands/explain_state.c +++ b/src/backend/commands/explain_state.c @@ -67,6 +67,7 @@ NewExplainState(void) /* Set default options (most fields can be left as zeroes). */ es->costs = true; + es->show_nested = -1; /* show all nested plans by default */ /* Prepare output buffer. */ es->str = makeStringInfo(); @@ -164,6 +165,17 @@ ParseExplainOptionList(ExplainState *es, List *options, ParseState *pstate) } else if (strcmp(opt->defname, "io") == 0) es->io = defGetBoolean(opt); + else if (strcmp(opt->defname, "nested_statements") == 0) + es->nested_statements = defGetBoolean(opt); + else if (strcmp(opt->defname, "show_nested") == 0) + { + es->show_nested = defGetInt32(opt); + if (es->show_nested < 0) + ereport(ERROR, + (errcode(ERRCODE_INVALID_PARAMETER_VALUE), + errmsg("EXPLAIN option %s must be a non-negative integer", + "SHOW_NESTED"))); + } else if (!ApplyExtensionExplainOption(es, opt, pstate)) ereport(ERROR, (errcode(ERRCODE_SYNTAX_ERROR), @@ -202,6 +214,19 @@ ParseExplainOptionList(ExplainState *es, List *options, ParseState *pstate) (errcode(ERRCODE_INVALID_PARAMETER_VALUE), errmsg("EXPLAIN option %s requires ANALYZE", "SERIALIZE"))); + /* check that NESTED_STATEMENTS is used with EXPLAIN ANALYZE */ + if (es->nested_statements && !es->analyze) + ereport(ERROR, + (errcode(ERRCODE_INVALID_PARAMETER_VALUE), + errmsg("EXPLAIN option %s requires ANALYZE", "NESTED_STATEMENTS"))); + + /* check that SHOW_NESTED is used with NESTED_STATEMENTS */ + if (es->show_nested >= 0 && !es->nested_statements) + ereport(ERROR, + (errcode(ERRCODE_INVALID_PARAMETER_VALUE), + errmsg("EXPLAIN option %s requires %s", + "SHOW_NESTED", "NESTED_STATEMENTS"))); + /* check that GENERIC_PLAN is not used with EXPLAIN ANALYZE */ if (es->generic && es->analyze) ereport(ERROR, diff --git a/src/backend/commands/trigger.c b/src/backend/commands/trigger.c index b87b4b40d07..097ddf800b0 100644 --- a/src/backend/commands/trigger.c +++ b/src/backend/commands/trigger.c @@ -6783,10 +6783,26 @@ assign_session_replication_role(int newval, void *extra) /* * SQL function pg_trigger_depth() */ +/* + * GetMyTriggerDepth - return current trigger nesting depth. + * + * This is a C-callable accessor for MyTriggerDepth, allowing other + * subsystems (e.g., EXPLAIN NESTED_STATEMENTS) to detect whether + * execution is currently inside a trigger function. + */ +int +GetMyTriggerDepth(void) +{ + return MyTriggerDepth; +} + +/* + * SQL-callable function to report trigger nesting depth. + */ Datum pg_trigger_depth(PG_FUNCTION_ARGS) { - PG_RETURN_INT32(MyTriggerDepth); + PG_RETURN_INT32(GetMyTriggerDepth()); } /* diff --git a/src/include/commands/explain_state.h b/src/include/commands/explain_state.h index 97bc7ed49f6..01fef3068b6 100644 --- a/src/include/commands/explain_state.h +++ b/src/include/commands/explain_state.h @@ -57,6 +57,8 @@ typedef struct ExplainState bool settings; /* print modified settings */ bool io; /* print info about IO (prefetch, ...) */ bool generic; /* generate a generic plan */ + bool nested_statements; /* print nested statement plans */ + int show_nested; /* how many nested plans to display (-1=all) */ ExplainSerializeOption serialize; /* serialize the query's output? */ ExplainFormat format; /* output format */ /* state for output formatting --- not reset for each new plan tree */ diff --git a/src/include/commands/trigger.h b/src/include/commands/trigger.h index 1d9869973c0..83c97141876 100644 --- a/src/include/commands/trigger.h +++ b/src/include/commands/trigger.h @@ -310,4 +310,6 @@ extern void RegisterAfterTriggerBatchCallback(AfterTriggerBatchCallback callback void *arg); extern bool AfterTriggerIsActive(void); +extern int GetMyTriggerDepth(void); + #endif /* TRIGGER_H */ -- 2.50.1 (Apple Git-155)