Search Postgresql Archives

Re: Restore postgres to specific time

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 






On Tue, Nov 27, 2012 at 8:27 AM, Jeff Janes <jeff.janes@xxxxxxxxx> wrote:
On Mon, Nov 26, 2012 at 12:23 PM, Kevin Grittner <kgrittn@xxxxxxxx> 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. :)

 

Cheers,

Jeff


[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]
[Index of Archives]     [Postgresql Jobs]     [Postgresql Admin]     [Postgresql Performance]     [Linux Clusters]     [PHP Home]     [PHP on Windows]     [Kernel Newbies]     [PHP Classes]     [PHP Books]     [PHP Databases]     [Postgresql & PHP]     [Yosemite]
  Powered by Linux