RE: Enforcing SQL execution plan

From: Hameed, Amir <Amir.Hameed_at_xerox.com>
Date: Fri, 2 Sep 2016 14:27:47 +0000
Message-ID: <AF02C941134B1A4AB5F61A726D08DCED2015B7BE_at_USA7109MB012.na.xerox.net>

Thanks Dominic.
I do not see implicit date conversion in the predicates section of the output from dbms_xplan.display_cursor. I have even tried to plug the values directly into the SQL as literal and I got the same plan as with binds.

From: Dominic Brooks [mailto:dombrooks_at_hotmail.com] Sent: Friday, September 02, 2016 4:23 AM To: Hameed, Amir <Amir.Hameed_at_xerox.com>; oracle-l_at_freelists.org Subject: RE: Enforcing SQL execution plan

For reproducing the problem execution in sql*plus, how are you dealing with the date parameter ? (assuming colunn is a DATE datatype).

Because sql*plus doesn't natively support DATE typed variables, you need to change the sql statement to use a TO_DATE around those combined with an appropriately formatted string or number variable.

Might be a red herring - predicates section of execution plan would highlight if implicit datatype conversion was an issue.

From: Amir.Hameed_at_xerox.com<mailto:Amir.Hameed_at_xerox.com> To: oracle-l_at_freelists.org<mailto:oracle-l_at_freelists.org> Subject: Enforcing SQL execution plan
Date: Fri, 2 Sep 2016 01:11:53 +0000
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 - 16:27:47 CEST

This message: [ Message body ]
Next message: Michael Cunningham: "Re: I'm stuck replace(column, '''') and replace(column,chr(39)) not working"
Previous message: Luis Santos: "Re: System Stats - MAXTHR and SLAVETHR"
Maybe in reply to: Hameed, Amir: "Enforcing SQL execution plan"
In reply to Jonathan Lewis: "RE: Enforcing SQL execution plan"
Next in thread: fmhabash_at_gmail.com: "RE: Enforcing SQL execution plan"

Contemporary messages sorted: [ by date ] [ by thread ] [ by subject ] [ by author ]

Original text of this message