I have a bit of an unexplainable situation.
We have a procedure which executes a query and it consistently chooses the worst index. When I execute it in SQL*Plus or SQL Developer it chooses the correct index. The only way I can get it to work fast in the procedure is to add hints.
The statistics are up to date no change in optimizer parameters. I ran a trace and I see in the trace it uses "ALL_ROWS" as that is the database parameter anyway. The explain plan in the trace show it uses the wrong index which is least selective.
SELECT EA.EVAS_ID EVASID, EA.EV_ID EVID, EA.CEVT_ID CEVID, EA.EV_ID_SOURCE
EVSOURCEID, EA.CEVT_ID_SOURCE CEVTSOURCEID, EV.EVENT_START_DATETIME
STARTDATE
FROM
MR_EVENTS EV, MR_EVENT_ASSOCIATIONS EA WHERE EV.EPI_ID = :B2 AND EV.ET_ID =
:B1 AND EV.EV_ID = EA.EV_ID UNION ALL SELECT EA.EVAS_ID EVASID, EA.EV_ID
EVID, EA.CEVT_ID CEVID, EA.EV_ID_SOURCE EVSOURCEID, EA.CEVT_ID_SOURCE
CEVTSOURCEID, CE.SENT_DATETIME STARTDATE FROM MR_CONTACT_EVENTS CE,
MR_EVENT_ASSOCIATIONS EA WHERE CE.EPI_ID = :B2 AND CE.ET_ID = :B1 AND
CE.CEVT_ID = EA.CEVT_ID UNION ALL SELECT NULL, NULL, CE2.CEVT_ID CEVID,
CE2.EV_ID_SOURCE EVSOURCEID, CE2.CEVT_ID_SOURCE CEVTSOURCEID,
CE2.SENT_DATETIME STARTDATE FROM MR_CONTACT_EVENTS CE2 WHERE CE2.EPI_ID =
:B2 AND CE2.ET_ID = :B1 AND NOT EXISTS ( SELECT 1 FROM
MR_EVENT_ASSOCIATIONS EA WHERE CE2.CEVT_ID = EA.CEVT_ID)
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 3 0.01 0.01 0 0 0 0
Execute 16 0.07 0.07 0 0 0 0
Fetch 16 236.32 253.81 1130634 2344502 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 35 236.41 253.90 1130634 2344502 0 0
Misses in library cache during parse: 2
Optimizer mode: ALL_ROWS
Parsing user id: 240 (recursive depth: 1)
Number of plan statistics captured: 3
Rows (1st) Rows (avg) Rows (max) Row Source Operation
---------- ---------- ---------- ---------------------------------------------------
0 0 0 UNION-ALL (cr=384508 pr=172552 pw=0 time=45178066 us starts=1)
0 0 0 NESTED LOOPS (cr=3 pr=1 pw=0 time=1442 us starts=1 cost=7 size=45 card=1)
0 0 0 NESTED LOOPS (cr=3 pr=1 pw=0 time=1436 us starts=1 cost=7 size=45 card=1)
0 0 0 TABLE ACCESS BY INDEX ROWID BATCHED MR_EVENTS (cr=3 pr=1 pw=0 time=1433 us starts=1 cost=4 size=23 card=1)
0 0 0 INDEX RANGE SCAN MR_EV_I5 (cr=3 pr=1 pw=0 time=1428 us starts=1 cost=3 size=0 card=1)(object id 40477)
0 0 0 INDEX RANGE SCAN MR_EVAS_EV_FK_I (cr=0 pr=0 pw=0 time=0 us starts=0 cost=2 size=0 card=1)(object id 40487)
0 0 0 TABLE ACCESS BY INDEX ROWID MR_EVENT_ASSOCIATIONS (cr=0 pr=0 pw=0 time=0 us starts=0 cost=3 size=22 card=1)
0 0 0 NESTED LOOPS (cr=192252 pr=86276 pw=0 time=29596732 us starts=1 cost=7 size=45 card=1)
0 0 0 NESTED LOOPS (cr=192252 pr=86276 pw=0 time=29596728 us starts=1 cost=7 size=45 card=1)
0 0 0 TABLE ACCESS BY INDEX ROWID BATCHED MR_CONTACT_EVENTS (cr=192252 pr=86276 pw=0 time=29596726 us starts=1 cost=4 size=23 card=1)
0 1350887 4052661 INDEX RANGE SCAN MR_CEVT_ET_FK_I (cr=2709 pr=0 pw=0 time=654095 us starts=1 cost=3 size=0 card=5)(object id 40392)
0 0 0 INDEX RANGE SCAN MR_EVAS_CEVT_FK_I (cr=0 pr=0 pw=0 time=0 us starts=0 cost=2 size=0 card=1)(object id 522519)
0 0 0 TABLE ACCESS BY INDEX ROWID MR_EVENT_ASSOCIATIONS (cr=0 pr=0 pw=0 time=0 us starts=0 cost=3 size=22 card=1)
0 0 0 NESTED LOOPS ANTI (cr=192252 pr=86275 pw=0 time=15579865 us starts=1 cost=6 size=33 card=1)
0 0 0 TABLE ACCESS BY INDEX ROWID BATCHED MR_CONTACT_EVENTS (cr=192252 pr=86275 pw=0 time=15579842 us starts=1 cost=4 size=29 card=1)
0 1350887 4052661 INDEX RANGE SCAN MR_CEVT_ET_FK_I (cr=2709 pr=0 pw=0 time=480736 us starts=1 cost=3 size=0 card=5)(object id 40392)
0 0 0 INDEX RANGE SCAN MR_EVAS_CEVT_FK_I (cr=0 pr=0 pw=0 time=0 us starts=0 cost=2 size=79901760 card=19975440)(object id 522519)
This is the wrong index "INDEX RANGE SCAN MR_CEVT_ET_FK_I"
SQL*Plus
SQL> explain plan for
SELECT EA.EVAS_ID EVASID, EA.EV_ID EVID, EA.CEVT_ID CEVID, EA.EV_ID_SOURCE
EVSOURCEID, EA.CEVT_ID_SOURCE CEVTSOURCEID, EV.EVENT_START_DATETIME
STARTDATE
FROM
MR_EVENTS EV, MR_EVENT_ASSOCIATIONS EA WHERE EV.EPI_ID = :B2 AND EV.ET_ID =
:B1 AND EV.EV_ID = EA.EV_ID UNION ALL SELECT EA.EVAS_ID EVASID, EA.EV_ID
EVID, EA.CEVT_ID CEVID, EA.EV_ID_SOURCE EVSOURCEID, EA.CEVT_ID_SOURCE
CEVTSOURCEID, CE.SENT_DATETIME STARTDATE FROM MR_CONTACT_EVENTS CE,
MR_EVENT_ASSOCIATIONS EA WHERE CE.EPI_ID = :B2 AND CE.ET_ID = :B1 AND
CE.CEVT_ID = EA.CEVT_ID UNION ALL SELECT NULL, NULL, CE2.CEVT_ID CEVID,
CE2.EV_ID_SOURCE EVSOURCEID, CE2.CEVT_ID_SOURCE CEVTSOURCEID,
CE2.SENT_DATETIME STARTDATE FROM MR_CONTACT_EVENTS CE2 WHERE CE2.EPI_ID =
:B2 AND CE2.ET_ID = :B1 AND NOT EXISTS ( SELECT 1 FROM
MR_EVENT_ASSOCIATIONS EA WHERE CE2.CEVT_ID = EA.CEVT_ID);
PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 3146950259
----------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 3 | 123 | 26 (0)| 00:00:01 |
| 1 | UNION-ALL | | | | | |
| 2 | NESTED LOOPS | | 1 | 45 | 7 (0)| 00:00:01 |
| 3 | NESTED LOOPS | | 1 | 45 | 7 (0)| 00:00:01 |
| 4 | TABLE ACCESS BY INDEX ROWID BATCHED| MR_EVENTS | 1 | 23 | 4 (0)| 00:00:01 |
|* 5 | INDEX RANGE SCAN | MR_EV_I5 | 1 | | 3 (0)| 00:00:01 |
|* 6 | INDEX RANGE SCAN | MR_EVAS_EV_FK_I | 1 | | 2 (0)| 00:00:01 |
| 7 | TABLE ACCESS BY INDEX ROWID | MR_EVENT_ASSOCIATIONS | 1 | 22 | 3 (0)| 00:00:01 |
| 8 | NESTED LOOPS | | 1 | 45 | 10 (0)| 00:00:01 |
| 9 | NESTED LOOPS | | 1 | 45 | 10 (0)| 00:00:01 |
|* 10 | TABLE ACCESS BY INDEX ROWID BATCHED| MR_CONTACT_EVENTS | 1 | 23 | 7 (0)| 00:00:01 |
|* 11 | INDEX RANGE SCAN | MR_CEVT_EPI_FK_I | 5 | | 3 (0)| 00:00:01 |
|* 12 | INDEX RANGE SCAN | MR_EVAS_CEVT_FK_I | 1 | | 2 (0)| 00:00:01 |
| 13 | TABLE ACCESS BY INDEX ROWID | MR_EVENT_ASSOCIATIONS | 1 | 22 | 3 (0)| 00:00:01 |
| 14 | NESTED LOOPS ANTI | | 1 | 33 | 9 (0)| 00:00:01 |
|* 15 | TABLE ACCESS BY INDEX ROWID BATCHED | MR_CONTACT_EVENTS | 1 | 29 | 7 (0)| 00:00:01 |
|* 16 | INDEX RANGE SCAN | MR_CEVT_EPI_FK_I | 5 | | 3 (0)| 00:00:01 |
|* 17 | INDEX RANGE SCAN | MR_EVAS_CEVT_FK_I | 19M| 76M| 2 (0)| 00:00:01 |
----------------------------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
5 - access("EV"."ET_ID"=TO_NUMBER(:B1) AND "EV"."EPI_ID"=TO_NUMBER(:B2))
6 - access("EV"."EV_ID"="EA"."EV_ID")
filter("EA"."EV_ID" IS NOT NULL)
10 - filter("CE"."ET_ID"=TO_NUMBER(:B1))
11 - access("CE"."EPI_ID"=TO_NUMBER(:B2))
12 - access("CE"."CEVT_ID"="EA"."CEVT_ID")
filter("EA"."CEVT_ID" IS NOT NULL)
15 - filter("CE2"."ET_ID"=TO_NUMBER(:B1))
16 - access("CE2"."EPI_ID"=TO_NUMBER(:B2))
17 - access("CE2"."CEVT_ID"="EA"."CEVT_ID")
filter("EA"."CEVT_ID" IS NOT NULL)
This is the right index "INDEX RANGE SCAN MR_CEVT_EPI_FK_I"
INDEX_NAME INDEX_TYPE UNIQUENESS COMPRESSION LOGGING LEAF_BLOCKS DISTINCT_KEYS AVG_LEAF_BLOCKS_PER_KEY AVG_DATA_BLOCKS_PER_KEY CLUSTERING_FACTOR STATUS NUM_ROWS LAST_ANALYZED DEGREE
MR_CEVT_ET_FK_I NORMAL NONUNIQUE DISABLED NO 73750 252 292 16616 4187410 VALID 34284810 09/JAN/22 1
MR_CEVT_EPI_FK_I NORMAL NONUNIQUE DISABLED NO 49000 4503842 1 3 14410550 VALID 19513210 09/JAN/22 1
I thought maybe the first parameter passed to :B1 would be very distinct (:B2 is always the same value) and bind peeking would influence the optimizer, but the first value passed has 4 million occurrences in the 34 million. And as you can see the index MR_CEVT_EPI_FK_I is far more selective.
optimizer_adaptive_plans is set to false.
I hope I supplied all relevant information.
Any light on this behaviour would be appreciated.