為什麼 Amazon RDS 資料庫執行個體的時間點還原需要很長的時間?

上次更新日期:2022 年 7 月 6 日

我正在執行 Amazon Relational Database Service (Amazon RDS) 資料庫執行個體的時間點還原操作。此操作需要很長時間才能完成。

簡短描述

使用 Restore to point in time (還原到時間點) 選項,您可以在啟用自動備份時,將資料庫執行個體還原到特定的時間點。已啟用自動備份的 Amazon RDS 執行個體可以還原到最早的可還原時間。最早可還原的時間會指定您可以在備份保留期內還原多久之前的執行個體。最長保留期間設定為 35 天,即五個行事曆週。您可以修改執行個體來變更此值 (從 0 至 35 天)。您可以在保留期內啟動時間點還原並指定任何日期和時間,最長為最近可還原的時間。最近可還原時間是您可從中還原執行個體的最近時間。

您可以使用 AWS Command Line Interface (AWS CLI) 命令 describe-db-instances 傳回執行個體的最近可還原時間。最近可還原時間通常在最近五分鐘內。您也可以在 Amazon RDS 主控台中選擇自動備份,找到最近的可還原時間。

當您為資料庫執行個體啟動時間點還原時,Amazon RDS 會代表您呼叫 RestoreDBInstanceToPointInTime API。此 API 會在 AWS CloudTrail 中進行追蹤。如需詳細資訊,請參閱在 CloudTrail 主控台中檢視 CloudTrail 事件

您也可以檢閱 RDS 日誌檔案來檢查時間點還原的進度。從備份還原 RDS 執行個體之後,您可以使用 RDS 日誌檔案來追蹤復原進度。

RDS 每五分鐘就會將資料庫執行個體的交易日誌上傳至 Amazon Simple Storage Service (Amazon S3)。在時間點還原期間,將會先還原最接近時間點中所提及時間的快照。然後,系統會套用交易日誌檔案,直到您在啟動還原點時所提及的時間為止。根據必須套用的交易日誌數目,此操作可能會花費較長的時間。

例如,假設您已經在今天 UTC 04:00 執行資料庫執行個體的自動備份,而且您必須在 UTC 06:15 執行時間點還原。在此情況下,執行個體會從 UTC 04:00 建立的備份還原。然後,再將 UTC 06:16 之前的交易日誌套用至還原的執行個體,以完成時間點還原程序。

解決方案

請使用下列最佳實務,來減少將資料庫執行個體還原至特定時間點所花費的時間:

  • 如果您已在來源執行個體上啟用自動備份功能,則最佳實務是定期建立手動快照,以避免因堆積而造成大量差異變更,並減少復原點目標
  • 請確定在執行時間點還原時,來源資料庫上沒有執行任何長時間執行的查詢。長時間執行的交易可能會延長復原時間,這表示資料庫可能需要更長的時間才能使用。
  • 請盡可能使用合適的交易日誌檔案大小。大型交易會一次寫入交易檔案,而且不會在不同的檔案之間分割。因此,交易日誌檔案最後會變得不必要的過大,增加當機復原時間。
  • 在時間點還原期間,還原執行個體的快照之後,S3 中的快照資料將會複製至基礎 Amazon Elastic Block Store (Amazon EBS) 磁碟區。此程序稱為延遲載入。當您嘗試存取尚未複製的區塊時,RDS 將會從 S3 提取該區塊,進而導致 I/O 延遲。若要協助減輕延遲載入對您需要快速存取之資料表的影響,您可以執行涉及完整資料表掃描的操作,例如 SELECT *。這可讓 Amazon RDS 從 S3 下載所有備份的資料表資料。

範例:

將 RDS for PostgreSQL 資料庫執行個體還原至特定時間點時,您可能會在日誌檔案中看到下列資訊:

2022-06-01 13:16:19 UTC::@:[8613]:LOG: starting point-in-time recovery to 2022-06-01 12:54:30+00
2022-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