Skip to content

Commit 2421e9a

Browse files
michaelpqmichaelpq
committed
Remove read/sync fields from pg_stat_wal and GUC track_wal_io_timing
The four following attributes are removed from pg_stat_wal: * wal_write * wal_sync * wal_write_time * wal_sync_time a051e71 has added an equivalent of this information in pg_stat_io with more granularity as this now spreads across the backend types, IO context and IO objects. So, keeping the same information in pg_stat_wal has little benefits. Another benefit of this commit is the removal of PendingWalStats, simplifying an upcoming patch to add per-backend WAL statistics, which already support IO statistics and which have access to the write/sync stats data of WAL. The GUC track_wal_io_timing, that was used to enable or disable the aggregation of the write and sync timings for WAL, is also removed. pgstat_prepare_io_time() is simplified. Bump catalog version. Bump PGSTAT_FILE_FORMAT_ID, due to the update of PgStat_WalStats. Author: Bertrand Drouvot <bertranddrouvot.pg@gmail.com> Discussion: https://postgr.es/m/Z7RkQ0EfYaqqjgz/@ip-10-97-1-34.eu-west-3.compute.internal
1 parent fc0d0ce commit 2421e9a

File tree

20 files changed

+32
-229
lines changed

20 files changed

+32
-229
lines changed

‎doc/src/sgml/config.sgml

Lines changed: 0 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -8393,28 +8393,6 @@ COPY postgres_log FROM '/full/path/to/logfile.csv' WITH csv;
83938393
</listitem>
83948394
</varlistentry>
83958395

8396-
<varlistentry id="guc-track-wal-io-timing" xreflabel="track_wal_io_timing">
8397-
<term><varname>track_wal_io_timing</varname> (<type>boolean</type>)
8398-
<indexterm>
8399-
<primary><varname>track_wal_io_timing</varname> configuration parameter</primary>
8400-
</indexterm>
8401-
</term>
8402-
<listitem>
8403-
<para>
8404-
Enables timing of WAL I/O calls. This parameter is off by default,
8405-
as it will repeatedly query the operating system for the current time,
8406-
which may cause significant overhead on some platforms.
8407-
You can use the <application>pg_test_timing</application> tool to
8408-
measure the overhead of timing on your system.
8409-
I/O timing information is
8410-
displayed in <link linkend="monitoring-pg-stat-wal-view">
8411-
<structname>pg_stat_wal</structname></link>.
8412-
Only superusers and users with the appropriate <literal>SET</literal>
8413-
privilege can change this setting.
8414-
</para>
8415-
</listitem>
8416-
</varlistentry>
8417-
84188396
<varlistentry id="guc-track-functions" xreflabel="track_functions">
84198397
<term><varname>track_functions</varname> (<type>enum</type>)
84208398
<indexterm>

‎doc/src/sgml/monitoring.sgml

Lines changed: 0 additions & 62 deletions
Original file line numberDiff line numberDiff line change
@@ -183,11 +183,6 @@ postgres 27093 0.0 0.0 30096 2752 ? Ss 11:34 0:00 postgres: ser
183183
of block read, write, extend, and fsync times.
184184
</para>
185185

186-
<para>
187-
The parameter <xref linkend="guc-track-wal-io-timing"/> enables monitoring
188-
of WAL write and fsync times.
189-
</para>
190-
191186
<para>
192187
Normally these parameters are set in <filename>postgresql.conf</filename> so
193188
that they apply to all server processes, but it is possible to turn
@@ -3265,63 +3260,6 @@ description | Waiting for a newly initialized WAL file to reach durable storage
32653260
</para></entry>
32663261
</row>
32673262

3268-
<row>
3269-
<entry role="catalog_table_entry"><para role="column_definition">
3270-
<structfield>wal_write</structfield> <type>bigint</type>
3271-
</para>
3272-
<para>
3273-
Number of times WAL buffers were written out to disk via
3274-
<function>XLogWrite</function> request.
3275-
See <xref linkend="wal-configuration"/> for more information about
3276-
the internal WAL function <function>XLogWrite</function>.
3277-
</para></entry>
3278-
</row>
3279-
3280-
<row>
3281-
<entry role="catalog_table_entry"><para role="column_definition">
3282-
<structfield>wal_sync</structfield> <type>bigint</type>
3283-
</para>
3284-
<para>
3285-
Number of times WAL files were synced to disk via
3286-
<function>issue_xlog_fsync</function> request
3287-
(if <xref linkend="guc-fsync"/> is <literal>on</literal> and
3288-
<xref linkend="guc-wal-sync-method"/> is either
3289-
<literal>fdatasync</literal>, <literal>fsync</literal> or
3290-
<literal>fsync_writethrough</literal>, otherwise zero).
3291-
See <xref linkend="wal-configuration"/> for more information about
3292-
the internal WAL function <function>issue_xlog_fsync</function>.
3293-
</para></entry>
3294-
</row>
3295-
3296-
<row>
3297-
<entry role="catalog_table_entry"><para role="column_definition">
3298-
<structfield>wal_write_time</structfield> <type>double precision</type>
3299-
</para>
3300-
<para>
3301-
Total amount of time spent writing WAL buffers to disk via
3302-
<function>XLogWrite</function> request, in milliseconds
3303-
(if <xref linkend="guc-track-wal-io-timing"/> is enabled,
3304-
otherwise zero). This includes the sync time when
3305-
<varname>wal_sync_method</varname> is either
3306-
<literal>open_datasync</literal> or <literal>open_sync</literal>.
3307-
</para></entry>
3308-
</row>
3309-
3310-
<row>
3311-
<entry role="catalog_table_entry"><para role="column_definition">
3312-
<structfield>wal_sync_time</structfield> <type>double precision</type>
3313-
</para>
3314-
<para>
3315-
Total amount of time spent syncing WAL files to disk via
3316-
<function>issue_xlog_fsync</function> request, in milliseconds
3317-
(if <varname>track_wal_io_timing</varname> is enabled,
3318-
<varname>fsync</varname> is <literal>on</literal>, and
3319-
<varname>wal_sync_method</varname> is either
3320-
<literal>fdatasync</literal>, <literal>fsync</literal> or
3321-
<literal>fsync_writethrough</literal>, otherwise zero).
3322-
</para></entry>
3323-
</row>
3324-
33253263
<row>
33263264
<entry role="catalog_table_entry"><para role="column_definition">
33273265
<structfield>stats_reset</structfield> <type>timestamp with time zone</type>

‎src/backend/access/transam/xlog.c

Lines changed: 6 additions & 36 deletions
Original file line numberDiff line numberDiff line change
@@ -134,7 +134,6 @@ int CommitSiblings = 5; /* # concurrent xacts needed to sleep */
134134
int wal_retrieve_retry_interval = 5000;
135135
int max_slot_wal_keep_size_mb = -1;
136136
int wal_decode_buffer_size = 512 * 1024;
137-
bool track_wal_io_timing = false;
138137

139138
#ifdef WAL_DEBUG
140139
bool XLOG_DEBUG = false;
@@ -2436,10 +2435,9 @@ XLogWrite(XLogwrtRqst WriteRqst, TimeLineID tli, bool flexible)
24362435
errno = 0;
24372436

24382437
/*
2439-
* Measure I/O timing to write WAL data, for pg_stat_io and/or
2440-
* pg_stat_wal.
2438+
* Measure I/O timing to write WAL data, for pg_stat_io.
24412439
*/
2442-
start = pgstat_prepare_io_time(track_io_timing || track_wal_io_timing);
2440+
start = pgstat_prepare_io_time();
24432441

24442442
pgstat_report_wait_start(WAIT_EVENT_WAL_WRITE);
24452443
written = pg_pwrite(openLogFile, from, nleft, startoffset);
@@ -2448,20 +2446,6 @@ XLogWrite(XLogwrtRqst WriteRqst, TimeLineID tli, bool flexible)
24482446
pgstat_count_io_op_time(IOOBJECT_WAL, IOCONTEXT_NORMAL,
24492447
IOOP_WRITE, start, 1, written);
24502448

2451-
/*
2452-
* Increment the I/O timing and the number of times WAL data
2453-
* were written out to disk.
2454-
*/
2455-
if (track_wal_io_timing)
2456-
{
2457-
instr_time end;
2458-
2459-
INSTR_TIME_SET_CURRENT(end);
2460-
INSTR_TIME_ACCUM_DIFF(PendingWalStats.wal_write_time, end, start);
2461-
}
2462-
2463-
PendingWalStats.wal_write++;
2464-
24652449
if (written <= 0)
24662450
{
24672451
char xlogfname[MAXFNAMELEN];
@@ -3264,7 +3248,7 @@ XLogFileInitInternal(XLogSegNo logsegno, TimeLineID logtli,
32643248
errmsg("could not create file \"%s\": %m", tmppath)));
32653249

32663250
/* Measure I/O timing when initializing segment */
3267-
io_start = pgstat_prepare_io_time(track_io_timing);
3251+
io_start = pgstat_prepare_io_time();
32683252

32693253
pgstat_report_wait_start(WAIT_EVENT_WAL_INIT_WRITE);
32703254
save_errno = 0;
@@ -3326,7 +3310,7 @@ XLogFileInitInternal(XLogSegNo logsegno, TimeLineID logtli,
33263310
}
33273311

33283312
/* Measure I/O timing when flushing segment */
3329-
io_start = pgstat_prepare_io_time(track_io_timing);
3313+
io_start = pgstat_prepare_io_time();
33303314

33313315
pgstat_report_wait_start(WAIT_EVENT_WAL_INIT_SYNC);
33323316
if (pg_fsync(fd) != 0)
@@ -8758,10 +8742,9 @@ issue_xlog_fsync(int fd, XLogSegNo segno, TimeLineID tli)
87588742
return;
87598743

87608744
/*
8761-
* Measure I/O timing to sync the WAL file for pg_stat_io and/or
8762-
* pg_stat_wal.
8745+
* Measure I/O timing to sync the WAL file for pg_stat_io.
87638746
*/
8764-
start = pgstat_prepare_io_time(track_io_timing || track_wal_io_timing);
8747+
start = pgstat_prepare_io_time();
87658748

87668749
pgstat_report_wait_start(WAIT_EVENT_WAL_SYNC);
87678750
switch (wal_sync_method)
@@ -8807,21 +8790,8 @@ issue_xlog_fsync(int fd, XLogSegNo segno, TimeLineID tli)
88078790

88088791
pgstat_report_wait_end();
88098792

8810-
/*
8811-
* Increment the I/O timing and the number of times WAL files were synced.
8812-
*/
8813-
if (track_wal_io_timing)
8814-
{
8815-
instr_time end;
8816-
8817-
INSTR_TIME_SET_CURRENT(end);
8818-
INSTR_TIME_ACCUM_DIFF(PendingWalStats.wal_sync_time, end, start);
8819-
}
8820-
88218793
pgstat_count_io_op_time(IOOBJECT_WAL, IOCONTEXT_NORMAL, IOOP_FSYNC,
88228794
start, 1, 0);
8823-
8824-
PendingWalStats.wal_sync++;
88258795
}
88268796

88278797
/*

‎src/backend/access/transam/xlogreader.c

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -1557,7 +1557,7 @@ WALRead(XLogReaderState *state,
15571557

15581558
#ifndef FRONTEND
15591559
/* Measure I/O timing when reading segment */
1560-
io_start = pgstat_prepare_io_time(track_io_timing);
1560+
io_start = pgstat_prepare_io_time();
15611561

15621562
pgstat_report_wait_start(WAIT_EVENT_WAL_READ);
15631563
#endif

‎src/backend/access/transam/xlogrecovery.c

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3401,7 +3401,7 @@ XLogPageRead(XLogReaderState *xlogreader, XLogRecPtr targetPagePtr, int reqLen,
34013401
readOff = targetPageOff;
34023402

34033403
/* Measure I/O timing when reading segment */
3404-
io_start = pgstat_prepare_io_time(track_io_timing);
3404+
io_start = pgstat_prepare_io_time();
34053405

34063406
pgstat_report_wait_start(WAIT_EVENT_WAL_READ);
34073407
r = pg_pread(readFile, readBuf, XLOG_BLCKSZ, (off_t) readOff);

‎src/backend/catalog/system_views.sql

Lines changed: 0 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -1189,10 +1189,6 @@ CREATE VIEW pg_stat_wal AS
11891189
w.wal_fpi,
11901190
w.wal_bytes,
11911191
w.wal_buffers_full,
1192-
w.wal_write,
1193-
w.wal_sync,
1194-
w.wal_write_time,
1195-
w.wal_sync_time,
11961192
w.stats_reset
11971193
FROM pg_stat_get_wal() w;
11981194

‎src/backend/storage/buffer/bufmgr.c

Lines changed: 5 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -1509,7 +1509,7 @@ WaitReadBuffers(ReadBuffersOperation *operation)
15091509
io_pages[io_buffers_len++] = BufferGetBlock(buffers[i]);
15101510
}
15111511

1512-
io_start = pgstat_prepare_io_time(track_io_timing);
1512+
io_start = pgstat_prepare_io_time();
15131513
smgrreadv(operation->smgr, forknum, io_first_block, io_pages, io_buffers_len);
15141514
pgstat_count_io_op_time(io_object, io_context, IOOP_READ, io_start,
15151515
1, io_buffers_len * BLCKSZ);
@@ -2401,7 +2401,7 @@ ExtendBufferedRelShared(BufferManagerRelation bmr,
24012401
}
24022402
}
24032403

2404-
io_start = pgstat_prepare_io_time(track_io_timing);
2404+
io_start = pgstat_prepare_io_time();
24052405

24062406
/*
24072407
* Note: if smgrzeroextend fails, we will end up with buffers that are
@@ -3858,7 +3858,7 @@ FlushBuffer(BufferDesc *buf, SMgrRelation reln, IOObject io_object,
38583858
*/
38593859
bufToWrite = PageSetChecksumCopy((Page) bufBlock, buf->tag.blockNum);
38603860

3861-
io_start = pgstat_prepare_io_time(track_io_timing);
3861+
io_start = pgstat_prepare_io_time();
38623862

38633863
/*
38643864
* bufToWrite is either the shared buffer or a copy, as appropriate.
@@ -4460,7 +4460,7 @@ FlushRelationBuffers(Relation rel)
44604460

44614461
PageSetChecksumInplace(localpage, bufHdr->tag.blockNum);
44624462

4463-
io_start = pgstat_prepare_io_time(track_io_timing);
4463+
io_start = pgstat_prepare_io_time();
44644464

44654465
smgrwrite(srel,
44664466
BufTagGetForkNum(&bufHdr->tag),
@@ -5917,7 +5917,7 @@ IssuePendingWritebacks(WritebackContext *wb_context, IOContext io_context)
59175917
sort_pending_writebacks(wb_context->pending_writebacks,
59185918
wb_context->nr_pending);
59195919

5920-
io_start = pgstat_prepare_io_time(track_io_timing);
5920+
io_start = pgstat_prepare_io_time();
59215921

59225922
/*
59235923
* Coalesce neighbouring writes, but nothing else. For that we iterate

‎src/backend/storage/buffer/localbuf.c

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -244,7 +244,7 @@ GetLocalVictimBuffer(void)
244244

245245
PageSetChecksumInplace(localpage, bufHdr->tag.blockNum);
246246

247-
io_start = pgstat_prepare_io_time(track_io_timing);
247+
io_start = pgstat_prepare_io_time();
248248

249249
/* And write... */
250250
smgrwrite(oreln,
@@ -414,7 +414,7 @@ ExtendBufferedRelLocal(BufferManagerRelation bmr,
414414
}
415415
}
416416

417-
io_start = pgstat_prepare_io_time(track_io_timing);
417+
io_start = pgstat_prepare_io_time();
418418

419419
/* actually extend relation */
420420
smgrzeroextend(bmr.smgr, fork, first_block, extend_by, false);

‎src/backend/storage/smgr/md.c

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1381,7 +1381,7 @@ register_dirty_segment(SMgrRelation reln, ForkNumber forknum, MdfdVec *seg)
13811381
ereport(DEBUG1,
13821382
(errmsg_internal("could not forward fsync request because request queue is full")));
13831383

1384-
io_start = pgstat_prepare_io_time(track_io_timing);
1384+
io_start = pgstat_prepare_io_time();
13851385

13861386
if (FileSync(seg->mdfd_vfd, WAIT_EVENT_DATA_FILE_SYNC) < 0)
13871387
ereport(data_sync_elevel(ERROR),
@@ -1786,7 +1786,7 @@ mdsyncfiletag(const FileTag *ftag, char *path)
17861786
need_to_close = true;
17871787
}
17881788

1789-
io_start = pgstat_prepare_io_time(track_io_timing);
1789+
io_start = pgstat_prepare_io_time();
17901790

17911791
/* Sync the file. */
17921792
result = FileSync(file, WAIT_EVENT_DATA_FILE_SYNC);

‎src/backend/utils/activity/pgstat_io.c

Lines changed: 3 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -83,15 +83,14 @@ pgstat_count_io_op(IOObject io_object, IOContext io_context, IOOp io_op,
8383
}
8484

8585
/*
86-
* Initialize the internal timing for an IO operation, depending on an
87-
* IO timing GUC.
86+
* Initialize the internal timing for an IO operation.
8887
*/
8988
instr_time
90-
pgstat_prepare_io_time(bool track_io_guc)
89+
pgstat_prepare_io_time(void)
9190
{
9291
instr_time io_start;
9392

94-
if (track_io_guc)
93+
if (track_io_timing)
9594
INSTR_TIME_SET_CURRENT(io_start);
9695
else
9796
{

‎src/backend/utils/activity/pgstat_wal.c

Lines changed: 2 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -21,8 +21,6 @@
2121
#include "utils/pgstat_internal.h"
2222

2323

24-
PgStat_PendingWalStats PendingWalStats = {0};
25-
2624
/*
2725
* WAL usage counters saved from pgWalUsage at the previous call to
2826
* pgstat_report_wal(). This is used to calculate how much WAL usage
@@ -118,17 +116,10 @@ pgstat_wal_flush_cb(bool nowait)
118116

119117
#define WALSTAT_ACC(fld, var_to_add) \
120118
(stats_shmem->stats.fld += var_to_add.fld)
121-
#define WALSTAT_ACC_INSTR_TIME(fld) \
122-
(stats_shmem->stats.fld += INSTR_TIME_GET_MICROSEC(PendingWalStats.fld))
123119
WALSTAT_ACC(wal_records, wal_usage_diff);
124120
WALSTAT_ACC(wal_fpi, wal_usage_diff);
125121
WALSTAT_ACC(wal_bytes, wal_usage_diff);
126122
WALSTAT_ACC(wal_buffers_full, wal_usage_diff);
127-
WALSTAT_ACC(wal_write, PendingWalStats);
128-
WALSTAT_ACC(wal_sync, PendingWalStats);
129-
WALSTAT_ACC_INSTR_TIME(wal_write_time);
130-
WALSTAT_ACC_INSTR_TIME(wal_sync_time);
131-
#undef WALSTAT_ACC_INSTR_TIME
132123
#undef WALSTAT_ACC
133124

134125
LWLockRelease(&stats_shmem->lock);
@@ -138,11 +129,6 @@ pgstat_wal_flush_cb(bool nowait)
138129
*/
139130
prevWalUsage = pgWalUsage;
140131

141-
/*
142-
* Clear out the statistics buffer, so it can be re-used.
143-
*/
144-
MemSet(&PendingWalStats, 0, sizeof(PendingWalStats));
145-
146132
return false;
147133
}
148134

@@ -158,18 +144,12 @@ pgstat_wal_init_backend_cb(void)
158144
}
159145

160146
/*
161-
* To determine whether any WAL activity has occurred since last time, not
162-
* only the number of generated WAL records but also the numbers of WAL
163-
* writes and syncs need to be checked. Because even transaction that
164-
* generates no WAL records can write or sync WAL data when flushing the
165-
* data pages.
147+
* To determine whether WAL usage happened.
166148
*/
167149
bool
168150
pgstat_wal_have_pending_cb(void)
169151
{
170-
return pgWalUsage.wal_records != prevWalUsage.wal_records ||
171-
PendingWalStats.wal_write != 0 ||
172-
PendingWalStats.wal_sync != 0;
152+
return pgWalUsage.wal_records != prevWalUsage.wal_records;
173153
}
174154

175155
void

0 commit comments

Comments
 (0)