GoldenGate 之 Bounded Recovery說明

 首先，我們來看兩個OGG同步中可能的問題：

l oracle在線日志包含已提交的和未提交的事務，但OGG只會將已提交的事務寫入到隊列文件。因此，針對未提交的事務，特別是未提交的長事務，OGG會怎樣處理呢？

l 有些長事務是在批處理作業中，需要幾個小時才能執行完成，比如晚上跑批的作業。OGG在解析過程中，會從這些事務一執行就開始讀取在線日志，但這些事務可能會持續很久，在期間，在線日志可能會切換到歸檔日志，同時這期間也會有其它事務在執行和提交，如果長事務一直未提交，歸檔日志又因為定期的rman備份而刪除，OGG將如何處理？

針對以上情況，OGG有2種處理方式，第一種就是使用正常恢復歸檔的方式，即恢復OGG需要的所有歸檔日志，可能是從長事務開始的那個歸檔開始，這樣OGG將從事務開始的檢查點開始解析；第二種方式就是使用Bounded Recovery的方式，下面的內容將討論這種方式。

簡單來說，BR（Bounded Recovery ）默認的設置是4小時，即每4小時OGG抽取進程會做一個檢查點，在每個檢查點的時間點上，OGG會檢查長事務，并將超過4小時的長事務的狀態寫入到磁盤（如果沒有達到4小時，則此事務不會被BR寫入），默認保存在OGG安裝目錄的BR目錄下。在每個BR的間隔點，這個操作會一直持續，直到事務提交，或事務回滾。

下面的示例中，我們設置BRINTERVAL為20分鐘：

BR BRINTERVAL 20M

下面是針對BR的官方文檔描述：

使用磁盤持久保存數據，用于恢復長事務，讓抽取進程可以確保捕獲性能（雖然只有在極端情況下才會發生捕獲延遲）。如果抽取進程停止時，有些事務的開始時間遠在這個時間點之前，那么系統需要占用大量的日志空間，也有可能這些日志文件不在磁盤上或已被刪除。而且，重新從一個很早的日志文件開始讀取事務，這種做法是不可接受的，因為這些日志文件中的其它事務已經被解析并被寫入到隊列文件。

如果通過持久化數據能恢復這些長事務的狀態，那么就可以消除這個往返讀取的動作。極端的情況下，如果有多個長事務，如果每個事務都要求從起點重新讀取，那么OGG的捕獲性能將大大降低。

在本示例中，我們將BR的間隔設置為20分鐘，然后執行一個insert語句，但不提交。此時，抽取進程會從在線日志的某個點開始讀取，在線日志的序號為：#14878。

然后我們切換幾組日志，備份并刪除序號為14878的日志文件。我們可以看到每隔20分鐘，BR checkpoint就會執行，此時，長事務的狀態信息及數據就會被寫入到磁盤上。即使磁盤上沒有對應的歸檔日志文件，抽取進程也不會再去讀取這些日志，而是直接從磁盤上保存的BR數據中進行恢復，如果事務提交，則OGG會直接將BR目錄下的數據寫入到隊列中。

測試步驟如下：

執行下面的INSERT語句，但不提交，用于測試長事務的場景：

SQL> insert into myobjects

select object_id,object_name,object_type from dba_objects;

75372 rows created.

通過infor ext1檢查當前讀取的在線日志序號，本測試中是14878

GGSCI 2> info ext1

EXTRACT EXT1 Last Started 2014-06-21 18:07 Status RUNNING

Checkpoint Lag 00:00:00 (updated 00:00:08 ago)

Process ID 15190

Log Read Checkpoint Oracle Redo Logs

2014-06-21 18:10:21 Seqno 14878, RBA 5936128

SCN 0.9137531 (9137531)

使用SEND EXTRACT SHOWTRANS查看是否有事務是打開狀態：

GGSCI 4> send ext1 showtrans

Sending SHOWTRANS request to EXTRACT EXT1 …

Oldest redo log file necessary to restart Extract is:

Redo Log Sequence Number 14878, RBA 116752

————————————————————

XID: 10.16.1533

Items: 75372

Extract: EXT1

Redo Thread: 1

Start Time: 2014-06-21:18:10:14

SCN: 0.9137521 (9137521)

Redo Seq: 14878

Redo RBA: 116752

Status: Running

INFO EXTRACT SHOWCH會顯示抽取進程檢查點的更多信息，包括當前事務（日志）中的讀取點，寫入隊列文件的位置等。下面的示例中，第一個檢查點是抽取進程啟動時的讀取點：14861，接著是最早未提交事務的讀取點：序號14878，SCN：9137521，最后是抽取進程當前的日志讀取檢查點，序號仍然是14878，但SCN是9137612，說明在這個未提交的事務之后，DB已經有一些其它操作。

GGSCI 5> info ext1 showch

EXTRACT EXT1 Last Started 2014-06-21 18:07 Status RUNNING

Checkpoint Lag 00:00:00 (updated 00:00:06 ago)

Process ID 15190

Log Read Checkpoint Oracle Redo Logs

2014-06-21 18:11:41 Seqno 14878, RBA 5977088

SCN 0.9137612 (9137612)

Current Checkpoint Detail:

Read Checkpoint #1

Oracle Redo Log

Startup Checkpoint (starting position in the data source):

Thread #: 1

Sequence #: 14861

RBA: 5918224

Timestamp: 2014-06-21 16:49:33.000000

SCN: 0.9129707 (9129707)

Redo File: /u01/app/oracle/fast_recovery_area/GGATE1/archivelog/2014_06_21/o1_mf_1_14861_9tbo7pys_.arc

Recovery Checkpoint (position of oldest unprocessed transaction in the data source):

Thread #: 1

Sequence #: 14878

RBA: 116752

Timestamp: 2014-06-21 18:10:14.000000

SCN: 0.9137521 (9137521)

Redo File: /u01/app/oracle/oradata/ggate1/redo03.log

Current Checkpoint (position of last record read in the data source):

Thread #: 1

Sequence #: 14878

RBA: 5977088

Timestamp: 2014-06-21 18:11:41.000000

SCN: 0.9137612 (9137612)

Redo File: /u01/app/oracle/oradata/ggate1/redo03.log

Write Checkpoint #1

GGS Log Trail

Current Checkpoint (current write position):

Sequence #: 3

RBA: 8130790

Timestamp: 2014-06-21 18:11:44.414364

Extract Trail: ./dirdat/zz

Trail Type: RMTTRAIL

大約20分鐘之后，我們繼續使用showch，看看與前面的命令相比，輸出有哪些差異：

可以看到，當前讀取的在線日志序號已經變為14884（以前是14878）。

但恢復檢查點仍然沒有變化，與上一個命令執行結果相同。

GGSCI 2> info ext1 showch

EXTRACT EXT1 Last Started 2014-06-21 18:07 Status RUNNING

Checkpoint Lag 00:00:00 (updated 00:00:04 ago)

Process ID 15190

Log Read Checkpoint Oracle Redo Logs

2014-06-21 18:40:34 Seqno 14884, RBA 72704

SCN 0.9139491 (9139491)

Current Checkpoint Detail:

Read Checkpoint #1

Oracle Redo Log

Startup Checkpoint (starting position in the data source):

Thread #: 1

Sequence #: 14861

RBA: 5918224

Timestamp: 2014-06-21 16:49:33.000000

SCN: 0.9129707 (9129707)

Redo File: /u01/app/oracle/fast_recovery_area/GGATE1/archivelog/2014_06_21/o1_mf_1_14861_9tbo7pys_.arc

Recovery Checkpoint (position of oldest unprocessed transaction in the data source):

Thread #: 1

Sequence #: 14878

RBA: 116752

Timestamp: 2014-06-21 18:10:14.000000

SCN: 0.9137521 (9137521)

Redo File: /u01/app/oracle/oradata/ggate1/redo03.log

Current Checkpoint (position of last record read in the data source):

Thread #: 1

Sequence #: 14884

RBA: 72704

Timestamp: 2014-06-21 18:40:34.000000

SCN: 0.9139491 (9139491)

Redo File: /u01/app/oracle/oradata/ggate1/redo03.log

通過上面的命令，我們看到了BR檢查點的相關信息，前面我們把BR間隔從默認4小時改為20分鐘，因此，每隔20分鐘（本示例中是：18:07，18:27，18:47...），長事務當前的狀態信息會被抽取進程寫入到磁盤上的BR目錄。

因此，我們看到在18:27的BR間隔時間點，BR將在線日志14881的信息持久到磁盤上，如果這個時候extract有錯誤或重啟，extract不再需要從早于14881序號的redo或歸檔里讀取數據。

BR Previous Recovery Checkpoint:

Thread #: 0

Sequence #: 0

RBA: 0

Timestamp: 2014-06-21 18:07:35.982719

SCN: Not available

Redo File:

BR Begin Recovery Checkpoint:

Thread #: 0

Sequence #: 14878

RBA: 116752

Timestamp: 2014-06-21 18:10:14.000000

SCN: 0.9137521 (9137521)

Redo File:

BR End Recovery Checkpoint:

Thread #: 1

Sequence #: 14881

RBA: 139776

Timestamp: 2014-06-21 18:27:38.000000

SCN: 0.9138688 (9138688)

Redo File:

在BR目錄中我們可以看到抽取進程ext1生成的一些文件：

GGSCI 4> info ext1

EXTRACT EXT1 Last Started 2014-06-21 18:07 Status RUNNING

Checkpoint Lag 00:00:00 (updated 00:00:06 ago)

Process ID 15190

Log Read Checkpoint Oracle Redo Logs

2014-06-21 18:41:35 Seqno 14884, RBA 131072

SCN 0.9139583 (9139583)

GGSCI 3> shell ls -l ./BR/EXT1

total 20

-rw-r—– 1 oracle oinstall 65536 Jun 21 18:27 CP.EXT1.000000015

drwxr-x— 2 oracle oinstall 4096 Jun 19 17:07 stale

此時，如果我們刪除14878的歸檔日志會怎樣呢？因為BR檢查點已經將包含長事務的日志序號為14878的信息寫入到磁盤，extract進程將不再需要這些舊的歸檔文件。為了測試這個功能，我們將14878歸檔備份之后刪除，記住，這個序號是長事務開始時的序號，在抽取進程檢查點日志中有記錄。

RMAN> backup archivelog sequence 14878 delete input;

Starting backup at 21-JUN-14

using target database control file instead of recovery catalog

allocated channel: ORA_DISK_1

channel ORA_DISK_1: SID=24 device type=DISK

channel ORA_DISK_1: starting archived log backup set

channel ORA_DISK_1: specifying archived log(s) in backup set

input archived log thread=1 sequence=14878 RECID=30497 STAMP=850846396

channel ORA_DISK_1: starting piece 1 at 21-JUN-14

channel ORA_DISK_1: finished piece 1 at 21-JUN-14

piece handle=/u01/app/oracle/fast_recovery_area/GGATE1/backupset/2014_06_21/o1_mf_annnn_TAG20140621T234659_9tcb7msp_.bkp tag=TAG20140621T234659 comment=NONE

channel ORA_DISK_1: backup set complete, elapsed time: 00:00:01

channel ORA_DISK_1: deleting archived log(s)

archived log file name=/u01/app/oracle/fast_recovery_area/GGATE1/archivelog/2014_06_21/o1_mf_1_14878_9tbpowlm_.arc RECID=30497 STAMP=850846396

Finished backup at 21-JUN-14

好，我們現在來提交這個交易。

SQL> insert into myobjects

2 select object_id,object_name,object_type from dba_objects;

75372 rows created.

SQL> commit;

Commit complete.

在抽取進程ext1的日志報告中，可以看到有長事務的信息、BR檢查點的信息，而且每隔20分鐘，BR檢查點寫入的redo日志序號是在增長的，即OGG抽取進程每20分鐘會將當前日志序號寫入，同時在OGG日志報告中體現出來。

2014-06-21 18:17:42 WARNING OGG-01027 Long Running Transaction: XID 10.16.1533, Items 75372, Extract EXT1, Redo Thread 1, SCN 0.9137521 (9137521), Redo Seq #14878, R

edo RBA 116752.

2014-06-21 18:27:41 INFO OGG-01971 The previous message, ‘WARNING OGG-01027′, repeated 1 times.

2014-06-21 18:27:41 INFO OGG-01738 BOUNDED RECOVERY: CHECKPOINT: for object pool 1: p23540_extr: start=SeqNo: 14878, RBA: 116752, SCN: 0.9137521 (9137521), Timest

amp: 2014-06-21 18:10:14.000000, end=SeqNo: 14881, RBA: 139776, SCN: 0.9138688 (9138688), Timestamp: 2014-06-21 18:27:38.000000, Thread: 1.

2014-06-21 18:47:50 INFO OGG-01738 BOUNDED RECOVERY: CHECKPOINT: for object pool 1: p23540_extr: start=SeqNo: 14885, RBA: 144912, SCN: 0.9139983 (9139983), Timest

amp: 2014-06-21 18:47:47.000000, Thread: 1, end=SeqNo: 14885, RBA: 145408, SCN: 0.9139983 (9139983), Timestamp: 2014-06-21 18:47:47.000000, Thread: 1.

2014-06-21 19:07:59 INFO OGG-01738 BOUNDED RECOVERY: CHECKPOINT: for object pool 1: p23540_extr: start=SeqNo: 14889, RBA: 176144, SCN: 0.9141399 (9141399), Timest

amp: 2014-06-21 19:07:56.000000, Thread: 1, end=SeqNo: 14889, RBA: 176640, SCN: 0.9141399 (9141399), Timestamp: 2014-06-21 19:07:56.000000, Thread: 1.

最后，記住一點：如果使用BR默認的4小時，則當前磁盤上至少要保存過去8小時的歸檔日志，以便滿足任何長事務的要求，當然，在實際生產環境中，往往要求保存的時間會更長。下面的圖示中

T27, T45開始于BR N-1之前，會在BR N這個檢查點上記錄狀態；而T801是在BR N-1之后開始，在BR N檢查點時，由于不滿足BR interval的時間要求，因此不會被記錄到BR N這個檢查點上，而是會記錄在BR N+1這個檢查點上。

    一旦在BR N和BR N+1這個時間范圍內，extract當掉，則T801的所有信息丟失，重啟extract之后，將會從T801開始的時間點解析日志。