Re: PITR potentially broken in 9.2

On 2012-11-27 10:08:12 -0800, Jeff Janes wrote:
> Doing PITR in 9.2.1, the system claims that it reached a consistent
> recovery state immediately after redo starts.
> This leads to it various mysterious failures, when it should instead
> throw a "requested recovery stop point is before consistent recovery
> point" error.
> (If you are unlucky, I think it might even silently start up in a
> corrupt state.)
>
> This seems to have been introduced in:
> commit 8366c7803ec3d0591cf2d1226fea1fee947d56c3
> Author: Simon Riggs <simon(at)2ndQuadrant(dot)com>
> Date: Wed Jan 25 18:02:04 2012 +0000
>
> Allow pg_basebackup from standby node with safety checking.
> Base backup follows recommended procedure, plus goes to great
> lengths to ensure that partial page writes are avoided.
>
> Jun Ishizuka and Fujii Masao, with minor modifications
>
>
> the backup file:
>
> START WAL LOCATION: 1/CD89E48 (file 00000001000000010000000C)
> STOP WAL LOCATION: 1/1AFA11A0 (file 00000001000000010000001A)
> CHECKPOINT LOCATION: 1/188D8120
> BACKUP METHOD: pg_start_backup
> BACKUP FROM: master
> START TIME: 2012-11-27 09:40:13 PST
> LABEL: label
> STOP TIME: 2012-11-27 09:42:10 PST
>
> (The file 00000001000000010000000C was archived at 9:37.)
>
> recovery.conf:
> restore_command = 'cp /tmp/archivedir/%f %p'
> recovery_target_time = '2012-11-27 09:38:00 PST'
>
>
> Log file:
>
> 22110 2012-11-27 09:49:15.220 PST LOG: database system was
> interrupted; last known up at 2012-11-27 09:40:13 PST
> 22110 2012-11-27 09:49:15.235 PST LOG: starting point-in-time
> recovery to 2012-11-27 09:38:00-08
> 22110 2012-11-27 09:49:15.271 PST LOG: restored log file
> "000000010000000100000018" from archive
> 22110 2012-11-27 09:49:15.367 PST LOG: restored log file
> "00000001000000010000000C" from archive
> 22110 2012-11-27 09:49:15.372 PST LOG: redo starts at 1/CD89E48

Hm. Are you sure its actually reading your backup file? Its hard to say
without DEBUG1 output but I would tentatively say its not reading it at
all because the the "redo starts at ..." message indicates its not using
the checkpoint location from the backup file.

Can you reproduce the issue? If so, can you give an exact guide? If not,
do you still have the datadir et al. from above?

Greetings,

Andres Freund

--
Andres Freund http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services