Hello hackers,
Please look at a new failure of 041_checkpoint_at_promote.pl produced by
bushmaster, [1]:
[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].
[1]
https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=bushmaster&dt=2026-10-03%2021%3A37%3A08
[2] https://postgr.es/m/[email protected]
Best regards,
Alexander
