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.
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
;
Ready to optimize your Oracle Database for the future?