From 3247f796350791b9b2fcf48ec9360e2ef2bb4140 Mon Sep 17 00:00:00 2001 From: Bertrand Drouvot Date: Tue, 9 Jun 2026 09:54:28 +0000 Subject: [PATCH v2 2/4] Add injection-point test for logical decoding timeline race during promotion Add an injection point "promotion-after-wal-segment-cleanup" in StartupXLOG(), right after CleanupAfterArchiveRecovery() removes old timeline WAL segments but before SharedRecoveryState is set to RECOVERY_STATE_DONE. Add a test in 035_standby_logical_decoding.pl that uses this injection point to deterministically reproduce the race condition where a walsender doing logical decoding would pick the old timeline after segment removal, resulting in: ERROR: requested WAL segment ... has already been removed The test pauses the startup process at the injection point, starts pg_recvlogical (whose walsender must read WAL from the removed segment), verifies decoding succeeds while startup is still paused, then resumes promotion. Author: Bertrand Drouvot Reviewed-by: Xuneng Zhou Reviewed-by: Hayato Kuroda Discussion: https://postgr.es/m/7daef094-abf3-4672-bc23-3df4763b16a3%40gmail.com --- src/backend/access/transam/xlog.c | 2 + .../t/035_standby_logical_decoding.pl | 74 +++++++++++++++++++ 2 files changed, 76 insertions(+) 97.8% src/test/recovery/t/ diff --git a/src/backend/access/transam/xlog.c b/src/backend/access/transam/xlog.c index d69d03b2ef3..6c2304fef33 100644 --- a/src/backend/access/transam/xlog.c +++ b/src/backend/access/transam/xlog.c @@ -6571,6 +6571,8 @@ StartupXLOG(void) if (ArchiveRecoveryRequested) CleanupAfterArchiveRecovery(EndOfLogTLI, EndOfLog, newTLI); + INJECTION_POINT("promotion-after-wal-segment-cleanup", NULL); + /* * Local WAL inserts enabled, so it's time to finish initialization of * commit timestamp. diff --git a/src/test/recovery/t/035_standby_logical_decoding.pl b/src/test/recovery/t/035_standby_logical_decoding.pl index 4421059f100..9b45c819241 100644 --- a/src/test/recovery/t/035_standby_logical_decoding.pl +++ b/src/test/recovery/t/035_standby_logical_decoding.pl @@ -1060,4 +1060,78 @@ is($cascading_stdout, $expected, 'got same expected output from pg_recvlogical decoding session on cascading standby' ); +################################################## +# Test that logical decoding on standby correctly handles the timeline +# change during promotion. There is a window during promotion where +# RecoveryInProgress() still returns true but old timeline WAL segments +# have already been removed. Verify the walsender uses the correct +# timeline in this window. +################################################## + +# Create a logical slot on the cascading standby for this test. +$node_cascading_standby->create_logical_slot_on_standby($node_standby, + 'race_slot', 'testdb'); + +# Insert data so the slot has WAL to decode. +$node_standby->safe_psql('testdb', + qq[INSERT INTO decoding_test(x,y) SELECT s, s::text FROM generate_series(10,13) s;] +); +$node_standby->wait_for_replay_catchup($node_cascading_standby); + +$expected = q{BEGIN +table public.decoding_test: INSERT: x[integer]:10 y[text]:'10' +table public.decoding_test: INSERT: x[integer]:11 y[text]:'11' +table public.decoding_test: INSERT: x[integer]:12 y[text]:'12' +table public.decoding_test: INSERT: x[integer]:13 y[text]:'13' +COMMIT}; + +# Create the injection_points extension on the cascading standby. +$node_standby->safe_psql('testdb', 'CREATE EXTENSION injection_points;'); +$node_standby->wait_for_replay_catchup($node_cascading_standby); + +# Attach injection point to pause startup after WAL segment cleanup +# but before RecoveryInProgress() flips to false. +$node_cascading_standby->safe_psql('testdb', + "SELECT injection_points_attach('promotion-after-wal-segment-cleanup', 'wait');" +); + +# Promote with no-wait so we can synchronize with the injection point. +$node_cascading_standby->safe_psql('testdb', "SELECT pg_promote(false)"); + +# Wait for startup to pause after removing old timeline WAL segments. +$node_cascading_standby->wait_for_event('startup', + 'promotion-after-wal-segment-cleanup'); + +# Start pg_recvlogical. +my ($stdout2, $stderr2); +my $handle2 = IPC::Run::start( + [ + 'pg_recvlogical', + '--dbname' => $node_cascading_standby->connstr('testdb'), + '--slot' => 'race_slot', + '--option' => 'include-xids=0', + '--option' => 'skip-empty-xacts=1', + '--file' => '-', + '--no-loop', + '--start', + ], + '>' => \$stdout2, + '2>' => \$stderr2, + IPC::Run::timeout($default_timeout)); + +# Verify pg_recvlogical successfully decodes the data while startup is still +# paused. This proves the walsender went through logical_read_xlog_page() +# and selected the correct timeline in the race window. +$pump_timeout = IPC::Run::timer($default_timeout); +ok( pump_until($handle2, $pump_timeout, \$stdout2, qr/COMMIT/s), + 'pg_recvlogical works during promotion timeline switch'); +chomp($stdout2); +is($stdout2, $expected, + 'got expected output from pg_recvlogical during promotion timeline switch' +); + +# Resume promotion. +$node_cascading_standby->safe_psql('testdb', + "SELECT injection_points_wakeup('promotion-after-wal-segment-cleanup');"); + done_testing(); -- 2.34.1