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、查看异常进程的当前状态,信息如下。

数据库并发控制题(抽取进程无法捕获数据)(1)

可以看出,该进程的当前状态为: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目录下存在的残余信息,并重启抽取进程,该抽取进程立刻工作,可以正常抽取数据。

恢复后查看进程信息:

数据库并发控制题(抽取进程无法捕获数据)(2)

进程当前状态: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 -

,