BUG #16159: recovery requests WALs for the next timelines before timeline switch LSN has been reached

From: PG Bug reporting form <noreply(at)postgresql(dot)org>
To: pgsql-bugs(at)lists(dot)postgresql(dot)org
Cc: psuderevsky(at)gmail(dot)com
Subject: BUG #16159: recovery requests WALs for the next timelines before timeline switch LSN has been reached
Date: 2019-12-11 12:39:20
Message-ID: 16159-f5a34a3a04dc67e0@postgresql.org
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-bugs pgsql-hackers

The following bug has been logged on the website:

Bug reference: 16159
Logged by: Pavel Suderevsky
Email address: psuderevsky(at)gmail(dot)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*.

Responses

Browse pgsql-bugs by date

  From Date Subject
Next Message Robert Haas 2019-12-11 14:17:35 Re: BUG #16059: Tab-completion of filenames in COPY commands removes required quotes
Previous Message Amul 2019-12-11 11:27:04 Postgres 11.2 given error "Failed to initialize transaction_deferrable to 0"

Browse pgsql-hackers by date

  From Date Subject
Next Message Ranier Vilela 2019-12-11 12:52:38 RE: [Proposal] Level4 Warnings show many shadow vars
Previous Message Michael Paquier 2019-12-11 12:15:07 Re: error context for vacuum to include block number