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
>From 0cd60f0c623f338a3a023064c4245b42a7bf40ec Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot...@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
>From e07ea0385ad10b7a017b34d4876f06686bb293f2 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot...@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
>From a463d37a3112419a95585ed8dcb7c8a45cd04941 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot...@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
>From f41617f26672c24ce90d3d80479217146e8cb3d1 Mon Sep 17 00:00:00 2001
From: Bertrand Drouvot <bertranddrouvot...@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
