On Mon, 13 Jul 2026 at 17:26, Nick Ivanov <[email protected]> wrote:
>
> Hello Fabrice,
>
> I'm wondering if you had a chance to reproduce the problem. I'm seeing
> something similar, but not exactly, so I'm curious if this may be another
> manifestation of the error I get.
I threw this at Claude which managed to reproduce the issue, identify
the cause, and has produced a fix.
Here's the report:
A user running 17.7 reported that the walsummarizer process on a standby
logged this, over and over, every 10 seconds, and never made progress:
ERROR: could not read WAL from timeline 6 at 698/460000A0: invalid
record length at 698/460000A0: expected at least 24, got 0
698/460000A0 was the switch point from timeline 6 to timeline 7 (per the
history file); on disk, timeline 6 ends there with a shutdown checkpoint
followed by zeroes. The summarizer on the primary was fine. Restarting it
"fixed" things only in the sense that it jumped forward to the current
timeline and silently left a gap in the summaries, breaking the incremental
backup chain across that range.
I looked into it and believe there are two related problems, both in
src/backend/postmaster/walsummarizer.c.
Root cause
----------
SummarizeWAL() reads WAL up to a horizon, private_data->read_upto. On a
standby that comes from GetLatestLSN(), i.e. the greater of the WAL
receiver's flush position and the replay position. That value can sit
past the last *complete* record on the timeline being read: the flush
pointer can be a little ahead of the last good record, and a timeline
that ends at a switch point is followed by zeroed WAL space.
When the summarizer then reads into that zeroed space, XLogReadRecord()
returns the usual end-of-WAL marker (xl_tot_len == 0), reported as
"invalid record length ... got 0". SummarizeWAL() treats that as a fatal
error rather than as end of WAL, so it errors out, sleeps 10 s, and
retries from GetOldestUnsummarizedLSN() -- which returns the same place,
because nothing advanced. And because unsummarized WAL is pinned on disk
(KeepLogSeg() keeps everything >= GetOldestUnsummarizedLSN()), the
offending segment is retained forever, so the condition cannot clear on
its own. That's the 10-second loop.
The primary never hits this because there GetLatestLSN() is
GetFlushRecPtr(), which is always the end of a complete record on the
current timeline.
Separately, and contributing to the above: when SummarizeWAL() is reading
a *historic* timeline, it still sets read_upto = maximum_lsn (the latest
position on the current timeline), which can be far past where the
historic timeline ended. summarizer_read_local_xlog_page() already clamps
read_upto to the switch point when it *discovers* mid-read that a timeline
has gone historic (that's the case cf8a4898360 dealt with), and the
SummarizeWAL() header comment says maximum_lsn "should be the switch point
when reading a historic timeline" -- but the initial setup doesn't
actually clamp it.
Reproduction
------------
The attached TAP test reproduces it deterministically: stream a standby,
promote it at a chosen LSN to fork a new timeline, then overwrite the tail
of the old timeline with zeroes ahead of its switch point, and turn on
summarize_wal. Without the fix the summarizer loops on the error above and
never advances; with it, the summarizer stops cleanly at the end of valid
WAL. (The zeroing stands in for "the timeline's on-disk WAL ends, in
zeroes, before read_upto" -- which is what happens on the reporter's box,
just arrived at through the standby's position reporting rather than by
hand.)
Proposed fix
------------
0001 clamps read_upto to the switch point when reading a historic
timeline, matching the page-read callback and the documented contract.
0002 makes SummarizeWAL() recognise a zeroed record (xl_tot_len == 0, the
canonical end-of-WAL marker) as end of WAL instead of a hard error: it
ends the current summary there and waits, with backoff, for the situation
to change (more WAL, or a timeline switch that the main loop then
follows). This mirrors how recovery treats the same condition on a
standby. Other invalid records (bad CRC, bad rmid, ...) are still reported
as errors, so genuine corruption isn't masked. 0002 also carries the TAP
test.
Both patches pass the existing pg_walsummary and pg_combinebackup suites
(including 008_promote, incremental backup across a promotion).
Open question
-------------
0002 is really hardening the summarizer against a read horizon that points
past valid WAL. The deeper question -- why a standby's reported flush/
replay position ends up past the real end of a timeline in the first place
-- may deserve a separate look on the recovery side. But the summarizer
should not melt down regardless, and today it does, so I think the
hardening is worthwhile on its own.
</claude>
Patches attached.
Regards
Thom
diff --git src/backend/postmaster/walsummarizer.c src/backend/postmaster/walsummarizer.c
index 4f12eaf2c85..8365fe55788 100644
--- src/backend/postmaster/walsummarizer.c
+++ src/backend/postmaster/walsummarizer.c
@@ -921,7 +921,20 @@ SummarizeWAL(TimeLineID tli, XLogRecPtr start_lsn, bool exact,
private_data = palloc0_object(SummarizerReadLocalXLogPrivate);
private_data->tli = tli;
private_data->historic = XLogRecPtrIsValid(switch_lsn);
- private_data->read_upto = maximum_lsn;
+
+ /*
+ * When reading a historic timeline, we must not read past the point where
+ * it was replaced by a newer timeline, even if the flush/replay position
+ * on the current timeline (maximum_lsn) is much further ahead. Clamp
+ * read_upto to the switch point in that case; this matches what the page
+ * read callback does when it discovers mid-read that the timeline has
+ * become historic, and keeps us from reading into the zeroed tail of a
+ * timeline that ends at a switch point.
+ */
+ if (private_data->historic)
+ private_data->read_upto = switch_lsn;
+ else
+ private_data->read_upto = maximum_lsn;
/* Create xlogreader. */
xlogreader = XLogReaderAllocate(wal_segment_size, NULL,
diff --git src/backend/postmaster/walsummarizer.c src/backend/postmaster/walsummarizer.c
index 8365fe55788..617024f1344 100644
--- src/backend/postmaster/walsummarizer.c
+++ src/backend/postmaster/walsummarizer.c
@@ -173,6 +173,8 @@ static int summarizer_read_local_xlog_page(XLogReaderState *state,
int reqLen,
XLogRecPtr targetRecPtr,
char *cur_page);
+static bool summarizer_reached_end_of_wal(XLogReaderState *xlogreader,
+ TimeLineID tli);
static void summarizer_wait_for_wal(void);
static void MaybeRemoveOldWalSummaries(void);
@@ -878,6 +880,44 @@ ProcessWalSummarizerInterrupts(void)
ProcessLogMemoryContextInterrupt();
}
+/*
+ * Determine whether a failed record read simply means that we've reached the
+ * end of the WAL that has actually been written.
+ *
+ * When XLogReadRecord() fails, it might be because the WAL is genuinely
+ * unreadable, but it might also be because we've caught up with the end of
+ * valid WAL even though read_upto (which is derived from GetLatestLSN())
+ * indicated that more WAL should be available. This is possible on a standby:
+ * the reported flush or replay position can be slightly ahead of the last
+ * complete record, and a timeline that ends at a switch point is followed by
+ * zeroed WAL space.
+ *
+ * The canonical end-of-WAL marker is a record whose xl_tot_len is zero, so we
+ * peek at the failed location and check for that. We deliberately do not treat
+ * other kinds of invalid records (bad CRC, bad resource manager ID, etc.) as
+ * end-of-WAL, so that genuine WAL corruption is still reported as an error.
+ */
+static bool
+summarizer_reached_end_of_wal(XLogReaderState *xlogreader, TimeLineID tli)
+{
+ uint32 xl_tot_len = 0;
+ WALReadError errinfo;
+
+ StaticAssertStmt(offsetof(XLogRecord, xl_tot_len) == 0,
+ "xl_tot_len must be the first field of XLogRecord");
+
+ /*
+ * EndRecPtr is the location of the failed record. Read just its length
+ * field back from WAL; if the whole record header is zeroed, xl_tot_len
+ * will be zero, which is how the end of WAL is represented on disk.
+ */
+ if (!WALRead(xlogreader, (char *) &xl_tot_len, xlogreader->EndRecPtr,
+ sizeof(xl_tot_len), tli, &errinfo))
+ return false;
+
+ return xl_tot_len == 0;
+}
+
/*
* Summarize a range of WAL records on a single timeline.
*
@@ -1058,6 +1098,44 @@ SummarizeWAL(TimeLineID tli, XLogRecPtr start_lsn, bool exact,
summary_end_lsn = private_data->read_upto;
break;
}
+
+ /*
+ * We failed to read a record, but it might just be that we've
+ * reached the end of the WAL that has actually been written, even
+ * though read_upto (derived from GetLatestLSN) suggested that more
+ * WAL should be available. On a standby this can happen: for
+ * example, the flush or replay pointer can momentarily be reported
+ * beyond the last valid record on a timeline that ends in zeroed
+ * space at a timeline switch. See summarizer_reached_end_of_wal().
+ *
+ * If we fail here, we'll sleep and retry forever, and because the
+ * unsummarized WAL is retained on disk (see KeepLogSeg), we'll also
+ * pin that WAL segment permanently. Instead, treat this like
+ * reaching the end of WAL: wait for more WAL so that we don't
+ * busy-loop, stop the current summary here, and let the main loop
+ * re-evaluate. It will back up to the switch point if the timeline
+ * has changed, or resume once more WAL becomes available.
+ */
+ if (summarizer_reached_end_of_wal(xlogreader, tli))
+ {
+ ereport(DEBUG1,
+ errmsg_internal("could not read WAL from timeline %u at %X/%08X: reached end of WAL (read_upto %X/%08X)",
+ tli,
+ LSN_FORMAT_ARGS(xlogreader->EndRecPtr),
+ LSN_FORMAT_ARGS(private_data->read_upto)));
+
+ /*
+ * We made no real progress, so make sure the wait below backs
+ * off rather than busy-looping while we wait for the situation
+ * to change (more WAL to arrive, or a timeline switch).
+ */
+ pages_read_since_last_sleep = 0;
+ ProcessWalSummarizerInterrupts();
+ summarizer_wait_for_wal();
+ summary_end_lsn = xlogreader->EndRecPtr;
+ break;
+ }
+
if (errormsg)
ereport(ERROR,
(errcode_for_file_access(),
diff --git src/bin/pg_walsummary/t/003_end_of_wal.pl src/bin/pg_walsummary/t/003_end_of_wal.pl
new file mode 100644
index 00000000000..9b2a9659d04
--- /dev/null
+++ src/bin/pg_walsummary/t/003_end_of_wal.pl
@@ -0,0 +1,132 @@
+# Copyright (c) 2024-2026, PostgreSQL Global Development Group
+
+# Test that the WAL summarizer does not error out and retry forever when it
+# reaches the end of the valid WAL on a timeline before the point that its read
+# horizon (derived from the reported flush/replay position) suggested was
+# available.
+#
+# This happens on a standby at a timeline switch, where the timeline being
+# summarized ends in zeroed WAL space ahead of the switch point. Before the
+# fix, the summarizer raised "could not read WAL from timeline N ...: invalid
+# record length ...: expected at least 24, got 0" every 10 seconds forever, and
+# because unsummarized WAL is retained on disk, it also pinned that WAL segment
+# permanently.
+
+use strict;
+use warnings FATAL => 'all';
+use PostgreSQL::Test::Cluster;
+use PostgreSQL::Test::Utils;
+use Test::More;
+
+# Get a GUC value from a node, as an integer.
+sub get_int_setting
+{
+ my ($node, $name) = @_;
+ return int(
+ $node->safe_psql(
+ 'postgres', "SELECT setting FROM pg_settings WHERE name = '$name'")
+ );
+}
+
+# Set up a primary. Disabling autovacuum and stretching checkpoint_timeout
+# keeps stray WAL activity from moving the LSNs we capture around. WAL
+# summarization is left off for now, so that no summary files exist for
+# timeline 1 before we are ready.
+my $primary = PostgreSQL::Test::Cluster->new('primary');
+$primary->init(allows_streaming => 1);
+$primary->append_conf(
+ 'postgresql.conf', qq{
+autovacuum = off
+checkpoint_timeout = '1h'
+wal_keep_size = '1GB'
+summarize_wal = off
+});
+$primary->start;
+
+my $segment_size = get_int_setting($primary, 'wal_segment_size');
+
+# Switch to a fresh segment so everything that follows lands in one segment.
+$primary->safe_psql('postgres', "SELECT pg_switch_wal()");
+
+# Take a backup; the standby will stream everything generated after this.
+$primary->backup('backup');
+
+# Emit some WAL. This is the "valid prefix" of timeline 1 that the summarizer
+# will eventually summarize. Non-transactional logical messages give us one
+# WAL record per call with no surrounding commit records.
+$primary->safe_psql('postgres',
+ "SELECT pg_logical_emit_message(false, 'test', repeat('a', 8192)) FROM generate_series(1, 20)"
+);
+
+# X is the record boundary at which we will later truncate timeline 1 to
+# zeroes, so that the timeline's valid WAL ends here.
+my ($x_lsn, $x_bytes) = split m{\|}, $primary->safe_psql('postgres',
+ "SELECT pg_current_wal_insert_lsn(), pg_current_wal_insert_lsn() - '0/0'");
+
+# Emit more WAL beyond X. It is valid WAL on the primary, and the standby will
+# fork its new timeline past X, but we will overwrite it with zeroes on the
+# standby to simulate a timeline that ends in zeroed space before its switch
+# point.
+$primary->safe_psql('postgres',
+ "SELECT pg_logical_emit_message(false, 'test', repeat('b', 8192)) FROM generate_series(1, 20)"
+);
+
+# Y is the switch point: we promote the standby here, safely past X.
+my $y_lsn = $primary->safe_psql('postgres', "SELECT pg_current_wal_insert_lsn()");
+
+# A little more WAL so that recovery can actually reach Y and pause there.
+$primary->safe_psql('postgres',
+ "SELECT pg_logical_emit_message(false, 'test', repeat('c', 8192)) FROM generate_series(1, 10)"
+);
+
+# Bring up a standby that streams from the primary and pauses replay at Y.
+my $standby = PostgreSQL::Test::Cluster->new('standby');
+$standby->init_from_backup($primary, 'backup', has_streaming => 1);
+$standby->append_conf(
+ 'postgresql.conf', qq{
+recovery_target_lsn = '$y_lsn'
+recovery_target_action = 'pause'
+summarize_wal = off
+});
+$standby->start;
+
+# Wait until replay pauses at Y, then promote to fork timeline 2 at Y.
+$standby->poll_query_until('postgres',
+ "SELECT pg_get_wal_replay_pause_state() = 'paused'")
+ or die "timed out waiting for recovery to pause";
+$standby->safe_psql('postgres', "SELECT pg_promote()");
+$standby->poll_query_until('postgres', "SELECT NOT pg_is_in_recovery()")
+ or die "timed out waiting for promotion";
+
+# Overwrite timeline 1 from X to the end of X's segment with zeroes, so that
+# timeline 1's on-disk WAL ends (in zeroed space) at X, well before its switch
+# point Y.
+$standby->stop('fast');
+my $zero_length = $segment_size - ($x_bytes % $segment_size);
+$standby->write_wal(1, $x_bytes, $segment_size, "\x00" x $zero_length);
+
+# Turn on WAL summarization and start the node (now the primary of timeline 2).
+# The summarizer will read historic timeline 1 and reach the zeroed tail at X
+# while its read horizon is still Y, which is greater than X.
+my $log_offset = -s $standby->logfile;
+$standby->append_conf('postgresql.conf', 'summarize_wal = on');
+$standby->start;
+
+# With the fix, the summarizer treats X as the end of WAL, summarizes timeline 1
+# up to X, and stops there cleanly. Without the fix, it errors out and retries
+# forever, so it never reaches X and this poll times out.
+my $reached = $standby->poll_query_until(
+ 'postgres', qq{
+SELECT summarized_tli = 1 AND summarized_lsn = '$x_lsn'::pg_lsn
+FROM pg_get_wal_summarizer_state()
+});
+ok($reached, "summarizer stopped cleanly at end of valid WAL on timeline 1");
+
+# And it must not have raised the end-of-WAL read error. Check only the log
+# written since we turned summarization on.
+ok( !$standby->log_contains(
+ 'could not read WAL from timeline 1 .*: invalid record length',
+ $log_offset),
+ "no spurious end-of-WAL read error from summarizer");
+
+done_testing();
