Hi, On Tue, 10 Oct 2023 at 03:54, Michael Paquier <mich...@paquier.xyz> wrote: > > In ~14, as far as I can see blk_write_time is only incremented for > shared buffers. FWIW, I agree that we should improve these stats for > local buffers but I am not on board with a solution where we'd use the > same counter for local and shared buffers while we've historically > only counted the former, because that could confuse existing > monitoring queries. It seems to me that the right solution is to do > the same separation as temp blocks with two separate counters, without > a backpatch. I'd like to go as far as renaming blk_read_time and > blk_write_time to respectively shared_blk_read_time and > shared_blk_write_time to know exactly what the type of block dealt > with is when querying this data, particularly for pg_stat_statements's > sake.
Yes, that could be a better solution. Also, having more detailed stats for shared and local buffers is helpful. I updated patches in line with that: 0001: Counts extends same way as a write. 0002: Rename blk_{read|write}_time as shared_blk_{read|write}_time. 0003: Add new local_blk_{read|write}_time variables. Regards, Nazir Bilal Yavuz Microsoft
From acf5a2781760f284aef770da0f64acf8685b6445 Mon Sep 17 00:00:00 2001 From: Nazir Bilal Yavuz <byavu...@gmail.com> Date: Fri, 13 Oct 2023 17:35:00 +0300 Subject: [PATCH v3 1/3] Include IOOp IOOP_EXTENDs while calculating block write times Extends are counted as writes in block context, so include IOOP_EXTENDs while calculating block write times. --- src/backend/utils/activity/pgstat_io.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/backend/utils/activity/pgstat_io.c b/src/backend/utils/activity/pgstat_io.c index eb7d35d422..8ec8670199 100644 --- a/src/backend/utils/activity/pgstat_io.c +++ b/src/backend/utils/activity/pgstat_io.c @@ -119,7 +119,7 @@ pgstat_count_io_op_time(IOObject io_object, IOContext io_context, IOOp io_op, INSTR_TIME_SET_CURRENT(io_time); INSTR_TIME_SUBTRACT(io_time, start_time); - if (io_op == IOOP_WRITE) + if (io_op == IOOP_WRITE || io_op == IOOP_EXTEND) { pgstat_count_buffer_write_time(INSTR_TIME_GET_MICROSEC(io_time)); if (io_object == IOOBJECT_RELATION) -- 2.42.0
From 1f0933c7057e20c074f6b9355f6d91a9277a8c09 Mon Sep 17 00:00:00 2001 From: Nazir Bilal Yavuz <byavu...@gmail.com> Date: Thu, 12 Oct 2023 14:40:23 +0300 Subject: [PATCH v3 3/3] Add local_blk_{read|write}_time I/O timing statistics There was no I/O timing statistics for counting local blocks' timings. So, add local_blk_{read|write}_time variables for counting these. These counters are exposed in EXPLAIN and pg_stat_statements. pg_stat_statements is bumped to 1.12. --- contrib/pg_stat_statements/Makefile | 1 + .../expected/oldextversions.out | 60 ++++++++++++++++ contrib/pg_stat_statements/meson.build | 1 + .../pg_stat_statements--1.11--1.12.sql | 71 +++++++++++++++++++ .../pg_stat_statements/pg_stat_statements.c | 33 ++++++++- .../pg_stat_statements.control | 2 +- .../pg_stat_statements/sql/oldextversions.sql | 5 ++ doc/src/sgml/pgstatstatements.sgml | 20 ++++++ src/backend/commands/explain.c | 23 +++++- src/backend/executor/instrument.c | 6 ++ src/backend/utils/activity/pgstat_io.c | 4 ++ src/include/executor/instrument.h | 2 + src/test/regress/expected/explain.out | 4 ++ 13 files changed, 228 insertions(+), 4 deletions(-) create mode 100644 contrib/pg_stat_statements/pg_stat_statements--1.11--1.12.sql diff --git a/contrib/pg_stat_statements/Makefile b/contrib/pg_stat_statements/Makefile index eba4a95d91..b7d12bc7fb 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.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 \ pg_stat_statements--1.7--1.8.sql pg_stat_statements--1.6--1.7.sql \ diff --git a/contrib/pg_stat_statements/expected/oldextversions.out b/contrib/pg_stat_statements/expected/oldextversions.out index 9e18fe2e47..b84e0c8484 100644 --- a/contrib/pg_stat_statements/expected/oldextversions.out +++ b/contrib/pg_stat_statements/expected/oldextversions.out @@ -308,4 +308,64 @@ SELECT count(*) > 0 AS has_data FROM pg_stat_statements; t (1 row) +-- New views for pg_stat_statements in 1.12 +AlTER EXTENSION pg_stat_statements UPDATE TO '1.12'; +\d pg_stat_statements + View "public.pg_stat_statements" + Column | Type | Collation | Nullable | Default +------------------------+------------------+-----------+----------+--------- + userid | oid | | | + dbid | oid | | | + toplevel | boolean | | | + queryid | bigint | | | + query | text | | | + plans | bigint | | | + total_plan_time | double precision | | | + min_plan_time | double precision | | | + max_plan_time | double precision | | | + mean_plan_time | double precision | | | + stddev_plan_time | double precision | | | + calls | bigint | | | + total_exec_time | double precision | | | + min_exec_time | double precision | | | + max_exec_time | double precision | | | + mean_exec_time | double precision | | | + stddev_exec_time | double precision | | | + rows | bigint | | | + shared_blks_hit | bigint | | | + shared_blks_read | bigint | | | + shared_blks_dirtied | bigint | | | + shared_blks_written | bigint | | | + local_blks_hit | bigint | | | + local_blks_read | bigint | | | + local_blks_dirtied | bigint | | | + local_blks_written | bigint | | | + temp_blks_read | bigint | | | + temp_blks_written | bigint | | | + shared_blk_read_time | double precision | | | + shared_blk_write_time | double precision | | | + local_blk_read_time | double precision | | | + local_blk_write_time | double precision | | | + temp_blk_read_time | double precision | | | + temp_blk_write_time | double precision | | | + wal_records | bigint | | | + wal_fpi | bigint | | | + wal_bytes | numeric | | | + jit_functions | bigint | | | + jit_generation_time | double precision | | | + jit_inlining_count | bigint | | | + jit_inlining_time | double precision | | | + jit_optimization_count | bigint | | | + jit_optimization_time | double precision | | | + jit_emission_count | bigint | | | + jit_emission_time | double precision | | | + jit_deform_count | bigint | | | + jit_deform_time | double precision | | | + +SELECT count(*) > 0 AS has_data FROM pg_stat_statements; + has_data +---------- + t +(1 row) + DROP EXTENSION pg_stat_statements; diff --git a/contrib/pg_stat_statements/meson.build b/contrib/pg_stat_statements/meson.build index 15b7c7f2b0..017b926bf8 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.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/pg_stat_statements--1.11--1.12.sql b/contrib/pg_stat_statements/pg_stat_statements--1.11--1.12.sql new file mode 100644 index 0000000000..f5259358e9 --- /dev/null +++ b/contrib/pg_stat_statements/pg_stat_statements--1.11--1.12.sql @@ -0,0 +1,71 @@ +/* contrib/pg_stat_statements/pg_stat_statements--1.11--1.12.sql */ + +-- complain if script is sourced in psql, rather than via ALTER EXTENSION +\echo Use "ALTER EXTENSION pg_stat_statements UPDATE TO '1.12'" 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 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 +) +RETURNS SETOF record +AS 'MODULE_PATHNAME', 'pg_stat_statements_1_12' +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 9fd886596c..323164db5b 100644 --- a/contrib/pg_stat_statements/pg_stat_statements.c +++ b/contrib/pg_stat_statements/pg_stat_statements.c @@ -118,7 +118,8 @@ typedef enum pgssVersion PGSS_V1_8, PGSS_V1_9, PGSS_V1_10, - PGSS_V1_11 + PGSS_V1_11, + PGSS_V1_12 } pgssVersion; typedef enum pgssStoreKind @@ -184,6 +185,10 @@ typedef struct Counters * msec */ double shared_blk_write_time; /* time spent writing shared blocks, in * msec */ + double local_blk_read_time; /* time spent reading local blocks, in + * msec */ + double local_blk_write_time; /* time spent writing local blocks, in + * msec */ double temp_blk_read_time; /* time spent reading temp blocks, in msec */ double temp_blk_write_time; /* time spent writing temp blocks, in * msec */ @@ -320,6 +325,7 @@ PG_FUNCTION_INFO_V1(pg_stat_statements_1_8); PG_FUNCTION_INFO_V1(pg_stat_statements_1_9); 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); PG_FUNCTION_INFO_V1(pg_stat_statements_info); @@ -1395,6 +1401,8 @@ pgss_store(const char *query, uint64 queryId, e->counters.temp_blks_written += bufusage->temp_blks_written; e->counters.shared_blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->shared_blk_read_time); e->counters.shared_blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->shared_blk_write_time); + e->counters.local_blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->local_blk_read_time); + e->counters.local_blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->local_blk_write_time); e->counters.temp_blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->temp_blk_read_time); e->counters.temp_blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->temp_blk_write_time); e->counters.usage += USAGE_EXEC(total_time); @@ -1473,7 +1481,8 @@ pg_stat_statements_reset(PG_FUNCTION_ARGS) #define PG_STAT_STATEMENTS_COLS_V1_9 33 #define PG_STAT_STATEMENTS_COLS_V1_10 43 #define PG_STAT_STATEMENTS_COLS_V1_11 45 -#define PG_STAT_STATEMENTS_COLS 45 /* maximum of above */ +#define PG_STAT_STATEMENTS_COLS_V1_12 47 +#define PG_STAT_STATEMENTS_COLS 47 /* maximum of above */ /* * Retrieve statement statistics. @@ -1485,6 +1494,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_12(PG_FUNCTION_ARGS) +{ + bool showtext = PG_GETARG_BOOL(0); + + pg_stat_statements_internal(fcinfo, PGSS_V1_12, showtext); + + return (Datum) 0; +} + Datum pg_stat_statements_1_11(PG_FUNCTION_ARGS) { @@ -1629,6 +1648,10 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo, if (api_version != PGSS_V1_11) elog(ERROR, "incorrect number of output arguments"); break; + case PG_STAT_STATEMENTS_COLS_V1_12: + if (api_version != PGSS_V1_12) + elog(ERROR, "incorrect number of output arguments"); + break; default: elog(ERROR, "incorrect number of output arguments"); } @@ -1828,6 +1851,11 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo, values[i++] = Float8GetDatumFast(tmp.shared_blk_read_time); values[i++] = Float8GetDatumFast(tmp.shared_blk_write_time); } + if (api_version >= PGSS_V1_12) + { + values[i++] = Float8GetDatumFast(tmp.local_blk_read_time); + values[i++] = Float8GetDatumFast(tmp.local_blk_write_time); + } if (api_version >= PGSS_V1_10) { values[i++] = Float8GetDatumFast(tmp.temp_blk_read_time); @@ -1875,6 +1903,7 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo, api_version == PGSS_V1_9 ? PG_STAT_STATEMENTS_COLS_V1_9 : api_version == PGSS_V1_10 ? PG_STAT_STATEMENTS_COLS_V1_10 : api_version == PGSS_V1_11 ? PG_STAT_STATEMENTS_COLS_V1_11 : + api_version == PGSS_V1_12 ? PG_STAT_STATEMENTS_COLS_V1_12 : -1 /* fail if you forget to update this assert */ )); tuplestore_putvalues(rsinfo->setResult, rsinfo->setDesc, values, nulls); diff --git a/contrib/pg_stat_statements/pg_stat_statements.control b/contrib/pg_stat_statements/pg_stat_statements.control index 8a76106ec6..d45ebc12e3 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.11' +default_version = '1.12' module_pathname = '$libdir/pg_stat_statements' relocatable = true diff --git a/contrib/pg_stat_statements/sql/oldextversions.sql b/contrib/pg_stat_statements/sql/oldextversions.sql index 2435c0c576..d72cd823aa 100644 --- a/contrib/pg_stat_statements/sql/oldextversions.sql +++ b/contrib/pg_stat_statements/sql/oldextversions.sql @@ -53,4 +53,9 @@ AlTER EXTENSION pg_stat_statements UPDATE TO '1.11'; \d pg_stat_statements SELECT count(*) > 0 AS has_data FROM pg_stat_statements; +-- New views for pg_stat_statements in 1.12 +AlTER EXTENSION pg_stat_statements UPDATE TO '1.12'; +\d pg_stat_statements +SELECT count(*) > 0 AS has_data FROM pg_stat_statements; + DROP EXTENSION pg_stat_statements; diff --git a/doc/src/sgml/pgstatstatements.sgml b/doc/src/sgml/pgstatstatements.sgml index ac8e6935b7..4eca7d01f4 100644 --- a/doc/src/sgml/pgstatstatements.sgml +++ b/doc/src/sgml/pgstatstatements.sgml @@ -353,6 +353,26 @@ </para></entry> </row> + <row> + <entry role="catalog_table_entry"><para role="column_definition"> + <structfield>local_blk_read_time</structfield> <type>double precision</type> + </para> + <para> + Total time the statement spent reading local data file blocks, in milliseconds + (if <xref linkend="guc-track-io-timing"/> is enabled, otherwise zero) + </para></entry> + </row> + + <row> + <entry role="catalog_table_entry"><para role="column_definition"> + <structfield>local_blk_write_time</structfield> <type>double precision</type> + </para> + <para> + Total time the statement spent writing local data file blocks, in milliseconds + (if <xref linkend="guc-track-io-timing"/> is enabled, otherwise zero) + </para></entry> + </row> + <row> <entry role="catalog_table_entry"><para role="column_definition"> <structfield>temp_blk_read_time</structfield> <type>double precision</type> diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 45cd22b299..40ad0f6b30 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -3564,11 +3564,14 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning) usage->temp_blks_written > 0); bool has_shared_timing = (!INSTR_TIME_IS_ZERO(usage->shared_blk_read_time) || !INSTR_TIME_IS_ZERO(usage->shared_blk_write_time)); + bool has_local_timing = (!INSTR_TIME_IS_ZERO(usage->local_blk_read_time) || + !INSTR_TIME_IS_ZERO(usage->local_blk_write_time)); bool has_temp_timing = (!INSTR_TIME_IS_ZERO(usage->temp_blk_read_time) || !INSTR_TIME_IS_ZERO(usage->temp_blk_write_time)); bool show_planning = (planning && (has_shared || has_local || has_temp || has_shared_timing || + has_local_timing || has_temp_timing)); if (show_planning) @@ -3634,7 +3637,7 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning) } /* As above, show only positive counter values. */ - if (has_shared_timing || has_temp_timing) + if (has_shared_timing || has_local_timing || has_temp_timing) { ExplainIndentText(es); appendStringInfoString(es->str, "I/O Timings:"); @@ -3651,6 +3654,18 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning) if (has_temp_timing) appendStringInfoChar(es->str, ','); } + if (has_local_timing) + { + appendStringInfoString(es->str, " local"); + if (!INSTR_TIME_IS_ZERO(usage->local_blk_read_time)) + appendStringInfo(es->str, " read=%0.3f", + INSTR_TIME_GET_MILLISEC(usage->local_blk_read_time)); + if (!INSTR_TIME_IS_ZERO(usage->local_blk_write_time)) + appendStringInfo(es->str, " write=%0.3f", + INSTR_TIME_GET_MILLISEC(usage->local_blk_write_time)); + if (has_temp_timing) + appendStringInfoChar(es->str, ','); + } if (has_temp_timing) { appendStringInfoString(es->str, " temp"); @@ -3697,6 +3712,12 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning) ExplainPropertyFloat("Shared I/O Write Time", "ms", INSTR_TIME_GET_MILLISEC(usage->shared_blk_write_time), 3, es); + ExplainPropertyFloat("Local I/O Read Time", "ms", + INSTR_TIME_GET_MILLISEC(usage->local_blk_read_time), + 3, es); + ExplainPropertyFloat("Local I/O Write Time", "ms", + INSTR_TIME_GET_MILLISEC(usage->local_blk_write_time), + 3, es); ExplainPropertyFloat("Temp I/O Read Time", "ms", INSTR_TIME_GET_MILLISEC(usage->temp_blk_read_time), 3, es); diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c index ef2a24b7cf..c383f34c06 100644 --- a/src/backend/executor/instrument.c +++ b/src/backend/executor/instrument.c @@ -237,6 +237,8 @@ BufferUsageAdd(BufferUsage *dst, const BufferUsage *add) dst->temp_blks_written += add->temp_blks_written; INSTR_TIME_ADD(dst->shared_blk_read_time, add->shared_blk_read_time); INSTR_TIME_ADD(dst->shared_blk_write_time, add->shared_blk_write_time); + INSTR_TIME_ADD(dst->local_blk_read_time, add->local_blk_read_time); + INSTR_TIME_ADD(dst->local_blk_write_time, add->local_blk_write_time); INSTR_TIME_ADD(dst->temp_blk_read_time, add->temp_blk_read_time); INSTR_TIME_ADD(dst->temp_blk_write_time, add->temp_blk_write_time); } @@ -261,6 +263,10 @@ BufferUsageAccumDiff(BufferUsage *dst, add->shared_blk_read_time, sub->shared_blk_read_time); INSTR_TIME_ACCUM_DIFF(dst->shared_blk_write_time, add->shared_blk_write_time, sub->shared_blk_write_time); + INSTR_TIME_ACCUM_DIFF(dst->local_blk_read_time, + add->local_blk_read_time, sub->local_blk_read_time); + INSTR_TIME_ACCUM_DIFF(dst->local_blk_write_time, + add->local_blk_write_time, sub->local_blk_write_time); INSTR_TIME_ACCUM_DIFF(dst->temp_blk_read_time, add->temp_blk_read_time, sub->temp_blk_read_time); INSTR_TIME_ACCUM_DIFF(dst->temp_blk_write_time, diff --git a/src/backend/utils/activity/pgstat_io.c b/src/backend/utils/activity/pgstat_io.c index 297cfc15fb..490d5a9ab7 100644 --- a/src/backend/utils/activity/pgstat_io.c +++ b/src/backend/utils/activity/pgstat_io.c @@ -124,12 +124,16 @@ pgstat_count_io_op_time(IOObject io_object, IOContext io_context, IOOp io_op, pgstat_count_buffer_write_time(INSTR_TIME_GET_MICROSEC(io_time)); if (io_object == IOOBJECT_RELATION) INSTR_TIME_ADD(pgBufferUsage.shared_blk_write_time, io_time); + else if (io_object == IOOBJECT_TEMP_RELATION) + INSTR_TIME_ADD(pgBufferUsage.local_blk_write_time, io_time); } else if (io_op == IOOP_READ) { pgstat_count_buffer_read_time(INSTR_TIME_GET_MICROSEC(io_time)); if (io_object == IOOBJECT_RELATION) INSTR_TIME_ADD(pgBufferUsage.shared_blk_read_time, io_time); + else if (io_object == IOOBJECT_TEMP_RELATION) + INSTR_TIME_ADD(pgBufferUsage.local_blk_read_time, io_time); } INSTR_TIME_ADD(PendingIOStats.pending_times[io_object][io_context][io_op], diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h index 8c3e5184fd..9233c25739 100644 --- a/src/include/executor/instrument.h +++ b/src/include/executor/instrument.h @@ -35,6 +35,8 @@ typedef struct BufferUsage int64 temp_blks_written; /* # of temp blocks written */ instr_time shared_blk_read_time; /* time spent reading shared blocks */ instr_time shared_blk_write_time; /* time spent writing shared blocks */ + instr_time local_blk_read_time; /* time spent reading local blocks */ + instr_time local_blk_write_time; /* time spent writing local blocks */ instr_time temp_blk_read_time; /* time spent reading temp blocks */ instr_time temp_blk_write_time; /* time spent writing temp blocks */ } BufferUsage; diff --git a/src/test/regress/expected/explain.out b/src/test/regress/expected/explain.out index a101886299..809655e16e 100644 --- a/src/test/regress/expected/explain.out +++ b/src/test/regress/expected/explain.out @@ -260,6 +260,8 @@ select explain_filter('explain (analyze, buffers, format json) select * from int "Temp Written Blocks": N, + "Shared I/O Read Time": N.N, + "Shared I/O Write Time": N.N,+ + "Local I/O Read Time": N.N, + + "Local I/O Write Time": N.N, + "Temp I/O Read Time": N.N, + "Temp I/O Write Time": N.N + }, + @@ -276,6 +278,8 @@ select explain_filter('explain (analyze, buffers, format json) select * from int "Temp Written Blocks": N, + "Shared I/O Read Time": N.N, + "Shared I/O Write Time": N.N,+ + "Local I/O Read Time": N.N, + + "Local I/O Write Time": N.N, + "Temp I/O Read Time": N.N, + "Temp I/O Write Time": N.N + }, + -- 2.42.0
From 4b14f54c94f8c3692fd55f712dbe0d67c7587812 Mon Sep 17 00:00:00 2001 From: Nazir Bilal Yavuz <byavu...@gmail.com> Date: Fri, 13 Oct 2023 16:28:03 +0300 Subject: [PATCH v3 2/3] Rename I/O timing statistics columns to shared_blk_{read|write}_time Since only shared blocks' timings are counted in blk_{read|write}_time, rename them as shared_blk_{read|write}_time --- .../expected/oldextversions.out | 202 +++++++++--------- .../pg_stat_statements--1.0--1.1.sql | 4 +- .../pg_stat_statements--1.1--1.2.sql | 4 +- .../pg_stat_statements--1.10--1.11.sql | 4 +- .../pg_stat_statements--1.2--1.3.sql | 4 +- .../pg_stat_statements--1.4.sql | 4 +- .../pg_stat_statements--1.7--1.8.sql | 4 +- .../pg_stat_statements--1.8--1.9.sql | 4 +- .../pg_stat_statements--1.9--1.10.sql | 4 +- .../pg_stat_statements/pg_stat_statements.c | 14 +- doc/src/sgml/pgstatstatements.sgml | 8 +- src/backend/commands/explain.c | 29 +-- src/backend/executor/instrument.c | 12 +- src/backend/utils/activity/pgstat_io.c | 4 +- src/include/executor/instrument.h | 4 +- src/test/regress/expected/explain.out | 108 +++++----- 16 files changed, 208 insertions(+), 205 deletions(-) diff --git a/contrib/pg_stat_statements/expected/oldextversions.out b/contrib/pg_stat_statements/expected/oldextversions.out index 64982aad60..9e18fe2e47 100644 --- a/contrib/pg_stat_statements/expected/oldextversions.out +++ b/contrib/pg_stat_statements/expected/oldextversions.out @@ -53,32 +53,32 @@ SELECT pg_get_functiondef('pg_stat_statements_reset'::regproc); (1 row) \d pg_stat_statements - View "public.pg_stat_statements" - Column | Type | Collation | Nullable | Default ----------------------+------------------+-----------+----------+--------- - userid | oid | | | - dbid | oid | | | - queryid | bigint | | | - query | text | | | - calls | bigint | | | - total_time | double precision | | | - min_time | double precision | | | - max_time | double precision | | | - mean_time | double precision | | | - stddev_time | double precision | | | - rows | bigint | | | - shared_blks_hit | bigint | | | - shared_blks_read | bigint | | | - shared_blks_dirtied | bigint | | | - shared_blks_written | bigint | | | - local_blks_hit | bigint | | | - local_blks_read | bigint | | | - local_blks_dirtied | bigint | | | - local_blks_written | bigint | | | - temp_blks_read | bigint | | | - temp_blks_written | bigint | | | - blk_read_time | double precision | | | - blk_write_time | double precision | | | + View "public.pg_stat_statements" + Column | Type | Collation | Nullable | Default +-----------------------+------------------+-----------+----------+--------- + userid | oid | | | + dbid | oid | | | + queryid | bigint | | | + query | text | | | + calls | bigint | | | + total_time | double precision | | | + min_time | double precision | | | + max_time | double precision | | | + mean_time | double precision | | | + stddev_time | double precision | | | + rows | bigint | | | + shared_blks_hit | bigint | | | + shared_blks_read | bigint | | | + shared_blks_dirtied | bigint | | | + shared_blks_written | bigint | | | + local_blks_hit | bigint | | | + local_blks_read | bigint | | | + local_blks_dirtied | bigint | | | + local_blks_written | bigint | | | + temp_blks_read | bigint | | | + temp_blks_written | bigint | | | + shared_blk_read_time | double precision | | | + shared_blk_write_time | double precision | | | SELECT count(*) > 0 AS has_data FROM pg_stat_statements; has_data @@ -89,41 +89,41 @@ SELECT count(*) > 0 AS has_data FROM pg_stat_statements; -- New functions and views for pg_stat_statements in 1.8 AlTER EXTENSION pg_stat_statements UPDATE TO '1.8'; \d pg_stat_statements - View "public.pg_stat_statements" - Column | Type | Collation | Nullable | Default ----------------------+------------------+-----------+----------+--------- - userid | oid | | | - dbid | oid | | | - queryid | bigint | | | - query | text | | | - plans | bigint | | | - total_plan_time | double precision | | | - min_plan_time | double precision | | | - max_plan_time | double precision | | | - mean_plan_time | double precision | | | - stddev_plan_time | double precision | | | - calls | bigint | | | - total_exec_time | double precision | | | - min_exec_time | double precision | | | - max_exec_time | double precision | | | - mean_exec_time | double precision | | | - stddev_exec_time | double precision | | | - rows | bigint | | | - shared_blks_hit | bigint | | | - shared_blks_read | bigint | | | - shared_blks_dirtied | bigint | | | - shared_blks_written | bigint | | | - local_blks_hit | bigint | | | - local_blks_read | bigint | | | - local_blks_dirtied | bigint | | | - local_blks_written | bigint | | | - temp_blks_read | bigint | | | - temp_blks_written | bigint | | | - blk_read_time | double precision | | | - blk_write_time | double precision | | | - wal_records | bigint | | | - wal_fpi | bigint | | | - wal_bytes | numeric | | | + View "public.pg_stat_statements" + Column | Type | Collation | Nullable | Default +-----------------------+------------------+-----------+----------+--------- + userid | oid | | | + dbid | oid | | | + queryid | bigint | | | + query | text | | | + plans | bigint | | | + total_plan_time | double precision | | | + min_plan_time | double precision | | | + max_plan_time | double precision | | | + mean_plan_time | double precision | | | + stddev_plan_time | double precision | | | + calls | bigint | | | + total_exec_time | double precision | | | + min_exec_time | double precision | | | + max_exec_time | double precision | | | + mean_exec_time | double precision | | | + stddev_exec_time | double precision | | | + rows | bigint | | | + shared_blks_hit | bigint | | | + shared_blks_read | bigint | | | + shared_blks_dirtied | bigint | | | + shared_blks_written | bigint | | | + local_blks_hit | bigint | | | + local_blks_read | bigint | | | + local_blks_dirtied | bigint | | | + local_blks_written | bigint | | | + temp_blks_read | bigint | | | + temp_blks_written | bigint | | | + shared_blk_read_time | double precision | | | + shared_blk_write_time | double precision | | | + wal_records | bigint | | | + wal_fpi | bigint | | | + wal_bytes | numeric | | | SELECT pg_get_functiondef('pg_stat_statements_reset'::regproc); pg_get_functiondef @@ -151,42 +151,42 @@ SELECT pg_get_functiondef('pg_stat_statements_info'::regproc); (1 row) \d pg_stat_statements - View "public.pg_stat_statements" - Column | Type | Collation | Nullable | Default ----------------------+------------------+-----------+----------+--------- - userid | oid | | | - dbid | oid | | | - toplevel | boolean | | | - queryid | bigint | | | - query | text | | | - plans | bigint | | | - total_plan_time | double precision | | | - min_plan_time | double precision | | | - max_plan_time | double precision | | | - mean_plan_time | double precision | | | - stddev_plan_time | double precision | | | - calls | bigint | | | - total_exec_time | double precision | | | - min_exec_time | double precision | | | - max_exec_time | double precision | | | - mean_exec_time | double precision | | | - stddev_exec_time | double precision | | | - rows | bigint | | | - shared_blks_hit | bigint | | | - shared_blks_read | bigint | | | - shared_blks_dirtied | bigint | | | - shared_blks_written | bigint | | | - local_blks_hit | bigint | | | - local_blks_read | bigint | | | - local_blks_dirtied | bigint | | | - local_blks_written | bigint | | | - temp_blks_read | bigint | | | - temp_blks_written | bigint | | | - blk_read_time | double precision | | | - blk_write_time | double precision | | | - wal_records | bigint | | | - wal_fpi | bigint | | | - wal_bytes | numeric | | | + View "public.pg_stat_statements" + Column | Type | Collation | Nullable | Default +-----------------------+------------------+-----------+----------+--------- + userid | oid | | | + dbid | oid | | | + toplevel | boolean | | | + queryid | bigint | | | + query | text | | | + plans | bigint | | | + total_plan_time | double precision | | | + min_plan_time | double precision | | | + max_plan_time | double precision | | | + mean_plan_time | double precision | | | + stddev_plan_time | double precision | | | + calls | bigint | | | + total_exec_time | double precision | | | + min_exec_time | double precision | | | + max_exec_time | double precision | | | + mean_exec_time | double precision | | | + stddev_exec_time | double precision | | | + rows | bigint | | | + shared_blks_hit | bigint | | | + shared_blks_read | bigint | | | + shared_blks_dirtied | bigint | | | + shared_blks_written | bigint | | | + local_blks_hit | bigint | | | + local_blks_read | bigint | | | + local_blks_dirtied | bigint | | | + local_blks_written | bigint | | | + temp_blks_read | bigint | | | + temp_blks_written | bigint | | | + shared_blk_read_time | double precision | | | + shared_blk_write_time | double precision | | | + wal_records | bigint | | | + wal_fpi | bigint | | | + wal_bytes | numeric | | | SELECT count(*) > 0 AS has_data FROM pg_stat_statements; has_data @@ -228,8 +228,8 @@ AlTER EXTENSION pg_stat_statements UPDATE TO '1.10'; local_blks_written | bigint | | | temp_blks_read | bigint | | | temp_blks_written | bigint | | | - blk_read_time | double precision | | | - blk_write_time | double precision | | | + shared_blk_read_time | double precision | | | + shared_blk_write_time | double precision | | | temp_blk_read_time | double precision | | | temp_blk_write_time | double precision | | | wal_records | bigint | | | @@ -284,8 +284,8 @@ AlTER EXTENSION pg_stat_statements UPDATE TO '1.11'; local_blks_written | bigint | | | temp_blks_read | bigint | | | temp_blks_written | bigint | | | - blk_read_time | double precision | | | - blk_write_time | double precision | | | + shared_blk_read_time | double precision | | | + shared_blk_write_time | double precision | | | temp_blk_read_time | double precision | | | temp_blk_write_time | double precision | | | wal_records | bigint | | | diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.0--1.1.sql b/contrib/pg_stat_statements/pg_stat_statements--1.0--1.1.sql index 5be281ea47..749f0ecbc0 100644 --- a/contrib/pg_stat_statements/pg_stat_statements--1.0--1.1.sql +++ b/contrib/pg_stat_statements/pg_stat_statements--1.0--1.1.sql @@ -29,8 +29,8 @@ CREATE FUNCTION pg_stat_statements( 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 + OUT shared_blk_read_time float8, + OUT shared_blk_write_time float8 ) RETURNS SETOF record AS 'MODULE_PATHNAME' diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.1--1.2.sql b/contrib/pg_stat_statements/pg_stat_statements--1.1--1.2.sql index 74ae43868d..9a20aca158 100644 --- a/contrib/pg_stat_statements/pg_stat_statements--1.1--1.2.sql +++ b/contrib/pg_stat_statements/pg_stat_statements--1.1--1.2.sql @@ -30,8 +30,8 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean, 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 + OUT shared_blk_read_time float8, + OUT shared_blk_write_time float8 ) RETURNS SETOF record AS 'MODULE_PATHNAME', 'pg_stat_statements_1_2' diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.10--1.11.sql b/contrib/pg_stat_statements/pg_stat_statements--1.10--1.11.sql index 20bae80458..448ef3682f 100644 --- a/contrib/pg_stat_statements/pg_stat_statements--1.10--1.11.sql +++ b/contrib/pg_stat_statements/pg_stat_statements--1.10--1.11.sql @@ -41,8 +41,8 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean, 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, + OUT shared_blk_read_time float8, + OUT shared_blk_write_time float8, OUT temp_blk_read_time float8, OUT temp_blk_write_time float8, OUT wal_records int8, diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.2--1.3.sql b/contrib/pg_stat_statements/pg_stat_statements--1.2--1.3.sql index a56f151b99..4737671938 100644 --- a/contrib/pg_stat_statements/pg_stat_statements--1.2--1.3.sql +++ b/contrib/pg_stat_statements/pg_stat_statements--1.2--1.3.sql @@ -34,8 +34,8 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean, 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 + OUT shared_blk_read_time float8, + OUT shared_blk_write_time float8 ) RETURNS SETOF record AS 'MODULE_PATHNAME', 'pg_stat_statements_1_3' diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.4.sql b/contrib/pg_stat_statements/pg_stat_statements--1.4.sql index 58cdf600fc..d124669126 100644 --- a/contrib/pg_stat_statements/pg_stat_statements--1.4.sql +++ b/contrib/pg_stat_statements/pg_stat_statements--1.4.sql @@ -31,8 +31,8 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean, 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 + OUT shared_blk_read_time float8, + OUT shared_blk_write_time float8 ) RETURNS SETOF record AS 'MODULE_PATHNAME', 'pg_stat_statements_1_3' 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 index 0f63f08f7e..dbb1844f79 100644 --- 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 @@ -40,8 +40,8 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean, 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, + OUT shared_blk_read_time float8, + OUT shared_blk_write_time float8, OUT wal_records int8, OUT wal_fpi int8, OUT wal_bytes numeric diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.8--1.9.sql b/contrib/pg_stat_statements/pg_stat_statements--1.8--1.9.sql index c45223f888..5f7404d0b9 100644 --- a/contrib/pg_stat_statements/pg_stat_statements--1.8--1.9.sql +++ b/contrib/pg_stat_statements/pg_stat_statements--1.8--1.9.sql @@ -55,8 +55,8 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean, 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, + OUT shared_blk_read_time float8, + OUT shared_blk_write_time float8, OUT wal_records int8, OUT wal_fpi int8, OUT wal_bytes numeric diff --git a/contrib/pg_stat_statements/pg_stat_statements--1.9--1.10.sql b/contrib/pg_stat_statements/pg_stat_statements--1.9--1.10.sql index 811813c491..f5985145c3 100644 --- a/contrib/pg_stat_statements/pg_stat_statements--1.9--1.10.sql +++ b/contrib/pg_stat_statements/pg_stat_statements--1.9--1.10.sql @@ -41,8 +41,8 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean, 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, + OUT shared_blk_read_time float8, + OUT shared_blk_write_time float8, OUT temp_blk_read_time float8, OUT temp_blk_write_time float8, OUT wal_records int8, diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c index a46f2db352..9fd886596c 100644 --- a/contrib/pg_stat_statements/pg_stat_statements.c +++ b/contrib/pg_stat_statements/pg_stat_statements.c @@ -180,8 +180,10 @@ typedef struct Counters int64 local_blks_written; /* # of local disk blocks written */ int64 temp_blks_read; /* # of temp blocks read */ int64 temp_blks_written; /* # of temp blocks written */ - double blk_read_time; /* time spent reading blocks, in msec */ - double blk_write_time; /* time spent writing blocks, in msec */ + double shared_blk_read_time; /* time spent reading shared blocks, in + * msec */ + double shared_blk_write_time; /* time spent writing shared blocks, in + * msec */ double temp_blk_read_time; /* time spent reading temp blocks, in msec */ double temp_blk_write_time; /* time spent writing temp blocks, in * msec */ @@ -1391,8 +1393,8 @@ pgss_store(const char *query, uint64 queryId, 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.shared_blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->shared_blk_read_time); + e->counters.shared_blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->shared_blk_write_time); e->counters.temp_blk_read_time += INSTR_TIME_GET_MILLISEC(bufusage->temp_blk_read_time); e->counters.temp_blk_write_time += INSTR_TIME_GET_MILLISEC(bufusage->temp_blk_write_time); e->counters.usage += USAGE_EXEC(total_time); @@ -1823,8 +1825,8 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo, values[i++] = Int64GetDatumFast(tmp.temp_blks_written); if (api_version >= PGSS_V1_1) { - values[i++] = Float8GetDatumFast(tmp.blk_read_time); - values[i++] = Float8GetDatumFast(tmp.blk_write_time); + values[i++] = Float8GetDatumFast(tmp.shared_blk_read_time); + values[i++] = Float8GetDatumFast(tmp.shared_blk_write_time); } if (api_version >= PGSS_V1_10) { diff --git a/doc/src/sgml/pgstatstatements.sgml b/doc/src/sgml/pgstatstatements.sgml index 7e7c5c9ff8..ac8e6935b7 100644 --- a/doc/src/sgml/pgstatstatements.sgml +++ b/doc/src/sgml/pgstatstatements.sgml @@ -335,20 +335,20 @@ <row> <entry role="catalog_table_entry"><para role="column_definition"> - <structfield>blk_read_time</structfield> <type>double precision</type> + <structfield>shared_blk_read_time</structfield> <type>double precision</type> </para> <para> - Total time the statement spent reading data file blocks, in milliseconds + Total time the statement spent reading shared data file blocks, in milliseconds (if <xref linkend="guc-track-io-timing"/> is enabled, otherwise zero) </para></entry> </row> <row> <entry role="catalog_table_entry"><para role="column_definition"> - <structfield>blk_write_time</structfield> <type>double precision</type> + <structfield>shared_blk_write_time</structfield> <type>double precision</type> </para> <para> - Total time the statement spent writing data file blocks, in milliseconds + Total time the statement spent writing shared data file blocks, in milliseconds (if <xref linkend="guc-track-io-timing"/> is enabled, otherwise zero) </para></entry> </row> diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c index 13217807ee..45cd22b299 100644 --- a/src/backend/commands/explain.c +++ b/src/backend/commands/explain.c @@ -3562,12 +3562,13 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning) usage->local_blks_written > 0); bool has_temp = (usage->temp_blks_read > 0 || usage->temp_blks_written > 0); - bool has_timing = (!INSTR_TIME_IS_ZERO(usage->blk_read_time) || - !INSTR_TIME_IS_ZERO(usage->blk_write_time)); + bool has_shared_timing = (!INSTR_TIME_IS_ZERO(usage->shared_blk_read_time) || + !INSTR_TIME_IS_ZERO(usage->shared_blk_write_time)); bool has_temp_timing = (!INSTR_TIME_IS_ZERO(usage->temp_blk_read_time) || !INSTR_TIME_IS_ZERO(usage->temp_blk_write_time)); bool show_planning = (planning && (has_shared || - has_local || has_temp || has_timing || + has_local || has_temp || + has_shared_timing || has_temp_timing)); if (show_planning) @@ -3633,20 +3634,20 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning) } /* As above, show only positive counter values. */ - if (has_timing || has_temp_timing) + if (has_shared_timing || has_temp_timing) { ExplainIndentText(es); appendStringInfoString(es->str, "I/O Timings:"); - if (has_timing) + if (has_shared_timing) { - appendStringInfoString(es->str, " shared/local"); - if (!INSTR_TIME_IS_ZERO(usage->blk_read_time)) + appendStringInfoString(es->str, " shared"); + if (!INSTR_TIME_IS_ZERO(usage->shared_blk_read_time)) appendStringInfo(es->str, " read=%0.3f", - INSTR_TIME_GET_MILLISEC(usage->blk_read_time)); - if (!INSTR_TIME_IS_ZERO(usage->blk_write_time)) + INSTR_TIME_GET_MILLISEC(usage->shared_blk_read_time)); + if (!INSTR_TIME_IS_ZERO(usage->shared_blk_write_time)) appendStringInfo(es->str, " write=%0.3f", - INSTR_TIME_GET_MILLISEC(usage->blk_write_time)); + INSTR_TIME_GET_MILLISEC(usage->shared_blk_write_time)); if (has_temp_timing) appendStringInfoChar(es->str, ','); } @@ -3690,11 +3691,11 @@ show_buffer_usage(ExplainState *es, const BufferUsage *usage, bool planning) usage->temp_blks_written, es); if (track_io_timing) { - ExplainPropertyFloat("I/O Read Time", "ms", - INSTR_TIME_GET_MILLISEC(usage->blk_read_time), + ExplainPropertyFloat("Shared I/O Read Time", "ms", + INSTR_TIME_GET_MILLISEC(usage->shared_blk_read_time), 3, es); - ExplainPropertyFloat("I/O Write Time", "ms", - INSTR_TIME_GET_MILLISEC(usage->blk_write_time), + ExplainPropertyFloat("Shared I/O Write Time", "ms", + INSTR_TIME_GET_MILLISEC(usage->shared_blk_write_time), 3, es); ExplainPropertyFloat("Temp I/O Read Time", "ms", INSTR_TIME_GET_MILLISEC(usage->temp_blk_read_time), diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c index ee78a5749d..ef2a24b7cf 100644 --- a/src/backend/executor/instrument.c +++ b/src/backend/executor/instrument.c @@ -235,8 +235,8 @@ BufferUsageAdd(BufferUsage *dst, const BufferUsage *add) dst->local_blks_written += add->local_blks_written; dst->temp_blks_read += add->temp_blks_read; dst->temp_blks_written += add->temp_blks_written; - INSTR_TIME_ADD(dst->blk_read_time, add->blk_read_time); - INSTR_TIME_ADD(dst->blk_write_time, add->blk_write_time); + INSTR_TIME_ADD(dst->shared_blk_read_time, add->shared_blk_read_time); + INSTR_TIME_ADD(dst->shared_blk_write_time, add->shared_blk_write_time); INSTR_TIME_ADD(dst->temp_blk_read_time, add->temp_blk_read_time); INSTR_TIME_ADD(dst->temp_blk_write_time, add->temp_blk_write_time); } @@ -257,10 +257,10 @@ BufferUsageAccumDiff(BufferUsage *dst, dst->local_blks_written += add->local_blks_written - sub->local_blks_written; dst->temp_blks_read += add->temp_blks_read - sub->temp_blks_read; dst->temp_blks_written += add->temp_blks_written - sub->temp_blks_written; - INSTR_TIME_ACCUM_DIFF(dst->blk_read_time, - add->blk_read_time, sub->blk_read_time); - INSTR_TIME_ACCUM_DIFF(dst->blk_write_time, - add->blk_write_time, sub->blk_write_time); + INSTR_TIME_ACCUM_DIFF(dst->shared_blk_read_time, + add->shared_blk_read_time, sub->shared_blk_read_time); + INSTR_TIME_ACCUM_DIFF(dst->shared_blk_write_time, + add->shared_blk_write_time, sub->shared_blk_write_time); INSTR_TIME_ACCUM_DIFF(dst->temp_blk_read_time, add->temp_blk_read_time, sub->temp_blk_read_time); INSTR_TIME_ACCUM_DIFF(dst->temp_blk_write_time, diff --git a/src/backend/utils/activity/pgstat_io.c b/src/backend/utils/activity/pgstat_io.c index 8ec8670199..297cfc15fb 100644 --- a/src/backend/utils/activity/pgstat_io.c +++ b/src/backend/utils/activity/pgstat_io.c @@ -123,13 +123,13 @@ pgstat_count_io_op_time(IOObject io_object, IOContext io_context, IOOp io_op, { pgstat_count_buffer_write_time(INSTR_TIME_GET_MICROSEC(io_time)); if (io_object == IOOBJECT_RELATION) - INSTR_TIME_ADD(pgBufferUsage.blk_write_time, io_time); + INSTR_TIME_ADD(pgBufferUsage.shared_blk_write_time, io_time); } else if (io_op == IOOP_READ) { pgstat_count_buffer_read_time(INSTR_TIME_GET_MICROSEC(io_time)); if (io_object == IOOBJECT_RELATION) - INSTR_TIME_ADD(pgBufferUsage.blk_read_time, io_time); + INSTR_TIME_ADD(pgBufferUsage.shared_blk_read_time, io_time); } INSTR_TIME_ADD(PendingIOStats.pending_times[io_object][io_context][io_op], diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h index 87e5e2183b..8c3e5184fd 100644 --- a/src/include/executor/instrument.h +++ b/src/include/executor/instrument.h @@ -33,8 +33,8 @@ typedef struct BufferUsage int64 local_blks_written; /* # of local disk blocks written */ int64 temp_blks_read; /* # of temp blocks read */ int64 temp_blks_written; /* # of temp blocks written */ - instr_time blk_read_time; /* time spent reading blocks */ - instr_time blk_write_time; /* time spent writing blocks */ + instr_time shared_blk_read_time; /* time spent reading shared blocks */ + instr_time shared_blk_write_time; /* time spent writing shared blocks */ instr_time temp_blk_read_time; /* time spent reading temp blocks */ instr_time temp_blk_write_time; /* time spent writing temp blocks */ } BufferUsage; diff --git a/src/test/regress/expected/explain.out b/src/test/regress/expected/explain.out index 1aca77491b..a101886299 100644 --- a/src/test/regress/expected/explain.out +++ b/src/test/regress/expected/explain.out @@ -230,60 +230,60 @@ select explain_filter('explain (buffers, format json) select * from int8_tbl i8' -- but always set in JSON format, so check them only in this case. set track_io_timing = on; select explain_filter('explain (analyze, buffers, format json) select * from int8_tbl i8'); - explain_filter ------------------------------------- - [ + - { + - "Plan": { + - "Node Type": "Seq Scan", + - "Parallel Aware": false, + - "Async Capable": false, + - "Relation Name": "int8_tbl",+ - "Alias": "i8", + - "Startup Cost": N.N, + - "Total Cost": N.N, + - "Plan Rows": N, + - "Plan Width": N, + - "Actual Startup Time": N.N, + - "Actual Total Time": N.N, + - "Actual Rows": N, + - "Actual Loops": N, + - "Shared Hit Blocks": N, + - "Shared Read Blocks": N, + - "Shared Dirtied Blocks": N, + - "Shared Written Blocks": N, + - "Local Hit Blocks": N, + - "Local Read Blocks": N, + - "Local Dirtied Blocks": N, + - "Local Written Blocks": N, + - "Temp Read Blocks": N, + - "Temp Written Blocks": N, + - "I/O Read Time": N.N, + - "I/O Write Time": N.N, + - "Temp I/O Read Time": N.N, + - "Temp I/O Write Time": N.N + - }, + - "Planning": { + - "Shared Hit Blocks": N, + - "Shared Read Blocks": N, + - "Shared Dirtied Blocks": N, + - "Shared Written Blocks": N, + - "Local Hit Blocks": N, + - "Local Read Blocks": N, + - "Local Dirtied Blocks": N, + - "Local Written Blocks": N, + - "Temp Read Blocks": N, + - "Temp Written Blocks": N, + - "I/O Read Time": N.N, + - "I/O Write Time": N.N, + - "Temp I/O Read Time": N.N, + - "Temp I/O Write Time": N.N + - }, + - "Planning Time": N.N, + - "Triggers": [ + - ], + - "Execution Time": N.N + - } + + explain_filter +------------------------------------- + [ + + { + + "Plan": { + + "Node Type": "Seq Scan", + + "Parallel Aware": false, + + "Async Capable": false, + + "Relation Name": "int8_tbl", + + "Alias": "i8", + + "Startup Cost": N.N, + + "Total Cost": N.N, + + "Plan Rows": N, + + "Plan Width": N, + + "Actual Startup Time": N.N, + + "Actual Total Time": N.N, + + "Actual Rows": N, + + "Actual Loops": N, + + "Shared Hit Blocks": N, + + "Shared Read Blocks": N, + + "Shared Dirtied Blocks": N, + + "Shared Written Blocks": N, + + "Local Hit Blocks": N, + + "Local Read Blocks": N, + + "Local Dirtied Blocks": N, + + "Local Written Blocks": N, + + "Temp Read Blocks": N, + + "Temp Written Blocks": N, + + "Shared I/O Read Time": N.N, + + "Shared I/O Write Time": N.N,+ + "Temp I/O Read Time": N.N, + + "Temp I/O Write Time": N.N + + }, + + "Planning": { + + "Shared Hit Blocks": N, + + "Shared Read Blocks": N, + + "Shared Dirtied Blocks": N, + + "Shared Written Blocks": N, + + "Local Hit Blocks": N, + + "Local Read Blocks": N, + + "Local Dirtied Blocks": N, + + "Local Written Blocks": N, + + "Temp Read Blocks": N, + + "Temp Written Blocks": N, + + "Shared I/O Read Time": N.N, + + "Shared I/O Write Time": N.N,+ + "Temp I/O Read Time": N.N, + + "Temp I/O Write Time": N.N + + }, + + "Planning Time": N.N, + + "Triggers": [ + + ], + + "Execution Time": N.N + + } + ] (1 row) -- 2.42.0