We are using version 11.2.0.4 of Oracle. We have tow databases holding exactly same records and the DB parameters are also same. one of the query runs for very long time(~4hr+ still not finished) in one database as compared to other(~15minutes). I was trying to get the session level statistics mainly related to UNDO and Chained/migrated rows. I see the query running in slow database is spending most of the time in reading from UNDO. I have published the sql monitor and the session statistics as below. As ,the DML activity on the base tables are same in both the databases, so I wanted to understand, if its the underlying I/O which is a factor in this issue, means the I/O is faster in one database causing the query to finish in quick time so traversing lesser UNDO but the other one having slow I/O so eventually visiting large UNDO?
I do see we have INSERT and DELETE queries runs on the base tables(PATA and PATM) during the same time in both the databases. and those are single row insert and deletes generated from third party application, ~30million inserts/deletes each day. Not sure if we can make it in bulk and that can improve the situation?
sql query:-
INSERT INTO TISDA (c1,
c2,
c3,
...)
SELECT
c1,
c2,
c3,c4,....
FROM PATA ADDM,
PATM MAIN,
( SELECT TRIM (SUBSTR (TXT,INSTR (TXT,',', 1,LEVEL)+ 1, INSTR (TXT,',',1,LEVEL + 1)- INSTR (TXT,',',1,LEVEL)- 1)) AS S_DATE FROM (SELECT ',' || :B1 || ',' TXT FROM DUAL) CONNECT BY LEVEL <=LENGTH ( :B1) - LENGTH (REPLACE ( :B1, ',', '')) + 1)
SDATE
WHERE MAIN.PMN = ADDM.PMN
AND MAIN.TNBR = ADDM.TNBR
AND MAIN.SIND = ADDM.SIND
AND MAIN.BNBR = ADDM.BNBR
AND MAIN.SNBR = ADDM.SNBR
AND MAIN.HDT = ADDM.HDT
AND MAIN.HMSC = ADDM.HMSC
AND MAIN.SIND = 'H'
AND ADDM.ANM = 'PCAN'
AND LPAD (TRIM (SUBSTR (ADDM.DAESDT, 1, 4)),
4,
'0') = SDATE.S_DATE;
Fast database query sql_monitor and session stats:-
***************************************************
Global Information
------------------------------
Status : DONE
Instance ID : 1
SQL Execution ID : 16777216
Execution Started : 07/19/2018 09:50:14
First Refresh Time : 07/19/2018 09:50:18
Last Refresh Time : 07/19/2018 10:04:26
Duration : 852s
Service : SYS$USERS
PLSQL Entry Ids (Object/Subprogram) : 125500,4
PLSQL Current Ids (Object/Subprogram) : 125500,1
Global Stats
======================================================================
| Elapsed | Cpu | IO | Concurrency | Buffer | Read | Read |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Gets | Reqs | Bytes |
======================================================================
| 869 | 155 | 713 | 0.04 | 5M | 794K | 12GB |
======================================================================
SQL Plan Monitoring Details (Plan Hash Value=3015087776)
=================================================================================================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Read | Read | Mem | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes | (Max) | (%) | (# samples) |
=================================================================================================================================================================================================
| 0 | INSERT STATEMENT | | | | | | 1 | | | | | | |
| 1 | LOAD TABLE CONVENTIONAL | | | | 849 | +4 | 1 | 0 | | | | 0.84 | Cpu (7) |
| 2 | NESTED LOOPS | | 10083 | 756K | 849 | +4 | 1 | 225K | | | | | |
| 3 | NESTED LOOPS | | 10083 | 756K | 849 | +4 | 1 | 225K | | | | 0.12 | Cpu (1) |
| 4 | HASH JOIN | | 10083 | 747K | 849 | +4 | 1 | 225K | | | 1M | 0.36 | Cpu (3) |
| 5 | VIEW | | 1 | 2 | 1 | +4 | 1 | 11 | | | | | |
| 6 | CONNECT BY WITHOUT FILTERING | | | | 1 | +4 | 1 | 11 | | | | | |
| 7 | FAST DUAL | | 1 | 2 | 1 | +4 | 1 | 1 | | | | | |
| 8 | TABLE ACCESS FULL | PATA | 1M | 747K | 850 | +3 | 1 | 1M | 652K | 11GB | | 64.40 | Cpu (128) |
| | | | | | | | | | | | | | latch free (1) |
| | | | | | | | | | | | | | db file scattered read (331) |
| | | | | | | | | | | | | | db file sequential read (79) |
| 9 | INDEX UNIQUE SCAN | PATM_PK | 1 | 1 | 851 | +2 | 246K | 225K | 15113 | 118MB | | 3.23 | Cpu (9) |
| | | | | | | | | | | | | | db file sequential read (18) |
| 10 | TABLE ACCESS BY INDEX ROWID | PATM | 1 | 1 | 849 | +4 | 345K | 225K | 126K | 574MB | | 30.94 | Cpu (7) |
| | | | | | | | | | | | | | db file parallel read (181) |
| | | | | | | | | | | | | | db file sequential read (71) |
=================================================================================================================================================================================================
Execution Plan
----------------------------------------------------------
Plan hash value: 3015087776
------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 10083 | 2225K| 756K (2)| 00:52:03 |
| 1 | NESTED LOOPS | | 10083 | 2225K| 756K (2)| 00:52:03 |
| 2 | NESTED LOOPS | | 10083 | 2225K| 756K (2)| 00:52:03 |
|* 3 | HASH JOIN | | 10083 | 896K| 747K (2)| 00:51:25 |
| 4 | VIEW | | 1 | 19 | 2 (0)| 00:00:01 |
|* 5 | CONNECT BY WITHOUT FILTERING| | | | | |
| 6 | FAST DUAL | | 1 | | 2 (0)| 00:00:01 |
|* 7 | TABLE ACCESS FULL | PATA | 1008K| 69M| 747K (2)| 00:51:25 |
|* 8 | INDEX UNIQUE SCAN | PATM_PK | 1 | | 1 (0)| 00:00:01 |
| 9 | TABLE ACCESS BY INDEX ROWID | PATM | 1 | 135 | 1 (0)| 00:00:01 |
------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
3 - access("SDATE"."S_DATE"=LPAD(TRIM(SUBSTR(TO_CHAR("ADDM"."DAESDT"),1,4)),4,'0'))
5 - filter(LEVEL<=LENGTH(:B1)-LENGTH(REPLACE(:B1,',',''))+1)
7 - filter("ADDM"."ANM"='PCAN' AND "ADDM"."SIND"='H')
8 - access("MAIN"."PMN"="ADDM"."PMN" AND "MAIN"."SIND"='H' AND
"MAIN"."TNBR"="ADDM"."TNBR" AND "MAIN"."BNBR"="ADDM"."BNBR" AND
"MAIN"."SNBR"="ADDM"."SNBR" AND "MAIN"."HDT"="ADDM"."HDT" AND
"MAIN"."HMSC"="ADDM"."HMSC")
session statistics:-
table fetch by rowid 3722627
data blocks consistent reads - undo records applied 1217953
cleanouts only - consistent read gets 104828
transaction tables consistent reads - undo records applied 75289
cleanouts and rollbacks - consistent read gets 1011
rollback changes - undo records applied 10
table fetch continued row 0
Slow database query sql_monitor and session stats:-
****************************************************
Global Information
------------------------------
Status : EXECUTING
Instance ID : 1
SQL Execution ID : 16777217
Execution Started : 07/19/2018 10:29:42
First Refresh Time : 07/19/2018 10:29:47
Last Refresh Time : 07/19/2018 14:28:23
Duration : 14978s
Service : SYS$USERS
PLSQL Entry Ids (Object/Subprogram) : 61119,4
PLSQL Current Ids (Object/Subprogram) : 61119,1
Global Stats
======================================================================
| Elapsed | Cpu | IO | Concurrency | Buffer | Read | Read |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Gets | Reqs | Bytes |
======================================================================
| 14475 | 638 | 13836 | 0.30 | 17M | 6M | 50GB |
======================================================================
SQL Plan Monitoring Details (Plan Hash Value=3015087776)
============================================================================================================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Read | Read | Mem | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes | | (%) | (# samples) |
============================================================================================================================================================================================================
| 0 | INSERT STATEMENT | | | | | | 1 | | | | | | |
| -> 1 | LOAD TABLE CONVENTIONAL | | | | 14317 | +5 | 1 | 0 | 88 | 704KB | | | |
| -> 2 | NESTED LOOPS | | 10595 | 224K | 14317 | +5 | 1 | 195K | | | | | |
| -> 3 | NESTED LOOPS | | 10595 | 224K | 14317 | +5 | 1 | 195K | | | | | |
| -> 4 | HASH JOIN | | 10595 | 215K | 14317 | +5 | 1 | 195K | | | 1M | | |
| 5 | VIEW | | 1 | 2 | 1 | +5 | 1 | 11 | | | | | |
| 6 | CONNECT BY WITHOUT FILTERING | | | | 1 | +5 | 1 | 11 | | | | | |
| 7 | FAST DUAL | | 1 | 2 | 1 | +5 | 1 | 1 | | | | | |
| 8 | TABLE ACCESS FULL | PATA | 1M | 215K | 14317 | +5 | 1 | 931K | 2M | 18GB | | 8.51 | Cpu (12) |
| | | | | | | | | | | | | | db file scattered read (2) |
| | | | | | | | | | | | | | db file sequential read (715) |
| -> 9 | INDEX UNIQUE SCAN | PATM_PK | 1 | 1 | 14975 | +5 | 202K | 195K | 4M | 30GB | | 89.98 | latch: cache buffers chains (1) |
| | | | | | | | | | | | | | Cpu (229) |
| | | | | | | | | | | | | | latch: object queue header operation (1) |
| | | | | | | | | | | | | | db file sequential read (7469) |
| | | | | | | | | | | | | | read by other session (12) |
| 10 | TABLE ACCESS BY INDEX ROWID | PATM | 1 | 1 | 14317 | +5 | 219K | 195K | 244K | 2GB | | 1.52 | Cpu (4) |
| | | | | | | | | | | | | | db file sequential read (126) |
============================================================================================================================================================================================================
Execution Plan
----------------------------------------------------------
Plan hash value: 3015087776
------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 10595 | 2348K| 224K (4)| 00:15:26 |
| 1 | NESTED LOOPS | | 10595 | 2348K| 224K (4)| 00:15:26 |
| 2 | NESTED LOOPS | | 10595 | 2348K| 224K (4)| 00:15:26 |
|* 3 | HASH JOIN | | 10595 | 951K| 214K (4)| 00:14:47 |
| 4 | VIEW | | 1 | 19 | 2 (0)| 00:00:01 |
|* 5 | CONNECT BY WITHOUT FILTERING| | | | | |
| 6 | FAST DUAL | | 1 | | 2 (0)| 00:00:01 |
|* 7 | TABLE ACCESS FULL | PATA | 1059K| 73M| 214K (4)| 00:14:47 |
|* 8 | INDEX UNIQUE SCAN | PATM_PK | 1 | | 1 (0)| 00:00:01 |
| 9 | TABLE ACCESS BY INDEX ROWID | PATM | 1 | 135 | 1 (0)| 00:00:01 |
------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
3 - access("SDATE"."S_DATE"=LPAD(TRIM(SUBSTR(TO_CHAR("ADDM"."DAESDT"),1,4)),4,'0'))
5 - filter(LEVEL<=LENGTH(:B1)-LENGTH(REPLACE(:B1,',',''))+1)
7 - filter("ADDM"."ANM"='PCAN' AND "ADDM"."SIND"='H')
8 - access("MAIN"."PMN"="ADDM"."PMN" AND "MAIN"."SIND"='H' AND
"MAIN"."TNBR"="ADDM"."TNBR" AND "MAIN"."BNBR"="ADDM"."BNBR" AND
"MAIN"."SNBR"="ADDM"."SNBR" AND "MAIN"."HDT"="ADDM"."HDT" AND
"MAIN"."HMSC"="ADDM"."HMSC")
session statistics(was still executing):-
transaction tables consistent reads - undo records applied 12338014
data blocks consistent reads - undo records applied 1828617
table fetch by rowid 219763
cleanouts and rollbacks - consistent read gets 2357
cleanouts only - consistent read gets 1706
table fetch continued row 11
rollback changes - undo records applied 0