Hi hackers,
While working on per-backend WAL statistics ([1]) it has been discussed to
move wal_buffers_full to WalUsage (It's currently tracked in
PgStat_PendingWalStats).
There is some benefits doing so:
- Simplifies [1]
- Adds the ability to report it in pg_stat_statements (among wal_records,
wal_fpi
and wal_bytes)
- Adds the ability to report it in explain/auto_explain (among wal_records,
wal_fpi
and wal_bytes)
I did a bit of archeology to try to understand why it's not already the
case. From what I can see, in commit time order:
1. df3b181499 introduced the WalUsage structure
2. 6b466bf5f2 added the wal usage in pg_stat_statements
3. 33e05f89c5 added the wal usage in EXPLAIN
4. 8d9a935965f added pg_stat_wal (and wal_buffers_full)
5. 01469241b2f added the wal usage in pg_stat_wal
So, wal_buffers_full has been introduced after the WalUsage structure was
there but I don't see any reason in the emails/threads as to why it's not in the
WalUsage structure.
==== A few thoughts:
About explain:
One could not be 100% sure that the statement being explained is fully
responsible
of the wal buffer being full (as it could just be a "victim" of an already
almost
full wal buffer). But OTOH that might help to understand why an EXPLAIN analyze
is slower than another one (i.e one generating wal buffer full and the other
not).
About pg_stat_statements:
That could also provide valuable information. Say if one can observe that a
statement generates (at least) a WAL buffer full each time it's executed or not.
The later could explain "un-stable" performance for the statement (if WAL buffer
full is not zero).
The former could try to be improved if needed.
=== Patch's structure
The patch series is made of 3 "small" sub-patches:
0001: to move wal_buffers_full to WalUsage
0002: to report wal_buffers_full in pg_stat_statements
0003: to report wal_buffers_full in explain/auto_explain
==== Some remarks:
0002: it doesn't bump the version of pg_stat_statements as the same is done for
this release in commit cf54a2c00254.
0002 and 0003 don't add tests. It looks like there is no existing tests for
wal_buffers_full, reason probably is that it would not be easy to have a stable
and performant test.
[1]:
https://www.postgresql.org/message-id/Z6M7/zq4vgE4lch2%40ip-10-97-1-34.eu-west-3.compute.internal
Looking forward to your feedback,
Regards,
--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
>From 2047ee9b06f42bf79b39b87b69a2840fe402a95f Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot...@gmail.com>
Date: Wed, 5 Feb 2025 13:17:43 +0000
Subject: [PATCH v1 1/3] Move wal_buffers_full to pgWalUsage
Moving wal_buffers_full to pgWalUsage. That simplifies the refactoring needed
in an upcoming commit (to display per-backend WAL statistics). Last but not
least that also open the door to add wal_buffers_full in EXPLAIN and in
pg_stat_statements (all existing pgWalUsage members are reported in the
above).
---
src/backend/access/transam/xlog.c | 2 +-
src/backend/executor/instrument.c | 2 ++
src/backend/utils/activity/pgstat_wal.c | 2 +-
src/include/executor/instrument.h | 1 +
src/include/pgstat.h | 1 -
5 files changed, 5 insertions(+), 3 deletions(-)
19.2% src/backend/access/transam/
30.4% src/backend/executor/
24.1% src/backend/utils/activity/
17.7% src/include/executor/
8.4% src/include/
diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c
index 9c270e7d466..b334f0dd9e6 100644
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -2057,7 +2057,7 @@ AdvanceXLInsertBuffer(XLogRecPtr upto, TimeLineID tli, bool opportunistic)
WriteRqst.Flush = 0;
XLogWrite(WriteRqst, tli, false);
LWLockRelease(WALWriteLock);
- PendingWalStats.wal_buffers_full++;
+ pgWalUsage.wal_buffers_full++;
TRACE_POSTGRESQL_WAL_BUFFER_WRITE_DIRTY_DONE();
}
/* Re-acquire WALBufMappingLock and retry */
diff --git a/src/backend/executor/instrument.c b/src/backend/executor/instrument.c
index 2d3569b3748..56e635f4700 100644
--- a/src/backend/executor/instrument.c
+++ b/src/backend/executor/instrument.c
@@ -280,6 +280,7 @@ WalUsageAdd(WalUsage *dst, WalUsage *add)
dst->wal_bytes += add->wal_bytes;
dst->wal_records += add->wal_records;
dst->wal_fpi += add->wal_fpi;
+ dst->wal_buffers_full += add->wal_buffers_full;
}
void
@@ -288,4 +289,5 @@ WalUsageAccumDiff(WalUsage *dst, const WalUsage *add, const WalUsage *sub)
dst->wal_bytes += add->wal_bytes - sub->wal_bytes;
dst->wal_records += add->wal_records - sub->wal_records;
dst->wal_fpi += add->wal_fpi - sub->wal_fpi;
+ dst->wal_buffers_full += add->wal_buffers_full - sub->wal_buffers_full;
}
diff --git a/src/backend/utils/activity/pgstat_wal.c b/src/backend/utils/activity/pgstat_wal.c
index 18fa6b2936a..c1ca65eb991 100644
--- a/src/backend/utils/activity/pgstat_wal.c
+++ b/src/backend/utils/activity/pgstat_wal.c
@@ -123,7 +123,7 @@ pgstat_wal_flush_cb(bool nowait)
WALSTAT_ACC(wal_records, wal_usage_diff);
WALSTAT_ACC(wal_fpi, wal_usage_diff);
WALSTAT_ACC(wal_bytes, wal_usage_diff);
- WALSTAT_ACC(wal_buffers_full, PendingWalStats);
+ WALSTAT_ACC(wal_buffers_full, wal_usage_diff);
WALSTAT_ACC(wal_write, PendingWalStats);
WALSTAT_ACC(wal_sync, PendingWalStats);
WALSTAT_ACC_INSTR_TIME(wal_write_time);
diff --git a/src/include/executor/instrument.h b/src/include/executor/instrument.h
index 5a6eff75c69..03653ab6c6c 100644
--- a/src/include/executor/instrument.h
+++ b/src/include/executor/instrument.h
@@ -53,6 +53,7 @@ typedef struct WalUsage
int64 wal_records; /* # of WAL records produced */
int64 wal_fpi; /* # of WAL full page images produced */
uint64 wal_bytes; /* size of WAL records produced */
+ int64 wal_buffers_full; /* # of times the WAL buffers became full */
} WalUsage;
/* Flag bits included in InstrAlloc's instrument_options bitmask */
diff --git a/src/include/pgstat.h b/src/include/pgstat.h
index dd823d3f56e..53f2a8458e6 100644
--- a/src/include/pgstat.h
+++ b/src/include/pgstat.h
@@ -495,7 +495,6 @@ typedef struct PgStat_WalStats
*/
typedef struct PgStat_PendingWalStats
{
- PgStat_Counter wal_buffers_full;
PgStat_Counter wal_write;
PgStat_Counter wal_sync;
instr_time wal_write_time;
--
2.34.1
>From a5f4fa5076d36891ae9143e2e05142ff286ebfdf Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot...@gmail.com>
Date: Wed, 5 Feb 2025 15:55:36 +0000
Subject: [PATCH v1 2/3] Allow pg_stat_statements to track WAL buffers full
Now that wal_buffers_full is part of the WalUsage struct, let's report it in
pg_stat_statements.
This commit doesn't bump the version of pg_stat_statements as the same is done
for this release in commit cf54a2c00254.
---
contrib/pg_stat_statements/expected/oldextversions.out | 1 +
.../pg_stat_statements--1.11--1.12.sql | 1 +
contrib/pg_stat_statements/pg_stat_statements.c | 7 +++++--
doc/src/sgml/pgstatstatements.sgml | 9 +++++++++
4 files changed, 16 insertions(+), 2 deletions(-)
10.4% contrib/pg_stat_statements/expected/
55.1% contrib/pg_stat_statements/
34.4% doc/src/sgml/
diff --git a/contrib/pg_stat_statements/expected/oldextversions.out b/contrib/pg_stat_statements/expected/oldextversions.out
index 0c60fc81274..1ff3a053298 100644
--- a/contrib/pg_stat_statements/expected/oldextversions.out
+++ b/contrib/pg_stat_statements/expected/oldextversions.out
@@ -397,6 +397,7 @@ AlTER EXTENSION pg_stat_statements UPDATE TO '1.12';
jit_deform_time | double precision | | |
parallel_workers_to_launch | bigint | | |
parallel_workers_launched | bigint | | |
+ wal_buffers_full | bigint | | |
stats_since | timestamp with time zone | | |
minmax_stats_since | timestamp with time zone | | |
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
index 80e6be25445..1a1ace6c85d 100644
--- 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
@@ -62,6 +62,7 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean,
OUT jit_deform_time float8,
OUT parallel_workers_to_launch int8,
OUT parallel_workers_launched int8,
+ OUT wal_buffers_full int8,
OUT stats_since timestamp with time zone,
OUT minmax_stats_since timestamp with time zone
)
diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c
index bebf8134eb0..8107da02017 100644
--- a/contrib/pg_stat_statements/pg_stat_statements.c
+++ b/contrib/pg_stat_statements/pg_stat_statements.c
@@ -206,6 +206,7 @@ typedef struct Counters
* to be launched */
int64 parallel_workers_launched; /* # of parallel workers actually
* launched */
+ int64 wal_buffers_full; /* # of times the WAL buffers became full */
} Counters;
/*
@@ -1465,6 +1466,7 @@ pgss_store(const char *query, uint64 queryId,
entry->counters.wal_records += walusage->wal_records;
entry->counters.wal_fpi += walusage->wal_fpi;
entry->counters.wal_bytes += walusage->wal_bytes;
+ entry->counters.wal_buffers_full += walusage->wal_buffers_full;
if (jitusage)
{
entry->counters.jit_functions += jitusage->created_functions;
@@ -1557,8 +1559,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 49
-#define PG_STAT_STATEMENTS_COLS_V1_12 51
-#define PG_STAT_STATEMENTS_COLS 51 /* maximum of above */
+#define PG_STAT_STATEMENTS_COLS_V1_12 52
+#define PG_STAT_STATEMENTS_COLS 52 /* maximum of above */
/*
* Retrieve statement statistics.
@@ -1975,6 +1977,7 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
{
values[i++] = Int64GetDatumFast(tmp.parallel_workers_to_launch);
values[i++] = Int64GetDatumFast(tmp.parallel_workers_launched);
+ values[i++] = Int64GetDatumFast(tmp.wal_buffers_full);
}
if (api_version >= PGSS_V1_11)
{
diff --git a/doc/src/sgml/pgstatstatements.sgml b/doc/src/sgml/pgstatstatements.sgml
index 501b468e9af..b73636e6342 100644
--- a/doc/src/sgml/pgstatstatements.sgml
+++ b/doc/src/sgml/pgstatstatements.sgml
@@ -545,6 +545,15 @@
</para></entry>
</row>
+ <row>
+ <entry role="catalog_table_entry"><para role="column_definition">
+ <structfield>wal_buffers_full</structfield> <type>bigint</type>
+ </para>
+ <para>
+ Number of times the WAL buffers became full
+ </para></entry>
+ </row>
+
<row>
<entry role="catalog_table_entry"><para role="column_definition">
<structfield>stats_since</structfield> <type>timestamp with time zone</type>
--
2.34.1
>From 20f33d76aa412e3f5c0c6ec422b7c27eb0ae6f89 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot...@gmail.com>
Date: Thu, 6 Feb 2025 08:26:26 +0000
Subject: [PATCH v1 3/3] Allow EXPLAIN to track WAL buffers full
Now that wal_buffers_full is part of the WalUsage struct, let's report it in
explain/auto_explain when the WAL option/auto_explain.log_wal is enabled.
---
doc/src/sgml/ref/explain.sgml | 5 +++--
src/backend/commands/explain.c | 5 +++++
2 files changed, 8 insertions(+), 2 deletions(-)
61.8% doc/src/sgml/ref/
38.1% src/backend/commands/
diff --git a/doc/src/sgml/ref/explain.sgml b/doc/src/sgml/ref/explain.sgml
index 6361a14e65d..652ece7213a 100644
--- a/doc/src/sgml/ref/explain.sgml
+++ b/doc/src/sgml/ref/explain.sgml
@@ -242,8 +242,9 @@ ROLLBACK;
<listitem>
<para>
Include information on WAL record generation. Specifically, include the
- number of records, number of full page images (fpi) and the amount of WAL
- generated in bytes. In text format, only non-zero values are printed.
+ number of records, number of full page images (fpi), the amount of WAL
+ generated in bytes and the number of times the WAL buffers became full.
+ In text format, only non-zero values are printed.
This parameter may only be used when <literal>ANALYZE</literal> is also
enabled. It defaults to <literal>FALSE</literal>.
</para>
diff --git a/src/backend/commands/explain.c b/src/backend/commands/explain.c
index c24e66f82e1..0512eb49733 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -4256,6 +4256,9 @@ show_wal_usage(ExplainState *es, const WalUsage *usage)
if (usage->wal_bytes > 0)
appendStringInfo(es->str, " bytes=" UINT64_FORMAT,
usage->wal_bytes);
+ if (usage->wal_buffers_full > 0)
+ appendStringInfo(es->str, " buffers_full=%lld",
+ (long long) usage->wal_buffers_full);
appendStringInfoChar(es->str, '\n');
}
}
@@ -4267,6 +4270,8 @@ show_wal_usage(ExplainState *es, const WalUsage *usage)
usage->wal_fpi, es);
ExplainPropertyUInteger("WAL Bytes", NULL,
usage->wal_bytes, es);
+ ExplainPropertyInteger("WAL Buffers Full", NULL,
+ usage->wal_buffers_full, es);
}
}
--
2.34.1
