diff --git a/contrib/pg_stat_statements/expected/level_tracking.out b/contrib/pg_stat_statements/expected/level_tracking.out index d924c87b41e..0b94c71c9c1 100644 --- a/contrib/pg_stat_statements/expected/level_tracking.out +++ b/contrib/pg_stat_statements/expected/level_tracking.out @@ -67,6 +67,61 @@ SELECT toplevel, calls, query FROM pg_stat_statements t | 1 | SET pg_stat_statements.track = 'all' (7 rows) +-- DO block - top-level tracking without utility. +SET pg_stat_statements.track = 'top'; +SET pg_stat_statements.track_utility = FALSE; +SELECT pg_stat_statements_reset(); + pg_stat_statements_reset +-------------------------- + +(1 row) + +DELETE FROM stats_track_tab; +DO $$ +BEGIN + DELETE FROM stats_track_tab; +END; $$; +DO LANGUAGE plpgsql $$ +BEGIN + -- this is a SELECT + PERFORM 'hello world'::TEXT; +END; $$; +SELECT toplevel, calls, query FROM pg_stat_statements + ORDER BY query COLLATE "C", toplevel; + toplevel | calls | query +----------+-------+----------------------------------- + t | 1 | DELETE FROM stats_track_tab + t | 1 | SELECT pg_stat_statements_reset() +(2 rows) + +-- DO block - all-level tracking without utility. +SET pg_stat_statements.track = 'all'; +SELECT pg_stat_statements_reset(); + pg_stat_statements_reset +-------------------------- + +(1 row) + +DELETE FROM stats_track_tab; +DO $$ +BEGIN + DELETE FROM stats_track_tab; +END; $$; +DO LANGUAGE plpgsql $$ +BEGIN + -- this is a SELECT + PERFORM 'hello world'::TEXT; +END; $$; +SELECT toplevel, calls, query FROM pg_stat_statements + ORDER BY query COLLATE "C", toplevel; + toplevel | calls | query +----------+-------+----------------------------------- + f | 1 | DELETE FROM stats_track_tab + t | 1 | DELETE FROM stats_track_tab + f | 1 | SELECT $1::TEXT + t | 1 | SELECT pg_stat_statements_reset() +(4 rows) + -- PL/pgSQL function - top-level tracking. SET pg_stat_statements.track = 'top'; SET pg_stat_statements.track_utility = FALSE; @@ -118,6 +173,31 @@ SELECT calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C"; 1 | 1 | SELECT pg_stat_statements_reset() (3 rows) +-- immutable SQL function --- can be executed at plan time +CREATE FUNCTION PLUS_THREE(i INTEGER) RETURNS INTEGER AS +$$ SELECT i + 3 LIMIT 1 $$ IMMUTABLE LANGUAGE SQL; +SELECT PLUS_THREE(8); + plus_three +------------ + 11 +(1 row) + +SELECT PLUS_THREE(10); + plus_three +------------ + 13 +(1 row) + +SELECT toplevel, calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C"; + toplevel | calls | rows | query +----------+-------+------+------------------------------------------------------------------------------ + t | 2 | 2 | SELECT PLUS_ONE($1) + t | 2 | 2 | SELECT PLUS_THREE($1) + t | 2 | 2 | SELECT PLUS_TWO($1) + t | 1 | 3 | SELECT calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C" + t | 1 | 1 | SELECT pg_stat_statements_reset() +(5 rows) + -- PL/pgSQL function - all-level tracking. SET pg_stat_statements.track = 'all'; SELECT pg_stat_statements_reset(); @@ -129,6 +209,7 @@ SELECT pg_stat_statements_reset(); -- we drop and recreate the functions to avoid any caching funnies DROP FUNCTION PLUS_ONE(INTEGER); DROP FUNCTION PLUS_TWO(INTEGER); +DROP FUNCTION PLUS_THREE(INTEGER); -- PL/pgSQL function CREATE FUNCTION PLUS_TWO(i INTEGER) RETURNS INTEGER AS $$ DECLARE @@ -174,7 +255,34 @@ SELECT calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C"; 1 | 1 | SELECT pg_stat_statements_reset() (5 rows) -DROP FUNCTION PLUS_ONE(INTEGER); +-- immutable SQL function --- can be executed at plan time +CREATE FUNCTION PLUS_THREE(i INTEGER) RETURNS INTEGER AS +$$ SELECT i + 3 LIMIT 1 $$ IMMUTABLE LANGUAGE SQL; +SELECT PLUS_THREE(8); + plus_three +------------ + 11 +(1 row) + +SELECT PLUS_THREE(10); + plus_three +------------ + 13 +(1 row) + +SELECT toplevel, calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C"; + toplevel | calls | rows | query +----------+-------+------+------------------------------------------------------------------------------ + f | 2 | 2 | SELECT (i + $2 + $3)::INTEGER + f | 2 | 2 | SELECT (i + $2)::INTEGER LIMIT $3 + t | 2 | 2 | SELECT PLUS_ONE($1) + t | 2 | 2 | SELECT PLUS_THREE($1) + t | 2 | 2 | SELECT PLUS_TWO($1) + t | 1 | 5 | SELECT calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C" + f | 2 | 2 | SELECT i + $2 LIMIT $3 + t | 1 | 1 | SELECT pg_stat_statements_reset() +(8 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 767b6ceb107..6c63acf9898 100644 --- a/contrib/pg_stat_statements/pg_stat_statements.c +++ b/contrib/pg_stat_statements/pg_stat_statements.c @@ -99,13 +99,6 @@ static const uint32 PGSS_PG_MAJOR_VERSION = PG_VERSION_NUM / 100; #define USAGE_DEALLOC_PERCENT 5 /* free this % of entries at once */ #define IS_STICKY(c) ((c.calls[PGSS_PLAN] + c.calls[PGSS_EXEC]) == 0) -/* - * Utility statements that pgss_ProcessUtility and pgss_post_parse_analyze - * ignores. - */ -#define PGSS_HANDLED_UTILITY(n) (!IsA(n, ExecuteStmt) && \ - !IsA(n, PrepareStmt)) - /* * Extension version number, for supporting older extension versions' objects */ @@ -255,11 +248,8 @@ typedef struct pgssSharedState /*---- Local variables ----*/ -/* Current nesting depth of ExecutorRun+ProcessUtility calls */ -static int exec_nested_level = 0; - -/* Current nesting depth of planner calls */ -static int plan_nested_level = 0; +/* Current nesting depth of planner/ExecutorRun/ProcessUtility calls */ +static int nesting_level = 0; /* Saved hook values in case of unload */ static shmem_request_hook_type prev_shmem_request_hook = NULL; @@ -836,16 +826,18 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query, JumbleState *jstate) prev_post_parse_analyze_hook(pstate, query, jstate); /* Safety check... */ - if (!pgss || !pgss_hash || !pgss_enabled(exec_nested_level)) + if (!pgss || !pgss_hash || !pgss_enabled(nesting_level)) return; /* - * Clear queryId for prepared statements related utility, as those will - * inherit from the underlying statement's one. + * If it's EXECUTE, clear the queryId so that stats will accumulate for + * the underlying PREPARE. But don't do this if we're not tracking + * utility statements, to avoid messing up another extension that might be + * tracking them. */ if (query->utilityStmt) { - if (pgss_track_utility && !PGSS_HANDLED_UTILITY(query->utilityStmt)) + if (pgss_track_utility && IsA(query->utilityStmt, ExecuteStmt)) { query->queryId = UINT64CONST(0); return; @@ -897,7 +889,7 @@ pgss_planner(Query *parse, * So testing the planner nesting level only is not enough to detect real * top level planner call. */ - if (pgss_enabled(plan_nested_level + exec_nested_level) + if (pgss_enabled(nesting_level) && pgss_track_planning && query_string && parse->queryId != UINT64CONST(0)) { @@ -918,7 +910,7 @@ pgss_planner(Query *parse, walusage_start = pgWalUsage; INSTR_TIME_SET_CURRENT(start); - plan_nested_level++; + nesting_level++; PG_TRY(); { if (prev_planner_hook) @@ -930,7 +922,7 @@ pgss_planner(Query *parse, } PG_FINALLY(); { - plan_nested_level--; + nesting_level--; } PG_END_TRY(); @@ -959,12 +951,26 @@ pgss_planner(Query *parse, } else { - if (prev_planner_hook) - result = prev_planner_hook(parse, query_string, cursorOptions, - boundParams); - else - result = standard_planner(parse, query_string, cursorOptions, - boundParams); + /* + * Even though we're not tracking plan time for this statement, we + * must still increment the nesting level, to ensure that functions + * evaluated during planning are not seen as top-level calls. + */ + nesting_level++; + PG_TRY(); + { + if (prev_planner_hook) + result = prev_planner_hook(parse, query_string, cursorOptions, + boundParams); + else + result = standard_planner(parse, query_string, cursorOptions, + boundParams); + } + PG_FINALLY(); + { + nesting_level--; + } + PG_END_TRY(); } return result; @@ -986,7 +992,7 @@ pgss_ExecutorStart(QueryDesc *queryDesc, int eflags) * counting of optimizable statements that are directly contained in * utility statements. */ - if (pgss_enabled(exec_nested_level) && queryDesc->plannedstmt->queryId != UINT64CONST(0)) + if (pgss_enabled(nesting_level) && queryDesc->plannedstmt->queryId != UINT64CONST(0)) { /* * Set up to track total elapsed time in ExecutorRun. Make sure the @@ -1011,7 +1017,7 @@ static void pgss_ExecutorRun(QueryDesc *queryDesc, ScanDirection direction, uint64 count, bool execute_once) { - exec_nested_level++; + nesting_level++; PG_TRY(); { if (prev_ExecutorRun) @@ -1021,7 +1027,7 @@ pgss_ExecutorRun(QueryDesc *queryDesc, ScanDirection direction, uint64 count, } PG_FINALLY(); { - exec_nested_level--; + nesting_level--; } PG_END_TRY(); } @@ -1032,7 +1038,7 @@ pgss_ExecutorRun(QueryDesc *queryDesc, ScanDirection direction, uint64 count, static void pgss_ExecutorFinish(QueryDesc *queryDesc) { - exec_nested_level++; + nesting_level++; PG_TRY(); { if (prev_ExecutorFinish) @@ -1042,7 +1048,7 @@ pgss_ExecutorFinish(QueryDesc *queryDesc) } PG_FINALLY(); { - exec_nested_level--; + nesting_level--; } PG_END_TRY(); } @@ -1056,7 +1062,7 @@ pgss_ExecutorEnd(QueryDesc *queryDesc) uint64 queryId = queryDesc->plannedstmt->queryId; if (queryId != UINT64CONST(0) && queryDesc->totaltime && - pgss_enabled(exec_nested_level)) + pgss_enabled(nesting_level)) { /* * Make sure stats accumulation is done. (Note: it's okay if several @@ -1097,6 +1103,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString, uint64 saved_queryId = pstmt->queryId; int saved_stmt_location = pstmt->stmt_location; int saved_stmt_len = pstmt->stmt_len; + bool enabled = pgss_track_utility && pgss_enabled(nesting_level); /* * Force utility statements to get queryId zero. We do this even in cases @@ -1112,7 +1119,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString, * that user configured another extension to handle utility statements * only. */ - if (pgss_enabled(exec_nested_level) && pgss_track_utility) + if (enabled) pstmt->queryId = UINT64CONST(0); /* @@ -1124,11 +1131,13 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString, * hash table entry for the PREPARE (with hash calculated from the query * string), and then a different one with the same query string (but hash * calculated from the query tree) would be used to accumulate costs of - * ensuing EXECUTEs. This would be confusing, and inconsistent with other - * cases where planning time is not included at all. + * ensuing EXECUTEs. This would be confusing. Since PREPARE doesn't + * actually run the planner (only parse+rewrite), its costs are generally + * pretty negligible and it seems okay to just ignore it. */ - if (pgss_track_utility && pgss_enabled(exec_nested_level) && - PGSS_HANDLED_UTILITY(parsetree)) + if (enabled && + !IsA(parsetree, ExecuteStmt) && + !IsA(parsetree, PrepareStmt)) { instr_time start; instr_time duration; @@ -1142,7 +1151,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString, walusage_start = pgWalUsage; INSTR_TIME_SET_CURRENT(start); - exec_nested_level++; + nesting_level++; PG_TRY(); { if (prev_ProcessUtility) @@ -1156,7 +1165,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString, } PG_FINALLY(); { - exec_nested_level--; + nesting_level--; } PG_END_TRY(); @@ -1206,14 +1215,41 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString, } else { - if (prev_ProcessUtility) - prev_ProcessUtility(pstmt, queryString, readOnlyTree, - context, params, queryEnv, - dest, qc); - else - standard_ProcessUtility(pstmt, queryString, readOnlyTree, + /* + * Even though we're not tracking execution time for this statement, + * we must still increment the nesting level, to ensure that functions + * evaluated within it are not seen as top-level calls. But don't do + * so for EXECUTE; that way, when control reaches pgss_planner or + * pgss_ExecutorStart, we will treat the costs as top-level if + * appropriate. Likewise, don't bump for PREPARE, so that parse + * analysis will treat the statement as top-level if appropriate. + * + * To be absolutely certain we don't mess up the nesting level, + * evaluate the bump_level condition just once. + */ + bool bump_level = + !IsA(parsetree, ExecuteStmt) && + !IsA(parsetree, PrepareStmt); + + if (bump_level) + nesting_level++; + PG_TRY(); + { + if (prev_ProcessUtility) + prev_ProcessUtility(pstmt, queryString, readOnlyTree, context, params, queryEnv, dest, qc); + else + standard_ProcessUtility(pstmt, queryString, readOnlyTree, + context, params, queryEnv, + dest, qc); + } + PG_FINALLY(); + { + if (bump_level) + nesting_level--; + } + PG_END_TRY(); } } @@ -1271,7 +1307,7 @@ pgss_store(const char *query, uint64 queryId, key.userid = GetUserId(); key.dbid = MyDatabaseId; key.queryid = queryId; - key.toplevel = (exec_nested_level == 0); + key.toplevel = (nesting_level == 0); /* Lookup the hash table entry with shared lock. */ LWLockAcquire(pgss->lock, LW_SHARED); diff --git a/contrib/pg_stat_statements/sql/level_tracking.sql b/contrib/pg_stat_statements/sql/level_tracking.sql index 0c20b8ce69b..dcd0b043580 100644 --- a/contrib/pg_stat_statements/sql/level_tracking.sql +++ b/contrib/pg_stat_statements/sql/level_tracking.sql @@ -33,6 +33,39 @@ END; $$; SELECT toplevel, calls, query FROM pg_stat_statements ORDER BY query COLLATE "C", toplevel; +-- DO block - top-level tracking without utility. +SET pg_stat_statements.track = 'top'; +SET pg_stat_statements.track_utility = FALSE; +SELECT pg_stat_statements_reset(); +DELETE FROM stats_track_tab; +DO $$ +BEGIN + DELETE FROM stats_track_tab; +END; $$; +DO LANGUAGE plpgsql $$ +BEGIN + -- this is a SELECT + PERFORM 'hello world'::TEXT; +END; $$; +SELECT toplevel, calls, query FROM pg_stat_statements + ORDER BY query COLLATE "C", toplevel; + +-- DO block - all-level tracking without utility. +SET pg_stat_statements.track = 'all'; +SELECT pg_stat_statements_reset(); +DELETE FROM stats_track_tab; +DO $$ +BEGIN + DELETE FROM stats_track_tab; +END; $$; +DO LANGUAGE plpgsql $$ +BEGIN + -- this is a SELECT + PERFORM 'hello world'::TEXT; +END; $$; +SELECT toplevel, calls, query FROM pg_stat_statements + ORDER BY query COLLATE "C", toplevel; + -- PL/pgSQL function - top-level tracking. SET pg_stat_statements.track = 'top'; SET pg_stat_statements.track_utility = FALSE; @@ -57,6 +90,15 @@ SELECT PLUS_ONE(10); SELECT calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C"; +-- immutable SQL function --- can be executed at plan time +CREATE FUNCTION PLUS_THREE(i INTEGER) RETURNS INTEGER AS +$$ SELECT i + 3 LIMIT 1 $$ IMMUTABLE LANGUAGE SQL; + +SELECT PLUS_THREE(8); +SELECT PLUS_THREE(10); + +SELECT toplevel, calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C"; + -- PL/pgSQL function - all-level tracking. SET pg_stat_statements.track = 'all'; SELECT pg_stat_statements_reset(); @@ -64,6 +106,7 @@ SELECT pg_stat_statements_reset(); -- we drop and recreate the functions to avoid any caching funnies DROP FUNCTION PLUS_ONE(INTEGER); DROP FUNCTION PLUS_TWO(INTEGER); +DROP FUNCTION PLUS_THREE(INTEGER); -- PL/pgSQL function CREATE FUNCTION PLUS_TWO(i INTEGER) RETURNS INTEGER AS $$ @@ -85,7 +128,15 @@ SELECT PLUS_ONE(3); SELECT PLUS_ONE(1); SELECT calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C"; -DROP FUNCTION PLUS_ONE(INTEGER); + +-- immutable SQL function --- can be executed at plan time +CREATE FUNCTION PLUS_THREE(i INTEGER) RETURNS INTEGER AS +$$ SELECT i + 3 LIMIT 1 $$ IMMUTABLE LANGUAGE SQL; + +SELECT PLUS_THREE(8); +SELECT PLUS_THREE(10); + +SELECT toplevel, calls, rows, query FROM pg_stat_statements ORDER BY query COLLATE "C"; -- -- pg_stat_statements.track = none