【PostgreSQL 9.6】指定した時間までリカバリするPITR

はじめに

現在サーバーリプレイスの移行作業(Windows Server 2008R2 + Oracle 11g から Windows Server 2016 + PostgreSQL 9.6)を行っています。

バックアップとリカバリについて調査しつつ、今回のテーマである指定した時間までリカバリする方法を確立しておきたいと思います。Windows版PostgreSQLの記事が少ないんですよね。

残念ながら、pg_rman (PostgreSQL のバックアップ/リストア管理ツール)はWindowsには対応していません。

【2021/08/02追記】 PostgreSQL 12用の記事を書きました。

バックアップ

バックアップには、大きく論理バックアップと物理バックアップがあります。

論理バックアップ

サーバーを起動したまま、pg_dumpコマンドでバックアップを取得します。
デフォルト形式の場合、データベースに格納されたデータをSQLの形で抽出します。
pg_dumpオプションによってテーブル指定やスキーマ指定が可能です。

pg_dumpコマンドでは、globalデータと呼ばれるロールやテーブルスペースなどの情報はバックアップされません。これらの情報も含めてデータベースクラスタ全体をバックアップしたい場合は、pg_dumpallコマンドを使えばそれらも全てコピーすることができます。pg_dumpallコマンドは、内部動作としてはpg_dumpコマンドを呼び出しています。

論理バックアップは、簡単に取得できてサイズも小さくなりますが、リカバリには一からデータをDBに投入し直すので時間がかかる傾向があります。

物理バックアップ

オフライン・バックアップ

サーバーを停止後、dataフォルダ以下をまるまるコピーします。

オンライン・バックアップ

pg_basebackupコマンドを使用して、サーバーを起動したままdataフォルダ以下をまるまるコピーします。また、WALアーカイブログも取得します。
オンラインなのでバックアップ中に更新があったデータを反映させる必要があります。そこで WALという仕組みを利用します。

WAL(Write Ahead Logging)とはログ先行書き込みのことで、トランザクションの処理の内容をデータファイルに反映する前に、ログファイル(WALセグメントファイル)に書き出そうという動きをさせるものです。

WALアーカイブログは、PostgreSQLが出力したトランザクションログ(WAL)ファイルを別の場所にコピーすることです。WALファイルはデフォルト設定では直近の一定数しか保存されず、古くなったものは削除もしくは再利用されていきます。そのため、リカバリに使えるようにWALファイルを別の場所に保存しておく必要があります。

WALアーカイブログを適用することで、DBの状態を任意の時刻の時点に戻すことができます。

pg_basebackup コマンド使用前の設定

「FATAL: pg_hba.conf にホスト"127.0.0.1"、ユーザ"postgres", SSL無効用のエントリがありません.」のエラーが出た場合、以下のコメントアウトを外す。

pg_hda.conf

host    replication     postgres        127.0.0.1/32            md5
host    replication     postgres        ::1/128                 md5

postgresql.confの max_wal_sender 設定のデフォルトは 0 です。最低でも 1 以上でないと pg_basebackupコマンドは実行できないので修正します。

postgresql.conf

max_wal_sender = 1

WALアーカイブの設定をします。
WALアーカイブを例「D:\PostgreSQL\ARCHIVELOG」フォルダにコピーします。

postgresql.conf

wal_level = replica  # リカバリに使える情報を保存するようにminimal以外の値にしておく
archive_mode = on   # PostgreSQLによるWALアーカイブ処理を有効にする
archive_command = 'copy "%p" "D:\\PostgreSQL\\ARCHIVELOG\\%f"'  # WALアーカイブ処理時に使われるコマンドを指定する　%pはwalファイル名、%fはwalアーカイブファイル名が自動で入力される

※PostgreSQL9.6を使用する場合、archiveとhot_standbyが新しい設定値「replica」に統合
※archive_commandのフォルダは先に作成しておく。
※archive_commandで「"%p"」などのようにパスの部分をダブルクォテーションでくくらないと正しく実行されません。
※SELECT pg_switch_xlog()でarchive_commandの内容を実行できます。

他のWALアーカイブの設定
postgresql.confにある archive_timeout と wal_keep_segments の設定

【archive_timeoutの設定】
archive_timeoutはトランザクションがほとんど発生しない「なぎ」のとき、WALにたまった内容がいつまで経ってもアーカイブされないことを防ぐ。デフォルトでは0（機能無効）

検証で archive_timeout = 60 に設定したのですが、容量が無駄との思いにいたりデフォルトの0に戻しました。
archive_timeout = 60 とした場合、16MB*60回/時*24時間=23040MB/日≒23GB/日 が発生しうる。

• archive_timeoutの意味
• Set PostgreSQL archive_timeout to 0 by default
• PostgresのPITR

【wal_keep_segmentsの設定】
検証でarchive_timeout = 60 としていた際にバックアップ後のpg_logに下記のエラーが発生していました。※archive_timeout と関連しているかは不明

2019-08-06 02:18:35 JST ERROR:  requested WAL segment 000000010000005A000000D1 has already been removed
日本語訳：要求された wal セグメント * はすでに削除されています。

対処として、wal_keep_segmentsをゼロ以外の値に設定する。
これは、ストリームの危険性が追いつかなくなるのを防ぐためです。
ただしpg_basebackupを使用する場合は、 – checkpoint = fastも忘れないでください。
https://codeday.me/jp/qa/20190609/972945.html

postgresql.conf

#wal_keep_segments = 0      # in logfile segments, 16MB each; 0 disables
↓
wal_keep_segments = 128

backup.bat の見直し

backup.bat

pg_basebackup -U postgres -D "%bkPath%" -F t -x -z
↓
pg_basebackup -U postgres -D "%bkPath%" -F t -x -z --checkpoint=fast

リストア

論理バックアップからのリストア

pg_dumpコマンドのバックアップは、スクリプト形式(デフォルト)とアーカイブ形式があり、それによりリストア方法が違います。

• スクリプト形式は平文のSQL文なので、psqlコマンドでリストアします。
• アーカイブ形式はバイナリの形で出力されているため、pg_restoreコマンドでリストアします。

物理バックアップからのリストア

リストアは以下の手順で行います。

1. PostgreSQLサービスの停止
2. リストア(Dataフォルダの書き戻し)
3. PostgreSQLサービスの開始

リカバリ

リストアとリカバリとは区別しないで使うときもあるが、今回は分けました。

• リストアはバックアップデータを、バックアップを取ったときと同じ状態に物理的に復元すること
• リカバリはリストアしたデータに何かの処理をして最新の状態や正常な状態に復旧させること

ポイントインタイムリカバリ(PITR)

ポイントインタイムリカバリ(PITR:Point In Time Recovery)はベースバックアップにアーカイブログ(WALログ)を適用することで任意の時点まで復元することが可能です。復元ポイントやリカバリの設定はrecovery.confに記述します。

• PostgreSQLのポイントインタイムリカバリ(PITR)めも
• PostgreSQL 9.4 バックアップ(ファイル直接：オンラインバックアップ：PITR)
• PostgreSQLのオンラインバックアップとリカバリ
• PostgreSQLのWALって何? ログ、PITR、障害時のデータ復旧の話

WALレコードの適用までの流れ

リカバリを開始してWALレコードを適用するまでの流れは次のようになっている。

1. pg_controlファイルを読み込む
2. recovery.confを読み込む
3. backup_labelを読み込む
4. pg_controlファイルを更新し、backup_labelを削除する
5. 必要なWALを繰り返し適用する

※backup_labelファイルから適用を開始すべきWALの位置を取得できなかった場合は、pg_controlファイルの情報を元にリカバリを開始します。

pg_controlファイルは、バイナリファイルなので通常のエディタでは内容を確認できません。そのためにpg_controldataコマンドが用意されています。
pg_controldataコマンドを実行すると最終チェックポイントのREDO WALファイルが分かります。

pg_controldata -D C:\PostgreSQL\9.6\data

最終チェックポイント

PostgreSQLはトランザクションをメモリ上で処理している。メモリ上に持っている間にPostgreSQLがクラッシュするとコミットしたはずのデータが消えてしまう。それを防ぐためにコミットした分だけをWALという形で書き込んでいる。しかし、いつまでもWALだけに持っておくわけにいかないので、あるタイミングでWALの内容をテーブルファイルに反映しなければならない。そのタイミングがチェックポイント(CHECKPOINT)である。
その間隔は設定checkpoint_timeoutでデフォルトは5分だが30分が推奨される。最終チェックポイントは直近でチェックポイントされた情報を示す。

クラッシックリカバリ時は最終チェックポイント以降のWALを適用すれば最新に戻せる。

• チェックポイント(CHECKPOINT)
• CHECKPOINTって何
• まずやっとくPostgreSQLチューニング - SlideShare

PITRの実施

下記サイトの手順を実際にやってみました。
PostgreSQL 9.6.3で時刻指定のPITR(Point In Time Recovery)を実行する

PITRで利用するデータの格納先を以下に示します。

種類	フォルダ
データベースクラスタ	C:\PostgreSQL\9.6\data
データベースクラスタの退避先	C:\PostgreSQL\9.6\data_bk
WALファイル	C:\PostgreSQL\9.6\data\pg_xlog
アーカイブファイル	D:\PostgreSQL\ARCHIVELOG
ベースバックアップ	D:\data_backup

今回の操作の時系列を以下にまとめます。

2019/07/07 01:25:00 テーブルの作成
2019/07/07 01:30:09 1件目のデータ挿入
2019/07/07 01:32:51 2件目のデータ挿入
2019/07/07 01:35:40 3件目のデータ挿入
2019/07/07 02:00:00 ベースバックアップの取得（pg_basebackupの実行）
2019/07/07 02:12:18 4件目のデータ挿入
2019/07/07 02:13:58 5件目のデータ挿入
2019/07/07 02:14:47 6件目のデータ挿入
2019/07/07 02:15:39 7件目のデータ挿入
2019/07/07 02:18:07 8件目のデータ挿入
★----------ここの状態に戻したい----------★
2019/07/07 10:54:53 9件目のデータ挿入 ★誤操作★
2019/07/07 11:00:00 1件目のデータ削除 ★誤操作★
2019/07/07 13:37:30 PostgreSQLを停止し、リカバリ作業開始

手順

(1) テーブルの作成と初期データ挿入
PITRの動作検証用のテーブル（テーブル名：testtbl）を1つ作成し、初期データを3件挿入します。 リカバリポイントが分かりやすいように、テーブルにはデータを挿入したタイムスタンプを格納するカラムを持たせます。

-- testtblテーブルを作成
create table testtbl (
  id integer primary key,
  last_update timestamp
);

insert into testtbl values (1, now()); -- 1件目のデータ挿入
insert into testtbl values (2, now()); -- 2件目のデータ挿入
insert into testtbl values (3, now()); -- 3件目のデータ挿入

select * from testtbl; -- テーブルに格納されたデータの確認

id  last_update
1   2019/07/07 1:30:09.123
2   2019/07/07 1:32:51.533
3   2019/07/07 1:35:40.222

(2) ベースバックアップの取得
動作検証用のテーブルにデータが3件入っている状態で、 データベースクラスタのベースバックアップを取得します。

pg_basebackup -U postgres -D D:\data_backup --xlog --checkpoint=fast --progress

(3) 正常なテーブル更新処理
ベースバックアップ取得後にデータの挿入処理を続けます。 ここまでは処理として何の問題もないと仮定します。

insert into testtbl values (4, now()); -- 4件目のデータ挿入
insert into testtbl values (5, now()); -- 5件目のデータ挿入
insert into testtbl values (6, now()); -- 6件目のデータ挿入
insert into testtbl values (7, now()); -- 7件目のデータ挿入
insert into testtbl values (8, now()); -- 8件目のデータ挿入

select * from testtbl; -- テーブルに格納されたデータの確認

id  last_update
1   2019/07/07 1:30:09.123
2   2019/07/07 1:32:51.533
3   2019/07/07 1:35:40.222
4   2019/07/07 2:12:18.927
5   2019/07/07 2:13:58.385
6   2019/07/07 2:14:47.382
7   2019/07/07 2:15:39.858
8   2019/07/07 2:18:07.601

(4) 間違ったテーブル更新処理
ここで必要のない9件目のデータをウッカリ挿入してしまい、これを削除しようとしたが、間違って1件目のデータを削除してしまったとします。

insert into testtbl values (9, now()); -- 間違って9件目のデータ挿入

select * from testtbl; -- テーブルに格納されたデータの確認
id  last_update
1   2019/07/07 1:30:09.123
2   2019/07/07 1:32:51.533
3   2019/07/07 1:35:40.222
4   2019/07/07 2:12:18.927
5   2019/07/07 2:13:58.385
6   2019/07/07 2:14:47.382
7   2019/07/07 2:15:39.858
8   2019/07/07 2:18:07.601
9   2019/07/07 10:54:53.577 -- 不要なデータをウッカリ挿入してしまった

delete from testtbl where id = 1; -- 9件目のデータではなく1件目のデータを間違って削除

select * from testtbl; -- テーブルに格納されたデータの確認

id  last_update
2   2019/07/07 1:32:51.533 -- 1件目のデータが消えてしまった
3   2019/07/07 1:35:40.222
4   2019/07/07 2:12:18.927
5   2019/07/07 2:13:58.385
6   2019/07/07 2:14:47.382
7   2019/07/07 2:15:39.858
8   2019/07/07 2:18:07.601
9   2019/07/07 10:54:53.577 -- 不要な9件目のデータは削除できていない

この状態からPITRでリカバリを行い、データベースを正しい状態に戻します。

データベースのリカバリ

これからデータベースをデータが正しい時の状態にリカバリします。
最新の状態にリカバリするためには下記4つを使用します。

• ベースバックアップ
• 最新のWALファイル
• 最新のアーカイブファイル
• リカバリ設定ファイル(recovery.conf)

これらファイルを使用してデータベースが正常だった時刻（2019年7月7日 2時20分00秒）の状態に戻します。

(1) PostgreSQLの停止
データベースを復旧するに当たり、まずはPostgreSQLを停止します。
GUI上ならタスクマネージャーのサービスタブ「postgresql-x64-9.6」を選択して「停止」します。

net stop postgresql-x64-9.6

(2) データベースクラスタの退避
データベースクラスタ内のデータはWALファイル(data/pg_xlog)以外はもう使用しません。 ただ、念のためデータベースクラスタ全体をリネームして退避しておきます。 これはリカバリが成功してから消せば良いです。

cd C:\PostgreSQL\9.6
ren data data_bk

(3) ベースバックアップからのリストア
pg_basebackupコマンドで取得したベースバックアップをリストアします。リストアといってもベースバックアップのデータをデータベースクラスタのパス（C:\PostgreSQL\9.6\data）にコピーするだけです。

cd C:\PostgreSQL\9.6
xcopy D:\data_backup data /E /Y /I /D

(4) 最新のWALファイルを格納
ベースバックアップのファイルを戻しただけだと、ベースバックアップを取得した時点にしかリカバリできないため、最新のWALファイルと最新のアーカイブファイルを使用してロールフォワード(データの更新ログを元にデータベースを再更新)します。
ベースバックアップを取得した時点のWALファイルは使用しないためフォルダごと削除してしまいます。そして最新のWALファイルを適用するため先ほど退避しておいたデータベースクラスタからWALファイルだけを取り出してデータベースクラスタにコピーします。

cd C:\PostgreSQL\9.6
REM ベースバックアップ時点のWALファイルを削除
rd data\pg_xlog /s /q
REM 退避しておいた最新のWALファイルをコピー
xcopy data_bk\pg_xlog data\pg_xlog /E /Y /I /D 

(5) リカバリ設定ファイル作成
データベースクラスタのパス直下(C:\PostgreSQL\9.6\data)に recovery.confファイルを作成します。このファイルに、どのアーカイブファイルを使用してリカバリするか、どの時点（時刻）にリカバリするかを記述します。 今回はデータベースが正常だった2019年7月7日 2時20分00秒に戻したいとします。 アーカイブファイルは「D:\PostgreSQL\ARCHIVELOG」フォルダに格納されています。

recovery.conf

restore_command = 'copy "D:\\PostgreSQL\\ARCHIVELOG\\%f" "%p"'
recovery_target_time = '2019-07-07 02:20:00'

※recovery_target_timeの設定がない場合、リストアできるところまでリストアしようとします。

(6) PostgreSQLの起動
ここまででPITRに必要な情報が揃ったため、PostgreSQLを起動します。 起動時にrecovery.confを読み込んでPITRが実行されます。
GUI上ならタスクマネージャーのサービスタブ「postgresql-x64-9.6」を選択して「開始」します。

net start postgresql-x64-9.6

(7) PITRでのリカバリ完了の確認
先ほど作成したrecovery.confファイルは、リカバリが正常に終了するとrecovery.doneに自動でリネームされます。そのため、これ以降PostgreSQLを再起動しても、間違ってまたリカバリが実行されることはありません。

pg_logの出力ログ

2019-07-07 13:37:32 JST FATAL:  データベースシステムは起動しています
2019-07-07 13:37:33 JST LOG:  2019-07-07 02:20:00+09 に対してポイントインタイムリカバリを開始しています
2019-07-07 13:37:33 JST LOG:  ログファイル"00000004.history"をアーカイブからリストアしました
2019-07-07 13:37:33 JST FATAL:  データベースシステムは起動しています
2019-07-07 13:37:34 JST LOG:  ログファイル"000000040000000000000007"をアーカイブからリストアしました
2019-07-07 13:37:34 JST LOG:  0/7000028のREDOを開始します
2019-07-07 13:37:34 JST LOG:  0/7000130 でリカバリー状態の整合が取れました
2019-07-07 13:37:34 JST FATAL:  データベースシステムは起動しています
2019-07-07 13:37:35 JST FATAL:  データベースシステムは起動しています
2019-07-07 13:37:35 JST LOG:  ログファイル"000000040000000000000008"をアーカイブからリストアしました
2019-07-07 13:37:35 JST FATAL:  データベースシステムは起動しています
2019-07-07 13:37:36 JST LOG:  リカバリがトランザクション604のコミット、時刻2019-07-07 10:54:53.578267+09の前に停止しました
2019-07-07 13:37:36 JST LOG:  0/8006898のREDOが終わりました
2019-07-07 13:37:36 JST LOG:  最後に完了したトランザクションはログ時刻2019-07-07 02:18:07.601846+09でした
2019-07-07 13:37:36 JST LOG:  選択された新しいタイムラインID: 5
2019-07-07 13:37:37 JST LOG:  アーカイブリカバリが完了しました
2019-07-07 13:37:37 JST FATAL:  データベースシステムは起動しています
2019-07-07 13:37:37 JST LOG:  ログファイル"00000004.history"をアーカイブからリストアしました
2019-07-07 13:37:38 JST LOG:  MultiXact member wraparound protections are now enabled
2019-07-07 13:37:38 JST LOG:  データベースシステムの接続受付準備が整いました。
2019-07-07 13:37:38 JST LOG:  自動バキュームランチャプロセス

リカバリ、つまりWALからREDOしているのがわかるかと思います。

(8) リカバリ後のデータの確認
ではデータベースに接続してデータの状態を確認します。間違って削除してしまった1件目のデータも復活していますし、間違って挿入してしまった9件目のデータも削除されていることが分かります。 ここで行われた動作は、ベースバックアップの状態（1～3件目のデータが挿入された状態）を元に、 アーカイブファイルとWALファイルに書かれた更新情報を使用して、4～8件目のデータ挿入処理を実行しています。 間違って実行してしまった9件目のデータ挿入と1件目のデータ削除は実行されなかったため、 データベースが正しい状態になっています。

select * from testtbl; -- テーブルに格納されたデータの確認

id  last_update
1   2019/07/07 1:30:09.123
2   2019/07/07 1:32:51.533
3   2019/07/07 1:35:40.222
4   2019/07/07 2:12:18.927
5   2019/07/07 2:13:58.385
6   2019/07/07 2:14:47.382
7   2019/07/07 2:15:39.858
8   2019/07/07 2:18:07.601

(9) 連続リカバリ
試しにもう少し前にリカバリできるか確認してみました。
PostgreSQLのサービスを停止して、recovery.doneをrecovery.confにファイル名を変更して、6番目以降未登録の状態にしようとしました。

recovery.conf

restore_command = 'copy "D:\\PostgreSQL\\ARCHIVELOG\\%f" "%p"'
recovery_target_time = '2019-07-07 02:14:00'

PostgreSQLのサービスを開始しましたが、「REDOは必要ありません」というログ結果が出て戻りませんでした。直に連続でやるのは出来ないようです。

しかし、PostgreSQL停止後に「(4) 最新のWALファイルを格納」からやり直すことで、6番目以降未登録の状態に戻すことが出来ました。

select * from testtbl; -- テーブルに格納されたデータの確認

id  last_update
1   2019/07/07 1:30:09.123
2   2019/07/07 1:32:51.533
3   2019/07/07 1:35:40.222
4   2019/07/07 2:12:18.927
5   2019/07/07 2:13:58.385

最後に

私が関わった5年前から30近くのサーバーをOracleで管理していますが、1回だけマザーボードがイカれPCが壊れたことでOracleのデータが破損したことがありました。その際はフルバックアップからデータ復旧して戻したのですが、数時間分のデータは消失しました。正しいやり方を知っていればもう少しなんとかなったのではないかと反省しました。
その時の記事は下記に書いています。
Oracle接続エラー(ORA-12528,ORA-214,ORA-12154,ORA-01122)対応の備忘録

今回、PostgreSQLで直近までのリカバリ方法を理解することができました。