How To Trace GoldenGate To Find Bad Code

DBA for client panic after seeing 15:59:15 hours Lag at Chkpt

REPLICAT=XXXXX
GGSCI (xxxxxx07) 3>  info all
Program     Status      Group       Lag at Chkpt  Time Since Chkpt
REPLICAT    RUNNING     XXXXX       15:59:15      00:00:08  unsure why this one is now behind – non-staging

Without access to the system, I requested following to trace what replicat is doing.

Please run and share results.
REPLICAT=XXXXX

send XXXXX trace2 /tmp/XXXXX.trc
wait for 2 minutes, then turn tracing off:
send XXXXX trace2 off 
Email XXXXX.trc as attachment

Findings is bad coding practices by committing every 10 records.

Unknown – was this recently deployed? What is it doing? This is where development would know.

Was there any code review or BVT (basic validation testing)?

SCHEMA.TABLE_BS count is 26,946,719 rows with AVG row length 27

How did I know there as commit every 10 records?

Trace contains 21,648 lines:
$ wc -l XXXXX.trc
21648 XXXXX.trc

Find occurrences for table from trace:
$ grep -c SCHEMA.TABLE_BS XXXXX.trc
1267
 
Find occurrences for ORA-01403: no data found from trace:
$ grep -c 1403 XXXXX.trc
1632

Find occurrences for successful database updates
$ grep -c "successful database updates" XXXXX.trc
364

Committing every 10 rows.
$ grep "successful database updates" XXXXX.trc|head
15:26:53.745 (3100055) successful database updates 0.253% (execute=7.847,total=3100.044,count=60)
15:26:54.539 (3100848) successful database updates 0.278% (execute=8.641,total=3100.838,count=70)
15:26:55.326 (3101635) successful database updates 0.303% (execute=9.411,total=3101.625,count=80)
15:26:56.119 (3102428) successful database updates 0.328% (execute=10.204,total=3102.417,count=90)
15:26:56.200 (3102509) successful database updates 0.331% (execute=10.285,total=3102.498,count=100)
15:26:56.213 (3102522) successful database updates 0.331% (execute=10.297,total=3102.512,count=110)
15:26:56.219 (3102528) successful database updates 0.332% (execute=10.302,total=3102.517,count=120)
15:26:56.224 (3102533) successful database updates 0.332% (execute=10.306,total=3102.522,count=130)
15:26:56.235 (3102544) successful database updates 0.332% (execute=10.315,total=3102.533,count=140)
15:26:56.240 (3102549) successful database updates 0.332% (execute=10.320,total=3102.539,count=150)

$ grep "successful database updates" XXXXX.trc|tail
15:28:50.482 (3216791) successful database updates 3.841% (execute=123.585,total=3216.781,count=3600)
15:28:50.488 (3216797) successful database updates 3.842% (execute=123.590,total=3216.786,count=3610)
15:28:50.498 (3216807) successful database updates 3.842% (execute=123.597,total=3216.797,count=3620)
15:28:50.504 (3216813) successful database updates 3.842% (execute=123.602,total=3216.802,count=3630)
15:28:50.516 (3216825) successful database updates 3.842% (execute=123.609,total=3216.814,count=3640)
15:28:50.528 (3216837) successful database updates 3.842% (execute=123.619,total=3216.826,count=3650)
15:28:50.536 (3216845) successful database updates 3.843% (execute=123.624,total=3216.835,count=3660)
15:28:50.543 (3216852) successful database updates 3.843% (execute=123.631,total=3216.841,count=3670)
15:28:51.479 (3217788) successful database updates 3.870% (execute=124.556,total=3217.778,count=3680)
15:28:53.212 (3219522) successful database updates 3.922% (execute=126.289,total=3219.511,count=3690)