Oracle DB - why would execution plan of this seeming wrong query changed suddenly? Not sure if the correct version can fix the plan

Viewed 333

Long version: I have a large table which I want to execute a query like:

-- original
select IH.* from ITEM_HISTORY IH 
    join ITEM_PACKAGE IP on IP.PACKAGE_NAME = IH.PACKAGE_NAME 
    where IP.OPERATOR_ID = ? 
    and (
        IH.OPERATION != 'CHANGE_OWNER' OR IH.EVENT_DATE = IH.INSTALLATION_DATE
    ) and IH.EXTERNAL_SERVICE_ACTION != 'NOT_APPLICABLE' 
    and IH.EVENT_DATE >= ? and IH.EVENT_DATE < ?
    and ROWNUM <= 500000
    order by IH.EVENT_DATE

which is a native query defined in @NamedNativeQuery of JPA. Each row represents a change event happened to an item. There are so many operators who can modify items, so ITEM_HISTORY table is a huge table which oftentimes causes us trouble. It contains millions of records and often times out.

Recently, we have an incident where when production pods running this query, Oracle suddenly changed the execution plan to a bad one, going a less optimized "route", and slowed down the pods, finally leads to application non responsiveness. We had to restart the pod to make it back to normal. Clients are unhappy and DB team just fixed the execution plan to the usual, better one. But they ask us, as DEV, what can be done at application side.

At first sight, I think: ah, this is wrong, because in Oracle database, we should use "inline view" or fetch first X rows, because in this way, Oracle database knows how to optimize it with stopkey sort or window sort pushed rank, so, this is an easy one!(I learned these from here and here)

So I changed it to:

-- version 1
select * from (
    select IH.* from ITEM_HISTORY IH 
        join ITEM_PACKAGE IP on IP.PACKAGE_NAME = IH.PACKAGE_NAME 
        where IP.OPERATOR_ID = ? 
        and (
            IH.OPERATION != 'CHANGE_OWNER' OR IH.EVENT_DATE = IH.INSTALLATION_DATE
        ) and IH.EXTERNAL_SERVICE_ACTION != 'NOT_APPLICABLE' 
        and IH.EVENT_DATE >= ? and IH.EVENT_DATE < ?
        order by IH.EVENT_DATE
) where ROWNUM <= 500000

And, this one:

-- version 2
select IH.* from ITEM_HISTORY IH 
    join ITEM_PACKAGE IP on IP.PACKAGE_NAME = IH.PACKAGE_NAME 
    where IP.OPERATOR_ID = ? 
    and (
        IH.OPERATION != 'CHANGE_OWNER' OR IH.EVENT_DATE = IH.INSTALLATION_DATE
    ) and IH.EXTERNAL_SERVICE_ACTION != 'NOT_APPLICABLE' 
    and IH.EVENT_DATE >= ? and IH.EVENT_DATE < ?
    and ROWNUM <= 500000
    order by IH.EVENT_DATE
    fetch first 500000 rows only;

But, I don't find much performance improvement. I see version 1 is even slower than original, and version 2 is faster, but the execution plans shows the same cost. (The test is done in staging env, where the range filter will fetch 400K rows)

-- original 21789 ms / 34598 ms
explain plan for
select * from ITEM_HISTORY IH 
join PACKAGE P on P.PACKAGE_NAME = IH.PACKAGE_NAME
where OPERATOR_ID = '88000001' and (IH.OPERATION != 'CHANGE_OWNER' OR IH.EVENT_DATE = IH.INSTALLATION_DATE) 
and IH.EXTERNAL_SERVICE_ACTION != 'NOT_APPLICABLE'
and IH.EVENT_DATE >= TO_DATE('2018/07/01', 'yyyy/mm/dd') and IH.EVENT_DATE < TO_DATE('2020/05/01', 'yyyy/mm/dd')
and rownum < 500000
order by IH.EVENT_DATE;

SELECT * FROM TABLE(DBMS_XPLAN.DIP.AY(NULL));
-- Plan hash.value: 1529757427
--  
-- ----------------------------------------------------------------------------------------------------------------------------
-- | Id  | Operation                   | Name                 | Rows  | Bytes |TempP.| Cost (%CPU)| Time     | Pstart| Pstop |
-- ----------------------------------------------------------------------------------------------------------------------------
-- |   0 | SELECT STATEMENT            |                      | 66280 |    29M|       |   133K  (1)| 00:00:06 |       |       |
-- |   1 |  SORT ORDER BY              |                      | 66280 |    29M|    34M|   133K  (1)| 00:00:06 |       |       |
-- |*  2 |   COUNT STOPKEY             |                      |       |       |       |            |          |       |       |
-- |*  3 |    hash.JOIN                |                      | 66280 |    29M|       |   126K  (1)| 00:00:05 |       |       |
-- |*  4 |     TABLE ACCESS FULL       | PACKAGE              |   545 |   120K|       |    25   (0)| 00:00:01 |       |       |
-- |   5 |     PARTITION RANGE ITERATOR|                      |   287K|    64M|       |   126K  (1)| 00:00:05 |    44 |    65 |
-- |*  6 |      TABLE ACCESS FULL      | ITEM_HISTORY         |   287K|    64M|       |   126K  (1)| 00:00:05 |    44 |    65 |
-- ----------------------------------------------------------------------------------------------------------------------------
--  
-- Predicate Information (identified by operation id):
-- ---------------------------------------------------
--  
--    2 - filter(ROWNUM<500000)
--    3 - access("P"."PACKAGE_NAME"="IH"."PACKAGE_NAME")
--    4 - filter("P"."OPERATOR_ID"='88000001')
--    6 - filter("IH"."EXTERNAL_SERVICE_ACTION"<>'NOT_APPLICABLE' AND ("IH"."OPERATION"<>'CHANGE_OWNER' OR 
--               "IH"."EVENT_DATE"="IH"."INSTALLATION_DATE"))
--  
-- Note
-- -----
--    - this is an adaptive plan

-- final query(new) 33342 ms / 26423 ms
select * from (
    select * from ITEM_HISTORY IH 
    join PACKAGE P on P.PACKAGE_NAME = IH.PACKAGE_NAME
    where OPERATOR_ID = '88000001' and (IH.OPERATION != 'CHANGE_OWNER' OR IH.EVENT_DATE = IH.INSTALLATION_DATE) 
    and IH.EXTERNAL_SERVICE_ACTION != 'NOT_APPLICABLE'
    and IH.EVENT_DATE >= TO_DATE('2018/07/01', 'yyyy/mm/dd') and IH.EVENT_DATE < TO_DATE('2020/05/01', 'yyyy/mm/dd')
    order by IH.EVENT_DATE
) where rownum < 500000;
SELECT *   FROM TABLE(DBMS_XPLAN.DIP.AY(NULL));
-- Plan hash.value: 3376840570
--  
-- -----------------------------------------------------------------------------------------------------------------------------
-- | Id  | Operation                    | Name                 | Rows  | Bytes |TempP.| Cost (%CPU)| Time     | Pstart| Pstop |
-- -----------------------------------------------------------------------------------------------------------------------------
-- |   0 | SELECT STATEMENT             |                      | 66280 |   412M|       |   133K  (1)| 00:00:06 |       |       |
-- |*  1 |  COUNT STOPKEY               |                      |       |       |       |            |          |       |       |
-- |   2 |   VIEW                       |                      | 66280 |   412M|       |   133K  (1)| 00:00:06 |       |       |
-- |*  3 |    SORT ORDER BY STOPKEY     |                      | 66280 |    29M|    34M|   133K  (1)| 00:00:06 |       |       |
-- |*  4 |     hash.JOIN                |                      | 66280 |    29M|       |   126K  (1)| 00:00:05 |       |       |
-- |*  5 |      TABLE ACCESS FULL       | PACKAGE |   545 |   120K|       |    25   (0)| 00:00:01 |       |       |
-- |   6 |      PARTITION RANGE ITERATOR|                      |   287K|    64M|       |   126K  (1)| 00:00:05 |    44 |    65 |
-- |*  7 |       TABLE ACCESS FULL      | ITEM_HISTORY |   287K|    64M|       |   126K  (1)| 00:00:05 |    44 |    65 |
-- -----------------------------------------------------------------------------------------------------------------------------
--  
-- Predicate Information (identified by operation id):
-- ---------------------------------------------------
--  
--    1 - filter(ROWNUM<500000)
--    3 - filter(ROWNUM<500000)
--    4 - access("P"."PACKAGE_NAME"="IH"."PACKAGE_NAME")
--    5 - filter("P"."OPERATOR_ID"='88000001')
--    7 - filter("IH"."EXTERNAL_SERVICE_ACTION"<>'NOT_APPLICABLE' AND ("IH"."OPERATION"<>'CHANGE_OWNER' OR 
--               "IH"."EVENT_DATE"="IH"."INSTALLATION_DATE"))


-- final query 2(fetch X rows only) 19662 ms / 19437 ms 
explain plan for
    select * from ITEM_HISTORY IH 
    join PACKAGE P on P.PACKAGE_NAME = IH.PACKAGE_NAME
    where OPERATOR_ID = '88000001' and (IH.OPERATION != 'CHANGE_OWNER' OR IH.EVENT_DATE = IH.INSTALLATION_DATE) 
    and IH.EXTERNAL_SERVICE_ACTION != 'NOT_APPLICABLE'
    and IH.EVENT_DATE >= TO_DATE('2018/07/01', 'yyyy/mm/dd') and IH.EVENT_DATE < TO_DATE('2020/05/01', 'yyyy/mm/dd')
    order by IH.EVENT_DATE
fetch first 500000 rows only;
SELECT * 
  FROM TABLE(DBMS_XPLAN.DIP.AY(NULL));
--Plan hash.value: 3207167953
-- 
------------------------------------------------------------------------------------------------------------------------------
--| Id  | Operation                   | Name                 | Rows  | Bytes |TempP.| Cost (%CPU)| Time     | Pstart| Pstop |
------------------------------------------------------------------------------------------------------------------------------
--|   0 | SELECT STATEMENT            |                      |   500K|  3120M|       |   133K  (1)| 00:00:06 |       |       |
--|*  1 |  VIEW                       |                      |   500K|  3120M|       |   133K  (1)| 00:00:06 |       |       |
--|*  2 |   WINDOW SORT PUIH.D RANK   |                      | 66280 |    29M|    34M|   133K  (1)| 00:00:06 |       |       |
--|*  3 |    hash.JOIN                |                      | 66280 |    29M|       |   126K  (1)| 00:00:05 |       |       |
--|*  4 |     TABLE ACCESS FULL       | PACKAGE              |   545 |   120K|       |    25   (0)| 00:00:01 |       |       |
--|   5 |     PARTITION RANGE ITERATOR|                      |   287K|    64M|       |   126K  (1)| 00:00:05 |    44 |    65 |
--|*  6 |      TABLE ACCESS FULL      | ITEM_HISTORY         |   287K|    64M|       |   126K  (1)| 00:00:05 |    44 |    65 |
------------------------------------------------------------------------------------------------------------------------------
-- 
--Predicate Information (identified by operation id):
-----------------------------------------------------
-- 
--   1 - filter("from$_subquery$_004"."rowlimit_$$_rownumber"<=500000)
--   2 - filter(ROW_NUMBER() OVER ( ORDER BY "IH"."EVENT_DATE")<=500000)
--   3 - access("P"."PACKAGE_NAME"="IH"."PACKAGE_NAME")
--   4 - filter("P"."OPERATOR_ID"='88000001')
--   6 - filter("IH"."EXTERNAL_SERVICE_ACTION"<>'NOT_APPLICABLE' AND ("IH"."OPERATION"<>'CHANGE_OWNER' OR 
--              "IH"."EVENT_DATE"="IH"."INSTALLATION_DATE"))

So, the question:

  • At last, will the version 2 solve the execution changed to bad one problem? I am not sure. - Does it have to do with the rows fetched? I suspect that most of the time, the rows are so few, that original version, even wrong, have covered all rows, so it's actually correct, as when X < 500K, original will fetch all and sort, which gives correct results. But at the time of incident the rows number became bigger, and the plan changed. But I am not DBA and I am not sure DBA said that this query always returns almost 500K records indeed, so we always have a lot of rows to fetch.
  • What can cause an execution plan change, and then slow down the Oracle DB, and then leads to application crash? I don't get it.

EDIT: I managed to get the execution plans used during the incident. The first one and second one are usually used. The bad one is the third one. Timestamp 1 and 2 are several days before incident time. Timestamp 3 is incident time.

DBID SQL_ID PLAN_HASH_VALUE ID OPERATION OPTIONS OBJECT_NODE OBJECT# OBJECT_OWNER OBJECT_NAME OBJECT_ALIAS OBJECT_TYPE OPTIMIZER PARENT_ID DEPTH POSITION SEARCH_COLUMNS COST CARDINALITY BYTES OTHER_TAG PARTITION_START PARTITION_STOP PARTITION_ID OTHER DISTRIBUTION CPU_COST IO_COST TEMP_SPACE ACCESS_PREDICATES FILTER_PREDICATES PROJECTION TIME QBLOCK_NAME REMARKS TIMESTAMP OTHER_XML CON_DBID CON_ID
random_number random_id hash1 0 SELECT STATEMENT ALL_ROWS 0 111 0 111 timestamp1 random_number 0
random_number random_id hash1 1 SORT ORDER BY 0 1 1 0 111 30 8220 40060576 110 1 SEL$58A6D7F6 timestamp1 random_number 0
random_number random_id hash1 2 COUNT STOPKEY 1 2 1 0 timestamp1 random_number 0
random_number random_id hash1 3 FILTER 2 3 1 0 timestamp1 random_number 0
random_number random_id hash1 4 HASH JOIN 3 4 1 0 110 30 8220 5581756 110 1 timestamp1 random_number 0
random_number random_id hash1 5 TABLE ACCESS FULL 175586 MY_APP PACKAGE SP@SEL$1 TABLE 4 5 1 0 105 27 945 4897690 105 1 SEL$58A6D7F6 timestamp1 random_number 0
random_number random_id hash1 6 PARTITION RANGE ITERATOR 4 5 2 0 5 426 101814 KEY KEY 6 37416 5 1 timestamp1 random_number 0
random_number random_id hash1 7 TABLE ACCESS BY LOCAL INDEX ROWID BATCHED 174723 MY_APP ITEM_HISTORY SH@SEL$1 TABLE 6 6 1 0 5 426 101814 KEY KEY 6 37416 5 1 SEL$58A6D7F6 timestamp1 random_number 0
random_number random_id hash1 8 INDEX RANGE SCAN 174726 MY_APP IX_ITEM_HISTORY_EVENTD SH@SEL$1 INDEX 7 7 1 1 3 1 KEY KEY 6 21764 3 1 SEL$58A6D7F6 timestamp1 random_number 0
random_number random_id hash2 0 SELECT STATEMENT ALL_ROWS 0 6 0 6 2021-09-01 23:00:00 random_number 0
random_number random_id hash2 1 COUNT STOPKEY 0 1 1 0 SEL$58A6D7F6 timestamp2 random_number 0
random_number random_id hash2 2 FILTER 1 2 1 0 timestamp2 random_number 0
random_number random_id hash2 3 NESTED LOOPS 2 3 1 0 6 1 274 47177 6 1 timestamp2 random_number 0
random_number random_id hash2 4 NESTED LOOPS 3 4 1 0 6 1 274 47177 6 1 timestamp2 random_number 0
random_number random_id hash2 5 PARTITION RANGE ITERATOR 4 5 1 0 5 1 239 KEY KEY 5 37416 5 1 timestamp2 random_number 0
random_number random_id hash2 6 TABLE ACCESS BY LOCAL INDEX ROWID 174723 MY_APP ITEM_HISTORY SH@SEL$1 TABLE 5 6 1 0 5 1 239 KEY KEY 5 37416 5 1 SEL$58A6D7F6 timestamp2 random_number 0
random_number random_id hash2 7 INDEX RANGE SCAN 174726 MY_APP IX_ITEM_HISTORY_EVENTD SH@SEL$1 INDEX 6 7 1 1 3 1 KEY KEY 5 21764 3 1 SEL$58A6D7F6 timestamp2 random_number 0
random_number random_id hash2 8 INDEX UNIQUE SCAN 175998 MY_APP UK_PACKAGE_NAME SP@SEL$1 INDEX (UNIQUE) 4 5 2 1 0 1 1900 0 SEL$58A6D7F6 timestamp2 random_number 0
random_number random_id hash2 9 TABLE ACCESS BY INDEX ROWID 175586 MY_APP PACKAGE SP@SEL$1 TABLE 3 4 2 0 1 1 35 9761 1 1 SEL$58A6D7F6 timestamp2 random_number 0
random_number random_id hash3 0 SELECT STATEMENT HINT: ALL_ROWS 0 25551 0 25551 timestamp3 random_number 0
random_number random_id hash3 1 SORT ORDER BY 0 1 1 0 25551 391 111044 1414967960 25510 1 SEL$58A6D7F6 timestamp3 random_number 0
random_number random_id hash3 2 COUNT STOPKEY 1 2 1 0 timestamp3 random_number 0
random_number random_id hash3 3 PX COORDINATOR 2 3 1 0 timestamp3 random_number 0
random_number random_id hash3 4 PX SEND QC (RANDOM) :Q1001 SYS :TQ10001 3 4 1 0 25550 391 111044 PARALLEL_TO_SERIAL QC (RANDOM) 1376651756 25510 1 timestamp3 random_number 0
random_number random_id hash3 5 COUNT STOPKEY :Q1001 4 5 1 0 PARALLEL_COMBINED_WITH_CHILD timestamp3 random_number 0
random_number random_id hash3 6 FILTER :Q1001 5 6 1 0 PARALLEL_COMBINED_WITH_CHILD timestamp3 random_number 0
random_number random_id hash3 7 HASH JOIN :Q1001 6 7 1 0 25550 391 111044 PARALLEL_COMBINED_WITH_PARENT 1376651756 25510 1 timestamp3 random_number 0
random_number random_id hash3 8 JOIN FILTER CREATE :Q1001 SYS :BF0000 7 8 1 0 105 21 735 PARALLEL_COMBINED_WITH_PARENT 4938130 105 1 timestamp3 random_number 0
random_number random_id hash3 9 PX RECEIVE :Q1001 8 9 1 0 105 21 735 PARALLEL_COMBINED_WITH_PARENT 4938130 105 1 timestamp3 random_number 0
random_number random_id hash3 10 PX SEND BROADCAST :Q1000 SYS :TQ10000 9 10 1 0 105 21 735 PARALLEL_FROM_SERIAL BROADCAST 4938130 105 1 timestamp3 random_number 0
random_number random_id hash3 11 PX SELECTOR :Q1000 10 11 1 0 SINGLE_COMBINED_WITH_CHILD timestamp3 random_number 0
random_number random_id hash3 12 TABLE ACCESS FULL :Q1000 175586 MY_APP PACKAGE SP@SEL$1 TABLE 11 12 1 0 105 21 735 SINGLE_COMBINED_WITH_PARENT 4938130 105 1 SEL$58A6D7F6 timestamp3 random_number 0
random_number random_id hash3 13 JOIN FILTER USE :Q1001 SYS :BF0000 7 8 2 0 25445 14946 3721554 PARALLEL_COMBINED_WITH_PARENT 1370926276 25405 1 timestamp3 random_number 0
random_number random_id hash3 14 PX BLOCK ITERATOR :Q1001 13 9 1 0 25445 14946 3721554 PARALLEL_COMBINED_WITH_CHILD KEY KEY 14 1370926276 25405 1 timestamp3 random_number 0
random_number random_id hash3 15 TABLE ACCESS FULL :Q1001 174723 MY_APP ITEM_HISTORY SH@SEL$1 TABLE 14 10 1 0 25445 14946 3721554 PARALLEL_COMBINED_WITH_PARENT KEY KEY 14 1370926276 25405 1 SEL$58A6D7F6 timestamp3 random_number 0
1 Answers

As requested by the comment's section, let me summarize:

  • If one statement runs in parallel with the same sql_id, then it is clear that either you run the statement, or a SQL Profile was generated as recommendation to improve the execution using parallel query.
  • That can only happen automatically when SQL Profiles are automatically accepted.
  • My advice: That is a really bad practice. SQL Profiles should not be automatically accepted. They should be reviewed by the DBAS, and only accepted after consideration and proper analysis.

A normal scenario is the so called bind peeking issue. I am not going to explain it, you have a lot of articles in Internet about it. One way to fix it is to create a sql plan baseline.

How to create a SQL Plan Baseline ?

From Cache

Step 1

Manual plan loading can be used in conjunction with, or as an alternative to automatic plan capture. The load operations are performed using the DBMS_SPM package, which allows SQL plan baselines to be loaded from SQL tuning sets or from specific SQL statements in the cursor cache. Manually loaded statements are flagged as accepted by default. If a SQL plan baseline is present for a SQL statement, the plan is added to the baseline, otherwise a new baseline is created.

DECLARE
  l_plans_loaded  PLS_INTEGER;
BEGIN
  l_plans_loaded := DBMS_SPM.load_plans_from_sqlset(
    sqlset_name => 'my_sqlset');
END;
/

DECLARE
  l_plans_loaded  PLS_INTEGER;
BEGIN
  l_plans_loaded := DBMS_SPM.load_plans_from_cursor_cache(
    sql_id => 'yoursqlid', plan_hash_value => 'yourplanhasvalue');
END;
/

The return value of the LOAD_PLANS_FROM_SQLSET and LOAD_PLANS_FROM_CURSOR_CACHE functions indicates the number of plan loaded by the function call.

SELECT sql_handle, plan_name, enabled, accepted FROM   dba_sql_plan_baselines 

Verify that the plan is accepted and enabled.

If the sql_id and plan_hash_value are not longer in memory, you would need to use AWR for creating the baseline. If that is the case, here you have a very good guide step by step

Sql Baseline using AWR

Related