OGG抽取进程异常一例

1、问题现象

出去进程常常running，但是没有新产生trail文件，lag比较大

GGSCI (xxxdb) 3> info all
Program     Status      Group       Lag at Chkpt  Time Since Chkpt

MANAGER     RUNNING                                           
EXTRACT     RUNNING     EXT1        05:35:57      492:33:56   
EXTRACT     RUNNING     PUMP1       00:00:00      00:00:02    
GGSCI (xxxdb) 4> 
GGSCI (xxxdb) 4> info EXT1,showch

EXTRACT    EXT1      Last Started 2018-05-28 17:20   Status RUNNING
Checkpoint Lag       05:35:57 (updated 492:35:53 ago)
Log Read Checkpoint  Oracle Redo Logs
                     2018-05-07 23:13:49  Seqno 5331, RBA 289991960
                     SCN 3439.4180128660 (14774572659604)
					 

2018-05-28 17:20:53  INFO    OGG-00987  Oracle GoldenGate Command Interpreter for Oracle:  GGSCI command (dtogg): start EXT1.
2018-05-28 17:20:53  INFO    OGG-00963  Oracle GoldenGate Manager for Oracle, mgr.prm:  Command received from GGSCI on host pacsdb (START EXTRACT EXT1 ).
2018-05-28 17:20:53  INFO    OGG-00975  Oracle GoldenGate Manager for Oracle, mgr.prm:  EXTRACT EXT1 starting.
2018-05-28 17:20:53  INFO    OGG-00992  Oracle GoldenGate Capture for Oracle, ext1.prm:  EXTRACT EXT1 starting.
2018-05-28 17:20:53  INFO    OGG-03035  Oracle GoldenGate Capture for Oracle, ext1.prm:  Operating system character set identified as ISO-8859-1. Locale: en
_US, LC_ALL:.
2018-05-28 17:20:54  INFO    OGG-01815  Oracle GoldenGate Capture for Oracle, ext1.prm:  Virtual Memory Facilities for: BR
    anon alloc: mmap(MAP_ANON)  anon free: munmap
    file alloc: mmap(MAP_SHARED)  file free: munmap
    target directories:
    /oracle/10.2/ogg/BR/EXT1.
2018-05-28 17:20:54  INFO    OGG-01815  Oracle GoldenGate Capture for Oracle, ext1.prm:  Virtual Memory Facilities for: COM
    anon alloc: mmap(MAP_ANON)  anon free: munmap
    file alloc: mmap(MAP_SHARED)  file free: munmap
    target directories:
    /oracle/10.2/ogg/dirtmp.
2018-05-28 17:20:54  INFO    OGG-01639  Oracle GoldenGate Capture for Oracle, ext1.prm:  BOUNDED RECOVERY:  ACTIVE: for object pool 1: p48169162_extr.
2018-05-28 17:20:54  INFO    OGG-01640  Oracle GoldenGate Capture for Oracle, ext1.prm:  BOUNDED RECOVERY: recovery start XID: 117.11.252267.
2018-05-28 17:20:54  INFO    OGG-01641  Oracle GoldenGate Capture for Oracle, ext1.prm:  BOUNDED RECOVERY: recovery start position: SeqNo: 5327, RBA: 322457
76, SCN: 3439.4175624574 (14774568155518), Timestamp: 2018-05-07 21:09:55.000000.
2018-05-28 17:20:54  INFO    OGG-01642  Oracle GoldenGate Capture for Oracle, ext1.prm:  BOUNDED RECOVERY: recovery end position: SeqNo: 5329, RBA: 82061788
4, SCN: 3439.4180119353 (14774572650297), Timestamp: 2018-05-07 23:09:01.000000, Thread: 1.
2018-05-28 17:20:54  INFO    OGG-01579  Oracle GoldenGate Capture for Oracle, ext1.prm:  BOUNDED RECOVERY: VALID BCP: CP.EXT1.000001412.
2018-05-28 17:20:54  INFO    OGG-01629  Oracle GoldenGate Capture for Oracle, ext1.prm:  BOUNDED RECOVERY: PERSISTED OBJECTS RECOVERED: 9.
2018-05-28 17:20:54  INFO    OGG-00987  Oracle GoldenGate Command Interpreter for Oracle:  GGSCI command (dtogg):  start ext1.
2018-05-28 17:20:55  INFO    OGG-01513  Oracle GoldenGate Capture for Oracle, ext1.prm:  Positioning to Sequence 5327, RBA 32245776, SCN 3439.4175624574.
2018-05-28 17:20:57  INFO    OGG-01516  Oracle GoldenGate Capture for Oracle, ext1.prm:  Positioned to Sequence 5327, RBA 32245776, SCN 3439.4175624574, May
 7, 2018 9:09:55 PM.

2、问题解决

通过 info ext1 showch  查看抽取进程的Recovery Checkpoint，设置抽取进程到相应时间

GGSCI (xxxdb) 7> alter extract EXT1 ,tranlog ,begin 2018-05-07 23:13:49

EXTRACT altered.

GGSCI (xxxdb) 8> start EXT1

Sending START request to MANAGER ...
EXTRACT EXT1 starting

GGSCI (xxxdb) 9> info EXT1

EXTRACT    EXT1      Initialized   2018-05-28 17:28   Status RUNNING
Checkpoint Lag       498:14:13 (updated 00:00:10 ago)
Log Read Checkpoint  Oracle Redo Logs
                     2018-05-07 23:13:49  Seqno 0, RBA 0
                     SCN 0.0 (0)

GGSCI (xxxdb) 12> info EXT1

EXTRACT    EXT1      Last Started 2018-05-28 17:28   Status RUNNING
Checkpoint Lag       498:13:54 (updated 00:00:09 ago)
Log Read Checkpoint  Oracle Redo Logs
                     2018-05-07 23:14:31  Seqno 5331, RBA 834580564
                     SCN 3439.4180220954 (14774572751898)

GGSCI (xxxdb) 13> info all

Program     Status      Group       Lag at Chkpt  Time Since Chkpt

MANAGER     RUNNING                                           
EXTRACT     RUNNING     EXT1        498:09:51     00:00:03    
EXTRACT     RUNNING     PUMP1       498:10:04     00:00:04    

GGSCI (xxxdb) 14>  info EXT1

EXTRACT    EXT1      Last Started 2018-05-28 17:28   Status RUNNING
Checkpoint Lag       498:08:55 (updated 00:00:07 ago)
Log Read Checkpoint  Oracle Redo Logs
                     2018-05-07 23:20:30  Seqno 5333, RBA 1141071888
                     SCN 3439.4180340086 (14774572871030)

2018-05-28 17:28:02  INFO    OGG-00987  Oracle GoldenGate Command Interpreter for Oracle:  GGSCI command (dtogg): alter extract EXT1  tranlog ,begin 2018-05
-07 23:13:49.
2018-05-28 17:28:09  INFO    OGG-00987  Oracle GoldenGate Command Interpreter for Oracle:  GGSCI command (dtogg): start EXT1.
2018-05-28 17:28:09  INFO    OGG-00963  Oracle GoldenGate Manager for Oracle, mgr.prm:  Command received from GGSCI on host pacsdb (START EXTRACT EXT1 ).
2018-05-28 17:28:09  INFO    OGG-00975  Oracle GoldenGate Manager for Oracle, mgr.prm:  EXTRACT EXT1 starting.
2018-05-28 17:28:09  INFO    OGG-00992  Oracle GoldenGate Capture for Oracle, ext1.prm:  EXTRACT EXT1 starting.
2018-05-28 17:28:09  INFO    OGG-03035  Oracle GoldenGate Capture for Oracle, ext1.prm:  Operating system character set identified as ISO-8859-1. Locale: en
_US, LC_ALL:.
2018-05-28 17:28:09  INFO    OGG-01635  Oracle GoldenGate Capture for Oracle, ext1.prm:  BOUNDED RECOVERY: reset to initial or altered checkpoint.
2018-05-28 17:28:09  INFO    OGG-01815  Oracle GoldenGate Capture for Oracle, ext1.prm:  Virtual Memory Facilities for: BR
    anon alloc: mmap(MAP_ANON)  anon free: munmap
    file alloc: mmap(MAP_SHARED)  file free: munmap
    target directories:
    /oracle/10.2/ogg/BR/EXT1.
2018-05-28 17:28:09  INFO    OGG-01815  Oracle GoldenGate Capture for Oracle, ext1.prm:  Virtual Memory Facilities for: COM
    anon alloc: mmap(MAP_ANON)  anon free: munmap
    file alloc: mmap(MAP_SHARED)  file free: munmap
    target directories:
    /oracle/10.2/ogg/dirtmp.
2018-05-28 17:28:10  INFO    OGG-01515  Oracle GoldenGate Capture for Oracle, ext1.prm:  Positioning to begin time May 7, 2018 11:13:49 PM.
2018-05-28 17:28:15  INFO    OGG-01516  Oracle GoldenGate Capture for Oracle, ext1.prm:  Positioned to Sequence 5331, RBA 279352336, SCN 0.0, May 7, 2018 11
:13:49 PM.
2018-05-28 17:28:15  INFO    OGG-00993  Oracle GoldenGate Capture for Oracle, ext1.prm:  EXTRACT EXT1 started.
2018-05-28 17:28:15  INFO    OGG-01055  Oracle GoldenGate Capture for Oracle, ext1.prm:  Recovery initialization completed for target file /oradata/ogg/dird
at/e1002586, at RBA 1024.
2018-05-28 17:28:15  INFO    OGG-01478  Oracle GoldenGate Capture for Oracle, ext1.prm:  Output file /oradata/ogg/dirdat/e1 is using format RELEASE 11.2.
2018-05-28 17:28:15  WARNING OGG-01438  Oracle GoldenGate Capture for Oracle, ext1.prm:  Checkpoint marked as from graceful shutdown, but records found afte
r checkpoint in trail /oradata/ogg/dirdat/e1.  Expected EOF Seqno 2583, RBA 6228814.  Found Seqno 2586, RBA 1024.
2018-05-28 17:28:15  INFO    OGG-01026  Oracle GoldenGate Capture for Oracle, ext1.prm:  Rolling over remote file /oradata/ogg/dirdat/e1002586.
2018-05-28 17:28:15  INFO    OGG-01053  Oracle GoldenGate Capture for Oracle, ext1.prm:  Recovery completed for target file /oradata/ogg/dirdat/e1002587, at
 RBA 1024.
2018-05-28 17:28:15  INFO    OGG-01057  Oracle GoldenGate Capture for Oracle, ext1.prm:  Recovery completed for all targets.
2018-05-28 17:28:15  INFO    OGG-01517  Oracle GoldenGate Capture for Oracle, ext1.prm:  Position of first record processed Sequence 5331, RBA 279352336, SC
N 3439.4180128606, May 7, 2018 11:13:49 PM.

shell下通过下列脚本过滤出OGG进程状态，留作监控使用

(echo info all;echo exit)|./ggsci|grep -E "EXTRACT|REPLICAT" |awk 'BEGIN {FS=" +"} {print $1","$3","$2","$4","$5}'