Saturday, October 31, 2015

How to Trace Goldengate process?

Scenario:  Goldengate process is running very slow, Goldengate is blocking itself. We want to trace  goldengate replicat. When we trace, goldengate process write process information to trace 


Turn on Tracing 

Here in this scenario, I am tracing replicat 

GGSCI (tnc301) 5> send replicat RNLGGSM1, trace rnlggsm1.trc

Sending trace request to REPLICAT RNLGGSM1 ...
Trace file /usr/local/opt/oracle//112106/rnlggsm1.trc opened.

Turn off Tracing 

GGSCI (tnc301) 6> send replicat RNLGGSM1, trace off

Sending trace request to REPLICAT RNLGGSM1 ...
Closing all trace files..


--------- 
Trace file output -- 

22:56:10.308 (19549288) exited READ_EXTRACT_RECORD (stat=0, seqno=1658, rba=270679289)
22:56:10.308 (19549288) processing record for M71152.NSP_LU
22:56:10.308 (19549288) * --- entering READ_EXTRACT_RECORD --- *
22:56:10.308 (19549288) exited READ_EXTRACT_RECORD (stat=0, seqno=1658, rba=270679663)
22:56:10.308 (19549288) processing record for M71152.NSP_LU
22:56:10.308 (19549288) * --- entering READ_EXTRACT_RECORD --- *
22:56:10.308 (19549288) exited READ_EXTRACT_RECORD (stat=0, seqno=1658, rba=270680037)
22:56:10.308 (19549288) processing record for M71152.NSP_LU
22:56:10.308 (19549288) * --- entering READ_EXTRACT_RECORD --- *
22:56:10.308 (19549288) exited READ_EXTRACT_RECORD (stat=0, seqno=1658, rba=270680413)
22:56:10.308 (19549288) processing record for M71152.NSP_LU
22:56:10.308 (19549288) mapping record
22:56:10.308 (19549288) entering perform_sql_statements (normal)
22:56:10.308 (19549288) entering execute_statement (op_type=15,NSPDBA.NSP_LU_GIS_GLID_STATUS)
22:56:10.308 (19549288) iotype:15 mode:0
22:56:10.308 (19549288) BIND val for col:3  :45 31
22:56:10.308 (19549288) BIND val for col:5  :0 0
22:56:10.308 (19549288) BIND val for col:0 :35 30 len:6 blen:0
22:56:10.308 (19549288) BIND val for col:1 :31 35 len:7 blen:0
22:56:10.308 (19549288) BIND val for col:2 :4e 0 len:1 blen:0
22:56:10.312 (19549291) OCI statement executed successfully...
22:56:10.312 (19549291) executed stmt (sql_err=0)
22:56:10.312 (19549291) exited perform_sql_statements (sql_err=0,recs output=1256695)
22:56:10.312 (19549291) * --- entering READ_EXTRACT_RECORD --- *
22:56:10.312 (19549291) exited READ_EXTRACT_RECORD (stat=0, seqno=1658, rba=270680791)
22:56:10.312 (19549291) processing record for M71152.NSP_LU
22:56:10.312 (19549291) * --- entering READ_EXTRACT_RECORD --- *
22:56:10.312 (19549291) exited READ_EXTRACT_RECORD (stat=0, seqno=1658, rba=270681169)
22:56:10.312 (19549291) processing record for M71152.NSP_LU
22:56:10.312 (19549291) * --- entering READ_EXTRACT_RECORD --- *
22:56:10.312 (19549291) exited READ_EXTRACT_RECORD (stat=0, seqno=1658, rba=270681541)
22:56:10.312 (19549291) processing record for M71152.NSP_LU
22:56:10.312 (19549291) * --- entering READ_EXTRACT_RECORD --- *
22:56:10.312 (19549291) exited READ_EXTRACT_RECORD (stat=0, seqno=1658, rba=270681915)
22:56:10.312 (19549291) processing record for M71152.NSP_LU
22:56:10.312 (19549291) mapping record
22:56:10.312 (19549291) entering perform_sql_statements (normal)
22:56:10.312 (19549291) entering execute_statement (op_type=15,NSPDBA.NSP_LU_GIS_GLID_STATUS)
22:56:10.312 (19549291) iotype:15 mode:0
22:56:10.312 (19549291) BIND val for col:3  :4e 31
22:56:10.312 (19549291) BIND val for col:5  :0 0
22:56:10.312 (19549291) BIND val for col:0 :38 31 len:6 blen:0
22:56:10.312 (19549291) BIND val for col:1 :31 37 len:7 blen:0
22:56:10.312 (19549291) BIND val for col:2 :4e 0 len:1 blen:0
22:56:10.334 (19549314) OCI statement executed successfully...
22:56:10.334 (19549314) executed stmt (sql_err=0)
22:56:10.334 (19549314) exited perform_sql_statements (sql_err=0,recs output=1256696)
22:56:10.336 (19549315) accepted connection from mipd301.sfdc.sbc.com:60190
22:56:10.336 (19549315) IPC_read from mipd301.sfdc.sbc.com:60190(144.155.227.120)

SUMMARY STATISTICS

General statistics:
99.26%  Checking messages (includes checkpointing)
         0.00%  Checking periodic tasks
 0.00%  Waiting for more data
 0.00%  Converting ASCII header to internal
 0.00%  Converting ASCII data to internal
 0.02%  Reading input records
 0.64%  Writing output records (replicate_io)
         0.00%  Mapping columns
         0.00%  Outputting data records
         0.63%  Performing SQL statements
 0.00%  Performing BATCHSQL statements
 0.61%  Performing actual DB op
 0.00%  Preparing SQL statements
 0.00%  Performing transaction commits
 0.00%  Checkpointing

Closing Trace File at 2015-09-10 Thu EDT 22:56:10

------Tracing helps to analyze process info of the goldengate processes |
------When you are raising Oracle SR in goldengate environment, Oracle guy recommend you to send trace info the goldengate process 

---NIKHIL TATINENI 
---Oracle in memory ---- 


Querys to monitor RAC

following few  Query's will help to find out culprits-  Query to check long running transaction from last 8 hours  Col Sid Fo...