How To correlate Oracle Database transaction with GoldenGate

Posted in: Technical Track

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
;

 

email

Author

Interested in working with Michael? Schedule a tech call.

4 Comments. Leave new

Where can I find the xplan.sql?
Thank you.

Reply

xplan.sql basically displays plan for SQL. Here is one version https://www.williamrobertson.net/code/xplan.sql and might want to search for others that satisfy what you are looking for.

Reply

Hi, the page is not available ( Could you please post it here..
Thank you!

Reply

— xplan.sql
— William Robertson – http://www.williamrobertson.net
— Transparent “Explain Plan” utility for SQL*Plus.

— Usage:
— @xplan
— Reports the execution plan of the current SQL buffer (i.e. the most recent SQL
— statement to be run, edited, fetched etc (not necessarily run), and then places it
— back in the buffer, as far as possible leaving everything the way it was.

— Notes:
— 2004/02/29: Changed to use DBMS_XPLAN.
— 2007/03/08: Uses SYS.PLAN_TABLE$ if available (sometimes an old plan_table is still present)
— 2007/03/15: Derives OS-specific OS commands by checking SQL*Plus executable extension in v$session.
— 2008/01/31: Refined OS checks so don’t need access to v$ tables;
— Also now specify “.lst” extension for SPOOL commands as Windows defaults to uppercase .LST and DEL is case-sensitive.
— 2008/02/12 Accepts optional “format” parameter for DBMS_SQL.DISPLAY_CURSOR(), e.g. @xplan all

set term off
store set sqlplus_settings.sql replace
def PLAN_TABLE = sys.plan_table$

ttitle off
set pause off
set feed off
set verify off
set timing off
set pages 999
set trimout on
set trimspool on
set long 2000
set autotrace off
set lines 150
set flagger off
set tab off
set serverout on size 10000

col QUERY_PATH format a70 hea “Query Path”
col STATEMENT_ID new_value STATEMENT_ID
col 1 new_value 1
col FORMAT_OPTIONS new_value FORMAT_OPTIONS
col DELETE_COMMAND new_value DELETE_COMMAND
col LIST_COMMAND new_value LIST_COMMAND
col OPTIMIZER format a9

break on report
comp sum label ” of cost on report

0 explain plan set statement_id = ‘&STATEMENT_ID’ into &PLAN_TABLE for

save xplan.buf repl

— “_O_VERSION” is predefined in SQL*Plus from around 10.1 and gives more information than v$version etc
— But just in case this is an old version of SQL*Plus, initialise it to null if it is undefined:
col dbversion new_value _o_version
select ” as dbversion from dual where 1=2;

— Now give _o_version a value from v$version if it’s empty (i.e. if we created it empty above):
select banner as dbversion from V$version where ‘&_O_VERSION’ is null and banner like ‘Oracle Database %’;

— savepoint xplan;

— Initialise “&1” in case no options were specified (&1 => “format” option of DBMS_XPLAN.DISPLAY_CURSOR):
select dummy as “1” from dual where 1 = 2;

— Generate unique statement_id for plan:
select user||to_char(sysdate,’DDMMYYHH24MISS’) statement_id
, coalesce(trim(‘&1’), ‘all -projection’) as format_options
from dual;

undef 1

— Define OS commands for showing and deleting files:
select case os when ‘MSWIN’ then ‘type’ else ‘cat’ end as list_command
, case os when ‘MSWIN’ then ‘del’ else ‘rm’ end as delete_command
from ( select case
when lower(sys_context(‘userenv’,’client_program_name’)) like ‘%.exe’
or sys_context(‘userenv’,’host’) like ‘%\%’
then ‘MSWIN’
end as os
from dual );

delete &PLAN_TABLE where statement_id = ‘&STATEMENT_ID’;

get xplan.buf nolist

spool xplan_errors.lst
@xplan.buf
spool off

set term on

spool xplan.lst

prompt &_o_version

declare
dbversion varchar2(20);
dbcompatibility varchar2(20);
begin
dbms_utility.db_version(dbversion, dbcompatibility);
— dbms_output.put_line(‘Oracle database version ‘ || dbversion);
if dbcompatibility <> dbversion then
dbms_output.put_line(‘Compatibility is set to ‘ || dbcompatibility);
end if;
end;
/

set hea off

select * from table(dbms_xplan.display(‘&PLAN_TABLE’,’&STATEMENT_ID’, ‘&format_options’));

set doc off

host &LIST_COMMAND xplan_errors.lst
host &DELETE_COMMAND xplan_errors.lst

spool off

set term off

set feed on hea on
–rollback to xplan;

get xplan.buf nolist
l1
del

clear breaks
undef STATEMENT_ID
— undef format_options
undef 1
@sqlplus_settings.sql
ho &DELETE_COMMAND sqlplus_settings.sql
ho &DELETE_COMMAND xplan.lst

set term on

Reply

Leave a Reply

Your email address will not be published. Required fields are marked *