From a28849b79a47d9c22a46e961b0ebf8b35b862367 Mon Sep 17 00:00:00 2001 From: Julien Rouhaud Date: Wed, 27 Mar 2019 11:24:35 +0100 Subject: [PATCH 2/2] Add planning counters to pg_stat_statements --- contrib/pg_stat_statements/Makefile | 3 +- .../expected/pg_stat_statements.out | 64 ++++ .../pg_stat_statements--1.7--1.8.sql | 52 +++ .../pg_stat_statements/pg_stat_statements.c | 316 +++++++++++++----- .../pg_stat_statements.control | 2 +- .../sql/pg_stat_statements.sql | 16 + doc/src/sgml/pgstatstatements.sgml | 49 ++- 7 files changed, 413 insertions(+), 89 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 051ce46f0c..db33d9ffe1 100644 --- a/contrib/pg_stat_statements/Makefile +++ b/contrib/pg_stat_statements/Makefile @@ -4,7 +4,8 @@ MODULE_big = pg_stat_statements OBJS = pg_stat_statements.o $(WIN32RES) 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 c759763be2..8517b124e4 100644 --- a/contrib/pg_stat_statements/expected/pg_stat_statements.out +++ b/contrib/pg_stat_statements/expected/pg_stat_statements.out @@ -593,4 +593,68 @@ 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(); + 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 +(5 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..de75643928 --- /dev/null +++ b/contrib/pg_stat_statements/pg_stat_statements--1.7--1.8.sql @@ -0,0 +1,52 @@ +/* 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 calls int8, + OUT total_exec_time float8, + OUT min_time float8, + OUT max_time float8, + OUT mean_time float8, + OUT stddev_time float8, + OUT rows int8, + OUT shared_blks_hit int8, + OUT shared_blks_read int8, + OUT shared_blks_dirtied int8, + OUT shared_blks_written int8, + OUT local_blks_hit int8, + OUT local_blks_read int8, + OUT local_blks_dirtied int8, + OUT local_blks_written int8, + OUT temp_blks_read int8, + OUT temp_blks_written int8, + OUT blk_read_time float8, + OUT blk_write_time float8 +) +RETURNS SETOF record +AS 'MODULE_PATHNAME', 'pg_stat_statements_1_8' +LANGUAGE C STRICT VOLATILE PARALLEL SAFE; + +CREATE VIEW pg_stat_statements AS + SELECT *, total_plan_time + total_exec_time AS total_time + FROM pg_stat_statements(true); + +GRANT SELECT ON pg_stat_statements TO PUBLIC; + + diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c index 16b8074a00..6baafe53a6 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 @@ -66,6 +67,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" @@ -120,9 +122,17 @@ 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_JUMBLE, + PGSS_EXEC_TIME, + PGSS_PLAN_TIME +} 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. @@ -145,11 +155,13 @@ typedef struct pgssHashKey typedef struct Counters { int64 calls; /* # of times executed */ - double total_time; /* total execution time, in msec */ + double total_exec_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 plans; /* # of times planned */ + double total_plan_time; /* total planning time, in msec */ int64 rows; /* total # of retrieved or affected rows */ int64 shared_blks_hit; /* # of shared buffer hits */ int64 shared_blks_read; /* # of shared disk blocks read */ @@ -238,6 +250,7 @@ static int nested_level = 0; /* Saved hook values in case of unload */ static shmem_startup_hook_type prev_shmem_startup_hook = NULL; +static planner_hook_type prev_planner_hook = NULL; static post_parse_analyze_hook_type prev_post_parse_analyze_hook = NULL; static ExecutorStart_hook_type prev_ExecutorStart = NULL; static ExecutorRun_hook_type prev_ExecutorRun = NULL; @@ -268,6 +281,7 @@ static const struct config_enum_entry track_options[] = static int pgss_max; /* max # statements to track */ static int pgss_track; /* tracking level */ +static bool pgss_track_planning; /* whether to track planning duration */ static bool pgss_track_utility; /* whether to track utility commands */ static bool pgss_save; /* whether to save stats across shutdown */ @@ -293,10 +307,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 +330,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, @@ -340,6 +361,7 @@ static char *generate_normalized_query(pgssJumbleState *jstate, const char *quer static void fill_in_constant_lengths(pgssJumbleState *jstate, const char *query, int query_loc); static int comp_location(const void *a, const void *b); +static BufferUsage compute_buffer_counters(BufferUsage start, BufferUsage stop); /* @@ -398,7 +420,18 @@ _PG_init(void) NULL, NULL); - DefineCustomBoolVariable("pg_stat_statements.save", + 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, &pgss_save, @@ -424,6 +457,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; @@ -447,6 +482,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; @@ -834,13 +870,87 @@ pgss_post_parse_analyze(ParseState *pstate, Query *query) */ if (jstate.clocations_count > 0) pgss_store(pstate->p_sourcetext, - query->queryId, - query->stmt_location, - query->stmt_len, - 0, + query->queryId, + query->stmt_location, + query->stmt_len, + PGSS_JUMBLE, + 0, + 0, + NULL, + &jstate); +} + +/* + * Planner hook: forward to regular planner, but measure planning time. + */ +static PlannedStmt * +pgss_planner_hook(Query *parse, + const char *query_text, + int cursorOptions, + ParamListInfo boundParams) +{ + PlannedStmt *result; + BufferUsage bufusage_start, + bufusage; + + bufusage_start = pgBufferUsage; + if (pgss_enabled() && pgss_track_planning) + { + instr_time start; + instr_time duration; + + INSTR_TIME_SET_CURRENT(start); + + nested_level++; + PG_TRY(); + { + if (prev_planner_hook) + result = prev_planner_hook(parse, query_text, cursorOptions, + boundParams); + else + result = standard_planner(parse, query_text, cursorOptions, + boundParams); + nested_level--; + } + PG_CATCH(); + { + nested_level--; + PG_RE_THROW(); + } + PG_END_TRY(); + + INSTR_TIME_SET_CURRENT(duration); + INSTR_TIME_SUBTRACT(duration, start); + + /* calc differences of buffer counters. */ + bufusage = compute_buffer_counters(bufusage_start, pgBufferUsage); + + /* + * we only store planning duration, query text has been initialized during + * previous pgss_post_parse_analyze as it not available inside + * pgss_planner_hook. + */ + pgss_store(query_text, + parse->queryId, + parse->stmt_location, + parse->stmt_len, + PGSS_PLAN_TIME, + INSTR_TIME_GET_MILLISEC(duration), 0, - NULL, - &jstate); + &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; } /* @@ -944,6 +1054,7 @@ pgss_ExecutorEnd(QueryDesc *queryDesc) queryId, queryDesc->plannedstmt->stmt_location, queryDesc->plannedstmt->stmt_len, + PGSS_EXEC_TIME, queryDesc->totaltime->total * 1000.0, /* convert to msec */ queryDesc->estate->es_processed, &queryDesc->totaltime->bufusage, @@ -977,8 +1088,8 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString, * string), and then a different one with the same query string (but hash * calculated from the query tree) would be used to accumulate costs of * ensuing EXECUTEs. This would be confusing, and inconsistent with other - * cases where planning time is not included at all. - * + * cases where planning time is not included at all. + * * Likewise, we don't track execution of DEALLOCATE. */ if (pgss_track_utility && pgss_enabled() && @@ -1026,35 +1137,13 @@ pgss_ProcessUtility(PlannedStmt *pstmt, const char *queryString, rows = 0; /* calc differences of buffer counters. */ - bufusage.shared_blks_hit = - pgBufferUsage.shared_blks_hit - bufusage_start.shared_blks_hit; - bufusage.shared_blks_read = - pgBufferUsage.shared_blks_read - bufusage_start.shared_blks_read; - bufusage.shared_blks_dirtied = - pgBufferUsage.shared_blks_dirtied - bufusage_start.shared_blks_dirtied; - bufusage.shared_blks_written = - pgBufferUsage.shared_blks_written - bufusage_start.shared_blks_written; - bufusage.local_blks_hit = - pgBufferUsage.local_blks_hit - bufusage_start.local_blks_hit; - bufusage.local_blks_read = - pgBufferUsage.local_blks_read - bufusage_start.local_blks_read; - bufusage.local_blks_dirtied = - pgBufferUsage.local_blks_dirtied - bufusage_start.local_blks_dirtied; - bufusage.local_blks_written = - pgBufferUsage.local_blks_written - bufusage_start.local_blks_written; - bufusage.temp_blks_read = - pgBufferUsage.temp_blks_read - bufusage_start.temp_blks_read; - bufusage.temp_blks_written = - pgBufferUsage.temp_blks_written - bufusage_start.temp_blks_written; - bufusage.blk_read_time = pgBufferUsage.blk_read_time; - INSTR_TIME_SUBTRACT(bufusage.blk_read_time, bufusage_start.blk_read_time); - bufusage.blk_write_time = pgBufferUsage.blk_write_time; - INSTR_TIME_SUBTRACT(bufusage.blk_write_time, bufusage_start.blk_write_time); + bufusage = compute_buffer_counters(bufusage_start, pgBufferUsage); pgss_store(queryString, 0, /* signal that it's a utility stmt */ pstmt->stmt_location, pstmt->stmt_len, + PGSS_EXEC_TIME, INSTR_TIME_GET_MILLISEC(duration), rows, &bufusage, @@ -1093,12 +1182,14 @@ 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. total_exec_time, rows, bufusage are ignored in this case. */ 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) { @@ -1153,8 +1244,9 @@ pgss_store(const char *query, uint64 queryId, queryId = pgss_hash_string(query, query_len); /* - * If we are unlucky enough to get a hash of zero(invalid), use queryID - * as 2 instead, queryID 1 is already in use for normal statements. + * If we are unlucky enough to get a hash of zero(invalid), use + * queryID as 2 instead, queryID 1 is already in use for normal + * statements. */ if (queryId == UINT64CONST(0)) queryId = UINT64CONST(2); @@ -1185,8 +1277,10 @@ pgss_store(const char *query, uint64 queryId, * in the interval where we don't hold the lock below. That case is * handled by entry_alloc.) */ - if (jstate) + if (kind == PGSS_JUMBLE) { + Assert(jstate); + LWLockRelease(pgss->lock); norm_query = generate_normalized_query(jstate, query, query_location, @@ -1235,7 +1329,7 @@ pgss_store(const char *query, uint64 queryId, } /* Increment the counts, except when jstate is not NULL */ - if (!jstate) + if (kind != PGSS_JUMBLE) { /* * Grab the spinlock while updating the counters (see comment about @@ -1249,47 +1343,58 @@ pgss_store(const char *query, uint64 queryId, if (e->counters.calls == 0) e->counters.usage = USAGE_INIT; - e->counters.calls += 1; - e->counters.total_time += total_time; - if (e->counters.calls == 1) + if (kind == PGSS_EXEC_TIME) { - e->counters.min_time = total_time; - e->counters.max_time = total_time; - e->counters.mean_time = total_time; + /* updating counters for executions */ + e->counters.calls += 1; + e->counters.total_exec_time += timing; + + if (e->counters.calls == 1 ) + { + e->counters.min_time = timing; + e->counters.max_time = timing; + e->counters.mean_time = timing; + } + else + { + /* + * Welford's method for accurately computing variance. See + * + */ + double old_mean = e->counters.mean_time; + + e->counters.mean_time += + (timing - old_mean) / e->counters.calls; + e->counters.sum_var_time += + (timing - old_mean) * (timing - e->counters.mean_time); + + /* calculate min and max time */ + if (e->counters.min_time > timing) + e->counters.min_time = timing; + if (e->counters.max_time < timing) + e->counters.max_time = timing; + } + e->counters.rows += rows; + e->counters.shared_blks_hit += bufusage->shared_blks_hit; + e->counters.shared_blks_read += bufusage->shared_blks_read; + e->counters.shared_blks_dirtied += bufusage->shared_blks_dirtied; + e->counters.shared_blks_written += bufusage->shared_blks_written; + e->counters.local_blks_hit += bufusage->local_blks_hit; + e->counters.local_blks_read += bufusage->local_blks_read; + e->counters.local_blks_dirtied += bufusage->local_blks_dirtied; + e->counters.local_blks_written += bufusage->local_blks_written; + e->counters.temp_blks_read += bufusage->temp_blks_read; + 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_exec_time); } else { - /* - * Welford's method for accurately computing variance. See - * - */ - double old_mean = e->counters.mean_time; - - 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); - - /* 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; + /* updating counters for planning */ + e->counters.plans += 1; + e->counters.total_plan_time += timing; } - e->counters.rows += rows; - e->counters.shared_blks_hit += bufusage->shared_blks_hit; - e->counters.shared_blks_read += bufusage->shared_blks_read; - e->counters.shared_blks_dirtied += bufusage->shared_blks_dirtied; - e->counters.shared_blks_written += bufusage->shared_blks_written; - e->counters.local_blks_hit += bufusage->local_blks_hit; - e->counters.local_blks_read += bufusage->local_blks_read; - e->counters.local_blks_dirtied += bufusage->local_blks_dirtied; - e->counters.local_blks_written += bufusage->local_blks_written; - e->counters.temp_blks_read += bufusage->temp_blks_read; - 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); SpinLockRelease(&e->mutex); } @@ -1337,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 25 +#define PG_STAT_STATEMENTS_COLS 25 /* maximum of above */ /* * Retrieve statement statistics. @@ -1349,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) { @@ -1455,6 +1571,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"); } @@ -1613,8 +1733,13 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo, if (tmp.calls == 0) continue; + if (api_version >= PGSS_V1_8) + { + values[i++] = Int64GetDatumFast(tmp.plans); + values[i++] = Float8GetDatumFast(tmp.total_plan_time); + } values[i++] = Int64GetDatumFast(tmp.calls); - values[i++] = Float8GetDatumFast(tmp.total_time); + values[i++] = Float8GetDatumFast(tmp.total_exec_time); if (api_version >= PGSS_V1_3) { values[i++] = Float8GetDatumFast(tmp.min_time); @@ -1656,6 +1781,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); @@ -3242,3 +3368,31 @@ comp_location(const void *a, const void *b) else return 0; } + +static BufferUsage +compute_buffer_counters(BufferUsage start, BufferUsage stop) +{ + BufferUsage result; + + result.shared_blks_hit = stop.shared_blks_hit - start.shared_blks_hit; + result.shared_blks_read = stop.shared_blks_read - start.shared_blks_read; + result.shared_blks_dirtied = stop.shared_blks_dirtied - + start.shared_blks_dirtied; + result.shared_blks_written = stop.shared_blks_written - + start.shared_blks_written; + result.local_blks_hit = stop.local_blks_hit - start.local_blks_hit; + result.local_blks_read = stop.local_blks_read - start.local_blks_read; + result.local_blks_dirtied = stop.local_blks_dirtied - + start.local_blks_dirtied; + result.local_blks_written = stop.local_blks_written - + start.local_blks_written; + result.temp_blks_read = stop.temp_blks_read - start.temp_blks_read; + result.temp_blks_written = stop.temp_blks_written - + start.temp_blks_written; + result.blk_read_time = stop.blk_read_time; + INSTR_TIME_SUBTRACT(result.blk_read_time, start.blk_read_time); + result.blk_write_time = stop.blk_write_time; + INSTR_TIME_SUBTRACT(result.blk_write_time, start.blk_write_time); + + return result; +} diff --git a/contrib/pg_stat_statements/pg_stat_statements.control b/contrib/pg_stat_statements/pg_stat_statements.control index 14cb422354..7fb20df886 100644 --- a/contrib/pg_stat_statements/pg_stat_statements.control +++ b/contrib/pg_stat_statements/pg_stat_statements.control @@ -1,5 +1,5 @@ # pg_stat_statements extension comment = 'track execution statistics of all SQL statements executed' -default_version = '1.7' +default_version = '1.8' module_pathname = '$libdir/pg_stat_statements' relocatable = true diff --git a/contrib/pg_stat_statements/sql/pg_stat_statements.sql b/contrib/pg_stat_statements/sql/pg_stat_statements.sql index aef890d893..4d7d6e584d 100644 --- a/contrib/pg_stat_statements/sql/pg_stat_statements.sql +++ b/contrib/pg_stat_statements/sql/pg_stat_statements.sql @@ -259,4 +259,20 @@ SELECT query, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; DROP ROLE regress_stats_user1; DROP ROLE regress_stats_user2; +-- +-- [re]plan counting +-- +SELECT pg_stat_statements_reset(); +CREATE TABLE test (); +PREPARE prep1 AS SELECT COUNT(*) FROM test;; +EXECUTE prep1; +EXECUTE prep1; +EXECUTE prep1; +ALTER TABLE test ADD COLUMN x int; +EXECUTE prep1; +SELECT 42; +SELECT 42; +SELECT 42; +SELECT query, plans, calls, rows FROM pg_stat_statements ORDER BY query COLLATE "C"; + DROP EXTENSION pg_stat_statements; diff --git a/doc/src/sgml/pgstatstatements.sgml b/doc/src/sgml/pgstatstatements.sgml index 26bb82da4a..368daf3e39 100644 --- a/doc/src/sgml/pgstatstatements.sgml +++ b/doc/src/sgml/pgstatstatements.sgml @@ -9,7 +9,8 @@ The pg_stat_statements 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. @@ -82,6 +83,20 @@ Text of a representative statement + + plans + bigint + + Number of times the statement was planned + + + + total_plan_time + double precision + + Total time spent planning the statement, in milliseconds + + calls bigint @@ -89,39 +104,46 @@ Number of times executed + + total_exec_time + double precision + + Total time spent executing the statement, in milliseconds + + total_time double precision - Total time spent in the statement, in milliseconds + Total time spent planning and executing the statement, in milliseconds min_time double precision - Minimum time spent in the statement, in milliseconds + Minimum time spent executing the statement, in milliseconds max_time double precision - Maximum time spent in the statement, in milliseconds + Maximum time spent executing the statement, in milliseconds mean_time double precision - Mean time spent in the statement, in milliseconds + Mean time spent executing the statement, in milliseconds stddev_time double precision - Population standard deviation of time spent in the statement, in milliseconds + Population standard deviation of time spent executing the statement, in milliseconds @@ -431,6 +453,21 @@ + + + pg_stat_statements.track_planning (boolean) + + + + + pg_stat_statements.track_planning controls whether + planning operations and duration are tracked by the module. + The default value is on. + Only superusers can change this setting. + + + + pg_stat_statements.track_utility (boolean) -- 2.20.1