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();