archive recovery fetching wrong segments

Hello, hackers!

I`m investigating a complains from our clients about archive recovery
speed been very slow, and I`ve noticed a really strange and, I think, a
very dangerous recovery behavior.

When running multi-timeline archive recovery, for every requested segno
startup process iterates through every timeline in restore target
timeline history, starting from highest timeline and ending in current,
and tries to fetch the segno in question from this timeline.

Consider the following example.
Timelines:
ARCHIVE INSTANCE 'node'
================================================================================================================================

 TLI  Parent TLI  Switchpoint  Min Segno                 Max
Segno                 N segments  Size   Zratio  N backups  Status
================================================================================================================================

 3    2           0/AEFFEDE0   0000000300000000000000AE
0000000300000000000000D5  40          41MB   15.47   0 OK
 2    1           0/A08768D0   0000000200000000000000A0
0000000200000000000000AE  15          14MB   17.24   0 OK
 1    0           0/0          000000010000000000000001
0000000100000000000000BB  187         159MB  18.77   1          OK

Backup:
================================================================================================================================

 Instance  Version  ID      Recovery Time           Mode  WAL Mode 
TLI  Time  Data   WAL  Zratio  Start LSN  Stop LSN   Status
================================================================================================================================

 node      11       Q8C8IH  2020-04-06 02:13:31+03  FULL ARCHIVE 1/0   
3s  23MB  16MB    1.00  0/2000028  0/30000B8  OK

So when we are trying to restore this backup, located on Timeline 1, to
the restore target on Timeline 3, we are getting this in the PostgreSQL
log:
....
2020-04-05 23:24:36 GMT [28508]: [5-1] LOG:  restored log file
"00000003.history" from archive
INFO: PID [28511]: pg_probackup archive-get WAL file:
000000030000000000000002, remote: none, threads: 1/1, batch: 20
ERROR: PID [28511]: pg_probackup archive-get failed to deliver WAL file
000000030000000000000002, prefetched: 0/20, time elapsed: 0ms
INFO: PID [28512]: pg_probackup archive-get WAL file:
000000020000000000000002, remote: none, threads: 1/1, batch: 20
ERROR: PID [28512]: pg_probackup archive-get failed to deliver WAL file
000000020000000000000002, prefetched: 0/20, time elapsed: 0ms
INFO: PID [28513]: pg_probackup archive-get WAL file:
000000010000000000000002, remote: none, threads: 1/1, batch: 20
INFO: PID [28513]: pg_probackup archive-get copied WAL file
000000010000000000000002
2020-04-05 23:24:36 GMT [28508]: [6-1] LOG:  restored log file
"000000010000000000000002" from archive
...

Before requesting 000000010000000000000002 recovery tries to fetch
000000030000000000000002 and 000000020000000000000002 and that goes for
every segment, restored from the archive.
This tremendously slows down recovery speed, especially if archive is
located on remote machine with high latency network.
And it also may lead to feeding recovery with wrong WAL segment, located
on the next timeline.

Is there a reason behind this behavior?

Also I`ve  attached a patch, which fixed this issue for me, but I`m not
sure, that chosen approach is sound and didn`t break something.

--
Grigory Smolkin
Postgres Professional: http://www.postgrespro.com
The Russian Postgres Company