Re: recovery_target_time ignored ?

On Tue, Mar 24, 2015 at 9:54 AM, David Steele <david(at)pgmasters(dot)net> wrote:

> On 3/23/15 12:42 AM, Venkata Balaji N wrote:
> > Hi,
> >
> > Assuming that this might require a patch, i am posting this in
> > pgsql-hackers. Apologies, if this is not the appropriate mailing list to
> > start this discussion.
> >
> > I performed a PITR and saw the below message in the log file is a bit
> > confusing.
> >
> > 2015-03-23 13:49:09.816 GMT-10 DB= PID=4707 LOG: *database system was
> > interrupted; last known up at 2015-03-23 10:30:26 GMT-10*
> > 2015-03-23 13:49:09.817 GMT-10 DB= PID=4707 LOG: *starting point-in-time
> > recovery to 2015-03-23 10:00:26+10*
> > 2015-03-23 13:49:09.827 GMT-10 DB= PID=4707 LOG: restored log file
> > "000000010000000B00000020" from archive
> > 2015-03-23 13:49:09.888 GMT-10 DB= PID=4707 LOG: redo starts at
> B/20000090
> > 2015-03-23 13:49:09.937 GMT-10 DB= PID=4707 LOG: consistent recovery
> > state reached at B/200000B8
> > 2015-03-23 13:49:09.947 GMT-10 DB= PID=4707 LOG: restored log file
> > "000000010000000B00000021" from archive
> > 2015-03-23 13:49:09.950 GMT-10 DB= PID=4707 LOG: *recovery stopping
> > before commit of transaction 16267, time 2015-03-23 13:22:37.53007+10*
> >
> >
> > By mistake i gave "recovery_target_time" as 10:00 GMT which is 25/30
> > minutes behind the backup start/end time registered in the backup_label.
> >
> > The parameter recovery_target_time is ignored and recovery proceeds
> > further applying all the available WAL Archive files finally ends up
> > bringing up the database.
> >
> > I think it would make sense if the recovery does not proceed any further
> > and error out with a message like "recovery_target_time is behind the
> > backup time.. please consider using the backup taken prior to the
> > recovery_target_time"
>
> I just tried it with 9.3.5 and I do get an error:
>
> LOG: starting point-in-time recovery to 2015-03-23 17:26:02.721307-04
> LOG: restored log file "000000010000000000000003" from archive
> LOG: redo starts at 0/30000C8
> LOG: recovery stopping before commit of transaction 1001, time
> 2015-03-23 18:26:01.012593-04
> LOG: redo done at 0/3000228
> FATAL: requested recovery stop point is before consistent recovery point
>

That makes more sense. This is what i was expecting to happen. Then, i
think it is something to do with the timestamp format.

> Here's my recovery.conf file:
>
> restore_command = '/usr/bin/pg_backrest.pl --stanza=db archive-get %f
> "%p"'
> recovery_target_time = '2015-03-23 17:26:02.721307 EDT'
>
> > recovery.conf file is as follows :
> >
> > restore_command='cp /data/pgdata9400backup/pgwalarch9400backup/%f %p '
> > recovery_target_time='2015-03-23 10:00:26 GMT-10'
> > recovery_target_inclusive='true'
>
> You have '2015-03-23 10:00:26 GMT-10' in recovery.conf but the log says
> 'starting point-in-time recovery to 2015-03-23 10:00:26+10'. Note the -
> vs +.
>

This is my confusion too. I picked up the time format from the backup label.

Could you check your log and recovery.conf and make sure the timezone
> offsets are actually different?
>

I am not sure why the timestamp is taken as "2015-03-23 10:00:26+10"
for "2015-03-23
10:00:26 GMT-10'".

My another system's timestamp format is also AEDT. I did another test and I
get the same problem.

Below is the text from the log file. I gave a recovery_target_time almost a
day behind the consistent recovery point. Still, the recovery_target_time
is taken as "*2015-03-23 11:07:10+11*" for "*2015-03-23 11:07:10 AEDT*"

2015-03-24 18:42:44.608 AEDT LOG: database system was interrupted; last
known up at *2015-03-24 18:20:53 AEDT*

2015-03-24 18:42:44.608 AEDT LOG: starting point-in-time recovery to
*2015-03-23
11:07:10+11*

cp: /disk3/pgwalarch9401/0000000100000003000000FE: No such file or directory

2015-03-24 18:42:44.626 AEDT LOG: record with zero length at 3/FE000090

Below is my recovery.conf file

restore_command='cp /disk3/pgwalarch9401/%f %p'

recovery_target_time='*2015-03-23 11:07:10 AEDT*'

recovery_target_inclusive=true

I am checking if this has something to do with my system timestamp format.

Not sure what am i missing. Do i need to give any special time format ?

Regards,
Venkata Balaji N