Re: walsummarizer can get stuck when switching timelines

Hello Robert,

31.07.2026 19:55, Robert Haas wrote:
> It took me way longer than I was hoping to find the time to get this
> committed and back-patched, but I have now done so. The test case
> required some adjustments for v17 and v18.

Buildfarm animal sidewinder managed to fail the new test 003_tli_switch.pl,
[1]:
### Promoting node "node2"
# Running: pg_ctl --pgdata
/home/pgbf/buildroot/REL_19_STABLE/pgsql.build/src/bin/pg_walsummary/tmp_check/t_003_tli_switch_node2_data/pgdata --log
/home/pgbf/buildroot/REL_19_STABLE/pgsql.build/src/bin/pg_walsummary/tmp_check/log/003_tli_switch_node2.log promote
waiting for server to promote.... done
server promoted
### Reloading node "node3"
# Running: pg_ctl --pgdata
/home/pgbf/buildroot/REL_19_STABLE/pgsql.build/src/bin/pg_walsummary/tmp_check/t_003_tli_switch_node3_data/pgdata reload
server signaled
[23:03:08.443](215.681s) # poll_query_until timed out executing this query:
# SELECT EXISTS (SELECT * FROM pg_available_wal_summaries() WHERE tli = 2)
#
# expecting this output:
# t
# last actual query output:
# f
# with stderr:
[23:03:08.444](0.001s) not ok 1 - WAL summarization on node3 advanced past timeline switch
[23:03:08.445](0.001s)
[23:03:08.445](0.000s) #   Failed test 'WAL summarization on node3 advanced past timeline switch'
#   at t/003_tli_switch.pl line 113.

003_tli_switch_node3.log contains:
2026-08-01 22:59:41.862 CEST [25416:2] DEBUG:  switch point from TLI 1 to TLI 2 is at 0/0301DBE8
2026-08-01 22:59:41.864 CEST [25416:3] DEBUG:  summarized WAL on TLI 1 from 0/02000028 to 0/0301DBE8
2026-08-01 22:59:41.865 CEST [4231:1] [unknown] LOG:  connection received: host=[local]
2026-08-01 22:59:41.866 CEST [4231:2] [unknown] LOG:  connection authenticated: user="pgbf" method=trust
(/home/pgbf/buildroot/REL_19_STABLE/pgsql.build/src/bin/pg_walsummary/tmp_check/t_003_tli_switch_node3_data/pgdata/pg_hba.conf:117)
2026-08-01 22:59:41.866 CEST [4231:3] [unknown] LOG:  connection authorized: user=pgbf database=postgres
application_name=003_tli_switch.pl
cp:
/home/pgbf/buildroot/REL_19_STABLE/pgsql.build/src/bin/pg_walsummary/tmp_check/t_003_tli_switch_node2_data/archives/00000003.history:
No such file or directory
2026-08-01 22:59:41.867 CEST [22705:14] LOG:  waiting for WAL to become available at 0/04000018
2026-08-01 22:59:41.867 CEST [4231:4] 003_tli_switch.pl LOG: statement: SELECT EXISTS (SELECT * FROM
pg_available_wal_summaries() WHERE tli = 2)
...
2026-08-01 23:03:08.336 CEST [222:4] 003_tli_switch.pl LOG: statement: SELECT EXISTS (SELECT * FROM
pg_available_wal_summaries() WHERE tli = 2)
2026-08-01 23:03:08.338 CEST [222:5] 003_tli_switch.pl LOG: disconnection: session time: 0:00:00.006 user=pgbf
database=postgres host=[local]
cp:
/home/pgbf/buildroot/REL_19_STABLE/pgsql.build/src/bin/pg_walsummary/tmp_check/t_003_tli_switch_node2_data/archives/000000020000000000000004:
No such file or directory
cp:
/home/pgbf/buildroot/REL_19_STABLE/pgsql.build/src/bin/pg_walsummary/tmp_check/t_003_tli_switch_node2_data/archives/00000003.history:
No such file or directory
2026-08-01 23:03:08.407 CEST [22705:419] LOG:  waiting for WAL to become available at 0/04000018

003_tli_switch_node2.log:
2026-08-01 22:59:41.062 CEST [11464:4] 003_tli_switch.pl LOG: statement: SELECT pg_switch_wal();
2026-08-01 22:59:41.129 CEST [18094:4] LOG:  database system is ready to accept connections
2026-08-01 22:59:41.204 CEST [14948:1] LOG:  checkpoint starting: force
2026-08-01 22:59:41.205 CEST [11464:5] 003_tli_switch.pl LOG: statement: CHECKPOINT;
2026-08-01 22:59:41.426 CEST [14948:2] LOG:  checkpoint complete: force: wrote 21 buffers (16.4%), wrote 3 SLRU buffers;
0 WAL file(s) added, 0 removed, 0 recycled; write=0.043 s, sync=0.001 s, total=0.302 s; sync files=0, longest=0.000 s,
average=0.000 s; distance=32768 kB, estimate=32768 kB; lsn=0/04000088, redo lsn=0/04000028
2026-08-01 22:59:41.426 CEST [14948:3] LOG:  checkpoint starting: fast force wait
2026-08-01 22:59:41.434 CEST [14948:4] LOG:  checkpoint complete: fast force wait: wrote 0 buffers (0.0%), wrote 0 SLRU
buffers; 0 WAL file(s) added, 0 removed, 0 recycled; write=0.001 s, sync=0.001 s, total=0.009 s; sync files=0,
longest=0.000 s, average=0.000 s; distance=0 kB, estimate=29491 kB; lsn=0/04000168, redo lsn=0/04000108
2026-08-01 22:59:41.471 CEST [11464:6] 003_tli_switch.pl LOG: disconnection: session time: 0:00:00.411 user=pgbf
database=postgres host=[local]
(both redo_lsn belong to segment 4)

vs the previous successful run [2]:
003_tli_switch_node2.log
2026-08-01 00:55:39.071 CEST [965:4] 003_tli_switch.pl LOG: statement: SELECT pg_switch_wal();
2026-08-01 00:55:39.241 CEST [965:5] 003_tli_switch.pl LOG: statement: CHECKPOINT;
2026-08-01 00:55:39.727 CEST [15172:2] LOG:  checkpoint complete: force: wrote 21 buffers (16.4%), wrote 3 SLRU buffers;
0 WAL file(s) added, 0 removed, 0 recycled; write=0.318 s, sync=0.001 s, total=0.813 s; sync files=0, longest=0.000 s,
average=0.000 s; distance=16502 kB, estimate=16502 kB; lsn=0/04000060, redo lsn=0/0301DC20
2026-08-01 00:55:39.727 CEST [15172:3] LOG:  checkpoint starting: fast force wait
2026-08-01 00:55:39.747 CEST [15172:4] LOG:  checkpoint complete: fast force wait: wrote 0 buffers (0.0%), wrote 0 SLRU
buffers; 0 WAL file(s) added, 0 removed, 1 recycled; write=0.001 s, sync=0.001 s, total=0.020 s; sync files=0,
longest=0.000 s, average=0.000 s; distance=16265 kB, estimate=16479 kB; lsn=0/04000140, redo lsn=0/040000E0
(the first redo_lsn belongs to segment 3)

So it looks like the test might fail when the checkpoint record slips into
segment 4. I've reproduced the failure with:
--- a/src/backend/access/transam/xlog.c
+++ b/src/backend/access/transam/xlog.c
@@ -7448,2 +7448,3 @@ CreateCheckPoint(int flags)
        INJECTION_POINT_LOAD("create-checkpoint-run");
+pg_usleep(1000000);

PROVE_TESTS="t/003*" make -s check -C src/bin/pg_walsummary/

# +++ tap check in src/bin/pg_walsummary +++
t/003_tli_switch.pl .. # poll_query_until timed out executing this query:
# SELECT EXISTS (SELECT * FROM pg_available_wal_summaries() WHERE tli = 2)
#
# expecting this output:
# t
# last actual query output:
# f
# with stderr:
t/003_tli_switch.pl .. 1/?
#   Failed test 'WAL summarization on node3 advanced past timeline switch'
#   at t/003_tli_switch.pl line 113.

Could you please have a look?

[1] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=sidewinder&dt=2026-08-01%2020%3A35%3A00
[2] https://buildfarm.postgresql.org/cgi-bin/show_log.pl?nm=sidewinder&dt=2026-07-31%2022%3A35%3A00

Best regards,
Alexander