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 -

「」