We are using Crunchy PGO which uses "pgbackrest".
Over Christmas we had a disk full error on the "pgbackrest" repo followed by a disk full error on the PostgreSQL instance pod.
Unfortunately, a colleague then deleted the current "pg_wal" directory on the instance pod. So we had to do a point-in-time recovery to overcome this situation. we started a PITR to 2022-12-23 01:34 based on the following "pgbackrest" backup: sh-4.4$ pgbackrest info stanza: db status: ok cipher: none db (current) wal archive min/max (13): 0000000B0000010B000000C1/0000000C000001110000000A full backup: 20221222-230004F timestamp start/stop: 2022-12-22 23:00:04 / 2022-12-23 01:32:17 wal start/stop: 0000000B0000010B000000C1 / 0000000B0000010C0000005C database size: 46.3GB, database backup size: 46.3GB repo1: backup set size: 17.6GB, backup size: 17.6GB During the point-in-time recovery, the "pgbackrest" pod terminated incorrectly with an error "pg_ctl: server did not start in time".
There is a known PGO bug on this (pg_ctl default timeout of 60 secs cannot be changed). PGO started the instance pod anyway in following, which leads to a regular PostgreSQL crash recovery ending with "last completed transaction was at log time 2022-12-23 20:52:29.584555+01": ... 2023-01-04 15:26:35 CET : =>@ : 94-4=>63b58c9b.5e : 00000 LOG: starting PostgreSQL 13.7 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 8.5.0 20210514 (Red Hat 8.5.0-10), 64-bit 2023-01-04 15:26:35 CET : =>@ : 94-5=>63b58c9b.5e : 00000 LOG: listening on IPv4 address "0.0.0.0", port 5432 2023-01-04 15:26:35 CET : =>@ : 94-6=>63b58c9b.5e : 00000 LOG: listening on IPv6 address "::", port 5432 2023-01-04 15:26:35 CET : =>@ : 94-7=>63b58c9b.5e : 00000 LOG: listening on Unix socket "/tmp/postgres/.s.PGSQL.5432" 2023-01-04 15:26:35 CET : =>@ : 108-1=>63b58c9b.6c : 00000 LOG: database system was interrupted while in recovery at log time 2022-12-23 01:06:58 CET 2023-01-04 15:26:35 CET : =>@ : 108-2=>63b58c9b.6c : 00000 HINT: If this has occurred more than once some data might be corrupted and you might need to choose an earlier recovery target. 2023-01-04 15:26:35 CET : =>@ : 108-3=>63b58c9b.6c : 00000 LOG: entering standby mode 2023-01-04 15:26:35 CET : =>@ : 108-4=>63b58c9b.6c : 00000 LOG: restored log file "0000000B.history" from archive 2023-01-04 15:26:35 CET : =>@ : 108-5=>63b58c9b.6c : 00000 LOG: restored log file "0000000B0000010C0000000C" from archive ... 2023-01-04 15:30:06 CET : =>@ : 108-1198=>63b58c9b.6c : 00000 LOG: restored log file "0000000B00000110000000AD" from archive 2023-01-04 15:30:06 CET : =>@ : 108-1199=>63b58c9b.6c : 00000 LOG: received promote request 2023-01-04 15:30:06 CET : =>@ : 108-1200=>63b58c9b.6c : 00000 LOG: redo done at 110/AD0005B8 2023-01-04 15:30:06 CET : =>@ : 108-1201=>63b58c9b.6c : 00000 LOG: last completed transaction was at log time 2022-12-23 20:52:29.584555+01 2023-01-04 15:30:07 CET : =>@ : 108-1202=>63b58c9b.6c : 00000 LOG: restored log file "0000000B00000110000000AD" from archive 2023-01-04 15:30:07 CET : =>@ : 108-1203=>63b58c9b.6c : 00000 LOG: selected new timeline ID: 12 2023-01-04 15:30:07 CET : =>@ : 108-1204=>63b58c9b.6c : 00000 LOG: archive recovery complete 2023-01-04 15:30:07 CET : =>@ : 108-1205=>63b58c9b.6c : 00000 LOG: restored log file "0000000B.history" from archive 2023-01-04 15:30:07 CET : =>@ : 94-9=>63b58c9b.5e : 00000 LOG: database system is ready to accept connections ... QUESTION: ========= I wondered how the crash recovery can run to 2022-12-23 20:52:29.584555 and simply open the database?
When I got it right the full backup itself would be consistent with "wal stop 0000000B0000010C0000005C". PostgreSQL additionally added some wal files until 0000000B00000110000000AD (2022-12-23 20:52:29.584555) because it didn't find any more before the recovery target of 2022-12-23 01:34. Am I right or did I miss something? |