From f7ee0e80f0c9093b33d10b4e0881df6e4b83700f Mon Sep 17 00:00:00 2001 From: Ubuntu Date: Wed, 14 Jan 2026 00:09:15 +0000 Subject: [PATCH v2 1/1] pg_stat_statements: Fix nested tracking for implicitly closed cursors When cursors are implicitly closed during COMMIT, pg_stat_statements incorrectly marks the cursor's underlying query as toplevel=true because PortalCleanup, which triggers ExecutorEnd, runs after ProcessUtility and at which point the nesting_level is 0. Fix by adding an is_txn_end flag to detect COMMIT statements and temporarily adjust nesting_level in ExecutorEnd. Add regression tests for both explicit and implicit cursor closure, with track = 'all' and with and without track_planning. Discussion: https://postgr.es/m/CAA5RZ0t2+GLnE_55L2cfCay+L8yPFpdPRVQo-JswUFgXy-EK5Q@mail.gmail.com --- .../expected/level_tracking.out | 176 ++++++++++++++++++ .../pg_stat_statements/pg_stat_statements.c | 90 ++++++--- .../pg_stat_statements/sql/level_tracking.sql | 62 ++++++ 3 files changed, 302 insertions(+), 26 deletions(-) diff --git a/contrib/pg_stat_statements/expected/level_tracking.out b/contrib/pg_stat_statements/expected/level_tracking.out index 8e8388dd5cb..df4e5374c66 100644 --- a/contrib/pg_stat_statements/expected/level_tracking.out +++ b/contrib/pg_stat_statements/expected/level_tracking.out @@ -1122,6 +1122,7 @@ SELECT toplevel, calls, query FROM pg_stat_statements (2 rows) -- DECLARE CURSOR, all-level tracking. +-- Explicitly close cursor SET pg_stat_statements.track = 'all'; SELECT pg_stat_statements_reset() IS NOT NULL AS t; t @@ -1151,6 +1152,157 @@ SELECT toplevel, calls, query FROM pg_stat_statements t | 1 | SELECT pg_stat_statements_reset() IS NOT NULL AS t (7 rows) +-- Implicitly close cursor +SET pg_stat_statements.track = 'all'; +SELECT pg_stat_statements_reset() IS NOT NULL AS t; + t +--- + t +(1 row) + +BEGIN; +DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; +FETCH FORWARD 1 FROM foocur; + x +--- +(0 rows) + +COMMIT; +SELECT toplevel, calls, query FROM pg_stat_statements + ORDER BY query COLLATE "C"; + toplevel | calls | query +----------+-------+---------------------------------------------------------- + t | 1 | BEGIN + t | 1 | COMMIT + t | 1 | DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab + f | 1 | DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; + t | 1 | FETCH FORWARD $1 FROM foocur + t | 1 | SELECT pg_stat_statements_reset() IS NOT NULL AS t +(6 rows) + +SET pg_stat_statements.track = 'all'; +SELECT pg_stat_statements_reset() IS NOT NULL AS t; + t +--- + t +(1 row) + +BEGIN; +DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; +FETCH FORWARD 1 FROM foocur; + x +--- +(0 rows) + +END; +SELECT toplevel, calls, query FROM pg_stat_statements + ORDER BY query COLLATE "C"; + toplevel | calls | query +----------+-------+---------------------------------------------------------- + t | 1 | BEGIN + t | 1 | DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab + f | 1 | DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; + t | 1 | END + t | 1 | FETCH FORWARD $1 FROM foocur + t | 1 | SELECT pg_stat_statements_reset() IS NOT NULL AS t +(6 rows) + +-- DECLARE CURSOR, all-level tracking with track_planning +-- Explicitly close cursor +SET pg_stat_statements.track = 'all'; +SET pg_stat_statements.track_planning = 'on'; +SELECT pg_stat_statements_reset() IS NOT NULL AS t; + t +--- + t +(1 row) + +BEGIN; +DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; +FETCH FORWARD 1 FROM foocur; + x +--- +(0 rows) + +CLOSE foocur; +COMMIT; +SELECT toplevel, calls, plans, query FROM pg_stat_statements + ORDER BY query COLLATE "C"; + toplevel | calls | plans | query +----------+-------+-------+-------------------------------------------------------------- + t | 1 | 0 | BEGIN + t | 1 | 0 | CLOSE foocur + t | 1 | 0 | COMMIT + t | 1 | 0 | DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab + f | 1 | 1 | DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; + t | 1 | 0 | FETCH FORWARD $1 FROM foocur + t | 1 | 0 | SELECT pg_stat_statements_reset() IS NOT NULL AS t + t | 0 | 1 | SELECT toplevel, calls, plans, query FROM pg_stat_statements+ + | | | ORDER BY query COLLATE "C" +(8 rows) + +-- Implicitly close cursor +SET pg_stat_statements.track = 'all'; +SET pg_stat_statements.track_planning = 'on'; +SELECT pg_stat_statements_reset() IS NOT NULL AS t; + t +--- + t +(1 row) + +BEGIN; +DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; +FETCH FORWARD 1 FROM foocur; + x +--- +(0 rows) + +COMMIT; +SELECT toplevel, calls, plans, query FROM pg_stat_statements + ORDER BY query COLLATE "C"; + toplevel | calls | plans | query +----------+-------+-------+-------------------------------------------------------------- + t | 1 | 0 | BEGIN + t | 1 | 0 | COMMIT + t | 1 | 0 | DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab + f | 1 | 1 | DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; + t | 1 | 0 | FETCH FORWARD $1 FROM foocur + t | 1 | 0 | SELECT pg_stat_statements_reset() IS NOT NULL AS t + t | 0 | 1 | SELECT toplevel, calls, plans, query FROM pg_stat_statements+ + | | | ORDER BY query COLLATE "C" +(7 rows) + +SET pg_stat_statements.track = 'all'; +SET pg_stat_statements.track_planning = 'on'; +SELECT pg_stat_statements_reset() IS NOT NULL AS t; + t +--- + t +(1 row) + +BEGIN; +DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; +FETCH FORWARD 1 FROM foocur; + x +--- +(0 rows) + +END; +SELECT toplevel, calls, plans, query FROM pg_stat_statements + ORDER BY query COLLATE "C"; + toplevel | calls | plans | query +----------+-------+-------+-------------------------------------------------------------- + t | 1 | 0 | BEGIN + t | 1 | 0 | DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab + f | 1 | 1 | DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; + t | 1 | 0 | END + t | 1 | 0 | FETCH FORWARD $1 FROM foocur + t | 1 | 0 | SELECT pg_stat_statements_reset() IS NOT NULL AS t + t | 0 | 1 | SELECT toplevel, calls, plans, query FROM pg_stat_statements+ + | | | ORDER BY query COLLATE "C" +(7 rows) + +RESET pg_stat_statements.track_planning; -- DECLARE CURSOR, top-level tracking. SET pg_stat_statements.track = 'top'; SELECT pg_stat_statements_reset() IS NOT NULL AS t; @@ -1535,6 +1687,30 @@ SELECT toplevel, calls, rows, query FROM pg_stat_statements ORDER BY query COLLA t | 1 | 1 | SELECT pg_stat_statements_reset() IS NOT NULL AS t (8 rows) +-- +-- Ensure that a statement following a COMMIT has correct tracking level +-- +SELECT pg_stat_statements_reset() IS NOT NULL AS t; + t +--- + t +(1 row) + +BEGIN; +COMMIT; +SELECT 1, 2; + ?column? | ?column? +----------+---------- + 1 | 2 +(1 row) + +SELECT toplevel, calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C"; + toplevel | calls | rows | query +----------+-------+------+---------------------------------------------------- + t | 1 | 1 | SELECT $1, $2 + t | 1 | 1 | SELECT pg_stat_statements_reset() IS NOT NULL AS t +(2 rows) + -- -- pg_stat_statements.track = none -- diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c index adc493e9850..3cb888a5cd2 100644 --- a/contrib/pg_stat_statements/pg_stat_statements.c +++ b/contrib/pg_stat_statements/pg_stat_statements.c @@ -263,6 +263,18 @@ typedef struct pgssSharedState /* Current nesting depth of planner/ExecutorRun/ProcessUtility calls */ static int nesting_level = 0; +/* + * This flag is set to true in pgss_ProcessUtility when processing a COMMIT, + * and checked in pgss_ExecutorEnd to increment the nesting_level, which + * is needed when pgss_ExecutorEnd is called during PortalCleanup. An example + * is storing a query associated with a DECLARE CURSOR statement. + * + * The flag is reset to false at the start of each hook function + * (pgss_post_parse_analyze, pgss_planner, pgss_ProcessUtility, and in + * pgss_ExecutorEnd after use) to ensure it never leaks across statements. + */ +static bool is_txn_end = false; + /* Saved hook values */ static shmem_request_hook_type prev_shmem_request_hook = NULL; static shmem_startup_hook_type prev_shmem_startup_hook = NULL; @@ -841,6 +853,8 @@ error: static void pgss_post_parse_analyze(ParseState *pstate, Query *query, JumbleState *jstate) { + is_txn_end = false; + if (prev_post_parse_analyze_hook) prev_post_parse_analyze_hook(pstate, query, jstate); @@ -900,6 +914,8 @@ pgss_planner(Query *parse, { PlannedStmt *result; + is_txn_end = false; + /* * We can't process the query if no query_string is provided, as * pgss_store needs it. We also ignore query without queryid, as it would @@ -1079,35 +1095,47 @@ pgss_ExecutorEnd(QueryDesc *queryDesc) { int64 queryId = queryDesc->plannedstmt->queryId; - if (queryId != INT64CONST(0) && queryDesc->totaltime && - pgss_enabled(nesting_level)) + if (is_txn_end) + nesting_level++; + + PG_TRY(); { - /* - * Make sure stats accumulation is done. (Note: it's okay if several - * levels of hook all do this.) - */ - InstrEndLoop(queryDesc->totaltime); + if (queryId != INT64CONST(0) && queryDesc->totaltime && + pgss_enabled(nesting_level)) + { + /* + * Make sure stats accumulation is done. (Note: it's okay if + * several levels of hook all do this.) + */ + InstrEndLoop(queryDesc->totaltime); + + pgss_store(queryDesc->sourceText, + queryId, + queryDesc->plannedstmt->stmt_location, + queryDesc->plannedstmt->stmt_len, + PGSS_EXEC, + INSTR_TIME_GET_MILLISEC(queryDesc->totaltime->total), + queryDesc->estate->es_total_processed, + &queryDesc->totaltime->bufusage, + &queryDesc->totaltime->walusage, + queryDesc->estate->es_jit ? &queryDesc->estate->es_jit->instr : NULL, + NULL, + queryDesc->estate->es_parallel_workers_to_launch, + queryDesc->estate->es_parallel_workers_launched, + queryDesc->plannedstmt->planOrigin); + } - pgss_store(queryDesc->sourceText, - queryId, - queryDesc->plannedstmt->stmt_location, - queryDesc->plannedstmt->stmt_len, - PGSS_EXEC, - INSTR_TIME_GET_MILLISEC(queryDesc->totaltime->total), - queryDesc->estate->es_total_processed, - &queryDesc->totaltime->bufusage, - &queryDesc->totaltime->walusage, - queryDesc->estate->es_jit ? &queryDesc->estate->es_jit->instr : NULL, - NULL, - queryDesc->estate->es_parallel_workers_to_launch, - queryDesc->estate->es_parallel_workers_launched, - queryDesc->plannedstmt->planOrigin); + if (prev_ExecutorEnd) + prev_ExecutorEnd(queryDesc); + else + standard_ExecutorEnd(queryDesc); } - - if (prev_ExecutorEnd) - prev_ExecutorEnd(queryDesc); - else - standard_ExecutorEnd(queryDesc); + PG_FINALLY(); + { + if (is_txn_end) + nesting_level--; + } + PG_END_TRY(); } /* @@ -1126,6 +1154,8 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString, int saved_stmt_len = pstmt->stmt_len; bool enabled = pgss_track_utility && pgss_enabled(nesting_level); + is_txn_end = false; + /* * Force utility statements to get queryId zero. We do this even in cases * where the statement contains an optimizable statement for which a @@ -1236,6 +1266,14 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString, 0, 0, pstmt->planOrigin); + + /* Set flag for COMMIT to adjust nesting_level in ExecutorEnd */ + if (IsA(parsetree, TransactionStmt)) + { + TransactionStmt *stmt = (TransactionStmt *) parsetree; + + is_txn_end = (stmt->kind == TRANS_STMT_COMMIT); + } } else { diff --git a/contrib/pg_stat_statements/sql/level_tracking.sql b/contrib/pg_stat_statements/sql/level_tracking.sql index 86f007e8552..123919d4562 100644 --- a/contrib/pg_stat_statements/sql/level_tracking.sql +++ b/contrib/pg_stat_statements/sql/level_tracking.sql @@ -252,6 +252,7 @@ SELECT toplevel, calls, query FROM pg_stat_statements ORDER BY query COLLATE "C"; -- DECLARE CURSOR, all-level tracking. +-- Explicitly close cursor SET pg_stat_statements.track = 'all'; SELECT pg_stat_statements_reset() IS NOT NULL AS t; BEGIN; @@ -261,6 +262,58 @@ CLOSE foocur; COMMIT; SELECT toplevel, calls, query FROM pg_stat_statements ORDER BY query COLLATE "C"; +-- Implicitly close cursor +SET pg_stat_statements.track = 'all'; +SELECT pg_stat_statements_reset() IS NOT NULL AS t; +BEGIN; +DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; +FETCH FORWARD 1 FROM foocur; +COMMIT; +SELECT toplevel, calls, query FROM pg_stat_statements + ORDER BY query COLLATE "C"; + +SET pg_stat_statements.track = 'all'; +SELECT pg_stat_statements_reset() IS NOT NULL AS t; +BEGIN; +DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; +FETCH FORWARD 1 FROM foocur; +END; +SELECT toplevel, calls, query FROM pg_stat_statements + ORDER BY query COLLATE "C"; + +-- DECLARE CURSOR, all-level tracking with track_planning +-- Explicitly close cursor +SET pg_stat_statements.track = 'all'; +SET pg_stat_statements.track_planning = 'on'; +SELECT pg_stat_statements_reset() IS NOT NULL AS t; +BEGIN; +DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; +FETCH FORWARD 1 FROM foocur; +CLOSE foocur; +COMMIT; +SELECT toplevel, calls, plans, query FROM pg_stat_statements + ORDER BY query COLLATE "C"; +-- Implicitly close cursor +SET pg_stat_statements.track = 'all'; +SET pg_stat_statements.track_planning = 'on'; +SELECT pg_stat_statements_reset() IS NOT NULL AS t; +BEGIN; +DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; +FETCH FORWARD 1 FROM foocur; +COMMIT; +SELECT toplevel, calls, plans, query FROM pg_stat_statements + ORDER BY query COLLATE "C"; + +SET pg_stat_statements.track = 'all'; +SET pg_stat_statements.track_planning = 'on'; +SELECT pg_stat_statements_reset() IS NOT NULL AS t; +BEGIN; +DECLARE FOOCUR CURSOR FOR SELECT * from stats_track_tab; +FETCH FORWARD 1 FROM foocur; +END; +SELECT toplevel, calls, plans, query FROM pg_stat_statements + ORDER BY query COLLATE "C"; +RESET pg_stat_statements.track_planning; -- DECLARE CURSOR, top-level tracking. SET pg_stat_statements.track = 'top'; @@ -432,6 +485,15 @@ SELECT PLUS_THREE(10); SELECT toplevel, calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C"; +-- +-- Ensure that a statement following a COMMIT has correct tracking level +-- +SELECT pg_stat_statements_reset() IS NOT NULL AS t; +BEGIN; +COMMIT; +SELECT 1, 2; +SELECT toplevel, calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C"; + -- -- pg_stat_statements.track = none -- -- 2.43.0