We are using version-11.2.0.4 of oracle exadata. We have below query which changes execution plan and sometimes it runs for ~10minutes and other times finishing in seconds and then we noticed the execution plan changes based on the volume of records in table RSSG, when the data volume is small(~200 records) its going for a SORT JOIN and the query running for long time and when the data volume in this table RSSG is ~100k its going for HASH join path and finishes in seconds. I am trying to understand why in case of low volume in this table the optimizer is picking up a bad execution path and if we can fix this issue, without any hints/profiles?
Below is the sql monitor and auto-trace output for the query with the default plan which runs for ~6minutes and most of the time spent on step-9 and step-10 i.e. a sort JOIN and a Filter consuming significant CPU. Not sure what exactly influencing the optimizer for this plan, but i just then tried by forcing table(RSSG) to go for full scan and the query finishing in seconds.
SELECT RSSF.SID,
RSSF.SETIM,
RSCM.CID,
RSCM.MDAY
FROM RSSF,RSCM, RSSC, RSSG
WHERE RSSC.BTSID = 100
AND NVL (RSSC.STS, 'F') = 'F'
AND RSCM.CID = RSSG.CID
AND RSSG.FID = RSSF.FID
AND RSSF.PDT >= TO_DATE ( TO_CHAR ( TRUNC (RSSF.SETIM),'MM/DD/YYYY')|| ' '|| RSCM.MDAY,'MM/DD/YYYY HH:MI:SS AM')+ 1 / 24
AND RSSF.SETIM <TO_DATE ( TO_CHAR (TRUNC (RSSF.SETIM),'MM/DD/YYYY')|| ' '|| RSCM.MDAY,'MM/DD/YYYY HH:MI:SS AM')
AND RSSF.PDT >=TO_DATE (RSCM.LSDAY,'MM/DD/YYYY HH:MI:SS AM')
AND (RSSC.CRTIM - 2 / 24) >= TO_DATE (RSCM.LSDAY,'MM/DD/YYYY HH:MI:SS AM')- 1 / 24
AND RSSF.PDT < RSSC.CRTIM
************* default execution path*************
Global Information
------------------------------
STS : DONE (ALL ROWS)
Instance ID : 3
SQL Execution ID : 50331648
Execution Started : 08/22/2018 07:03:14
First Refresh Time : 08/22/2018 07:03:20
Last Refresh Time : 08/22/2018 07:09:52
Duration : 398s
Module/Action : SQL*Plus/-
Program : sqlplus.exe
Fetch Calls : 1
Global Stats
======================================================================================
| Elapsed | Cpu | IO | Cluster | Other | Fetch | Buffer | Read | Read |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Waits(s) | Calls | Gets | Reqs | Bytes |
======================================================================================
| 397 | 395 | 0.07 | 0.02 | 1.98 | 1 | 4428 | 406 | 30MB |
======================================================================================
SQL Plan Monitoring Details (Plan Hash Value=480587725)
=====================================================================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Mem | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | (Max) | (%) | (# samples) |
=====================================================================================================================================================================
| 0 | SELECT STATEMENT | | | | | | 1 | | | | |
| 1 | NESTED LOOPS | | 1 | 4298 | 109 | +6 | 1 | 0 | | | |
| 2 | NESTED LOOPS | | 27340 | 4298 | 393 | +6 | 1 | 2643 | | | |
| 3 | MERGE JOIN | | 1367 | 1554 | 393 | +6 | 1 | 106K | | | |
| 4 | SORT JOIN | | 2406 | 174 | 393 | +6 | 1 | 48148 | 3M | 0.25 | Cpu (1) |
| 5 | NESTED LOOPS | | 2406 | 173 | 1 | +6 | 1 | 48148 | | | |
| 6 | TABLE ACCESS BY INDEX ROWID | RSSC | 1 | 1 | 1 | +6 | 1 | 1 | | | |
| 7 | INDEX UNIQUE SCAN | RSSC_PK | 1 | | 1 | +6 | 1 | 1 | | | |
| 8 | TABLE ACCESS STORAGE FULL | RSCM | 2406 | 172 | 1 | +6 | 1 | 48148 | | | |
| 9 | FILTER | | | | 398 | +1 | 48148 | 106K | | 93.94 | Cpu (372) |
| 10 | SORT JOIN | | 38912 | 1366 | 393 | +6 | 48148 | 130M | 2M | 5.81 | Cpu (23) |
| 11 | TABLE ACCESS STORAGE FULL | RSSF | 38912 | 1027 | 1 | +6 | 1 | 32660 | | | |
| 12 | INDEX RANGE SCAN | RSSG_PK | 20 | 2 | 109 | +6 | 106K | 2643 | | | |
| 13 | TABLE ACCESS BY INDEX ROWID | RSSG | 1 | 11 | | | 2643 | | | | |
=====================================================================================================================================================================
Elapsed: 00:06:37.74
Execution Plan
----------------------------------------------------------
Plan hash value: 480587725
----------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes |TempSpc| Cost (%CPU)| Time |
----------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 98 | | 4298 (1)| 00:00:52 |
| 1 | NESTED LOOPS | | 1 | 98 | | 4298 (1)| 00:00:52 |
| 2 | NESTED LOOPS | | 27340 | 98 | | 4298 (1)| 00:00:52 |
| 3 | MERGE JOIN | | 1367 | 116K| | 1554 (2)| 00:00:19 |
| 4 | SORT JOIN | | 2406 | 122K| | 174 (1)| 00:00:03 |
| 5 | NESTED LOOPS | | 2406 | 122K| | 173 (0)| 00:00:03 |
| 6 | TABLE ACCESS BY INDEX ROWID| RSSC | 1 | 12 | | 1 (0)| 00:00:01 |
|* 7 | INDEX UNIQUE SCAN | RSSC_PK | 1 | | | 0 (0)| 00:00:01 |
|* 8 | TABLE ACCESS STORAGE FULL | RSCM | 2406 | 96240 | | 172 (0)| 00:00:03 |
|* 9 | FILTER | | | | | | |
|* 10 | SORT JOIN | | 38912 | 1330K| 3672K| 1366 (1)| 00:00:17 |
| 11 | TABLE ACCESS STORAGE FULL | RSSF | 38912 | 1330K| | 1027 (1)| 00:00:13 |
|* 12 | INDEX RANGE SCAN | RSSG_PK | 20 | | | 2 (0)| 00:00:01 |
|* 13 | TABLE ACCESS BY INDEX ROWID | RSSG | 1 | 11 | | 11 (0)| 00:00:01 |
----------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
7 - access("RSSC"."BTSID"=100)
8 - storage(INTERNAL_FUNCTION("RSSC"."CRTIM")-.0833333333333333333333333333333
333333333>=TO_DATE("RSCM"."LSDAY",'MM/DD/YYYY HH:MI:SS
AM')-.0416666666666666666666666666666666666667)
filter(INTERNAL_FUNCTION("RSSC"."CRTIM")-.08333333333333333333333333333333
33333333>=TO_DATE("RSCM"."LSDAY",'MM/DD/YYYY HH:MI:SS
AM')-.0416666666666666666666666666666666666667)
9 - filter("RSSF"."PDT">=TO_DATE(TO_CHAR(TRUNC(INTERNAL_FUNCTION("RSSF"."SETIM")),'MM/DD/YYYY')||' '||"RSCM"."MDAY",'MM/DD/YYYY
HH:MI:SS AM')+.0416666666666666666666666666666666666667 AND
"RSSF"."SETIM"<TO_DATE(TO_CHAR(TRUNC(INTERNAL_FUNCTION("RSSF
"."SETIM")),'MM/DD/YYYY')||' '||"RSCM"."MDAY",'MM/DD/YYYY HH:MI:SS
AM') AND "RSSF"."PDT"<"RSSC"."CRTIM")
10 - access("RSSF"."PDT">=TO_DATE("RSCM"."LSDAY",
'MM/DD/YYYY HH:MI:SS AM'))
filter("RSSF"."PDT">=TO_DATE("RSCM"."LSDAY",
'MM/DD/YYYY HH:MI:SS AM'))
12 - access("RSSG"."FID"="RSSF"."FID")
13 - filter("RSCM"."CID"="RSSG"."CID")
Statistics
----------------------------------------------------------
1 recursive calls
0 db block gets
4428 consistent gets
3779 physical reads
106744 redo size
442 bytes sent via SQL*Net to client
461 bytes received via SQL*Net from client
1 SQL*Net roundtrips to/from client
2 sorts (memory)
0 sorts (disk)
0 rows processed
*************** With FULL(RSSG) HINTS**************
Global Information
------------------------------
STS : DONE (ALL ROWS)
Instance ID : 4
SQL Execution ID : 67108864
Execution Started : 08/22/2018 07:06:19
First Refresh Time : 08/22/2018 07:06:19
Last Refresh Time : 08/22/2018 07:06:19
Duration : .065989s
Module/Action : SQL*Plus/-
Program : sqlplus.exe
Fetch Calls : 1
Global Stats
======================================
| Elapsed | Cpu | Fetch | Buffer |
| Time(s) | Time(s) | Calls | Gets |
======================================
| 0.07 | 0.07 | 1 | 35646 |
======================================
SQL Plan Monitoring Details (Plan Hash Value=1139378162)
======================================================================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Mem | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | (Max) | (%) | (# samples) |
======================================================================================================================================================================
| 0 | SELECT STATEMENT | | | | | | 1 | | | | |
| 1 | NESTED LOOPS | | 1 | 9602 | 1 | +0 | 1 | 0 | | | |
| 2 | NESTED LOOPS | | 30 | 9602 | 1 | +0 | 1 | 252 | | | |
| 3 | HASH JOIN | | 30 | 9572 | 1 | +0 | 1 | 252 | 1M | | |
| 4 | TABLE ACCESS STORAGE FULL | RSSG | 257 | 8544 | 1 | +0 | 1 | 258 | | | |
| 5 | NESTED LOOPS | | 4546 | 1028 | 1 | +0 | 1 | 31081 | | | |
| 6 | TABLE ACCESS BY INDEX ROWID | RSSC | 1 | 1 | 1 | +0 | 1 | 1 | | | |
| 7 | INDEX UNIQUE SCAN | RSSC_PK | 1 | | 1 | +0 | 1 | 1 | | | |
| 8 | TABLE ACCESS STORAGE FULL | RSSF | 4546 | 1027 | 1 | +0 | 1 | 31081 | | | |
| 9 | INDEX UNIQUE SCAN | RSCM_PK | 1 | | 1 | +0 | 252 | 252 | | | |
| 10 | TABLE ACCESS BY INDEX ROWID | RSCM | 1 | 1 | | | 252 | | | | |
======================================================================================================================================================================
Elapsed: 00:00:00.28
Execution Plan
----------------------------------------------------------
Plan hash value: 1139378162
---------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 98 | 9602 (1)| 00:01:56 |
| 1 | NESTED LOOPS | | 1 | 98 | 9602 (1)| 00:01:56 |
| 2 | NESTED LOOPS | | 30 | 98 | 9602 (1)| 00:01:56 |
|* 3 | HASH JOIN | | 30 | 1740 | 9572 (1)| 00:01:55 |
| 4 | TABLE ACCESS STORAGE FULL | RSSG | 257 | 2827 | 8544 (1)| 00:01:43 |
| 5 | NESTED LOOPS | | 4546 | 208K| 1028 (1)| 00:00:13 |
| 6 | TABLE ACCESS BY INDEX ROWID| RSSC | 1 | 12 | 1 (0)| 00:00:01 |
|* 7 | INDEX UNIQUE SCAN | RSSC_PK | 1 | | 0 (0)| 00:00:01 |
|* 8 | TABLE ACCESS STORAGE FULL | RSSF | 4546 | 155K| 1027 (1)| 00:00:13 |
|* 9 | INDEX UNIQUE SCAN | RSCM_PK | 1 | | 0 (0)| 00:00:01 |
|* 10 | TABLE ACCESS BY INDEX ROWID | RSCM | 1 | 40 | 1 (0)| 00:00:01 |
---------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
3 - access("RSSG"."FID"="RSSF"."FID")
7 - access("RSSC"."BTSID"=100)
8 - storage("RSSF"."PDT"<"RSSC"."CRTIM")
filter("RSSF"."PDT"<"RSSC"."CRTIM")
9 - access("RSCM"."CID"="RSSG"."CID")
10 - filter("RSSF"."PDT">=TO_DATE(TO_CHAR(TRUNC(INTERNAL_FUNCTION("RSSF"."SETIM")),'MM/DD/YYYY')||'
'||"RSCM"."MDAY",'MM/DD/YYYY HH:MI:SS
AM')+.0416666666666666666666666666666666666667 AND "RSSF"."SETIM"<TO_DATE(
TO_CHAR(TRUNC(INTERNAL_FUNCTION("RSSF"."SETIM")),'MM/DD/YYYY')||'
'||"RSCM"."MDAY",'MM/DD/YYYY HH:MI:SS AM') AND
"RSSF"."PDT">=TO_DATE("RSCM"."LSDAY",'MM/DD/
YYYY HH:MI:SS AM') AND INTERNAL_FUNCTION("RSSC"."CRTIM")-.0833333333333333
333333333333333333333333>=TO_DATE("RSCM"."LSDAY",'MM/DD/YYYY HH:MI:SS
AM')-.0416666666666666666666666666666666666667)
Statistics
----------------------------------------------------------
1 recursive calls
0 db block gets
35646 consistent gets
0 physical reads
0 redo size
442 bytes sent via SQL*Net to client
461 bytes received via SQL*Net from client
1 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
0 rows processed