GoldenGate故障案例一则:
抽取进程无法无法捕获数据
⒈ 背景
某软件开发商自己维护的一套Goldengate环境,一共有5个抽取进程,所有的抽取进程状态都为running,但其中的一个抽取进程无法捕获数据变化,该抽取进程所对应的trail文件大小没有任何增长。
开发商无力解决该故障,最终希望我们帮忙看看这个故障。
2. 分析过程
1、首先查看GoldenGate的ggserr.log日志,在日志文件中,没有看到任何的异常日志。
2、对比正常进程和异常进程的配置文件,没有发现任何配置层面的问题。
3、查看异常检查抽取进程的检查点信息,检查点信息如下所示。
GGSCI (ceshi2) 25> info E_CQ,showch
EXTRACT E_CQ Last Started 2022-04-14 16:00 Status RUNNING
Checkpoint Lag 01:26:24 (updated 00:00:16 ago)
Log Read Checkpoint Oracle Redo Logs
2022-04-14 14:33:43 Seqno 416, RBA 127790608
SCN 4038.4242876625 (17347320817873)
Current Checkpoint Detail:
Read Checkpoint #1
Oracle Redo Log
Startup Checkpoint (starting position in the data source):
Thread #: 1
Sequence #: 416
RBA: 127790096
Timestamp: 2022-04-14 14:33:42.000000
SCN: 4038.4242876623 (17347320817871)
Redo File: DG_DATA/shengchan/onlinelog/group_1108.488.1100857375
Recovery Checkpoint (position of oldest unprocessed transaction in the data source):
Thread #: 1
Sequence #: 416
RBA: 127790096
Timestamp: 2022-04-14 14:33:42.000000
SCN: 4038.4242876623 (17347320817871)
Redo File: DG_DATA/shengchan/onlinelog/group_1108.488.1100857375
Current Checkpoint (position of last record read in the data source):
Thread #: 1
Sequence #: 416
RBA: 127790608
Timestamp: 2022-04-14 14:33:43.000000
SCN: 4038.4242876625 (17347320817873)
Redo File: DG_DATA/shengchan/onlinelog/group_1108.488.1100857375
Write Checkpoint #1
GGS Log Trail
Current Checkpoint (current write position):
Sequence #: 1
RBA: 0
Timestamp: 2022-04-14 14:33:05.962312
Extract Trail: ./dirdat/xa
Trail Type: EXTTRAIL
(略……)
从检查点信息可以看出,Recovery Checkpoint和Current Checkpoint已经基本上一致,那说明GoldenGate恢复已经基本上完成。同时也可以看到当前trail文件写的情况,写EXTTRAIL并没有写入,Sequence #: 1,RBA: 0,这说明这个抽取进程应该是刚刚创建。
4、查看异常进程的当前状态,信息如下。
可以看出,该进程的当前状态为:recovery[2] :at EOF,这说明这个抽取进程还没有完成恢复工作,当然也就不会进行数据抽取了。
查看GoldenGate官方文档,对进程的恢复状态进行了说明。
在异常终止事件后的Extract恢复期间出现符号。当Extract在恢复过程中不断更改其日志读取位置时,您可以跟踪其进展。
◆In recovery[1](在恢复[1])——提取正在恢复到其事务日志中的检查点。
◆In recovery[2](在恢复[2])——提取是恢复从其检查点到trail文件结束。
◆Recovery complete(恢复完成)——恢复完成,将恢复正常处理。
该进程一直卡在这个状态,那基本上可以判断与该进程所对应的trail文件有关,所以马上去看下dirdat文件下以xa开头的trail文件,发现当前以xa开头的文件为xa234255,这就很奇怪了,既然这是一套新环境,dirdat目录下怎么会有这些trail文件?
5、找到软件开发商,希望了解更多的细节。经过沟通才了解到新环境的GoldenGate是从老环境中拷贝过来的,他们在新环境中只是重建了抽取进程,但dirdat目录下的文件没有清理掉。
6、至此,应该已经找到问题的所在了。新环境中存在残余的信息,导致抽取进程恢复工作无法完成。把残余的trail文件删除,重启抽取后进程,应该就可以解决故障。
3. 解决方案
在新环境中,删除GoldenGate软件中dirdat目录下存在的残余信息,并重启抽取进程,该抽取进程立刻工作,可以正常抽取数据。
恢复后查看进程信息:
进程当前状态:Recovery complete:at EOF,恢复完成,该进程开始正常处理数据。
GGSCI (ceshi2) 36> info E_CQ,showch
EXTRACT E_CQ Last Started 2022-04-14 16:20 Status RUNNING
Checkpoint Lag 00:00:00 (updated 00:00:05 ago)
Log Read Checkpoint Oracle Redo Logs
2022-04-14 17:43:13 Seqno 416, RBA 380195328
SCN 4038.4243052302 (17347320993550)
Current Checkpoint Detail:
Read Checkpoint #1
Oracle Redo Log
Startup Checkpoint (starting position in the data source):
Thread #: 1
Sequence #: 416
RBA: 127790096
Timestamp: 2022-04-14 14:33:42.000000
SCN: 4038.4242876623 (17347320817871)
Redo File: DG_DATA/shengchan/onlinelog/group_1108.488.1100857375
Recovery Checkpoint (position of oldest unprocessed transaction in the data source):
Thread #: 1
Sequence #: 416
RBA: 380194832
Timestamp: 2022-04-14 17:43:13.000000
SCN: 4038.4243052302 (17347320993550)
Redo File: DG_DATA/shengchan/onlinelog/group_1108.488.1100857375
Current Checkpoint (position of last record read in the data source):
Thread #: 1
Sequence #: 416
RBA: 380195328
Timestamp: 2022-04-14 17:43:13.000000
SCN: 4038.4243052302 (17347320993550)
Redo File: DG_DATA/shengchan/onlinelog/group_1108.488.1100857375
Write Checkpoint #1
GGS Log Trail
Current Checkpoint (current write position):
Sequence #: 1
RBA: 12637521
Timestamp: 2022-04-14 17:43:15.541947
Extract Trail: ./dirdat/xa
Trail Type: EXTTRAIL
(略。。。。。。)
可以看到当前写的位置,写入trail文件,RBA: 12637521,多做几个可以看到rba是在变化,trail文件也在增加。
- END -
,