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:([email protected]):PRIMARY> select max(sequence#)+1 from v$log_history; MAX(SEQUENCE#)+1 ---------------- 196 ARROW:([email protected]):PRIMARY> update INVENTORIES set QUANTITY_ON_HAND=QUANTITY_ON_HAND-10 where PRODUCT_ID=171 and WAREHOUSE_ID=560; 1 row updated. ARROW:([email protected]):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:([email protected]):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:([email protected]):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:([email protected]):PRIMARY>
For fun, switched logfile and perform another update.
ARROW:([email protected]):PRIMARY> select max(sequence#)+1 from v$log_history; MAX(SEQUENCE#)+1 ---------------- 196 ARROW:([email protected]):PRIMARY> alter system switch logfile; System altered. ARROW:([email protected]):PRIMARY> / System altered. ARROW:([email protected]):PRIMARY> / System altered. ARROW:([email protected]):PRIMARY> / System altered. ARROW:([email protected]):PRIMARY> select max(sequence#)+1 from v$log_history; MAX(SEQUENCE#)+1 ---------------- 200 ARROW:([email protected]):PRIMARY> update SOE.INVENTORIES set QUANTITY_ON_HAND=QUANTITY_ON_HAND-10 where PRODUCT_ID=170; 883 rows updated. ARROW:([email protected]):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:([email protected]):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:([email protected]):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:([email protected]):PRIMARY> alter system kill session '105,9' immediate; System altered. ARROW:([email protected]):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:([email protected]):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
;
4 Comments. Leave new
Where can I find the xplan.sql?
Thank you.
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.
Hi, the page is not available ( Could you please post it here..
Thank you!
— 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