GoldenGate Extract process hang solution example
The normal extract process suddenly hang. At first, I suspected that the Archive was not found. However, after careful check, all the archives required by extract are still there, and no error is reported in the log. In addition, after the extract process is stopped, it can also become normal without any errors or warnings:
// Ggserr. log
11:03:27 INFO OGG-01513 Oracle GoldenGate Capture for Oracle, elis. prm: Positioning to (Thread 1) Sequence 5824, RBA 290544656, SCN 1415.2504802626.
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,201 5 4:50:25 PM.
11:03:27 INFO OGG-01513 Oracle GoldenGate Capture for Oracle, elis. prm: Positioning to (Thread 2) Sequence 4798, RBA 18781712, SCN 1415.2504799356.
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,201 5 4:50:19 PM.
11:03:27 INFO OGG-00993 Oracle GoldenGate Capture for Oracle, elis. prm: extract elis started.
// The rpt file of the extract Process
11:03:27 INFO OGG-00546 Default thread stack size: 196608.
11:03:27 INFO OGG-00547 Increasing thread stack size from 196608 to 1048576.
11:03:27 INFO OGG-01513 Positioning to (Thread 1) Sequence 5824, RBA 290544656, SCN 1415.2504802626.
11:03:27 INFO OGG-01516 Positioned to (Thread 1) Sequence 5824, RBA 290544656, SCN 1415.2504802626, May 20,201 5 4:50:25 PM.
11:03:27 INFO OGG-01513 Positioning to (Thread 2) Sequence 4798, RBA 18781712, SCN 1415.2504799356.
11:03:27 INFO OGG-01516 Positioned to (Thread 2) Sequence 4798, RBA 18781712, SCN 1415.2504799356, May 20,201 5 4:50:19 PM.
11:03:27 INFO OGG-01517 Position of first record processed for Thread 1, Sequence 5824, RBA 290544656, SCN 1415.2504802623, May 20,201 5 4:50:25 PM.
11:03:27 INFO OGG-01644 bounded recovery: COMPLETE: for object pool 1: p3365o4_redo Thread 1 at SeqNo: 5824, RBA: 290545168, SCN: 1415.2504802626 (6079883526466), Thread: 1.
11:03:27 INFO OGG-01055 Recovery initialization completed for target file/ogg/ggate/data/dirext/lis/ea002534, at RBA 1109.
11:03:27 INFO OGG-01478 Output file/ogg/ggate/data/dirext/lis/ea is using format RELEASE 11.2.
11:03:27 INFO OGG-01517 Position of first record processed for Thread 2, Sequence 4798, RBA 18781712, SCN 1415.2504799356, May 20,201 5 4:50:19 PM.
11:03:27 INFO OGG-01026 Rolling over remote file/ogg/ggate/data/dirext/lis/ea002534.
11:03:27 INFO OGG-01053 Recovery completed for target file/ogg/ggate/data/dirext/lis/ea002535, at RBA 1109.
11:03:27 INFO OGG-01057 Recovery completed for all targets.
From the log, there is no problem with the extract process, but the extract process is actually not running properly:
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
The lag of the extract process is growing, and the trail files are no longer growing. This is really confusing. Let's take a look at the operating environment of the current system:
GoldenGate: 11.2.1.0.27
Database: RAC at 11.2.0.3, Using ASM
OS: AIX 6.1
Search for Oracle Support and find Article 1432994.1, which is a bit similar to the situation encountered. DBLOGREADER is also used in our environment, but the difference is that DBLOGREADERBUFSIZE has been configured to 1 M:
...
Tranlogoptions bufsize 1048576
Tranlogoptions dblogreader, DBLOGREADERBUFSIZE 1048576
-- TRANLOGOPTIONS _ NOREADAHEAD ANY
EXTTRAIL/ogg/ggate/data/dirext/lis/ea
...
This is the maximum value that can be configured in AIX. Is the value too large? So I tried to change the value to 512 K:
...
Tranlogoptions bufsize 1048576
Tranlogoptions dblogreader, DBLOGREADERBUFSIZE 524288
-- TRANLOGOPTIONS _ NOREADAHEAD ANY
EXTTRAIL/ogg/ggate/data/dirext/lis/ea
...
Then restart the extract process and the result will be normal. It is estimated that DBLOGREADER has many bugs.