I am using Version 12.1.0.2.0 Of oracle Exadata. We have a query which is running for ~1minutes sometimes with an indexed path of execution. The same query is finishing in few seconds with full scan on the base object. I was trying to find if any specific statistics is influencing this bad execution path and if that can be fixed. TRANSACTION is the main transaction table and other two tables(SCOM,SSC) are reference data table. The estimations looks not that bad which would influence the INDEXED path over FTS.
Another thing i notice, the sql monitor for the indexed execution path is showing wrong information(Actual rows etc). I see the actual rows resulted out of the query is ~17k however its showing ~4k. Then i collected the row source statistics plan with "gather_plan_statistics" hint which looks correct.
Below is the object statistics:-
Index TRANSACTION_IX7 is on column (PDATE)
Index TRANSACTION_IX2 is on column (CID, STATUS)
| TABLE_NAME | INDEX_NAME | BLEVEL | LEAF_BLOCKS | DISTINCT_KEYS | CLUSTERING_FACTOR | NUM_ROWS | SAMPLE_SIZE | LAST_ANALYZED |
| TRANSACTION | TRANSACTION_IX2 | 3 | 3500713 | 760320 | 663607742 | 758506648 | 2537230 | 2/13/2019 17:55 |
| TRANSACTION | TRANSACTION_IX7 | 3 | 5047845 | 4560 | 40023434 | 747440333 | 172651 | 2/13/2019 17:55 |
| | | | | | | | |
| TABLE_NAME | NUM_ROWS | BLOCKS | AVG_ROW_LEN | SAMPLE_SIZE | LAST_ANALYZED |
| SSC | 406 | 124 | 86 | 406 | 2/13/2019 17:36 |
| SCOM | 833550 | 26423 | 234 | 833550 | 2/13/2019 17:41 |
| TRANSACTION | 728590541 | 18759024 | 176 | 728590541 | 2/13/2019 17:55 |
| | | | | |
| TABLE_NAME | COLUMN_NAME | DATA_TYPE | NUM_DISTINCT | DENSITY | NUM_NULLS | SAMPLE_SIZE | HISTOGRAM |
| TRANSACTION | DATE_MODIFY | DATE | 5634048 | 0 | 0 | 5951 | HYBRID |
| TRANSACTION | PDATE | DATE | 4560 | 9.40E-05 | 1 | 5951 | HYBRID |
| TRANSACTION | status | VARCHAR2 | 9 | 6.86E-10 | 0 | 728590541 | FREQUENCY |
| TRANSACTION | CID | NUMBER | 760320 | 1.00E-06 | 0 | 5951 | HYBRID |
| SCOM | CID | NUMBER | 833550 | 1.20E-06 | 0 | 833550 | NONE |
We do have the default system statistics and its not been gathered in EXADATA mode. So i was thinking if that is making optimizer to calculate the index scan more cheaper as it would have been in Exadata. So i tried calculating the cost of FTS if the actual value of "IOTFRSPEED" in Exadat system would have been somewhere around ~80K. And as per below calculation the cost of FTS would have been 1/10th of the current FTS cost(~800k), but still i see the indexed path is having cost ~400k , is lower than that value too. So want to know, what exact thing is influencing the optimizer here?
I/O cost= ceil ( blocks / mbrc * (ioseektim + db_block_size / iotfrspeed) / (ioseektim + db_file_multiblock_read_count * db_block_size / iotfrspeed) ) + 1
PNAME PVAL1
CPUSPEEDNW 2268
IOSEEKTIM 4
IOTFRSPEED 4096
MBRC
db_file_multiblock_read_count= 128
select *
FROM SSC,
TRANSACTION,
SCOM
WHERE TRANSACTION.amt <> 0
AND ( ( TRANSACTION.STATUS IN ('AA','BB','CC','DD','EE')
)
OR ( TRANSACTION.STATUS='XX'
AND TRANSACTION.PDATE >=TRUNC (SSC.LSSTIME)
)
)
AND SCOM.INDICATOR = 0
AND SSC.BTID = 1111
AND NVL (SSC.status, 'F') = 'F'
AND SCOM.CID = TRANSACTION.CID
AND TRANSACTION.DATE_MODIFY >= '14-dec-2018'
AND TRANSACTION.DATE_MODIFY < SSC.CSTIME - 1 ;
Global Information
------------------------------
Status : DONE (ALL ROWS)
Instance ID : 2
SQL ID : 8craux2nu2syg
SQL Execution ID : 33554432
Execution Started : 02/14/2019 09:10:18
First Refresh Time : 02/14/2019 09:10:18
Last Refresh Time : 02/14/2019 09:10:50
Duration : 32s
Module/Action : SQL*Plus/-
Program : sqlplus.exe
Fetch Calls : 5
Global Stats
===========================================================================
| Elapsed | Cpu | IO | Cluster | Fetch | Buffer | Read | Read |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Calls | Gets | Reqs | Bytes |
===========================================================================
| 38 | 20 | 18 | 0.52 | 5 | 4M | 229K | 2GB |
===========================================================================
SQL Plan Monitoring Details (Plan Hash Value=1839688732)
=======================================================================================================================================================================================================
| 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 | | | | 33 | +0 | 1 | 4671 | | | | | |
| 1 | CONCATENATION | | | | 33 | +0 | 1 | 4671 | | | | | |
| 2 | HASH JOIN | | 2494 | 419K | 5 | +0 | 1 | 4671 | | | 15M | | |
| 3 | TABLE ACCESS STORAGE FULL | SCOM | 45019 | 11071 | 1 | +0 | 1 | 45020 | | | | | |
| 4 | NESTED LOOPS | | 42115 | 406K | 5 | +0 | 1 | 4682 | | | | | |
| 5 | TABLE ACCESS BY INDEX ROWID | SSC | 1 | 1 | 1 | +0 | 1 | 1 | | | | | |
| 6 | INDEX UNIQUE SCAN | SSC_UK | 1 | | 3 | +0 | 1 | 1 | | | | | |
| 7 | TABLE ACCESS BY INDEX ROWID | TRANSACTION | 42115 | 406K | 5 | +0 | 1 | 4682 | 2152 | 17MB | | 6.06 | cell single block physical read (2) |
| 8 | INDEX RANGE SCAN | TRANSACTION_IX7 | 7M | 45556 | 5 | +0 | 1 | 334K | 2327 | 18MB | | 3.03 | cell single block physical read (1) |
| 9 | NESTED LOOPS | | | | 29 | +4 | 1 | 12419 | | | | 3.03 | Cpu (1) |
| 10 | NESTED LOOPS | | 3112 | 2M | 29 | +4 | 1 | 4M | | | | | |
| 11 | NESTED LOOPS | | 45019 | 11072 | 29 | +4 | 1 | 45020 | | | | | |
| 12 | TABLE ACCESS BY INDEX ROWID | SSC | 1 | 1 | 1 | +4 | 1 | 1 | | | | | |
| 13 | INDEX UNIQUE SCAN | SSC_UK | 1 | | 28 | +4 | 1 | 1 | | | | | |
| 14 | TABLE ACCESS STORAGE FULL | SCOM | 45019 | 11071 | 29 | +4 | 1 | 45020 | | | | | |
| 15 | INLIST ITERATOR | | | | 29 | +4 | 45020 | 4M | | | | | |
| 16 | INDEX RANGE SCAN | TRANSACTION_IX2 | 34 | 7 | 30 | +3 | 225K | 4M | 27846 | 218MB | | 42.42 | Cpu (3) |
| | | | | | | | | | | | | | cell single block physical read (11) |
| 17 | TABLE ACCESS BY INDEX ROWID | TRANSACTION | 1 | 37 | 29 | +4 | 5M | 12419 | 197K | 2GB | | 45.45 | Cpu (11) |
| | | | | | | | | | | | | | cell list of blocks physical read (4) |
=======================================================================================================================================================================================================
**********Using gather_plan_statistics
Plan hash value: 1839688732
-------------------------------------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | Reads | OMem | 1Mem | Used-Mem |
-------------------------------------------------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | | 17090 |00:03:57.80 | 4441K| 550K| | | |
| 1 | CONCATENATION | | 1 | | 17090 |00:03:57.80 | 4441K| 550K| | | |
|* 2 | HASH JOIN | | 1 | 2494 | 4671 |00:00:01.29 | 46213 | 5977 | 14M| 4286K| 14M (0)|
|* 3 | TABLE ACCESS STORAGE FULL | SCOM | 1 | 45019 | 45020 |00:00:00.15 | 26434 | 0 | 1025K| 1025K| |
| 4 | NESTED LOOPS | | 1 | 42115 | 4682 |00:00:03.18 | 19779 | 5977 | | | |
|* 5 | TABLE ACCESS BY INDEX ROWID | SSC | 1 | 1 | 1 |00:00:00.01 | 2 | 0 | | | |
|* 6 | INDEX UNIQUE SCAN | SSC_UK | 1 | 1 | 1 |00:00:00.01 | 1 | 0 | 1025K| 1025K| |
|* 7 | TABLE ACCESS BY INDEX ROWID | TRANSACTION | 1 | 42115 | 4682 |00:00:03.18 | 19777 | 5977 | | | |
|* 8 | INDEX RANGE SCAN | TRANSACTION_IX7 | 1 | 6726K| 333K|00:00:01.02 | 2358 | 2350 | 1025K| 1025K| |
| 9 | NESTED LOOPS | | 1 | | 12419 |00:16:45.07 | 4395K| 544K| | | |
| 10 | NESTED LOOPS | | 1 | 3112 | 4482K|00:00:23.04 | 426K| 40128 | | | |
| 11 | NESTED LOOPS | | 1 | 45019 | 45020 |00:00:00.26 | 26438 | 0 | | | |
|* 12 | TABLE ACCESS BY INDEX ROWID| SSC | 1 | 1 | 1 |00:00:00.01 | 2 | 0 | | | |
|* 13 | INDEX UNIQUE SCAN | SSC_UK | 1 | 1 | 1 |00:00:00.01 | 1 | 0 | 1025K| 1025K| |
|* 14 | TABLE ACCESS STORAGE FULL | SCOM | 1 | 45019 | 45020 |00:00:00.25 | 26436 | 0 | 1025K| 1025K| |
| 15 | INLIST ITERATOR | | 45020 | | 4482K|00:00:36.59 | 399K| 40128 | | | |
|* 16 | INDEX RANGE SCAN | TRANSACTION_IX2 | 225K| 34 | 4482K|00:00:21.06 | 399K| 40128 | 1025K| 1025K| |
|* 17 | TABLE ACCESS BY INDEX ROWID | TRANSACTION | 4482K| 1 | 12419 |00:04:02.22 | 3969K| 504K| | | |
-------------------------------------------------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - access("SCOM"."CID"="TRANSACTION"."CID")
3 - storage("SCOM"."INDICATOR"=0)
filter("SCOM"."INDICATOR"=0)
5 - filter(INTERNAL_FUNCTION("SSC"."CSTIME")-1>TO_DATE(' 2018-12-14 00:00:00', 'syyyy-mm-dd hh24:mi:ss') AND NVL("SSC"."STATUS",'F')='F')
6 - access("SSC"."BTID"=1111)
7 - filter("TRANSACTION"."DATE_MODIFY">=TO_DATE(' 2018-12-14 00:00:00', 'syyyy-mm-dd hh24:mi:ss')
AND "TRANSACTION"."STATUS"='XX' AND "TRANSACTION"."AMT"<>0 AND "TRANSACTION"."DATE_MODIFY"<INTERNAL_FUNCTION("SSC"."CSTIME")-1)
8 - access("TRANSACTION"."PDATE">=TRUNC(INTERNAL_FUNCTION("SSC"."LSSTIME")))
12 - filter(INTERNAL_FUNCTION("SSC"."CSTIME")-1>TO_DATE(' 2018-12-14 00:00:00', 'syyyy-mm-dd hh24:mi:ss') AND NVL("SSC"."STATUS",'F')='F')
13 - access("SSC"."BTID"=1111)
14 - storage("SCOM"."INDICATOR"=0)
filter("SCOM"."INDICATOR"=0)
16 - access("SCOM"."CID"="TRANSACTION"."CID" AND
("TRANSACTION"."STATUS"='BB' OR "TRANSACTION"."STATUS"='CC' OR "TRANSACTION"."STATUS"='AA' OR "TRANSACTION"."STATUS"='EE' OR "TRANSACTION"."STATUS"='DD'))
17 - filter("TRANSACTION"."DATE_MODIFY">=TO_DATE(' 2018-12-14 00:00:00', 'syyyy-mm-dd hh24:mi:ss')
AND "TRANSACTION"."AMT"<>0 AND "TRANSACTION"."DATE_MODIFY"<INTERNAL_FUNCTION("SSC"."CSTIME")-1 AND (LNNVL("TRANSACTION"."STATUS"='XX') OR
LNNVL("TRANSACTION"."PDATE">=TRUNC(INTERNAL_FUNCTION("SSC"."LSSTIME")))))
Statistics
----------------------------------------------------------
1 recursive calls
0 db block gets
4442380 consistent gets
229315 physical reads
7375408 redo size
3323884 bytes sent via SQL*Net to client
533 bytes received via SQL*Net from client
5 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
17090 rows processed
*********** sql monitor when using FULL Hint******************
select /*+MONITOR FULL(TRANSACTION)*/*
FROM SSC,
TRANSACTION,
SCOM
WHERE TRANSACTION.amt <> 0
AND ( ( TRANSACTION.STATUS IN ('AA','BB','CC','DD','EE')
)
OR ( TRANSACTION.STATUS='XX'
AND TRANSACTION.PDATE >=TRUNC (SSC.LSSTIME)
)
)
AND SCOM.INDICATOR = 0
AND SSC.BTID = 1111
AND NVL (SSC.status, 'F') = 'F'
AND SCOM.CID = TRANSACTION.CID
AND TRANSACTION.DATE_MODIFY >= '14-dec-2018'
AND TRANSACTION.DATE_MODIFY < SSC.CSTIME - 1 ;
Global Information
------------------------------
Status : DONE (ALL ROWS)
Instance ID : 2
SQL ID : 319g5y94nau0n
SQL Execution ID : 33554432
Execution Started : 02/14/2019 09:16:01
First Refresh Time : 02/14/2019 09:16:01
Last Refresh Time : 02/14/2019 09:16:04
Duration : 3s
Module/Action : SQL*Plus/-
Program : sqlplus.exe
Fetch Calls : 5
Global Stats
===================================================================================================
| Elapsed | Cpu | IO | Application | Cluster | Fetch | Buffer | Read | Read | Cell |
| Time(s) | Time(s) | Waits(s) | Waits(s) | Waits(s) | Calls | Gets | Reqs | Bytes | Offload |
===================================================================================================
| 2.58 | 1.72 | 0.84 | 0.01 | 0.00 | 5 | 19M | 147K | 143GB | 99.94% |
===================================================================================================
SQL Plan Monitoring Details (Plan Hash Value=4254176831)
===============================================================================================================================================================================================
| Id | Operation | Name | Rows | Cost | Time | Start | Execs | Rows | Read | Read | Cell | Mem | Activity | Activity Detail |
| | | | (Estim) | | Active(s) | Active | | (Actual) | Reqs | Bytes | Offload | (Max) | (%) | (# samples) |
===============================================================================================================================================================================================
| 0 | SELECT STATEMENT | | | | 3 | +1 | 1 | 17090 | | | | | | |
| 1 | HASH JOIN | | 4204 | 8M | 3 | +1 | 1 | 17090 | | | | 15M | | |
| 2 | TABLE ACCESS STORAGE FULL | SCOM | 45019 | 11071 | 1 | +1 | 1 | 45020 | | | | | | |
| 3 | NESTED LOOPS | | 70996 | 8M | 3 | +1 | 1 | 41259 | | | | | | |
| 4 | TABLE ACCESS BY INDEX ROWID | SSC | 1 | 1 | 1 | +1 | 1 | 1 | | | | | | |
| 5 | INDEX UNIQUE SCAN | SSC_UK | 1 | | 3 | +1 | 1 | 1 | | | | | | |
| 6 | TABLE ACCESS STORAGE FULL | TRANSACTION | 70996 | 8M | 4 | +1 | 1 | 41259 | 147K | 143GB | 99.94% | 15M | 100.00 | Cpu (2) |
| | | | | | | | | | | | | | | cell smart table scan (1) |
===============================================================================================================================================================================================
Predicate Information (identified by operation id):
---------------------------------------------------
1 - access("SCOM"."CID"="TRANSACTION"."CID")
2 - storage("SCOM"."INDICATOR"=0)
filter("SCOM"."INDICATOR"=0)
4 - filter(INTERNAL_FUNCTION("SSC"."CSTIME")-1>TO_DATE(' 2018-12-14 00:00:00', 'syyyy-mm-dd hh24:mi:ss') AND NVL("SSC"."STATUS",'F')='F')
5 - access("SSC"."BTID"=1111)
6 - storage("TRANSACTION"."DATE_MODIFY">=TO_DATE(' 2018-12-14 00:00:00', 'syyyy-mm-dd hh24:mi:ss') AND "TRANSACTION"."AMT"<>0 AND (("TRANSACTION"."STATUS"='BB' OR
"TRANSACTION"."STATUS"='CC' OR "TRANSACTION"."STATUS"='AA' OR "TRANSACTION"."STATUS"='EE' OR "TRANSACTION"."STATUS"='DD') OR
"TRANSACTION"."STATUS"='XX' AND "TRANSACTION"."PDATE">=TRUNC(INTERNAL_FUNCTION("SSC"."LSSTIME"))) AND "TRANSACTION"."DATE_MODIFY"<INTERNAL_FUNCTION("SSC"."CSTIME")-1)
filter("TRANSACTION"."DATE_MODIFY">=TO_DATE(' 2018-12-14 00:00:00', 'syyyy-mm-dd hh24:mi:ss') AND "TRANSACTION"."AMT"<>0 AND (("TRANSACTION"."STATUS"='BB' OR
"TRANSACTION"."STATUS"='CC' OR "TRANSACTION"."STATUS"='AA' OR "TRANSACTION"."STATUS"='EE' OR "TRANSACTION"."STATUS"='DD') OR
"TRANSACTION"."STATUS"='XX' AND "TRANSACTION"."PDATE">=TRUNC(INTERNAL_FUNCTION("SSC"."LSSTIME"))) AND "TRANSACTION"."DATE_MODIFY"<INTERNAL_FUNCTION("SSC"."CSTIME")-1)
Statistics
----------------------------------------------------------
1 recursive calls
0 db block gets
18846090 consistent gets
18753383 physical reads
0 redo size
4781864 bytes sent via SQL*Net to client
533 bytes received via SQL*Net from client
5 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
17090 rows processed