On Thu, Mar 26, 2020 at 02:22:47PM +0100, Julien Rouhaud wrote:
> On Thu, Mar 26, 2020 at 08:08:35PM +0900, Fujii Masao wrote:
> >
> > Here are other comments.
> >
> > - if (jstate)
> > + if (kind == PGSS_JUMBLE)
> >
> > Why is PGSS_JUMBLE necessary? ISTM that we can still use jstate here,
> > instead.
> >
> > If it's ok to remove PGSS_JUMBLE, we can define PGSS_NUM_KIND(=2) instead
> > and replace 2 in, e.g., total_time[2] with PGSS_NUM_KIND. Thought?
>
> Yes, we could be using jstate here. I originally used that to avoid passing
> PGSS_EXEC (or the other one) as a way to say "ignore this information as
> there's the jstate which says it's yet another meaning". If that's not an
> issue, I can change that as PGSS_NUM_KIND will clearly improve the explicit
> "2"
> all over the place.
Done, passing PGSS_PLAN when jumble is intended, with a comment saying that the
pgss_kind is ignored in that case.
> > + <entry><structfield>total_time</structfield></entry>
> > + <entry><type>double precision</type></entry>
> > + <entry></entry>
> > + <entry>
> > + Total time spend planning and executing the statement, in
> > milliseconds
> > + </entry>
> > + </row>
> >
> > pg_stat_statements view has this column but the function not.
> > We should make both have the column or not at all, for consistency?
> > I'm not sure if it's good thing to expose the sum of total_plan_time
> > and total_exec_time as total_time. If some users want that, they can
> > easily calculate it from total_plan_time and total_exec_time by using
> > their own logic.
>
> I think we originally added it as a way to avoid too much compatibility break,
> and also because it seems like a field most users will be interested in
> anyway.
> Now that I'm thinking about it again, I indeed think it was a mistake to have
> that in view part only. Not mainly for consistency, but for users who would
> be
> interested in the total_time field while not wanting to pay the overhead of
> retrieving the query text if they don't need it. So I'll change that!
Done
> > + nested_level++;
> > + PG_TRY();
> >
> > In old thread [1], Tom Lane commented the usage of nested_level
> > in the planner hook. There seems no reply to that so far. What's
> > your opinion about that comment?
> >
> > [1] https://www.postgresql.org/message-id/28980.1515803...@sss.pgh.pa.us
>
> Oh thanks, I didn't noticed this part of the discussion. I agree with Tom's
> concern, and I think that having a specific nesting level variable for the
> planner is the best workaround, so I'll implement that.
Done.
I also exported BufferUsageAccumDiff as mentioned previously, as it seems
clearner and will avoid future useless code churn, and run pgindent.
v10 attached.
>From b4db0211ccc9113b14a1e8a668551791add3f6dc 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 v10 1/2] 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 | 13 ++++++++-----
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, 34 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 ff2f45cfb2..ee0e638f33 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -376,7 +376,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 c53aaaca61..1c387a952e 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 b65abf6046..45ade4bd3c 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 cb8c23e4b7..981f7c25c7 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;
@@ -871,7 +872,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 +940,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 +963,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 +1155,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.25.1
>From dec1a7ac3484a4f01de5abfde8837ccfd649c358 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 v10 2/2] 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 | 316 +++++++++++++-----
.../pg_stat_statements.control | 2 +-
.../sql/pg_stat_statements.sql | 16 +
doc/src/sgml/pgstatstatements.sgml | 89 ++++-
src/backend/executor/instrument.c | 4 +-
src/include/executor/instrument.h | 3 +
9 files changed, 539 insertions(+), 181 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..64b05d8d42
--- /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 total_time float8,
+ 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 * 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..0262c576d9 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,
+} pgssStoreKind;
+#define PGSS_NUMKIND 2
+
/*
* 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,17 @@ 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[PGSS_NUMKIND]; /* # of times planned/executed */
+ double total_time[PGSS_NUMKIND]; /* total planning/execution time,
+ * in msec */
+ double min_time[PGSS_NUMKIND]; /* minimum planning/execution time in
+ * msec */
+ double max_time[PGSS_NUMKIND]; /* maximum planning/execution time in
+ * msec */
+ double mean_time[PGSS_NUMKIND]; /* mean planning/execution time in
+ * msec */
+ double sum_var_time[PGSS_NUMKIND]; /* 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 */
@@ -234,10 +255,14 @@ typedef struct pgssJumbleState
/*---- Local variables ----*/
/* Current nesting depth of ExecutorRun+ProcessUtility calls */
-static int nested_level = 0;
+static int exec_nested_level = 0;
+
+/* Current nesting depth of Planner calls */
+static int plan_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,13 +293,14 @@ 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 */
-#define pgss_enabled() \
+#define pgss_enabled(level) \
(pgss_track == PGSS_TRACK_ALL || \
- (pgss_track == PGSS_TRACK_TOP && nested_level == 0))
+ (pgss_track == PGSS_TRACK_TOP && level == 0))
#define record_gc_qtexts() \
do { \
@@ -293,10 +319,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 +342,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,
@@ -399,6 +432,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 +469,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 +494,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 +649,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 */
@@ -788,7 +835,7 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query)
Assert(query->queryId == UINT64CONST(0));
/* Safety check... */
- if (!pgss || !pgss_hash || !pgss_enabled())
+ if (!pgss || !pgss_hash || !pgss_enabled(exec_nested_level))
return;
/*
@@ -838,12 +885,90 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query)
query->queryId,
query->stmt_location,
query->stmt_len,
+ PGSS_PLAN, /* this is ignored when jstate is provided */
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;
+
+ /*
+ * We can't process the query if no query_text is provided, as pgss_store
+ * needs it. We also ignore query without queryid, as it would be treated
+ * as a utility statement, which may not be the case.
+ */
+ if (pgss_enabled(plan_nested_level) && pgss_track_planning && query_text
+ && parse->queryId != UINT64CONST(0))
+ {
+ instr_time start;
+ instr_time duration;
+
+ INSTR_TIME_SET_CURRENT(start);
+
+ plan_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);
+ plan_nested_level--;
+ }
+ PG_CATCH();
+ {
+ plan_nested_level--;
+ PG_RE_THROW();
+ }
+ PG_END_TRY();
+
+ INSTR_TIME_SET_CURRENT(duration);
+ INSTR_TIME_SUBTRACT(duration, start);
+
+ /* calc differences of buffer counters. */
+ memset(&bufusage, 0, sizeof(BufferUsage));
+ BufferUsageAccumDiff(&bufusage, &pgBufferUsage, &bufusage_start);
+
+ 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
*/
@@ -860,7 +985,7 @@ pgss_ExecutorStart(QueryDesc *queryDesc, int eflags)
* counting of optimizable statements that are directly contained in
* utility statements.
*/
- if (pgss_enabled() && queryDesc->plannedstmt->queryId != UINT64CONST(0))
+ if (pgss_enabled(exec_nested_level) && queryDesc->plannedstmt->queryId != UINT64CONST(0))
{
/*
* Set up to track total elapsed time in ExecutorRun. Make sure the
@@ -885,7 +1010,7 @@ static void
pgss_ExecutorRun(QueryDesc *queryDesc, ScanDirection direction, uint64 count,
bool execute_once)
{
- nested_level++;
+ exec_nested_level++;
PG_TRY();
{
if (prev_ExecutorRun)
@@ -895,7 +1020,7 @@ pgss_ExecutorRun(QueryDesc *queryDesc, ScanDirection direction, uint64 count,
}
PG_FINALLY();
{
- nested_level--;
+ exec_nested_level--;
}
PG_END_TRY();
}
@@ -906,7 +1031,7 @@ pgss_ExecutorRun(QueryDesc *queryDesc, ScanDirection direction, uint64 count,
static void
pgss_ExecutorFinish(QueryDesc *queryDesc)
{
- nested_level++;
+ exec_nested_level++;
PG_TRY();
{
if (prev_ExecutorFinish)
@@ -916,7 +1041,7 @@ pgss_ExecutorFinish(QueryDesc *queryDesc)
}
PG_FINALLY();
{
- nested_level--;
+ exec_nested_level--;
}
PG_END_TRY();
}
@@ -929,7 +1054,8 @@ pgss_ExecutorEnd(QueryDesc *queryDesc)
{
uint64 queryId = queryDesc->plannedstmt->queryId;
- if (queryId != UINT64CONST(0) && queryDesc->totaltime && pgss_enabled())
+ if (queryId != UINT64CONST(0) && queryDesc->totaltime &&
+ pgss_enabled(exec_nested_level))
{
/*
* Make sure stats accumulation is done. (Note: it's okay if several
@@ -941,6 +1067,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,
@@ -978,7 +1105,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
*
* Likewise, we don't track execution of DEALLOCATE.
*/
- if (pgss_track_utility && pgss_enabled() &&
+ if (pgss_track_utility && pgss_enabled(exec_nested_level) &&
!IsA(parsetree, ExecuteStmt) &&
!IsA(parsetree, PrepareStmt) &&
!IsA(parsetree, DeallocateStmt))
@@ -992,7 +1119,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
bufusage_start = pgBufferUsage;
INSTR_TIME_SET_CURRENT(start);
- nested_level++;
+ exec_nested_level++;
PG_TRY();
{
if (prev_ProcessUtility)
@@ -1006,7 +1133,7 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString,
}
PG_FINALLY();
{
- nested_level--;
+ exec_nested_level--;
}
PG_END_TRY();
@@ -1016,35 +1143,14 @@ 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);
+ memset(&bufusage, 0, sizeof(BufferUsage));
+ BufferUsageAccumDiff(&bufusage, &pgBufferUsage, &bufusage_start);
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 +1189,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)
{
@@ -1234,19 +1345,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 +1368,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 +1394,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 +1442,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 30
+#define PG_STAT_STATEMENTS_COLS 30 /* maximum of above */
/*
* Retrieve statement statistics.
@@ -1340,6 +1455,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 +1570,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,30 +1729,43 @@ 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 < PGSS_NUMKIND; 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);
+ if (api_version >= PGSS_V1_8)
+ values[i++] = Int64GetDatumFast(tmp.total_time[0] +
+ tmp.total_time[1]);
values[i++] = Int64GetDatumFast(tmp.shared_blks_hit);
values[i++] = Int64GetDatumFast(tmp.shared_blks_read);
if (api_version >= PGSS_V1_1)
@@ -1646,6 +1788,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 +1924,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;
@@ -2486,6 +2629,7 @@ JumbleRowMarks(pgssJumbleState *jstate, List *rowMarks)
foreach(lc, rowMarks)
{
RowMarkClause *rowmark = lfirst_node(RowMarkClause, lc);
+
if (!rowmark->pushedDown)
{
APP_JUMB(rowmark->rti);
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..11de629227 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,48 @@
<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>min_plan_time</structfield></entry>
+ <entry><type>double precision</type></entry>
+ <entry></entry>
+ <entry>Minimum time spent planning the statement, in milliseconds</entry>
+ </row>
+
+ <row>
+ <entry><structfield>max_plan_time</structfield></entry>
+ <entry><type>double precision</type></entry>
+ <entry></entry>
+ <entry>Maximum time spent planning the statement, in milliseconds</entry>
+ </row>
+
+ <row>
+ <entry><structfield>mean_plan_time</structfield></entry>
+ <entry><type>double precision</type></entry>
+ <entry></entry>
+ <entry>Mean time spent planning the statement, in milliseconds</entry>
+ </row>
+
+ <row>
+ <entry><structfield>stddev_plan_time</structfield></entry>
+ <entry><type>double precision</type></entry>
+ <entry></entry>
+ <entry>Population standard deviation of time spent planning the statement, in milliseconds</entry>
+ </row>
+
<row>
<entry><structfield>calls</structfield></entry>
<entry><type>bigint</type></entry>
@@ -90,38 +133,38 @@
</row>
<row>
- <entry><structfield>total_time</structfield></entry>
+ <entry><structfield>total_exec_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 executing the statement, in milliseconds</entry>
</row>
<row>
- <entry><structfield>min_time</structfield></entry>
+ <entry><structfield>min_exec_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><structfield>max_exec_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><structfield>mean_exec_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><structfield>stddev_exec_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>
@@ -221,6 +264,15 @@
</entry>
</row>
+ <row>
+ <entry><structfield>total_time</structfield></entry>
+ <entry><type>double precision</type></entry>
+ <entry></entry>
+ <entry>
+ Total time spend planning and executing the statement, in milliseconds
+ </entry>
+ </row>
+
</tbody>
</tgroup>
</table>
@@ -431,6 +483,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>)
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index bc1d42bf64..042e10f96b 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -21,8 +21,6 @@ BufferUsage pgBufferUsage;
static BufferUsage save_pgBufferUsage;
static void BufferUsageAdd(BufferUsage *dst, const BufferUsage *add);
-static void BufferUsageAccumDiff(BufferUsage *dst,
- const BufferUsage *add, const BufferUsage *sub);
/* Allocate new instrumentation structure(s) */
@@ -203,7 +201,7 @@ BufferUsageAdd(BufferUsage *dst, const BufferUsage *add)
}
/* dst += add - sub */
-static void
+void
BufferUsageAccumDiff(BufferUsage *dst,
const BufferUsage *add,
const BufferUsage *sub)
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index f48d46aede..f1658e9fa0 100644
--- a/src/include/executor/instrument.h
+++ b/src/include/executor/instrument.h
@@ -72,6 +72,9 @@ typedef struct WorkerInstrumentation
extern PGDLLIMPORT BufferUsage pgBufferUsage;
+extern void BufferUsageAccumDiff(BufferUsage *dst,
+ const BufferUsage *add, const BufferUsage *sub);
+
extern Instrumentation *InstrAlloc(int n, int instrument_options);
extern void InstrInit(Instrumentation *instr, int instrument_options);
extern void InstrStartNode(Instrumentation *instr);
--
2.25.1
