Point In Time Recovery

PostgreSQLのPITR(Point In Time Recovery)という、オンライン物理バックアップ、任意の時点のリストアを試してみました。このしくみを知るには、WAL(Write Ahead Log)の理解が不可欠ということで、WALファイルの作成され方にも焦点をあてています。

環境) Postgresql 14.6 / Ubuntu 22.04
環境をゼロに戻すために(インストール後テストでつかっていたため)、データベースの初期化から行います。

initdb -D /var/lib/postgresql/14/main

このコマンドばUbuntu環境のもので、/usr/lib/postgresql/14/bin にパスを通しておきます。
pg_ctlを使ってやるべきかもしれませんが、Ubuntuはよく使うことと、違った環境でやることによっていろいろな発見があるため、あえてトライしました。(postgresql.confなどの場所による違いがあり、起動・停止のみ、rootユーザになってから、service postgresql start/stop でやることが無難)
操作はインストール時自動で追加されるpostgresユーザで行いますが、.profileを作成して上記バスを追加しておきます。
後になりましたが下記デフォルトのPGDATAは、そのまま利用するため、initdb前に削除またはバックアップしておきます。

/var/lib/postgresql/14/main

参考)
「【PostgreSQL 12】指定した時間までリカバリするPITR」
https://qiita.com/yaju/items/51e7b1037a99856e547c
「PostgreSQL 13 PITR(Point In Time Recovery)基本概念の説明 」
https://changineer.info/server/postgresql/postgresql_backup_pitr01.html
また、最下部の動画「PostgreSQLのバックアップ方法(PostgreSQL学習)」を参考にさせていただきました。しかしこの動画ではバージョンが古いためrecovery.confを使ったやり方の説明されています。(現在はpostgresql.confに統合されている) 個人的には、リカバリー情報はその時しか使わないため実行とともに消えてくれる古いやり方の方が好みですが。。

設定(/etc/postgresql/14/main/postgresql.conf)

archive_mode = on
archive_command = ‘cp “%p” “/var/lib/postgresql/14/walarc/%f”‘

restore_command = ‘cp “/var/lib/postgresql/14/walarc/%f” “%p”‘
recovery_target_time = ‘2023-02-16 01:00:36’

WALアーカイブの保存とリカバー時にアーカイブの参照場所、リカバリー時間の設定を記述します。
リカバー情報は、リカバーのときに記述すればよいのですが、まとめて説明しました。

touch recovery.signal

このファイルが、/var/lib/postgresql/14/main にあるときリカバリーとして動作します。
リカバリーが成功後、

SELECT pg_wal_replay_resume();

の実行で、このファイルが削除されます。(これを実行するまではリードオンリー)

テストテーブル作成

CREATE TABLE test_tbl(id int, update timestamp);

テスト手順
タイムスタンプ付きのデータを5つずつ3回INSERTします。
1回目と2回目が終わったとき、DBバックアップをとります。
この後1回目のバックアップデータを使って、指定時間までリカバリーします。(2回目よりも前の時点)
(※最後に、psql操作をすべて掲載)

INSERT INTO test_tbl VALUES(1, now());

上記idを変えながら5回実行

SELECT * FROM test_tbl;
id | update
—-+—————————-
1 | 2023-02-16 00:57:21.847445
2 | 2023-02-16 00:57:24.841029
3 | 2023-02-16 00:57:28.084766
4 | 2023-02-16 00:57:31.11219
5 | 2023-02-16 00:57:34.502703
(5 rows)

WALファイル (/var/lib/postgresql/14/main/pg_wal)
WALアーカイブファイル (/var/lib/postgresql/14/walarc)

postgres@n0d:~/14$ ls -l main/pg_wal ; ls -l walarc
total 16388
-rw——- 1 postgres postgres 16777216 Feb 16 00:57 000000010000000000000001
drwx—— 2 postgres postgres 4096 Feb 16 00:48 archive_status
total 16384
-rw——- 1 postgres postgres 16777216 Feb 16 00:47 000000010000000000000001

バックアップ

pg_basebackup -D /tmp/base01 –checkpoint=fast –progress -X n

この時点でのWALファイル(main/pg_wal)は不要なのでバックアップはとりません。(-X n)
実行すると下記のように変化します。

postgres@n0d:~/14$ ls -l main/pg_wal ; ls -l walarc
total 32776
-rw——- 1 postgres postgres 16777216 Feb 16 00:59 000000010000000000000002
-rw——- 1 postgres postgres 338 Feb 16 00:59 000000010000000000000002.00000028.backup
-rw——- 1 postgres postgres 16777216 Feb 16 00:59 000000010000000000000003
drwx—— 2 postgres postgres 4096 Feb 16 00:59 archive_status
total 32772
-rw——- 1 postgres postgres 16777216 Feb 16 00:59 000000010000000000000001
-rw——- 1 postgres postgres 16777216 Feb 16 00:59 000000010000000000000002
-rw——- 1 postgres postgres 338 Feb 16 00:59 000000010000000000000002.00000028.backup

そしてさらに、続けます。

INSERT INTO test_tbl VALUES(6, now());

2回目バックアップ

pg_basebackup -D /tmp/base02 –checkpoint=fast –progress -X n

WALファイル

postgres@n0d:~/14$ ls -l main/pg_wal ; ls -l walarc
total 49160
-rw——- 1 postgres postgres 16777216 Feb 16 01:03 000000010000000000000004
-rw——- 1 postgres postgres 338 Feb 16 01:03 000000010000000000000004.00000028.backup
-rw——- 1 postgres postgres 16777216 Feb 16 01:03 000000010000000000000005
-rw——- 1 postgres postgres 16777216 Feb 16 01:03 000000010000000000000006
drwx—— 2 postgres postgres 4096 Feb 16 01:03 archive_status
total 65544
-rw——- 1 postgres postgres 16777216 Feb 16 00:59 000000010000000000000001
-rw——- 1 postgres postgres 16777216 Feb 16 00:59 000000010000000000000002
-rw——- 1 postgres postgres 338 Feb 16 00:59 000000010000000000000002.00000028.backup
-rw——- 1 postgres postgres 16777216 Feb 16 01:03 000000010000000000000003
-rw——- 1 postgres postgres 16777216 Feb 16 01:03 000000010000000000000004
-rw——- 1 postgres postgres 338 Feb 16 01:03 000000010000000000000004.00000028.backup

3回目インサート後

SELECT * FROM test_tbl;
id | update
—-+—————————-
1 | 2023-02-16 00:57:21.847445
2 | 2023-02-16 00:57:24.841029
3 | 2023-02-16 00:57:28.084766
4 | 2023-02-16 00:57:31.11219
5 | 2023-02-16 00:57:34.502703
6 | 2023-02-16 01:00:29.170667
7 | 2023-02-16 01:00:33.334199
8 | 2023-02-16 01:00:36.499042
9 | 2023-02-16 01:00:39.428708
10 | 2023-02-16 01:00:44.688255
11 | 2023-02-16 01:04:43.192166
12 | 2023-02-16 01:04:50.342296
13 | 2023-02-16 01:04:53.43745
14 | 2023-02-16 01:04:57.402116
15 | 2023-02-16 01:05:02.865745
(15 rows)

postgres@n0d:~/14$ ls -l main/pg_wal ; ls -l walarc
total 49160
-rw——- 1 postgres postgres 16777216 Feb 16 01:03 000000010000000000000004
-rw——- 1 postgres postgres 338 Feb 16 01:03 000000010000000000000004.00000028.backup
-rw——- 1 postgres postgres 16777216 Feb 16 01:05 000000010000000000000005
-rw——- 1 postgres postgres 16777216 Feb 16 01:03 000000010000000000000006
drwx—— 2 postgres postgres 4096 Feb 16 01:03 archive_status
total 65544
-rw——- 1 postgres postgres 16777216 Feb 16 00:59 000000010000000000000001
-rw——- 1 postgres postgres 16777216 Feb 16 00:59 000000010000000000000002
-rw——- 1 postgres postgres 338 Feb 16 00:59 000000010000000000000002.00000028.backup
-rw——- 1 postgres postgres 16777216 Feb 16 01:03 000000010000000000000003
-rw——- 1 postgres postgres 16777216 Feb 16 01:03 000000010000000000000004
-rw——- 1 postgres postgres 338 Feb 16 01:03 000000010000000000000004.00000028.backup

コマンドでカレントWALファイルの確認

SELECT pg_walfile_name(pg_current_wal_lsn());
pg_walfile_name
————————–
000000010000000000000005
(1 row)

順番にアーカイブされていくことがわかります。

そしてリカバリーのテストをするためDBを停止し、次の起動時に下記時刻のデータにもどします。

recovery_target_time = ‘2023-02-16 01:00:36

7 | 2023-02-16 01:00:33.334199
8 | 2023-02-16 01:00:36.499042

バックアップしたファイルをmainにします。(これまでのmainはリネームして退避しておきます)
重要なのは、最新のWALファイルは利用するということです。

cd /var/lib/postgresql/14
mv main main_bak
cp -pr /tmp/base01 main
cp main_bak/pg_wal/* main/pg_wal/
touch main/recovery.signal

rootユーザで起動

service postgresql start

ログ表示

tail -f /var/log/postgresql/postgresql-14-main.log

2023-02-16 01:17:30.345 UTC [9566] LOG: starting PostgreSQL 14.6 (Ubuntu 14.6-0ubuntu0.22.04.1) on x86_64-pc-linux-gnu, compiled by gcc (Ubuntu 11.3.0-1ubuntu1~22.04) 11.3.0, 64-bit
2023-02-16 01:17:30.346 UTC [9566] LOG: listening on IPv4 address “127.0.0.1”, port 5432
2023-02-16 01:17:30.349 UTC [9566] LOG: listening on Unix socket “/var/run/postgresql/.s.PGSQL.5432”
2023-02-16 01:17:30.356 UTC [9567] LOG: database system was interrupted; last known up at 2023-02-16 00:59:14 UTC
cp: cannot stat ‘/var/lib/postgresql/14/walarc/00000002.history’: No such file or directory
2023-02-16 01:17:30.892 UTC [9567] LOG: starting point-in-time recovery to 2023-02-16 01:00:36+00
2023-02-16 01:17:31.011 UTC [9567] LOG: restored log file “000000010000000000000002” from archive
2023-02-16 01:17:31.044 UTC [9567] LOG: redo starts at 0/2000028
2023-02-16 01:17:31.048 UTC [9567] LOG: consistent recovery state reached at 0/2000100
2023-02-16 01:17:31.050 UTC [9566] LOG: database system is ready to accept read-only connections
2023-02-16 01:17:31.182 UTC [9567] LOG: restored log file “000000010000000000000003” from archive
2023-02-16 01:17:31.212 UTC [9567] LOG: recovery stopping before commit of transaction 741, time 2023-02-16 01:00:36.499152+00
2023-02-16 01:17:31.212 UTC [9567] LOG: pausing at the end of recovery
2023-02-16 01:17:31.212 UTC [9567] HINT: Execute pg_wal_replay_resume() to promote.

postgres@n0d:~/14$ ls -l main/pg_wal ; ls -l walarc
total 98316
-rw——- 1 postgres postgres 16777216 Feb 16 01:17 000000010000000000000003
-rw——- 1 postgres postgres 338 Feb 16 01:14 000000010000000000000004.00000028.backup
-rw——- 1 postgres postgres 16777216 Feb 16 01:19 000000020000000000000003
-rw——- 1 postgres postgres 16777216 Feb 16 01:17 000000020000000000000004
-rw——- 1 postgres postgres 16777216 Feb 16 01:14 000000020000000000000005
-rw——- 1 postgres postgres 16777216 Feb 16 01:14 000000020000000000000006
-rw——- 1 postgres postgres 16777216 Feb 16 01:14 000000020000000000000007
-rw——- 1 postgres postgres 50 Feb 16 01:18 00000002.history
drwx—— 2 postgres postgres 4096 Feb 16 01:18 archive_status
total 81932
-rw——- 1 postgres postgres 16777216 Feb 16 00:59 000000010000000000000001
-rw——- 1 postgres postgres 16777216 Feb 16 00:59 000000010000000000000002
-rw——- 1 postgres postgres 338 Feb 16 00:59 000000010000000000000002.00000028.backup
-rw——- 1 postgres postgres 16777216 Feb 16 01:03 000000010000000000000003
-rw——- 1 postgres postgres 16777216 Feb 16 01:03 000000010000000000000004
-rw——- 1 postgres postgres 338 Feb 16 01:03 000000010000000000000004.00000028.backup
-rw——- 1 postgres postgres 16777216 Feb 16 01:08 000000010000000000000005
-rw——- 1 postgres postgres 50 Feb 16 01:18 00000002.history

SELECT pg_walfile_name(pg_current_wal_lsn());
pg_walfile_name
————————–
000000020000000000000003
(1 row)

そして、下記意図どおりの結果となりました。

postgres=# SELECT * FROM test_tbl;
id | update
—-+—————————-
1 | 2023-02-16 00:57:21.847445
2 | 2023-02-16 00:57:24.841029
3 | 2023-02-16 00:57:28.084766
4 | 2023-02-16 00:57:31.11219
5 | 2023-02-16 00:57:34.502703
6 | 2023-02-16 01:00:29.170667
7 | 2023-02-16 01:00:33.334199
(7 rows)

2回目のバックアップのリカバリーは想像がつくと思いますのでテストをしませんが、バックアップを起点としてWALファイルを使って任意の時点の復旧ができることが確認できました。
WALアーカイブがどんどん作成され、pg_walは削除されていきます。ベースバックアップをとった時点からのWALがないと復元できないので、アーカイブの必要性がわかります。
WALファイルはシーケンシャルだから、これさえあればどの時点でも復元できるだろうと、過去のWALファイルのみでいろいろとテストしましたがうまくいかず、結局最新のWALファイルがあること、そして基点となる物理バックアップがあることが必須のようです。
今回WALを追いかけたかったは、タイムライン履歴というものも理解したかったからですが(.history)、そのための下地でした。
(レプリケーションやRewindツールなどの理解にも)

また理解を深めていきたいと思います。

以下psql操作履歴 ———————————————————-

postgres=# \d
Did not find any relations.
postgres=# CREATE TABLE test_tbl(id int, update timestamp);
CREATE TABLE
postgres=# INSERT INTO test_tbl VALUES(1, now());
INSERT 0 1
postgres=# INSERT INTO test_tbl VALUES(2, now());
INSERT 0 1
postgres=# INSERT INTO test_tbl VALUES(3, now());
INSERT 0 1
postgres=# INSERT INTO test_tbl VALUES(4, now());
INSERT 0 1
postgres=# INSERT INTO test_tbl VALUES(5, now());
INSERT 0 1
postgres=# SELECT * FROM test_tbl;
id | update
—-+—————————-
1 | 2023-02-16 00:57:21.847445
2 | 2023-02-16 00:57:24.841029
3 | 2023-02-16 00:57:28.084766
4 | 2023-02-16 00:57:31.11219
5 | 2023-02-16 00:57:34.502703
(5 rows)

postgres=# \q
postgres@n0d:~/14$ pg_basebackup -D /tmp/base01 –checkpoint=fast –progress -X n
NOTICE: all required WAL segments have been archived
26304/26304 kB (100%), 1/1 tablespace
postgres@n0d:~/14$ psql
psql (14.6 (Ubuntu 14.6-0ubuntu0.22.04.1))
Type “help” for help.

postgres=# INSERT INTO test_tbl VALUES(6, now());
INSERT 0 1
postgres=# INSERT INTO test_tbl VALUES(7, now());
INSERT 0 1
postgres=# INSERT INTO test_tbl VALUES(8, now());
INSERT 0 1
postgres=# INSERT INTO test_tbl VALUES(9, now());
INSERT 0 1
postgres=# INSERT INTO test_tbl VALUES(10, now());
INSERT 0 1
postgres=# SELECT * FROM test_tbl;
id | update
—-+—————————-
1 | 2023-02-16 00:57:21.847445
2 | 2023-02-16 00:57:24.841029
3 | 2023-02-16 00:57:28.084766
4 | 2023-02-16 00:57:31.11219
5 | 2023-02-16 00:57:34.502703
6 | 2023-02-16 01:00:29.170667
7 | 2023-02-16 01:00:33.334199
8 | 2023-02-16 01:00:36.499042
9 | 2023-02-16 01:00:39.428708
10 | 2023-02-16 01:00:44.688255
(10 rows)

postgres=# \q
postgres@n0d:~/14$ pg_basebackup -D /tmp/base02 –checkpoint=fast –progress -X n
NOTICE: all required WAL segments have been archived
26304/26304 kB (100%), 1/1 tablespace
postgres@n0d:~/14$ psql
psql (14.6 (Ubuntu 14.6-0ubuntu0.22.04.1))
Type “help” for help.

postgres=# INSERT INTO test_tbl VALUES(11, now());
INSERT 0 1
postgres=# INSERT INTO test_tbl VALUES(12, now());
INSERT 0 1
postgres=# INSERT INTO test_tbl VALUES(13, now());
INSERT 0 1
postgres=# INSERT INTO test_tbl VALUES(14, now());
INSERT 0 1
postgres=# INSERT INTO test_tbl VALUES(15, now());
INSERT 0 1
postgres=# SELECT * FROM test_tbl;
id | update
—-+—————————-
1 | 2023-02-16 00:57:21.847445
2 | 2023-02-16 00:57:24.841029
3 | 2023-02-16 00:57:28.084766
4 | 2023-02-16 00:57:31.11219
5 | 2023-02-16 00:57:34.502703
6 | 2023-02-16 01:00:29.170667
7 | 2023-02-16 01:00:33.334199
8 | 2023-02-16 01:00:36.499042
9 | 2023-02-16 01:00:39.428708
10 | 2023-02-16 01:00:44.688255
11 | 2023-02-16 01:04:43.192166
12 | 2023-02-16 01:04:50.342296
13 | 2023-02-16 01:04:53.43745
14 | 2023-02-16 01:04:57.402116
15 | 2023-02-16 01:05:02.865745
(15 rows)

postgres=# SELECT pg_walfile_name(pg_current_wal_lsn());
pg_walfile_name
————————–
000000010000000000000005
(1 row)

postgres=# \q
postgres@n0d:~/14$ psql
psql (14.6 (Ubuntu 14.6-0ubuntu0.22.04.1))
Type “help” for help.

postgres=# SELECT * FROM test_tbl;
id | update
—-+—————————-
1 | 2023-02-16 00:57:21.847445
2 | 2023-02-16 00:57:24.841029
3 | 2023-02-16 00:57:28.084766
4 | 2023-02-16 00:57:31.11219
5 | 2023-02-16 00:57:34.502703
6 | 2023-02-16 01:00:29.170667
7 | 2023-02-16 01:00:33.334199
(7 rows)

postgres=# INSERT INTO test_tbl VALUES(20, now());
ERROR: cannot execute INSERT in a read-only transaction
postgres=# SELECT pg_wal_replay_resume();
pg_wal_replay_resume
———————-

(1 row)

postgres=# INSERT INTO test_tbl VALUES(20, now());
INSERT 0 1
postgres=# SELECT * FROM test_tbl;
id | update
—-+—————————-
1 | 2023-02-16 00:57:21.847445
2 | 2023-02-16 00:57:24.841029
3 | 2023-02-16 00:57:28.084766
4 | 2023-02-16 00:57:31.11219
5 | 2023-02-16 00:57:34.502703
6 | 2023-02-16 01:00:29.170667
7 | 2023-02-16 01:00:33.334199
20 | 2023-02-16 01:19:05.32481
(8 rows)

postgres=# SELECT pg_walfile_name(pg_current_wal_lsn());
pg_walfile_name
————————–
000000020000000000000003
(1 row)