ORs, IN lists and LNNVL
April 5, 2013 8 Comments
I’ve previously written about manually rewriting an OR condition into a UNION ALL using LNNVL.
This is a description of a performance issue observed in the real world from the optimizer coming up with a CONCATENATION operation against many child operations including an INLIST operator and other children which then have to use LNNVL as a filter.
Really this is nothing more than an illustration of our old performance killing friend the function call from within SQL, particularly from within predicates, and the problem of context switching.
Ok. So, the real world example is a crazy query.
It contains 1091 OR clauses each stipulating a unique key lookup.
Yes, “1091” OR clauses.
I know, I know.
Probably itself a workaround to avoid the 1000 limit on an IN list, who knows?
Anyway.
I’m going to use a table just to illustrate the execution plan and then use some metrics from the execution of the real world example.
drop table t1; create table t1 (col1 number ,col2 number ,col3 varchar2(10) ,constraint pk_t1 primary key (col1, col2)); insert into t1 select mod(rownum,10000)+1 col1 , ceil(rownum/10000) col2 , rpad('X',10,'X') col3 from dual connect by rownum <= 100000 order by col1, col2; commit;
If we use a simple multi-column OR condition, we don’t get the desired LNNVLs.
explain plan for select * from t1 where (col1 = 1 and col2 = 1) or (col1 = 2 and col2 = 2) or (col1 = 3 and col2 = 3) or (col1 = 3 and col2 = 4); select * from table(dbms_xplan.display);
The optimizer just uses an INLIST iterator:
-------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | -------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1129 | 37257 | 5 (0)| 00:00:01 | | 1 | INLIST ITERATOR | | | | | | | 2 | TABLE ACCESS BY INDEX ROWID| T1 | 1129 | 37257 | 5 (0)| 00:00:01 | |* 3 | INDEX UNIQUE SCAN | PK_T1 | 7 | | 4 (0)| 00:00:01 | -------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 3 - access(("COL1"=1 AND "COL2"=1 OR "COL1"=2 AND "COL2"=2 OR "COL1"=3 AND "COL2"=3 OR "COL1"=3 AND "COL2"=4))
However, if we combine an IN list with some of those ORs:
explain plan for select * from t1 where (col1 = 1 and col2 = 1) or (col1 = 2 and col2 = 2) or (col1 = 3 and col2 IN (3,4)); select * from table(dbms_xplan.display);
Which gives
--------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | --------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1140 | 37620 | 2 (0)| 00:00:01 | | 1 | CONCATENATION | | | | | | | 2 | TABLE ACCESS BY INDEX ROWID | T1 | 11 | 363 | 1 (0)| 00:00:01 | |* 3 | INDEX RANGE SCAN | PK_T1 | 1 | | 2 (0)| 00:00:01 | | 4 | INLIST ITERATOR | | | | | | | 5 | TABLE ACCESS BY INDEX ROWID| T1 | 1129 | 37257 | 1 (0)| 00:00:01 | |* 6 | INDEX UNIQUE SCAN | PK_T1 | 1 | | 3 (0)| 00:00:01 | --------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 3 - access("COL1"=3) filter("COL2"=3 OR "COL2"=4) 6 - access(("COL1"=1 AND "COL2"=1 OR "COL1"=2 AND "COL2"=2)) filter(LNNVL("COL1"=3) OR LNNVL("COL2"=3) AND LNNVL("COL2"=4))
We get the CONCATENATION of the simpler OR conditions which are combined into a single INLIST ITERATOR operations with another child operation which applies LNNVLs in the filter predicate.
Now imagine we have a much larger number of the simpler OR predicates combined with liberal scatterings of such IN clauses throughout our 1091 OR’d predicates.
Perhaps we’d be a bit concerned about the context switching and increased cpu usage?
Looking at my real world example right here… there’s no point me pasting in the thousands of lines.
If I run the real world behemoth:
Client elapsed time 108 seconds
DBMS_XPLAN.DISPLAY_CURSOR tells me it ran in 1.26 seconds:
plan hash value: 4262066066 -------------------------------------------------------------------------------------------------------------------- | Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers | Reads | -------------------------------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | | 1628 |00:00:01.26 | 3352 | 418 | | 1 | CONCATENATION | | 1 | | 1628 |00:00:01.26 | 3352 | 418 | | 2 | INLIST ITERATOR | | 1 | | 966 |00:00:00.94 | 2735 | 389 | | 3 | TABLE ACCESS BY INDEX ROWID| XXXXXXXXXX | 966 | 624 | 966 |00:00:00.94 | 2735 | 389 | |* 4 | INDEX RANGE SCAN | XXXXXXXXXX_UK01 | 966 | 624 | 966 |00:00:00.86 | 1915 | 380 | | 5 | TABLE ACCESS BY INDEX ROWID | XXXXXXXXXX | 1 | 1 | 2 |00:00:00.01 | 4 | 0 | |* 6 | INDEX RANGE SCAN | XXXXXXXXXX_UK01 | 1 | 1 | 2 |00:00:00.01 | 3 | 0 | .... | 253 | TABLE ACCESS BY INDEX ROWID | XXXXXXXXXX | 1 | 2 | 47 |00:00:00.01 | 14 | 1 | |*254 | INDEX RANGE SCAN | XXXXXXXXXX_UK01 | 1 | 2 | 47 |00:00:00.01 | 3 | 1 | -------------------------------------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 4 - access(((("XXXXXXXXXX"."VERSION"=1 AND "XXXXXXXXXX"."ID_XXXXXXXXXX"=1611722) OR ("XXXXXXXXXX"."VERSION"=1 AND "XXXXXXXXXX"."ID_XXXXXXXXXX"=1611795) OR ("XXXXXXXXXX"."VERSION"=1 AND "XXXXXXXXXX"."ID_XXXXXXXXXX"=1611863) OR ("XXXXXXXXXX"."VERSION"=1 AND "XXXXXXXXXX"."ID_XXXXXXXXXX"=1612023) OR ("XXXXXXXXXX"."VERSION"=1 AND ..... 6 - access "XXXXXXXXXX"."ID_XXXXXXXXXX"=2046939) filter(((LNNVL("XXXXXXXXXX"."VERSION"=1) OR LNNVL("XXXXXXXXXX"."ID_XXXXXXXXXX"=1611722)) AND (LNNVL("XXXXXXXXXX"."VERSION"=1) OR LNNVL("XXXXXXXXXX"."ID_XXXXXXXXXX"=1611795)) AND (LNNVL("XXXXXXXXXX"."VERSION"=1) OR LNNVL("XXXXXXXXXX"."ID_XXXXXXXXXX"=1611863)) AND .....
DBMS_MONITOR tells me the query ran in 1.68 seconds:
Global Information Status : DONE (ALL ROWS) Instance ID : 2 Session ID : 1220 SQL ID : 5fvt3tfbgmqp3 SQL Execution ID : 33554432 Plan Hash Value : 4262066066 Execution Started : 04/05/2013 14:53:42 First Refresh Time : 04/05/2013 14:53:42 Last Refresh Time : 04/05/2013 14:53:45 -------------------------------------------------------------------- | Elapsed | Cpu | IO | Cluster | Fetch | Buffer | Reads | | Time(s) | Time(s) | Waits(s) | Waits(s) | Calls | Gets | | -------------------------------------------------------------------- | 1.68 | 0.50 | 1.13 | 0.05 | 4 | 3352 | 418 | --------------------------------------------------------------------
Fortunately V$SQL tells me the real story:
select sql_id, executions, rows_processed, elapsed_time/1000/1000, cpu_time/1000/1000 from v$sql where sql_id = '5fvt3tfbgmqp3';
Gives
SQL_ID EXECUTIONS ROWS_PROCESSED ELAPSED_TIME/1000/1000 CPU_TIME/1000/1000 ------------- ---------- -------------- ---------------------- ------------------ 5fvt3tfbgmqp3 1 1628 105.81511 104.581102
Then again, if you write nasty code, nasty things can happen.
Dom,
Given the apparent contradiction between the execution times reported by v$sql_monitor and V$sql, I’d be inclined to suspect that most of the time is about the parse time for the query, not about execution time and function calls. Is this something you checked ?
I’ll dig out the statement and double check.
Thinking about it, I thought I got the same performance from repeated executions… But can’t now be sure.
Jonathan,
Spot on.
Sloppy initial analysis…
Thanks.
Cheers,
Dominic
Dominic,
Thanks for the follow-up.
I was struggling to figure out how the execution could take so long – now I’m struggling to figure out how the optimisation could take so long ;(
I may have to write a program to create a dataset and (more importantly) a query that’s insane enough to emulate your monster.
This was the problem I had with my initial “demo” – I struggled to create a test case away from the application that had the same impact (now known to be parsing).
If you want to take it further, would it help if I emailed the original query or anything else?
Dominic,
I built an approximate model based on reverse engineering your execution plan before I saw the offer. I’ll try to find time to wrap it in a little text and post it later on tonight.
I had a similar example today. Was in hard parse for hours. Couldn’t receive alter session kill message. Had to be killed from OS.
Pingback: Parse Time | Oracle Scratchpad