Restore postgres to specific time

wd wrote:

I've try to restore Postgres to a specific time but failed.

The recovery.conf as bellow
restore_command='cp /t/xlog/%f %p'
recovery_target_time='2012-11-22 5:01:09 CST'
pause_at_recovery_target=true
recovery_target_inclusive=false

The basebackup was made at 2012-11-22 3:10 CST, I've copy wal log files at 3:00 to 5:10 into /t/xlog,
but the recovery will not stop at 2012-11-22 5:01:09。

How to do this?

Looks ok.
What does the server log say during the restore?

Yours,
Laurenz Albe

Thanks for your reply, the logs are something like bellow，postgres will
restore every wal log I put in the xlog directory，and then continues
waiting for next wal log. The postgres version is 9.1.6.

[ 2012-11-22 18:49:24.175 CST 25744 50ae0334.6490 1 0]LOG: database
system was shut down in recovery at 2012-11-22 18:49:22 CST
[ 2012-11-22 18:49:24.176 CST 25744 50ae0334.6490 2 0]LOG: entering
standby mode
[ 2012-11-22 18:49:24.210 CST 25744 50ae0334.6490 3 0]LOG: restored log
file "000000010000002800000023" from archive
[ 2012-11-22 18:49:24.213 CST 25744 50ae0334.6490 4 0]LOG: redo starts
at 28/23001900
[ 2012-11-22 18:49:24.619 CST 25744 50ae0334.6490 5 0]LOG: consistent
recovery state reached at 28/23FFFFC8
[ 2012-11-22 18:49:24.620 CST 25736 50ae0333.6488 2 0]LOG: database
system is ready to accept read only connections
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
[ 2012-11-22 18:50:49.828 CST 25744 50ae0334.6490 6 0]LOG: restored log
file "000000010000002800000024" from archive
[ 2012-11-22 18:50:50.291 CST 25744 50ae0334.6490 7 0]LOG: restored log
file "000000010000002800000025" from archive
[ 2012-11-22 18:50:50.759 CST 25744 50ae0334.6490 8 0]LOG: restored log
file "000000010000002800000026" from archive
[ 2012-11-22 18:50:51.220 CST 25744 50ae0334.6490 9 0]LOG: restored log
file "000000010000002800000027" from archive
[ 2012-11-22 18:50:51.686 CST 25744 50ae0334.6490 10 0]LOG: restored
log file "000000010000002800000028" from archive
[ 2012-11-22 18:50:52.145 CST 25744 50ae0334.6490 11 0]LOG: restored
log file "000000010000002800000029" from archive
[ 2012-11-22 18:50:52.613 CST 25744 50ae0334.6490 12 0]LOG: restored
log file "00000001000000280000002A" from archive
[ 2012-11-22 18:50:53.073 CST 25744 50ae0334.6490 13 0]LOG: restored
log file "00000001000000280000002B" from archive
[ 2012-11-22 18:50:53.538 CST 25744 50ae0334.6490 14 0]LOG: restored
log file "00000001000000280000002C" from archive
[ 2012-11-22 18:50:53.999 CST 25744 50ae0334.6490 15 0]LOG: restored
log file "00000001000000280000002D" from archive
[ 2012-11-22 18:50:54.459 CST 25744 50ae0334.6490 16 0]LOG: restored
log file "00000001000000280000002E" from archive
[ 2012-11-22 18:50:54.920 CST 25744 50ae0334.6490 17 0]LOG: restored
log file "00000001000000280000002F" from archive
cp: cannot stat `/export/t/xlog/000000010000002800000030': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000030': No such file or
directory

On Thu, Nov 22, 2012 at 10:39 PM, Albe Laurenz <laurenz.albe@wien.gv.at>wrote:

On Fri, Nov 23, 2012 at 8:59 AM, wd <wd@wdicc.com> wrote:

Thanks for your reply, the logs are something like bellow，postgres will
restore every wal log I put in the xlog directory，and then continues
waiting for next wal log. The postgres version is 9.1.6.

[ 2012-11-22 18:49:24.175 CST 25744 50ae0334.6490 1 0]LOG: database
system was shut down in recovery at 2012-11-22 18:49:22 CST
[ 2012-11-22 18:49:24.176 CST 25744 50ae0334.6490 2 0]LOG: entering
standby mode
[ 2012-11-22 18:49:24.210 CST 25744 50ae0334.6490 3 0]LOG: restored
log file "000000010000002800000023" from archive
[ 2012-11-22 18:49:24.213 CST 25744 50ae0334.6490 4 0]LOG: redo starts
at 28/23001900
[ 2012-11-22 18:49:24.619 CST 25744 50ae0334.6490 5 0]LOG: consistent
recovery state reached at 28/23FFFFC8
[ 2012-11-22 18:49:24.620 CST 25736 50ae0333.6488 2 0]LOG: database
system is ready to accept read only connections
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or
directory
[ 2012-11-22 18:50:49.828 CST 25744 50ae0334.6490 6 0]LOG: restored
log file "000000010000002800000024" from archive
[ 2012-11-22 18:50:50.291 CST 25744 50ae0334.6490 7 0]LOG: restored
log file "000000010000002800000025" from archive
[ 2012-11-22 18:50:50.759 CST 25744 50ae0334.6490 8 0]LOG: restored
log file "000000010000002800000026" from archive
[ 2012-11-22 18:50:51.220 CST 25744 50ae0334.6490 9 0]LOG: restored
log file "000000010000002800000027" from archive
[ 2012-11-22 18:50:51.686 CST 25744 50ae0334.6490 10 0]LOG: restored
log file "000000010000002800000028" from archive
[ 2012-11-22 18:50:52.145 CST 25744 50ae0334.6490 11 0]LOG: restored
log file "000000010000002800000029" from archive
[ 2012-11-22 18:50:52.613 CST 25744 50ae0334.6490 12 0]LOG: restored
log file "00000001000000280000002A" from archive
[ 2012-11-22 18:50:53.073 CST 25744 50ae0334.6490 13 0]LOG: restored
log file "00000001000000280000002B" from archive
[ 2012-11-22 18:50:53.538 CST 25744 50ae0334.6490 14 0]LOG: restored
log file "00000001000000280000002C" from archive
[ 2012-11-22 18:50:53.999 CST 25744 50ae0334.6490 15 0]LOG: restored
log file "00000001000000280000002D" from archive
[ 2012-11-22 18:50:54.459 CST 25744 50ae0334.6490 16 0]LOG: restored
log file "00000001000000280000002E" from archive
[ 2012-11-22 18:50:54.920 CST 25744 50ae0334.6490 17 0]LOG: restored
log file "00000001000000280000002F" from archive
cp: cannot stat `/export/t/xlog/000000010000002800000030': No such file or
directory
cp: cannot stat `/export/t/xlog/000000010000002800000030': No such file or
directory

As per logs,it is working as a host-standby. For doing the point in time

recovery,recovery.conf file requires only two settings:

restore_command='cp /t/xlog/%f %p'
recovery_target_time='2012-11-22 5:01:09 CST'

--Raghu Ram

wd wrote:

I've try to restore Postgres to a specific time but failed.

The recovery.conf as bellow
restore_command='cp /t/xlog/%f %p'
recovery_target_time='2012-11-22 5:01:09 CST'
pause_at_recovery_target=true
recovery_target_inclusive=false

The basebackup was made at 2012-11-22 3:10 CST, I've copy wal log files at 3:00 to 5:10 into /t/xlog,
but the recovery will not stop at 2012-11-22 5:01:09。

How to do this?

Thanks for your reply, the logs are something like bellow，postgres will restore every wal log I put
in the xlog directory，and then continues waiting for next wal log. The postgres version is 9.1.6.

[ 2012-11-22 18:49:24.176 CST 25744 50ae0334.6490 2 0]LOG: entering standby mode
[ 2012-11-22 18:49:24.210 CST 25744 50ae0334.6490 3 0]LOG: restored log file
"000000010000002800000023" from archive
[ 2012-11-22 18:49:24.213 CST 25744 50ae0334.6490 4 0]LOG: redo starts at 28/23001900
[ 2012-11-22 18:49:24.619 CST 25744 50ae0334.6490 5 0]LOG: consistent recovery state reached at
28/23FFFFC8
[ 2012-11-22 18:49:24.620 CST 25736 50ae0333.6488 2 0]LOG: database system is ready to accept read
only connections
cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or directory

[...]

cp: cannot stat `/export/t/xlog/000000010000002800000024': No such file or directory
[ 2012-11-22 18:50:49.828 CST 25744 50ae0334.6490 6 0]LOG: restored log file
"000000010000002800000024" from archive

[...]

[ 2012-11-22 18:50:54.920 CST 25744 50ae0334.6490 17 0]LOG: restored log file
"00000001000000280000002F" from archive
cp: cannot stat `/export/t/xlog/000000010000002800000030': No such file or directory
cp: cannot stat `/export/t/xlog/000000010000002800000030': No such file or directory

Can you also show us postgresql.conf from the standby?

Try to find out where you are in log replay.

Connect to the standby and run the following query:

SELECT pg_last_xact_replay_timestamp();

It would be interesting what time that is.

Yours,
Laurenz Albe

On Thu, Nov 22, 2012 at 7:29 PM, wd <wd@wdicc.com> wrote:

Thanks for your reply, the logs are something like bellow，postgres will
restore every wal log I put in the xlog directory，and then continues waiting
for next wal log. The postgres version is 9.1.6.

[ 2012-11-22 18:49:24.175 CST 25744 50ae0334.6490 1 0]LOG: database
system was shut down in recovery at 2012-11-22 18:49:22 CST
[ 2012-11-22 18:49:24.176 CST 25744 50ae0334.6490 2 0]LOG: entering
standby mode

Do you have standby_mode=on in your recovery.conf? If so, remove it.

It is meaningless to specify both standy_mode, and recovery_target_time.

Cheers,

Jeff

Yes, you are right, after set the two command, the recovery will stop at
that time.

But there is an other question, how to make this recovered Postgres can be
read and write? According to the manual, Postgres should be rename
recovery.conf to recovery.done, but it didn't.

I've tried pg_ctl promote, delete recovery.conf, it's also not work.

And, I've set hot_standby='on' in postgres.conf, but still can't connect
into this postgres ,why?

(sorry for the individual mail sent to you, I should send it to the list)

On Fri, Nov 23, 2012 at 5:02 PM, raghu ram <raghuchennuru@gmail.com> wrote:

On Sat, Nov 24, 2012 at 6:00 AM, wd <wd@wdicc.com> wrote:

Yes, you are right, after set the two command, the recovery will stop at
that time.

But there is an other question, how to make this recovered Postgres can be
read and write? According to the manual, Postgres should be rename
recovery.conf to recovery.done, but it didn't.

This is after you removed "standby_mode=on"?

It should happen automatically.

What entries are you getting in the log file?

Cheers,

Jeff

On Sun, Nov 25, 2012 at 4:25 AM, Jeff Janes <jeff.janes@gmail.com> wrote:

On Sat, Nov 24, 2012 at 6:00 AM, wd <wd@wdicc.com> wrote:

Yes, you are right, after set the two command, the recovery will stop at
that time.

But there is an other question, how to make this recovered Postgres can

be

read and write? According to the manual, Postgres should be rename
recovery.conf to recovery.done, but it didn't.

This is after you removed "standby_mode=on"?

Yes, the recovery file like this:

recovery_target_time='2012-11-24 03:35:09+8'
recovery_target_inclusive=true
restore_command='cp /export/t/xlog/%f %p'

It should happen automatically.

What entries are you getting in the log file?

Logs are something like this:

[ 2012-11-24 21:51:33.374 CST 583 50b0d0e5.247 1 0]LOG: database system
was shut down in recovery at 2012-11-24 21:51:32 CST
[ 2012-11-24 21:51:33.375 CST 583 50b0d0e5.247 2 0]LOG: starting
point-in-time recovery to 2012-11-24 03:35:09+08
[ 2012-11-24 21:51:33.415 CST 583 50b0d0e5.247 3 0]LOG: restored log
file "000000010000002B00000085" from archive
[ 2012-11-24 21:51:33.457 CST 583 50b0d0e5.247 4 0]LOG: restored log
file "000000010000002B00000084" from archive
[ 2012-11-24 21:51:33.458 CST 583 50b0d0e5.247 5 0]LOG: redo starts at
2B/8401D6E8
[ 2012-11-24 21:51:33.498 CST 583 50b0d0e5.247 6 0]LOG: restored log
file "000000010000002B00000085" from archive
[ 2012-11-24 21:51:33.591 CST 583 50b0d0e5.247 7 0]LOG: restored log
file "000000010000002B00000086" from archive
[ 2012-11-24 21:51:33.591 CST 583 50b0d0e5.247 8 0]LOG: recovery
stopping before commit of transaction 1573829, time 2012-11-24
03:35:17.704521+08
[ 2012-11-24 21:51:33.591 CST 583 50b0d0e5.247 9 0]LOG: recovery has
paused
[ 2012-11-24 21:51:33.591 CST 583 50b0d0e5.247 10 0]HINT: Execute
pg_xlog_replay_resume() to continue.

wd wrote:

Logs are something like this:
[ 2012-11-24 21:51:33.591 CST 583 50b0d0e5.247 9 0]LOG: recovery

has paused

[ 2012-11-24 21:51:33.591 CST 583 50b0d0e5.247 10 0]HINT: Execute

pg_xlog_replay_resume() to continue.

Well, try

SELECT pg_xlog_replay_resume();

Yours,
Laurenz Albe

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

I can't connect to postgres at that time.

On Mon, Nov 26, 2012 at 4:33 PM, Albe Laurenz <laurenz.albe@wien.gv.at>wrote:

wd wrote:

Logs are something like this:

[ 2012-11-24 21:51:33.591 CST 583 50b0d0e5.247 9 0]LOG: recovery

has paused

[ 2012-11-24 21:51:33.591 CST 583 50b0d0e5.247 10 0]HINT:

Execute pg_xlog_replay_resume() to continue.

Well, try

SELECT pg_xlog_replay_resume();

I can't connect to postgres at that time.

Duh.
Then the trick is not to pause at all.
Make sure that pause_at_recovery_target is not set in
recovery.conf.
Stop the recovering server, then start it again.
That should do the trick.

Yours,
Laurenz Albe

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

On Sat, Nov 24, 2012 at 3:44 PM, wd <wd@wdicc.com> wrote:

What entries are you getting in the log file?

Logs are something like this:

[ 2012-11-24 21:51:33.374 CST 583 50b0d0e5.247 1 0]LOG: database system
was shut down in recovery at 2012-11-24 21:51:32 CST
[ 2012-11-24 21:51:33.375 CST 583 50b0d0e5.247 2 0]LOG: starting
point-in-time recovery to 2012-11-24 03:35:09+08

...

[ 2012-11-24 21:51:33.591 CST 583 50b0d0e5.247 8 0]LOG: recovery
stopping before commit of transaction 1573829, time 2012-11-24
03:35:17.704521+08
[ 2012-11-24 21:51:33.591 CST 583 50b0d0e5.247 9 0]LOG: recovery has
paused
[ 2012-11-24 21:51:33.591 CST 583 50b0d0e5.247 10 0]HINT: Execute
pg_xlog_replay_resume() to continue.

Something is strange here. There is no message about reaching a
consistent recovery point (which is why it doesn't start in hot
standby mode I guess). But when I arrange for that to happen myself,
by specifying a time before consistent recovery would be reached, I
get this error:

FATAL: requested recovery stop point is before consistent recovery point

I don't understand why are you not getting this message. I wonder if
the earlier attempts you made at doing this left the system in some
inconsistent state. If you start over again with a fresh restore of
the base backup and a recovery.conf which is correctly configured the
first time you try to use it, do you still see this?

Cheers,

Jeff

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

Jeff Janes wrote:

FATAL: requested recovery stop point is before consistent recovery point

I don't understand why are you not getting this message.

Is it before the point where pg_stop_backup() was run?

-Kevin

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

On Mon, Nov 26, 2012 at 12:23 PM, Kevin Grittner <kgrittn@mail.com> wrote:

Jeff Janes wrote:

FATAL: requested recovery stop point is before consistent recovery point

I don't understand why are you not getting this message.

Is it before the point where pg_stop_backup() was run?

It turns out that the I had requested a time before even
pg_start_backup was run.

If I pick a time between start and stop, then I see the original
poster's symptoms. The database does not start, but gives no notice
of the problem.

Cheers,

Jeff

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

On Mon, Nov 26, 2012 at 11:32 PM, Albe Laurenz <laurenz.albe@wien.gv.at>wrote:

wd wrote:

Logs are something like this:

[ 2012-11-24 21:51:33.591 CST 583 50b0d0e5.247 9 0]LOG: recovery

has paused

[ 2012-11-24 21:51:33.591 CST 583 50b0d0e5.247 10 0]HINT:

Execute pg_xlog_replay_resume() to continue.

Well, try

SELECT pg_xlog_replay_resume();

I can't connect to postgres at that time.

Duh.
Then the trick is not to pause at all.
Make sure that pause_at_recovery_target is not set in
recovery.conf.
Stop the recovering server, then start it again.
That should do the trick.

I've tried set pause_at_recovery_target to true, it's not work. and also

tried comment out this setting it's the same.

Restart have no effect, the recovery.conf is always there, I think it's
should be rename to recovery.done if it's work.

On Tue, Nov 27, 2012 at 8:27 AM, Jeff Janes <jeff.janes@gmail.com> wrote:

On Mon, Nov 26, 2012 at 12:23 PM, Kevin Grittner <kgrittn@mail.com> wrote:

Jeff Janes wrote:

FATAL: requested recovery stop point is before consistent recovery point

I don't understand why are you not getting this message.

Is it before the point where pg_stop_backup() was run?

It turns out that the I had requested a time before even
pg_start_backup was run.

If I pick a time between start and stop, then I see the original
poster's symptoms. The database does not start, but gives no notice
of the problem.

I've tried after your mail, full log as below:

Extract PGDATA from a basebakup, and write a recovery.conf:
recovery_target_time='2012-11-27 03:20:09+8'
recovery_target_inclusive=false
restore_command='cp /export/t/xlog/%f %p'

The basebackup info:
START WAL LOCATION: 30/94000020 (file 000000010000003000000094)
STOP WAL LOCATION: 30/9A014DB0 (file 00000001000000300000009A)
CHECKPOINT LOCATION: 30/94000058
BACKUP METHOD: pg_start_backup
START TIME: 2012-11-27 03:00:05 CST
LABEL: omnipitr_slave_backup_with_master_callback
STOP TIME: 2012-11-27 03:34:45 CST

You can see, the time is between backup start and stop.

Now start postgres.

[ 2012-11-27 11:15:20.071 CST 8166 50b43048.1fe6 1 0]LOG: database
system was interrupted while in recovery at log time 2012-11-27 03:00:02 CST
[ 2012-11-27 11:15:20.071 CST 8166 50b43048.1fe6 2 0]HINT: If this has
occurred more than once some data might be corrupted and you might need to
choose an earlier recovery target.
[ 2012-11-27 11:15:20.072 CST 8166 50b43048.1fe6 3 0]LOG: starting
point-in-time recovery to 2012-11-27 03:20:09+08
[ 2012-11-27 11:15:20.109 CST 8166 50b43048.1fe6 4 0]LOG: restored log
file "000000010000003000000094" from archive
[ 2012-11-27 11:15:20.120 CST 8166 50b43048.1fe6 5 0]LOG: redo starts
at 30/94000020
[ 2012-11-27 11:15:20.178 CST 8166 50b43048.1fe6 6 0]LOG: restored log
file "000000010000003000000095" from archive
[ 2012-11-27 11:15:20.226 CST 8166 50b43048.1fe6 7 0]LOG: restored log
file "000000010000003000000096" from archive
[ 2012-11-27 11:15:20.271 CST 8166 50b43048.1fe6 8 0]LOG: restored log
file "000000010000003000000097" from archive
[ 2012-11-27 11:15:20.319 CST 8166 50b43048.1fe6 9 0]LOG: restored log
file "000000010000003000000098" from archive
[ 2012-11-27 11:15:20.320 CST 8166 50b43048.1fe6 10 0]LOG: recovery
stopping before commit of transaction 1799510, time 2012-11-27
03:20:51.98131+08
[ 2012-11-27 11:15:20.320 CST 8166 50b43048.1fe6 11 0]LOG: recovery has
paused
[ 2012-11-27 11:15:20.320 CST 8166 50b43048.1fe6 12 0]HINT: Execute
pg_xlog_replay_resume() to continue.

Restore will stop here, I've tried to connect, but failed.

[[unknown] [unknown] [unknown] 2012-11-27 11:15:31.519 CST 8174
50b43053.1fee 1 0]LOG: connection received: host=[local]
[postgres qads_product [unknown] [local] 2012-11-27 11:15:31.519 CST 8174
50b43053.1fee 2 0]FATAL: the database system is starting up

Then restart the Postgres, and wish it will stop recovery and let me login.

[ 2012-11-27 11:15:38.554 CST 8144 50b43047.1fd0 2 0]LOG: received
smart shutdown request
[ 2012-11-27 11:15:38.555 CST 8168 50b43048.1fe8 1 0]LOG: shutting down
[ 2012-11-27 11:15:38.579 CST 8168 50b43048.1fe8 2 0]LOG: database
system is shut down
[ 2012-11-27 11:15:41.423 CST 8189 50b4305d.1ffd 1 0]LOG: database
system was shut down in recovery at 2012-11-27 11:15:38 CST
[ 2012-11-27 11:15:41.423 CST 8189 50b4305d.1ffd 2 0]LOG: starting
point-in-time recovery to 2012-11-27 03:20:09+08
[ 2012-11-27 11:15:41.466 CST 8189 50b4305d.1ffd 3 0]LOG: restored log
file "000000010000003000000098" from archive
[ 2012-11-27 11:15:41.510 CST 8189 50b4305d.1ffd 4 0]LOG: restored log
file "000000010000003000000097" from archive
[ 2012-11-27 11:15:41.510 CST 8189 50b4305d.1ffd 5 0]LOG: redo starts
at 30/9701A2A8
[ 2012-11-27 11:15:41.552 CST 8189 50b4305d.1ffd 6 0]LOG: restored log
file "000000010000003000000098" from archive
[ 2012-11-27 11:15:41.554 CST 8189 50b4305d.1ffd 7 0]LOG: recovery
stopping before commit of transaction 1799510, time 2012-11-27
03:20:51.98131+08
[ 2012-11-27 11:15:41.554 CST 8189 50b4305d.1ffd 8 0]LOG: recovery has
paused
[ 2012-11-27 11:15:41.554 CST 8189 50b4305d.1ffd 9 0]HINT: Execute
pg_xlog_replay_resume() to continue.

The recovery.done is not there, change the settings in recovery.conf:
recovery_target_time='2012-11-27 03:40:09+8'

The time is after the base backup stop. Start postgres:

[ 2012-11-27 11:15:47.851 CST 8181 50b4305d.1ff5 2 0]LOG: received
smart shutdown request
[ 2012-11-27 11:15:47.852 CST 8191 50b4305d.1fff 1 0]LOG: shutting down
[ 2012-11-27 11:15:47.861 CST 8191 50b4305d.1fff 2 0]LOG: database
system is shut down
[ 2012-11-27 11:16:12.802 CST 8429 50b4307c.20ed 1 0]LOG: database
system was shut down in recovery at 2012-11-27 11:15:47 CST
[ 2012-11-27 11:16:12.803 CST 8429 50b4307c.20ed 2 0]LOG: starting
point-in-time recovery to 2012-11-27 03:40:09+08
[ 2012-11-27 11:16:12.845 CST 8429 50b4307c.20ed 3 0]LOG: restored log
file "000000010000003000000098" from archive
[ 2012-11-27 11:16:12.893 CST 8429 50b4307c.20ed 4 0]LOG: restored log
file "000000010000003000000097" from archive
[ 2012-11-27 11:16:12.893 CST 8429 50b4307c.20ed 5 0]LOG: redo starts
at 30/9701A2A8
[ 2012-11-27 11:16:12.935 CST 8429 50b4307c.20ed 6 0]LOG: restored log
file "000000010000003000000098" from archive
[ 2012-11-27 11:16:12.983 CST 8429 50b4307c.20ed 7 0]LOG: restored log
file "000000010000003000000099" from archive
[ 2012-11-27 11:16:13.030 CST 8429 50b4307c.20ed 8 0]LOG: restored log
file "00000001000000300000009A" from archive
[ 2012-11-27 11:16:13.032 CST 8429 50b4307c.20ed 9 0]LOG: consistent
recovery state reached at 30/9B000000
[ 2012-11-27 11:16:13.032 CST 8421 50b4307c.20e5 2 0]LOG: database
system is ready to accept read only connections
[ 2012-11-27 11:16:13.076 CST 8429 50b4307c.20ed 10 0]LOG: restored log
file "00000001000000300000009B" from archive
[ 2012-11-27 11:16:13.161 CST 8429 50b4307c.20ed 11 0]LOG: restored log
file "00000001000000300000009C" from archive
[ 2012-11-27 11:16:13.170 CST 8429 50b4307c.20ed 12 0]LOG: recovery
stopping before commit of transaction 1799547, time 2012-11-27
03:40:20.90089+08
[ 2012-11-27 11:16:13.170 CST 8429 50b4307c.20ed 13 0]LOG: recovery has
paused
[ 2012-11-27 11:16:13.170 CST 8429 50b4307c.20ed 14 0]HINT: Execute
pg_xlog_replay_resume() to continue.

Recovery stop again, and I can login, but I forgot the pass, so change the
pg_hba.conf, and restart again.

[[unknown] [unknown] [unknown] 2012-11-27 11:16:23.677 CST 8448
50b43087.2100 1 0]LOG: connection received: host=[local]
[[unknown] [unknown] [unknown] 2012-11-27 11:16:27.387 CST 8467
50b4308b.2113 1 0]LOG: connection received: host=[local]
[[unknown] [unknown] [unknown] 2012-11-27 11:16:56.638 CST 8523
50b430a8.214b 1 0]LOG: connection received: host=[local]
[[unknown] [unknown] [unknown] 2012-11-27 11:16:57.884 CST 8525
50b430a9.214d 1 0]LOG: connection received: host=[local]
[ 2012-11-27 11:17:24.844 CST 8421 50b4307c.20e5 3 0]LOG: received
smart shutdown request
[ 2012-11-27 11:17:24.845 CST 8431 50b4307c.20ef 1 0]LOG: shutting down
[ 2012-11-27 11:17:24.868 CST 8431 50b4307c.20ef 2 0]LOG: database
system is shut down
[ 2012-11-27 11:17:36.937 CST 8570 50b430d0.217a 1 0]LOG: database
system was shut down in recovery at 2012-11-27 11:17:24 CST
[ 2012-11-27 11:17:36.938 CST 8570 50b430d0.217a 2 0]LOG: starting
point-in-time recovery to 2012-11-27 03:40:09+08
[ 2012-11-27 11:17:36.979 CST 8570 50b430d0.217a 3 0]LOG: restored log
file "00000001000000300000009C" from archive
[ 2012-11-27 11:17:36.982 CST 8570 50b430d0.217a 4 0]LOG: redo starts
at 30/9C000650
[ 2012-11-27 11:17:36.982 CST 8570 50b430d0.217a 5 0]LOG: consistent
recovery state reached at 30/9C000CE0
[ 2012-11-27 11:17:36.983 CST 8570 50b430d0.217a 6 0]LOG: recovery
stopping before commit of transaction 1799547, time 2012-11-27
03:40:20.90089+08
[ 2012-11-27 11:17:36.983 CST 8570 50b430d0.217a 7 0]LOG: recovery has
paused
[ 2012-11-27 11:17:36.983 CST 8570 50b430d0.217a 8 0]HINT: Execute
pg_xlog_replay_resume() to continue.
[ 2012-11-27 11:17:36.983 CST 8561 50b430d0.2171 2 0]LOG: database
system is ready to accept read only connections

Connect again, Try to rename recovery.conf to recovery.done, but not work.
Postgres can't start.

[[unknown] [unknown] [unknown] 2012-11-27 11:18:24.206 CST 8696
50b43100.21f8 1 0]LOG: connection received: host=[local]
[postgres qads_product [unknown] [local] 2012-11-27 11:18:24.208 CST 8696
50b43100.21f8 2 0]LOG: connection authorized: user=postgres
database=qads_product
[postgres qads_product psql [local] 2012-11-27 11:18:27.691 CST 8696
50b43100.21f8 3 0]LOG: disconnection: session time: 0:00:03.485
user=postgres database=qads_product host=[local]
[ 2012-11-27 11:18:37.134 CST 8561 50b430d0.2171 3 0]LOG: received
smart shutdown request
[ 2012-11-27 11:18:37.135 CST 8572 50b430d0.217c 1 0]LOG: shutting down
[ 2012-11-27 11:18:37.143 CST 8572 50b430d0.217c 2 0]LOG: database
system is shut down
[ 2012-11-27 11:19:11.842 CST 8899 50b4312f.22c3 1 0]LOG: database
system was shut down in recovery at 2012-11-27 11:18:37 CST
[ 2012-11-27 11:19:11.843 CST 8899 50b4312f.22c3 2 0]LOG: could not
open file "pg_xlog/00000001000000300000009C" (log file 48, segment 156): No
such file or directory
[ 2012-11-27 11:19:11.843 CST 8899 50b4312f.22c3 3 0]LOG: invalid
primary checkpoint record
[ 2012-11-27 11:19:11.843 CST 8899 50b4312f.22c3 4 0]LOG: could not
open file "pg_xlog/00000001000000300000009C" (log file 48, segment 156): No
such file or directory
[ 2012-11-27 11:19:11.843 CST 8899 50b4312f.22c3 5 0]LOG: invalid
secondary checkpoint record
[ 2012-11-27 11:19:11.843 CST 8899 50b4312f.22c3 6 0]PANIC: could not
locate a valid checkpoint record
[ 2012-11-27 11:19:11.843 CST 8891 50b4312f.22bb 2 0]LOG: startup
process (PID 8899) was terminated by signal 6: Aborted
[ 2012-11-27 11:19:11.843 CST 8891 50b4312f.22bb 3 0]LOG: aborting
startup due to startup process failure

Reanme back the recovery.conf, and start it agagin.

[ 2012-11-27 11:19:35.110 CST 8939 50b43147.22eb 1 0]LOG: database
system was shut down in recovery at 2012-11-27 11:18:37 CST
[ 2012-11-27 11:19:35.111 CST 8939 50b43147.22eb 2 0]LOG: starting
point-in-time recovery to 2012-11-27 03:40:09+08
[ 2012-11-27 11:19:35.153 CST 8939 50b43147.22eb 3 0]LOG: restored log
file "00000001000000300000009C" from archive
[ 2012-11-27 11:19:35.156 CST 8939 50b43147.22eb 4 0]LOG: redo starts
at 30/9C000650
[ 2012-11-27 11:19:35.157 CST 8939 50b43147.22eb 5 0]LOG: consistent
recovery state reached at 30/9C000CE0
[ 2012-11-27 11:19:35.157 CST 8939 50b43147.22eb 6 0]LOG: recovery
stopping before commit of transaction 1799547, time 2012-11-27
03:40:20.90089+08
[ 2012-11-27 11:19:35.157 CST 8939 50b43147.22eb 7 0]LOG: recovery has
paused
[ 2012-11-27 11:19:35.157 CST 8939 50b43147.22eb 8 0]HINT: Execute
pg_xlog_replay_resume() to continue.
[ 2012-11-27 11:19:35.157 CST 8931 50b43146.22e3 2 0]LOG: database
system is ready to accept read only connections

Connect and execute 'select pg_xlog_replay_resume()'

[[unknown] [unknown] [unknown] 2012-11-27 11:19:56.946 CST 8964
50b4315c.2304 1 0]LOG: connection received: host=[local]
[postgres qads_product [unknown] [local] 2012-11-27 11:19:56.947 CST 8964
50b4315c.2304 2 0]LOG: connection authorized: user=postgres
database=qads_product
[postgres qads_product psql [local] 2012-11-27 11:20:05.567 CST 8964
50b4315c.2304 3 0]LOG: statement: select pg_xlog_replay_resume();
[ 2012-11-27 11:20:06.361 CST 8939 50b43147.22eb 9 0]LOG: redo done at
30/9C000CE0
cp: cannot stat `/export/t/xlog/00000002.history': No such file or directory
[ 2012-11-27 11:20:06.366 CST 8939 50b43147.22eb 10 0]LOG: selected new
timeline ID: 2
cp: cannot stat `/export/t/xlog/00000001.history': No such file or directory
[ 2012-11-27 11:20:06.372 CST 8939 50b43147.22eb 11 0]LOG: archive
recovery complete
[ 2012-11-27 11:20:06.479 CST 8931 50b43146.22e3 3 0]LOG: database
system is ready to accept connections
[ 2012-11-27 11:20:06.479 CST 8998 50b43166.2326 1 0]LOG: autovacuum
launcher started
[postgres qads_product psql [local] 2012-11-27 11:20:12.382 CST 8964
50b4315c.2304 4 0]LOG: disconnection: session time: 0:00:15.436
user=postgres database=qads_product host=[local]

The recovery is done.

Thanks for every helped me. :)

wd wrote:

the time is between backup start and stop.

That is the problem -- until the point where pg_stop_backup() was
run PostgreSQL can't be sure of having a consistent database. It is
waiting from enough WAL to get it there. My practice is always to
keep the last two base backups and all WAL from the start of the
earlier one to current. If I want to recover to a point in time
which was during a backup, I use the previous base backup, which is
complete and usable.

It does seem that there is an opportunity here to make it more
clear what is happening.

-Kevin

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

"Kevin Grittner" <kgrittn@mail.com> writes:

That is the problem -- until the point where pg_stop_backup() was
run PostgreSQL can't be sure of having a consistent database. It is
waiting from enough WAL to get it there. My practice is always to
keep the last two base backups and all WAL from the start of the
earlier one to current. If I want to recover to a point in time
which was during a backup, I use the previous base backup, which is
complete and usable.

It does seem that there is an opportunity here to make it more
clear what is happening.

Seems like we could throw an error if the requested stop time is earlier
than the pg_stop_backup time. (That should then allow some code
simplification --- I imagine currently we're doing a max() calculation
somewhere ...)

regards, tom lane

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general

On Tue, Nov 27, 2012 at 6:59 AM, Kevin Grittner <kgrittn@mail.com> wrote:

wd wrote:

the time is between backup start and stop.

That is the problem -- until the point where pg_stop_backup() was
run PostgreSQL can't be sure of having a consistent database. It is
waiting from enough WAL to get it there. My practice is always to
keep the last two base backups and all WAL from the start of the
earlier one to current. If I want to recover to a point in time
which was during a backup, I use the previous base backup, which is
complete and usable.

It does seem that there is an opportunity here to make it more
clear what is happening.

It seems like the code is already there to throw an error, it is just
that hot_standby=on somehow suppresses it during this window.

Cheers,

Jeff

--
Sent via pgsql-general mailing list (pgsql-general@postgresql.org)
To make changes to your subscription:
http://www.postgresql.org/mailpref/pgsql-general