GoldenGateExtract進(jìn)程hang問(wèn)題解決一例

一直運(yùn)行正常的extract進(jìn)程突然hang住了，起初懷疑是不是找不到歸檔所致，但是細(xì)細(xì)的檢查了下，extract所需的歸檔都還在，而且日

一直運(yùn)行正常的extract進(jìn)程突然hang住了，起初懷疑是不是找不到歸檔所致，但是細(xì)細(xì)的檢查了下，extract所需的歸檔都還在，而且日志中也沒(méi)報(bào)任何錯(cuò)。而且將extract進(jìn)程停掉后，也能正常起來(lái)，沒(méi)有任何錯(cuò)誤或者告警：

// ggserr.log
2015-05-25 11:03:27 INFO OGG-01513 Oracle GoldenGate Capture for Oracle, elis.prm: Positioning to (Thread 1) Sequence 5824, RBA 290544656, SCN 1415.2504802626.
2015-05-25 11:03:27 INFO OGG-01516 Oracle GoldenGate Capture for Oracle, elis.prm: Positioned to (Thread 1) Sequence 5824, RBA 290544656, SCN 1415.2504802626, May 20, 2015 4:50:25 PM.
2015-05-25 11:03:27 INFO OGG-01513 Oracle GoldenGate Capture for Oracle, elis.prm: Positioning to (Thread 2) Sequence 4798, RBA 18781712, SCN 1415.2504799356.
2015-05-25 11:03:27 INFO OGG-01516 Oracle GoldenGate Capture for Oracle, elis.prm: Positioned to (Thread 2) Sequence 4798, RBA 18781712, SCN 1415.2504799356, May 20, 2015 4:50:19 PM.
2015-05-25 11:03:27 INFO OGG-00993 Oracle GoldenGate Capture for Oracle, elis.prm: EXTRACT ELIS started.

//extract進(jìn)程的rpt文件
2015-05-25 11:03:27 INFO OGG-00546 Default thread stack size: 196608.

2015-05-25 11:03:27 INFO OGG-00547 Increasing thread stack size from 196608 to 1048576.

2015-05-25 11:03:27 INFO OGG-01513 Positioning to (Thread 1) Sequence 5824, RBA 290544656, SCN 1415.2504802626.

2015-05-25 11:03:27 INFO OGG-01516 Positioned to (Thread 1) Sequence 5824, RBA 290544656, SCN 1415.2504802626, May 20, 2015 4:50:25 PM.

2015-05-25 11:03:27 INFO OGG-01513 Positioning to (Thread 2) Sequence 4798, RBA 18781712, SCN 1415.2504799356.

2015-05-25 11:03:27 INFO OGG-01516 Positioned to (Thread 2) Sequence 4798, RBA 18781712, SCN 1415.2504799356, May 20, 2015 4:50:19 PM.

2015-05-25 11:03:27 INFO OGG-01517 Position of first record processed for Thread 1, Sequence 5824, RBA 290544656, SCN 1415.2504802623, May 20, 2015 4:50:25 PM.

2015-05-25 11:03:27 INFO OGG-01644 BOUNDED RECOVERY: COMPLETE: for object pool 1: p33619994_Redo Thread 1 at SeqNo: 5824, RBA: 290545168, SCN: 1415.2504802626 (6079883526466), Thread: 1.

2015-05-25 11:03:27 INFO OGG-01055 Recovery initialization completed for target file /ogg/ggate/data/dirext/lis/ea002534, at RBA 1109.

2015-05-25 11:03:27 INFO OGG-01478 Output file /ogg/ggate/data/dirext/lis/ea is using format RELEASE 11.2.

2015-05-25 11:03:27 INFO OGG-01517 Position of first record processed for Thread 2, Sequence 4798, RBA 18781712, SCN 1415.2504799356, May 20, 2015 4:50:19 PM.

2015-05-25 11:03:27 INFO OGG-01026 Rolling over remote file /ogg/ggate/data/dirext/lis/ea002534.

2015-05-25 11:03:27 INFO OGG-01053 Recovery completed for target file /ogg/ggate/data/dirext/lis/ea002535, at RBA 1109.

2015-05-25 11:03:27 INFO OGG-01057 Recovery completed for all targets.
從日志中看，extract進(jìn)程沒(méi)有問(wèn)題，但是extract進(jìn)程實(shí)際上是運(yùn)行不正常的：

GGSCI (hxddlis01) 8> info all

Program Status Group Lag at Chkpt Time Since Chkpt

MANAGER RUNNING
JAGENT RUNNING
EXTRACT RUNNING ELIS 96:14:58 00:00:04
EXTRACT RUNNING PL2IS 00:00:00 00:00:00
EXTRACT RUNNING PLIS 00:00:00 00:00:09
extract進(jìn)程的lag越來(lái)越大，而且trail文件也不再增長(zhǎng)。這情況真是讓人一頭霧水。我們先來(lái)看看當(dāng)前系統(tǒng)的運(yùn)行環(huán)境：

GoldenGate：11.2.1.0.27
Database: 11.2.0.3 兩節(jié)點(diǎn)的RAC，使用ASM
OS: AIX 6.1
然后搜索Oracle Support，，找到一篇文章1432994.1，和碰到的情形有點(diǎn)相像。在我們的環(huán)境中也是使用了DBLOGREADER，但是不同的是DBLOGREADERBUFSIZE已經(jīng)配置成1M：

...
TRANLOGOPTIONS BUFSIZE 1048576
TRANLOGOPTIONS DBLOGREADER, DBLOGREADERBUFSIZE 1048576
--TRANLOGOPTIONS _NOREADAHEAD ANY
EXTTRAIL /ogg/ggate/data/dirext/lis/ea
...
這也是AIX下能配置的最大值。難道該值還是太大的緣故？所以就嘗試將該值改成了512K：

...
TRANLOGOPTIONS BUFSIZE 1048576
TRANLOGOPTIONS DBLOGREADER, DBLOGREADERBUFSIZE 524288
--TRANLOGOPTIONS _NOREADAHEAD ANY
EXTTRAIL /ogg/ggate/data/dirext/lis/ea
...
然后重啟extract進(jìn)程，結(jié)果就正常了。估計(jì)使用DBLOGREADER還是有不少的bug。

本文永久更新鏈接地址：

聲明：本網(wǎng)頁(yè)內(nèi)容旨在傳播知識(shí)，若有侵權(quán)等問(wèn)題請(qǐng)及時(shí)與本網(wǎng)聯(lián)系，我們將在第一時(shí)間刪除處理。TEL:177 7030 7066 E-MAIL:11247931@qq.com