BUG #16159: recovery requests WALs for the next timelines before timeline switch LSN has been reached
The Post Office <noreply@postgresql.org>
From: PG Bug reporting form <noreply@postgresql.org>
To: pgsql-bugs@lists.postgresql.org
Cc: psuderevsky@gmail.com
Date: 2019-12-11T12:39:20Z
Lists: pgsql-bugs, pgsql-hackers
The following bug has been logged on the website: Bug reference: 16159 Logged by: Pavel Suderevsky Email address: psuderevsky@gmail.com PostgreSQL version: 11.6 Operating system: CentOS 7.6.1810 (3.10.0-957.el7.x86_64) Description: Reproduced 11.2,11.6. If PostgreSQL starts recovery and finds a history file for a timeline that is higher than current one, it will request file with the segment for the future timeline (that most likely doesn't exist yet) and only then it will request file with the segment for current timeline. If archive is located on remote storage it can take huge time to find that segments for the future timelines are not exist yet and therefore recovery can take too long. Example: recovery.conf: >restore_command = 'echo -e "Searching WAL: %f, location: %p"; /usr/bin/pgbackrest --stanza=platform archive-get %f "%p"' >recovery_target_timeline = 'latest' >standby_mode = 'on' Postgres log during startup: > > 2019-12-06 07:11:16 CST LOG: database system was shut down in recovery > at 2019-12-06 07:11:08 CST > Searching WAL: 00000022.history, location: pg_wal/RECOVERYHISTORY > 2019-12-06 07:11:16 CST LOG: restored log file "00000022.history" from > archive > Searching WAL: 00000023.history, location: pg_wal/RECOVERYHISTORY > 2019-12-06 07:11:16 CST LOG: entering standby mode > Searching WAL: 00000022.history, location: pg_wal/RECOVERYHISTORY > 2019-12-06 07:11:16 CST LOG: restored log file "00000022.history" from > archive > Searching WAL: 00000022000018C60000003F, location: pg_wal/RECOVERYXLOG > Searching WAL: 00000021000018C60000003F, location: pg_wal/RECOVERYXLOG > 2019-12-06 07:11:20 CST LOG: restored log file > "00000021000018C60000003F" from archive > Searching WAL: 00000021.history, location: pg_wal/RECOVERYHISTORY > 2019-12-06 07:11:20 CST LOG: restored log file "00000021.history" from > archive > Searching WAL: 00000022000018BF0000001B, location: pg_wal/RECOVERYXLOG > Searching WAL: 00000021000018BF0000001B, location: pg_wal/RECOVERYXLOG > 2019-12-06 07:11:27 CST LOG: restored log file > "00000021000018BF0000001B" from archive > 2019-12-06 07:11:27 CST LOG: redo starts at 18BF/1B311260 > Searching WAL: 00000022000018BF0000001C, location: pg_wal/RECOVERYXLOG > Searching WAL: 00000021000018BF0000001C, location: pg_wal/RECOVERYXLOG > 2019-12-06 07:11:34 CST LOG: restored log file > "00000021000018BF0000001C" from archive > Searching WAL: 00000022000018BF0000001D, location: pg_wal/RECOVERYXLOG > Searching WAL: 00000021000018BF0000001D, location: pg_wal/RECOVERYXLOG > 2019-12-06 07:11:40 CST LOG: restored log file > "00000021000018BF0000001D" from archive > Searching WAL: 00000022000018BF0000001E, location: pg_wal/RECOVERYXLOG > Searching WAL: 00000021000018BF0000001E, location: pg_wal/RECOVERYXLOG > 2019-12-06 07:11:46 CST LOG: restored log file > "00000021000018BF0000001E" from archive > Searching WAL: 00000022000018BF0000001F, location: pg_wal/RECOVERYXLOG > Searching WAL: 00000021000018BF0000001F, location: pg_wal/RECOVERYXLOG > 2019-12-06 07:11:53 CST LOG: restored log file > "00000021000018BF0000001F" from archive As you can see Postgres tries to restore 00000022* WALs before timeline switch LSN has been reached while restoring 00000021*.
Commits
-
Prevent archive recovery from scanning non-existent WAL files.
- e3f5b148ed32 9.5.22 landed
- 70b5979742f8 9.6.18 landed
- 660f1fc40d7a 10.13 landed
- dcd1569fb05d 11.8 landed
- 683e0ef5530f 12.3 landed
- 4bd0ad9e44be 13.0 landed