Stabilize and shorten test_checksums/013_rewind test

Started by Nazir Bilal Yavuz3 days ago3 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.

appliessuccessCI 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:t253838
psql -h localhost -U postgres

Built from patchset v1 (message #1), September 20, 2026 at 10:40 AM.

Every patchset is also pushed to a branch of our PostgreSQL fork, so you can check out the same tree CI built. Without a PostgreSQL checkout:

git clone --branch t253838_1 https://github.com/hackorum-dev/postgres.git

In a checkout you already have, add the fork once:

git remote add hackorum https://github.com/hackorum-dev/postgres.git

then, for this patchset and every later one:

git fetch hackorum t253838_1 && git checkout t253838_1

Patchset v1 (message #1) is on t253838_1

Jump to latest
#1Nazir Bilal Yavuz
byavuz81@gmail.com

Hi,

I encountered two problems with the test_checksums/013_rewind test:

1. It takes ~45 seconds to finish on my machine and it seems timing
doesn't depend the machine it runs on. It is always last finishing
tests on my machine and I need to wait ~30 seconds after all other
tests are done. Some numbers:

Local: 013_rewind -> 45s | 027_stream_regress -> 24s

Windows CI: 013_rewind -> 33s | 027_stream_regress -> 150s

2. The "8 - last common checkpoint is a shutdown checkpoint" test is
flaky. This test fails ~1/10 of the runs on my machine without any
external effort. Error message:

[11:31:29.021](0.007s) not ok 8 - last common checkpoint is a shutdown
checkpoint
[11:31:29.022](0.001s) # Failed test 'last common checkpoint is a
shutdown checkpoint'
# at /home/nbyavuz/Desktop/projects/postgres/src/test/modules/test_checksums/t/013_rewind.pl
line 161.
[11:31:29.022](0.000s) # ''
# doesn't match '(?^:CHECKPOINT_SHUTDOWN)'

I also saw same error on the CI [1]https://github.com/postgres/postgres/actions/runs/35096253076/job/104794579050#step:13:499.

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

I spent some time fixing these problems with the help of an LLM.

Problem #1:

We wait for the primary's insert LSN in three places, but the primary
might be idle and not have sent it yet:

1.1:

$node_a->backup('backup');
my $node_b = PostgreSQL::Test::Cluster->new('node_b');
$node_b->init_from_backup($node_a, 'backup', has_streaming => 1);
$node_b->start;

$node_a->wait_for_catchup($node_b, 'replay', $node_a->lsn('insert'));
test_checksum_state($node_a, 'off');
test_checksum_state($node_b, 'off');

backup() already flushes the LSN, we can wait for the flush LSN here.

1.2

$node_a->safe_psql('postgres', "CHECKPOINT;");
$node_a->wait_for_catchup($node_b, 'replay', $node_a->lsn('insert'));

Since there is already a CHECKPOINT, the changes should be flushed. We
can wait for the flush LSN.

1.3

# Start the rewound node as a standby of the new primary. Replay runs
# through the pre-enable WAL stretch and the online enable.
#
# The rewind replaced the configuration files with those of the new
# primary, so put the port back.
...
$node_a->set_standby_mode;
$node_a->start;

$node_b->wait_for_catchup($node_a, 'replay', $node_b->lsn('insert'));
test_checksum_state($node_a, 'on');

We can use pg_switch_wal() function to make sure changes are flushed
and then we can wait for the flush LSN.

These 3 changes reduces test time from ~45s to ~3s on my local environment.

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

Problem #2

($stdout, $stderr) = run_command(
[
'pg_waldump',
'-p' => $node_a->data_dir . '/pg_wal',
'-t' => 1,
'-s' => $shutdown_ckpt,
'-n' => 1,
]);
like($stdout, qr/CHECKPOINT_SHUTDOWN/,
'last common checkpoint is a shutdown checkpoint');

We don't specifiy which WAL file that pg_waldump() will use, then
pg_waldump select first WAL data available in the directory. Then, it
might select a WAL file whose header is not initialized yet (a
preallocated WAL file). So, when pg_waldump tries to get segment_size
from this file it reads 0 and fails. I run pg_waldump on the failed
test artifacts and I get this error; which I think confirms the
problem:

$ pg_waldump -p
testrun/test_checksums/013_rewind/data/t_013_rewind_node_a_data/pgdata/pg_wal/
pg_waldump: error: invalid WAL segment size in WAL file
"000000020000000000000005" (0 bytes)
pg_waldump: detail: The WAL segment size must be a power of two
between 1 MB and 1 GB.

This problem is solved by specifying the WAL file.

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

Two patchs are attached, 0001 for the problem #1 and 0002 for the problem #2.

[1]: https://github.com/postgres/postgres/actions/runs/35096253076/job/104794579050#step:13:499

--
Regards,
Nazir Bilal Yavuz
Microsoft

Attachments:

t253838_1
v1-0001-Avoid-idle-WAL-waits-in-the-checksum-rewind-test.patchtext/x-patch; charset=US-ASCII; name=v1-0001-Avoid-idle-WAL-waits-in-the-checksum-rewind-test.patchDownload+9-4
v1-0002-Fix-WAL-file-selection-in-checksum-rewind-test.patchtext/x-patch; charset=US-ASCII; name=v1-0002-Fix-WAL-file-selection-in-checksum-rewind-test.patchDownload+10-5
#2Daniel Gustafsson
daniel@yesql.se
In reply to: Nazir Bilal Yavuz (#1)
Re: Stabilize and shorten test_checksums/013_rewind test

On 18 Sep 2026, at 12:26, Nazir Bilal Yavuz <byavuz81@gmail.com> wrote:

I encountered two problems with the test_checksums/013_rewind test:
...
I spent some time fixing these problems with the help of an LLM.

Thanks!

Problem #1:

We wait for the primary's insert LSN in three places, but the primary
might be idle and not have sent it yet:

Makes sense.

-$node_a->wait_for_catchup($node_b, 'replay', $node_a->lsn('insert'));
+# Backup completion has flushed the required WAL.
+$node_a->wait_for_catchup($node_b, 'replay', $node_a->lsn('flush'));

In these cases, couldn't we just wait for the replay LSN, ie the default for
wait_for_catchup?

Problem #2

($stdout, $stderr) = run_command(
[
'pg_waldump',
'-p' => $node_a->data_dir . '/pg_wal',
'-t' => 1,
'-s' => $shutdown_ckpt,
'-n' => 1,
]);
like($stdout, qr/CHECKPOINT_SHUTDOWN/,
'last common checkpoint is a shutdown checkpoint');

We don't specifiy which WAL file that pg_waldump() will use, then
pg_waldump select first WAL data available in the directory. Then, it
might select a WAL file whose header is not initialized yet (a
preallocated WAL file).

Nice find, this patch seems quite straightforward.

--
Daniel Gustafsson

#3Nazir Bilal Yavuz
byavuz81@gmail.com
In reply to: Daniel Gustafsson (#2)
Re: Stabilize and shorten test_checksums/013_rewind test

Hi,

Thank you for looking into this!

On Fri, 18 Sept 2026 at 15:51, Daniel Gustafsson <daniel@yesql.se> wrote:

On 18 Sep 2026, at 12:26, Nazir Bilal Yavuz <byavuz81@gmail.com> wrote:
Problem #1:

We wait for the primary's insert LSN in three places, but the primary
might be idle and not have sent it yet:

Makes sense.

-$node_a->wait_for_catchup($node_b, 'replay', $node_a->lsn('insert'));
+# Backup completion has flushed the required WAL.
+$node_a->wait_for_catchup($node_b, 'replay', $node_a->lsn('flush'));

In these cases, couldn't we just wait for the replay LSN, ie the default for
wait_for_catchup?

Sorry, I am a bit confused. AFAIU, you meant:

$node_a->wait_for_catchup($node_b);

which is

$node_a->wait_for_catchup($node_b, 'replay', $node_a->lsn('write'));

If that is the case, could we still need to wait for an additional
primary-side flush, since written WAL might not have been flushed yet?
I understand that this might not cause the same long delay as waiting
for the insert LSN. On my local, ->lsn('write') and ->lsn('flush') are
basically same, they both take ~3 seconds.

My idea was that since the WAL needed by the tests has already been
flushed, I thought that would be enough for the tests. Also, is using
->lsn('write') considered better for these cases or do you recommend
it because of the simplicity?

--
Regards,
Nazir Bilal Yavuz
Microsoft