041_checkpoint_at_promote.pl might fail due to race condition on child kill
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.
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:t254086psql -h localhost -U postgresBuilt from patchset v4 (message #4), October 22, 2026 at 08:01 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 t254086_4 https://github.com/hackorum-dev/postgres.gitIn a checkout you already have, add the fork once:
git remote add hackorum https://github.com/hackorum-dev/postgres.gitthen, for this patchset and every later one:
git fetch hackorum t254086_4 && git checkout t254086_4Patchset v4 (message #4) is on t254086_4
Hello hackers,
Please look at a new failure of 041_checkpoint_at_promote.pl produced by
bushmaster, [1]https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=bushmaster&dt=2026-10-03%2021%3A37%3A08:
[23:56:13.841](0.002s) ok 4 - psql query died successfully after SIGKILL
[23:56:13.902](0.061s) not ok 5 - psql connect success
[23:56:13.902](0.000s)
[23:56:13.902](0.000s) # Failed test 'psql connect success'
# at t/041_checkpoint_at_promote.pl line 168.
[23:56:13.902](0.000s) # got: '2'
# expected: '0'
[23:56:13.902](0.000s) not ok 6 - psql select 1
[23:56:13.902](0.000s)
[23:56:13.902](0.000s) # Failed test 'psql select 1'
# at t/041_checkpoint_at_promote.pl line 169.
[23:56:13.902](0.000s) # got: ''
# expected: '1'
[23:56:13.902](0.000s) 1..6
pgsql.build/src/test/recovery/tmp_check/log/041_checkpoint_at_promote_standby1.log
2026-10-03 23:56:13.852 CEST [4159149][postmaster][:0] LOG: client backend (PID 4159398) was terminated by signal 9: Killed
2026-10-03 23:56:13.852 CEST [4159149][postmaster][:0] DETAIL: Failed process was running: SELECT pg_backend_pid();
2026-10-03 23:56:13.852 CEST [4159149][postmaster][:0] LOG: terminating any other active server processes
2026-10-03 23:56:13.855 CEST [4159149][postmaster][:0] LOG: all server processes terminated; reinitializing
2026-10-03 23:56:13.899 CEST [4159414][startup][:0] LOG: database system was interrupted; last known up at 2026-10-03
23:56:13 CEST
2026-10-03 23:56:13.899 CEST [4159414][startup][:0] LOG: database system was not properly shut down; automatic recovery
in progress
2026-10-03 23:56:13.899 CEST [4159414][startup][:0] LOG: crash recovery starts in timeline 1 and has target timeline 2
2026-10-03 23:56:13.900 CEST [4159414][startup][:0] LOG: redo starts at 0/3000028
2026-10-03 23:56:13.900 CEST [4159417][not initialized][:0] LOG: connection received: host=[local]
2026-10-03 23:56:13.900 CEST [4159417][client backend][:0] FATAL: the database system is in recovery mode
I've reproduced this failure locally, running multiple tests concurrently inside a 4-core VM, in a loop:
for i in {1..50}; do echo "Iteration $i"; parallel -j40 --linebuffer --tag PROVE_TESTS="t/041*" NO_TEMP_INSTALL=1
TEMP_CONFIG=~/extra.config make -s check -s -C src/test/recovery_{} PROVE_FLAGS="--timer" ::: `seq 25` || break; done;
(with bushmaster's parameters put in ~/extra.config)
This failed for me on iterations 14, 30, 10:
...
Iteration 10
...
10
10 # Failed test 'psql connect success'
10 # at t/041_checkpoint_at_promote.pl line 168.
10 # got: '2'
10 # expected: '0'
10
10 # Failed test 'psql select 1'
10 # at t/041_checkpoint_at_promote.pl line 169.
10 # got: ''
10 # expected: '1'
10 # Looks like you failed 2 tests of 6.
10 [03:51:18] t/041_checkpoint_at_promote.pl ..
10 Dubious, test returned 2 (wstat 512, 0x200)
10 Failed 2/6 subtests
10 [03:51:18]
10
10 Test Summary Report
10 -------------------
10 t/041_checkpoint_at_promote.pl (Wstat: 512 (exited 2) Tests: 6 Failed: 2)
10 Failed tests: 5-6
10 Non-zero exit status: 2
It looks like the same race condition was fixed in 022_crash_temp_files.pl
by e37ad5fa4 two years before 041_checkpoint_at_promote.pl appeared: [2]/messages/by-id/1801850.1649047827@sss.pgh.pa.us.
[1]: https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=bushmaster&dt=2026-10-03%2021%3A37%3A08
[2]: /messages/by-id/1801850.1649047827@sss.pgh.pa.us
Best regards,
Alexander
On Wed, Oct 7, 2026 at 1:00 PM Alexander Lakhin <exclusion@gmail.com> wrote:
It looks like the same race condition was fixed in 022_crash_temp_files.pl
by e37ad5fa4 two years before 041_checkpoint_at_promote.pl appeared: [2].
I tried creating the patch based on that fix. How about the attached patch?
Regards,
--
Fujii Masao
Hello Fujii-san,
07.10.2026 19:46, Fujii Masao wrote:
On Wed, Oct 7, 2026 at 1:00 PM Alexander Lakhin<exclusion@gmail.com> wrote:
It looks like the same race condition was fixed in 022_crash_temp_files.pl
by e37ad5fa4 two years before 041_checkpoint_at_promote.pl appeared: [2].I tried creating the patch based on that fix. How about the attached patch?
Your patch works for me test-wise. The same test loop passed 100+
iterations successfully. Thank you for paying attention to this!
Best regards,
Alexander
On Fri, Oct 9, 2026 at 4:00 AM Alexander Lakhin <exclusion@gmail.com> wrote:
Your patch works for me test-wise. The same test loop passed 100+
iterations successfully. Thank you for paying attention to this!
Thanks for the test!
On second thought, we can simplify the test by waiting for the postmaster to
log "all server processes terminated; reinitializing" instead of using
another backend connection to detect the crash. This ensures that the
postmaster has detected the crash and started restarting. The attached
patch takes this approach. Thoughts?
Regards,
--
Fujii Masao