GoldenGate案例一則：抽取進程無法捕獲數據

語言: CN / TW / HK

時間 2022-06-11 09:42:05 楊建榮的學習筆記

主題: 進程

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.424305 2302 (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 -

「其他文章」