So there I was troubleshooting GoldenGate issue and was puzzled as to why GoldenGate transactions were not seen from Oracle database.
I had the transaction XID correct; however, I was filtering by ACTIVE transaction from Oracle which was causing the issue.
Please allow me to share a test case so that you don’t get stumped like I did.
Identify current log and update table
ARROW:(SOE@san):PRIMARY> select max(sequence#)+1 from v$log_history;
MAX(SEQUENCE#)+1
----------------
196
ARROW:(SOE@san):PRIMARY> update INVENTORIES set QUANTITY_ON_HAND=QUANTITY_ON_HAND-10 where PRODUCT_ID=171 and WAREHOUSE_ID=560;
1 row updated.
ARROW:(SOE@san):PRIMARY>
From GoldenGate, find opened transactions for duration of 10 minutes
$ ./ggsci
Oracle GoldenGate Command Interpreter for Oracle
Version 11.2.1.0.21 18343248 OGGCORE_11.2.1.0.0OGGBP_PLATFORMS_140404.1029_FBO
Linux, x64, 64bit (optimized), Oracle 11g on Apr 4 2014 15:18:36
Copyright (C) 1995, 2014, Oracle and/or its affiliates. All rights reserved.
GGSCI (arrow.localdomain) 1> info all
Program Status Group Lag at Chkpt Time Since Chkpt
MANAGER RUNNING
EXTRACT RUNNING ESAN 00:00:00 00:00:05
EXTRACT STOPPED PSAN_LAS 00:00:00 68:02:14
REPLICAT STOPPED RLAS_SAN 00:00:00 68:02:12
GGSCI (arrow.localdomain) 2> send esan, status
Sending STATUS request to EXTRACT ESAN ...
EXTRACT ESAN (PID 2556)
Current status: Recovery complete: At EOF
Current read position:
Redo thread #: 1
Sequence #: 196
RBA: 5861376
Timestamp: 2014-07-21 10:52:59.000000
SCN: 0.1653210
Current write position:
Sequence #: 7
RBA: 1130
Timestamp: 2014-07-21 10:52:52.621948
Extract Trail: /u01/app/ggs01/dirdat/ss
GGSCI (arrow.localdomain) 3> send esan, showtrans duration 10m
Sending showtrans request to EXTRACT ESAN ...
Oldest redo log file necessary to restart Extract is:
Redo Log Sequence Number 196, RBA 4955152
------------------------------------------------------------
XID: 3.29.673
Items: 1
Extract: ESAN
Redo Thread: 1
Start Time: 2014-07-21:10:41:41
SCN: 0.1652053 (1652053)
Redo Seq: 196
Redo RBA: 4955152
Status: Running
GGSCI (arrow.localdomain) 4>
Note the Redo Seq: 196 matches the sequence when the update was performed from Oracle database.
Also, note XID: 3.29.673
Let’s find the transaction from the database an notice the XID matches between GoldenGate and Oracle database.
ARROW:(SYS@san):PRIMARY> @trans.sql
START_TIME XID STATUS SID SERIAL# USERNAME STATUS SCHEMANAME SQLID CHILD
-------------------- ---------------- -------- ---------- ---------- ------------------ -------- ------------------ ------------- ----------
07/21/14 10:41:39 3.29.673 INACTIVE 105 9 SOE INACTIVE SOE 6cmmk52wfnr7r 0
ARROW:(SYS@san):PRIMARY> @xplan.sql
Enter value for sqlid: 6cmmk52wfnr7r
Enter value for child: 0
SQL_ID 6cmmk52wfnr7r, child number 0
-------------------------------------
update INVENTORIES set QUANTITY_ON_HAND=QUANTITY_ON_HAND-10 where
PRODUCT_ID=171 and WAREHOUSE_ID=560
Plan hash value: 2141863993
-----------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-----------------------------------------------------------------------------------
| 0 | UPDATE STATEMENT | | | | 3 (100)| |
| 1 | UPDATE | INVENTORIES | | | | |
|* 2 | INDEX UNIQUE SCAN| INVENTORY_PK | 1 | 14 | 2 (0)| 00:00:01 |
-----------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("PRODUCT_ID"=171 AND "WAREHOUSE_ID"=560)
20 rows selected.
ARROW:(SYS@san):PRIMARY>
For fun, switched logfile and perform another update.
ARROW:(MDINH@san):PRIMARY> select max(sequence#)+1 from v$log_history;
MAX(SEQUENCE#)+1
----------------
196
ARROW:(MDINH@san):PRIMARY> alter system switch logfile;
System altered.
ARROW:(MDINH@san):PRIMARY> /
System altered.
ARROW:(MDINH@san):PRIMARY> /
System altered.
ARROW:(MDINH@san):PRIMARY> /
System altered.
ARROW:(MDINH@san):PRIMARY> select max(sequence#)+1 from v$log_history;
MAX(SEQUENCE#)+1
----------------
200
ARROW:(MDINH@san):PRIMARY> update SOE.INVENTORIES set QUANTITY_ON_HAND=QUANTITY_ON_HAND-10 where PRODUCT_ID=170;
883 rows updated.
ARROW:(MDINH@san):PRIMARY>
Check GoldenGate transactions to find 2 open transactions, one from Redo Seq: 196 and one from Redo Seq: 200
GGSCI (arrow.localdomain) 1> send esan, showtrans
Sending SHOWTRANS request to EXTRACT ESAN ...
Oldest redo log file necessary to restart Extract is:
Redo Log Sequence Number 196, RBA 4955152
------------------------------------------------------------
XID: 3.29.673
Items: 1
Extract: ESAN
Redo Thread: 1
Start Time: 2014-07-21:10:41:41
SCN: 0.1652053 (1652053)
Redo Seq: 196
Redo RBA: 4955152
Status: Running
------------------------------------------------------------
XID: 4.20.516
Items: 883
Extract: ESAN
Redo Thread: 1
Start Time: 2014-07-21:11:03:20
SCN: 0.1654314 (1654314)
Redo Seq: 200
Redo RBA: 5136
Status: Running
GGSCI (arrow.localdomain) 2>
Let’s kill the transaction by SOE user.
ARROW:(SYS@san):PRIMARY> @trans.sql
START_TIME XID STATUS SID SERIAL# USERNAME STATUS SCHEMANAME SQLID CHILD
-------------------- ---------------- -------- ---------- ---------- ------------------ -------- ------------------ ------------- ----------
07/21/14 10:41:39 3.29.673 INACTIVE 105 9 SOE INACTIVE SOE 6cmmk52wfnr7r 0
07/21/14 11:03:19 4.20.516 INACTIVE 18 53 MDINH INACTIVE MDINH a5qywm8993bqg 0
ARROW:(SYS@san):PRIMARY> @xplan.sql
Enter value for sqlid: a5qywm8993bqg
Enter value for child: 0
SQL_ID a5qywm8993bqg, child number 0
-------------------------------------
update SOE.INVENTORIES set QUANTITY_ON_HAND=QUANTITY_ON_HAND-10 where
PRODUCT_ID=170
Plan hash value: 1060265186
------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------------
| 0 | UPDATE STATEMENT | | | | 28 (100)| |
| 1 | UPDATE | INVENTORIES | | | | |
|* 2 | INDEX RANGE SCAN| INV_PRODUCT_IX | 900 | 12600 | 4 (0)| 00:00:01 |
------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("PRODUCT_ID"=170)
20 rows selected.
ARROW:(SYS@san):PRIMARY> alter system kill session '105,9' immediate;
System altered.
ARROW:(SYS@san):PRIMARY> @trans.sql
START_TIME XID STATUS SID SERIAL# USERNAME STATUS SCHEMANAME SQLID CHILD
-------------------- ---------------- -------- ---------- ---------- ------------------ -------- ------------------ ------------- ----------
07/21/14 11:03:19 4.20.516 INACTIVE 18 53 MDINH INACTIVE MDINH a5qywm8993bqg 0
ARROW:(SYS@san):PRIMARY>
Verify transaction from killed session is removed from GoldenGate
GGSCI (arrow.localdomain) 1> send esan, status
Sending STATUS request to EXTRACT ESAN ...
EXTRACT ESAN (PID 2556)
Current status: Recovery complete: At EOF
Current read position:
Redo thread #: 1
Sequence #: 200
RBA: 464896
Timestamp: 2014-07-21 11:06:40.000000
SCN: 0.1654584
Current write position:
Sequence #: 7
RBA: 1130
Timestamp: 2014-07-21 11:06:37.435383
Extract Trail: /u01/app/ggs01/dirdat/ss
GGSCI (arrow.localdomain) 2> send esan, showtrans
Sending SHOWTRANS request to EXTRACT ESAN ...
Oldest redo log file necessary to restart Extract is:
Redo Log Sequence Number 200, RBA 5136
------------------------------------------------------------
XID: 4.20.516
Items: 883
Extract: ESAN
Redo Thread: 1
Start Time: 2014-07-21:11:03:20
SCN: 0.1654314 (1654314)
Redo Seq: 200
Redo RBA: 5136
Status: Running
GGSCI (arrow.localdomain) 3>
-- trans.sql
set lines 200 pages 1000
col xid for a16
col username for a18
col schemaname for a18
col osuser for a12
select t.start_time, t.xidusn||'.'||t.xidslot||'.'||t.xidsqn xid, s.status,
s.sid,s.serial#,s.username,s.status,s.schemaname,
decode(s.sql_id,null,s.prev_sql_id) sqlid, decode(s.sql_child_number,null,s.prev_child_number) child
from v$transaction t, v$session s
where s.saddr = t.ses_addr
order by t.start_time
;
No Comments Yet
Let us know what you think