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
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
(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
(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
(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
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;
--
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
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
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)
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)
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)
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)
(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;
--- /dev/null
+/* 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 * FROM pg_stat_statements(true);
+
+GRANT SELECT ON pg_stat_statements TO PUBLIC;
+
+
/*-------------------------------------------------------------------------
*
* pg_stat_statements.c
- * Track statement execution times across a whole database cluster.
+ * Track statement planning and execution times as well as resource
+ * usage across a whole database 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
#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"
#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 */
PGSS_V1_0 = 0,
PGSS_V1_1,
PGSS_V1_2,
- PGSS_V1_3
+ PGSS_V1_3,
+ PGSS_V1_8
} pgssVersion;
+typedef enum pgssStoreKind
+{
+ PGSS_INVALID = -1,
+
+ /*
+ * 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_NUMKIND /* Must be last value of this enum */
+} 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.
*/
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 */
/*---- 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 post_parse_analyze_hook_type prev_post_parse_analyze_hook = NULL;
+static planner_hook_type prev_planner_hook = NULL;
static ExecutorStart_hook_type prev_ExecutorStart = NULL;
static ExecutorRun_hook_type prev_ExecutorRun = NULL;
static ExecutorFinish_hook_type prev_ExecutorFinish = NULL;
static int pgss_max; /* max # statements to track */
static int pgss_track; /* tracking level */
static bool pgss_track_utility; /* whether to track utility commands */
+static bool pgss_track_planning; /* whether to track planning duration */
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 { \
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 void pgss_post_parse_analyze(ParseState *pstate, Query *query);
+static PlannedStmt *pgss_planner(Query *parse,
+ const char *query_string,
+ int cursorOptions,
+ ParamListInfo boundParams);
static void pgss_ExecutorStart(QueryDesc *queryDesc, int eflags);
static void pgss_ExecutorRun(QueryDesc *queryDesc,
ScanDirection direction,
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,
+ pgssStoreKind kind,
double total_time, uint64 rows,
const BufferUsage *bufusage,
pgssJumbleState *jstate);
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,
shmem_startup_hook = pgss_shmem_startup;
prev_post_parse_analyze_hook = post_parse_analyze_hook;
post_parse_analyze_hook = pgss_post_parse_analyze;
+ prev_planner_hook = planner_hook;
+ planner_hook = pgss_planner;
prev_ExecutorStart = ExecutorStart_hook;
ExecutorStart_hook = pgss_ExecutorStart;
prev_ExecutorRun = ExecutorRun_hook;
/* 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;
buffer[temp.query_len] = '\0';
/* Skip loading "sticky" entries */
- if (temp.counters.calls == 0)
+ if (IS_STICKY(temp.counters))
continue;
/* Store the query text */
Assert(query->queryId == UINT64CONST(0));
/* Safety check... */
- if (!pgss || !pgss_hash || !pgss_enabled())
+ if (!pgss || !pgss_hash || !pgss_enabled(exec_nested_level))
return;
/*
query->queryId,
query->stmt_location,
query->stmt_len,
+ PGSS_INVALID,
0,
0,
NULL,
&jstate);
}
+/*
+ * Planner hook: forward to regular planner, but measure planning time
+ * if needed.
+ */
+static PlannedStmt *
+pgss_planner(Query *parse,
+ const char *query_string,
+ int cursorOptions,
+ ParamListInfo boundParams)
+{
+ PlannedStmt *result;
+
+ /*
+ * We can't process the query if no query_string is provided, as
+ * pgss_store needs it. We also ignore query without queryid, as it would
+ * be treated as a utility statement, which may not be the case.
+ *
+ * Note that planner_hook can be called from the planner itself, so we
+ * have a specific nesting level for the planner. However, utility
+ * commands containing optimizable statements can also call the planner,
+ * same for regular DML (for instance for underlying foreign key queries).
+ * So testing the planner nesting level only is not enough to detect real
+ * top level planner call.
+ */
+ if (pgss_enabled(plan_nested_level + exec_nested_level)
+ && pgss_track_planning && query_string
+ && parse->queryId != UINT64CONST(0))
+ {
+ instr_time start;
+ instr_time duration;
+ BufferUsage bufusage_start,
+ bufusage;
+
+ /* We need to track buffer usage as the planner can access them. */
+ bufusage_start = pgBufferUsage;
+ INSTR_TIME_SET_CURRENT(start);
+
+ plan_nested_level++;
+ PG_TRY();
+ {
+ if (prev_planner_hook)
+ result = prev_planner_hook(parse, query_string, cursorOptions,
+ boundParams);
+ else
+ result = standard_planner(parse, query_string, cursorOptions,
+ boundParams);
+ }
+ PG_FINALLY();
+ {
+ plan_nested_level--;
+ }
+ 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_string,
+ 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_string, cursorOptions,
+ boundParams);
+ else
+ result = standard_planner(parse, query_string, cursorOptions,
+ boundParams);
+ }
+
+ return result;
+}
+
/*
* ExecutorStart hook: start up tracking if needed
*/
* 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
pgss_ExecutorRun(QueryDesc *queryDesc, ScanDirection direction, uint64 count,
bool execute_once)
{
- nested_level++;
+ exec_nested_level++;
PG_TRY();
{
if (prev_ExecutorRun)
}
PG_FINALLY();
{
- nested_level--;
+ exec_nested_level--;
}
PG_END_TRY();
}
static void
pgss_ExecutorFinish(QueryDesc *queryDesc)
{
- nested_level++;
+ exec_nested_level++;
PG_TRY();
{
if (prev_ExecutorFinish)
}
PG_FINALLY();
{
- nested_level--;
+ exec_nested_level--;
}
PG_END_TRY();
}
{
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
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,
*
* 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))
bufusage_start = pgBufferUsage;
INSTR_TIME_SET_CURRENT(start);
- nested_level++;
+ exec_nested_level++;
PG_TRY();
{
if (prev_ProcessUtility)
}
PG_FINALLY();
{
- nested_level--;
+ exec_nested_level--;
}
PG_END_TRY();
0, /* signal that it's a utility stmt */
pstmt->stmt_location,
pstmt->stmt_len,
+ PGSS_EXEC,
INSTR_TIME_GET_MILLISEC(duration),
rows,
&bufusage,
* 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.
+ *
+ * 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,
+ pgssStoreKind kind,
double total_time, uint64 rows,
const BufferUsage *bufusage,
pgssJumbleState *jstate)
*/
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] += total_time;
+
+ 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] = total_time;
+ e->counters.max_time[kind] = total_time;
+ e->counters.mean_time[kind] = total_time;
}
else
{
* 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] +=
+ (total_time - old_mean) / e->counters.calls[kind];
+ e->counters.sum_var_time[kind] +=
+ (total_time - old_mean) * (total_time - 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] > total_time)
+ e->counters.min_time[kind] = total_time;
+ if (e->counters.max_time[kind] < total_time)
+ e->counters.max_time[kind] = total_time;
}
e->counters.rows += rows;
e->counters.shared_blks_hit += bufusage->shared_blks_hit;
#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.
* 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)
{
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");
}
}
/* 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);
values[i++] = Int64GetDatumFast(tmp.shared_blks_hit);
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);
{
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;
# pg_stat_statements extension
-comment = 'track execution statistics of all SQL statements executed'
-default_version = '1.7'
+comment = 'track planning and execution statistics of all SQL statements executed'
+default_version = '1.8'
module_pathname = '$libdir/pg_stat_statements'
relocatable = true
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;
<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>
<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>
</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>
</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.save</varname> (<type>boolean</type>)
$ pgbench -c10 -t300 bench
bench=# \x
-bench=# SELECT query, calls, total_time, rows, 100.0 * shared_blks_hit /
+bench=# SELECT query, calls, total_exec_time, rows, 100.0 * shared_blks_hit /
nullif(shared_blks_hit + shared_blks_read, 0) AS hit_percent
- FROM pg_stat_statements ORDER BY total_time DESC LIMIT 5;
--[ RECORD 1 ]--------------------------------------------------------------------
-query | UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2
-calls | 3000
-total_time | 25565.855387
-rows | 3000
-hit_percent | 100.0000000000000000
--[ RECORD 2 ]--------------------------------------------------------------------
-query | UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2
-calls | 3000
-total_time | 20756.669379
-rows | 3000
-hit_percent | 100.0000000000000000
--[ RECORD 3 ]--------------------------------------------------------------------
-query | copy pgbench_accounts from stdin
-calls | 1
-total_time | 291.865911
-rows | 100000
-hit_percent | 100.0000000000000000
--[ RECORD 4 ]--------------------------------------------------------------------
-query | UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2
-calls | 3000
-total_time | 271.232977
-rows | 3000
-hit_percent | 98.5723926698852723
--[ RECORD 5 ]--------------------------------------------------------------------
-query | alter table pgbench_accounts add primary key (aid)
-calls | 1
-total_time | 160.588563
-rows | 0
-hit_percent | 100.0000000000000000
+ FROM pg_stat_statements ORDER BY total_exec_time DESC LIMIT 5;
+-[ RECORD 1 ]---+--------------------------------------------------------------------
+query | UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2
+calls | 3000
+total_exec_time | 25565.855387
+rows | 3000
+hit_percent | 100.0000000000000000
+-[ RECORD 2 ]---+--------------------------------------------------------------------
+query | UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2
+calls | 3000
+total_exec_time | 20756.669379
+rows | 3000
+hit_percent | 100.0000000000000000
+-[ RECORD 3 ]---+--------------------------------------------------------------------
+query | copy pgbench_accounts from stdin
+calls | 1
+total_exec_time | 291.865911
+rows | 100000
+hit_percent | 100.0000000000000000
+-[ RECORD 4 ]---+--------------------------------------------------------------------
+query | UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2
+calls | 3000
+total_exec_time | 271.232977
+rows | 3000
+hit_percent | 98.8454011741682975
+-[ RECORD 5 ]---+--------------------------------------------------------------------
+query | alter table pgbench_accounts add primary key (aid)
+calls | 1
+total_exec_time | 160.588563
+rows | 0
+hit_percent | 100.0000000000000000
bench=# SELECT pg_stat_statements_reset(0,0,s.queryid) FROM pg_stat_statements AS s
WHERE s.query = 'UPDATE pgbench_branches SET bbalance = bbalance + $1 WHERE bid = $2';
-bench=# SELECT query, calls, total_time, rows, 100.0 * shared_blks_hit /
+bench=# SELECT query, calls, total_exec_time, rows, 100.0 * shared_blks_hit /
nullif(shared_blks_hit + shared_blks_read, 0) AS hit_percent
- FROM pg_stat_statements ORDER BY total_time DESC LIMIT 5;
--[ RECORD 1 ]--------------------------------------------------------------------
-query | UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2
-calls | 3000
-total_time | 20756.669379
-rows | 3000
-hit_percent | 100.0000000000000000
--[ RECORD 2 ]--------------------------------------------------------------------
-query | copy pgbench_accounts from stdin
-calls | 1
-total_time | 291.865911
-rows | 100000
-hit_percent | 100.0000000000000000
--[ RECORD 3 ]--------------------------------------------------------------------
-query | UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2
-calls | 3000
-total_time | 271.232977
-rows | 3000
-hit_percent | 98.5723926698852723
--[ RECORD 4 ]--------------------------------------------------------------------
-query | alter table pgbench_accounts add primary key (aid)
-calls | 1
-total_time | 160.588563
-rows | 0
-hit_percent | 100.0000000000000000
--[ RECORD 5 ]--------------------------------------------------------------------
-query | vacuum analyze pgbench_accounts
-calls | 1
-total_time | 136.448116
-rows | 0
-hit_percent | 99.9201915403032721
+ FROM pg_stat_statements ORDER BY total_exec_time DESC LIMIT 5;
+-[ RECORD 1 ]---+--------------------------------------------------------------------
+query | UPDATE pgbench_tellers SET tbalance = tbalance + $1 WHERE tid = $2
+calls | 3000
+total_exec_time | 20756.669379
+rows | 3000
+hit_percent | 100.0000000000000000
+-[ RECORD 2 ]---+--------------------------------------------------------------------
+query | copy pgbench_accounts from stdin
+calls | 1
+total_exec_time | 291.865911
+rows | 100000
+hit_percent | 100.0000000000000000
+-[ RECORD 3 ]---+--------------------------------------------------------------------
+query | UPDATE pgbench_accounts SET abalance = abalance + $1 WHERE aid = $2
+calls | 3000
+total_exec_time | 271.232977
+rows | 3000
+hit_percent | 98.8454011741682975
+-[ RECORD 4 ]---+--------------------------------------------------------------------
+query | alter table pgbench_accounts add primary key (aid)
+calls | 1
+total_exec_time | 160.588563
+rows | 0
+hit_percent | 100.0000000000000000
+-[ RECORD 5 ]---+--------------------------------------------------------------------
+query | vacuum analyze pgbench_accounts
+calls | 1
+total_exec_time | 136.448116
+rows | 0
+hit_percent | 99.9201915403032721
bench=# SELECT pg_stat_statements_reset(0,0,0);
-bench=# SELECT query, calls, total_time, rows, 100.0 * shared_blks_hit /
+bench=# SELECT query, calls, total_exec_time, rows, 100.0 * shared_blks_hit /
nullif(shared_blks_hit + shared_blks_read, 0) AS hit_percent
- FROM pg_stat_statements ORDER BY total_time DESC LIMIT 5;
--[ RECORD 1 ]---------------------------------------
-query | SELECT pg_stat_statements_reset(0,0,0)
-calls | 1
-total_time | 0.189497
-rows | 1
-hit_percent |
+ FROM pg_stat_statements ORDER BY total_exec_time DESC LIMIT 5;
+-[ RECORD 1 ]---+-----------------------------------------------------------------------------
+query | SELECT pg_stat_statements_reset(0,0,0)
+calls | 1
+total_exec_time | 0.189497
+rows | 1
+hit_percent |
+-[ RECORD 2 ]---+-----------------------------------------------------------------------------
+query | SELECT query, calls, total_exec_time, rows, $1 * shared_blks_hit / +
+ | nullif(shared_blks_hit + shared_blks_read, $2) AS hit_percent+
+ | FROM pg_stat_statements ORDER BY total_exec_time DESC LIMIT $3
+calls | 0
+total_exec_time | 0
+rows | 0
+hit_percent |
</screen>
</sect2>
pgssJumbleState
pgssLocationLen
pgssSharedState
+pgssStoreKind
pgssVersion
pgstat_page
pgstattuple_type
projects / postgresql.git / commitdiff