RE: BUG #17375: RECOVERY TARGET TIME RESTORE IS FAILING TO START SERVER - Mailing list pgsql-bugs

Hello,

The problem is that we are providing a time target that Postgres does not know how to reach. This is because there are
notransactions in between the backups.
 
For example, if I take two backups but don't have any transactions in between them the restore will fail to any point
intime between them.
 
However, if we add a transaction between the backups and restore to a time before that transaction then the restore is
successful.

Prior to 13, a missed target would be ignored, and recovery would play to the end of the WAL. So, this issue was not
seenwith earlier versions.
 
Please suggest how can we achieve a successful restore in this case.

Thanks and Regards,
Ganesh Kishan

-----Original Message-----
From: PG Bug reporting form <noreply@postgresql.org> 
Sent: 20 January 2022 20:06
To: pgsql-bugs@lists.postgresql.org
Cc: B Ganesh Kishan <bkishan@commvault.com>
Subject: BUG #17375: RECOVERY TARGET TIME RESTORE IS FAILING TO START SERVER

External email. Inspect before opening.



The following bug has been logged on the website:

Bug reference:      17375
Logged by:          Ganesh Kishan
Email address:      bkishan@commvault.com
PostgreSQL version: 13.5
Operating system:   RHEL 7.6
Description:

Hi Team,

I am trying to restore a PG13 server to a particular point in time.

These are the recovery settings in postgresql.conf:
restore_command = 'cp /var/lib/pgsql/13/wal/%f %p'
recovery_end_command = 'touch
/var/lib/pgsql/13/data_small/recovery.done.cv'
recovery_target_time = '2022-01-20 07:22:00GMT'
recovery_target_action = promote

I see the server fails to start with below error in :

-bash-4.2$ tail -f postgresql-Thu.log
2022-01-20 19:57:10.937 IST [34742] LOG:  starting PostgreSQL 13.5 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 4.8.5
20150623(Red Hat 4.8.5-44), 64-bit
 
2022-01-20 19:57:10.938 IST [34742] LOG:  listening on IPv4 address "0.0.0.0", port 5432
2022-01-20 19:57:10.938 IST [34742] LOG:  listening on IPv6 address "::", port 5432
2022-01-20 19:57:10.938 IST [34742] LOG:  listening on Unix socket "/var/run/postgresql/.s.PGSQL.5432"
2022-01-20 19:57:10.939 IST [34742] LOG:  listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-01-20 19:57:10.942 IST [34744] LOG:  database system was interrupted; last known up at 2022-01-20 12:10:21 IST
cp: cannot stat ‘/var/lib/pgsql/13/wal/00000003.history’: No such file or directory
2022-01-20 19:57:10.967 IST [34744] LOG:  starting point-in-time recovery to
2022-01-20 12:52:00+05:30
2022-01-20 19:57:10.970 IST [34744] LOG:  restored log file "00000002.history" from archive
2022-01-20 19:57:10.988 IST [34744] LOG:  restored log file "000000020000000000000011" from archive
2022-01-20 19:57:11.190 IST [34744] LOG:  redo starts at 0/11000060
2022-01-20 19:57:11.190 IST [34744] LOG:  consistent recovery state reached at 0/11000170
2022-01-20 19:57:11.191 IST [34742] LOG:  database system is ready to accept read only connections
2022-01-20 19:57:11.208 IST [34744] LOG:  restored log file "000000020000000000000012" from archive
2022-01-20 19:57:11.350 IST [34744] LOG:  restored log file "000000020000000000000013" from archive
2022-01-20 19:57:11.500 IST [34744] LOG:  restored log file "000000020000000000000014" from archive
2022-01-20 19:57:11.626 IST [34744] LOG:  restored log file "000000020000000000000015" from archive
2022-01-20 19:57:11.795 IST [34744] LOG:  restored log file "000000020000000000000016" from archive
2022-01-20 19:57:11.890 IST [34744] LOG:  restored log file "000000020000000000000017" from archive
2022-01-20 19:57:12.041 IST [34744] LOG:  restored log file "000000020000000000000018" from archive
2022-01-20 19:57:12.089 IST [34744] LOG:  restored log file "000000020000000000000019" from archive
2022-01-20 19:57:12.126 IST [34744] LOG:  restored log file "00000002000000000000001A" from archive
2022-01-20 19:57:12.165 IST [34744] LOG:  restored log file "00000002000000000000001B" from archive
2022-01-20 19:57:12.196 IST [34744] LOG:  restored log file "00000002000000000000001C" from archive
2022-01-20 19:57:12.244 IST [34744] LOG:  restored log file "00000002000000000000001D" from archive
cp: cannot stat ‘/var/lib/pgsql/13/wal/00000002000000000000001E’: No such file or directory
2022-01-20 19:57:12.320 IST [34744] LOG:  redo done at 0/1D000148
2022-01-20 19:57:12.320 IST [34744] FATAL:  recovery ended before configured recovery target was reached
2022-01-20 19:57:12.322 IST [34742] LOG:  startup process (PID 34744) exited with exit code 1
2022-01-20 19:57:12.322 IST [34742] LOG:  terminating any other active server processes
2022-01-20 19:57:12.325 IST [34742] LOG:  database system is shut down


For restoring till the specified time we need 000000020000000000000016 log which is already present.
Still its failing with: FATAL:  recovery ended before configured recovery target was reached.
Same steps are working with PostgreSQL 12 but failing for PostgreSQL13. Did anything change in this part?