test: avoid redundant standby catchup in 049_wait_for_lsn

Started by Xuneng Zhou6 months ago17 messageshackers
Beta feature

Hackorum builds and tests every patch posted to the lists, not only commitfest submissions. This is Hackorum's own CI rather than the PostgreSQL project's, and it is still under testing - please report anything that looks wrong.

never appliedCI history

You can run a PostgreSQL built from this patch straight from Docker, with no checkout and no build:

docker run --rm -p 5432:5432 ghcr.io/hackorum-dev/postgres-patch:t139363
psql -h localhost -U postgres

This image is from patchset v9 (message #9) - the current patchset v10 (message #10) has not produced an image.

Jump to latest
#1Xuneng Zhou
xunengzhou@gmail.com

Hi Alexander, Hackers,

While working on adding more edge-case tests and fixing the timeline
handling for WAIT FOR LSN, I noticed that the overall runtime of the
test had increased by about 7 seconds since a8b61c23c5ff. I looked
into the slowdown and found a potential source.

Currently, the test creates the function, waits for the standby to
catch up, tests it, then creates the procedure and waits for the
standby to catch up again. Since both objects are only used by the
same block of top-level statement checks, we can create them together
in a single primary-side transaction and perform just one
wait_for_catchup() before running both standby-side calls.

This small TAP cleanup merges the creation of the PL/pgSQL wrapper
function and procedure used for the top-level WAIT FOR checks in
049_wait_for_lsn.pl.

The change preserves the same coverage while removing one redundant
replay catch-up on the delayed standby. It appears to reduce the test
runtime by about 7 seconds, though I have looked into why much of the
improvement comes from this change alone.

Patch attached.

Thanks.
--
Best,
Xuneng

Attachments:

v1-0001-test-merge-wrapper-DDL-and-catchup-in-wait_for_ls.patchapplication/x-patch; name=v1-0001-test-merge-wrapper-DDL-and-catchup-in-wait_for_ls.patchDownload+7-12
#2Michael Paquier
michael@paquier.xyz
In reply to: Xuneng Zhou (#1)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

On Fri, Apr 17, 2026 at 08:25:35PM +0800, Xuneng Zhou wrote:

The change preserves the same coverage while removing one redundant
replay catch-up on the delayed standby. It appears to reduce the test
runtime by about 7 seconds, though I have looked into why much of the
improvement comes from this change alone.

Alexander may think differently and remove that, but I disagree. The
test is clearly written so as we want two wait checks to happen, for
for CREATE FUNCTION, and one for CREATE PROCEDURE. Removing the first
check to keep only the second one removes its meaning. In short, I
see nothing wrong to deal with here.
--
Michael

#3Xuneng Zhou
xunengzhou@gmail.com
In reply to: Michael Paquier (#2)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

Hi Michael,

On Fri, Apr 17, 2026 at 08:25:35PM +0800, Xuneng Zhou wrote:

The change preserves the same coverage while removing one redundant
replay catch-up on the delayed standby. It appears to reduce the test
runtime by about 7 seconds, though I have looked into why much of the
improvement comes from this change alone.

Alexander may think differently and remove that, but I disagree. The
test is clearly written so as we want two wait checks to happen, for
for CREATE FUNCTION, and one for CREATE PROCEDURE. Removing the first
check to keep only the second one removes its meaning. In short, I
see nothing wrong to deal with here.

Thank you for the review. I agree that the two wait checks serve distinct
purposes and are not redundant. The main motivation for this patch was
efficiency. In my testing, the new test added approximately 7 seconds to
the runtime, while the creation of the procedure and function completed
quickly. I suspect the latency stems from the wait-for-catch-up step. When
I removed it, the test runtime dropped by about 7 seconds.I haven't yet
investigated why the wait is so costly in this case. I should probably look
into that before proposing this change.

Best,
Xuneng

Show quoted text
#4Alexander Korotkov
aekorotkov@gmail.com
In reply to: Xuneng Zhou (#3)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

Hi, Xuneng.

On Sat, Apr 18, 2026 at 7:20 AM Xuneng Zhou <xunengzhou@gmail.com> wrote:

On Fri, Apr 17, 2026 at 08:25:35PM +0800, Xuneng Zhou wrote:

The change preserves the same coverage while removing one redundant
replay catch-up on the delayed standby. It appears to reduce the test
runtime by about 7 seconds, though I have looked into why much of the
improvement comes from this change alone.

Alexander may think differently and remove that, but I disagree. The
test is clearly written so as we want two wait checks to happen, for
for CREATE FUNCTION, and one for CREATE PROCEDURE. Removing the first
check to keep only the second one removes its meaning. In short, I
see nothing wrong to deal with here.

Thank you for the review. I agree that the two wait checks serve distinct purposes and are not redundant. The main motivation for this patch was efficiency. In my testing, the new test added approximately 7 seconds to the runtime, while the creation of the procedure and function completed quickly. I suspect the latency stems from the wait-for-catch-up step. When I removed it, the test runtime dropped by about 7 seconds.I haven't yet investigated why the wait is so costly in this case. I should probably look into that before proposing this change.

On my laptop the time needed to run t/049_wait_for_lsn.pl also drops
from 20 secs to 12 secs. The influence to the runtime of the whole
test suite in parallel would be not that big as CPU time only drops
from 2.16 sec to 2.07 sec. But anyway that's pretty significant.
I've revised comment message a bit and surrounding comments. I'm
going to push this if no objections.

------
Regards,
Alexander Korotkov
Supabase

Attachments:

v2-0001-049_wait_for_lsn.pl-create-function-and-procedure.patchapplication/octet-stream; name=v2-0001-049_wait_for_lsn.pl-create-function-and-procedure.patchDownload+11-14
#5Alexander Korotkov
aekorotkov@gmail.com
In reply to: Michael Paquier (#2)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

Hi, Michael!

On Sat, Apr 18, 2026 at 12:47 AM Michael Paquier <michael@paquier.xyz> wrote:

On Fri, Apr 17, 2026 at 08:25:35PM +0800, Xuneng Zhou wrote:

The change preserves the same coverage while removing one redundant
replay catch-up on the delayed standby. It appears to reduce the test
runtime by about 7 seconds, though I have looked into why much of the
improvement comes from this change alone.

Alexander may think differently and remove that, but I disagree. The
test is clearly written so as we want two wait checks to happen, for
for CREATE FUNCTION, and one for CREATE PROCEDURE. Removing the first
check to keep only the second one removes its meaning. In short, I
see nothing wrong to deal with here.

Thank you for your observation. The intention of this test is to
check explicit calls to WAIT FOR LSN. Yes, wait_for_catchup() now
also internally calls WAIT FOR LSN. But checking wait_for_catchup()
is not intention of this test, it's used in awfully a lot of other
places.

------
Regards,
Alexander Korotkov
Supabase

#6Alexander Korotkov
aekorotkov@gmail.com
In reply to: Alexander Korotkov (#4)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

On Sat, Apr 18, 2026 at 10:58 AM Alexander Korotkov
<aekorotkov@gmail.com> wrote:

On Sat, Apr 18, 2026 at 7:20 AM Xuneng Zhou <xunengzhou@gmail.com> wrote:

On Fri, Apr 17, 2026 at 08:25:35PM +0800, Xuneng Zhou wrote:

The change preserves the same coverage while removing one redundant
replay catch-up on the delayed standby. It appears to reduce the test
runtime by about 7 seconds, though I have looked into why much of the
improvement comes from this change alone.

Alexander may think differently and remove that, but I disagree. The
test is clearly written so as we want two wait checks to happen, for
for CREATE FUNCTION, and one for CREATE PROCEDURE. Removing the first
check to keep only the second one removes its meaning. In short, I
see nothing wrong to deal with here.

Thank you for the review. I agree that the two wait checks serve distinct purposes and are not redundant. The main motivation for this patch was efficiency. In my testing, the new test added approximately 7 seconds to the runtime, while the creation of the procedure and function completed quickly. I suspect the latency stems from the wait-for-catch-up step. When I removed it, the test runtime dropped by about 7 seconds.I haven't yet investigated why the wait is so costly in this case. I should probably look into that before proposing this change.

On my laptop the time needed to run t/049_wait_for_lsn.pl also drops
from 20 secs to 12 secs. The influence to the runtime of the whole
test suite in parallel would be not that big as CPU time only drops
from 2.16 sec to 2.07 sec. But anyway that's pretty significant.
I've revised comment message a bit and surrounding comments. I'm
going to push this if no objections.

Pushed.

------
Regards,
Alexander Korotkov
Supabase

#7Xuneng Zhou
xunengzhou@gmail.com
In reply to: Alexander Korotkov (#6)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

On Mon, Apr 20, 2026 at 6:21 PM Alexander Korotkov <aekorotkov@gmail.com> wrote:

On Sat, Apr 18, 2026 at 10:58 AM Alexander Korotkov
<aekorotkov@gmail.com> wrote:

On Sat, Apr 18, 2026 at 7:20 AM Xuneng Zhou <xunengzhou@gmail.com> wrote:

On Fri, Apr 17, 2026 at 08:25:35PM +0800, Xuneng Zhou wrote:

The change preserves the same coverage while removing one redundant
replay catch-up on the delayed standby. It appears to reduce the test
runtime by about 7 seconds, though I have looked into why much of the
improvement comes from this change alone.

Alexander may think differently and remove that, but I disagree. The
test is clearly written so as we want two wait checks to happen, for
for CREATE FUNCTION, and one for CREATE PROCEDURE. Removing the first
check to keep only the second one removes its meaning. In short, I
see nothing wrong to deal with here.

Thank you for the review. I agree that the two wait checks serve distinct purposes and are not redundant. The main motivation for this patch was efficiency. In my testing, the new test added approximately 7 seconds to the runtime, while the creation of the procedure and function completed quickly. I suspect the latency stems from the wait-for-catch-up step. When I removed it, the test runtime dropped by about 7 seconds.I haven't yet investigated why the wait is so costly in this case. I should probably look into that before proposing this change.

On my laptop the time needed to run t/049_wait_for_lsn.pl also drops
from 20 secs to 12 secs. The influence to the runtime of the whole
test suite in parallel would be not that big as CPU time only drops
from 2.16 sec to 2.07 sec. But anyway that's pretty significant.
I've revised comment message a bit and surrounding comments. I'm
going to push this if no objections.

Pushed.

Thanks for pushing it. I haven't had time to investigate the latency
yet, but will do it later.

Best,
Xuneng

#8Xuneng Zhou
xunengzhou@gmail.com
In reply to: Xuneng Zhou (#7)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

Hi Alexander,

On Mon, Apr 20, 2026 at 9:54 PM Xuneng Zhou <xunengzhou@gmail.com> wrote:

On Mon, Apr 20, 2026 at 6:21 PM Alexander Korotkov <aekorotkov@gmail.com> wrote:

On Sat, Apr 18, 2026 at 10:58 AM Alexander Korotkov
<aekorotkov@gmail.com> wrote:

On Sat, Apr 18, 2026 at 7:20 AM Xuneng Zhou <xunengzhou@gmail.com> wrote:

On Fri, Apr 17, 2026 at 08:25:35PM +0800, Xuneng Zhou wrote:

The change preserves the same coverage while removing one redundant
replay catch-up on the delayed standby. It appears to reduce the test
runtime by about 7 seconds, though I have looked into why much of the
improvement comes from this change alone.

Alexander may think differently and remove that, but I disagree. The
test is clearly written so as we want two wait checks to happen, for
for CREATE FUNCTION, and one for CREATE PROCEDURE. Removing the first
check to keep only the second one removes its meaning. In short, I
see nothing wrong to deal with here.

Thank you for the review. I agree that the two wait checks serve distinct purposes and are not redundant. The main motivation for this patch was efficiency. In my testing, the new test added approximately 7 seconds to the runtime, while the creation of the procedure and function completed quickly. I suspect the latency stems from the wait-for-catch-up step. When I removed it, the test runtime dropped by about 7 seconds.I haven't yet investigated why the wait is so costly in this case. I should probably look into that before proposing this change.

On my laptop the time needed to run t/049_wait_for_lsn.pl also drops
from 20 secs to 12 secs. The influence to the runtime of the whole
test suite in parallel would be not that big as CPU time only drops
from 2.16 sec to 2.07 sec. But anyway that's pretty significant.
I've revised comment message a bit and surrounding comments. I'm
going to push this if no objections.

Pushed.

Thanks for pushing it. I haven't had time to investigate the latency
yet, but will do it later.

While working on other things, I revisited the thread and looked into
the issue. The delayed investigation has exposed an unexpected
fragility. I'll post some findings soon.

--
Regards,
Xuneng Zhou
HighGo Software Co., Ltd.

#9Xuneng Zhou
xunengzhou@gmail.com
In reply to: Xuneng Zhou (#8)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

On Sun, Sep 20, 2026 at 10:16 AM Xuneng Zhou <xunengzhou@gmail.com> wrote:

Hi Alexander,

On Mon, Apr 20, 2026 at 9:54 PM Xuneng Zhou <xunengzhou@gmail.com> wrote:

On Mon, Apr 20, 2026 at 6:21 PM Alexander Korotkov <aekorotkov@gmail.com>

wrote:

On Sat, Apr 18, 2026 at 10:58 AM Alexander Korotkov
<aekorotkov@gmail.com> wrote:

On Sat, Apr 18, 2026 at 7:20 AM Xuneng Zhou <xunengzhou@gmail.com>

wrote:

On Fri, Apr 17, 2026 at 08:25:35PM +0800, Xuneng Zhou wrote:

The change preserves the same coverage while removing one

redundant

replay catch-up on the delayed standby. It appears to reduce

the test

runtime by about 7 seconds, though I have looked into why much

of the

improvement comes from this change alone.

Alexander may think differently and remove that, but I

disagree. The

test is clearly written so as we want two wait checks to happen,

for

for CREATE FUNCTION, and one for CREATE PROCEDURE. Removing the

first

check to keep only the second one removes its meaning. In

short, I

see nothing wrong to deal with here.

Thank you for the review. I agree that the two wait checks serve

distinct purposes and are not redundant. The main motivation for this patch
was efficiency. In my testing, the new test added approximately 7 seconds
to the runtime, while the creation of the procedure and function completed
quickly. I suspect the latency stems from the wait-for-catch-up step. When
I removed it, the test runtime dropped by about 7 seconds.I haven't yet
investigated why the wait is so costly in this case. I should probably look
into that before proposing this change.

On my laptop the time needed to run t/049_wait_for_lsn.pl also drops
from 20 secs to 12 secs. The influence to the runtime of the whole
test suite in parallel would be not that big as CPU time only drops
from 2.16 sec to 2.07 sec. But anyway that's pretty significant.
I've revised comment message a bit and surrounding comments. I'm
going to push this if no objections.

Pushed.

Thanks for pushing it. I haven't had time to investigate the latency
yet, but will do it later.

While working on other things, I revisited the thread and looked into
the issue. The delayed investigation has exposed an unexpected
fragility. I'll post some findings soon.

===== The cause of the delay
In 23cbadeeb47, we combined the creation of two wrappers into a single
session and used one wait_for_catchup for synchronization. After this
commit, the 8s delay has disappeared, which is strange, since the saved
wait_for_catchup shouldn't be that costly. In a timed run on a build before
23cbadeeb47, the two DDL catch-ups took 0.987s and 0.985s (matched the
configured one-second replay delay), which means the time for saving the
catchup is less than 1s. The rest of saving time has gone somewhere else.

[09:49:21.319](0.012s) # TIMING 0.006 standby
ALTER SYSTEM SET primary_conninfo = '...'; SELECT pg_reload_conf();

[09:49:29.901](8.582s) # TIMING 0.016 standby
SELECT pg_lsn_cmp(...);
[09:49:29.901](0.000s) ok 31 - mixed mode waiters: all modes completed and
reached target LSN

In the timed runs on the same historical build, there's a consistent ~8s
gap between resuming the wal receiver and the lsn check in test 7d. This
means that it tooks ~8s for the 6 waiters to reach their target LSN, which
is unexpected since there's no additional delay settings.

These are the fetched LSN for the waiting:

Wait target: 0/0301A018
Primary insertion: 0/0301A018

Primary write/flush: 0/0301A000
Standby write/flush/replay: 0/0301A000

Blocked waiters: 6

We cans see that the primary and standby's progressing LSNs had all reached
'0/0301A000'. But the target LSN returned by pg_current_wal_insert_lsn()
was '0/0301A018' -- 24 bytes ahead.

That gap corresponds exactly to a WAL page header. '0/0301A000' lies on an
8kb page boundary Consistently, pg_waldump showed a 34-byte COMMIT record
starting at 0/03019FD8; after alignment, it occupies 40 bytes and ends
exactly at that boundary.

At this boundary, pg_current_wal_insert_lsn() returns the next insertion
address, which is after the header gap. The test thus waited for a position
beyond the existing WAL, requiring another WAL record to make progress. The
unrelated progression comes from the primary's background writer who
generated a RUNNING_XACTS record, advancing WAL to 0/0301A050, and then
notified the waiters.

There are similar cases reported and fixed before[1]/messages/by-id/E1w1B0a-0002Si-0M@gemulon.postgresql.org [2]/messages/by-id/vf4hbwrotvhbgcnknrqmfbqlu75oyjkmausvy66ic7x7vuhafx@e4rvwavtjswo.

===== The accidental removal of the delay
In a small experiment to differentiate the time saved by removing one
catch-up and combining two creations into one sessions, the results shows
as follows:

Variant Sessions Catch-ups Result
Before 2 2 Boundary stall;
20.072s
After 1 1 No boundary
stall; 11.297s
Control 2 1 Boundary stall
returns; 19.012s

the combination of creations contributed the majority of time saving. That
change also introduced the initial divergence and subsequent changes of the
layout of WAL records in before-and-after commit runs:

--- The WAL layout before the commit 23cbadeeb47

Section / operation XID Aligned COMMIT end Offset
within 8 KiB WAL page

5: wrapper function DDL 698 0/0300CFC0 0x0FC0
5: procedure DDL 699 0/0300F5B8 0x15B8

...

7d: mixed waiters 717 0/0301A000 0x0000

--- The WAL layout after the commit

5: wrapper function DDL 698 0/0300CFC0 0x0FC0
5: procedure DDL 699 0/0300F888 0x1888

...

7d: mixed waiters 717 0/030143F0 0x03F0

We can see that the first divergence occurred in 5: procedure DDL and
section 7d's COMMIT end shifted away from the boundary 0/0301A000 to
0/030143F0. Therefore, the getter pg_current_wal_insert_lsn would just
return the current insert LSN as the target LSN without adding the header
gap. It won't exceed the LSN being replayed and flushed, hence avoiding the
stall of waiting future unrelated WAL records.

Where did the WAL reduction from 0/0301A000 to 0/030143F0 between two runs
comes from? An analysis with pg_waldump shows that combining the
definitions of function and procedure in 5d into one backend session
preserves its cached insertion target, so the procedure creation can reuse
the catalog page modified by the preceding function, thus avoiding another
full-page image. That different placement also changes subsequent FSM
searches and page occupancy, allowing later helpers definitions to
genenerate smaller or fewer page images.

===== Fix it once for all

As the investigation indicates, the root cause of the delay is
pg_current_wal_insert_lsn can return a position beyond the end of existing
WAL: when the last record ends exactly at a page boundary, the returned
position skips the next page’s header. In practice, this seems not a
serious problem as long as the WAL reception and replay is normal --
unrelated WAL records would eventually unleash the waiters. In some edge
cases, however, it would be more concerning since future wake-up is could
be unguaranteed. Other getters like pg_current_wal_lsn(),
pg_current_wal_flush_lsn() do not skip page headers and can work well for
synchronous commit. But COMMIT could return before its WAL is written or
flushed in asynchronous settings. I am wondering whether we would expose
GetXLogInsertEndRecPtr() introduced in b1f14c96720 as sql function and let
the command make use of it.

[1]: /messages/by-id/E1w1B0a-0002Si-0M@gemulon.postgresql.org
/messages/by-id/E1w1B0a-0002Si-0M@gemulon.postgresql.org
[2]: /messages/by-id/vf4hbwrotvhbgcnknrqmfbqlu75oyjkmausvy66ic7x7vuhafx@e4rvwavtjswo
/messages/by-id/vf4hbwrotvhbgcnknrqmfbqlu75oyjkmausvy66ic7x7vuhafx@e4rvwavtjswo

--
Regards,
Xuneng Zhou
HighGo Software Co., Ltd.

Attachments:

t139363_9
v1-0002-Use-WAL-insertion-end-positions-in-WAIT-examples-.patchapplication/octet-stream; name=v1-0002-Use-WAL-insertion-end-positions-in-WAIT-examples-.patchDownload+53-36
v1-0001-Expose-the-WAL-insertion-end-position-to-SQL.patchapplication/octet-stream; name=v1-0001-Expose-the-WAL-insertion-end-position-to-SQL.patchDownload+54-1
#10Xuneng Zhou
xunengzhou@gmail.com
In reply to: Xuneng Zhou (#9)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

On Tue, Sep 22, 2026 at 5:22 PM Xuneng Zhou <xunengzhou@gmail.com> wrote:

On Sun, Sep 20, 2026 at 10:16 AM Xuneng Zhou <xunengzhou@gmail.com> wrote:

Hi Alexander,

On Mon, Apr 20, 2026 at 9:54 PM Xuneng Zhou <xunengzhou@gmail.com>

wrote:

On Mon, Apr 20, 2026 at 6:21 PM Alexander Korotkov <

aekorotkov@gmail.com> wrote:

On Sat, Apr 18, 2026 at 10:58 AM Alexander Korotkov
<aekorotkov@gmail.com> wrote:

On Sat, Apr 18, 2026 at 7:20 AM Xuneng Zhou <xunengzhou@gmail.com>

wrote:

On Fri, Apr 17, 2026 at 08:25:35PM +0800, Xuneng Zhou wrote:

The change preserves the same coverage while removing one

redundant

replay catch-up on the delayed standby. It appears to reduce

the test

runtime by about 7 seconds, though I have looked into why

much of the

improvement comes from this change alone.

Alexander may think differently and remove that, but I

disagree. The

test is clearly written so as we want two wait checks to

happen, for

for CREATE FUNCTION, and one for CREATE PROCEDURE. Removing

the first

check to keep only the second one removes its meaning. In

short, I

see nothing wrong to deal with here.

Thank you for the review. I agree that the two wait checks serve

distinct purposes and are not redundant. The main motivation for this patch
was efficiency. In my testing, the new test added approximately 7 seconds
to the runtime, while the creation of the procedure and function completed
quickly. I suspect the latency stems from the wait-for-catch-up step. When
I removed it, the test runtime dropped by about 7 seconds.I haven't yet
investigated why the wait is so costly in this case. I should probably look
into that before proposing this change.

On my laptop the time needed to run t/049_wait_for_lsn.pl also

drops

from 20 secs to 12 secs. The influence to the runtime of the whole
test suite in parallel would be not that big as CPU time only drops
from 2.16 sec to 2.07 sec. But anyway that's pretty significant.
I've revised comment message a bit and surrounding comments. I'm
going to push this if no objections.

Pushed.

Thanks for pushing it. I haven't had time to investigate the latency
yet, but will do it later.

While working on other things, I revisited the thread and looked into
the issue. The delayed investigation has exposed an unexpected
fragility. I'll post some findings soon.

===== The cause of the delay
In 23cbadeeb47, we combined the creation of two wrappers into a single
session and used one wait_for_catchup for synchronization. After this
commit, the 8s delay has disappeared, which is strange, since the saved
wait_for_catchup shouldn't be that costly. In a timed run on a build before
23cbadeeb47, the two DDL catch-ups took 0.987s and 0.985s (matched the
configured one-second replay delay), which means the time for saving the
catchup is less than 1s. The rest of saving time has gone somewhere else.

[09:49:21.319](0.012s) # TIMING 0.006 standby
ALTER SYSTEM SET primary_conninfo = '...'; SELECT pg_reload_conf();

[09:49:29.901](8.582s) # TIMING 0.016 standby
SELECT pg_lsn_cmp(...);
[09:49:29.901](0.000s) ok 31 - mixed mode waiters: all modes completed and
reached target LSN

In the timed runs on the same historical build, there's a consistent ~8s
gap between resuming the wal receiver and the lsn check in test 7d. This
means that it tooks ~8s for the 6 waiters to reach their target LSN, which
is unexpected since there's no additional delay settings.

These are the fetched LSN for the waiting:

Wait target: 0/0301A018
Primary insertion: 0/0301A018

Primary write/flush: 0/0301A000
Standby write/flush/replay: 0/0301A000

Blocked waiters: 6

We cans see that the primary and standby's progressing LSNs had all
reached '0/0301A000'. But the target LSN returned by
pg_current_wal_insert_lsn() was '0/0301A018' -- 24 bytes ahead.

That gap corresponds exactly to a WAL page header. '0/0301A000' lies on an
8kb page boundary Consistently, pg_waldump showed a 34-byte COMMIT record
starting at 0/03019FD8; after alignment, it occupies 40 bytes and ends
exactly at that boundary.

At this boundary, pg_current_wal_insert_lsn() returns the next insertion
address, which is after the header gap. The test thus waited for a position
beyond the existing WAL, requiring another WAL record to make progress. The
unrelated progression comes from the primary's background writer who
generated a RUNNING_XACTS record, advancing WAL to 0/0301A050, and then
notified the waiters.

There are similar cases reported and fixed before[1] [2].

===== The accidental removal of the delay
In a small experiment to differentiate the time saved by removing one
catch-up and combining two creations into one sessions, the results shows
as follows:

Variant Sessions Catch-ups Result
Before 2 2 Boundary stall;
20.072s
After 1 1 No boundary
stall; 11.297s
Control 2 1 Boundary stall
returns; 19.012s

the combination of creations contributed the majority of time saving. That
change also introduced the initial divergence and subsequent changes of the
layout of WAL records in before-and-after commit runs:

--- The WAL layout before the commit 23cbadeeb47

Section / operation XID Aligned COMMIT end Offset
within 8 KiB WAL page

5: wrapper function DDL 698 0/0300CFC0 0x0FC0
5: procedure DDL 699 0/0300F5B8 0x15B8

...

7d: mixed waiters 717 0/0301A000 0x0000

--- The WAL layout after the commit

5: wrapper function DDL 698 0/0300CFC0 0x0FC0
5: procedure DDL 699 0/0300F888 0x1888

...

7d: mixed waiters 717 0/030143F0 0x03F0

We can see that the first divergence occurred in 5: procedure DDL and
section 7d's COMMIT end shifted away from the boundary 0/0301A000 to
0/030143F0. Therefore, the getter pg_current_wal_insert_lsn would just
return the current insert LSN as the target LSN without adding the header
gap. It won't exceed the LSN being replayed and flushed, hence avoiding the
stall of waiting future unrelated WAL records.

Where did the WAL reduction from 0/0301A000 to 0/030143F0 between two runs
comes from? An analysis with pg_waldump shows that combining the
definitions of function and procedure in 5d into one backend session
preserves its cached insertion target, so the procedure creation can reuse
the catalog page modified by the preceding function, thus avoiding another
full-page image. That different placement also changes subsequent FSM
searches and page occupancy, allowing later helpers definitions to
genenerate smaller or fewer page images.

===== Fix it once for all

As the investigation indicates, the root cause of the delay is
pg_current_wal_insert_lsn can return a position beyond the end of existing
WAL: when the last record ends exactly at a page boundary, the returned
position skips the next page’s header. In practice, this seems not a
serious problem as long as the WAL reception and replay is normal --
unrelated WAL records would eventually unleash the waiters. In some edge
cases, however, it would be more concerning since future wake-up is could
be unguaranteed. Other getters like pg_current_wal_lsn(),
pg_current_wal_flush_lsn() do not skip page headers and can work well for
synchronous commit. But COMMIT could return before its WAL is written or
flushed in asynchronous settings. I am wondering whether we would expose
GetXLogInsertEndRecPtr() introduced in b1f14c96720 as sql function and let
the command make use of it.

[1]
/messages/by-id/E1w1B0a-0002Si-0M@gemulon.postgresql.org
[2]
/messages/by-id/vf4hbwrotvhbgcnknrqmfbqlu75oyjkmausvy66ic7x7vuhafx@e4rvwavtjswo

Here are the attachments of timing scripts, timestamped logs and the dumped
wal files.

On a second thought, GetXLogInsertEndRecPtr() still returns the globally
reserved insertion pointer rather than the specific ptr for session or txn,
so fetched target LSN could be an unrelated record generated by other
backends concurrently, which means that the user could also wait for
unnecessary wal progress to achieve read-after-your write consistency. We
could somehow expose the local commit record ptr, but it would narrow the
command use cases from waiting for wal progress to waiting for a commit
record, since some operations like non-transactional logical messages won't
emit a commit record.

--
Regards,
Xuneng Zhou
HighGo Software Co., Ltd.

Attachments:

before-waldump-through-8.txttext/plain; charset=US-ASCII; name=before-waldump-through-8.txtDownload
before-instrumentation.patchapplication/octet-stream; name=before-instrumentation.patchDownload+17-0
after-instrumentation.patchapplication/octet-stream; name=after-instrumentation.patchDownload+17-0
before-049-wait-for-lsn.tap.logapplication/octet-stream; name=before-049-wait-for-lsn.tap.logDownload
after-049-wait-for-lsn.tap.logapplication/octet-stream; name=after-049-wait-for-lsn.tap.logDownload
after-waldump-through-8.txttext/plain; charset=US-ASCII; name=after-waldump-through-8.txtDownload
#11Jobin Augustine
jobinau@gmail.com
In reply to: Xuneng Zhou (#10)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

Hi Xuneng, hackers,

I ran into the same pg_current_wal_insert_lsn() page-boundary problem
discussed in this thread, independently, outside the regression tests,
while evaluating WAIT FOR for read-your-writes on a standby using a custom
coded application to test the usability of this feature.

At this boundary, pg_current_wal_insert_lsn() returns the next insertion

address, which is after the header gap. The test thus waited for a position
beyond the existing WAL, requiring another WAL record to make progress. The
unrelated progression comes from the primary's background writer who
generated a RUNNING_XACTS record, advancing WAL to 0/0301A050, and then
notified the waiters.

About 1 in 2000 waits never succeeded and ran to the full TIMEOUT
Since all my sessions were using WAIT FOR LSN, it was a complete stall,
whenever it happens.

A client side workaround similar to the following is a temporary solution
for me for my tests:
CREATE FUNCTION wal_insert_end_lsn(l pg_lsn DEFAULT
pg_current_wal_insert_lsn())
RETURNS pg_lsn LANGUAGE sql STABLE AS $$
SELECT CASE
WHEN (l - '0/0'::pg_lsn) %
pg_size_bytes(current_setting('wal_segment_size'))
< current_setting('wal_block_size')::int -- first page of a
segment
THEN CASE WHEN (l - '0/0'::pg_lsn) %
current_setting('wal_block_size')::int = 40
THEN l - 40 ELSE l END
ELSE CASE WHEN (l - '0/0'::pg_lsn) %
current_setting('wal_block_size')::int = 24
THEN l - 24 ELSE l END
END
$$;

A server-side fix would be better
Could WAIT FOR itself also tolerate such targets? When the target points
exactly past a page header treat it as the page boundary.

Thanks for tracking this down in the test. It saved me from chasing what
looked like a WAIT FOR wakeup bug.

Thanks and Regards,
Jobin.

--

------------------------------

#12Xuneng Zhou
xunengzhou@gmail.com
In reply to: Jobin Augustine (#11)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

Hi Jobin,

On Tue, Sep 29, 2026 at 7:47 PM Jobin Augustine <jobin.augustine@percona.com>
wrote:

Hi Xuneng, hackers,

I ran into the same pg_current_wal_insert_lsn() page-boundary problem
discussed in this thread, independently, outside the regression tests,
while evaluating WAIT FOR for read-your-writes on a standby using a custom
coded application to test the usability of this feature.

At this boundary, pg_current_wal_insert_lsn() returns the next insertion

address, which is after the header gap. The test thus waited for a position
beyond the existing WAL, requiring another WAL record to make progress. The
unrelated progression comes from the primary's background writer who
generated a RUNNING_XACTS record, advancing WAL to 0/0301A050, and then
notified the waiters.

About 1 in 2000 waits never succeeded and ran to the full TIMEOUT
Since all my sessions were using WAIT FOR LSN, it was a complete stall,
whenever it happens.

Interestingly, is this a pressure test? Can you please elaborate a bit more
on how the application tests it? The stall in the TAP test 049 persisted
for ~8s because of no WAL activity in that test env, and it was saved by a
later RUNNING_XACTS record generated by bgwriter. In practice, I expected
the problem to be harder to notice since WAL is more active.

A client side workaround similar to the following is a temporary solution
for me for my tests:
CREATE FUNCTION wal_insert_end_lsn(l pg_lsn DEFAULT
pg_current_wal_insert_lsn())
RETURNS pg_lsn LANGUAGE sql STABLE AS $$
SELECT CASE
WHEN (l - '0/0'::pg_lsn) %
pg_size_bytes(current_setting('wal_segment_size'))
< current_setting('wal_block_size')::int -- first page of a
segment
THEN CASE WHEN (l - '0/0'::pg_lsn) %
current_setting('wal_block_size')::int = 40
THEN l - 40 ELSE l END
ELSE CASE WHEN (l - '0/0'::pg_lsn) %
current_setting('wal_block_size')::int = 24
THEN l - 24 ELSE l END
END
$$;

A server-side fix would be better
Could WAIT FOR itself also tolerate such targets? When the target points
exactly past a page header treat it as the page boundary.

I think we better fix the page/segment header issue on the server side.

--
Regards,
Xuneng Zhou
HighGo Software Co., Ltd.

#13Jobin Augustine
jobinau@gmail.com
In reply to: Xuneng Zhou (#12)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

Hi Xuneng,

Interestingly, is this a pressure test? Can you please elaborate a bit
more on how the application tests it?

It was a custom coded application in Rust designed to demonstrate how this
feature can reduce connections in the connection pool (deadpool of Rust
with 16 connections in the pool), Because primary can commit asynchronously
and release the connection back to pool and then wait for standby. I don't
mind sharing the code, if that helps.

A client side workaround similar to the following is a temporary solution
for me for my tests:
...

I think we better fix the page/segment header issue on the server side.

Agree, +1
We cannot expect every application to impliment workaround after
documenting the known problem
Thank you,
Jobin.

#14Xuneng Zhou
xunengzhou@gmail.com
In reply to: Jobin Augustine (#13)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

On Wed, Sep 30, 2026 at 12:24 PM Jobin Augustine <
jobin.augustine@percona.com> wrote:

Hi Xuneng,

Interestingly, is this a pressure test? Can you please elaborate a bit
more on how the application tests it?

It was a custom coded application in Rust designed to demonstrate how this
feature can reduce connections in the connection pool (deadpool of Rust
with 16 connections in the pool), Because primary can commit asynchronously
and release the connection back to pool and then wait for standby. I don't
mind sharing the code, if that helps.

Thanks. I had a general idea via your description and I'd like to know more
about the use case. Please share it if you are ok with that.

--
Regards,
Xuneng Zhou
HighGo Software Co., Ltd.

#15Jobin Augustine
jobinau@gmail.com
In reply to: Xuneng Zhou (#14)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

Hi Xuneng

Thanks. I had a general idea via your description and I'd like to know
more about the use case. Please share it if you are ok with that.

I am more than happy to share. The Rust program is pushed to my git repo
and path :
https://github.com/jobinau/pgscripts/tree/main/patroni/connection/waitforlsn
There is a "repro" subdirectory with a file with instructions :
REPRODUCE_WITH_WAITFORLSN.md please follow that for quick reproduction.
Basically the program has a function `normalize_insert_lsn`which
implements the client side fix. But passing a parameter `--raw-insert-lsn`
to the program disables this client side manipulation.
Thank you,
Jobin.

#16Jobin Augustine
jobinau@gmail.com
In reply to: Jobin Augustine (#15)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

Hi Hackers,
I'm curious whether this will be addressed before the PG 19 release.
Otherwise, we should expect many to fall into this pothole. of application
stalls and timeouts

Thanks and Regards,
Jobin

#17Xuneng Zhou
xunengzhou@gmail.com
In reply to: Jobin Augustine (#16)
Re: test: avoid redundant standby catchup in 049_wait_for_lsn

On Fri, Oct 9, 2026 at 12:06 PM Jobin Augustine <jobin.augustine@percona.com>
wrote:

Hi Hackers,
I'm curious whether this will be addressed before the PG 19 release.
Otherwise, we should expect many to fall into this pothole. of
application stalls and timeouts

Thanks and Regards,
Jobin

+1. We better address it before the upcoming release. Could you add it to
the open issue list so it doesn't fall through the cracks? I don't have
access to edit it myself.

[1]: https://wiki.postgresql.org/wiki/PostgreSQL_19_Open_Items#Open_Issues

--
Regards,
Xuneng Zhou
HighGo Software Co., Ltd.