mirrors/postgres
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

Rename I/O timing statistics columns to shared_blk_{read|write}_time

Browse Source 
These two counters, defined in BufferUsage to track respectively the
time spent while reading and writing blocks have historically only
tracked data related to shared buffers, when track_io_timing is enabled.

An upcoming patch to add specific counters for local buffers will take
advantage of this rename as it has come up that no data is currently
tracked for local buffers, and tracking local and shared buffers using
the same fields would be inconsistent with the treatment done for temp
buffers.  Renaming the existing fields clarifies what the block type of
each stats field is.

pg_stat_statement is updated to reflect the rename.  No extension
version bump is required as 5a3423ad8ee17 has done one, affecting v17~.

Author: Nazir Bilal Yavuz
Reviewed-by: Robert Haas, Melanie Plageman
Discussion: https://postgr.es/m/CAN55FZ19Ss279mZuqGbuUNxka0iPbLgYuOQXqAKewrjNrp27VA@mail.gmail.com
This commit is contained in:
Michael Paquier 2023-10-19 11:26:40 +09:00
parent 9b103f861e
commit 13d00729d4
9 changed files with 95 additions and 92 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

4
contrib/pg_stat_statements/expected/oldextversions.out
View File

@ -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 | | |

4
contrib/pg_stat_statements/pg_stat_statements--1.10--1.11.sql
View File

@ -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,

14
contrib/pg_stat_statements/pg_stat_statements.c
View File

@ -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)
{

8
doc/src/sgml/pgstatstatements.sgml
View File

@ -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 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 blocks, in milliseconds
(if <xref linkend="guc-track-io-timing"/> is enabled, otherwise zero)
</para></entry>
</row>

29
src/backend/commands/explain.c
View File

@ -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),

12
src/backend/executor/instrument.c
View File

@ -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,

4
src/backend/utils/activity/pgstat_io.c
View File

@ -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],

4
src/include/executor/instrument.h
View File

@ -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;

108
src/test/regress/expected/explain.out
View File

@ -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)