1
0
mirror of https://github.com/postgres/postgres.git synced 2025-07-31 22:04:40 +03:00

Track total amounts of times spent writing and syncing WAL data to disk.

This commit adds new GUC track_wal_io_timing. When this is enabled,
the total amounts of time XLogWrite writes and issue_xlog_fsync syncs
WAL data to disk are counted in pg_stat_wal. This information would be
useful to check how much WAL write and sync affect the performance.

Enabling track_wal_io_timing will make the server query the operating
system for the current time every time WAL is written or synced,
which may cause significant overhead on some platforms. To avoid such
additional overhead in the server with track_io_timing enabled,
this commit introduces track_wal_io_timing as a separate parameter from
track_io_timing.

Note that WAL write and sync activity by walreceiver has not been tracked yet.

This commit makes the server also track the numbers of times XLogWrite
writes and issue_xlog_fsync syncs WAL data to disk, in pg_stat_wal,
regardless of the setting of track_wal_io_timing. This counters can be
used to calculate the WAL write and sync time per request, for example.

Bump PGSTAT_FILE_FORMAT_ID.

Bump catalog version.

Author: Masahiro Ikeda
Reviewed-By: Japin Li, Hayato Kuroda, Masahiko Sawada, David Johnston, Fujii Masao
Discussion: https://postgr.es/m/0509ad67b585a5b86a83d445dfa75392@oss.nttdata.com
This commit is contained in:
Fujii Masao
2021-03-09 16:52:06 +09:00
parent 9d2d457009
commit ff99918c62
16 changed files with 285 additions and 29 deletions

View File

@ -7450,7 +7450,7 @@ COPY postgres_log FROM '/full/path/to/logfile.csv' WITH csv;
<listitem>
<para>
Enables timing of database I/O calls. This parameter is off by
default, because it will repeatedly query the operating system for
default, as it will repeatedly query the operating system for
the current time, which may cause significant overhead on some
platforms. You can use the <xref linkend="pgtesttiming"/> tool to
measure the overhead of timing on your system.
@ -7464,6 +7464,27 @@ COPY postgres_log FROM '/full/path/to/logfile.csv' WITH csv;
</listitem>
</varlistentry>
<varlistentry id="guc-track-wal-io-timing" xreflabel="track_wal_io_timing">
<term><varname>track_wal_io_timing</varname> (<type>boolean</type>)
<indexterm>
<primary><varname>track_wal_io_timing</varname> configuration parameter</primary>
</indexterm>
</term>
<listitem>
<para>
Enables timing of WAL I/O calls. This parameter is off by default,
as it will repeatedly query the operating system for the current time,
which may cause significant overhead on some platforms.
You can use the <application>pg_test_timing</application> tool to
measure the overhead of timing on your system.
I/O timing information is
displayed in <link linkend="monitoring-pg-stat-wal-view">
<structname>pg_stat_wal</structname></link>. Only superusers can
change this setting.
</para>
</listitem>
</varlistentry>
<varlistentry id="guc-track-functions" xreflabel="track_functions">
<term><varname>track_functions</varname> (<type>enum</type>)
<indexterm>

View File

@ -185,6 +185,11 @@ postgres 27093 0.0 0.0 30096 2752 ? Ss 11:34 0:00 postgres: ser
of block read and write times.
</para>
<para>
The parameter <xref linkend="guc-track-wal-io-timing"/> enables monitoring
of WAL write times.
</para>
<para>
Normally these parameters are set in <filename>postgresql.conf</filename> so
that they apply to all server processes, but it is possible to turn
@ -3477,6 +3482,63 @@ SELECT pid, wait_event_type, wait_event FROM pg_stat_activity WHERE wait_event i
</para></entry>
</row>
<row>
<entry role="catalog_table_entry"><para role="column_definition">
<structfield>wal_write</structfield> <type>bigint</type>
</para>
<para>
Number of times WAL buffers were written out to disk via
<function>XLogWrite</function> request.
See <xref linkend="wal-configuration"/> for more information about
the internal WAL function <function>XLogWrite</function>.
</para></entry>
</row>
<row>
<entry role="catalog_table_entry"><para role="column_definition">
<structfield>wal_sync</structfield> <type>bigint</type>
</para>
<para>
Number of times WAL files were synced to disk via
<function>issue_xlog_fsync</function> request
(if <xref linkend="guc-fsync"/> is <literal>on</literal> and
<xref linkend="guc-wal-sync-method"/> is either
<literal>fdatasync</literal>, <literal>fsync</literal> or
<literal>fsync_writethrough</literal>, otherwise zero).
See <xref linkend="wal-configuration"/> for more information about
the internal WAL function <function>issue_xlog_fsync</function>.
</para></entry>
</row>
<row>
<entry role="catalog_table_entry"><para role="column_definition">
<structfield>wal_write_time</structfield> <type>double precision</type>
</para>
<para>
Total amount of time spent writing WAL buffers to disk via
<function>XLogWrite</function> request, in milliseconds
(if <xref linkend="guc-track-wal-io-timing"/> is enabled,
otherwise zero). This includes the sync time when
<varname>wal_sync_method</varname> is either
<literal>open_datasync</literal> or <literal>open_sync</literal>.
</para></entry>
</row>
<row>
<entry role="catalog_table_entry"><para role="column_definition">
<structfield>wal_sync_time</structfield> <type>double precision</type>
</para>
<para>
Total amount of time spent syncing WAL files to disk via
<function>issue_xlog_fsync</function> request, in milliseconds
(if <varname>track_wal_io_timing</varname> is enabled,
<varname>fsync</varname> is <literal>on</literal>, and
<varname>wal_sync_method</varname> is either
<literal>fdatasync</literal>, <literal>fsync</literal> or
<literal>fsync_writethrough</literal>, otherwise zero).
</para></entry>
</row>
<row>
<entry role="catalog_table_entry"><para role="column_definition">
<structfield>stats_reset</structfield> <type>timestamp with time zone</type>

View File

@ -767,6 +767,35 @@
<acronym>WAL</acronym> call being logged to the server log. This
option might be replaced by a more general mechanism in the future.
</para>
<para>
There are two internal functions to write WAL data to disk:
<function>XLogWrite</function> and <function>issue_xlog_fsync</function>.
When <xref linkend="guc-track-wal-io-timing"/> is enabled, the total
amounts of time <function>XLogWrite</function> writes and
<function>issue_xlog_fsync</function> syncs WAL data to disk are counted as
<literal>wal_write_time</literal> and <literal>wal_sync_time</literal> in
<xref linkend="pg-stat-wal-view"/>, respectively.
<function>XLogWrite</function> is normally called by
<function>XLogInsertRecord</function> (when there is no space for the new
record in WAL buffers), <function>XLogFlush</function> and the WAL writer,
to write WAL buffers to disk and call <function>issue_xlog_fsync</function>.
<function>issue_xlog_fsync</function> is normally called by
<function>XLogWrite</function> to sync WAL files to disk.
If <varname>wal_sync_method</varname> is either
<literal>open_datasync</literal> or <literal>open_sync</literal>,
a write operation in <function>XLogWrite</function> guarantees to sync written
WAL data to disk and <function>issue_xlog_fsync</function> does nothing.
If <varname>wal_sync_method</varname> is either <literal>fdatasync</literal>,
<literal>fsync</literal>, or <literal>fsync_writethrough</literal>,
the write operation moves WAL buffers to kernel cache and
<function>issue_xlog_fsync</function> syncs them to disk. Regardless
of the setting of <varname>track_wal_io_timing</varname>, the numbers
of times <function>XLogWrite</function> writes and
<function>issue_xlog_fsync</function> syncs WAL data to disk are also
counted as <literal>wal_write</literal> and <literal>wal_sync</literal>
in <structname>pg_stat_wal</structname>, respectively.
</para>
</sect1>
<sect1 id="wal-internals">