情シスは何度でも甦るさ。

OracleDB/Ruby好きの情シス部員がお送りします

PostgreSQLでポイントインタイムリカバリ(PITR)で指定した時間で止めれなくてハマった話

最新までロールバックされちゃうんです

新しいシステムで、Windows Server上でPostgreSQL 10.4 を使うことになり、ポイントインタイムリカバリのテストをやっていたのですよ。 で、ちょっと検索すれば、そのやり方は出てくるし、マニュアル読めば普通に書いてる。Windowsだけど、そこにほとんど機能差は無い。

で、確かにアーカイブログ(WAL)を取っといてベースバックアップを戻して、PITRを実行すると、確かにその状態に戻るんです。 戻るんです。が、

デフォルトだと、READ ONLYモードでリカバリかかるので、通常モードに切り替えるために、サーバを再起動したらええんかいなと思ったら、

2018-10-18 17:44:52.555 JST [3332] LOG: database system was not properly shut down; automatic recovery in progress
2018-10-18 17:44:52.558 JST [3332] LOG: redo starts at 1/29000028
2018-10-18 17:44:52.559 JST [3332] LOG: consistent recovery state reached at 1/2A001088
2018-10-18 17:44:52.559 JST [3332] LOG: invalid record length at 1/2C000098: wanted 24, got 0
2018-10-18 17:44:52.559 JST [3332] LOG: redo done at 1/2C000028

なんか自動でロールフォワードかかっとる。

結果、ポイントインタイムリカバリではなく、最新時点までリカバリがかかってしまった。

うーん、どうすればいいんだ?

キーは"タイムライン"

マニュアルを読み込むも、いまいち記載がない。
なんとなく、タイムラインをスイッチすればいいっぽいのだが、
recovery_target_timeline ='2'
とか指定して起動しても、そんなタイムライン存在しません。とか言われて起動しない。

ということで、色々試してたら、
recovery.conf内に
recovery_target_action = 'promote'
をセットしてDBを起動したら、自動でタイムラインがSwitchされて、通常モードで起動された。

2018-10-18 19:30:53.700 JST [2360] LOG: database system was shut down in recovery at 2018-10-18 19:27:55 JST
2018-10-18 19:30:53.700 JST [2360] LOG: starting point-in-time recovery to 2018-10-18 19:19:10+09
2018-10-18 19:30:53.721 JST [2360] LOG: restored log file "000000010000000100000031" from archive
2018-10-18 19:30:54.653 JST [2360] LOG: redo starts at 1/31000098
2018-10-18 19:30:54.699 JST [2360] LOG: restored log file "000000010000000100000032" from archive
2018-10-18 19:30:55.607 JST [2360] LOG: consistent recovery state reached at 1/32002BE8
2018-10-18 19:30:55.608 JST [5616] LOG: database system is ready to accept read only connections
2018-10-18 19:30:55.608 JST [2360] LOG: recovery stopping before commit of transaction 9738, time 2018-10-18 19:19:14.630902+09
2018-10-18 19:30:55.608 JST [2360] LOG: redo done at 1/32002BE8
2018-10-18 19:30:55.608 JST [2360] LOG: last completed transaction was at log time 2018-10-18 19:19:04.706312+09
2018-10-18 19:30:55.635 JST [2360] LOG: selected new timeline ID: 2
2018-10-18 19:30:56.643 JST [2360] LOG: archive recovery complete
2018-10-18 19:30:56.755 JST [5616] LOG: database system is ready to accept connections

あと、walファイルの名称にも、TIMELINE IDが埋め込まれているらしくそれっぽく変わった。 f:id:ryoben:20181018201315p:plain

結論

最初はちゃんとリカバリできてるか確認するっしょ?

なので、
recovery_target_action = 'pause'
で起動して、READ ONLYモードしてあげるよ。

そいで、大丈夫だったら、
recovery_target_action = 'promote'
にして、再起動かけたら、リカバリ完了だよ。
(recovery.confもrecovery.doneにファイル名が自動で変換される)

ということでした。マニュアルにはこの手順書いてないっぽいんだけど。俺が探しきれてないだけなのだろうか。