Re: Standby stuck after walreceiver restart just before a WAL segment boundary

From: João Rito <joaovictor(dot)rito(at)gmail(dot)com>
To: Srinath Reddy Sadipiralla <srinath2133(at)gmail(dot)com>
Cc: David Shorten <shortenda(at)gmail(dot)com>, pgsql-hackers(at)lists(dot)postgresql(dot)org
Subject: Re: Standby stuck after walreceiver restart just before a WAL segment boundary
Date: 2026-11-10 05:33:37
Message-ID: CADMs5ONEdSH1zeibqD2Lye5us1Gj541Ut9HVYgxunfg2q3M_OA@mail.gmail.com
Views: Whole Thread | Raw Message | Download mbox | Resend email
Thread:
Lists: pgsql-hackers

Hi David,

Thank you for the patch. A standby that stops making progress after a
walreceiver restart is hard to diagnose in the field, and the test
reproduces it reliably.

I reviewed v1 (2026-10-31).

Tested against master c074737f687f604b64f6ee830fccbbe854719823 (2026-11-09),
Debian bookworm container, ./configure --enable-cassert --enable-debug
--enable-tap-tests.

Applying and building
- git apply works cleanly on current master.
- Build is clean, with no compiler warnings.

Tests
- 061_walrcv_restart_segment_boundary.pl without the fix: fails, with tail
gaps of 8, 16 and 24 bytes:
got: '0/05000000'
expected: '0/04000000'
The standby log shows the hang clearly. Startup repeats "invalid record
length at 0/04FFFFF8: expected at least 24, got 0" about 600 times, and
the walreceiver says "requested start point 0/05000000 on timeline 1 is
ahead of the upstream server's flush position 0/04FFFFF8, waiting". The
last bytes of segment 4 are never fetched again.
- 061 with the fix: PASS with tail gaps of 8, 16 and 24, and 3 more runs at
8 (all PASS).
- make -C src/test/recovery check with the fix: 60 files, 693 tests, PASS.

Back branches
- The code part applies cleanly on REL_15_STABLE, REL_16_STABLE,
REL_17_STABLE and REL_18_STABLE.
- The test part fails only on the src/test/recovery/meson.build hunk,
because the test lists differ there. With --exclude='*/meson.build' it
applies on all four.
- On REL_17_STABLE I also ran 061: it fails without the fix (same got
0/05000000, expected 0/04000000), and passes with it.

Comments

1. The fix looks correct to me. RecPtr here is the end of the WAL we need
(targetPagePtr + reqLen from XLogPageRead), and RequestXLogStreaming()
rounds the start point down to the segment start. So when RecPtr is exactly
on a segment boundary, streaming starts in the next segment, and the tail of
the current one is never fetched. Taking the segment of the last needed byte
fixes that. The tli is still taken from tliRecPtr, so the timeline choice
does not change.

2. On Srinath's suggestion to use "ptr = RecPtr - 1": I tried it, and 061
passes with it too. Since RequestXLogStreaming() rounds down to the segment
start anyway, both versions give the same start point. RecPtr - 1 is
shorter. The current version spells out the intent, and the comment explains
it well, so either seems fine to me. If you keep RecPtr - 1, the comment is
still worth keeping.

3. On the test, Srinath suggested truncating the standby's copy of the last
segment by 8 bytes instead of padding with a retry loop. I like the idea of
a deterministic setup, but I am not sure it works as described. WAL segment
files are always full size, and I think a short segment file makes the
standby fail with an error when it reads it, instead of showing the boundary
case. Zeroing the last 8 bytes instead of truncating might work better. I
have not tried either, so this is an open question rather than a request.

4. Small points on the test:
- In all my runs the first attempt of the retry loop worked (no "attempt
N" notes in the logs), so the loop costs nothing in the normal case.
- For back-patching, the meson.build hunk will need adjusting on each
branch.

Verdict: the fix is small and correct as far as I can see, and the test
shows the bug and the fix. Comments 2 to 4 are suggestions only. I think it
is close to Ready for Committer, once you and Srinath agree on the form of
the fix.

Thanks again.

Regards,
Joao Rito

Em ter., 10 de nov. de 2026 às 02:31, Srinath Reddy Sadipiralla
<srinath2133(at)gmail(dot)com> escreveu:
>
> Oops, keyboard slipped! Hit send too early.
>
> On Sat, Oct 31, 2026 at 8:34 AM David Shorten <shortenda(at)gmail(dot)com> wrote:
>>
>> Hello,
>>
>> We've found a bug where a streaming standby gets stuck if its
>> walreceiver restarts
>> while the last record it has received ends 8, 16 or 24 bytes before
>> the end of a WAL segment, so that the next record header reaches the
>> segment boundary. This issue reproduces on current master and the code
>> is the same on all supported branches.
>>
>> To read that header, XLogPageRead() asks WaitForWALToBecomeAvailable()
>> for WAL up to the end of the header, or the end of the page if the
>> header crosses it. Here that is exactly the end of the segment.
>> WaitForWALToBecomeAvailable() passes that end position (RecPtr) to
>> RequestXLogStreaming() as the start point, and RequestXLogStreaming()
>> rounds it down to a segment start. That's a no-op here, so the new
>> walreceiver starts streaming at the next segment and never fetches the
>> end of the current one:
>>
>> LOG: walreceiver requested start point 0/05000000 on timeline 1 is
>> ahead of the upstream server's flush position 0/04FFFFF8, waiting
>> LOG: started streaming WAL from primary at 0/05000000 on timeline 1
>> LOG: invalid record length at 0/04FFFFF8: expected at least 24, got 0
>> [... repeated forever]
>>
>> The attached patch starts streaming at the beginning of the segment
>> holding RecPtr - 1, which is the segment of the page being read, as
>> c06380e976 intended when it switched to RecPtr. Nothing changes unless
>> RecPtr is exactly on a segment boundary. It adds a TAP test,
>> t/061_walrcv_restart_segment_boundary.pl, which pads WAL so that the
>> last record ends 8 bytes before a boundary, restarts the walreceiver by
>> changing primary_conninfo, and checks where streaming restarts. It
>> fails on master without the fix and passes with it; I also checked gaps
>> of 16 and 24 bytes by changing the test. src/test/recovery passes with
>> make and meson.
>
>
> +1, i have reviewed the patch, i think we can simply use
> ptr = RecPtr - 1 instead of the conversions done in WaitForWALToBecomeAvailable
> , I think RequestXLogStreaming will handle those.
>
> Regarding the TAP test, instead of padding WAL to precisely the boundary - 8 and
> relying on a 5-attempt retry loop to remove unwanted WALs like XLOG_RUNNING_XACTS
> to avoid WAL between padding and the walreceiver restart, could we construct this state directly?
> We could generate enough WAL to cross the boundary on the primary, take a basebackup,
> and then truncate the standby's copy of that last WAL segment by 8 bytes before starting the
> replica. This would guarantee the exact starting LSN without the retry loop.
>
>
>>
>> I think it makes sense to backport the fix since it applies to
>> REL_15_STABLE through REL_19_STABLE. REL_14_STABLE
>> has the same code in xlog.c, and I can send a version for it.
>
> +1
>
>
> --
> Thanks :)
> Srinath Reddy Sadipiralla
> EDB: https://www.enterprisedb.com/

In response to

Browse pgsql-hackers by date

  From Date Subject
Next Message Chao Li 2026-11-10 05:40:09 Re: [PATCH] psql: Fix REPACK index completion after a column list
Previous Message Krishna Sarabu 2026-11-10 05:28:18 Avoid redundant BitmapAnd with a clauseless partial index