GoldenGate BR(bounded Recovery)简单说明
背景
Oracle数据库的在线日志包含已提交的和未提交的事务，但OGG只会将已提交的事务写入到队列文件。因此，针对未提交的事务，特别是未提交的长事务，OGG会怎样处理呢？
有些长事务是在批处理作业中，需要几个小时才能执行完成，比如晚上跑批的作业。这种情况，OGG会从这些事务一执行就开始读取在线日志，但这些事务可能会持续很久，从而在线日志也会切换到归档日志中，这期间也可能会有其它事务在执行和提交，如果长事务一直未提交，一旦OGG抽取进程有重启，归档日志又因为定期的rman备份而删除，此时该怎么办呢？
针对以上情况，OGG有2种处理方式，第一种就是使用正常恢复归档的方式，即恢复OGG需要的所有归档日志，可能是从长事务开始的那个归档开始，这样OGG能事务开始的检查点开始解析；第二种方式就是使用Bounded Recovery的方式，下面的内容将讨论这种方式。
简单来说，BR（Bounded Recovery ）默认的设置是4小时，即每4小时OGG抽取进程会做一个检查点，在每个检查点的时间点上，OGG会检查长事务，并将超过4小时的长事务的当前状态写入到磁盘，默认保存在OGG安装目录的BR目录下。在每个BR的间隔点，这个操作会一直持续，直到事务提交，或事务回滚。
下面是官方文档的描述：
使用磁盘持久保存数据，用于恢复长事务，让抽取进程可以确保捕获性能（虽然只有在极端情况下才会发生捕获延迟）。如果抽取进程停止时，有些事务的开始时间远在这个时间点之前，那么系统需要占用大量的日志空间，也有可能这些日志文件不再保存或被删除。而且，重新从一个很早的日志文件开始读取事务，这种做法还是有些问题的，因为这些日志文件中的其它事务已经被解析并被写入到队列文件。如果通过持久化数据能恢复这些长事务的状态，那么就可以消除这个往返读取的工具。极端的情况下，如果有多个长事务，如果每个事务都要求从起点重新读取，那么OGG的捕获性能将大大降低。
在本示例中，我们将BR的间隔设置为20分钟，然后执行一个insert语句，但不提交。此时，抽取进程会从在线日志的某个点开始读取，在线日志的序号为：#14878。OGG抽取进程的参数添加一行：
BR BRINTERVAL 20M
然后我们切换几组日志，备份并删除序号为14878的日志文件。我们可以看到每隔20分钟，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 (ol66) 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 (ol66) 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 (ol66) 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 (ol66) 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 (ol66) 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 (ol66)
GGSCI (ol66) 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> commit;
Commit complete.
在抽取进程ext1的日志报告中，可以看到长事务的信息提示，包括事物xid，记录数等，也包含BR检查点的信息，可以看到每20分钟，日志中就会有BR写入检查点的提示信息，而且检查点的SCN随着时间也在增长。
GGSCI>view report ext1 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, Redo 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), Timestamp: 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), Timestamp: 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), Timestamp: 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小时的归档日志，以便满足任何长事务的解析要求。
