Attached v9 addresses review feedback as well as resolving merge
conflicts with recent relation extension patchset.
I've changed pgstat_count_io_op_time() to take a count and call
pgstat_count_io_op_n() so it can be used with smgrzeroextend(). I do
wish that the parameter to pgstat_count_io_op_n() was called "count" and
not "cnt"...
I've also reordered the call site of pgstat_count_io_op_time() in a few
locations, but I have some questions about this.
Before, I didn't think it mattered much that we didn't finish counting
IO time until after setting BM_VALID or BM_DIRTY and unsetting
BM_IO_IN_PROGRESS. With the relation extension code doing this for many
buffers at once, though, I wondered if this will make the IO timing too
inaccurate.
As such, I've moved pgstat_count_io_op_time() to before we set those
flags in all locations. I did wonder if it is bad to prolong having the
buffer pinned and not having those flags set, though.
On Tue, Apr 4, 2023 at 8:59 PM Andres Freund <and...@anarazel.de> wrote:
>
> Hi,
>
> On 2023-03-31 15:44:58 -0400, Melanie Plageman wrote:
> > From 789d4bf1fb749a26523dbcd2c69795916b711c68 Mon Sep 17 00:00:00 2001
> > From: Melanie Plageman <melanieplage...@gmail.com>
> > Date: Tue, 21 Mar 2023 16:00:55 -0400
> > Subject: [PATCH v8 1/4] Count IO time for temp relation writes
> >
> > Both pgstat_database and pgBufferUsage write times failed to count
> > timing for flushes of dirty local buffers when acquiring a new local
> > buffer for a temporary relation block.
>
> I think it'd be worth mentioning here that we do count read time? Otherwise
> it'd not be as clear that adding tracking increases consistency...
Done
> > From f4e0db5c833f33b30d4c0b4bebec1096a1745d81 Mon Sep 17 00:00:00 2001
> > From: Melanie Plageman <melanieplage...@gmail.com>
> > Date: Tue, 21 Mar 2023 18:20:44 -0400
> > Subject: [PATCH v8 2/4] FlushRelationBuffers() counts temp relation IO
> > timing
> >
> > Add pgstat_database and pgBufferUsage IO timing counting to
> > FlushRelationBuffers() for writes of temporary relations.
> > ---
> > src/backend/storage/buffer/bufmgr.c | 18 ++++++++++++++++++
> > 1 file changed, 18 insertions(+)
> >
> > diff --git a/src/backend/storage/buffer/bufmgr.c
> > b/src/backend/storage/buffer/bufmgr.c
> > index b3adbbe7d2..05e98d5994 100644
> > --- a/src/backend/storage/buffer/bufmgr.c
> > +++ b/src/backend/storage/buffer/bufmgr.c
> > @@ -3571,6 +3571,8 @@ FlushRelationBuffers(Relation rel)
> > {
> > int i;
> > BufferDesc *bufHdr;
> > + instr_time io_start,
> > + io_time;
> >
> > if (RelationUsesLocalBuffers(rel))
> > {
> > @@ -3596,17 +3598,33 @@ FlushRelationBuffers(Relation rel)
> >
> > PageSetChecksumInplace(localpage,
> > bufHdr->tag.blockNum);
> >
> > + if (track_io_timing)
> > + INSTR_TIME_SET_CURRENT(io_start);
> > + else
> > + INSTR_TIME_SET_ZERO(io_start);
> > +
> > smgrwrite(RelationGetSmgr(rel),
> >
> > BufTagGetForkNum(&bufHdr->tag),
> > bufHdr->tag.blockNum,
> > localpage,
> > false);
> >
> > +
>
> Spurious newline.
Fixed.
> > From 2bdad725133395ded199ecc726096e052d6e654b Mon Sep 17 00:00:00 2001
> > From: Melanie Plageman <melanieplage...@gmail.com>
> > Date: Fri, 31 Mar 2023 15:32:36 -0400
> > Subject: [PATCH v8 3/4] Track IO times in pg_stat_io
> >
> > Add IO timing for reads, writes, extends, and fsyncs to pg_stat_io.
> >
> > Reviewed-by: Bertrand Drouvot <bertranddrouvot...@gmail.com>
> > Reviewed-by: Andres Freund <and...@anarazel.de>
> > Discussion:
> > https://www.postgresql.org/message-id/flat/CAAKRu_ay5iKmnbXZ3DsauViF3eMxu4m1oNnJXqV_HyqYeg55Ww%40mail.gmail.com
> > ---
>
> > -static PgStat_BktypeIO PendingIOStats;
> > +typedef struct PgStat_PendingIO
> > +{
> > + PgStat_Counter
> > counts[IOOBJECT_NUM_TYPES][IOCONTEXT_NUM_TYPES][IOOP_NUM_TYPES];
> > + instr_time
> > pending_times[IOOBJECT_NUM_TYPES][IOCONTEXT_NUM_TYPES][IOOP_NUM_TYPES];
> > +} PgStat_PendingIO;
>
> Probably will look less awful after adding the typedef to typedefs.list.
Done.
One day I will remember to add things to typedefs.list.
> > + /* we do track it */
> > + if (pgstat_tracks_io_op(bktype, io_object,
> > io_context, io_op))
> > + {
> > + /* ensure that if IO times are
> > non-zero, counts are > 0 */
> > + if
> > (backend_io->times[io_object][io_context][io_op] != 0 &&
> > +
> > backend_io->counts[io_object][io_context][io_op] <= 0)
> > + return false;
> > +
> > continue;
> > + }
> >
> > - /* There are stats and there shouldn't be */
> > - if (!bktype_tracked ||
> > - !pgstat_tracks_io_op(bktype,
> > io_object, io_context, io_op))
> > + /* we don't track it, and it is not 0 */
> > + if
> > (backend_io->counts[io_object][io_context][io_op] != 0)
> > return false;
> > +
> > + /* we don't track this IOOp, so make sure its
> > IO time is zero */
> > + if (pgstat_tracks_io_time(io_op) > -1)
> > + {
> > + if
> > (backend_io->times[io_object][io_context][io_op] != 0)
> > + return false;
> > + }
>
> I'm somehow doubtful it's worth having pgstat_tracks_io_time, what kind of
> error would be caught by this check?
Yea, now that the function to count IO timing also increments the count,
I don't think this can happen.
However, pgstat_tracks_io_time() is useful in its other call site in
pgstatfuncs which lets us continue in the loop if we don't need to fill
in that IO time. Perhaps it could be replaced with a if (io_op ==
IOOP_EVICT || io_op == IOOP_REUSE ... but I kind of like the function?
But, maybe it is overkill...
For now, I've moved pgstat_tracks_io_time() into pgstatfuncs.c as a
helper.
> > +/*
> > + * Get the number of the column containing IO times for the specified
> > IOOp. If
> > + * the specified IOOp is one for which IO time is not tracked, return -1.
> > Note
> > + * that this function assumes that IO time for an IOOp is displayed in the
> > view
> > + * in the column directly after the IOOp counts.
> > + */
> > +static io_stat_col
> > +pgstat_get_io_time_index(IOOp io_op)
> > +{
> > + if (pgstat_tracks_io_time(io_op) == -1)
> > + return -1;
>
> That seems dangerous - won't it just lead to accessing something from before
> the start of the array? Probably should just assert.
Yea. I've removed it entirely as the passed in io_op can't be negative
(unless we change the enum values) and we add one to it before
returning.
> > @@ -1363,20 +1389,32 @@ pg_stat_get_io(PG_FUNCTION_ARGS)
> >
> > for (int io_op = 0; io_op < IOOP_NUM_TYPES;
> > io_op++)
> > {
> > - int col_idx =
> > pgstat_get_io_op_index(io_op);
> > + PgStat_Counter count =
> > bktype_stats->counts[io_obj][io_context][io_op];
> > + int i =
> > pgstat_get_io_op_index(io_op);
> >
> > /*
> > * Some combinations of BackendType
> > and IOOp, of IOContext
> > * and IOOp, and of IOObject and IOOp
> > are not tracked. Set
> > * these cells in the view NULL.
> > */
> > - nulls[col_idx] =
> > !pgstat_tracks_io_op(bktype, io_obj, io_context, io_op);
> > + if (pgstat_tracks_io_op(bktype,
> > io_obj, io_context, io_op))
> > + values[i] =
> > Int64GetDatum(count);
> > + else
> > + nulls[i] = true;
> > + }
> >
> > - if (nulls[col_idx])
> > + for (int io_op = 0; io_op < IOOP_NUM_TYPES;
> > io_op++)
> > + {
> > + PgStat_Counter time =
> > bktype_stats->times[io_obj][io_context][io_op];
> > + int i =
> > pgstat_get_io_time_index(io_op);
> > +
> > + if (i == -1)
> > continue;
> >
> > - values[col_idx] =
> > -
> > Int64GetDatum(bktype_stats->data[io_obj][io_context][io_op]);
> > + if
> > (!nulls[pgstat_get_io_op_index(io_op)])
> > + values[i] =
> > Float8GetDatum(pg_stat_micro_to_millisecs(time));
> > + else
> > + nulls[i] = true;
> > }
>
> Why two loops?
Well, it was a stylistic choice that I now realize is actually
confusing.
I consolidated them.
- Melanie
From 33abf29c4673175c5a71ce01b3a8d3bf961e268a Mon Sep 17 00:00:00 2001
From: Melanie Plageman <melanieplage...@gmail.com>
Date: Tue, 21 Mar 2023 20:36:10 -0400
Subject: [PATCH v9 4/4] pgstat_database uses pgstat_io time counters
Use pgstat_io's pending counters to increment pgStatBlockWriteTime and
pgStatBlockReadTime.
Reviewed-by: Andres Freund <and...@anarazel.de>
Discussion: https://postgr.es/m/20230321023451.7rzy4kjj2iktrg2r%40awork3.anarazel.de
---
src/backend/utils/activity/pgstat_io.c | 14 ++++++++------
src/include/pgstat.h | 4 ----
2 files changed, 8 insertions(+), 10 deletions(-)
diff --git a/src/backend/utils/activity/pgstat_io.c b/src/backend/utils/activity/pgstat_io.c
index bc6787b3f3..7e7d7795fb 100644
--- a/src/backend/utils/activity/pgstat_io.c
+++ b/src/backend/utils/activity/pgstat_io.c
@@ -121,13 +121,11 @@ pgstat_count_io_op_time(IOObject io_object, IOContext io_context, IOOp io_op,
if (io_op == IOOP_WRITE)
{
- 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);
}
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);
}
@@ -178,15 +176,19 @@ pgstat_flush_io(bool nowait)
{
for (int io_op = 0; io_op < IOOP_NUM_TYPES; io_op++)
{
- instr_time time;
+ PgStat_Counter time;
bktype_shstats->counts[io_object][io_context][io_op] +=
PendingIOStats.counts[io_object][io_context][io_op];
- time = PendingIOStats.pending_times[io_object][io_context][io_op];
+ time = INSTR_TIME_GET_MICROSEC(PendingIOStats.pending_times[io_object][io_context][io_op]);
- bktype_shstats->times[io_object][io_context][io_op] +=
- INSTR_TIME_GET_MICROSEC(time);
+ bktype_shstats->times[io_object][io_context][io_op] += time;
+
+ if (io_op == IOOP_WRITE)
+ pgStatBlockWriteTime += time;
+ else if (io_op == IOOP_READ)
+ pgStatBlockReadTime += time;
}
}
}
diff --git a/src/include/pgstat.h b/src/include/pgstat.h
index 6f9ad0cf31..1d5aeb7dea 100644
--- a/src/include/pgstat.h
+++ b/src/include/pgstat.h
@@ -544,10 +544,6 @@ extern void pgstat_report_checksum_failures_in_db(Oid dboid, int failurecount);
extern void pgstat_report_checksum_failure(void);
extern void pgstat_report_connect(Oid dboid);
-#define pgstat_count_buffer_read_time(n) \
- (pgStatBlockReadTime += (n))
-#define pgstat_count_buffer_write_time(n) \
- (pgStatBlockWriteTime += (n))
#define pgstat_count_conn_active_time(n) \
(pgStatActiveTime += (n))
#define pgstat_count_conn_txn_idle_time(n) \
--
2.37.2
From d17524cdeec3297eb7d08876fd7acc41e0f0f1b5 Mon Sep 17 00:00:00 2001
From: Melanie Plageman <melanieplage...@gmail.com>
Date: Tue, 21 Mar 2023 16:00:55 -0400
Subject: [PATCH v9 1/4] Count IO time for temp relation writes
Both pgstat_database and pgBufferUsage count IO timing for reads of
temporary relation blocks into local buffers. However, both failed to
count write IO timing for flushes of dirty local buffers. Add this to
achieve parity.
Reviewed-by: Andres Freund <and...@anarazel.de>
Discussion: https://postgr.es/m/20230321023451.7rzy4kjj2iktrg2r%40awork3.anarazel.de
---
src/backend/storage/buffer/localbuf.c | 16 ++++++++++++++++
1 file changed, 16 insertions(+)
diff --git a/src/backend/storage/buffer/localbuf.c b/src/backend/storage/buffer/localbuf.c
index 3846d3eaca..3639296bc1 100644
--- a/src/backend/storage/buffer/localbuf.c
+++ b/src/backend/storage/buffer/localbuf.c
@@ -176,6 +176,8 @@ GetLocalVictimBuffer(void)
int trycounter;
uint32 buf_state;
BufferDesc *bufHdr;
+ instr_time io_start,
+ io_time;
ResourceOwnerEnlargeBuffers(CurrentResourceOwner);
@@ -239,6 +241,11 @@ GetLocalVictimBuffer(void)
PageSetChecksumInplace(localpage, bufHdr->tag.blockNum);
+ if (track_io_timing)
+ INSTR_TIME_SET_CURRENT(io_start);
+ else
+ INSTR_TIME_SET_ZERO(io_start);
+
/* And write... */
smgrwrite(oreln,
BufTagGetForkNum(&bufHdr->tag),
@@ -252,6 +259,15 @@ GetLocalVictimBuffer(void)
/* Temporary table I/O does not use Buffer Access Strategies */
pgstat_count_io_op(IOOBJECT_TEMP_RELATION, IOCONTEXT_NORMAL, IOOP_WRITE);
+
+ if (track_io_timing)
+ {
+ INSTR_TIME_SET_CURRENT(io_time);
+ INSTR_TIME_SUBTRACT(io_time, io_start);
+ pgstat_count_buffer_write_time(INSTR_TIME_GET_MICROSEC(io_time));
+ INSTR_TIME_ADD(pgBufferUsage.blk_write_time, io_time);
+ }
+
pgBufferUsage.local_blks_written++;
}
--
2.37.2
From 023554df02490e1098008bdb2b512bbd78974589 Mon Sep 17 00:00:00 2001
From: Melanie Plageman <melanieplage...@gmail.com>
Date: Fri, 31 Mar 2023 15:32:36 -0400
Subject: [PATCH v9 3/4] Track IO times in pg_stat_io
a9c70b46dbe and 8aaa04b32S added counting of IO operations to a new
view, pg_stat_io. Now, add IO timing for reads, writes, extends, and
fsyncs to pg_stat_io as well.
Reviewed-by: Andres Freund <and...@anarazel.de>
Reviewed-by: Bertrand Drouvot <bertranddrouvot...@gmail.com>
Discussion: https://postgr.es/m/flat/CAAKRu_ay5iKmnbXZ3DsauViF3eMxu4m1oNnJXqV_HyqYeg55Ww%40mail.gmail.com
---
doc/src/sgml/monitoring.sgml | 59 ++++++++++++++
src/backend/catalog/system_views.sql | 4 +
src/backend/storage/buffer/bufmgr.c | 66 +++++----------
src/backend/storage/buffer/localbuf.c | 31 +++-----
src/backend/storage/smgr/md.c | 31 +++++---
src/backend/utils/activity/pgstat_io.c | 106 ++++++++++++++++++++-----
src/backend/utils/adt/pgstatfuncs.c | 68 ++++++++++++++--
src/include/catalog/pg_proc.dat | 6 +-
src/include/pgstat.h | 8 +-
src/test/regress/expected/rules.out | 6 +-
src/tools/pgindent/typedefs.list | 1 +
11 files changed, 278 insertions(+), 108 deletions(-)
diff --git a/doc/src/sgml/monitoring.sgml b/doc/src/sgml/monitoring.sgml
index bce9ae4661..7da135d2f2 100644
--- a/doc/src/sgml/monitoring.sgml
+++ b/doc/src/sgml/monitoring.sgml
@@ -3814,6 +3814,18 @@ SELECT pid, wait_event_type, wait_event FROM pg_stat_activity WHERE wait_event i
</entry>
</row>
+ <row>
+ <entry role="catalog_table_entry">
+ <para role="column_definition">
+ <structfield>read_time</structfield> <type>double precision</type>
+ </para>
+ <para>
+ Time spent in read operations 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">
@@ -3826,6 +3838,18 @@ SELECT pid, wait_event_type, wait_event FROM pg_stat_activity WHERE wait_event i
</entry>
</row>
+ <row>
+ <entry role="catalog_table_entry">
+ <para role="column_definition">
+ <structfield>write_time</structfield> <type>double precision</type>
+ </para>
+ <para>
+ Time spent in write operations 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">
@@ -3838,6 +3862,18 @@ SELECT pid, wait_event_type, wait_event FROM pg_stat_activity WHERE wait_event i
</entry>
</row>
+ <row>
+ <entry role="catalog_table_entry">
+ <para role="column_definition">
+ <structfield>extend_time</structfield> <type>double precision</type>
+ </para>
+ <para>
+ Time spent in extend operations 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">
@@ -3913,6 +3949,18 @@ SELECT pid, wait_event_type, wait_event FROM pg_stat_activity WHERE wait_event i
</entry>
</row>
+ <row>
+ <entry role="catalog_table_entry">
+ <para role="column_definition">
+ <structfield>fsync_time</structfield> <type>double precision</type>
+ </para>
+ <para>
+ Time spent in fsync operations 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">
@@ -3978,6 +4026,17 @@ SELECT pid, wait_event_type, wait_event FROM pg_stat_activity WHERE wait_event i
</itemizedlist>
</para>
+ <note>
+ <para>
+ Columns tracking I/O time will only be non-zero when
+ <xref linkend="guc-track-io-timing"/> is enabled. The user should be
+ careful when referencing these columns in combination with their
+ corresponding IO operations in case <varname>track_io_timing</varname>
+ was not enabled for the entire time since the last stats reset.
+ </para>
+ </note>
+
+
</sect2>
diff --git a/src/backend/catalog/system_views.sql b/src/backend/catalog/system_views.sql
index 6b098234f8..41aafe0b87 100644
--- a/src/backend/catalog/system_views.sql
+++ b/src/backend/catalog/system_views.sql
@@ -1125,13 +1125,17 @@ SELECT
b.io_object,
b.io_context,
b.reads,
+ b.read_time,
b.writes,
+ b.write_time,
b.extends,
+ b.extend_time,
b.op_bytes,
b.hits,
b.evictions,
b.reuses,
b.fsyncs,
+ b.fsync_time,
b.stats_reset
FROM pg_stat_get_io() b;
diff --git a/src/backend/storage/buffer/bufmgr.c b/src/backend/storage/buffer/bufmgr.c
index ef69f21adf..a12d0c6c27 100644
--- a/src/backend/storage/buffer/bufmgr.c
+++ b/src/backend/storage/buffer/bufmgr.c
@@ -1112,23 +1112,12 @@ ReadBuffer_common(SMgrRelation smgr, char relpersistence, ForkNumber forkNum,
MemSet((char *) bufBlock, 0, BLCKSZ);
else
{
- instr_time io_start,
- io_time;
-
- if (track_io_timing)
- INSTR_TIME_SET_CURRENT(io_start);
+ instr_time io_start = pgstat_prepare_io_time();
smgrread(smgr, forkNum, blockNum, bufBlock);
- if (track_io_timing)
- {
- INSTR_TIME_SET_CURRENT(io_time);
- INSTR_TIME_SUBTRACT(io_time, io_start);
- pgstat_count_buffer_read_time(INSTR_TIME_GET_MICROSEC(io_time));
- INSTR_TIME_ADD(pgBufferUsage.blk_read_time, io_time);
- }
-
- pgstat_count_io_op(io_object, io_context, IOOP_READ);
+ pgstat_count_io_op_time(io_object, io_context,
+ IOOP_READ, io_start, 1);
/* check for garbage data */
if (!PageIsVerifiedExtended((Page) bufBlock, blockNum,
@@ -1837,6 +1826,7 @@ ExtendBufferedRelShared(ExtendBufferedWhat eb,
{
BlockNumber first_block;
IOContext io_context = IOContextForStrategy(strategy);
+ instr_time io_start;
LimitAdditionalPins(&extend_by);
@@ -2044,6 +2034,8 @@ ExtendBufferedRelShared(ExtendBufferedWhat eb,
}
}
+ io_start = pgstat_prepare_io_time();
+
/*
* Note: if smgzerorextend fails, we will end up with buffers that are
* allocated but not marked BM_VALID. The next relation extension will
@@ -2066,6 +2058,9 @@ ExtendBufferedRelShared(ExtendBufferedWhat eb,
if (!(flags & EB_SKIP_EXTENSION_LOCK))
UnlockRelationForExtension(eb.rel, ExclusiveLock);
+ pgstat_count_io_op_time(IOOBJECT_RELATION, io_context, IOOP_EXTEND,
+ io_start, extend_by);
+
/* Set BM_VALID, terminate IO, and wake up any waiters */
for (int i = 0; i < extend_by; i++)
{
@@ -2089,8 +2084,6 @@ ExtendBufferedRelShared(ExtendBufferedWhat eb,
}
pgBufferUsage.shared_blks_written += extend_by;
- pgstat_count_io_op_n(IOOBJECT_RELATION, io_context, IOOP_EXTEND,
- extend_by);
*extended_by = extend_by;
@@ -3344,8 +3337,7 @@ FlushBuffer(BufferDesc *buf, SMgrRelation reln, IOObject io_object,
{
XLogRecPtr recptr;
ErrorContextCallback errcallback;
- instr_time io_start,
- io_time;
+ instr_time io_start;
Block bufBlock;
char *bufToWrite;
uint32 buf_state;
@@ -3420,10 +3412,7 @@ FlushBuffer(BufferDesc *buf, SMgrRelation reln, IOObject io_object,
*/
bufToWrite = PageSetChecksumCopy((Page) bufBlock, buf->tag.blockNum);
- if (track_io_timing)
- INSTR_TIME_SET_CURRENT(io_start);
- else
- INSTR_TIME_SET_ZERO(io_start);
+ io_start = pgstat_prepare_io_time();
/*
* bufToWrite is either the shared buffer or a copy, as appropriate.
@@ -3452,15 +3441,8 @@ FlushBuffer(BufferDesc *buf, SMgrRelation reln, IOObject io_object,
* When a strategy is not in use, the write can only be a "regular" write
* of a dirty shared buffer (IOCONTEXT_NORMAL IOOP_WRITE).
*/
- pgstat_count_io_op(IOOBJECT_RELATION, io_context, IOOP_WRITE);
-
- if (track_io_timing)
- {
- INSTR_TIME_SET_CURRENT(io_time);
- INSTR_TIME_SUBTRACT(io_time, io_start);
- pgstat_count_buffer_write_time(INSTR_TIME_GET_MICROSEC(io_time));
- INSTR_TIME_ADD(pgBufferUsage.blk_write_time, io_time);
- }
+ pgstat_count_io_op_time(IOOBJECT_RELATION, io_context,
+ IOOP_WRITE, io_start, 1);
pgBufferUsage.shared_blks_written++;
@@ -4062,14 +4044,13 @@ FlushRelationBuffers(Relation rel)
{
int i;
BufferDesc *bufHdr;
- instr_time io_start,
- io_time;
if (RelationUsesLocalBuffers(rel))
{
for (i = 0; i < NLocBuffer; i++)
{
uint32 buf_state;
+ instr_time io_start;
bufHdr = GetLocalBufferDescriptor(i);
if (BufTagMatchesRelFileLocator(&bufHdr->tag, &rel->rd_locator) &&
@@ -4089,10 +4070,7 @@ FlushRelationBuffers(Relation rel)
PageSetChecksumInplace(localpage, bufHdr->tag.blockNum);
- if (track_io_timing)
- INSTR_TIME_SET_CURRENT(io_start);
- else
- INSTR_TIME_SET_ZERO(io_start);
+ io_start = pgstat_prepare_io_time();
smgrwrite(RelationGetSmgr(rel),
BufTagGetForkNum(&bufHdr->tag),
@@ -4100,19 +4078,13 @@ FlushRelationBuffers(Relation rel)
localpage,
false);
+ pgstat_count_io_op_time(IOOBJECT_TEMP_RELATION,
+ IOCONTEXT_NORMAL, IOOP_WRITE,
+ io_start, 1);
+
buf_state &= ~(BM_DIRTY | BM_JUST_DIRTIED);
pg_atomic_unlocked_write_u32(&bufHdr->state, buf_state);
- pgstat_count_io_op(IOOBJECT_TEMP_RELATION, IOCONTEXT_NORMAL, IOOP_WRITE);
-
- if (track_io_timing)
- {
- INSTR_TIME_SET_CURRENT(io_time);
- INSTR_TIME_SUBTRACT(io_time, io_start);
- pgstat_count_buffer_write_time(INSTR_TIME_GET_MICROSEC(io_time));
- INSTR_TIME_ADD(pgBufferUsage.blk_write_time, io_time);
- }
-
pgBufferUsage.local_blks_written++;
/* Pop the error context stack */
diff --git a/src/backend/storage/buffer/localbuf.c b/src/backend/storage/buffer/localbuf.c
index 3639296bc1..3d5bc9193d 100644
--- a/src/backend/storage/buffer/localbuf.c
+++ b/src/backend/storage/buffer/localbuf.c
@@ -176,8 +176,6 @@ GetLocalVictimBuffer(void)
int trycounter;
uint32 buf_state;
BufferDesc *bufHdr;
- instr_time io_start,
- io_time;
ResourceOwnerEnlargeBuffers(CurrentResourceOwner);
@@ -233,6 +231,7 @@ GetLocalVictimBuffer(void)
*/
if (buf_state & BM_DIRTY)
{
+ instr_time io_start;
SMgrRelation oreln;
Page localpage = (char *) LocalBufHdrGetBlock(bufHdr);
@@ -241,10 +240,7 @@ GetLocalVictimBuffer(void)
PageSetChecksumInplace(localpage, bufHdr->tag.blockNum);
- if (track_io_timing)
- INSTR_TIME_SET_CURRENT(io_start);
- else
- INSTR_TIME_SET_ZERO(io_start);
+ io_start = pgstat_prepare_io_time();
/* And write... */
smgrwrite(oreln,
@@ -253,21 +249,14 @@ GetLocalVictimBuffer(void)
localpage,
false);
+ /* Temporary table I/O does not use Buffer Access Strategies */
+ pgstat_count_io_op_time(IOOBJECT_TEMP_RELATION, IOCONTEXT_NORMAL,
+ IOOP_WRITE, io_start, 1);
+
/* Mark not-dirty now in case we error out below */
buf_state &= ~BM_DIRTY;
pg_atomic_unlocked_write_u32(&bufHdr->state, buf_state);
- /* Temporary table I/O does not use Buffer Access Strategies */
- pgstat_count_io_op(IOOBJECT_TEMP_RELATION, IOCONTEXT_NORMAL, IOOP_WRITE);
-
- if (track_io_timing)
- {
- INSTR_TIME_SET_CURRENT(io_time);
- INSTR_TIME_SUBTRACT(io_time, io_start);
- pgstat_count_buffer_write_time(INSTR_TIME_GET_MICROSEC(io_time));
- INSTR_TIME_ADD(pgBufferUsage.blk_write_time, io_time);
- }
-
pgBufferUsage.local_blks_written++;
}
@@ -325,6 +314,7 @@ ExtendBufferedRelLocal(ExtendBufferedWhat eb,
uint32 *extended_by)
{
BlockNumber first_block;
+ instr_time io_start;
/* Initialize local buffers if first request in this session */
if (LocalBufHash == NULL)
@@ -415,9 +405,14 @@ ExtendBufferedRelLocal(ExtendBufferedWhat eb,
}
}
+ io_start = pgstat_prepare_io_time();
+
/* actually extend relation */
smgrzeroextend(eb.smgr, fork, first_block, extend_by, false);
+ pgstat_count_io_op_time(IOOBJECT_TEMP_RELATION, IOCONTEXT_NORMAL, IOOP_EXTEND,
+ io_start, extend_by);
+
for (int i = 0; i < extend_by; i++)
{
Buffer buf = buffers[i];
@@ -434,8 +429,6 @@ ExtendBufferedRelLocal(ExtendBufferedWhat eb,
*extended_by = extend_by;
pgBufferUsage.temp_blks_written += extend_by;
- pgstat_count_io_op_n(IOOBJECT_TEMP_RELATION, IOCONTEXT_NORMAL, IOOP_EXTEND,
- extend_by);
return first_block;
}
diff --git a/src/backend/storage/smgr/md.c b/src/backend/storage/smgr/md.c
index 1c2d1405f8..d9d0367c89 100644
--- a/src/backend/storage/smgr/md.c
+++ b/src/backend/storage/smgr/md.c
@@ -1138,6 +1138,19 @@ register_dirty_segment(SMgrRelation reln, ForkNumber forknum, MdfdVec *seg)
if (!RegisterSyncRequest(&tag, SYNC_REQUEST, false /* retryOnError */ ))
{
+ instr_time io_start;
+
+ ereport(DEBUG1,
+ (errmsg_internal("could not forward fsync request because request queue is full")));
+
+ io_start = pgstat_prepare_io_time();
+
+ if (FileSync(seg->mdfd_vfd, WAIT_EVENT_DATA_FILE_SYNC) < 0)
+ ereport(data_sync_elevel(ERROR),
+ (errcode_for_file_access(),
+ errmsg("could not fsync file \"%s\": %m",
+ FilePathName(seg->mdfd_vfd))));
+
/*
* We have no way of knowing if the current IOContext is
* IOCONTEXT_NORMAL or IOCONTEXT_[BULKREAD, BULKWRITE, VACUUM] at this
@@ -1149,16 +1162,8 @@ register_dirty_segment(SMgrRelation reln, ForkNumber forknum, MdfdVec *seg)
* IOCONTEXT_NORMAL is likely clearer when investigating the number of
* backend fsyncs.
*/
- pgstat_count_io_op(IOOBJECT_RELATION, IOCONTEXT_NORMAL, IOOP_FSYNC);
-
- ereport(DEBUG1,
- (errmsg_internal("could not forward fsync request because request queue is full")));
-
- if (FileSync(seg->mdfd_vfd, WAIT_EVENT_DATA_FILE_SYNC) < 0)
- ereport(data_sync_elevel(ERROR),
- (errcode_for_file_access(),
- errmsg("could not fsync file \"%s\": %m",
- FilePathName(seg->mdfd_vfd))));
+ pgstat_count_io_op_time(IOOBJECT_RELATION, IOCONTEXT_NORMAL,
+ IOOP_FSYNC, io_start, 1);
}
}
@@ -1508,6 +1513,7 @@ mdsyncfiletag(const FileTag *ftag, char *path)
{
SMgrRelation reln = smgropen(ftag->rlocator, InvalidBackendId);
File file;
+ instr_time io_start;
bool need_to_close;
int result,
save_errno;
@@ -1533,6 +1539,8 @@ mdsyncfiletag(const FileTag *ftag, char *path)
need_to_close = true;
}
+ io_start = pgstat_prepare_io_time();
+
/* Sync the file. */
result = FileSync(file, WAIT_EVENT_DATA_FILE_SYNC);
save_errno = errno;
@@ -1540,7 +1548,8 @@ mdsyncfiletag(const FileTag *ftag, char *path)
if (need_to_close)
FileClose(file);
- pgstat_count_io_op(IOOBJECT_RELATION, IOCONTEXT_NORMAL, IOOP_FSYNC);
+ pgstat_count_io_op_time(IOOBJECT_RELATION, IOCONTEXT_NORMAL,
+ IOOP_FSYNC, io_start, 1);
errno = save_errno;
return result;
diff --git a/src/backend/utils/activity/pgstat_io.c b/src/backend/utils/activity/pgstat_io.c
index 0e4f26427c..bc6787b3f3 100644
--- a/src/backend/utils/activity/pgstat_io.c
+++ b/src/backend/utils/activity/pgstat_io.c
@@ -16,44 +16,55 @@
#include "postgres.h"
+#include "executor/instrument.h"
+#include "storage/bufmgr.h"
#include "utils/pgstat_internal.h"
-static PgStat_BktypeIO PendingIOStats;
+typedef struct PgStat_PendingIO
+{
+ PgStat_Counter counts[IOOBJECT_NUM_TYPES][IOCONTEXT_NUM_TYPES][IOOP_NUM_TYPES];
+ instr_time pending_times[IOOBJECT_NUM_TYPES][IOCONTEXT_NUM_TYPES][IOOP_NUM_TYPES];
+} PgStat_PendingIO;
+
+
+static PgStat_PendingIO PendingIOStats;
bool have_iostats = false;
/*
* Check that stats have not been counted for any combination of IOObject,
- * IOContext, and IOOp which are not tracked for the passed-in BackendType. The
- * passed-in PgStat_BktypeIO must contain stats from the BackendType specified
- * by the second parameter. Caller is responsible for locking the passed-in
- * PgStat_BktypeIO, if needed.
+ * IOContext, and IOOp which are not tracked for the passed-in BackendType. If
+ * stats are tracked for this combination and IO times are non-zero, counts
+ * should be non-zero.
+ *
+ * The passed-in PgStat_BktypeIO must contain stats from the BackendType
+ * specified by the second parameter. Caller is responsible for locking the
+ * passed-in PgStat_BktypeIO, if needed.
*/
bool
pgstat_bktype_io_stats_valid(PgStat_BktypeIO *backend_io,
BackendType bktype)
{
- bool bktype_tracked = pgstat_tracks_io_bktype(bktype);
-
for (int io_object = 0; io_object < IOOBJECT_NUM_TYPES; io_object++)
{
for (int io_context = 0; io_context < IOCONTEXT_NUM_TYPES; io_context++)
{
- /*
- * Don't bother trying to skip to the next loop iteration if
- * pgstat_tracks_io_object() would return false here. We still
- * need to validate that each counter is zero anyway.
- */
for (int io_op = 0; io_op < IOOP_NUM_TYPES; io_op++)
{
- /* No stats, so nothing to validate */
- if (backend_io->data[io_object][io_context][io_op] == 0)
+ /* we do track it */
+ if (pgstat_tracks_io_op(bktype, io_object, io_context, io_op))
+ {
+ /* ensure that if IO times are non-zero, counts are > 0 */
+ if (backend_io->times[io_object][io_context][io_op] != 0 &&
+ backend_io->counts[io_object][io_context][io_op] <= 0)
+ return false;
+
continue;
+ }
- /* There are stats and there shouldn't be */
- if (!bktype_tracked ||
- !pgstat_tracks_io_op(bktype, io_object, io_context, io_op))
+ /* we don't track it, and it is not 0 */
+ if (backend_io->counts[io_object][io_context][io_op] != 0)
return false;
}
}
@@ -76,11 +87,57 @@ pgstat_count_io_op_n(IOObject io_object, IOContext io_context, IOOp io_op, uint3
Assert((unsigned int) io_op < IOOP_NUM_TYPES);
Assert(pgstat_tracks_io_op(MyBackendType, io_object, io_context, io_op));
- PendingIOStats.data[io_object][io_context][io_op] += cnt;
+ PendingIOStats.counts[io_object][io_context][io_op] += cnt;
have_iostats = true;
}
+instr_time
+pgstat_prepare_io_time(void)
+{
+ instr_time io_start;
+
+ if (track_io_timing)
+ INSTR_TIME_SET_CURRENT(io_start);
+ else
+ INSTR_TIME_SET_ZERO(io_start);
+
+ return io_start;
+}
+
+/*
+ * Like pgstat_count_io_op_n() except it also accumulates time.
+ */
+void
+pgstat_count_io_op_time(IOObject io_object, IOContext io_context, IOOp io_op,
+ instr_time start_time, uint32 cnt)
+{
+ if (track_io_timing)
+ {
+ instr_time io_time;
+
+ INSTR_TIME_SET_CURRENT(io_time);
+ INSTR_TIME_SUBTRACT(io_time, start_time);
+
+ if (io_op == IOOP_WRITE)
+ {
+ 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);
+ }
+ 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(PendingIOStats.pending_times[io_object][io_context][io_op], io_time);
+ }
+
+ pgstat_count_io_op_n(io_object, io_context, io_op, cnt);
+}
+
PgStat_IO *
pgstat_fetch_stat_io(void)
{
@@ -120,8 +177,17 @@ pgstat_flush_io(bool nowait)
for (int io_context = 0; io_context < IOCONTEXT_NUM_TYPES; io_context++)
{
for (int io_op = 0; io_op < IOOP_NUM_TYPES; io_op++)
- bktype_shstats->data[io_object][io_context][io_op] +=
- PendingIOStats.data[io_object][io_context][io_op];
+ {
+ instr_time time;
+
+ bktype_shstats->counts[io_object][io_context][io_op] +=
+ PendingIOStats.counts[io_object][io_context][io_op];
+
+ time = PendingIOStats.pending_times[io_object][io_context][io_op];
+
+ bktype_shstats->times[io_object][io_context][io_op] +=
+ INSTR_TIME_GET_MICROSEC(time);
+ }
}
}
diff --git a/src/backend/utils/adt/pgstatfuncs.c b/src/backend/utils/adt/pgstatfuncs.c
index eec9f3cf9b..1bef923527 100644
--- a/src/backend/utils/adt/pgstatfuncs.c
+++ b/src/backend/utils/adt/pgstatfuncs.c
@@ -1256,13 +1256,17 @@ typedef enum io_stat_col
IO_COL_IO_OBJECT,
IO_COL_IO_CONTEXT,
IO_COL_READS,
+ IO_COL_READ_TIME,
IO_COL_WRITES,
+ IO_COL_WRITE_TIME,
IO_COL_EXTENDS,
+ IO_COL_EXTEND_TIME,
IO_COL_CONVERSION,
IO_COL_HITS,
IO_COL_EVICTIONS,
IO_COL_REUSES,
IO_COL_FSYNCS,
+ IO_COL_FSYNC_TIME,
IO_COL_RESET_TIME,
IO_NUM_COLUMNS,
} io_stat_col;
@@ -1296,6 +1300,52 @@ pgstat_get_io_op_index(IOOp io_op)
pg_unreachable();
}
+/*
+ * Get the number of the column containing IO times for the specified IOOp.
+ * This function encodes our assumption that IO time for an IOOp is displayed
+ * in the view in the column directly after the IOOp counts.
+ */
+static io_stat_col
+pgstat_get_io_time_index(IOOp io_op)
+{
+ return pgstat_get_io_op_index(io_op) + 1;
+}
+
+static inline
+PgStat_Counter
+pg_stat_micro_to_millisecs(PgStat_Counter val_microsec)
+{
+ return val_microsec * 0.001;
+}
+
+/*
+ * PgStat_BktypeIO->times contains IO times for IOOps. For simplicity this
+ * array has a spot for every IOOp. pgstat_tracks_io_time() is the source of
+ * truth for which IOOps have corresponding IO times.
+ */
+static IOOp
+pgstat_tracks_io_time(IOOp io_op)
+{
+ switch (io_op)
+ {
+ case IOOP_READ:
+ return IOOP_READ;
+ case IOOP_WRITE:
+ return IOOP_WRITE;
+ case IOOP_EXTEND:
+ return IOOP_EXTEND;
+ case IOOP_FSYNC:
+ return IOOP_FSYNC;
+ case IOOP_EVICT:
+ case IOOP_HIT:
+ case IOOP_REUSE:
+ return -1;
+ }
+
+ elog(ERROR, "unrecognized IOOp value: %d", io_op);
+ pg_unreachable();
+}
+
Datum
pg_stat_get_io(PG_FUNCTION_ARGS)
{
@@ -1363,20 +1413,28 @@ pg_stat_get_io(PG_FUNCTION_ARGS)
for (int io_op = 0; io_op < IOOP_NUM_TYPES; io_op++)
{
- int col_idx = pgstat_get_io_op_index(io_op);
+ PgStat_Counter count = bktype_stats->counts[io_obj][io_context][io_op];
+ PgStat_Counter time = bktype_stats->times[io_obj][io_context][io_op];
+ int op_idx = pgstat_get_io_op_index(io_op);
+ int time_idx = pgstat_get_io_time_index(io_op);
/*
* Some combinations of BackendType and IOOp, of IOContext
* and IOOp, and of IOObject and IOOp are not tracked. Set
* these cells in the view NULL.
*/
- nulls[col_idx] = !pgstat_tracks_io_op(bktype, io_obj, io_context, io_op);
+ if (pgstat_tracks_io_op(bktype, io_obj, io_context, io_op))
+ values[op_idx] = Int64GetDatum(count);
+ else
+ nulls[op_idx] = true;
- if (nulls[col_idx])
+ if (pgstat_tracks_io_time(io_op) == -1)
continue;
- values[col_idx] =
- Int64GetDatum(bktype_stats->data[io_obj][io_context][io_op]);
+ if (!nulls[op_idx])
+ values[time_idx] = Float8GetDatum(pg_stat_micro_to_millisecs(time));
+ else
+ nulls[time_idx] = true;
}
tuplestore_putvalues(rsinfo->setResult, rsinfo->setDesc,
diff --git a/src/include/catalog/pg_proc.dat b/src/include/catalog/pg_proc.dat
index f9f2642201..664a7ab41d 100644
--- a/src/include/catalog/pg_proc.dat
+++ b/src/include/catalog/pg_proc.dat
@@ -5749,9 +5749,9 @@
proname => 'pg_stat_get_io', provolatile => 'v',
prorows => '30', proretset => 't',
proparallel => 'r', prorettype => 'record', proargtypes => '',
- proallargtypes => '{text,text,text,int8,int8,int8,int8,int8,int8,int8,int8,timestamptz}',
- proargmodes => '{o,o,o,o,o,o,o,o,o,o,o,o}',
- proargnames => '{backend_type,io_object,io_context,reads,writes,extends,op_bytes,hits,evictions,reuses,fsyncs,stats_reset}',
+ proallargtypes => '{text,text,text,int8,float8,int8,float8,int8,float8,int8,int8,int8,int8,int8,float8,timestamptz}',
+ proargmodes => '{o,o,o,o,o,o,o,o,o,o,o,o,o,o,o,o}',
+ proargnames => '{backend_type,io_object,io_context,reads,read_time,writes,write_time,extends,extend_time,op_bytes,hits,evictions,reuses,fsyncs,fsync_time,stats_reset}',
prosrc => 'pg_stat_get_io' },
{ oid => '1136', descr => 'statistics: information about WAL activity',
diff --git a/src/include/pgstat.h b/src/include/pgstat.h
index e79b8a34eb..6f9ad0cf31 100644
--- a/src/include/pgstat.h
+++ b/src/include/pgstat.h
@@ -306,7 +306,8 @@ typedef enum IOOp
typedef struct PgStat_BktypeIO
{
- PgStat_Counter data[IOOBJECT_NUM_TYPES][IOCONTEXT_NUM_TYPES][IOOP_NUM_TYPES];
+ PgStat_Counter counts[IOOBJECT_NUM_TYPES][IOCONTEXT_NUM_TYPES][IOOP_NUM_TYPES];
+ PgStat_Counter times[IOOBJECT_NUM_TYPES][IOCONTEXT_NUM_TYPES][IOOP_NUM_TYPES];
} PgStat_BktypeIO;
typedef struct PgStat_IO
@@ -517,6 +518,10 @@ extern bool pgstat_bktype_io_stats_valid(PgStat_BktypeIO *context_ops,
BackendType bktype);
extern void pgstat_count_io_op(IOObject io_object, IOContext io_context, IOOp io_op);
extern void pgstat_count_io_op_n(IOObject io_object, IOContext io_context, IOOp io_op, uint32 cnt);
+extern instr_time pgstat_prepare_io_time(void);
+extern void pgstat_count_io_op_time(IOObject io_object, IOContext io_context,
+ IOOp io_op, instr_time time, uint32 cnt);
+
extern PgStat_IO *pgstat_fetch_stat_io(void);
extern const char *pgstat_get_io_context_name(IOContext io_context);
extern const char *pgstat_get_io_object_name(IOObject io_object);
@@ -527,7 +532,6 @@ extern bool pgstat_tracks_io_object(BackendType bktype,
extern bool pgstat_tracks_io_op(BackendType bktype, IOObject io_object,
IOContext io_context, IOOp io_op);
-
/*
* Functions in pgstat_database.c
*/
diff --git a/src/test/regress/expected/rules.out b/src/test/regress/expected/rules.out
index ab1aebfde4..d939d8067e 100644
--- a/src/test/regress/expected/rules.out
+++ b/src/test/regress/expected/rules.out
@@ -1881,15 +1881,19 @@ pg_stat_io| SELECT backend_type,
io_object,
io_context,
reads,
+ read_time,
writes,
+ write_time,
extends,
+ extend_time,
op_bytes,
hits,
evictions,
reuses,
fsyncs,
+ fsync_time,
stats_reset
- FROM pg_stat_get_io() b(backend_type, io_object, io_context, reads, writes, extends, op_bytes, hits, evictions, reuses, fsyncs, stats_reset);
+ FROM pg_stat_get_io() b(backend_type, io_object, io_context, reads, read_time, writes, write_time, extends, extend_time, op_bytes, hits, evictions, reuses, fsyncs, fsync_time, stats_reset);
pg_stat_progress_analyze| SELECT s.pid,
s.datid,
d.datname,
diff --git a/src/tools/pgindent/typedefs.list b/src/tools/pgindent/typedefs.list
index 3219ea5f05..494cc66d5b 100644
--- a/src/tools/pgindent/typedefs.list
+++ b/src/tools/pgindent/typedefs.list
@@ -2053,6 +2053,7 @@ PgStat_Kind
PgStat_KindInfo
PgStat_LocalState
PgStat_PendingDroppedStatsItem
+PgStat_PendingIO
PgStat_PendingWalStats
PgStat_SLRUStats
PgStat_ShmemControl
--
2.37.2
From b7960372c9ea618971dadb585e8dfab2afc425c6 Mon Sep 17 00:00:00 2001
From: Melanie Plageman <melanieplage...@gmail.com>
Date: Tue, 21 Mar 2023 18:20:44 -0400
Subject: [PATCH v9 2/4] FlushRelationBuffers() counts temp relation IO writes
FlushRelationBuffers() seems to have omitted counting write IO stats for
both pgstat_database and pgBufferUsage. Add temporary relation IO blocks
written counts to pgBufferUsage and write IO timing counting to both
pgstat_database and pgBufferUsage.
Reviewed-by: Andres Freund <and...@anarazel.de>
Discussion: https://postgr.es/m/20230321023451.7rzy4kjj2iktrg2r%40awork3.anarazel.de
---
src/backend/storage/buffer/bufmgr.c | 17 +++++++++++++++++
1 file changed, 17 insertions(+)
diff --git a/src/backend/storage/buffer/bufmgr.c b/src/backend/storage/buffer/bufmgr.c
index 908a8934bd..ef69f21adf 100644
--- a/src/backend/storage/buffer/bufmgr.c
+++ b/src/backend/storage/buffer/bufmgr.c
@@ -4062,6 +4062,8 @@ FlushRelationBuffers(Relation rel)
{
int i;
BufferDesc *bufHdr;
+ instr_time io_start,
+ io_time;
if (RelationUsesLocalBuffers(rel))
{
@@ -4087,6 +4089,11 @@ FlushRelationBuffers(Relation rel)
PageSetChecksumInplace(localpage, bufHdr->tag.blockNum);
+ if (track_io_timing)
+ INSTR_TIME_SET_CURRENT(io_start);
+ else
+ INSTR_TIME_SET_ZERO(io_start);
+
smgrwrite(RelationGetSmgr(rel),
BufTagGetForkNum(&bufHdr->tag),
bufHdr->tag.blockNum,
@@ -4098,6 +4105,16 @@ FlushRelationBuffers(Relation rel)
pgstat_count_io_op(IOOBJECT_TEMP_RELATION, IOCONTEXT_NORMAL, IOOP_WRITE);
+ if (track_io_timing)
+ {
+ INSTR_TIME_SET_CURRENT(io_time);
+ INSTR_TIME_SUBTRACT(io_time, io_start);
+ pgstat_count_buffer_write_time(INSTR_TIME_GET_MICROSEC(io_time));
+ INSTR_TIME_ADD(pgBufferUsage.blk_write_time, io_time);
+ }
+
+ pgBufferUsage.local_blks_written++;
+
/* Pop the error context stack */
error_context_stack = errcallback.previous;
}
--
2.37.2
