Flip Flop Hooray, Ho
June 19, 2012 Leave a comment
(Title reference for any old skool hip hop fans?)
An investigation into a flip flopping sql statement – the downside of dynamic sampling – why it can be a problem for fast changing tables and frequently executed SQL.
Yesterday morning a sql statement which processes outstanding messages was having performance problems.
There were two child cursors being executed by the four concurrent sessions, depending on their optimizer settings.
I’m not going to detail the optimzer environment differences because it’s mainly irrelvant other than, because of the child cursors, there was a hard parse at time T0 and a hard parse at time T1 and then these cursors were executed repeatedly / regularly over a number of hours.
SQL statistics show this:
SQL> select to_char(sn.end_interval_time,'DD/MM/YYYY HH24:MI') dt
2 , st.plan_hash_value plan_hash
3 , rows_processed_delta rws
4 , executions_delta execs
5 , elapsed_time_delta elp
6 , cpu_time_delta cpu
7 , buffer_gets_delta gets
8 , iowait_delta io
9 from dba_hist_snapshot sn
10 , dba_hist_sqlstat st
11 where st.snap_id = sn.snap_id
12 and st.sql_id = '1s1vgw24g2u1k'
13 and st.elapsed_time_delta > 0
14 and sn.end_interval_time between to_timestamp('18/06/2012 09:00','DD/MM/YYYY HH24:MI')
15 and to_timestamp('18/06/2012 10:00','DD/MM/YYYY HH24:MI')
16 order by sn.snap_id, st.plan_hash_value;
DT PLAN_HASH RWS EXECS ELP CPU GETS IO
---------------- ---------- ---------- ---------- ---------- ---------- ---------- ----------
18/06/2012 09:00 1081606725 1525 182 2163175676 101353586 3938349 2062115102
18/06/2012 09:00 3791039348 48 299 449781 380944 71472 68103
18/06/2012 09:30 1081606725 2032 24 3019992733 146890665 12995474 2886335201
18/06/2012 09:30 3791039348 43 289 73670959 73468837 56740610 24170
SQL>
Whereas this is representative of “normal”:
DT PLAN_HASH RWS EXECS ELP CPU GETS IO ---------------- ---------- ---------- ---------- ---------- ---------- ---------- ---------- 15/06/2012 09:00 3791039348 1289 1077 174434637 16030542 5470115 280865 SQL>
I mentioned that this code was processing outstanding messages.
These different processes aren’t balanced and aren’t expected to be.
But plan hash 3791039348 is good for everyone and in general plan hash 1081606725 suits no-one.
Here’s the sanitised SQL – remember this isn’t so much a SQL tuning/rewriting exercise so much as a root cause of slowness exercise (where the root cause is not initially meant to be “because the SQL is not brilliant”)
SELECT ....
FROM cmsg,
sint,
setm,
comp,
trga,
seti,
trad,
(SELECT COUNT(*) count,
setm_il.sett_mesg_tag sett_mesg_tag
FROM prco prco_il,
cmsg cmsg_il,
setm setm_il,
seti seti_il
WHERE cmsg_il.unacknowledged = prco_il.unack_code
AND cmsg_il.evnt_type = 'SI'
AND (cmsg_il.evnt_tag = seti_il.sett_istr_tag
OR cmsg_il.evnt_tag = seti_il.amending_si_tag)
AND setm_il.sett_istr_tag = seti_il.sett_istr_tag
GROUP BY setm_il.sett_mesg_tag) cmsg_si
WHERE cmsg.rowid IN (SELECT row_id
FROM (SELECT rowid row_id
FROM cmsg cmsg2
WHERE unacknowledged = :p_unack_code
AND evnt_type != 'SOD'
ORDER BY seq_num)
WHERE rownum <= :p_batch_lim)
AND sint.sint_tag (+) = cmsg.evnt_tag
AND sint.stus_ind (+) = 'C'
AND setm.sett_mesg_tag (+) = sint.sett_mesg_tag
AND comp.cmpy_num (+) = setm.cmpy_num
AND trga.trga_code (+) = comp.trga_code
AND seti.sett_istr_tag (+) = setm.sett_istr_tag
AND trad.trad_tag (+) = seti.trad_tag
AND trad.cmpy_num (+) = seti.cmpy_num
AND cmsg_si.sett_mesg_tag (+) = sint.sett_mesg_tag
ORDER by cmsg.seq_num;
Here is the relevant sections of the two execution plans:
The good:
SQL_ID 1s1vgw24g2u1k Plan hash value: 3791039348 ------------------------------------------------------------------------------------------------ | Id | Operation | Name | Rows | Cost | Time | ------------------------------------------------------------------------------------------------ | 0 | SELECT STATEMENT | | | 9192 | | | 1 | FOR UPDATE | | | | | | 2 | SORT ORDER BY | | 1 | 9192 | 00:46 | | 3 | NESTED LOOPS OUTER | | 1 | 9191 | 00:46 | | 4 | NESTED LOOPS OUTER | | 1 | 9190 | 00:46 | | 5 | NESTED LOOPS OUTER | | 1 | 9188 | 00:46 | | 6 | NESTED LOOPS OUTER | | 1 | 9187 | 00:46 | | 7 | NESTED LOOPS OUTER | | 1 | 9186 | 00:46 | | 8 | HASH JOIN OUTER | | 1 | 9184 | 00:46 | | 9 | NESTED LOOPS OUTER | | 1 | 10 | 00:01 | | 10 | NESTED LOOPS | | 1 | 7 | 00:01 | | 11 | VIEW | VW_NSO_1 | 3 | 5 | 00:01 | | 12 | SORT UNIQUE | | 1 | | | | 13 | COUNT STOPKEY | | | | | | 14 | VIEW | | 3 | 5 | 00:01 | | 15 | SORT ORDER BY STOPKEY | | 3 | 5 | 00:01 | | 16 | TABLE ACCESS BY INDEX ROWID | CMSG | 3 | 4 | 00:01 | | 17 | INDEX RANGE SCAN | CMSG3_IDX | 4 | 3 | 00:01 | | 18 | TABLE ACCESS BY USER ROWID | CMSG | 1 | 1 | 00:01 | | 19 | TABLE ACCESS BY INDEX ROWID | SETI | 1 | 3 | 00:01 | | 20 | INDEX RANGE SCAN | SETI_1 | 1 | 2 | 00:01 | | 21 | VIEW | | 14490 | 9173 | 00:46 | | 22 | SORT GROUP BY | | 14490 | | | | 23 | CONCATENATION | | | | | | 24 | NESTED LOOPS | | | | | | 25 | NESTED LOOPS | | 562 | 8472 | 00:43 | | 26 | NESTED LOOPS | | 428 | 6757 | 00:34 | | 27 | NESTED LOOPS | | 304 | 30 | 00:01 | | 28 | TABLE ACCESS BY INDEX ROWID | CMSG | 304 | 30 | 00:01 | | 29 | INDEX FULL SCAN | CMSG4_IDX | 1 | 29 | 00:01 | | 30 | INDEX UNIQUE SCAN | PRCO_2_IDX | 1 | 0 | | | 31 | PARTITION LIST ALL | | 1 | 24 | 00:01 | | 32 | TABLE ACCESS BY LOCAL INDEX ROWID | SETI | 1 | 24 | 00:01 | | 33 | INDEX RANGE SCAN | SETI_3_IDX | 36 | 22 | 00:01 | | 34 | INDEX RANGE SCAN | SETM_2_IDX | 1 | 2 | 00:01 | | 35 | TABLE ACCESS BY INDEX ROWID | SETM | 1 | 4 | 00:01 | | 36 | NESTED LOOPS | | | | | | 37 | NESTED LOOPS | | 20 | 700 | 00:04 | | 38 | NESTED LOOPS | | 15 | 640 | 00:04 | | 39 | NESTED LOOPS | | 15 | 640 | 00:04 | | 40 | TABLE ACCESS BY INDEX ROWID | CMSG | 304 | 30 | 00:01 | | 41 | INDEX FULL SCAN | CMSG4_IDX | 1 | 29 | 00:01 | | 42 | TABLE ACCESS BY GLOBAL INDEX ROWID| SETI | 1 | 2 | 00:01 | | 43 | INDEX UNIQUE SCAN | SETI_IDX | 1 | 1 | 00:01 | | 44 | INDEX UNIQUE SCAN | PRCO_2_IDX | 1 | 0 | | | 45 | INDEX RANGE SCAN | SETM_2_IDX | 1 | 2 | 00:01 | | 46 | TABLE ACCESS BY INDEX ROWID | SETM | 1 | 4 | 00:01 | | 47 | TABLE ACCESS BY INDEX ROWID | SETM | 1 | 2 | 00:01 | | 48 | INDEX UNIQUE SCAN | SETM_IDX | 1 | 1 | 00:01 | | 49 | TABLE ACCESS BY INDEX ROWID | COMP | 1 | 1 | 00:01 | | 50 | INDEX UNIQUE SCAN | COMP_PK | 1 | 0 | | | 51 | TABLE ACCESS BY INDEX ROWID | TRGA | 1 | 1 | 00:01 | | 52 | INDEX UNIQUE SCAN | TRGA_IDX | 1 | 0 | | | 53 | TABLE ACCESS BY GLOBAL INDEX ROWID | SETI | 1 | 2 | 00:01 | | 54 | INDEX UNIQUE SCAN | SETI_IDX | 1 | 1 | 00:01 | | 55 | PARTITION LIST ITERATOR | | 1 | 1 | 00:01 | | 56 | INDEX UNIQUE SCAN | TRAD_IDX | 1 | 1 | 00:01 | ------------------------------------------------------------------------------------------------
And the downright bad and ugly:
SQL_ID 1s1vgw24g2u1k Plan hash value: 1081606725 ------------------------------------------------------------------------------------------------ | Id | Operation | Name | Rows | Cost | Time | ------------------------------------------------------------------------------------------------ | 0 | SELECT STATEMENT | | | 436K| | | 1 | FOR UPDATE | | | | | | 2 | SORT ORDER BY | | 1 | 436K| 36:24 | | 3 | NESTED LOOPS OUTER | | 1 | 436K| 36:24 | | 4 | NESTED LOOPS OUTER | | 1 | 436K| 36:24 | | 5 | NESTED LOOPS OUTER | | 1 | 436K| 36:23 | | 6 | NESTED LOOPS OUTER | | 1 | 436K| 36:23 | | 7 | NESTED LOOPS OUTER | | 1 | 436K| 36:23 | | 8 | HASH JOIN OUTER | | 1 | 436K| 36:23 | | 9 | NESTED LOOPS OUTER | | 1 | 10 | 00:01 | | 10 | NESTED LOOPS | | 1 | 7 | 00:01 | | 11 | VIEW | VW_NSO_1 | 2 | 5 | 00:01 | | 12 | SORT UNIQUE | | 1 | | | | 13 | COUNT STOPKEY | | | | | | 14 | VIEW | | 2 | 5 | 00:01 | | 15 | SORT ORDER BY STOPKEY | | 2 | 5 | 00:01 | | 16 | TABLE ACCESS BY INDEX ROWID | CMSG | 2 | 4 | 00:01 | | 17 | INDEX RANGE SCAN | CMSG3_IDX | 2 | 3 | 00:01 | | 18 | TABLE ACCESS BY USER ROWID | CMSG | 1 | 1 | 00:01 | | 19 | TABLE ACCESS BY INDEX ROWID | SETI | 1 | 3 | 00:01 | | 20 | INDEX RANGE SCAN | SETI_1 | 1 | 2 | 00:01 | | 21 | VIEW | | 719K| 436K| 36:23 | | 22 | SORT GROUP BY | | 719K| | | | 23 | CONCATENATION | | | | | | 24 | NESTED LOOPS | | | | | | 25 | NESTED LOOPS | | 27212 | 403K| 33:40 | | 26 | HASH JOIN | | 20520 | 301K| 25:06 | | 27 | HASH JOIN | | 14473 | 35 | 00:01 | | 28 | INDEX FULL SCAN | PRCO_2_IDX | 502 | 1 | 00:01 | | 29 | TABLE ACCESS BY INDEX ROWID | CMSG | 14473 | 33 | 00:01 | | 30 | INDEX FULL SCAN | CMSG4_IDX | 1 | 32 | 00:01 | | 31 | PARTITION LIST ALL | | 30M| 300K| 25:02 | | 32 | TABLE ACCESS FULL | SETI | 30M| 300K| 25:02 | | 33 | INDEX RANGE SCAN | SETM_2_IDX | 1 | 3 | 00:01 | | 34 | TABLE ACCESS BY INDEX ROWID | SETM | 1 | 5 | 00:01 | | 35 | NESTED LOOPS | | | | | | 36 | NESTED LOOPS | | 960 | 32673 | 02:44 | | 37 | NESTED LOOPS | | 724 | 29046 | 02:26 | | 38 | NESTED LOOPS | | 724 | 29045 | 02:26 | | 39 | TABLE ACCESS BY INDEX ROWID | CMSG | 14473 | 33 | 00:01 | | 40 | INDEX FULL SCAN | CMSG4_IDX | 1 | 32 | 00:01 | | 41 | TABLE ACCESS BY GLOBAL INDEX ROWID| SETI | 1 | 2 | 00:01 | | 42 | INDEX UNIQUE SCAN | SETI_IDX | 1 | 1 | 00:01 | | 43 | INDEX UNIQUE SCAN | PRCO_2_IDX | 1 | 0 | | | 44 | INDEX RANGE SCAN | SETM_2_IDX | 1 | 3 | 00:01 | | 45 | TABLE ACCESS BY INDEX ROWID | SETM | 1 | 5 | 00:01 | | 46 | TABLE ACCESS BY INDEX ROWID | SETM | 1 | 2 | 00:01 | | 47 | INDEX UNIQUE SCAN | SETM_IDX | 1 | 1 | 00:01 | | 48 | TABLE ACCESS BY INDEX ROWID | COMP | 1 | 2 | 00:01 | | 49 | INDEX UNIQUE SCAN | COMP_PK | 1 | 1 | 00:01 | | 50 | TABLE ACCESS BY INDEX ROWID | TRGA | 1 | 1 | 00:01 | | 51 | INDEX UNIQUE SCAN | TRGA_IDX | 1 | 0 | | | 52 | TABLE ACCESS BY GLOBAL INDEX ROWID | SETI | 1 | 2 | 00:01 | | 53 | INDEX UNIQUE SCAN | SETI_IDX | 1 | 1 | 00:01 | | 54 | PARTITION LIST ITERATOR | | 1 | 1 | 00:01 | | 55 | INDEX UNIQUE SCAN | TRAD_IDX | 1 | 1 | 00:01 | ------------------------------------------------------------------------------------------------ Note ----- - dynamic sampling used for this statement (level=4)
The trouble with specific examples is that sometimes they’re a bit longer than ideal (as well as being a bit out of context).
Let me highlight what I see as the problem:
- There is a non-merged view with an OR (which is expanded to a CONCATENATION)
- In the good plan, @ line 33, one part of the OR condition is dealt with via an INDEX RANGE SCAN on SETI_3_IDX.
- In the bad plan, @ line 32, this is a TABLE ACCESS FULL on SETI.
- There’s a dynamic sampling note in the bad plan
Good:
| 21 | VIEW | | 14490 | 9173 (1)| 00:00:46 | ... | 26 | NESTED LOOPS | | 428 | 6757 (1)| 00:00:34 | | 27 | NESTED LOOPS | | 304 | 30 (0)| 00:00:01 | | 28 | TABLE ACCESS BY INDEX ROWID | CMSG | 304 | 30 (0)| 00:00:01 | | 29 | INDEX FULL SCAN | CMSG4_IDX | 1 | 29 (0)| 00:00:01 | | 30 | INDEX UNIQUE SCAN | PRCO_2_IDX | 1 | 0 (0)| | | 31 | PARTITION LIST ALL | | 1 | 24 (0)| 00:00:01 | | 32 | TABLE ACCESS BY LOCAL INDEX ROWID | SETI | 1 | 24 (0)| 00:00:01 | | 33 | INDEX RANGE SCAN | SETI_3_IDX | 36 | 22 (0)| 00:00:01 | ...
Bad:
| 21 | VIEW | | 719K| 436K (3)| 00:36:23 | ... | 26 | HASH JOIN | | 20520 | 301K (4)| 00:25:06 | | 27 | HASH JOIN | | 14473 | 35 (3)| 00:00:01 | | 28 | INDEX FULL SCAN | PRCO_2_IDX | 502 | 1 (0)| 00:00:01 | | 29 | TABLE ACCESS BY INDEX ROWID | CMSG | 14473 | 33 (0)| 00:00:01 | | 30 | INDEX FULL SCAN | CMSG4_IDX | 1 | 32 (0)| 00:00:01 | | 31 | PARTITION LIST ALL | | 30M| 300K (4)| 00:25:02 | | 32 | TABLE ACCESS FULL | SETI | 30M| 300K (4)| 00:25:02 | ... Note ----- - dynamic sampling used for this statement (level=4)
It’s always nice to simplify a situation and because the problem seems to be in this non-merged view, we can actually eliminate half the sql and then see if we can just reproduce the problem by adjusting the estimates.
Which we can, and via trial and error, we see that as we approach an estimate of 14000 rows from CMSG, the plan changes to the FULL TABLE SCAN of SETI:
SQL> explain plan for
2 SELECT /*+
3 opt_estimate(table cmsg_il rows=14000)
4 */
5 COUNT(*) count,
6 setm_il.sett_mesg_tag sett_mesg_tag
7 FROM prco prco_il,
8 cmsg cmsg_il,
9 setm setm_il,
10 seti seti_il
11 WHERE cmsg_il.unacknowledged = prco_il.unack_code
12 AND cmsg_il.evnt_type = 'SI'
13 AND (cmsg_il.evnt_tag = seti_il.sett_istr_tag OR
14 cmsg_il.evnt_tag = seti_il.amending_si_tag)
15 AND setm_il.sett_istr_tag = seti_il.sett_istr_tag
16 GROUP BY setm_il.sett_mesg_tag;
Explained.
SQL> select * from table(dbms_xplan.display);
Plan hash value: 273475595
-----------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Cost (%CPU)| Time |
-----------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 695K| 432K (3)| 00:36:01 |
| 1 | HASH GROUP BY | | 695K| | |
| 2 | CONCATENATION | | | | |
| 3 | NESTED LOOPS | | | | |
| 4 | NESTED LOOPS | | 26323 | 400K (3)| 00:33:23 |
|* 5 | HASH JOIN | | 19850 | 301K (4)| 00:25:06 |
|* 6 | HASH JOIN | | 14000 | 35 (3)| 00:00:01 |
| 7 | INDEX FULL SCAN | PRCO_2_IDX | 502 | 1 (0)| 00:00:01 |
|* 8 | TABLE ACCESS BY INDEX ROWID | CMSG | 14000 | 33 (0)| 00:00:01 |
|* 9 | INDEX FULL SCAN | CMSG4_IDX | 1 | 32 (0)| 00:00:01 |
| 10 | PARTITION LIST ALL | | 30M| 300K (4)| 00:25:02 |
| 11 | TABLE ACCESS FULL | SETI | 30M| 300K (4)| 00:25:02 |
|* 12 | INDEX RANGE SCAN | SETM_2_IDX | 1 | 3 (0)| 00:00:01 |
| 13 | TABLE ACCESS BY INDEX ROWID | SETM | 1 | 5 (0)| 00:00:01 |
| 14 | NESTED LOOPS | | | | |
| 15 | NESTED LOOPS | | 928 | 31605 (1)| 00:02:39 |
| 16 | NESTED LOOPS | | 700 | 28097 (1)| 00:02:21 |
| 17 | NESTED LOOPS | | 700 | 28097 (1)| 00:02:21 |
|* 18 | TABLE ACCESS BY INDEX ROWID | CMSG | 14000 | 33 (0)| 00:00:01 |
|* 19 | INDEX FULL SCAN | CMSG4_IDX | 1 | 32 (0)| 00:00:01 |
|* 20 | TABLE ACCESS BY GLOBAL INDEX ROWID| SETI | 1 | 2 (0)| 00:00:01 |
|* 21 | INDEX UNIQUE SCAN | SETI_IDX | 1 | 1 (0)| 00:00:01 |
|* 22 | INDEX UNIQUE SCAN | PRCO_2_IDX | 1 | 0 (0)| 00:00:01 |
|* 23 | INDEX RANGE SCAN | SETM_2_IDX | 1 | 3 (0)| 00:00:01 |
| 24 | TABLE ACCESS BY INDEX ROWID | SETM | 1 | 5 (0)| 00:00:01 |
-----------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
5 - access("CMSG_IL"."EVNT_TAG"="SETI_IL"."AMENDING_SI_TAG")
6 - access("CMSG_IL"."UNACKNOWLEDGED"="PRCO_IL"."UNACK_CODE")
8 - filter("CMSG_IL"."EVNT_TYPE"='SI')
9 - filter("CMSG_IL"."UNACKNOWLEDGED" IS NOT NULL)
12 - access("SETM_IL"."SETT_ISTR_TAG"="SETI_IL"."SETT_ISTR_TAG")
18 - filter("CMSG_IL"."EVNT_TYPE"='SI')
19 - filter("CMSG_IL"."UNACKNOWLEDGED" IS NOT NULL)
20 - filter(LNNVL("CMSG_IL"."EVNT_TAG"="SETI_IL"."AMENDING_SI_TAG"))
21 - access("CMSG_IL"."EVNT_TAG"="SETI_IL"."SETT_ISTR_TAG")
22 - access("CMSG_IL"."UNACKNOWLEDGED"="PRCO_IL"."UNACK_CODE")
23 - access("SETM_IL"."SETT_ISTR_TAG"="SETI_IL"."SETT_ISTR_TAG")
46 rows selected.
SQL>
So, optimizer environment differences and bind variable peeking are pretty much ruled out as influencing factors.
What remains is that the bad plan has a higher estimate of rows than the good plan and the bad plan has dynamic sampling.
Both SQL statements are the same.
Dynamic sampling level is the same for both (4 set at system level).
Dynamic sampling should be being applied because of the parameter setting and because there are two single table access predicates
– one from the predicate on CMSG_IL.EVENT_TYPE and one implicit IS NOT NULL predicate on the join column UNACKNOWLEDGED.
So why would we see DS in one plan and not anohther?
If we do a 10053 trace of the distilled non-mergeable view, we see:
Access path analysis for CMSG
***************************************
SINGLE TABLE ACCESS PATH
Single Table Cardinality Estimation for CMSG[CMSG_IL]
*** 2012-06-19 14:32:04.576
** Performing dynamic sampling initial checks. **
Column (#4):
NewDensity:0.000062, OldDensity:0.000000 BktCnt:8090, PopBktCnt:8084, PopValCnt:46, NDV:80
Column (#4): EVNT_TYPE(
AvgLen: 4 NDV: 80 Nulls: 0 Density: 0.000062
Histogram: Freq #Bkts: 52 UncompBkts: 8090 EndPtVals: 52
** Dynamic sampling initial checks returning TRUE (level = 4).
*** 2012-06-19 14:32:04.576
** Generated dynamic sampling query:
query text :
SELECT /* OPT_DYN_SAMP */
/*+
ALL_ROWS
IGNORE_WHERE_CLAUSE
NO_PARALLEL(SAMPLESUB)
opt_param('parallel_execution_enabled', 'false')
NO_PARALLEL_INDEX(SAMPLESUB)
NO_SQL_TUNE
*/
NVL(SUM(C1),0),
NVL(SUM(C2),0)
FROM (SELECT /*+
IGNORE_WHERE_CLAUSE NO_PARALLEL("CMSG_IL")
FULL("CMSG_IL")
NO_PARALLEL_INDEX("CMSG_IL")
*/
1 AS C1,
CASE WHEN "CMSG_IL"."EVNT_TYPE"=:B1
AND "CMSG_IL"."UNACKNOWLEDGED" IS NOT NULL
THEN 1
ELSE 0
END AS C2
FROM "CMSG" SAMPLE BLOCK (0.002711 , 1) SEED (1) "CMSG_IL") SAMPLESUB
*** 2012-06-19 14:32:04.612
** Executed dynamic sampling query:
level : 4
sample pct. : 0.002711
actual sample size : 1756
filtered sample card. : 0
orig. card. : 75899119
block cnt. table stat. : 1118909
block cnt. for sampling: 1143461
max. sample block cnt. : 32
sample block cnt. : 31
min. sel. est. : 0.00000001
** Not using dynamic sampling for single table sel. or cardinality.
So, the results of dynamic sampling are discarded as unreliable and the estimates fall back on using the stored object stats.
But at some point (one of the hard parses) the data returned in the sample must have found some relevant data and been considered reliable which led to the “bad” plan being executed repeatedly in inappropriate circumstances.
Two footnotes to this investigation.
Firstly, when you have tables with fast-changing data and row counts, there are usually two choices in approach for statistics
– either find a set of stats that gives the best (balance of) plans and lock them.
– or use dynamic sampling
The scenario above shows the downside of the dynamic sampling approach.
It may well be that the plan hash 1081606725 was good for the initial execution(s) of the statement when there maybe were a large number of outstanding messages but it very quickly became unsuitable given the frequent executions.
Secondly, I mentioned that this was not a SQL rewriting exercise, but, if it was, I’m not a great fan of the outer-joined inline view. It’s not merged but it seems sensible that a predicate be pushed into view.
Pushing the predicate, whether happening by default or hinted explicitly, would give a subsection of the plan like:
| 20 | VIEW PUSHED PREDICATE | | 1 | 38 (0)| 00:00:01 | | 21 | SORT GROUP BY | | 1 | 38 (0)| 00:00:01 | | 22 | NESTED LOOPS | | 1 | 38 (0)| 00:00:01 | | 23 | NESTED LOOPS | | 1 | 38 (0)| 00:00:01 | | 24 | NESTED LOOPS | | 1 | 5 (0)| 00:00:01 | | 25 | TABLE ACCESS BY INDEX ROWID | SETM | 1 | 3 (0)| 00:00:01 | |* 26 | INDEX UNIQUE SCAN | SETM_IDX | 1 | 2 (0)| 00:00:01 | | 27 | TABLE ACCESS BY GLOBAL INDEX ROWID| SETI | 30M| 2 (0)| 00:00:01 | |* 28 | INDEX UNIQUE SCAN | SETI_IDX | 1 | 1 (0)| 00:00:01 | |* 29 | TABLE ACCESS BY INDEX ROWID | CMSG | 1 | 33 (0)| 00:00:01 | |* 30 | INDEX FULL SCAN | CMSG_IDX | 1 | 32 (0)| 00:00:01 | |* 31 | INDEX UNIQUE SCAN | PRCO_2_IDX | 1 | 0 (0)| 00:00:01 |
However, I’m not keen on explicitly hinting this nor leaving it to chance and as it’s outer joined, I would strongly consider using a scalar subselect:
WITH cmsg AS
(SELECT *
FROM (SELECT cmsg.evnt_tag,
cmsg.evnt_type,
cmsg.seq_num
FROM cmsg
WHERE unacknowledged = :p_unack_code
AND evnt_type != 'SOD'
ORDER BY seq_num)
WHERE rownum <= :p_batch_lim)
SELECT ...,
(SELECT COUNT(*)
FROM proc prco_il,
cmsg cmsg_il,
setm setm_il,
seti seti_il
WHERE cmsg_il.unacknowledged = prco_il.unack_code
AND cmsg_il.evnt_type = 'SI'
AND (cmsg_il.evnt_tag = seti_il.sett_istr_tag
OR cmsg_il.evnt_tag = seti_il.amending_si_tag)
AND setm_il.sett_istr_tag = seti_il.sett_istr_tag
AND setm_il.sett_mesg_tag = sint.sett_mesg_tag) count
FROM cmsg,
sint,
setm,
comp,
trga,
seti,
trad
WHERE sint.sint_tag (+) = cmsg.evnt_tag
AND sint.stus_ind (+) = 'C'
AND setm.sett_mesg_tag (+) = sint.sett_mesg_tag
AND comp.cmpy_num (+) = setm.cmpy_num
AND trga.trga_code (+) = comp.trga_code
AND seti.sett_istr_tag (+) = setm.sett_istr_tag
AND trad.trad_tag (+) = seti.trad_tag
AND trad.cmpy_num (+) = seti.cmpy_num
ORDER by cmsg.seq_num;
Recent Comments