Re: Be strict when request to flush past end of WAL in WaitXLogInsertionsToFinish
Re: Be strict when request to flush past end of WAL in WaitXLogInsertionsToFinish
От:
Paul Kim <mok03127@gmail.com>
Дата:
On Wed, Sep 03, 2026 at 11:04:39AM +0900, Michael Paquier wrote: > On Wed, Sep 02, 2026 at 06:13:26PM -0700, Bharath Rupireddy wrote: >> Nice! Do you mind adding the reproducer as a TAP test for HEAD? > > I'm assuming that it should be possible to use an injection points > based on the fact that we would be up and running for the inserts. Thanks, both. Attached is v2: 0001 is the fix, unchanged from v1, and 0002 adds the reproducer as a TAP test on HEAD. The test adds a small module, src/test/modules/test_walwriter, with one C function that requests a segment switch and then stores the resulting insert position in asyncXactLSN. After a switch that position is just past the new segment's long page header, beyond the end of generated WAL, so the walwriter's next cycle requests a flush past the end of generated WAL -- the same shape as the production request. I did look at injection points first, but there is no INJECTION_POINT() in this path, and what the reproducer needs is a bogus value stored into asyncXactLSN rather than a backend stopped at a particular point, which would require a custom callback and hence a test module anyway. A plain test module also keeps the test runnable in builds without injection point support. The timing side needs no help: with the test's wal_writer_flush_after = 0, XLogSetAsyncXactLSN() wakes the walwriter, which picks the value up on its next cycle, so the test just waits for the existing "request to flush past end of generated WAL" message to show up in the log. After that message, the test checks that the advertised flush position is still below the bogus request, that no child process was terminated, and that normal WAL activity afterwards gets past that position. On unpatched HEAD the test fails in both assert and production builds: XLogWrite() hits its "xlog write request ... is past end of log" PANIC and the walwriter's crash takes the server down (TAP clusters run with restart_after_crash = off). (Which sanity check fires first depends on the WAL buffer state; with 1MB segments I had seen the Insert >= Write assertion instead.) With 0001 applied, both build types pass the test. Regards, Paul
Re: Be strict when request to flush past end of WAL in WaitXLogInsertionsToFinish
От:
Paul Kim <mok03127@gmail.com>
Дата:
The cfbot's Linux 32-bit task failed on v3: the TAP test's padding loop raised "could not align the insert position". The loop computed the exact-fill payload as (gap - base), with base measured from a message with an empty payload. Once the payload exceeds the short data header's range, the record switches to the long data header, which is 3 bytes larger. With 8-byte MAXALIGN those extra bytes disappear into alignment padding and the fill still lands exactly on the target, but with 4-byte MAXALIGN they round up to a 4-byte overshoot, so on 32-bit builds every attempt missed the window and the loop gave up. Here is v4, which approaches the target in small steps once the gap falls below base + 200 bytes, so the final exact-fill record always keeps the short data header. While at it, the window-hit check no longer hardcodes SizeOfXLogLongPHD as 40 bytes (36 on 32-bit): a normal switch reports the segment boundary itself and only the overridden EndPos lies past it, so any nonzero offset into the new segment marks the hit. No changes to the fix; 0001 is identical to v3. Regards, Paul Kim
Re: Be strict when request to flush past end of WAL in WaitXLogInsertionsToFinish
От:
Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
Дата:
Hi,
On Thu, Sep 3, 2026 at 6:29 PM Paul Kim wrote:
>
> > Just curious, how did the bogus LSN end up in asyncXactLSN in
> > production when you hit the issue?
>
> Honestly, we still don't know, but the value itself is telling.
>
> The production request was exactly segment boundary + 0x28, i.e.
> SizeOfXLogLongPHD past a segment start. That is precisely what the
> current insert position looks like right after a segment switch,
> before any record has been written into the new segment. So it does
> not look like random corruption; it looks like something captured the
> insert position at that moment and handed it to XLogSetAsyncXactLSN().
> That is also how the TAP test's injector reproduces the incident
> byte-for-byte.
>
> I went looking for an in-core path that could do this naturally on the
> affected version and came up empty: fault-free segment switches
> (~100 runs), async commits, LogStandbySnapshot() calls, and top-level
> aborts never produced the "past end of generated WAL" warning in my
> testing. The affected installation does load third-party preload
> libraries; auditing those for WAL-related symbol use is on my list but
> has not been done yet, so I cannot rule the source in or out.
>
> Either way, I think the fix stands on its own: whatever plants the
> value, WaitXLogInsertionsToFinish() already detects and clamps it, and
> XLogBackgroundFlush() discarding that clamp is what turns one bad
> request into the standby's prev-link retry loop.
Thanks for the patches. I don't see a CF entry yet, so I created one:
https://commitfest.postgresql.org/patch/7294/. Feel free to add
yourself as an author.
I went through this thread today. Here's my take.
What exactly caused the wait-for-any-in-progress-insertions-to-finish
to receive an LSN past the end of the generated WAL is one problem.
And, when that happens for whatever reason, the walwriter not honoring
the adjusted position in the caller and blindly writing such WAL to
WAL files is another problem.
In this case, although we don't yet know the root cause for the first
problem, which could be not necessarily the async commit/abort LSN
being wrong but could be anyone else setting up an LSN beyond what's
written in XLogCtl->LogwrtRqst, I think fixing the second problem is
the right direction (as the patch does here). The backend doing WAL
write already honors the adjusted position, so the walwriter missing
it needs to be fixed too. If the backend gets to write the WAL before
the walwriter, it would not have written this WAL record because
wait-for-any-in-progress-insertions-to-finish in XLogFlush() honors
the adjusted position. This matters because the consequences on the
standby are hard to deal with in production, stuck WAL replay, vacuum
issues on the primary, and possibly failovers.
If I understand correctly, you identified that the walwriter is the
problem by looking at the pid from the "request to flush past end of
generated WAL" log message, right? Nice find.
Also, I'm curious, how did the standby get out of the stuck error loop
"record with incorrect prev-link"?
Also, did you observe any "xlog flush request %X/%08X is not satisfied
--- flushed only to" or other messages on the primary? And I believe
if the primary had crashed before checkpointing this WAL record, it
would have also been stuck in a similar error loop, right?
A few comments on the patch.
1/ Nit. How about using "adjusted" instead of "clamped" in the
comments and commit message?
+ * if 'upto' is past the end of reserved WAL, the request is clamped to the
+ /* honor the clamp if the request was past the end of reserved WAL */
WaitXLogInsertionsToFinish() clamps a request that is past the end of
2/ Why do we need to check the adjusted LSN against the requested LSN
again? Also, is there a reason to compare it with the flush LSN? Why
not just assign the adjusted LSNs like XLogFlush() does?
+ /* honor the clamp if the request was past the end of reserved WAL */
+ if (insertpos < WriteRqst.Write)
+ {
+ WriteRqst.Write = insertpos;
+ if (WriteRqst.Flush > insertpos)
+ WriteRqst.Flush = insertpos;
+ }
3/ Do we need similar adjusted handling in AdvanceXLInsertBuffer()? I
don't think so because there the whole old page from the WAL buffer is
written anyway. Just want to clarify.
--
Bharath Rupireddy
Amazon Web Services: https://aws.amazon.com
Be strict when request to flush past end of WAL in WaitXLogInsertionsToFinish
От:
Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
Дата:
Hi,
While working on [1], it was identified that
WaitXLogInsertionsToFinish emits a LOG message, and adjusts the upto
ptr to proceed further when caller requests to flush past the end of
generated WAL. There's a comment explaining no caller should ever do
that intentionally except in cases with bogus LSNs. For a similar
situation, XLogWrite emits a PANIC "xlog write request %X/%X is past
end of log %X/%X". Although there's no problem if
WaitXLogInsertionsToFinish emits LOG, but why can't it be a bit more
harsh and emit PANIC something like the attached to detect the corner
case?
Thoughts?
[1] https://www.postgresql.org/message-id/b43615437ac7d7fdef86a36e5d5bf3fc049bc11b.camel%40j-davis.com
On Thu, Feb 22, 2024 at 1:54 AM Jeff Davis wrote:
>
> WaitXLogInsertionsToFinish() uses a LOG level message
> for the same situation. They should probably be the same log level, and
> I would think it would be either PANIC or WARNING. I have no idea why
> LOG was chosen.
[2]
/*
* No-one should request to flush a piece of WAL that hasn't even been
* reserved yet. However, it can happen if there is a block with a bogus
* LSN on disk, for example. XLogFlush checks for that situation and
* complains, but only after the flush. Here we just assume that to mean
* that all WAL that has been reserved needs to be finished. In this
* corner-case, the return value can be smaller than 'upto' argument.
*/
if (upto > reservedUpto)
{
ereport(LOG,
(errmsg("request to flush past end of generated WAL;
request %X/%X, current position %X/%X",
LSN_FORMAT_ARGS(upto), LSN_FORMAT_ARGS(reservedUpto))));
upto = reservedUpto;
}
--
Bharath Rupireddy
PostgreSQL Contributors Team
RDS Open Source Databases
Amazon Web Services: https://aws.amazon.com
Re: Be strict when request to flush past end of WAL in WaitXLogInsertionsToFinish
От:
Bharath Rupireddy <bharath.rupireddyforpostgres@gmail.com>
Дата:
Hi, On Thu, Sep 3, 2026 at 5:05 PM Paul Kim wrote: > > Thanks, both. Attached is v2: 0001 is the fix, unchanged from v1, and > 0002 adds the reproducer as a TAP test on HEAD. > > The test adds a small module, src/test/modules/test_walwriter, with one > C function that requests a segment switch and then stores the resulting > insert position in asyncXactLSN. After a switch that position is just > past the new segment's long page header, beyond the end of generated > WAL, so the walwriter's next cycle requests a flush past the end of > generated WAL -- the same shape as the production request. > > I did look at injection points first, but there is no INJECTION_POINT() > in this path, and what the reproducer needs is a bogus value stored > into asyncXactLSN rather than a backend stopped at a particular point, > which would require a custom callback and hence a test module anyway. Thanks for the v2 patches. Just curious, how did the bogus LSN end up in asyncXactLSN in production when you hit the issue? -- Bharath Rupireddy Amazon Web Services: https://aws.amazon.com
Re: Be strict when request to flush past end of WAL in WaitXLogInsertionsToFinish
От:
Jeff Davis <pgsql@j-davis.com>
Дата:
On Fri, 2024-03-15 at 13:12 +0530, Bharath Rupireddy wrote: > Hi, > > While working on [1], it was identified that > WaitXLogInsertionsToFinish emits a LOG message, and adjusts the upto > ptr to proceed further when caller requests to flush past the end of > generated WAL. There's a comment explaining no caller should ever do > that intentionally except in cases with bogus LSNs. For a similar > situation, XLogWrite emits a PANIC "xlog write request %X/%X is past > end of log %X/%X". Although there's no problem if > WaitXLogInsertionsToFinish emits LOG, but why can't it be a bit more > harsh and emit PANIC something like the attached to detect the corner > case? > > Thoughts? 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. As far as I can tell, once WaitXLogInsertionsToFinish() detects this bogus LSN, a PANIC is a likely outcome, so your proposed change makes sense. But then why are the callers also checking? I haven't looked in a lot of detail. Regards, Jeff Davis
