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 ----
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 ----