Amazon RDS DB インスタンスのポイントインタイム復元に時間がかかる原因を教えてください。

解決策

RDS DB インスタンスをバックアップから復元した後、Amazon RDS ログファイルを参照し、ポイントインタイム復元の進行状況を追跡します。

Amazon RDS は、5 分ごとに DB インスタンスでのトランザクションログのを Amazon Simple Storage Service (Amazon S3) にアップロードします。ポイントインタイム復元では、ポイントインタイムに設定した時間に最も近いスナップショットが最初に復元されます。その後、Amazon RDS は設定した時点までトランザクションログを適用します。操作の期間は、トランザクションログの数に依存します。

たとえば、同日の 04:00 UTC に作成された DB インスタンスの自動バックアップでは、06:15 UTC にポイントインタイム復元を実行する必要があります。この例では、インスタンスは 04:00 UTC に作成されたバックアップから復元されます。その後、Amazon RDS は復元されたインスタンスに 06:15 UTC までのトランザクションログを適用して、ポイントインタイム復元プロセスを完了します。

DB インスタンスを特定の時間まで復元するのにかかる時間を短縮するには、次のベストプラクティスを実施してください。

• 手動スナップショットを定期的に作成し、自動バックアップが有効であるソースインスタンスの目標復旧時点 (RPO) を削減します。
• ポイントインタイム復元の時点で、ソースデータベースには実行時間の長いクエリが存在しないことを確認します。トランザクションの実行時間が長くなると、復元時間が長くなり、データベースが長時間使用できなくなる可能性があります。
• トランザクションログのサイズを確認します。大容量のトランザクションは一度にトランザクションファイルに書き込まれます。Amazon RDS はトランザクションを複数のファイルに分割しません。
  注: トランザクションログファイルが大きい場合、クラッシュからの復元時間が長くなります。
• 復元後の重要なテーブルへのアクセスを高速化するには、各テーブルで SELECT * などのフルテーブルスキャンを実行します。こうすることで、Amazon RDS は Amazon S3 のすべてのテーブルデータを Amazon Elastic Block Store (Amazon EBS) ボリュームにダウンロードします。
  注: すべてのテーブルデータをダウンロードせずに EBS ブロックにアクセスしようとすると、遅延読み込みが発生する可能性があります。インスタンスのスナップショットが復元された後、Amazon S3 内のスナップショットのデータは EBS ボリュームにコピーされます。まだコピーされていないブロックにアクセスしようとすると、Amazon RDS は Amazon S3 からそのブロックをプルするため、I/O 遅延が発生します。

Amazon RDS for PostgreSQL DB インスタンスを特定の時点に復元する際、ログファイルに情報が表示されます。

出力例:

2022-06-01 13:16:19 UTC::@:[8613]:LOG: starting point-in-time recovery to 2022-06-01 12:54:30+002022-06-01 13:16:19 UTC::@:[8613]:LOG: redo starts at 0/48A3220
waiting for 000000010000000000000001 archive /rdsdbdata/log/restore/pg-wal-archive.1.* to be downloaded
2022-06-01 13:17:22 UTC:127.0.0.1(46110):rdsadmin@rdsadmin:[10322]:FATAL: the database system is starting up
2022-06-01 13:17:25 UTC::@:[8613]:LOG: restored log file "000000010000000000000001" from archive
recovering 000000010000000000000002
2022-06-01 13:17:26 UTC::@:[8613]:LOG: restored log file "000000010000000000000002" from archive
recovering 000000010000000000000003
2022-06-01 13:17:28 UTC::@:[8613]:LOG: restored log file "000000010000000000000003" from archive
recovering 000000010000000000000004
2022-06-01 13:18:54 UTC::@:[8613]:LOG: restored log file "000000010000000000000022" from archive
recovering 000000010000000000000023
.
.
2022-06-01 13:33:16 UTC::@:[8613]:LOG: restored log file "00000001000000060000000B" from archive
2022-06-01 13:33:16 UTC::@:[8613]:LOG: recovery stopping before commit of transaction 9266438, time 2022-06-01 12:56:14.648042+00
2022-06-01 13:33:16 UTC::@:[8613]:LOG: redo done at 6/2C0003C0
2022-06-01 13:33:16 UTC::@:[8613]:LOG: last completed transaction was at log time 2022-06-01 12:51:14.646151+00
recovering 00000002.history
2022-06-01 13:33:16 UTC::@:[8613]:LOG: selected new timeline ID: 2
2022-06-01 13:33:16 UTC::@:[8613]:LOG: archive recovery complete
recovering 00000001.history
2022-06-01 13:33:16 UTC::@:[8620]:LOG: checkpoint starting: end-of-recovery immediate wait
2022-06-01 13:33:16 UTC::@:[8620]:LOG: checkpoint complete: wrote 2 buffers (0.0%); 0 WAL file(s) added, 0 removed, 8 recycled; write=0.002 s, sync=0.003 s, total=0.031 s; sync files=2, longest=0.003 s, average=0.002 s; distance=655360 kB, estimate=1611806
kB
2022-06-01 13:33:16 UTC::@:[8607]:LOG: database system is ready to accept connections
2022-06-01 13:37:18 UTC::@:[8607]:LOG: received fast shutdown request
2022-06-01 13:37:18 UTC::@:[8607]:LOG: aborting any active transactions
2022-06-01 13:37:18 UTC::@:[8607]:LOG: background worker "logical replication launcher" (PID 7394) exited with exit code 1
2022-06-01 13:37:18 UTC::@:[8620]:LOG: shutting down
2022-06-01 13:37:18 UTC::@:[8620]:LOG: checkpoint starting: shutdown immediate
2022-06-01 13:37:18 UTC::@:[8620]:LOG: checkpoint complete: wrote 9 buffers (0.0%); 0 WAL file(s) added, 0 removed, 1 recycled; write=0.003 s, sync=0.003 s, total=0.024 s; sync files=7, longest=0.003 s, average=0.001 s; distance=65535 kB, estimate=1457179
        kB
2022-06-01 13:37:20 UTC::@:[8607]:LOG: database system is shut down
2022-06-01 13:37:24 UTC::@:[10870]:LOG: starting PostgreSQL 13.4 on x86_64-pc-linux-gnu, compiled by gcc (GCC) 7.3.1 20180712 (Red Hat 7.3.1-12), 64-bit
2022-06-01 13:37:24 UTC::@:[10870]:LOG: listening on IPv4 address "0.0.0.0", port 5432
2022-06-01 13:37:24 UTC::@:[10870]:LOG: listening on IPv6 address "::", port 5432
2022-06-01 13:37:24 UTC::@:[10870]:LOG: listening on Unix socket "/tmp/.s.PGSQL.5432"
2022-06-01 13:37:24 UTC::@:[10875]:LOG: database system was shut down at 2022-06-01 13:37:18 UTC
2022-06-01 13:37:24 UTC::@:[10870]:LOG: database system is ready to accept connections

関連情報

Amazon EBS スナップショット

Amazon Aurora DB クラスターのクローン、スナップショット復元、またはポイントインタイム復元に時間がかかる原因を教えてください