Re: Be strict when request to flush past end of WAL in WaitXLogInsertionsToFinish

On Tue, Mar 19, 2024 at 04:58:57AM +0000, Jeff Davis wrote:
> I'm not clear on why the callers of WaitXLogInsertionsToFinish() are
> handling errors the way they are. XLogWrite PANICs, XLogFlush ERRORs
> (which is likely to be escalated to a PANIC anyway), and the other
> callers ignore the return value and leave it up to XLogWrite() to
> PANIC.

I hit a production incident on PostgreSQL 15.13 with physical
streaming replication: the primary logged "request to flush past end
of generated WAL" for a position just past a segment boundary, and the
standby then got stuck retrying "record with incorrect prev-link" at
that same position. That led me to the ignored return value in
XLogBackgroundFlush(). In a non-assert build, XLogWrite() does not
necessarily PANIC for this caller.

I reproduced the following sequence on PostgreSQL 15.13 with 1MB WAL
segments:

1. Inject an asyncXactLSN at a segment boundary plus the 40-byte long
page header.
2. WaitXLogInsertionsToFinish() logs "request to flush past end of
generated WAL" and clamps the request to the reserved position.
3. XLogBackgroundFlush() discards that return value. XLogWrite() writes
the initialized WAL buffer page and advertises the original partial
position, so a physical walsender sends only the new page header.
4. If that header overwrites a recycled segment on the standby, the
remaining bytes are stale. Recovery can interpret them as a record
and report an incorrect prev-link. I reproduced the subsequent
five-second retry loop as well.

On current master with assertions enabled, the same injected request
instead fails the Insert >= Write assertion inside XLogWrite(). That
assertion was added in v17 (f3ff7bf83bc) and does not exist in 15, so
the 15.13 build silently proceeds as described above.

The original source of the bogus asyncXactLSN in the production case is
still unknown. The attached patch does not try to explain or hide that
source. It only prevents XLogBackgroundFlush() from discarding a clamp
that has already been made.

The patch uses the return value only when it is smaller than the request.
Assigning it unconditionally would be wrong because, on the normal path,
WaitXLogInsertionsToFinish() can return a position beyond the requested
one. The flush target is clamped together with the write target. The
patch also updates the header comment of WaitXLogInsertionsToFinish(),
which claimed that the return value is always >= 'upto', contradicting
the clamp documented in the function body.

I verified the patch on current master (92819e57945) with the same
injection reproducer, in both assert and non-assert builds. With the
patch, the assert build no longer fails the Insert >= Write assertion,
and the non-assert build's flush position no longer advances past the
end of reserved WAL for this request. Both servers keep running. One
behavior change worth noting: since the bogus asyncXactLSN itself is
not corrected, the existing "request to flush past end of generated
WAL" message now repeats on every walwriter cycle until real WAL
passes that position, whereas before the patch the first cycle
advanced the flush position past the end of reserved WAL and
subsequent cycles were silent. That seems preferable to me: the
repeated message keeps pointing at a corruption that is still there.

The patch applies as-is down to REL_17_STABLE. REL_15_STABLE and
REL_16_STABLE would need adjustments for the older LogwrtResult code
if backpatching is wanted.

Regards,
Paul