Variable execution time of sql with same plan
Date: Fri, 26 Nov 2021 18:06:22 +0530
Message-ID: <CAEjw_fho2eakzx3OgvMEbuG_VrFXmLFhAC2pE417HGXZLCdAjQ_at_mail.gmail.com>
Hello All, It's version 12.1.0.2.0 of oracle database with optimizer_feature_enable set as 11.2.0.4. We have the below query which sometimes runs in ~3-4minutes and sometimes goes for ~10minutes or even ~1hrs also. As its version 12.1 so was able to capture the sql monitor for a few of the good and bad runs for comparison. So I wanted to understand what is the reason behind the same and if we can make it better?
From the sql monitor it seems , it's the plan_line_id 8 and 9 i.e. fetching rows from table SFE using index SFE_IX1 is making the difference. But I want to understand , how come the difference is so much with the same plan hash value and even the EXECS column in the sql monitor shows the same amount of iteration in those index access steps?
SELECT *
FROM (SELECT /*+ ordered index(SFE SFE_IX1) index(SBD SBD_IX1) */
....,
ROW_NUMBER ()
OVER (PARTITION BY SBD.BDID
ORDER BY SFE.FID DESC) rn
FROM SBD , SFE ,STD
WHERE SFE.fhid = SBD.sfhid AND SFE.eid = STD.did AND
SFE.eid = SBD.did AND SFE.oid = SBD.sid AND SFE.ptcode IN ('XX',
'YY', 'ZZ')
AND SFE.ETYP = 'ZZZZ' AND NVL (SFE.SCID, '0') = NVL
(SBD.SCID, 0) AND SBD.P_DT = SFE.P_DT AND SBD.HD_ID = :b1 AND SBD.STAT =
:b2)
WHERE rn < 2;
Table SBD having total ~1.7million rows and table STD having ~4.2million rows.
SFE is the biggest one having ~1.7billion rows and partitioned. But all the indexes are global here. and the partition key is not used in the filter/join criteria. We have four indexes on the columns of the table that are used as join/filter predicate in this query.
COLUMN_NAME NUM_DISTINCT DENSITY NUM_NULLS HISTOGRAM
EIS 367397 2.72185E-06 0 NONE
ETYP 2 0.5 0 NONE
OID 219100 4.56413E-06 0 NONE
FHID 558916 1.78918E-06 0 NONE
PTCODE 419 0.002386635 0 NONE
SCID 1742 0.000574053 1693771500 NONE
P_DT 6546 0.0001527 0 NONE
Index SFE_IX4 - On column ptcode. Index SFE_IX2 - On column fhid. Index SFE_X1 - On column etyp , eid. Index SFE_TMP - On column p_dt.
INDEX_NAME BLEVEL LEAF_BLOCKS CLUSTERING_FACTOR NUM_ROWS distinct_keys
SFE_IX4 4 12553800 456127300 1670902700 419 SFE_IX2 4 13526400 79324200 1771657400 558916 SFE_X1 4 9883200 168223500 1730409900 367397 SFE_TMP 4 15856000 74249900 1737505200 6546
Below are the three different sql monitors captured with a big difference in run time.
Global Information
Status : DONE (ALL ROWS) Instance ID : 1 SQL Execution ID : 16777286 Execution Started : 11/10/2021 01:30:27 First Refresh Time : 11/10/2021 01:30:31 Last Refresh Time : 11/10/2021 01:33:11 Duration : 164s Program : JDBC Thin Client Fetch Calls : 1001
Global Stats
| Elapsed | Cpu | IO | Concurrency | Cluster | Fetch | Buffer |
Read | Read |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Waits(s) | Calls | Gets |
Reqs | Bytes |
| 175 | 94 | 81 | 0.00 | 0.73 | 1001 | 11M |
170K | 1GB |
| 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 | SELECT STATEMENT |
| | | 2 | +163 | 1 | 10000 | |
| | | |
| 1 | VIEW |
| 1 | 1385 | 2 | +163 | 1 | 10000 | |
| | | |
| 2 | WINDOW SORT PUSHED RANK |
| 1 | 1385 | 161 | +4 | 1 | 15000 | |
| 5M | | |
| 3 | NESTED LOOPS |
| | | 160 | +4 | 1 | 15000 | |
| | | |
| 4 | NESTED LOOPS |
| 1 | 1384 | 160 | +4 | 1 | 15000 | |
| | | |
| 5 | NESTED LOOPS |
| 1 | 1382 | 160 | +4 | 1 | 15000 | |
| | | |
| 6 | TABLE ACCESS BY INDEX ROWID | SBD
| 1 | 699 | 160 | +4 | 1 | 10000 | |
| | | |
| 7 | INDEX RANGE SCAN | SBD_IX1
| 9476 | 79 | 160 | +4 | 1 | 10000 | |
| | | |
| 8 | TABLE ACCESS BY GLOBAL INDEX ROWID | SFE
| 1 | 683 | 163 | +1 | 10000 | 15000 | 152K | 1GB
| | | |
| 9 | INDEX RANGE SCAN | SFE_IX1
| 4688 | 220 | 160 | +4 | 10000 | 108M | 18160 | 142MB
| | | |
| 10 | INDEX UNIQUE SCAN | STD_PK
| 1 | 1 | 161 | +4 | 15034 | 15000 | 3 | 24576
| | | |
| 11 | TABLE ACCESS BY INDEX ROWID | STD
| 1 | 2 | 160 | +4 | 15160 | 15000 | |
| | | |
=============================================================================================================================================================================================
Global Information
Status : DONE (ALL ROWS) Instance ID : 1 SQL Execution ID : 16777285 Execution Started : 11/10/2021 01:30:27 First Refresh Time : 11/10/2021 01:30:31 Last Refresh Time : 11/10/2021 01:38:48 Duration : 501s Program : JDBC Thin Client Fetch Calls : 1001
Global Stats
| Elapsed | Cpu | IO | Cluster | Fetch | Buffer | Read | Read |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Calls | Gets | Reqs | Bytes |
| 561 | 156 | 401 | 3.94 | 1001 | 9M | 864K | 7GB |
| 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 | SELECT STATEMENT |
| | | 1 | +501 | 1 | 10000 | |
| | | |
| 1 | VIEW |
| 1 | 1385 | 1 | +501 | 1 | 10000 | |
| | | |
| 2 | WINDOW SORT PUSHED RANK |
| 1 | 1385 | 498 | +4 | 1 | 15000 | |
| 5M | | |
| 3 | NESTED LOOPS |
| | | 498 | +4 | 1 | 15000 | |
| | | |
| 4 | NESTED LOOPS |
| 1 | 1384 | 498 | +4 | 1 | 15000 | |
| | | |
| 5 | NESTED LOOPS |
| 1 | 1382 | 498 | +4 | 1 | 15000 | |
| | | |
| 6 | TABLE ACCESS BY INDEX ROWID | SBD
| 1 | 699 | 498 | +4 | 1 | 10000 | 5 | 40960
| | | |
| 7 | INDEX RANGE SCAN | SBD_IX1
| 9476 | 79 | 498 | +4 | 1 | 10000 | |
| | | |
| 8 | TABLE ACCESS BY GLOBAL INDEX ROWID | SFE
| 1 | 683 | 498 | +4 | 10000 | 15000 | 696K | 5GB
| | | |
| 9 | INDEX RANGE SCAN | SFE_IX1
| 4688 | 220 | 501 | +1 | 10000 | 97M | 168K | 1GB
| | | |
| 10 | INDEX UNIQUE SCAN | STD_PK
| 1 | 1 | 498 | +4 | 15045 | 15000 | 5 | 40960 | | | |
| 11 | TABLE ACCESS BY INDEX ROWID | STD
| 1 | 2 | 498 | +4 | 15994 | 15000 | 2 | 16384
| | | |
============================================================================================================================================================================================
Global Information
Status : DONE (ALL ROWS) Instance ID : 1 SQL Execution ID : 16780848 Execution Started : 09/14/2021 12:17:54 First Refresh Time : 09/14/2021 12:17:58 Last Refresh Time : 09/14/2021 13:22:10 Duration : 3856s Program : JDBC Thin Client Fetch Calls : 1001
Global Stats
| Elapsed | Cpu | IO | Concurrency | Cluster | Other | Fetch
| Buffer | Read | Read |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Waits(s) | Waits(s) | Calls
| Gets | Reqs | Bytes |
| 3855 | 3822 | 26 | 0.02 | 2.31 | 5.45 | 1001
| 609M | 42879 | 335MB |
| 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 | SELECT STATEMENT |
| | | 2 | +3855 | 1 | 10000 | |
| | | |
| 1 | VIEW |
| 1 | 1374 | 2 | +3855 | 1 | 10000 | |
| | | |
| 2 | WINDOW SORT PUSHED RANK |
| 1 | 1374 | 3853 | +4 | 1 | 14998 | |
| 5M | | |
| 3 | NESTED LOOPS |
| | | 3852 | +4 | 1 | 14998 | |
| | | |
| 4 | NESTED LOOPS |
| 1 | 1373 | 3852 | +4 | 1 | 14998 | |
| | | |
| 5 | NESTED LOOPS |
| 1 | 1371 | 3852 | +4 | 1 | 14998 | |
| | | |
| 6 | TABLE ACCESS BY INDEX ROWID | SBD
| 1 | 677 | 3852 | +4 | 1 | 10000 | 304 | 2MB
| | | |
| 7 | INDEX RANGE SCAN | SBD_IX1
| 9362 | 78 | 3852 | +4 | 1 | 10000 | 57 | 456KB
| | | |
| 8 | TABLE ACCESS BY GLOBAL INDEX ROWID | SFE
| 1 | 694 | 3854 | +2 | 10000 | 14998 | 39830 | 311MB
| | | |
| 9 | INDEX RANGE SCAN | SFE_IX1
| 4180 | 230 | 3851 | +4 | 10000 | 4G | 2688 | 21MB
| | | |
| 10 | INDEX UNIQUE SCAN | STD_PK
| 1 | 1 | 3853 | +4 | 14998 | 14998 | |
| | | |
| 11 | TABLE ACCESS BY INDEX ROWID | STD
| 1 | 2 | 3852 | +4 | 14998 | 14998 | |
| | | |
=============================================================================================================================================================================================
Predicate Information (identified by operation id):
1 - filter("RN"<2)
2 - filter(ROW_NUMBER() OVER ( PARTITION BY "SBD"."BDID" ORDER BY
INTERNAL_FUNCTION("SFE"."FID") DESC )<2)
6 - filter("SBD"."STAT"=:B2)
7 - access("HD_ID"=:B1)
8 - filter(("SFE"."ptcode"='ZZ' OR "SFE"."ptcode"='XX' OR
"SFE"."ptcode"='YY') AND "SFE"."fhid"="SBD"."sfhid" AND
"SFE"."oid"="SBD"."sid" AND
NVL("SFE"."SCID",0)=NVL("SBD"."SCID",0) AND
"SBD"."P_DT"="SFE"."P_DT")
9 - access("SFE"."ETYP"='ZZZZ' AND "SFE"."eid"="SBD"."did")
10 - access("SFE"."eid"="STD"."did")
-- http://www.freelists.org/webpage/oracle-lReceived on Fri Nov 26 2021 - 13:36:22 CET