From 84dd45604725a4a88b1d5782b9fc06c357ded074 Mon Sep 17 00:00:00 2001 From: Pavlo Golub Date: Thu, 5 Feb 2026 16:59:56 +0000 Subject: [PATCH v1] pg_stat_statements: Add last_execution_start column MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Add a new column last_execution_start to pg_stat_statements that records the start timestamp of the most recent execution of each tracked statement. The value is obtained via GetCurrentStatementStartTimestamp(), which reads the already-computed xact_StartTimestamp variable — a simple load with no system call. This means there is no measurable overhead on the critical stats accumulation path. Benchmark (16-vCPU, pgbench -c8 -j4 -T60, explicit transactions with 15 SELECT statements each): master HEAD: ~4574 TPS (avg of 3 runs: 4636, 4585, 4500) patched: ~4571 TPS (avg of 3 runs: 4577, 4560, 4575) difference: ~0.1% — well within noise The column is initialized at entry allocation time and updated on every stats-recording call to pgss_store(). It is reset by pg_stat_statements_reset() but not by minmax-only resets. A monitoring query to find statements that have executed since the last observation could look like: SELECT query, calls, last_execution_start FROM pg_stat_statements WHERE last_execution_start >= $1 -- e.g. last check timestamp ORDER BY last_execution_start DESC; Bump PGSS_FILE_HEADER to 0x20260330 for the changed on-disk format. --- contrib/pg_stat_statements/Makefile | 1 + .../expected/entry_timestamp.out | 78 ++++++++++++++++++ contrib/pg_stat_statements/meson.build | 1 + .../pg_stat_statements--1.13--1.14.sql | 79 +++++++++++++++++++ .../pg_stat_statements/pg_stat_statements.c | 45 ++++++++++- .../pg_stat_statements.control | 2 +- .../sql/entry_timestamp.sql | 48 +++++++++++ doc/src/sgml/pgstatstatements.sgml | 9 +++ 8 files changed, 259 insertions(+), 4 deletions(-) create mode 100644 contrib/pg_stat_statements/pg_stat_statements--1.13--1.14.sql diff --git a/contrib/pg_stat_statements/Makefile b/contrib/pg_stat_statements/Makefile index c27e9529bb6..d7142f71cf7 100644 --- a/contrib/pg_stat_statements/Makefile +++ b/contrib/pg_stat_statements/Makefile @@ -7,6 +7,7 @@ OBJS = \ EXTENSION = pg_stat_statements DATA = pg_stat_statements--1.4.sql \ + pg_stat_statements--1.13--1.14.sql \ pg_stat_statements--1.12--1.13.sql \ pg_stat_statements--1.11--1.12.sql pg_stat_statements--1.10--1.11.sql \ pg_stat_statements--1.9--1.10.sql pg_stat_statements--1.8--1.9.sql \ diff --git a/contrib/pg_stat_statements/expected/entry_timestamp.out b/contrib/pg_stat_statements/expected/entry_timestamp.out index a10c4be6bac..db7382ea0a4 100644 --- a/contrib/pg_stat_statements/expected/entry_timestamp.out +++ b/contrib/pg_stat_statements/expected/entry_timestamp.out @@ -150,6 +150,84 @@ WHERE query LIKE '%STMTTS%'; 2 | 1 | 2 | 0 (1 row) +-- +-- last_execution_start timestamp tests +-- +-- Reset stats first to avoid queryId collisions: simple "SELECT const AS alias" +-- queries all share the same normalized structure as the STMTTS queries above, +-- so EXECSTART entries would otherwise land on the pre-existing STMTTS entry. +SELECT pg_stat_statements_reset() IS NOT NULL AS t; + t +--- + t +(1 row) + +-- Capture a reference timestamp before running the tracked queries. +SELECT now() AS ref_ts_upd1 \gset +SELECT 1 AS "EXECSTART1"; + EXECSTART1 +------------ + 1 +(1 row) + +-- last_execution_start should be set and >= ref_ts_upd1, because the +-- statement started after we captured the reference timestamp. +SELECT + query, + last_execution_start IS NOT NULL as has_ts, + last_execution_start >= :'ref_ts_upd1' as after_ref1, + stats_since <= last_execution_start as after_stats_since +FROM pg_stat_statements +WHERE query LIKE '%EXECSTART%' +ORDER BY query COLLATE "C"; + query | has_ts | after_ref1 | after_stats_since +---------------------------+--------+------------+------------------- + SELECT $1 AS "EXECSTART1" | t | t | f +(1 row) + +-- Run EXECSTART1 again and verify that last_execution_start is updated. +SELECT now() AS ref_ts_upd2 \gset +SELECT 1 AS "EXECSTART1"; + EXECSTART1 +------------ + 1 +(1 row) + +SELECT + query, + last_execution_start >= :'ref_ts_upd2' as updated +FROM pg_stat_statements +WHERE query LIKE '%EXECSTART1%'; + query | updated +---------------------------+--------- + SELECT $1 AS "EXECSTART1" | t +(1 row) + +-- test filtering (monitoring use case): find statements that started +-- executing since our last observation (ref_ts_upd2). +SELECT count(*) as filtered_count +FROM pg_stat_statements +WHERE last_execution_start >= :'ref_ts_upd2' + AND query LIKE '%EXECSTART%'; + filtered_count +---------------- + 1 +(1 row) + +-- minmax reset should not affect last_execution_start +SELECT pg_stat_statements_reset(0, 0, queryid, true) +FROM pg_stat_statements +WHERE query LIKE '%EXECSTART1%' \gset +SELECT + query, + last_execution_start >= :'ref_ts_upd2' as ts_preserved +FROM pg_stat_statements +WHERE query LIKE '%EXECSTART1%'; + query | ts_preserved +---------------------------+-------------- + SELECT $1 AS "EXECSTART1" | t +(1 row) + -- Cleanup SELECT pg_stat_statements_reset() IS NOT NULL AS t; t diff --git a/contrib/pg_stat_statements/meson.build b/contrib/pg_stat_statements/meson.build index 9d78cb88b7d..77148949c0d 100644 --- a/contrib/pg_stat_statements/meson.build +++ b/contrib/pg_stat_statements/meson.build @@ -21,6 +21,7 @@ contrib_targets += pg_stat_statements install_data( 'pg_stat_statements.control', 'pg_stat_statements--1.4.sql', + 'pg_stat_statements--1.13--1.14.sql', 'pg_stat_statements--1.12--1.13.sql', 'pg_stat_statements--1.11--1.12.sql', 'pg_stat_statements--1.10--1.11.sql', diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.13--1.14.sql b/contrib/pg_stat_statements/pg_stat_statements--1.13--1.14.sql new file mode 100644 index 00000000000..af4e177f5fa --- /dev/null +++ b/contrib/pg_stat_statements/pg_stat_statements--1.13--1.14.sql @@ -0,0 +1,79 @@ +/* contrib/pg_stat_statements/pg_stat_statements--1.13--1.14.sql */ + +-- complain if script is sourced in psql, rather than via ALTER EXTENSION +\echo Use "ALTER EXTENSION pg_stat_statements UPDATE TO '1.14'" 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 toplevel bool, + 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 shared_blk_read_time float8, + OUT shared_blk_write_time float8, + OUT local_blk_read_time float8, + OUT local_blk_write_time float8, + OUT temp_blk_read_time float8, + OUT temp_blk_write_time float8, + OUT wal_records int8, + OUT wal_fpi int8, + OUT wal_bytes numeric, + OUT wal_buffers_full int8, + OUT jit_functions int8, + OUT jit_generation_time float8, + OUT jit_inlining_count int8, + OUT jit_inlining_time float8, + OUT jit_optimization_count int8, + OUT jit_optimization_time float8, + OUT jit_emission_count int8, + OUT jit_emission_time float8, + OUT jit_deform_count int8, + OUT jit_deform_time float8, + OUT parallel_workers_to_launch int8, + OUT parallel_workers_launched int8, + OUT generic_plan_calls int8, + OUT custom_plan_calls int8, + OUT stats_since timestamp with time zone, + OUT minmax_stats_since timestamp with time zone, + OUT last_execution_start timestamp with time zone +) +RETURNS SETOF record +AS 'MODULE_PATHNAME', 'pg_stat_statements_1_14' +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 7975476b890..6beb26949cf 100644 --- a/contrib/pg_stat_statements/pg_stat_statements.c +++ b/contrib/pg_stat_statements/pg_stat_statements.c @@ -49,6 +49,7 @@ #include "access/htup_details.h" #include "access/parallel.h" +#include "access/xact.h" #include "catalog/pg_authid.h" #include "common/int.h" #include "executor/instrument.h" @@ -87,7 +88,7 @@ PG_MODULE_MAGIC_EXT( #define PGSS_TEXT_FILE PG_STAT_TMP_DIR "/pgss_query_texts.stat" /* Magic number identifying the stats file format */ -static const uint32 PGSS_FILE_HEADER = 0x20250731; +static const uint32 PGSS_FILE_HEADER = 0x20260330; /* PostgreSQL major version number, changes in which invalidate all entries */ static const uint32 PGSS_PG_MAJOR_VERSION = PG_VERSION_NUM / 100; @@ -117,6 +118,7 @@ typedef enum pgssVersion PGSS_V1_11, PGSS_V1_12, PGSS_V1_13, + PGSS_V1_14, } pgssVersion; typedef enum pgssStoreKind @@ -241,6 +243,7 @@ typedef struct pgssEntry int encoding; /* query text encoding */ TimestampTz stats_since; /* timestamp of entry allocation */ TimestampTz minmax_stats_since; /* timestamp of last min/max values reset */ + TimestampTz last_execution_start; /* start timestamp of the last execution */ slock_t mutex; /* protects the counters only */ } pgssEntry; @@ -328,6 +331,7 @@ PG_FUNCTION_INFO_V1(pg_stat_statements_1_10); PG_FUNCTION_INFO_V1(pg_stat_statements_1_11); PG_FUNCTION_INFO_V1(pg_stat_statements_1_12); PG_FUNCTION_INFO_V1(pg_stat_statements_1_13); +PG_FUNCTION_INFO_V1(pg_stat_statements_1_14); PG_FUNCTION_INFO_V1(pg_stat_statements); PG_FUNCTION_INFO_V1(pg_stat_statements_info); @@ -674,6 +678,7 @@ pgss_shmem_startup(void) entry->counters = temp.counters; entry->stats_since = temp.stats_since; entry->minmax_stats_since = temp.minmax_stats_since; + entry->last_execution_start = temp.last_execution_start; } /* Read global statistics for pg_stat_statements */ @@ -1409,8 +1414,16 @@ pgss_store(const char *query, int64 queryId, /* Increment the counts, except when jstate is not NULL */ if (!jstate) { + TimestampTz execution_start; + Assert(kind == PGSS_PLAN || kind == PGSS_EXEC); + /* + * GetCurrentStatementStartTimestamp() reads a variable set at statement + * start — no syscall needed, so we can call it under the spinlock. + */ + execution_start = GetCurrentStatementStartTimestamp(); + /* * Grab the spinlock while updating the counters (see comment about * locking rules at the head of the file) @@ -1515,6 +1528,9 @@ pgss_store(const char *query, int64 queryId, else if (planOrigin == PLAN_STMT_CACHE_CUSTOM) entry->counters.custom_plan_calls++; + /* Record the start time of this execution */ + entry->last_execution_start = execution_start; + SpinLockRelease(&entry->mutex); } @@ -1583,7 +1599,8 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS) #define PG_STAT_STATEMENTS_COLS_V1_11 49 #define PG_STAT_STATEMENTS_COLS_V1_12 52 #define PG_STAT_STATEMENTS_COLS_V1_13 54 -#define PG_STAT_STATEMENTS_COLS 54 /* maximum of above */ +#define PG_STAT_STATEMENTS_COLS_V1_14 55 +#define PG_STAT_STATEMENTS_COLS 55 /* maximum of above */ /* * Retrieve statement statistics. @@ -1595,6 +1612,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_14(PG_FUNCTION_ARGS) +{ + bool showtext = PG_GETARG_BOOL(0); + + pg_stat_statements_internal(fcinfo, PGSS_V1_14, showtext); + + return (Datum) 0; +} + Datum pg_stat_statements_1_13(PG_FUNCTION_ARGS) { @@ -1767,6 +1794,10 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo, if (api_version != PGSS_V1_13) elog(ERROR, "incorrect number of output arguments"); break; + case PG_STAT_STATEMENTS_COLS_V1_14: + if (api_version != PGSS_V1_14) + elog(ERROR, "incorrect number of output arguments"); + break; default: elog(ERROR, "incorrect number of output arguments"); } @@ -1843,6 +1874,7 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo, int64 queryid = entry->key.queryid; TimestampTz stats_since; TimestampTz minmax_stats_since; + TimestampTz last_execution_start; memset(values, 0, sizeof(values)); memset(nulls, 0, sizeof(nulls)); @@ -1911,11 +1943,12 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo, SpinLockRelease(&entry->mutex); /* - * The spinlock is not required when reading these two as they are + * The spinlock is not required when reading these three as they are * always updated when holding pgss->lock exclusively. */ stats_since = entry->stats_since; minmax_stats_since = entry->minmax_stats_since; + last_execution_start = entry->last_execution_start; /* Skip entry if unexecuted (ie, it's a pending "sticky" entry) */ if (IS_STICKY(tmp)) @@ -2030,6 +2063,10 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo, values[i++] = TimestampTzGetDatum(stats_since); values[i++] = TimestampTzGetDatum(minmax_stats_since); } + if (api_version >= PGSS_V1_14) + { + values[i++] = TimestampTzGetDatum(last_execution_start); + } Assert(i == (api_version == PGSS_V1_0 ? PG_STAT_STATEMENTS_COLS_V1_0 : api_version == PGSS_V1_1 ? PG_STAT_STATEMENTS_COLS_V1_1 : @@ -2041,6 +2078,7 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo, api_version == PGSS_V1_11 ? PG_STAT_STATEMENTS_COLS_V1_11 : api_version == PGSS_V1_12 ? PG_STAT_STATEMENTS_COLS_V1_12 : api_version == PGSS_V1_13 ? PG_STAT_STATEMENTS_COLS_V1_13 : + api_version == PGSS_V1_14 ? PG_STAT_STATEMENTS_COLS_V1_14 : -1 /* fail if you forget to update this assert */ )); tuplestore_putvalues(rsinfo->setResult, rsinfo->setDesc, values, nulls); @@ -2148,6 +2186,7 @@ entry_alloc(pgssHashKey *key, Size query_offset, int query_len, int encoding, entry->encoding = encoding; entry->stats_since = GetCurrentTimestamp(); entry->minmax_stats_since = entry->stats_since; + entry->last_execution_start = entry->stats_since; } return entry; diff --git a/contrib/pg_stat_statements/pg_stat_statements.control b/contrib/pg_stat_statements/pg_stat_statements.control index 2eee0ceffa8..61ae41efc14 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 planning and execution statistics of all SQL statements executed' -default_version = '1.13' +default_version = '1.14' module_pathname = '$libdir/pg_stat_statements' relocatable = true diff --git a/contrib/pg_stat_statements/sql/entry_timestamp.sql b/contrib/pg_stat_statements/sql/entry_timestamp.sql index d6d3027ab4f..81f9c6315da 100644 --- a/contrib/pg_stat_statements/sql/entry_timestamp.sql +++ b/contrib/pg_stat_statements/sql/entry_timestamp.sql @@ -110,5 +110,53 @@ SELECT FROM pg_stat_statements WHERE query LIKE '%STMTTS%'; +-- +-- last_execution_start timestamp tests +-- +-- Reset stats first to avoid queryId collisions: simple "SELECT const AS alias" +-- queries all share the same normalized structure as the STMTTS queries above, +-- so EXECSTART entries would otherwise land on the pre-existing STMTTS entry. +SELECT pg_stat_statements_reset() IS NOT NULL AS t; +-- Capture a reference timestamp before running the tracked queries. +SELECT now() AS ref_ts_upd1 \gset +SELECT 1 AS "EXECSTART1"; +-- last_execution_start should be set and >= ref_ts_upd1, because the +-- statement started after we captured the reference timestamp. +SELECT + query, + last_execution_start IS NOT NULL as has_ts, + last_execution_start >= :'ref_ts_upd1' as after_ref1, + stats_since <= last_execution_start as after_stats_since +FROM pg_stat_statements +WHERE query LIKE '%EXECSTART%' +ORDER BY query COLLATE "C"; + +-- Run EXECSTART1 again and verify that last_execution_start is updated. +SELECT now() AS ref_ts_upd2 \gset +SELECT 1 AS "EXECSTART1"; +SELECT + query, + last_execution_start >= :'ref_ts_upd2' as updated +FROM pg_stat_statements +WHERE query LIKE '%EXECSTART1%'; + +-- test filtering (monitoring use case): find statements that started +-- executing since our last observation (ref_ts_upd2). +SELECT count(*) as filtered_count +FROM pg_stat_statements +WHERE last_execution_start >= :'ref_ts_upd2' + AND query LIKE '%EXECSTART%'; + +-- minmax reset should not affect last_execution_start +SELECT pg_stat_statements_reset(0, 0, queryid, true) +FROM pg_stat_statements +WHERE query LIKE '%EXECSTART1%' \gset + +SELECT + query, + last_execution_start >= :'ref_ts_upd2' as ts_preserved +FROM pg_stat_statements +WHERE query LIKE '%EXECSTART1%'; + -- Cleanup SELECT pg_stat_statements_reset() IS NOT NULL AS t; diff --git a/doc/src/sgml/pgstatstatements.sgml b/doc/src/sgml/pgstatstatements.sgml index d753de5836e..feea4730820 100644 --- a/doc/src/sgml/pgstatstatements.sgml +++ b/doc/src/sgml/pgstatstatements.sgml @@ -593,6 +593,15 @@ max_exec_time) + + + + last_execution_start timestamp with time zone + + + Time at which the most recent execution of this statement started + + -- 2.53.0