Move wal_buffers_full to WalUsage (and report it in pgss/explain)

Started by Bertrand Drouvot11 months ago8 messages

bertranddrouvot.pg@gmail.com

11 months ago

3 attachment(s)

Hi hackers,

While working on per-backend WAL statistics ([1]/messages/by-id/Z6M7/zq4vgE4lch2@ip-10-97-1-34.eu-west-3.compute.internal) 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]/messages/by-id/Z6M7/zq4vgE4lch2@ip-10-97-1-34.eu-west-3.compute.internal
- 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]: /messages/by-id/Z6M7/zq4vgE4lch2@ip-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

Attachments:

v1-0001-Move-wal_buffers_full-to-pgWalUsage.patchtext/x-diff; charset=us-asciiDownload

From 2047ee9b06f42bf79b39b87b69a2840fe402a95f Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot.pg@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

v1-0002-Allow-pg_stat_statements-to-track-WAL-buffers-ful.patchtext/x-diff; charset=us-asciiDownload

From a5f4fa5076d36891ae9143e2e05142ff286ebfdf Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot.pg@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

v1-0003-Allow-EXPLAIN-to-track-WAL-buffers-full.patchtext/x-diff; charset=us-asciiDownload

From 20f33d76aa412e3f5c0c6ec422b7c27eb0ae6f89 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot.pg@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

Bertrand Drouvot

bertranddrouvot.pg@gmail.com

11 months ago

In reply to: Bertrand Drouvot (#1)

4 attachment(s)

Re: Move wal_buffers_full to WalUsage (and report it in pgss/explain)

Hi,

On Thu, Feb 06, 2025 at 10:27:17AM +0000, Bertrand Drouvot wrote:

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

While at it, adding 0004 to report wal_buffers_full in VACUUM/ANALYZE (VERBOSE).

Regards,

--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com

Attachments:

v2-0001-Move-wal_buffers_full-to-pgWalUsage.patchtext/x-diff; charset=us-asciiDownload

From 3f7ba865f2d3fe0ab1bd6497fb275d249a486067 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot.pg@gmail.com>
Date: Wed, 5 Feb 2025 13:17:43 +0000
Subject: [PATCH v2 1/4] 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

v2-0002-Allow-pg_stat_statements-to-track-WAL-buffers-ful.patchtext/x-diff; charset=us-asciiDownload

From 5d0345554afc326e6dc5e657694ba3f832b97d7b Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot.pg@gmail.com>
Date: Wed, 5 Feb 2025 15:55:36 +0000
Subject: [PATCH v2 2/4] 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

v2-0003-Allow-EXPLAIN-to-track-WAL-buffers-full.patchtext/x-diff; charset=us-asciiDownload

From e8580d820bdb79d7cb6d17b10cbf9cfa9b447216 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot.pg@gmail.com>
Date: Thu, 6 Feb 2025 08:26:26 +0000
Subject: [PATCH v2 3/4] 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

v2-0004-Add-wal_buffers_full-to-VACUUM-ANALYZE-VERBOSE.patchtext/x-diff; charset=us-asciiDownload

From 44e51d3bcf07c68a5f3e884112de08f2ab399cd2 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot.pg@gmail.com>
Date: Tue, 11 Feb 2025 09:00:00 +0000
Subject: [PATCH v2 4/4] Add wal_buffers_full to VACUUM/ANALYZE (VERBOSE)

Now that wal_buffers_full is part of the WalUsage struct, let's report it in
VACUUM/ANALYZE (VERBOSE) and autovacuum logs.
---
 src/backend/access/heap/vacuumlazy.c | 5 +++--
 src/backend/commands/analyze.c       | 5 +++--
 2 files changed, 6 insertions(+), 4 deletions(-)
  50.0% src/backend/access/heap/
  50.0% src/backend/commands/

diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 075af385cd1..83837ccf9c4 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -845,10 +845,11 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 							 (long long) total_blks_read,
 							 (long long) total_blks_dirtied);
 			appendStringInfo(&buf,
-							 _("WAL usage: %lld records, %lld full page images, %llu bytes\n"),
+							 _("WAL usage: %lld records, %lld full page images, %llu bytes, %lld buffers full\n"),
 							 (long long) walusage.wal_records,
 							 (long long) walusage.wal_fpi,
-							 (unsigned long long) walusage.wal_bytes);
+							 (unsigned long long) walusage.wal_bytes,
+							 (long long) walusage.wal_buffers_full);
 			appendStringInfo(&buf, _("system usage: %s"), pg_rusage_show(&ru0));
 
 			ereport(verbose ? INFO : LOG,
diff --git a/src/backend/commands/analyze.c b/src/backend/commands/analyze.c
index e5ab207d2ec..209eb78176c 100644
--- a/src/backend/commands/analyze.c
+++ b/src/backend/commands/analyze.c
@@ -823,10 +823,11 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
 							 (long long) total_blks_read,
 							 (long long) total_blks_dirtied);
 			appendStringInfo(&buf,
-							 _("WAL usage: %lld records, %lld full page images, %llu bytes\n"),
+							 _("WAL usage: %lld records, %lld full page images, %llu bytes, %lld buffers full\n"),
 							 (long long) walusage.wal_records,
 							 (long long) walusage.wal_fpi,
-							 (unsigned long long) walusage.wal_bytes);
+							 (unsigned long long) walusage.wal_bytes,
+							 (long long) walusage.wal_buffers_full);
 			appendStringInfo(&buf, _("system usage: %s"), pg_rusage_show(&ru0));
 
 			ereport(verbose ? INFO : LOG,
-- 
2.34.1

Ilia Evdokimov

ilya.evdokimov@tantorlabs.com

11 months ago

In reply to: Bertrand Drouvot (#2)

Re: Move wal_buffers_full to WalUsage (and report it in pgss/explain)

Hi,

Thank you for your work!

1. Perhaps In EXPLAIN you forget to check that usage->wal_buffers_full > 0:

if ((usage->wal_records > 0) || (usage->wal_fpi > 0) ||
(usage->wal_bytes > 0))

2. I have a small suggestion for pg_stat_statements: would it make sense
to move wal_buffers_full next to wal_records, wal_fpi and wal_bytes?
This way, all WAL-related information would be grouped together.

--
Best regards,
Ilia Evdokimov,
Tantor Labs LLC.

Bertrand Drouvot

bertranddrouvot.pg@gmail.com

11 months ago

In reply to: Ilia Evdokimov (#3)

Re: Move wal_buffers_full to WalUsage (and report it in pgss/explain)

Hi,

On Tue, Feb 11, 2025 at 03:30:09PM +0300, Ilia Evdokimov wrote:

Hi,

Thank you for your work!

Thanks for the review!

1. Perhaps In EXPLAIN you forget to check that usage->wal_buffers_full > 0:

if ((usage->wal_records > 0) || (usage->wal_fpi > 0) || (usage->wal_bytes >
0))

I don't think that's possible to have wal_buffers_full > 0 if the above returns
false. A check is done at appendStringInfo() time so I think that's ok as it is.

2. I have a small suggestion for pg_stat_statements:ï¿½would it make sense to
move wal_buffers_full next to wal_records, wal_fpi and wal_bytes? This way,
all WAL-related information would be grouped together.

I think I prefer to add it in "append" order. That way, that does not break
queries that rely on ordinal numbers.

Regards,

--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com

Michael Paquier

michael@paquier.xyz

11 months ago

In reply to: Bertrand Drouvot (#4)

Re: Move wal_buffers_full to WalUsage (and report it in pgss/explain)

On Tue, Feb 11, 2025 at 02:05:18PM +0000, Bertrand Drouvot wrote:

2. I have a small suggestion for pg_stat_statements: would it make sense to
move wal_buffers_full next to wal_records, wal_fpi and wal_bytes? This way,
all WAL-related information would be grouped together.

I think I prefer to add it in "append" order. That way, that does not break
queries that rely on ordinal numbers.

Not sure. FWIW, it makes sense to me to group them by "family" in
this case, as they would belong to the same instrument structure.
--
Michael

Michael Paquier

michael@paquier.xyz

11 months ago

In reply to: Bertrand Drouvot (#2)

Re: Move wal_buffers_full to WalUsage (and report it in pgss/explain)

On Tue, Feb 11, 2025 at 09:37:37AM +0000, Bertrand Drouvot wrote:

While at it, adding 0004 to report wal_buffers_full in VACUUM/ANALYZE (VERBOSE).

Thanks for summarizing the history behind WalUsage and
wal_buffers_full. FWIW, 0001 that moves wal_buffers_full from
PgStat_PendingWalStats to WalUsage is going to make our lives much
easier for your pending patch to adds backend statistics for WAL. WAL
write/sync numbers/times will be covered in the backend stats by
pg_stat_io, allowing us to remove entirely the dependency to
PgStat_PendingWalStats.

I have been wondering for a bit if the comment at the top of WalUsage
should be updated, but the current description fits as well with the
follow-up patch series.

Anyway, if there are no objections, I am planning to apply this one to
lift this barrier and help with the follow-up work for the backend
stats. That's the mandatory piece to makes the backend WAL stats
integration easier.

0002, 0003 and 0004 are straight-forward follow-ups. It's IMO one of
these things where extra data is cheap to have access to, and can be
useful to be aware when distributed across multiple contexts like
queries, plans or even EXPLAIN. So no real objections here. If other
have comments, feel free.

show_wal_usage() should have its check on (usage->wal_buffers_full) in
explain.c, as Ilia has mentioned. It's true that you would not get a
(wal_buffers_full > 0) if at least the condition on wal_bytes is not
satisfied, but the addition makes sense on consistency grounds, at
least.

Agreed about the attribute ordering in pgss with everything associated
to WalUsage grouped together, btw.
--
Michael

Bertrand Drouvot

bertranddrouvot.pg@gmail.com

11 months ago

In reply to: Michael Paquier (#6)

4 attachment(s)

Re: Move wal_buffers_full to WalUsage (and report it in pgss/explain)

Hi,

On Fri, Feb 14, 2025 at 03:24:22PM +0900, Michael Paquier wrote:

On Tue, Feb 11, 2025 at 09:37:37AM +0000, Bertrand Drouvot wrote:

While at it, adding 0004 to report wal_buffers_full in VACUUM/ANALYZE (VERBOSE).

Thanks for summarizing the history behind WalUsage and
wal_buffers_full.

Thanks for looking at it.

FWIW, 0001 that moves wal_buffers_full from
PgStat_PendingWalStats to WalUsage is going to make our lives much
easier for your pending patch to adds backend statistics for WAL. WAL
write/sync numbers/times will be covered in the backend stats by
pg_stat_io, allowing us to remove entirely the dependency to
PgStat_PendingWalStats.

Yup.

I have been wondering for a bit if the comment at the top of WalUsage
should be updated, but the current description fits as well with the
follow-up patch series.

Agree that the comment is "still" fine with the extra struct member.

0002, 0003 and 0004 are straight-forward follow-ups. It's IMO one of
these things where extra data is cheap to have access to, and can be
useful to be aware when distributed across multiple contexts like
queries, plans or even EXPLAIN. So no real objections here.

Yeah and that makes the comment at the top of WalUsage accurate ;-)

"
and is displayed by EXPLAIN command, pg_stat_statements extension, etc
"

show_wal_usage() should have its check on (usage->wal_buffers_full) in
explain.c, as Ilia has mentioned. It's true that you would not get a
(wal_buffers_full > 0) if at least the condition on wal_bytes is not
satisfied, but the addition makes sense on consistency grounds, at
least.

I'm thinking the opposite and think that the current check could be simplfied to
"usage->wal_bytes > 0" only. I don't think that wal_records and wal_fpi and
wal_buffers_full can be = 0 if wal_bytes > 0. I don't think that's worth a dedicated
thread and could be done in passing instead of adding the check on wal_buffers_full.

Done that way in the attached (added a comment in the commit message though).

Agreed about the attribute ordering in pgss with everything associated
to WalUsage grouped together, btw.

Ok, you have the majority then and looking at the ordering of the "api_version >="
checks in pg_stat_statements_internal() it looks like it's not the first time
we'd break queries relying on ordinal numbers. Done that way in the attached.
Note that the attached also changes the ordering in the Counters struct (to be
consistent with what 5147ab1dd34a did for example).

Regards,

--
Bertrand Drouvot
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com

Attachments:

v3-0001-Move-wal_buffers_full-to-pgWalUsage.patchtext/x-diff; charset=us-asciiDownload

From 0cd60f0c623f338a3a023064c4245b42a7bf40ec Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot.pg@gmail.com>
Date: Wed, 5 Feb 2025 13:17:43 +0000
Subject: [PATCH v3 1/4] 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 a50fd99d9e5..25a5c605404 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

v3-0002-Allow-pg_stat_statements-to-track-WAL-buffers-ful.patchtext/x-diff; charset=us-asciiDownload

From e07ea0385ad10b7a017b34d4876f06686bb293f2 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot.pg@gmail.com>
Date: Wed, 5 Feb 2025 15:55:36 +0000
Subject: [PATCH v3 2/4] 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          | 8 ++++++--
 doc/src/sgml/pgstatstatements.sgml                       | 9 +++++++++
 4 files changed, 17 insertions(+), 2 deletions(-)
  10.0% contrib/pg_stat_statements/expected/
  56.9% contrib/pg_stat_statements/
  33.0% doc/src/sgml/

diff --git a/contrib/pg_stat_statements/expected/oldextversions.out b/contrib/pg_stat_statements/expected/oldextversions.out
index 0c60fc81274..de679b19711 100644
--- a/contrib/pg_stat_statements/expected/oldextversions.out
+++ b/contrib/pg_stat_statements/expected/oldextversions.out
@@ -385,6 +385,7 @@ AlTER EXTENSION pg_stat_statements UPDATE TO '1.12';
  wal_records                | bigint                   |           |          | 
  wal_fpi                    | bigint                   |           |          | 
  wal_bytes                  | numeric                  |           |          | 
+ wal_buffers_full           | bigint                   |           |          | 
  jit_functions              | bigint                   |           |          | 
  jit_generation_time        | double precision         |           |          | 
  jit_inlining_count         | bigint                   |           |          | 
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..4343d83f0b8 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
@@ -50,6 +50,7 @@ CREATE FUNCTION pg_stat_statements(IN showtext boolean,
     OUT wal_records int8,
     OUT wal_fpi int8,
     OUT wal_bytes numeric,
+    OUT wal_buffers_full int8,
     OUT jit_functions int8,
     OUT jit_generation_time float8,
     OUT jit_inlining_count int8,
diff --git a/contrib/pg_stat_statements/pg_stat_statements.c b/contrib/pg_stat_statements/pg_stat_statements.c
index bebf8134eb0..16e4f642464 100644
--- a/contrib/pg_stat_statements/pg_stat_statements.c
+++ b/contrib/pg_stat_statements/pg_stat_statements.c
@@ -187,6 +187,7 @@ typedef struct Counters
 	int64		wal_records;	/* # of WAL records generated */
 	int64		wal_fpi;		/* # of WAL full page images generated */
 	uint64		wal_bytes;		/* total amount of WAL generated in bytes */
+	int64		wal_buffers_full;	/* # of times the WAL buffers became full */
 	int64		jit_functions;	/* total number of JIT functions emitted */
 	double		jit_generation_time;	/* total time to generate jit code */
 	int64		jit_inlining_count; /* number of times inlining time has been
@@ -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.
@@ -1955,6 +1957,8 @@ pg_stat_statements_internal(FunctionCallInfo fcinfo,
 											Int32GetDatum(-1));
 			values[i++] = wal_bytes;
 		}
+		if (api_version >= PGSS_V1_12)
+			values[i++] = Int64GetDatumFast(tmp.wal_buffers_full);
 		if (api_version >= PGSS_V1_10)
 		{
 			values[i++] = Int64GetDatumFast(tmp.jit_functions);
diff --git a/doc/src/sgml/pgstatstatements.sgml b/doc/src/sgml/pgstatstatements.sgml
index 501b468e9af..e2ac1c2d501 100644
--- a/doc/src/sgml/pgstatstatements.sgml
+++ b/doc/src/sgml/pgstatstatements.sgml
@@ -436,6 +436,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>jit_functions</structfield> <type>bigint</type>
-- 
2.34.1

v3-0003-Allow-EXPLAIN-to-track-WAL-buffers-full.patchtext/x-diff; charset=us-asciiDownload

From a463d37a3112419a95585ed8dcb7c8a45cd04941 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot.pg@gmail.com>
Date: Thu, 6 Feb 2025 08:26:26 +0000
Subject: [PATCH v3 3/4] 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.

In passing, simplifying the test in show_wal_usage() as the other checks in the
original condition can't be true without having wal_bytes > 0.
---
 doc/src/sgml/ref/explain.sgml  | 5 +++--
 src/backend/commands/explain.c | 8 ++++++--
 2 files changed, 9 insertions(+), 4 deletions(-)
  51.9% doc/src/sgml/ref/
  48.0% 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..25a43f9d40a 100644
--- a/src/backend/commands/explain.c
+++ b/src/backend/commands/explain.c
@@ -4241,8 +4241,7 @@ show_wal_usage(ExplainState *es, const WalUsage *usage)
 	if (es->format == EXPLAIN_FORMAT_TEXT)
 	{
 		/* Show only positive counter values. */
-		if ((usage->wal_records > 0) || (usage->wal_fpi > 0) ||
-			(usage->wal_bytes > 0))
+		if (usage->wal_bytes > 0)
 		{
 			ExplainIndentText(es);
 			appendStringInfoString(es->str, "WAL:");
@@ -4256,6 +4255,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 +4269,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

v3-0004-Add-wal_buffers_full-to-VACUUM-ANALYZE-VERBOSE.patchtext/x-diff; charset=us-asciiDownload

From f41617f26672c24ce90d3d80479217146e8cb3d1 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot.pg@gmail.com>
Date: Tue, 11 Feb 2025 09:00:00 +0000
Subject: [PATCH v3 4/4] Add wal_buffers_full to VACUUM/ANALYZE (VERBOSE)

Now that wal_buffers_full is part of the WalUsage struct, let's report it in
VACUUM/ANALYZE (VERBOSE) and autovacuum logs.
---
 src/backend/access/heap/vacuumlazy.c | 5 +++--
 src/backend/commands/analyze.c       | 5 +++--
 2 files changed, 6 insertions(+), 4 deletions(-)
  50.0% src/backend/access/heap/
  50.0% src/backend/commands/

diff --git a/src/backend/access/heap/vacuumlazy.c b/src/backend/access/heap/vacuumlazy.c
index 3df5b92afb8..64517ea5a3a 100644
--- a/src/backend/access/heap/vacuumlazy.c
+++ b/src/backend/access/heap/vacuumlazy.c
@@ -1106,10 +1106,11 @@ heap_vacuum_rel(Relation rel, VacuumParams *params,
 							 (long long) total_blks_read,
 							 (long long) total_blks_dirtied);
 			appendStringInfo(&buf,
-							 _("WAL usage: %lld records, %lld full page images, %llu bytes\n"),
+							 _("WAL usage: %lld records, %lld full page images, %llu bytes, %lld buffers full\n"),
 							 (long long) walusage.wal_records,
 							 (long long) walusage.wal_fpi,
-							 (unsigned long long) walusage.wal_bytes);
+							 (unsigned long long) walusage.wal_bytes,
+							 (long long) walusage.wal_buffers_full);
 			appendStringInfo(&buf, _("system usage: %s"), pg_rusage_show(&ru0));
 
 			ereport(verbose ? INFO : LOG,
diff --git a/src/backend/commands/analyze.c b/src/backend/commands/analyze.c
index e4302f4cdb2..24d4ddc7c5d 100644
--- a/src/backend/commands/analyze.c
+++ b/src/backend/commands/analyze.c
@@ -823,10 +823,11 @@ do_analyze_rel(Relation onerel, VacuumParams *params,
 							 (long long) total_blks_read,
 							 (long long) total_blks_dirtied);
 			appendStringInfo(&buf,
-							 _("WAL usage: %lld records, %lld full page images, %llu bytes\n"),
+							 _("WAL usage: %lld records, %lld full page images, %llu bytes, %lld buffers full\n"),
 							 (long long) walusage.wal_records,
 							 (long long) walusage.wal_fpi,
-							 (unsigned long long) walusage.wal_bytes);
+							 (unsigned long long) walusage.wal_bytes,
+							 (long long) walusage.wal_buffers_full);
 			appendStringInfo(&buf, _("system usage: %s"), pg_rusage_show(&ru0));
 
 			ereport(verbose ? INFO : LOG,
-- 
2.34.1

Michael Paquier

michael@paquier.xyz

11 months ago

In reply to: Michael Paquier (#5)

Re: Move wal_buffers_full to WalUsage (and report it in pgss/explain)

On Fri, Feb 14, 2025 at 03:02:51PM +0900, Michael Paquier wrote:

Not sure. FWIW, it makes sense to me to group them by "family" in
this case, as they would belong to the same instrument structure.

Looked at the full set again, and in the PGSS patch I have finished by
grouping all the WAL fields together, like we do for the rest. In
EXPLAIN, we have other fields that use spaces rather than underscores,
see "actual time" for example, so I've done the same for buffers full.

Nothing much more to say, so I've applied the set. Now let's see what
happens for the WAL stats patch at backend level.
--
Michael