Re: BUG #16894: PANIC: WAL contains references to invalid pages

Good day,

There are inaccuracies in the description, correct data (
https://github.com/pgbackrest/pgbackrest/issues/796)

* Restore without using PITR, just from a backup.

* Correct recovery.conf:

restore_command = 'pgbackrest --stanza=foo-db archive-get %f "%p"'

Ср, 24 февр. 2021 г. в 12:43, PG Bug reporting form <noreply(at)postgresql(dot)org
>:

> The following bug has been logged on the website:
>
> Bug reference: 16894
> Logged by: Anton
> Email address: antkurochkin(at)gmail(dot)com
> PostgreSQL version: 9.6.20
> Operating system: Oracle Linux Server 7.6
> Description:
>
> Good day,
>
> We got error when PITR restoring individual databases from a backup using
> pgbackrest.
>
> Opened issue in pgbackrest repository:
> https://github.com/pgbackrest/pgbackrest/issues/796
> It would be great if you would look at this problem. All the information is
> in the issue.
>
> Pgbackrest developers offered to provide this information to the postgres
> folks.
>
> Turned out that the problem is playing WAL files on databases that are
> restored with zero files.
> The database files from the backup are restored successfully, but an error
> occurs when starting PG and playing WAL:
>
> ```
> < 2021-02-21 10:34:57.950 UTC > LOG: starting archive recovery
> < 2021-02-21 10:34:58.137 UTC > LOG: restored log file
> "000000010000007E0000007D" from archive
> < 2021-02-21 10:34:58.151 UTC > LOG: redo starts at 7E/7D0090A8
> < 2021-02-21 10:34:58.521 UTC > LOG: restored log file
> "000000010000007E0000007E" from archive
> < 2021-02-21 10:34:58.711 UTC > LOG: consistent recovery state reached at
> 7E/7EF5E478
> < 2021-02-21 10:34:58.915 UTC > LOG: restored log file
> "000000010000007E0000007F" from archive
> < 2021-02-21 10:34:59.415 UTC > LOG: restored log file
> "000000010000007E00000080" from archive
> < 2021-02-21 10:35:01.521 UTC > LOG: restored log file
> "000000010000007E00000081" from archive
> < 2021-02-21 10:35:02.110 UTC > LOG: restored log file
> "000000010000007E00000082" from archive
> < 2021-02-21 10:35:02.577 UTC > LOG: restored log file
> "000000010000007E00000083" from archive
> < 2021-02-21 10:35:03.045 UTC > LOG: restored log file
> "000000010000007E00000084" from archive
> < 2021-02-21 10:35:03.544 UTC > LOG: restored log file
> "000000010000007E00000085" from archive
> < 2021-02-21 10:35:03.985 UTC > LOG: restored log file
> "000000010000007E00000086" from archive
> < 2021-02-21 10:35:05.394 UTC > LOG: restored log file
> "000000010000007E00000087" from archive
> < 2021-02-21 10:35:05.945 UTC > LOG: restored log file
> "000000010000007E00000088" from archive
> < 2021-02-21 10:35:06.623 UTC > LOG: restored log file
> "000000010000007E00000089" from archive
> < 2021-02-21 10:35:07.264 UTC > LOG: restored log file
> "000000010000007E0000008A" from archive
> < 2021-02-21 10:35:07.831 UTC > LOG: restored log file
> "000000010000007E0000008B" from archive
> < 2021-02-21 10:35:08.318 UTC > LOG: restored log file
> "000000010000007E0000008C" from archive
> < 2021-02-21 10:35:08.892 UTC > LOG: restored log file
> "000000010000007E0000008D" from archive
> < 2021-02-21 10:35:09.050 UTC > WARNING: page 22659 of relation
> base/17221/17557 is uninitialized
> < 2021-02-21 10:35:09.050 UTC > CONTEXT: xlog redo at 7E/8D9C04C0 for
> Heap2/VISIBLE: cutoff xid 810424291 flags 1
> < 2021-02-21 10:35:09.050 UTC > PANIC: WAL contains references to invalid
> pages
> < 2021-02-21 10:35:09.050 UTC > CONTEXT: xlog redo at 7E/8D9C04C0 for
> Heap2/VISIBLE: cutoff xid 810424291 flags 1
> < 2021-02-21 10:35:09.675 UTC > LOG: startup process (PID 9) was
> terminated
> by signal 6: Aborted
> ```
>
> In WAL there is only one line for `page 27536`:
>
> ```
> rmgr: Heap2 len (rec/tot): 59/ 59, tx: 0, lsn:
> 7E/8D9C04C0, prev 7E/8D9BE508, desc: VISIBLE cutoff xid 810424291 flags 1,
> blkref #0: rel 1663/17221/17557 fork vm blk 0, blkref #1: rel
> 1663/17221/17557 blk 22659
> ```
>
> We tried to find another information in WALs for `xid 810424291` and `blk
> 22659` - nothing.
>
> A few records before 7E/8D9C04C0 from last checkpoint:
>
> ```
> rmgr: XLOG len (rec/tot): 106/ 106, tx: 0, lsn:
> 7E/8D99C4B0, prev 7E/8D99C478, desc: CHECKPOINT_ONLINE redo 7E/8D90D0D8;
> tli
> 1; prev tli 1; fpw true; xid 0:810982162; oid 476718; multi 1; offset 0;
> oldest xid 628489828 in DB 16386; oldest multi 1 in DB 17221; oldest/newest
> commit timestamp xid: 0/0; oldest running xid 810982162; online
> rmgr: Heap2 len (rec/tot): 57/ 7965, tx: 0, lsn:
> 7E/8D99C520, prev 7E/8D99C4B0, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 3, blkref #0: rel 1663/17221/17557 blk 22557 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8213, tx: 0, lsn:
> 7E/8D99E458, prev 7E/8D99C520, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 1, blkref #0: rel 1663/17221/17557 blk 22631 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8229, tx: 0, lsn:
> 7E/8D9A0488, prev 7E/8D99E458, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 3, blkref #0: rel 1663/17221/17557 blk 22632 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8117, tx: 0, lsn:
> 7E/8D9A24C8, prev 7E/8D9A0488, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 3, blkref #0: rel 1663/17221/17557 blk 22633 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8093, tx: 0, lsn:
> 7E/8D9A4498, prev 7E/8D9A24C8, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 1, blkref #0: rel 1663/17221/17557 blk 22634 FPW
> rmgr: Heap2 len (rec/tot): 64/ 8256, tx: 0, lsn:
> 7E/8D9A6450, prev 7E/8D9A4498, desc: VISIBLE cutoff xid 0 flags 2, blkref
> #0: rel 1663/17221/17557 fork vm blk 0 FPW, blkref #1: rel
> 1663/17221/17557 blk 22634
> rmgr: Heap2 len (rec/tot): 57/ 8101, tx: 0, lsn:
> 7E/8D9A84A8, prev 7E/8D9A6450, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 4, blkref #0: rel 1663/17221/17557 blk 22639 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8149, tx: 0, lsn:
> 7E/8D9AA468, prev 7E/8D9A84A8, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 1, blkref #0: rel 1663/17221/17557 blk 22640 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8213, tx: 0, lsn:
> 7E/8D9AC458, prev 7E/8D9AA468, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 1, blkref #0: rel 1663/17221/17557 blk 22641 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8093, tx: 0, lsn:
> 7E/8D9AE488, prev 7E/8D9AC458, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 4, blkref #0: rel 1663/17221/17557 blk 22642 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8141, tx: 0, lsn:
> 7E/8D9B0440, prev 7E/8D9AE488, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 2, blkref #0: rel 1663/17221/17557 blk 22643 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8125, tx: 0, lsn:
> 7E/8D9B2428, prev 7E/8D9B0440, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 1, blkref #0: rel 1663/17221/17557 blk 22646 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8245, tx: 0, lsn:
> 7E/8D9B4400, prev 7E/8D9B2428, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 3, blkref #0: rel 1663/17221/17557 blk 22648 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8237, tx: 0, lsn:
> 7E/8D9B6450, prev 7E/8D9B4400, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 1, blkref #0: rel 1663/17221/17557 blk 22649 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8221, tx: 0, lsn:
> 7E/8D9B8498, prev 7E/8D9B6450, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 3, blkref #0: rel 1663/17221/17557 blk 22652 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8229, tx: 0, lsn:
> 7E/8D9BA4D0, prev 7E/8D9B8498, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 3, blkref #0: rel 1663/17221/17557 blk 22653 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8157, tx: 0, lsn:
> 7E/8D9BC510, prev 7E/8D9BA4D0, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 3, blkref #0: rel 1663/17221/17557 blk 22655 FPW
> rmgr: Heap2 len (rec/tot): 57/ 8093, tx: 0, lsn:
> 7E/8D9BE508, prev 7E/8D9BC510, desc: FREEZE_PAGE cutoff xid 760982701
> ntuples 1, blkref #0: rel 1663/17221/17557 blk 22657 FPW
> rmgr: Heap2 len (rec/tot): 59/ 59, tx: 0, lsn:
> 7E/8D9C04C0, prev 7E/8D9BE508, desc: VISIBLE cutoff xid 810424291 flags 1,
> blkref #0: rel 1663/ 17221/17557 fork vm blk 0, blkref #1: rel
> 1663/17221/17557 blk 22659
> ```
>
> File `base/17221/17557` - is a file for DB, which restored with zero
> files.
>
> recovery.conf:
>
> ```
> restore_command = 'pgbackrest --stanza=foo-db archive-get %f "%p"'
> recovery_target_time = '2021-02-20 07:00:00'
> recovery_target_action = 'promote'
> ```
>
> --
С уважением,
Антон