Enforcing SQL execution plan

From: Hameed, Amir <Amir.Hameed_at_xerox.com>
Date: Fri, 2 Sep 2016 01:11:53 +0000
Message-ID: <AF02C941134B1A4AB5F61A726D08DCED2015B3E4_at_USA7109MB012.na.xerox.net>



Hi,
We run a certain job in the Oracle E-Business Suite (EBS) through a concurrent program. The environment information is listed below: DB version - 11.2.0.4
EBS version - 11.5.10.2
OS - Solaris

The statement uses bind variables that are supplied as part of running the concurrent program. As far as I can tell, the statement always produces the following execution plan:


| Id  | Operation                       | Name                        | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
---------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                |                             |     17 |        |       |    12 (100)|          |     17 |00:00:00.01 |     145 |
|   1 |  CONCATENATION                  |                             |     17 |        |       |            |          |     17 |00:00:00.01 |     145 |

|* 2 | FILTER | | 17 | | | | | 17 |00:00:00.01 | 145 |
| 3 | NESTED LOOPS | | 17 | 1 | 197 | 6 (0)| 00:00:01 | 17 |00:00:00.01 | 145 |
|* 4 | TABLE ACCESS BY INDEX ROWID | WSH_DELIVERY_DETAILS | 17 | 1 | 184 | 3 (0)| 00:00:01 | 17 |00:00:00.01 | 73 |
|* 5 | INDEX UNIQUE SCAN | WSH_DELIVERY_DETAILS_U1 | 17 | 1 | | 2 (0)| 00:00:01 | 17 |00:00:00.01 | 51 |
|* 6 | TABLE ACCESS BY INDEX ROWID | WSH_DELIVERY_ASSIGNMENTS | 17 | 1 | 13 | 3 (0)| 00:00:01 | 17 |00:00:00.01 | 72 |
|* 7 | INDEX RANGE SCAN | WSH_DELIVERY_ASSIGNMENTS_N3 | 17 | 1 | | 2 (0)| 00:00:01 | 17 |00:00:00.01 | 53 |
|* 8 | FILTER | | 0 | | | | | 0 |00:00:00.01 | 0 |
| 9 | NESTED LOOPS | | 0 | 1 | 197 | 6 (0)| 00:00:01 | 0 |00:00:00.01 | 0 | | 10 | NESTED LOOPS | | 0 | 1 | 197 | 6 (0)| 00:00:01 | 0 |00:00:00.01 | 0 |
|* 11 | TABLE ACCESS BY INDEX ROWID| WSH_DELIVERY_DETAILS | 0 | 1 | 184 | 3 (0)| 00:00:01 | 0 |00:00:00.01 | 0 |
|* 12 | INDEX RANGE SCAN | WSH_DELIVERY_DETAILS_N1 | 0 | 1 | | 3 (0)| 00:00:01 | 0 |00:00:00.01 | 0 |
|* 13 | INDEX RANGE SCAN | WSH_DELIVERY_ASSIGNMENTS_N3 | 0 | 1 | | 2 (0)| 00:00:01 | 0 |00:00:00.01 | 0 |
|* 14 | TABLE ACCESS BY INDEX ROWID | WSH_DELIVERY_ASSIGNMENTS | 0 | 1 | 13 | 3 (0)| 00:00:01 | 0 |00:00:00.01 | 0 |
--------------------------------------------------------------------------------------------------------------------------------------------------------- For the past few weeks, the concurrent program has been intermittently taking time to complete. When traced, one of the "bad" runs produced the following information: call count cpu elapsed disk query current rows ------- ------ -------- ---------- ---------- ---------- ---------- ---------- Parse 1 0.00 0.00 0 0 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 1 614.23 11147.25 941317 18000438 0 1 ------- ------ -------- ---------- ---------- ---------- ---------- ---------- total 3 614.23 11147.25 941317 18000438 0 1 Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ db file sequential read 941317 1.00 3563.29 Disk file operations I/O 74 0.00 0.00 gc current grant busy 3 0.00 0.00 gc cr grant 2-way 44 0.08 0.09 read by other session 1706610 1.49 6482.34 gc buffer busy acquire 83710 1.00 431.39 latch: cache buffers chains 173199 0.01 9.25
...
(only the main wait events are shown above)

Rows (1st) Rows (avg) Rows (max) Row Source Operation

---------- ---------- ----------  ---------------------------------------------------
         1          1          1  CONCATENATION  (cr=18000438 pr=941317 pw=0 time=2557323227 us)
         0          0          0   FILTER  (cr=0 pr=0 pw=0 time=2 us)
         0          0          0    NESTED LOOPS  (cr=0 pr=0 pw=0 time=0 us cost=6 size=197 card=1)
         0          0          0     TABLE ACCESS BY INDEX ROWID WSH_DELIVERY_DETAILS (cr=0 pr=0 pw=0 time=0 us cost=3 size=184 card=1)
         0          0          0      INDEX UNIQUE SCAN WSH_DELIVERY_DETAILS_U1 (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)(object id 165859)
         0          0          0     TABLE ACCESS BY INDEX ROWID WSH_DELIVERY_ASSIGNMENTS (cr=0 pr=0 pw=0 time=0 us cost=3 size=13 card=1)
         0          0          0      INDEX RANGE SCAN WSH_DELIVERY_ASSIGNMENTS_N3 (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)(object id 165871)
         1          1          1   FILTER  (cr=18000438 pr=941317 pw=0 time=2557323217 us)
         1          1          1    NESTED LOOPS  (cr=18000438 pr=941317 pw=0 time=2557323212 us cost=6 size=197 card=1)
         1          1          1     NESTED LOOPS  (cr=18000361 pr=941296 pw=0 time=2557119556 us cost=6 size=197 card=1)
         1          1          1      TABLE ACCESS BY INDEX ROWID WSH_DELIVERY_DETAILS (cr=18000336 pr=941295 pw=0 time=2557112429 us cost=3 size=184 card=1)
  42599164   42599164   42599164       INDEX RANGE SCAN WSH_DELIVERY_DETAILS_N1 (cr=1798095 pr=99233 pw=0 time=600382285 us cost=3 size=0 card=1)(object id 917318)
         1          1          1      INDEX RANGE SCAN WSH_DELIVERY_ASSIGNMENTS_N3 (cr=25 pr=1 pw=0 time=7116 us cost=2 size=0 card=1)(object id 165871)
         1          1          1     TABLE ACCESS BY INDEX ROWID WSH_DELIVERY_ASSIGNMENTS (cr=77 pr=21 pw=0 time=203643 us cost=3 size=13 card=1)


It seems that when it runs longer, it scans a lot of rows from index WSH_DELIVERY_DETAILS_N1. This index is defined on a date column and is not very selective.

As part of the troubleshooting exercise, I captured bind variables of the bad run from DBA_HIST_SQLBIND, defined them as variables with appropriate data type and then ran them through SQL*Plus. The problem that I am facing is that from SQL*Plus, by using this technique, it always produces the following plan, regardless of whether I use values from the good run or the bad run:


| Id  | Operation                      | Name                        | Starts | E-Rows |E-Bytes| Cost (%CPU)| E-Time   | A-Rows |   A-Time   | Buffers |
--------------------------------------------------------------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT               |                             |      1 |        |       |    12 (100)|          |      0 |00:00:00.01 |       4 |
|   1 |  CONCATENATION                 |                             |      1 |        |       |            |          |      0 |00:00:00.01 |       4 |

|* 2 | FILTER | | 1 | | | | | 0 |00:00:00.01 | 0 |
| 3 | NESTED LOOPS | | 0 | 1 | 197 | 6 (0)| 00:00:01 | 0 |00:00:00.01 | 0 |
|* 4 | TABLE ACCESS BY INDEX ROWID| WSH_DELIVERY_DETAILS | 0 | 1 | 184 | 3 (0)| 00:00:01 | 0 |00:00:00.01 | 0 |
|* 5 | INDEX UNIQUE SCAN | WSH_DELIVERY_DETAILS_U1 | 0 | 1 | | 2 (0)| 00:00:01 | 0 |00:00:00.01 | 0 |
|* 6 | TABLE ACCESS BY INDEX ROWID| WSH_DELIVERY_ASSIGNMENTS | 0 | 1 | 13 | 3 (0)| 00:00:01 | 0 |00:00:00.01 | 0 |
|* 7 | INDEX RANGE SCAN | WSH_DELIVERY_ASSIGNMENTS_N3 | 0 | 1 | | 2 (0)| 00:00:01 | 0 |00:00:00.01 | 0 |
|* 8 | FILTER | | 1 | | | | | 0 |00:00:00.01 | 4 |
| 9 | NESTED LOOPS | | 1 | 1 | 197 | 6 (0)| 00:00:01 | 0 |00:00:00.01 | 4 |
|* 10 | TABLE ACCESS BY INDEX ROWID| WSH_DELIVERY_DETAILS | 1 | 1 | 184 | 3 (0)| 00:00:01 | 0 |00:00:00.01 | 4 |
|* 11 | INDEX UNIQUE SCAN | WSH_DELIVERY_DETAILS_U1 | 1 | 1 | | 2 (0)| 00:00:01 | 1 |00:00:00.01 | 3 |
|* 12 | TABLE ACCESS BY INDEX ROWID| WSH_DELIVERY_ASSIGNMENTS | 0 | 1 | 13 | 3 (0)| 00:00:01 | 0 |00:00:00.01 | 0 |
|* 13 | INDEX RANGE SCAN | WSH_DELIVERY_ASSIGNMENTS_N3 | 0 | 1 | | 2 (0)| 00:00:01 | 0 |00:00:00.01 | 0 |
--------------------------------------------------------------------------------------------------------------------------------------------------------

I have tried to capture hints through outline from the bad run and added them as hints to the statement that I am running from SQL*Plus but I am still not able to enforce the "bad" plan. The outline hints are shown below:

  /*+

      BEGIN_OUTLINE_DATA
      IGNORE_OPTIM_EMBEDDED_HINTS
      OPTIMIZER_FEATURES_ENABLE('11.2.0.4')
      DB_VERSION('11.2.0.4')
      OPT_PARAM('_b_tree_bitmap_plans' 'false')
      OPT_PARAM('_fast_full_scan_enabled' 'false')
      OPT_PARAM('_index_join_enabled' 'false')
      ALL_ROWS
      OUTLINE_LEAF(_at_"SEL$1")
      OUTLINE_LEAF(_at_"SEL$1_1")
      USE_CONCAT(_at_"SEL$1" 8 OR_PREDICATES(6) PREDICATE_REORDERS((23 22) (24 23) (26 24) (22 26)))
      OUTLINE_LEAF(_at_"SEL$1_2")
      OUTLINE(_at_"SEL$1")
      INDEX_RS_ASC(_at_"SEL$1_1" "WDD"_at_"SEL$1" ("WSH_DELIVERY_DETAILS"."DELIVERY_DETAIL_ID"))
      INDEX_RS_ASC(_at_"SEL$1_1" "WDA"_at_"SEL$1" ("WSH_DELIVERY_ASSIGNMENTS"."DELIVERY_DETAIL_ID"))
      INDEX_RS_ASC(_at_"SEL$1_2" "WDD"_at_"SEL$1_2" ("WSH_DELIVERY_DETAILS"."DATE_SCHEDULED"))
      INDEX(_at_"SEL$1_2" "WDA"_at_"SEL$1_2" ("WSH_DELIVERY_ASSIGNMENTS"."DELIVERY_DETAIL_ID"))
      LEADING(_at_"SEL$1_1" "WDD"_at_"SEL$1" "WDA"@"SEL$1")
      LEADING(_at_"SEL$1_2" "WDD"_at_"SEL$1_2" "WDA"@"SEL$1_2")
      USE_NL(_at_"SEL$1_1" "WDA"_at_"SEL$1")
      USE_NL(_at_"SEL$1_2" "WDA"_at_"SEL$1_2")
      NLJ_BATCHING(_at_"SEL$1_2" "WDA"_at_"SEL$1_2")
      END_OUTLINE_DATA

  */

The SQL statement is also pasted below:
SELECT WDD.SOURCE_LINE_ID, WDD.SOURCE_HEADER_ID, WDD.INVENTORY_ITEM_ID,

  WDD.SHIPMENT_PRIORITY_CODE, WDD.SOURCE_CODE SOURCE_CODE,
  WDD.SOURCE_HEADER_NUMBER SOURCE_HEADER_NUMBER, WDD.ORGANIZATION_ID,
  WDD.MOVE_ORDER_LINE_ID, WDD.SHIP_FROM_LOCATION_ID, WDD.SHIP_METHOD_CODE,
  WDD.SHIPMENT_PRIORITY_CODE, WDD.DATE_SCHEDULED, WDD.REQUESTED_QUANTITY,
  WDD.REQUESTED_QUANTITY_UOM, WDD.PREFERRED_GRADE, WDD.REQUESTED_QUANTITY2,
  WDD.REQUESTED_QUANTITY_UOM2, WDD.PROJECT_ID, WDD.TASK_ID, WDD.SUBINVENTORY,
  WDD.SUBINVENTORY, WDD.RELEASED_STATUS, WDD.SHIP_MODEL_COMPLETE_FLAG,
  WDD.TOP_MODEL_LINE_ID, WDD.SHIP_SET_ID, WDA.DELIVERY_ID,
  WDD.LAST_UPDATE_DATE

FROM
WSH_DELIVERY_DETAILS WDD, WSH_DELIVERY_ASSIGNMENTS WDA WHERE
  WDD.DELIVERY_DETAIL_ID = :B15 AND WDA.DELIVERY_DETAIL_ID =
  WDD.DELIVERY_DETAIL_ID AND WDD.DATE_SCHEDULED IS NOT NULL AND
  WDD.DATE_REQUESTED >= NVL(:B14 , WDD.DATE_REQUESTED) AND WDD.DATE_REQUESTED
  <= NVL(:B13 , WDD.DATE_REQUESTED) AND WDD.DATE_SCHEDULED >= NVL(:B12 ,   WDD.DATE_SCHEDULED) AND WDD.DATE_SCHEDULED <= NVL(:B11 , WDD.DATE_SCHEDULED)    AND NVL(WDD.REQUESTED_QUANTITY,0) > 0 AND WDD.RELEASED_STATUS IN ('R','B',   'X') AND NVL(WDD.SUBINVENTORY, -99) = DECODE(:B10 , NULL,   NVL(WDD.SUBINVENTORY, -99), :B10 ) AND NVL(WDD.PROJECT_ID,0) = DECODE(:B9 ,   0, NVL(WDD.PROJECT_ID,0), :B9 ) AND NVL(WDD.TASK_ID,0) = DECODE(:B8 , 0,   NVL(WDD.TASK_ID,0), :B8 ) AND NVL(WDD.SHIP_SET_ID,0) = DECODE(:B7 , 0,   NVL(WDD.SHIP_SET_ID,0), :B7 ) AND NVL(WDD.SHIPMENT_PRIORITY_CODE,-99) =   DECODE(:B6 , NULL, NVL(WDD.SHIPMENT_PRIORITY_CODE,-99), :B6 ) AND   WDD.ORGANIZATION_ID = NVL(:B5 , WDD.ORGANIZATION_ID) AND   WDD.SHIP_FROM_LOCATION_ID = DECODE(:B4 , -1, WDD.SHIP_FROM_LOCATION_ID, :B4   ) AND (( WDA.DELIVERY_ID IS NOT NULL AND ( :B3 <> 'N' OR WDA.DELIVERY_ID =   :B2 OR :B1 <> 0 ) ) OR ( WDA.DELIVERY_ID IS NULL AND :B2 = 0 AND :B1 = 0 ) )

How can I enforce the bad execution plan from SQL*Plus? If I am able to enforce it then I already have bind values from that run and I will be able to reproduce the issue.

Thanks,
Amir

--
http://www.freelists.org/webpage/oracle-l
Received on Fri Sep 02 2016 - 03:11:53 CEST

Original text of this message