PITR potentially broken in 9.2 - Mailing list pgsql-bugs

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@2ndQuadrant.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
22110  2012-11-27 09:49:15.374 PST LOG:  consistent recovery state
reached at 1/CD8B7F0
22110  2012-11-27 09:49:15.490 PST LOG:  restored log file
"00000001000000010000000D" from archive
22110  2012-11-27 09:49:15.775 PST LOG:  restored log file
"00000001000000010000000E" from archive
22110  2012-11-27 09:49:16.078 PST LOG:  restored log file
"00000001000000010000000F" from archive
22110  2012-11-27 09:49:16.345 PST LOG:  restored log file
"000000010000000100000010" from archive
22110  2012-11-27 09:49:16.533 PST LOG:  recovery stopping before
commit of transaction 951967, time 2012-11-27 09:38:00.000689-08
22110  2012-11-27 09:49:16.533 PST LOG:  redo done at 1/10F41900
22110  2012-11-27 09:49:16.533 PST LOG:  last completed transaction
was at log time 2012-11-27 09:37:59.998496-08
22110  2012-11-27 09:49:16.537 PST LOG:  selected new timeline ID: 2
22110  2012-11-27 09:49:16.584 PST LOG:  archive recovery complete
22113  2012-11-27 09:49:16.599 PST LOG:  checkpoint starting:
end-of-recovery immediate wait
22113  2012-11-27 09:49:17.815 PST LOG:  checkpoint complete: wrote
8336 buffers (12.7%); 0 transaction log file(s) added, 0 removed, 0
recycled; write=0.097 s, sync=1.115 s, total=1.230 s; sync files=14,
longest=0.578 s, average=0.079 s
22110  2012-11-27 09:49:17.929 PST FATAL:  could not access status of
transaction 1014015
22110  2012-11-27 09:49:17.929 PST DETAIL:  Could not read from file
"pg_clog/0000" at offset 245760: Success.
22109  2012-11-27 09:49:17.932 PST LOG:  startup process (PID 22110)
exited with exit code 1
22109  2012-11-27 09:49:17.932 PST LOG:  terminating any other active
server processes

Cheers,

Jeff