There is a common misconception that Index access is the best access method for query execution. This approach leads to people concentrate on removing Full Table Scans (FTS) from the Query execution plan. I recently worked on a performance tuning issue where I found such scenario. Basically customer was trying to generate report for 3 years and query was running for more then 8 hours without producing any results. We were asked to look into this problem.
Following diagnostic data was collected to diagnose the issue.
1) 10046 trace at level 12
2) Execution plan from V$SQL_PLAN (Database version is 9.2)
3) Explain plan for offending query
From 10046 trace and V$session_wait, I found out query was waiting on “db file sequential read” wait event for table SCOTT_BILL. This indicated that we were reading this table using index rowid’s. Please find below explain plan for the problematic query.
SQL> @?/rdbms/admin/utlxpls.sql
PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost |
------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 161 | 66436 |
| 1 | SORT ORDER BY | | 1 | 161 | 66433 |
|* 2 | FILTER | | | | |
| 3 | NESTED LOOPS | | 1 | 161 | 66424 |
| 4 | NESTED LOOPS | | 1 | 141 | 66421 |
| 5 | NESTED LOOPS | | 1 | 126 | 66419 |
| 6 | NESTED LOOPS | | 391 | 27761 | 65246 |
|* 7 | TABLE ACCESS FULL | SCOTT_PO | 21716 | 254K| 98 |
| 8 | TABLE ACCESS BY INDEX ROWID| SCOTT_POIC | 1 | 59 | 3 |
|* 9 | INDEX RANGE SCAN | SCOTT_POIC_MK3 | 1 | | 2 |
|* 10 | TABLE ACCESS BY INDEX ROWID | SCOTT_BILL | 1 | 55 | 3 |
|* 11 | INDEX RANGE SCAN | SCOTT_BILL_FK7 | 1 | | 2 |
|* 12 | TABLE ACCESS BY INDEX ROWID | SCOTT_CUST | 1 | 15 | 2 |
|* 13 | INDEX RANGE SCAN | SCOTT_CUST_FK1 | 1 | | 1 |
| 14 | TABLE ACCESS BY INDEX ROWID | SCOTT_DSST | 1 | 20 | 3 |
|* 15 | INDEX UNIQUE SCAN | SCOTT_DSST_PK | 1 | | 2 |
| 16 | SORT AGGREGATE | | 1 | 17 | |
| 17 | FIRST ROW | | 1 | 17 | 4 |
|* 18 | INDEX RANGE SCAN (MIN/MAX)| SCOTT_DSST_PK | 166M| | 4 |
| 19 | SORT AGGREGATE | | 1 | 36 | |
|* 20 | INDEX RANGE SCAN | SCOTT_POIC_UK1 | 1 | 36 | 3 |
------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - filter("SYS_ALIAS_5"."POIC_SEQ_NO"= (SELECT /*+ */ MAX("B"."POIC_SEQ_NO")
FROM "MAT"."SCOTT_POIC" "B" WHERE "B"."POIC_PO_SEQ_NO"=:B1 AND "B"."POIC_PO_NO"=:B2
AND "B"."POIC_ITEM_CODE"=:B3 AND "B"."POIC_PITM_SEQ_NO"=:B4 AND
NVL("B"."POIC_RQMT_NO",0)=NVL(:B5,0) AND "B"."POIC_CTRT_TYPE"='BAS'))
7 - filter(NVL("SCOTT_PO"."PO_COMP_CODE",'01')='01')
9 - access("SCOTT_PO"."PO_NO"="SYS_ALIAS_5"."POIC_PO_NO" AND
"SCOTT_PO"."PO_SEQ_NO"="SYS_ALIAS_5"."POIC_PO_SEQ_NO" AND
"SYS_ALIAS_5"."POIC_CTRT_TYPE"='BAS')
filter("SYS_ALIAS_5"."POIC_CTRT_TYPE"='BAS')
10 - filter("SYS_ALIAS_6"."BILL_ASRV_DATE">=TO_DATE('2008-04-01 00:00:00',
'yyyy-mm-dd hh24:mi:ss') AND "SYS_ALIAS_6"."BILL_ASRV_DATE"<=TO_DATE('2008-11-30
23:59:59', 'yyyy-mm-dd hh24:mi:ss') AND NVL("SYS_ALIAS_6"."BILL_COMP_CODE",'01')='01
' AND "SYS_ALIAS_6"."BILL_SRV_TYPE"='S' AND
"SYS_ALIAS_6"."BILL_EXCISE_FORM_SERIES_FLAG" IS NULL AND
NVL("SYS_ALIAS_6"."BILL_EXCISE_FORM_SERIES_FLAG",'X')<>'N' AND
"SYS_ALIAS_6"."BILL_INER_CODE" IS NULL AND
"SYS_ALIAS_6"."BILL_ITEM_CODE"="SYS_ALIAS_5"."POIC_ITEM_CODE" AND
"SYS_ALIAS_6"."BILL_PITM_SEQ_NO"="SYS_ALIAS_5"."POIC_PITM_SEQ_NO")
11 - access("SYS_ALIAS_6"."BILL_PO_NO"="SYS_ALIAS_5"."POIC_PO_NO" AND
"SYS_ALIAS_6"."BILL_PO_SEQ_NO"="SYS_ALIAS_5"."POIC_PO_SEQ_NO")
filter(NVL("SYS_ALIAS_6"."BILL_RQMT_NO",0)=NVL("SYS_ALIAS_5"."POIC_RQMT_NO",0
))
12 - filter(NVL("SCOTT_CUST"."CUST_COMP_CODE",'01')='01' AND
"SCOTT_CUST"."CUST_INER_CODE" IS NULL)
13 - access("SCOTT_CUST"."CUST_SRV_NO"="SYS_ALIAS_6"."BILL_SRV_NO")
15 - access("SYS_ALIAS_6"."BILL_SRV_NO"="C"."DSST_SRV_NO" AND
"C"."DSST_PROC_GROUP"=1 AND "C"."DSST_PROCESS"='PSRV' AND "C"."DSST_SEQ_NO"=
(SELECT /*+ */ MAX("D"."DSST_SEQ_NO") FROM "MAT"."SCOTT_DSST" "D" WHERE
"D"."DSST_PROCESS"='PSRV' AND "D"."DSST_PROC_GROUP"=1 AND "D"."DSST_SRV_NO"=:B1))
18 - access("D"."DSST_SRV_NO"=:B1 AND "D"."DSST_PROC_GROUP"=1 AND
"D"."DSST_PROCESS"='PSRV')
20 - access("B"."POIC_PO_NO"=:B1 AND "B"."POIC_PO_SEQ_NO"=:B2 AND
"B"."POIC_ITEM_CODE"=:B3 AND "B"."POIC_PITM_SEQ_NO"=:B4 AND
"B"."POIC_CTRT_TYPE"='BAS')
filter("B"."POIC_ITEM_CODE"=:B1 AND "B"."POIC_PITM_SEQ_NO"=:B2 AND
NVL("B"."POIC_RQMT_NO",0)=NVL(:B3,0) AND "B"."POIC_CTRT_TYPE"='BAS')
Looking at explain plan (and plan from V$SQL_PLAN) confirmed that we were using index SCOTT_BILL_FK7. Plan shows that CBO estimates only 1 row for this operation. But since we have been on this wait even for close to 8 hours, it was clear that we are accessing more then 1 row.Normally this query was run for small range(date column) and used to complete in 10 mins. e.g Below is explain plan for the same query with 4 day’s range.
SQL> @?/rdbms/admin/utlxpls.sql
PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------------------------
-----------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost |
-----------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 161 | 28876 |
| 1 | SORT ORDER BY | | 1 | 161 | 28873 |
|* 2 | FILTER | | | | |
|* 3 | TABLE ACCESS BY INDEX ROWID | SCOTT_CUST | 1 | 15 | 2 |
| 4 | NESTED LOOPS | | 1 | 161 | 28864 |
| 5 | NESTED LOOPS | | 1 | 146 | 28862 |
| 6 | NESTED LOOPS | | 1 | 134 | 28861 |
| 7 | NESTED LOOPS | | 56 | 4200 | 28581 |
|* 8 | TABLE ACCESS BY INDEX ROWID | SCOTT_BILL | 2123 | 114K| 22212 |
|* 9 | INDEX RANGE SCAN | SCOTT_BILL_MK10 | 26081 | | 85 |
| 10 | TABLE ACCESS BY INDEX ROWID | SCOTT_DSST | 1 | 20 | 3 |
|* 11 | INDEX UNIQUE SCAN | SCOTT_DSST_PK | 1 | | 2 |
| 12 | SORT AGGREGATE | | 1 | 17 | |
| 13 | FIRST ROW | | 1 | 17 | 4 |
|* 14 | INDEX RANGE SCAN (MIN/MAX)| SCOTT_DSST_PK | 166M| | 4 |
|* 15 | TABLE ACCESS BY INDEX ROWID | SCOTT_POIC | 1 | 59 | 5 |
|* 16 | INDEX RANGE SCAN | SCOTT_POIC_MK3 | 1 | | 2 |
|* 17 | TABLE ACCESS BY INDEX ROWID | SCOTT_PO | 1 | 12 | 1 |
|* 18 | INDEX UNIQUE SCAN | SCOTT_PO_PK | 1 | | |
|* 19 | INDEX RANGE SCAN | SCOTT_CUST_FK1 | 1 | | 1 |
| 20 | SORT AGGREGATE | | 1 | 36 | |
|* 21 | INDEX RANGE SCAN | SCOTT_POIC_UK1 | 1 | 36 | 3 |
-----------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - filter("SYS_ALIAS_5"."POIC_SEQ_NO"= (SELECT /*+ */ MAX("B"."POIC_SEQ_NO") FROM
"MAT"."SCOTT_POIC" "B" WHERE "B"."POIC_PO_SEQ_NO"=:B1 AND "B"."POIC_PO_NO"=:B2 AND
"B"."POIC_ITEM_CODE"=:B3 AND "B"."POIC_PITM_SEQ_NO"=:B4 AND
NVL("B"."POIC_RQMT_NO",0)=NVL(:B5,0) AND "B"."POIC_CTRT_TYPE"='BAS'))
3 - filter(NVL("SCOTT_CUST"."CUST_COMP_CODE",'01')='01' AND
"SCOTT_CUST"."CUST_INER_CODE" IS NULL)
8 - filter(NVL("SYS_ALIAS_6"."BILL_COMP_CODE",'01')='01' AND
"SYS_ALIAS_6"."BILL_SRV_TYPE"='S' AND "SYS_ALIAS_6"."BILL_EXCISE_FORM_SERIES_FLAG" IS
NULL AND NVL("SYS_ALIAS_6"."BILL_EXCISE_FORM_SERIES_FLAG",'X')<>'N' AND
"SYS_ALIAS_6"."BILL_INER_CODE" IS NULL)
9 - access("SYS_ALIAS_6"."BILL_ASRV_DATE">=TO_DATE('2008-04-01 00:00:00', 'yyyy-mm-dd
hh24:mi:ss') AND "SYS_ALIAS_6"."BILL_ASRV_DATE"<=TO_DATE('2008-04-05 23:59:59',
'yyyy-mm-dd hh24:mi:ss'))
11 - access("SYS_ALIAS_6"."BILL_SRV_NO"="C"."DSST_SRV_NO" AND "C"."DSST_PROC_GROUP"=1
AND "C"."DSST_PROCESS"='PSRV' AND "C"."DSST_SEQ_NO"= (SELECT /*+ */
MAX("D"."DSST_SEQ_NO") FROM "MAT"."SCOTT_DSST" "D" WHERE "D"."DSST_PROCESS"='PSRV' AND
"D"."DSST_PROC_GROUP"=1 AND "D"."DSST_SRV_NO"=:B1))
14 - access("D"."DSST_SRV_NO"=:B1 AND "D"."DSST_PROC_GROUP"=1 AND
"D"."DSST_PROCESS"='PSRV')
15 - filter("SYS_ALIAS_6"."BILL_PITM_SEQ_NO"="SYS_ALIAS_5"."POIC_PITM_SEQ_NO" AND
NVL("SYS_ALIAS_6"."BILL_RQMT_NO",0)=NVL("SYS_ALIAS_5"."POIC_RQMT_NO",0))
16 - access("SYS_ALIAS_6"."BILL_PO_NO"="SYS_ALIAS_5"."POIC_PO_NO" AND
"SYS_ALIAS_6"."BILL_PO_SEQ_NO"="SYS_ALIAS_5"."POIC_PO_SEQ_NO" AND
"SYS_ALIAS_6"."BILL_ITEM_CODE"="SYS_ALIAS_5"."POIC_ITEM_CODE" AND
"SYS_ALIAS_5"."POIC_CTRT_TYPE"='BAS')
17 - filter(NVL("SCOTT_PO"."PO_COMP_CODE",'01')='01')
18 - access("SCOTT_PO"."PO_NO"="SYS_ALIAS_5"."POIC_PO_NO" AND
"SCOTT_PO"."PO_SEQ_NO"="SYS_ALIAS_5"."POIC_PO_SEQ_NO")
19 - access("SCOTT_CUST"."CUST_SRV_NO"="SYS_ALIAS_6"."BILL_SRV_NO")
21 - access("B"."POIC_PO_NO"=:B1 AND "B"."POIC_PO_SEQ_NO"=:B2 AND
"B"."POIC_ITEM_CODE"=:B3 AND "B"."POIC_PITM_SEQ_NO"=:B4 AND "B"."POIC_CTRT_TYPE"='BAS')
filter("B"."POIC_ITEM_CODE"=:B1 AND "B"."POIC_PITM_SEQ_NO"=:B2 AND
NVL("B"."POIC_RQMT_NO",0)=NVL(:B3,0) AND "B"."POIC_CTRT_TYPE"='BAS')
Note: cpu costing is off
We can see that we used SCOTT_BILL_MK10 index here which was on the date column. This is also clear from predicate information available from explain plan.
9 - access("SYS_ALIAS_6"."BILL_ASRV_DATE">=TO_DATE('2008-04-01 00:00:00', 'yyyy-mm-dd
hh24:mi:ss') AND "SYS_ALIAS_6"."BILL_ASRV_DATE"<=TO_DATE('2008-04-05 23:59:59',
'yyyy-mm-dd hh24:mi:ss'))
Coming back to our case, we see that index SCOTT_BILL_FK7 is being used here.This index is created on BILL_PO_NO, BILL_PO_SEQ_NO and BILL_RQMT_NO columns.
From explain plan, we see that following condition is used due to which we access the index
11 - access("SYS_ALIAS_6"."BILL_PO_NO"="SYS_ALIAS_5"."POIC_PO_NO" AND
"SYS_ALIAS_6"."BILL_PO_SEQ_NO"="SYS_ALIAS_5"."POIC_PO_SEQ_NO")
filter(NVL("SYS_ALIAS_6"."BILL_RQMT_NO",0)=NVL("SYS_ALIAS_5"."POIC_RQMT_NO",0
))
Checking the column values, we see following
COLUMN_NAME NUM_DISTINCT NUM_NULLS ------------------------------ ------------ ---------- BILL_PO_NO 31841 636 BILL_PO_SEQ_NO 4 1296 BILL_RQMT_NO 437 27333280
I believe lot of null records present in the table along with NVL function usage is causing this issue. We can see from above data, that column BILL_RQMT_NO has 27 million null records. As B-Tree index does not index Null columns(B-tree indexes index null columns too if index is a concatenated index and the other column has non-null value. Refer to this article from Richard Foote). CBO assumed that only 1 row will be returned and it choose index SCOTT_BILL_FK7 as best access method. But because of NVL function, this returns more rows instead of just one row. This is my hypothesis and not sure , if its correct 🙂
As a quick fix , I suggested using FULL hint on SCOTT_BILL table so that we can perform a Full table Scan (FTS). This helped and query completed in 28 mins. If we look at long term solution, having a default value of 0 for this column could also be looked at. But all these things need to be decided in consideration with application design.
This is also a reminder to a fact that index access is not always the best access method. It is suitable if we are looking for very small data set and could become problem if data set increases.Whereas Full table Scan (FTS) perform better in such cases as we perform multiblock I/O.
“As B-Tree index does not index Null columns”
Steady on. The index is on “BILL_PO_NO, BILL_PO_SEQ_NO and BILL_RQMT_NO”, so there will be an index entry even when BILL_RQMT_NO is null (except maybe for the 636 with null BILL_PO_NO). Which you can see because the filter condition on the index access 11 on the problem query plan shows the NVL being applied.
Now the table has at least 27 million rows, with 32,000 distinct values for BILL_PO_NO so each BILL_PO_NO has about 850 entries, spread across 4 BILL_PO_SEQ_NO, so may give 200 entries each (though I bet there’s a lot of skew towards sequence no 1).
The NVL clause will go for, I think, a 1% default selectivity so will assume 2 rows returned. [Not sure how it gets that down to 1, unless there’s a lot more than 27 million rows in the table. ] In practice, we can see that with such a high proportion of nulls, we’d get pretty much a 100% selectivity, not 1%.
It would be nice to see the original query for this, and the query plan with the hint.
Gary, thanks for your update. After writing this article , I also came across article from Richard Foote. I have striked out the statement regarding B-Tree indexes and gave a new link.
I cannot share the query with you (have changed table name too). But I believe I can share some information from 10053 trace which I ran for problematic query.
Table stats Table: SCOTT_BILL Alias: SYS_ALIAS_6 TOTAL :: CDN: 27451688 NBLKS: 661386 AVG_ROW_LEN: 158 INDEX NAME: SCOTT_BILL_FK7 COL#: 8 17 9 TOTAL :: LVLS: 2 #LB: 101624 #DK: 21675 LB/K: 4 DB/K: 710 CLUF: 15399740 TABLE: SCOTT_BILL RSC_CPU: 0 RSC_IO: 3 IX_SEL: 7.8961e-06 TB_SEL: 2.4117e-11 Join: resc: 66419 resp: 66419 Access path: index (scan) Join order[9]: SCOTT_PO[SCOTT_PO]#1 SCOTT_POIC[SYS_ALIAS_5]#0 SCOTT_BILL[SYS_ALIAS_6]#2 SCOTT_CUST[SCOTT_CUST]#4 SCOTT_DSST[C]#3 Best so far: TABLE#: 1 CST: 98 CDN: 21716 BYTES: 260592 Best so far: TABLE#: 0 CST: 65246 CDN: 391 BYTES: 27761 Best so far: TABLE#: 2 CST: 66419 CDN: 1 BYTES: 126 Best so far: TABLE#: 4 CST: 66421 CDN: 1 BYTES: 141 Best so far: TABLE#: 3 CST: 66433 CDN: 1 BYTES: 161CBO has estimated cardinality to be 1 row, though I am not sure the way it has been calculated. I believe this is calculated as round(Table_selectivity *num_rows) for SCOTT_BILL table.This comes out to 1.
Yeah, I can see the table cardinality coming down to 1, because there’s a bunch of of criteria.
The cardinality of the index range scan gets me though. Index selectivity and table cardinality turn out to 216.76. But, since only two of the leading columns on the index are being used, maybe it isn’t using index selectivity. I’ll have to re-read my jonathan Lewis over Xmas.
Even I will have to re-read it. I was hoping Jonathan will stumble upon this article and give his opinion 🙂
cheers
Amit
What’s the high value and the low value in the stats for these columns? Is any value in the where clause out of range?
Daniel,
I do not remember these values as I worked on this site long back..But I believe I had checked and statistics were not stale. Note that in my case index SCOTT_BILL_FK7 was being used which did not have any date column. I actually suspected this issue to be caused by null values and use of nvl function.
And also there was “No out of range” messages in the 10053 as observed in my Post DBMS_STATS.COPY_TABLE_STATS does not copy low/high values