Hi Imai-san, On Thu, Mar 12, 2020 at 05:28:38AM +0000, imai.yoshik...@fujitsu.com wrote: > Hi Julien, > > On Mon, Mar 9, 2020 at 10:32 AM, Julien Rouhaud wrote: > > On Thu, Mar 05, 2020 at 01:26:19PM -0700, legrand legrand wrote: > > > Please consider PG13 shortest path ;o) > > > > > > My one is parse->queryId != UINT64CONST(0) in pgss_planner_hook(). > > > It fixes IVM problem (verified), > > > and keep CTAS equal to pgss without planning counters (verified too). > > > > I still disagree that hiding this problem is the right fix, but since no one > > objected here's a v5 with that behavior. Hopefully this will be fixed in > > v14. > > Is there any case that query_text will be NULL when executing pg_plan_query?
With current sources, there are no cases where the query text isn't provided AFAICS. > If query_text will be NULL, we need to add codes to avoid errors in > pgss_store like as current patch. If query_text will not be NULL, we should > add Assert in pg_plan_query so that other developers can notice that they > would not mistakenly set query_text as NULL even without using pgss_planning > counter. I totally agree. I already had such assert locally, and regression tests pass without any problem. I'm attaching a v6 with that extra assert. If the first patch is committed, it'll now be a requirement to provide it. Or if people think it's not, it'll make sure that we'll discuss it.
>From 3be06d43f0ef306f159a1c4ce0755d3bb0a4dd03 Mon Sep 17 00:00:00 2001 From: Julien Rouhaud <julien.rouh...@free.fr> Date: Thu, 28 Mar 2019 13:33:23 +0100 Subject: [PATCH v6 1/3] Pass query string to the planner --- src/backend/commands/copy.c | 3 ++- src/backend/commands/createas.c | 3 ++- src/backend/commands/explain.c | 2 +- src/backend/commands/extension.c | 2 +- src/backend/commands/matview.c | 2 +- src/backend/commands/portalcmds.c | 2 +- src/backend/executor/functions.c | 1 + src/backend/optimizer/plan/planner.c | 10 ++++++---- src/backend/tcop/postgres.c | 16 +++++++++++----- src/backend/utils/cache/plancache.c | 3 ++- src/include/optimizer/optimizer.h | 3 ++- src/include/optimizer/planner.h | 4 +++- src/include/tcop/tcopprot.h | 6 ++++-- 13 files changed, 37 insertions(+), 20 deletions(-) diff --git a/src/backend/commands/copy.c b/src/backend/commands/copy.c index fbde9f88e7..efb1e0d03e 100644 --- a/src/backend/commands/copy.c +++ b/src/backend/commands/copy.c @@ -1580,7 +1580,8 @@ BeginCopy(ParseState *pstate, } /* plan the query */ - plan = pg_plan_query(query, CURSOR_OPT_PARALLEL_OK, NULL); + plan = pg_plan_query(query, pstate->p_sourcetext, + CURSOR_OPT_PARALLEL_OK, NULL); /* * With row level security and a user using "COPY relation TO", we diff --git a/src/backend/commands/createas.c b/src/backend/commands/createas.c index 3a5676fb39..9febdc5165 100644 --- a/src/backend/commands/createas.c +++ b/src/backend/commands/createas.c @@ -329,7 +329,8 @@ ExecCreateTableAs(ParseState *pstate, CreateTableAsStmt *stmt, Assert(query->commandType == CMD_SELECT); /* plan the query */ - plan = pg_plan_query(query, CURSOR_OPT_PARALLEL_OK, params); + plan = pg_plan_query(query, pstate->p_sourcetext, + CURSOR_OPT_PARALLEL_OK, params); /* * Use a snapshot with an updated command ID to ensure this query sees diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index d901dc4a50..fb772aa5cd 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -375,7 +375,7 @@ ExplainOneQuery(Query *query, int cursorOptions, INSTR_TIME_SET_CURRENT(planstart); /* plan the query */ - plan = pg_plan_query(query, cursorOptions, params); + plan = pg_plan_query(query, queryString, cursorOptions, params); INSTR_TIME_SET_CURRENT(planduration); INSTR_TIME_SUBTRACT(planduration, planstart); diff --git a/src/backend/commands/extension.c b/src/backend/commands/extension.c index 00cf4ef268..38cbea385a 100644 --- a/src/backend/commands/extension.c +++ b/src/backend/commands/extension.c @@ -751,7 +751,7 @@ execute_sql_string(const char *sql) NULL, 0, NULL); - stmt_list = pg_plan_queries(stmt_list, CURSOR_OPT_PARALLEL_OK, NULL); + stmt_list = pg_plan_queries(stmt_list, sql, CURSOR_OPT_PARALLEL_OK, NULL); foreach(lc2, stmt_list) { diff --git a/src/backend/commands/matview.c b/src/backend/commands/matview.c index c3954f3e24..e5a5eef102 100644 --- a/src/backend/commands/matview.c +++ b/src/backend/commands/matview.c @@ -391,7 +391,7 @@ refresh_matview_datafill(DestReceiver *dest, Query *query, CHECK_FOR_INTERRUPTS(); /* Plan the query which will generate data for the refresh. */ - plan = pg_plan_query(query, 0, NULL); + plan = pg_plan_query(query, queryString, 0, NULL); /* * Use a snapshot with an updated command ID to ensure this query sees diff --git a/src/backend/commands/portalcmds.c b/src/backend/commands/portalcmds.c index 40be5069fe..6a2c233615 100644 --- a/src/backend/commands/portalcmds.c +++ b/src/backend/commands/portalcmds.c @@ -90,7 +90,7 @@ PerformCursorOpen(ParseState *pstate, DeclareCursorStmt *cstmt, ParamListInfo pa elog(ERROR, "non-SELECT statement in DECLARE CURSOR"); /* Plan the query, applying the specified options */ - plan = pg_plan_query(query, cstmt->options, params); + plan = pg_plan_query(query, pstate->p_sourcetext, cstmt->options, params); /* * Create a portal and copy the plan and query string into its memory. diff --git a/src/backend/executor/functions.c b/src/backend/executor/functions.c index 9b45a8a9a0..243d5cb3a6 100644 --- a/src/backend/executor/functions.c +++ b/src/backend/executor/functions.c @@ -510,6 +510,7 @@ init_execution_state(List *queryTree_list, } else stmt = pg_plan_query(queryTree, + fcache->src, CURSOR_OPT_PARALLEL_OK, NULL); diff --git a/src/backend/optimizer/plan/planner.c b/src/backend/optimizer/plan/planner.c index b44efd6314..19a9dafb5e 100644 --- a/src/backend/optimizer/plan/planner.c +++ b/src/backend/optimizer/plan/planner.c @@ -264,19 +264,21 @@ static int common_prefix_cmp(const void *a, const void *b); * *****************************************************************************/ PlannedStmt * -planner(Query *parse, int cursorOptions, ParamListInfo boundParams) +planner(Query *parse, const char *query_text, int cursorOptions, + ParamListInfo boundParams) { PlannedStmt *result; if (planner_hook) - result = (*planner_hook) (parse, cursorOptions, boundParams); + result = (*planner_hook) (parse, query_text, cursorOptions, boundParams); else - result = standard_planner(parse, cursorOptions, boundParams); + result = standard_planner(parse, query_text, cursorOptions, boundParams); return result; } PlannedStmt * -standard_planner(Query *parse, int cursorOptions, ParamListInfo boundParams) +standard_planner(Query *parse, const char *querytext, int cursorOptions, + ParamListInfo boundParams) { PlannedStmt *result; PlannerGlobal *glob; diff --git a/src/backend/tcop/postgres.c b/src/backend/tcop/postgres.c index 00c77b66c7..049f92c803 100644 --- a/src/backend/tcop/postgres.c +++ b/src/backend/tcop/postgres.c @@ -854,7 +854,8 @@ pg_rewrite_query(Query *query) * This is a thin wrapper around planner() and takes the same parameters. */ PlannedStmt * -pg_plan_query(Query *querytree, int cursorOptions, ParamListInfo boundParams) +pg_plan_query(Query *querytree, const char *query_text, int cursorOptions, + ParamListInfo boundParams) { PlannedStmt *plan; @@ -864,6 +865,9 @@ pg_plan_query(Query *querytree, int cursorOptions, ParamListInfo boundParams) /* Planner must have a snapshot in case it calls user-defined functions. */ Assert(ActiveSnapshotSet()); + /* And a query text should be provided. */ + Assert(query_text); + TRACE_POSTGRESQL_QUERY_PLAN_START(); @@ -871,7 +875,7 @@ pg_plan_query(Query *querytree, int cursorOptions, ParamListInfo boundParams) ResetUsage(); /* call the optimizer */ - plan = planner(querytree, cursorOptions, boundParams); + plan = planner(querytree, query_text, cursorOptions, boundParams); if (log_planner_stats) ShowUsage("PLANNER STATISTICS"); @@ -939,7 +943,8 @@ pg_plan_query(Query *querytree, int cursorOptions, ParamListInfo boundParams) * The result is a list of PlannedStmt nodes. */ List * -pg_plan_queries(List *querytrees, int cursorOptions, ParamListInfo boundParams) +pg_plan_queries(List *querytrees, const char *query_string, int cursorOptions, + ParamListInfo boundParams) { List *stmt_list = NIL; ListCell *query_list; @@ -961,7 +966,8 @@ pg_plan_queries(List *querytrees, int cursorOptions, ParamListInfo boundParams) } else { - stmt = pg_plan_query(query, cursorOptions, boundParams); + stmt = pg_plan_query(query, query_string, cursorOptions, + boundParams); } stmt_list = lappend(stmt_list, stmt); @@ -1152,7 +1158,7 @@ exec_simple_query(const char *query_string) querytree_list = pg_analyze_and_rewrite(parsetree, query_string, NULL, 0, NULL); - plantree_list = pg_plan_queries(querytree_list, + plantree_list = pg_plan_queries(querytree_list, query_string, CURSOR_OPT_PARALLEL_OK, NULL); /* diff --git a/src/backend/utils/cache/plancache.c b/src/backend/utils/cache/plancache.c index dbae18d68c..899e58b7a0 100644 --- a/src/backend/utils/cache/plancache.c +++ b/src/backend/utils/cache/plancache.c @@ -930,7 +930,8 @@ BuildCachedPlan(CachedPlanSource *plansource, List *qlist, /* * Generate the plan. */ - plist = pg_plan_queries(qlist, plansource->cursor_options, boundParams); + plist = pg_plan_queries(qlist, plansource->query_string, + plansource->cursor_options, boundParams); /* Release snapshot if we got one */ if (snapshot_set) diff --git a/src/include/optimizer/optimizer.h b/src/include/optimizer/optimizer.h index 5283995df8..302e47aa58 100644 --- a/src/include/optimizer/optimizer.h +++ b/src/include/optimizer/optimizer.h @@ -102,7 +102,8 @@ typedef enum extern int force_parallel_mode; extern bool parallel_leader_participation; -extern struct PlannedStmt *planner(Query *parse, int cursorOptions, +extern struct PlannedStmt *planner(Query *parse, const char *query_text, + int cursorOptions, struct ParamListInfoData *boundParams); extern Expr *expression_planner(Expr *expr); diff --git a/src/include/optimizer/planner.h b/src/include/optimizer/planner.h index 93df62d136..22bcf9c1e8 100644 --- a/src/include/optimizer/planner.h +++ b/src/include/optimizer/planner.h @@ -24,6 +24,7 @@ /* Hook for plugins to get control in planner() */ typedef PlannedStmt *(*planner_hook_type) (Query *parse, + const char *query_text, int cursorOptions, ParamListInfo boundParams); extern PGDLLIMPORT planner_hook_type planner_hook; @@ -37,7 +38,8 @@ typedef void (*create_upper_paths_hook_type) (PlannerInfo *root, extern PGDLLIMPORT create_upper_paths_hook_type create_upper_paths_hook; -extern PlannedStmt *standard_planner(Query *parse, int cursorOptions, +extern PlannedStmt *standard_planner(Query *parse, const char *query_text, + int cursorOptions, ParamListInfo boundParams); extern PlannerInfo *subquery_planner(PlannerGlobal *glob, Query *parse, diff --git a/src/include/tcop/tcopprot.h b/src/include/tcop/tcopprot.h index 750ba4a3e2..69c7b16ac7 100644 --- a/src/include/tcop/tcopprot.h +++ b/src/include/tcop/tcopprot.h @@ -52,9 +52,11 @@ extern List *pg_analyze_and_rewrite_params(RawStmt *parsetree, ParserSetupHook parserSetup, void *parserSetupArg, QueryEnvironment *queryEnv); -extern PlannedStmt *pg_plan_query(Query *querytree, int cursorOptions, +extern PlannedStmt *pg_plan_query(Query *querytree, const char *query_text, + int cursorOptions, ParamListInfo boundParams); -extern List *pg_plan_queries(List *querytrees, int cursorOptions, +extern List *pg_plan_queries(List *querytrees, const char *query_text, + int cursorOptions, ParamListInfo boundParams); extern bool check_max_stack_depth(int *newval, void **extra, GucSource source); -- 2.20.1
>From d5319a65b3e0c08b7b90ca9e852779a2013d6344 Mon Sep 17 00:00:00 2001 From: Julien Rouhaud <julien.rouh...@free.fr> Date: Wed, 27 Mar 2019 11:24:35 +0100 Subject: [PATCH v6 2/3] Add planning counters to pg_stat_statements --- contrib/pg_stat_statements/Makefile | 3 +- .../expected/pg_stat_statements.out | 231 +++++++++----- .../pg_stat_statements--1.7--1.8.sql | 56 ++++ .../pg_stat_statements/pg_stat_statements.c | 302 +++++++++++++----- .../pg_stat_statements.control | 2 +- .../sql/pg_stat_statements.sql | 16 + doc/src/sgml/pgstatstatements.sgml | 49 ++- 7 files changed, 498 insertions(+), 161 deletions(-) create mode 100644 contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql diff --git a/contrib/pg_stat_statements/Makefile b/contrib/pg_stat_statements/Makefile index 80042a0905..0f45e85b5b 100644 --- a/contrib/pg_stat_statements/Makefile +++ b/contrib/pg_stat_statements/Makefile @@ -6,7 +6,8 @@ OBJS = \ pg_stat_statements.o EXTENSION = pg_stat_statements -DATA = pg_stat_statements--1.4.sql pg_stat_statements--1.6--1.7.sql \ +DATA = pg_stat_statements--1.4.sql \ + pg_stat_statements--1.7--1.8.sql pg_stat_statements--1.6--1.7.sql \ pg_stat_statements--1.5--1.6.sql pg_stat_statements--1.4--1.5.sql \ pg_stat_statements--1.3--1.4.sql pg_stat_statements--1.2--1.3.sql \ pg_stat_statements--1.1--1.2.sql pg_stat_statements--1.0--1.1.sql diff --git a/contrib/pg_stat_statements/expected/pg_stat_statements.out b/contrib/pg_stat_statements/expected/pg_stat_statements.out index 6787ec1efd..7612bed6d5 100644 --- a/contrib/pg_stat_statements/expected/pg_stat_statements.out +++ b/contrib/pg_stat_statements/expected/pg_stat_statements.out @@ -96,25 +96,26 @@ EXECUTE pgss_test(1); DEALLOCATE pgss_test; SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; - query | calls | rows ----------------------------------------------------+-------+------ - PREPARE pgss_test (int) AS SELECT $1, $2 LIMIT $3 | 1 | 1 - SELECT $1 +| 4 | 4 - +| | - AS "text" | | - SELECT $1 + $2 | 2 | 2 - SELECT $1 + $2 + $3 AS "add" | 3 | 3 - SELECT $1 AS "float" | 1 | 1 - SELECT $1 AS "int" | 2 | 2 - SELECT $1 AS i UNION SELECT $2 ORDER BY i | 1 | 2 - SELECT $1 || $2 | 1 | 1 - SELECT pg_stat_statements_reset() | 1 | 1 - WITH t(f) AS ( +| 1 | 2 - VALUES ($1), ($2) +| | - ) +| | - SELECT f FROM t ORDER BY f | | - select $1::jsonb ? $2 | 1 | 1 -(11 rows) + query | calls | rows +------------------------------------------------------------------------------+-------+------ + PREPARE pgss_test (int) AS SELECT $1, $2 LIMIT $3 | 1 | 1 + SELECT $1 +| 4 | 4 + +| | + AS "text" | | + SELECT $1 + $2 | 2 | 2 + SELECT $1 + $2 + $3 AS "add" | 3 | 3 + SELECT $1 AS "float" | 1 | 1 + SELECT $1 AS "int" | 2 | 2 + SELECT $1 AS i UNION SELECT $2 ORDER BY i | 1 | 2 + SELECT $1 || $2 | 1 | 1 + SELECT pg_stat_statements_reset() | 1 | 1 + SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 0 | 0 + WITH t(f) AS ( +| 1 | 2 + VALUES ($1), ($2) +| | + ) +| | + SELECT f FROM t ORDER BY f | | + select $1::jsonb ? $2 | 1 | 1 +(12 rows) -- -- CRUD: INSERT SELECT UPDATE DELETE on test table @@ -196,18 +197,19 @@ SELECT * FROM test WHERE a IN (1, 2, 3, 4, 5); (8 rows) SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; - query | calls | rows --------------------------------------------------------------+-------+------ - DELETE FROM test WHERE a > $1 | 1 | 1 - INSERT INTO test (a, b) VALUES ($1, $2), ($3, $4), ($5, $6) | 1 | 3 - INSERT INTO test VALUES(generate_series($1, $2), $3) | 1 | 10 - SELECT * FROM test ORDER BY a | 1 | 12 - SELECT * FROM test WHERE a > $1 ORDER BY a | 2 | 4 - SELECT * FROM test WHERE a IN ($1, $2, $3, $4, $5) | 1 | 8 - SELECT pg_stat_statements_reset() | 1 | 1 - UPDATE test SET b = $1 WHERE a = $2 | 6 | 6 - UPDATE test SET b = $1 WHERE a > $2 | 1 | 3 -(9 rows) + query | calls | rows +------------------------------------------------------------------------------+-------+------ + DELETE FROM test WHERE a > $1 | 1 | 1 + INSERT INTO test (a, b) VALUES ($1, $2), ($3, $4), ($5, $6) | 1 | 3 + INSERT INTO test VALUES(generate_series($1, $2), $3) | 1 | 10 + SELECT * FROM test ORDER BY a | 1 | 12 + SELECT * FROM test WHERE a > $1 ORDER BY a | 2 | 4 + SELECT * FROM test WHERE a IN ($1, $2, $3, $4, $5) | 1 | 8 + SELECT pg_stat_statements_reset() | 1 | 1 + SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 0 | 0 + UPDATE test SET b = $1 WHERE a = $2 | 6 | 6 + UPDATE test SET b = $1 WHERE a > $2 | 1 | 3 +(10 rows) -- -- pg_stat_statements.track = none @@ -288,13 +290,14 @@ SELECT PLUS_ONE(10); (1 row) SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; - query | calls | rows ------------------------------------+-------+------ - SELECT $1::TEXT | 1 | 1 - SELECT PLUS_ONE($1) | 2 | 2 - SELECT PLUS_TWO($1) | 2 | 2 - SELECT pg_stat_statements_reset() | 1 | 1 -(4 rows) + query | calls | rows +------------------------------------------------------------------------------+-------+------ + SELECT $1::TEXT | 1 | 1 + SELECT PLUS_ONE($1) | 2 | 2 + SELECT PLUS_TWO($1) | 2 | 2 + SELECT pg_stat_statements_reset() | 1 | 1 + SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 0 | 0 +(5 rows) -- -- pg_stat_statements.track = all @@ -345,14 +348,15 @@ SELECT PLUS_ONE(1); (1 row) SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; - query | calls | rows ------------------------------------+-------+------ - SELECT (i + $2 + $3)::INTEGER | 2 | 2 - SELECT (i + $2)::INTEGER LIMIT $3 | 2 | 2 - SELECT PLUS_ONE($1) | 2 | 2 - SELECT PLUS_TWO($1) | 2 | 2 - SELECT pg_stat_statements_reset() | 1 | 1 -(5 rows) + query | calls | rows +------------------------------------------------------------------------------+-------+------ + SELECT (i + $2 + $3)::INTEGER | 2 | 2 + SELECT (i + $2)::INTEGER LIMIT $3 | 2 | 2 + SELECT PLUS_ONE($1) | 2 | 2 + SELECT PLUS_TWO($1) | 2 | 2 + SELECT pg_stat_statements_reset() | 1 | 1 + SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 0 | 0 +(6 rows) -- -- queries with locking clauses @@ -437,8 +441,9 @@ SELECT calls, query FROM pg_stat_statements ORDER BY query COLLATE "C"; 1 | SELECT * FROM pgss_a JOIN pgss_b ON pgss_b.a_id = pgss_a.id FOR UPDATE OF pgss_b 1 | SELECT * FROM pgss_a JOIN pgss_b ON pgss_b.a_id = pgss_a.id FOR UPDATE OF pgss_b, pgss_a 1 | SELECT * FROM pgss_a JOIN pgss_b ON pgss_b.a_id = pgss_a.id FOR UPDATE SKIP LOCKED + 0 | SELECT calls, query FROM pg_stat_statements ORDER BY query COLLATE "C" 1 | SELECT pg_stat_statements_reset() -(11 rows) +(12 rows) DROP TABLE pgss_a, pgss_b CASCADE; -- @@ -470,17 +475,18 @@ NOTICE: table "test" does not exist, skipping NOTICE: function plus_one(pg_catalog.int4) does not exist, skipping DROP FUNCTION PLUS_TWO(INTEGER); SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; - query | calls | rows --------------------------------------------+-------+------ - CREATE INDEX test_b ON test(b) | 1 | 0 - DROP FUNCTION IF EXISTS PLUS_ONE(INTEGER) | 1 | 0 - DROP FUNCTION PLUS_ONE(INTEGER) | 1 | 0 - DROP FUNCTION PLUS_TWO(INTEGER) | 1 | 0 - DROP TABLE IF EXISTS test | 3 | 0 - DROP TABLE test | 1 | 0 - SELECT $1 | 1 | 1 - SELECT pg_stat_statements_reset() | 1 | 1 -(8 rows) + query | calls | rows +------------------------------------------------------------------------------+-------+------ + CREATE INDEX test_b ON test(b) | 1 | 0 + DROP FUNCTION IF EXISTS PLUS_ONE(INTEGER) | 1 | 0 + DROP FUNCTION PLUS_ONE(INTEGER) | 1 | 0 + DROP FUNCTION PLUS_TWO(INTEGER) | 1 | 0 + DROP TABLE IF EXISTS test | 3 | 0 + DROP TABLE test | 1 | 0 + SELECT $1 | 1 | 1 + SELECT pg_stat_statements_reset() | 1 | 1 + SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 0 | 0 +(9 rows) -- -- Track user activity and reset them @@ -522,19 +528,20 @@ SELECT 1+1 AS "TWO"; RESET ROLE; SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; - query | calls | rows ------------------------------------+-------+------ - CREATE ROLE regress_stats_user1 | 1 | 0 - CREATE ROLE regress_stats_user2 | 1 | 0 - RESET ROLE | 2 | 0 - SELECT $1 AS "ONE" | 1 | 1 - SELECT $1 AS "ONE" | 1 | 1 - SELECT $1+$2 AS "TWO" | 1 | 1 - SELECT $1+$2 AS "TWO" | 1 | 1 - SELECT pg_stat_statements_reset() | 1 | 1 - SET ROLE regress_stats_user1 | 1 | 0 - SET ROLE regress_stats_user2 | 1 | 0 -(10 rows) + query | calls | rows +------------------------------------------------------------------------------+-------+------ + CREATE ROLE regress_stats_user1 | 1 | 0 + CREATE ROLE regress_stats_user2 | 1 | 0 + RESET ROLE | 2 | 0 + SELECT $1 AS "ONE" | 1 | 1 + SELECT $1 AS "ONE" | 1 | 1 + SELECT $1+$2 AS "TWO" | 1 | 1 + SELECT $1+$2 AS "TWO" | 1 | 1 + SELECT pg_stat_statements_reset() | 1 | 1 + SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 0 | 0 + SET ROLE regress_stats_user1 | 1 | 0 + SET ROLE regress_stats_user2 | 1 | 0 +(11 rows) -- -- Don't reset anything if any of the parameter is NULL @@ -557,7 +564,7 @@ SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; SELECT $1+$2 AS "TWO" | 1 | 1 SELECT pg_stat_statements_reset($1) | 1 | 1 SELECT pg_stat_statements_reset() | 1 | 1 - SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 1 | 10 + SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 1 | 11 SET ROLE regress_stats_user1 | 1 | 0 SET ROLE regress_stats_user2 | 1 | 0 (12 rows) @@ -592,7 +599,7 @@ SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; WHERE s.query = $2 LIMIT $3)) | | SELECT pg_stat_statements_reset($1) | 1 | 1 SELECT pg_stat_statements_reset() | 1 | 1 - SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 2 | 22 + SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 2 | 23 SET ROLE regress_stats_user1 | 1 | 0 SET ROLE regress_stats_user2 | 1 | 0 (12 rows) @@ -624,7 +631,7 @@ SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; SELECT pg_stat_statements_reset($1,$2,s.queryid) +| 1 | 2 FROM pg_stat_statements AS s WHERE s.query = $3 | | SELECT pg_stat_statements_reset() | 1 | 1 - SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 3 | 34 + SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 3 | 35 SET ROLE regress_stats_user1 | 1 | 0 SET ROLE regress_stats_user2 | 1 | 0 (11 rows) @@ -656,7 +663,7 @@ SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; SELECT pg_stat_statements_reset() | 1 | 1 SELECT pg_stat_statements_reset(r.oid) +| 1 | 1 FROM pg_roles AS r WHERE r.rolname = $1 | | - SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 4 | 45 + SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 4 | 46 SET ROLE regress_stats_user2 | 1 | 0 (10 rows) @@ -670,14 +677,80 @@ SELECT pg_stat_statements_reset(0,0,0); (1 row) SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; - query | calls | rows -----------------------------------------+-------+------ - SELECT pg_stat_statements_reset(0,0,0) | 1 | 1 -(1 row) + query | calls | rows +------------------------------------------------------------------------------+-------+------ + SELECT pg_stat_statements_reset(0,0,0) | 1 | 1 + SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 0 | 0 +(2 rows) -- -- cleanup -- DROP ROLE regress_stats_user1; DROP ROLE regress_stats_user2; +-- +-- [re]plan counting +-- +SELECT pg_stat_statements_reset(); + pg_stat_statements_reset +-------------------------- + +(1 row) + +CREATE TABLE test (); +PREPARE prep1 AS SELECT COUNT(*) FROM test;; +EXECUTE prep1; + count +------- + 0 +(1 row) + +EXECUTE prep1; + count +------- + 0 +(1 row) + +EXECUTE prep1; + count +------- + 0 +(1 row) + +ALTER TABLE test ADD COLUMN x int; +EXECUTE prep1; + count +------- + 0 +(1 row) + +SELECT 42; + ?column? +---------- + 42 +(1 row) + +SELECT 42; + ?column? +---------- + 42 +(1 row) + +SELECT 42; + ?column? +---------- + 42 +(1 row) + +SELECT query, plans, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; + query | plans | calls | rows +-------------------------------------------------------------------------------------+-------+-------+------ + ALTER TABLE test ADD COLUMN x int | 0 | 1 | 0 + CREATE TABLE test () | 0 | 1 | 0 + PREPARE prep1 AS SELECT COUNT(*) FROM test | 2 | 4 | 4 + SELECT $1 | 3 | 3 | 3 + SELECT pg_stat_statements_reset() | 0 | 1 | 1 + SELECT query, plans, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C" | 1 | 0 | 0 +(6 rows) + DROP EXTENSION pg_stat_statements; diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql b/contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql new file mode 100644 index 0000000000..5cf719ddc3 --- /dev/null +++ b/contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql @@ -0,0 +1,56 @@ +/* contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql */ + +-- complain if script is sourced in psql, rather than via ALTER EXTENSION +\echo Use "ALTER EXTENSION pg_stat_statements UPDATE TO '1.8'" to load this file. \quit + +/* First we have to remove them from the extension */ +ALTER EXTENSION pg_stat_statements DROP VIEW pg_stat_statements; +ALTER EXTENSION pg_stat_statements DROP FUNCTION pg_stat_statements(boolean); + +/* Then we can drop them */ +DROP VIEW pg_stat_statements; +DROP FUNCTION pg_stat_statements(boolean); + +/* Now redefine */ +CREATE FUNCTION pg_stat_statements(IN showtext boolean, + OUT userid oid, + OUT dbid oid, + OUT queryid bigint, + OUT query text, + OUT plans int8, + OUT total_plan_time float8, + OUT min_plan_time float8, + OUT max_plan_time float8, + OUT mean_plan_time float8, + OUT stddev_plan_time float8, + OUT calls int8, + OUT total_exec_time float8, + OUT min_exec_time float8, + OUT max_exec_time float8, + OUT mean_exec_time float8, + OUT stddev_exec_time float8, + OUT rows int8, + OUT shared_blks_hit int8, + OUT shared_blks_read int8, + OUT shared_blks_dirtied int8, + OUT shared_blks_written int8, + OUT local_blks_hit int8, + OUT local_blks_read int8, + OUT local_blks_dirtied int8, + OUT local_blks_written int8, + OUT temp_blks_read int8, + OUT temp_blks_written int8, + OUT blk_read_time float8, + OUT blk_write_time float8 +) +RETURNS SETOF record +AS 'MODULE_PATHNAME', 'pg_stat_statements_1_8' +LANGUAGE C STRICT VOLATILE PARALLEL SAFE; + +CREATE VIEW pg_stat_statements AS + SELECT *, total_plan_time + total_exec_time AS total_time + FROM pg_stat_statements(true); + +GRANT SELECT ON pg_stat_statements TO PUBLIC; + + diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c index 20dc8c605b..adb63a6fe9 100644 --- a/contrib/pg_stat_statements/pg_stat_statements.c +++ b/contrib/pg_stat_statements/pg_stat_statements.c @@ -1,7 +1,8 @@ /*------------------------------------------------------------------------- * * pg_stat_statements.c - * Track statement execution times across a whole database cluster. + * Track statement planning and execution times as well as resources + * consumption (like block reads, ...) across a whole cluster. * * Execution costs are totalled for each distinct source query, and kept in * a shared hashtable. (We track only as many distinct queries as will fit @@ -67,6 +68,7 @@ #include "funcapi.h" #include "mb/pg_wchar.h" #include "miscadmin.h" +#include "optimizer/planner.h" #include "parser/analyze.h" #include "parser/parsetree.h" #include "parser/scanner.h" @@ -109,6 +111,7 @@ static const uint32 PGSS_PG_MAJOR_VERSION = PG_VERSION_NUM / 100; #define USAGE_DECREASE_FACTOR (0.99) /* decreased every entry_dealloc */ #define STICKY_DECREASE_FACTOR (0.50) /* factor for sticky entries */ #define USAGE_DEALLOC_PERCENT 5 /* free this % of entries at once */ +#define IS_STICKY(c) ((c.calls[PGSS_PLAN] + c.calls[PGSS_EXEC]) == 0) #define JUMBLE_SIZE 1024 /* query serialization buffer size */ @@ -120,9 +123,22 @@ typedef enum pgssVersion PGSS_V1_0 = 0, PGSS_V1_1, PGSS_V1_2, - PGSS_V1_3 + PGSS_V1_3, + PGSS_V1_8 } pgssVersion; +typedef enum pgssStoreKind +{ + /* + * PGSS_PLAN and PGSS_EXEC must be respectively 0 and 1 as they're used to + * reference the underlying values in the arrays in the Counters struct, + * and this order is required in pg_stat_statements_internal(). + */ + PGSS_PLAN = 0, + PGSS_EXEC, + PGSS_JUMBLE, +} pgssStoreKind; + /* * Hashtable key that defines the identity of a hashtable entry. We separate * queries by user and by database even if they are otherwise identical. @@ -144,12 +160,12 @@ typedef struct pgssHashKey */ typedef struct Counters { - int64 calls; /* # of times executed */ - double total_time; /* total execution time, in msec */ - double min_time; /* minimum execution time in msec */ - double max_time; /* maximum execution time in msec */ - double mean_time; /* mean execution time in msec */ - double sum_var_time; /* sum of variances in execution time in msec */ + int64 calls[2]; /* # of times planned/executed */ + double total_time[2]; /* total planning/execution time, in msec */ + double min_time[2]; /* minimum planning/execution time in msec */ + double max_time[2]; /* maximum planning/execution time in msec */ + double mean_time[2]; /* mean planning/execution time in msec */ + double sum_var_time[2]; /* sum of variances in planning/execution time in msec */ int64 rows; /* total # of retrieved or affected rows */ int64 shared_blks_hit; /* # of shared buffer hits */ int64 shared_blks_read; /* # of shared disk blocks read */ @@ -238,6 +254,7 @@ static int nested_level = 0; /* Saved hook values in case of unload */ static shmem_startup_hook_type prev_shmem_startup_hook = NULL; +static planner_hook_type prev_planner_hook = NULL; static post_parse_analyze_hook_type prev_post_parse_analyze_hook = NULL; static ExecutorStart_hook_type prev_ExecutorStart = NULL; static ExecutorRun_hook_type prev_ExecutorRun = NULL; @@ -268,6 +285,7 @@ static const struct config_enum_entry track_options[] = static int pgss_max; /* max # statements to track */ static int pgss_track; /* tracking level */ +static bool pgss_track_planning; /* whether to track planning duration */ static bool pgss_track_utility; /* whether to track utility commands */ static bool pgss_save; /* whether to save stats across shutdown */ @@ -293,10 +311,15 @@ PG_FUNCTION_INFO_V1(pg_stat_statements_reset); PG_FUNCTION_INFO_V1(pg_stat_statements_reset_1_7); PG_FUNCTION_INFO_V1(pg_stat_statements_1_2); PG_FUNCTION_INFO_V1(pg_stat_statements_1_3); +PG_FUNCTION_INFO_V1(pg_stat_statements_1_8); PG_FUNCTION_INFO_V1(pg_stat_statements); static void pgss_shmem_startup(void); static void pgss_shmem_shutdown(int code, Datum arg); +static PlannedStmt *pgss_planner_hook(Query *parse, + const char *query_text, + int cursorOptions, + ParamListInfo boundParams); static void pgss_post_parse_analyze(ParseState *pstate, Query *query); static void pgss_ExecutorStart(QueryDesc *queryDesc, int eflags); static void pgss_ExecutorRun(QueryDesc *queryDesc, @@ -311,7 +334,9 @@ static void pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString, static uint64 pgss_hash_string(const char *str, int len); static void pgss_store(const char *query, uint64 queryId, int query_location, int query_len, - double total_time, uint64 rows, + pgssStoreKind kind, + double timing, + uint64 rows, const BufferUsage *bufusage, pgssJumbleState *jstate); static void pg_stat_statements_internal(FunctionCallInfo fcinfo, @@ -341,6 +366,7 @@ static char *generate_normalized_query(pgssJumbleState *jstate, const char *quer static void fill_in_constant_lengths(pgssJumbleState *jstate, const char *query, int query_loc); static int comp_location(const void *a, const void *b); +static BufferUsage compute_buffer_counters(BufferUsage start, BufferUsage stop); /* @@ -399,6 +425,17 @@ _PG_init(void) NULL, NULL); + DefineCustomBoolVariable("pg_stat_statements.track_planning", + "Selects whether planning duration is tracked by pg_stat_statements.", + NULL, + &pgss_track_planning, + true, + PGC_SUSET, + 0, + NULL, + NULL, + NULL); + DefineCustomBoolVariable("pg_stat_statements.save", "Save pg_stat_statements statistics across server shutdowns.", NULL, @@ -425,6 +462,8 @@ _PG_init(void) */ prev_shmem_startup_hook = shmem_startup_hook; shmem_startup_hook = pgss_shmem_startup; + prev_planner_hook = planner_hook; + planner_hook = pgss_planner_hook; prev_post_parse_analyze_hook = post_parse_analyze_hook; post_parse_analyze_hook = pgss_post_parse_analyze; prev_ExecutorStart = ExecutorStart_hook; @@ -448,6 +487,7 @@ _PG_fini(void) /* Uninstall hooks. */ shmem_startup_hook = prev_shmem_startup_hook; post_parse_analyze_hook = prev_post_parse_analyze_hook; + planner_hook = prev_planner_hook; ExecutorStart_hook = prev_ExecutorStart; ExecutorRun_hook = prev_ExecutorRun; ExecutorFinish_hook = prev_ExecutorFinish; @@ -602,7 +642,7 @@ pgss_shmem_startup(void) buffer[temp.query_len] = '\0'; /* Skip loading "sticky" entries */ - if (temp.counters.calls == 0) + if (IS_STICKY(temp.counters)) continue; /* Store the query text */ @@ -838,12 +878,83 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query) query->queryId, query->stmt_location, query->stmt_len, + PGSS_JUMBLE, 0, 0, NULL, &jstate); } +/* + * Planner hook: forward to regular planner, but measure planning time. + */ +static PlannedStmt * +pgss_planner_hook(Query *parse, + const char *query_text, + int cursorOptions, + ParamListInfo boundParams) +{ + PlannedStmt *result; + BufferUsage bufusage_start, + bufusage; + + /* We need to track buffer usage as the planner can access them. */ + bufusage_start = pgBufferUsage; + if (pgss_enabled() && pgss_track_planning + && parse->queryId != UINT64CONST(0)) + { + instr_time start; + instr_time duration; + + INSTR_TIME_SET_CURRENT(start); + + nested_level++; + PG_TRY(); + { + if (prev_planner_hook) + result = prev_planner_hook(parse, query_text, cursorOptions, + boundParams); + else + result = standard_planner(parse, query_text, cursorOptions, + boundParams); + nested_level--; + } + PG_CATCH(); + { + nested_level--; + PG_RE_THROW(); + } + PG_END_TRY(); + + INSTR_TIME_SET_CURRENT(duration); + INSTR_TIME_SUBTRACT(duration, start); + + /* calc differences of buffer counters. */ + bufusage = compute_buffer_counters(bufusage_start, pgBufferUsage); + + pgss_store(query_text, + parse->queryId, + parse->stmt_location, + parse->stmt_len, + PGSS_PLAN, + INSTR_TIME_GET_MILLISEC(duration), + 0, + &bufusage, + NULL); + } + else + { + if (prev_planner_hook) + result = prev_planner_hook(parse, query_text, cursorOptions, + boundParams); + else + result = standard_planner(parse, query_text, cursorOptions, + boundParams); + } + + return result; +} + /* * ExecutorStart hook: start up tracking if needed */ @@ -941,6 +1052,7 @@ pgss_ExecutorEnd(QueryDesc *queryDesc) queryId, queryDesc->plannedstmt->stmt_location, queryDesc->plannedstmt->stmt_len, + PGSS_EXEC, queryDesc->totaltime->total * 1000.0, /* convert to msec */ queryDesc->estate->es_processed, &queryDesc->totaltime->bufusage, @@ -1016,35 +1128,13 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString, rows = (qc && qc->commandTag == CMDTAG_COPY) ? qc->nprocessed : 0; /* calc differences of buffer counters. */ - bufusage.shared_blks_hit = - pgBufferUsage.shared_blks_hit - bufusage_start.shared_blks_hit; - bufusage.shared_blks_read = - pgBufferUsage.shared_blks_read - bufusage_start.shared_blks_read; - bufusage.shared_blks_dirtied = - pgBufferUsage.shared_blks_dirtied - bufusage_start.shared_blks_dirtied; - bufusage.shared_blks_written = - pgBufferUsage.shared_blks_written - bufusage_start.shared_blks_written; - bufusage.local_blks_hit = - pgBufferUsage.local_blks_hit - bufusage_start.local_blks_hit; - bufusage.local_blks_read = - pgBufferUsage.local_blks_read - bufusage_start.local_blks_read; - bufusage.local_blks_dirtied = - pgBufferUsage.local_blks_dirtied - bufusage_start.local_blks_dirtied; - bufusage.local_blks_written = - pgBufferUsage.local_blks_written - bufusage_start.local_blks_written; - bufusage.temp_blks_read = - pgBufferUsage.temp_blks_read - bufusage_start.temp_blks_read; - bufusage.temp_blks_written = - pgBufferUsage.temp_blks_written - bufusage_start.temp_blks_written; - bufusage.blk_read_time = pgBufferUsage.blk_read_time; - INSTR_TIME_SUBTRACT(bufusage.blk_read_time, bufusage_start.blk_read_time); - bufusage.blk_write_time = pgBufferUsage.blk_write_time; - INSTR_TIME_SUBTRACT(bufusage.blk_write_time, bufusage_start.blk_write_time); + bufusage = compute_buffer_counters(bufusage_start, pgBufferUsage); pgss_store(queryString, 0, /* signal that it's a utility stmt */ pstmt->stmt_location, pstmt->stmt_len, + PGSS_EXEC, INSTR_TIME_GET_MILLISEC(duration), rows, &bufusage, @@ -1083,12 +1173,17 @@ pgss_hash_string(const char *str, int len) * * If jstate is not NULL then we're trying to create an entry for which * we have no statistics as yet; we just want to record the normalized - * query string. total_time, rows, bufusage are ignored in this case. + * query string. timing, rows, bufusage are ignored in this case. + * + * If kind is PGSS_PLAN or PGSS_EXEC, its value is used as the array position + * for the arrays in the Counters field. */ static void pgss_store(const char *query, uint64 queryId, int query_location, int query_len, - double total_time, uint64 rows, + pgssStoreKind kind, + double timing, + uint64 rows, const BufferUsage *bufusage, pgssJumbleState *jstate) { @@ -1176,8 +1271,10 @@ pgss_store(const char *query, uint64 queryId, * in the interval where we don't hold the lock below. That case is * handled by entry_alloc.) */ - if (jstate) + if (kind == PGSS_JUMBLE) { + Assert(jstate); + LWLockRelease(pgss->lock); norm_query = generate_normalized_query(jstate, query, query_location, @@ -1234,19 +1331,22 @@ pgss_store(const char *query, uint64 queryId, */ volatile pgssEntry *e = (volatile pgssEntry *) entry; + Assert(kind == PGSS_PLAN || kind == PGSS_EXEC); + SpinLockAcquire(&e->mutex); /* "Unstick" entry if it was previously sticky */ - if (e->counters.calls == 0) + if (IS_STICKY(e->counters)) e->counters.usage = USAGE_INIT; - e->counters.calls += 1; - e->counters.total_time += total_time; - if (e->counters.calls == 1) + e->counters.calls[kind] += 1; + e->counters.total_time[kind] += timing; + + if (e->counters.calls[kind] == 1) { - e->counters.min_time = total_time; - e->counters.max_time = total_time; - e->counters.mean_time = total_time; + e->counters.min_time[kind] = timing; + e->counters.max_time[kind] = timing; + e->counters.mean_time[kind] = timing; } else { @@ -1254,18 +1354,18 @@ pgss_store(const char *query, uint64 queryId, * Welford's method for accurately computing variance. See * <http://www.johndcook.com/blog/standard_deviation/> */ - double old_mean = e->counters.mean_time; + double old_mean = e->counters.mean_time[kind]; - e->counters.mean_time += - (total_time - old_mean) / e->counters.calls; - e->counters.sum_var_time += - (total_time - old_mean) * (total_time - e->counters.mean_time); + e->counters.mean_time[kind] += + (timing - old_mean) / e->counters.calls[kind]; + e->counters.sum_var_time[kind] += + (timing - old_mean) * (timing - e->counters.mean_time[kind]); /* calculate min and max time */ - if (e->counters.min_time > total_time) - e->counters.min_time = total_time; - if (e->counters.max_time < total_time) - e->counters.max_time = total_time; + if (e->counters.min_time[kind] > timing) + e->counters.min_time[kind] = timing; + if (e->counters.max_time[kind] < timing) + e->counters.max_time[kind] = timing; } e->counters.rows += rows; e->counters.shared_blks_hit += bufusage->shared_blks_hit; @@ -1280,7 +1380,7 @@ pgss_store(const char *query, uint64 queryId, e->counters.temp_blks_written += bufusage->temp_blks_written; e->counters.blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->blk_read_time); e->counters.blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->blk_write_time); - e->counters.usage += USAGE_EXEC(total_time); + e->counters.usage += USAGE_EXEC(timing); SpinLockRelease(&e->mutex); } @@ -1328,7 +1428,8 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS) #define PG_STAT_STATEMENTS_COLS_V1_1 18 #define PG_STAT_STATEMENTS_COLS_V1_2 19 #define PG_STAT_STATEMENTS_COLS_V1_3 23 -#define PG_STAT_STATEMENTS_COLS 23 /* maximum of above */ +#define PG_STAT_STATEMENTS_COLS_V1_8 29 +#define PG_STAT_STATEMENTS_COLS 29 /* maximum of above */ /* * Retrieve statement statistics. @@ -1340,6 +1441,16 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS) * expected API version is identified by embedding it in the C name of the * function. Unfortunately we weren't bright enough to do that for 1.1. */ +Datum +pg_stat_statements_1_8(PG_FUNCTION_ARGS) +{ + bool showtext = PG_GETARG_BOOL(0); + + pg_stat_statements_internal(fcinfo, PGSS_V1_8, showtext); + + return (Datum) 0; +} + Datum pg_stat_statements_1_3(PG_FUNCTION_ARGS) { @@ -1445,6 +1556,10 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo, if (api_version != PGSS_V1_3) elog(ERROR, "incorrect number of output arguments"); break; + case PG_STAT_STATEMENTS_COLS_V1_8: + if (api_version != PGSS_V1_8) + elog(ERROR, "incorrect number of output arguments"); + break; default: elog(ERROR, "incorrect number of output arguments"); } @@ -1600,29 +1715,39 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo, } /* Skip entry if unexecuted (ie, it's a pending "sticky" entry) */ - if (tmp.calls == 0) + if (IS_STICKY(tmp)) continue; - values[i++] = Int64GetDatumFast(tmp.calls); - values[i++] = Float8GetDatumFast(tmp.total_time); - if (api_version >= PGSS_V1_3) + /* Note that we rely on PGSS_PLAN being 0 and PGSS_EXEC being 1. */ + for (int kind=0; kind < 2; kind++) { - values[i++] = Float8GetDatumFast(tmp.min_time); - values[i++] = Float8GetDatumFast(tmp.max_time); - values[i++] = Float8GetDatumFast(tmp.mean_time); + if (kind == PGSS_EXEC || api_version >= PGSS_V1_8) + { + values[i++] = Int64GetDatumFast(tmp.calls[kind]); + values[i++] = Float8GetDatumFast(tmp.total_time[kind]); + } - /* - * Note we are calculating the population variance here, not the - * sample variance, as we have data for the whole population, so - * Bessel's correction is not used, and we don't divide by - * tmp.calls - 1. - */ - if (tmp.calls > 1) - stddev = sqrt(tmp.sum_var_time / tmp.calls); - else - stddev = 0.0; - values[i++] = Float8GetDatumFast(stddev); + if ( (kind == PGSS_EXEC && api_version >= PGSS_V1_3) || + api_version >= PGSS_V1_8) + { + values[i++] = Float8GetDatumFast(tmp.min_time[kind]); + values[i++] = Float8GetDatumFast(tmp.max_time[kind]); + values[i++] = Float8GetDatumFast(tmp.mean_time[kind]); + + /* + * Note we are calculating the population variance here, not the + * sample variance, as we have data for the whole population, so + * Bessel's correction is not used, and we don't divide by + * tmp.calls - 1. + */ + if (tmp.calls[kind] > 1) + stddev = sqrt(tmp.sum_var_time[kind] / tmp.calls[kind]); + else + stddev = 0.0; + values[i++] = Float8GetDatumFast(stddev); + } } + values[i++] = Int64GetDatumFast(tmp.rows); values[i++] = Int64GetDatumFast(tmp.shared_blks_hit); values[i++] = Int64GetDatumFast(tmp.shared_blks_read); @@ -1646,6 +1771,7 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo, api_version == PGSS_V1_1 ? PG_STAT_STATEMENTS_COLS_V1_1 : api_version == PGSS_V1_2 ? PG_STAT_STATEMENTS_COLS_V1_2 : api_version == PGSS_V1_3 ? PG_STAT_STATEMENTS_COLS_V1_3 : + api_version == PGSS_V1_8 ? PG_STAT_STATEMENTS_COLS_V1_8 : -1 /* fail if you forget to update this assert */ )); tuplestore_putvalues(tupstore, tupdesc, values, nulls); @@ -1781,7 +1907,7 @@ entry_dealloc(void) { entries[i++] = entry; /* "Sticky" entries get a different usage decay rate. */ - if (entry->counters.calls == 0) + if (IS_STICKY(entry->counters)) entry->counters.usage *= STICKY_DECREASE_FACTOR; else entry->counters.usage *= USAGE_DECREASE_FACTOR; @@ -3249,3 +3375,31 @@ comp_location(const void *a, const void *b) else return 0; } + +static BufferUsage +compute_buffer_counters(BufferUsage start, BufferUsage stop) +{ + BufferUsage result; + + result.shared_blks_hit = stop.shared_blks_hit - start.shared_blks_hit; + result.shared_blks_read = stop.shared_blks_read - start.shared_blks_read; + result.shared_blks_dirtied = stop.shared_blks_dirtied - + start.shared_blks_dirtied; + result.shared_blks_written = stop.shared_blks_written - + start.shared_blks_written; + result.local_blks_hit = stop.local_blks_hit - start.local_blks_hit; + result.local_blks_read = stop.local_blks_read - start.local_blks_read; + result.local_blks_dirtied = stop.local_blks_dirtied - + start.local_blks_dirtied; + result.local_blks_written = stop.local_blks_written - + start.local_blks_written; + result.temp_blks_read = stop.temp_blks_read - start.temp_blks_read; + result.temp_blks_written = stop.temp_blks_written - + start.temp_blks_written; + result.blk_read_time = stop.blk_read_time; + INSTR_TIME_SUBTRACT(result.blk_read_time, start.blk_read_time); + result.blk_write_time = stop.blk_write_time; + INSTR_TIME_SUBTRACT(result.blk_write_time, start.blk_write_time); + + return result; +} diff --git a/contrib/pg_stat_statements/pg_stat_statements.control b/contrib/pg_stat_statements/pg_stat_statements.control index 14cb422354..7fb20df886 100644 --- a/contrib/pg_stat_statements/pg_stat_statements.control +++ b/contrib/pg_stat_statements/pg_stat_statements.control @@ -1,5 +1,5 @@ # pg_stat_statements extension comment = 'track execution statistics of all SQL statements executed' -default_version = '1.7' +default_version = '1.8' module_pathname = '$libdir/pg_stat_statements' relocatable = true diff --git a/contrib/pg_stat_statements/sql/pg_stat_statements.sql b/contrib/pg_stat_statements/sql/pg_stat_statements.sql index 8b527070d4..e36e64f633 100644 --- a/contrib/pg_stat_statements/sql/pg_stat_statements.sql +++ b/contrib/pg_stat_statements/sql/pg_stat_statements.sql @@ -290,4 +290,20 @@ SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; DROP ROLE regress_stats_user1; DROP ROLE regress_stats_user2; +-- +-- [re]plan counting +-- +SELECT pg_stat_statements_reset(); +CREATE TABLE test (); +PREPARE prep1 AS SELECT COUNT(*) FROM test;; +EXECUTE prep1; +EXECUTE prep1; +EXECUTE prep1; +ALTER TABLE test ADD COLUMN x int; +EXECUTE prep1; +SELECT 42; +SELECT 42; +SELECT 42; +SELECT query, plans, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; + DROP EXTENSION pg_stat_statements; diff --git a/doc/src/sgml/pgstatstatements.sgml b/doc/src/sgml/pgstatstatements.sgml index 26bb82da4a..368daf3e39 100644 --- a/doc/src/sgml/pgstatstatements.sgml +++ b/doc/src/sgml/pgstatstatements.sgml @@ -9,7 +9,8 @@ <para> The <filename>pg_stat_statements</filename> module provides a means for - tracking execution statistics of all SQL statements executed by a server. + tracking planning and execution statistics of all SQL statements executed by + a server. </para> <para> @@ -82,6 +83,20 @@ <entry>Text of a representative statement</entry> </row> + <row> + <entry><structfield>plans</structfield></entry> + <entry><type>bigint</type></entry> + <entry></entry> + <entry>Number of times the statement was planned</entry> + </row> + + <row> + <entry><structfield>total_plan_time</structfield></entry> + <entry><type>double precision</type></entry> + <entry></entry> + <entry>Total time spent planning the statement, in milliseconds</entry> + </row> + <row> <entry><structfield>calls</structfield></entry> <entry><type>bigint</type></entry> @@ -89,39 +104,46 @@ <entry>Number of times executed</entry> </row> + <row> + <entry><structfield>total_exec_time</structfield></entry> + <entry><type>double precision</type></entry> + <entry></entry> + <entry>Total time spent executing the statement, in milliseconds</entry> + </row> + <row> <entry><structfield>total_time</structfield></entry> <entry><type>double precision</type></entry> <entry></entry> - <entry>Total time spent in the statement, in milliseconds</entry> + <entry>Total time spent planning and executing the statement, in milliseconds</entry> </row> <row> <entry><structfield>min_time</structfield></entry> <entry><type>double precision</type></entry> <entry></entry> - <entry>Minimum time spent in the statement, in milliseconds</entry> + <entry>Minimum time spent executing the statement, in milliseconds</entry> </row> <row> <entry><structfield>max_time</structfield></entry> <entry><type>double precision</type></entry> <entry></entry> - <entry>Maximum time spent in the statement, in milliseconds</entry> + <entry>Maximum time spent executing the statement, in milliseconds</entry> </row> <row> <entry><structfield>mean_time</structfield></entry> <entry><type>double precision</type></entry> <entry></entry> - <entry>Mean time spent in the statement, in milliseconds</entry> + <entry>Mean time spent executing the statement, in milliseconds</entry> </row> <row> <entry><structfield>stddev_time</structfield></entry> <entry><type>double precision</type></entry> <entry></entry> - <entry>Population standard deviation of time spent in the statement, in milliseconds</entry> + <entry>Population standard deviation of time spent executing the statement, in milliseconds</entry> </row> <row> @@ -431,6 +453,21 @@ </listitem> </varlistentry> + <varlistentry> + <term> + <varname>pg_stat_statements.track_planning</varname> (<type>boolean</type>) + </term> + + <listitem> + <para> + <varname>pg_stat_statements.track_planning</varname> controls whether + planning operations and duration are tracked by the module. + The default value is <literal>on</literal>. + Only superusers can change this setting. + </para> + </listitem> + </varlistentry> + <varlistentry> <term> <varname>pg_stat_statements.track_utility</varname> (<type>boolean</type>) -- 2.20.1