Re: performance issue after upgrade to oracle 11.2.0.1 linux 32 bit.

From: Charles Hooper <hooperc2000_at_yahoo.com>
Date: Tue, 3 Nov 2009 08:22:38 -0800 (PST)
Message-ID: <4896fa0f-459f-49d5-8c94-4c9abe9066cd_at_d5g2000yqm.googlegroups.com>



On Nov 3, 10:29 am, lsllcm <lsl..._at_gmail.com> wrote:
> Hi All,
>
> I have one performance issue after upgrade to oracle 11.2.0.1 linux 32
> bit.
>
> The optimizer always choose index of "order by column", not use index
> of "where clause columns". Any comments are appreciated.
>
> Below are three test cases:
>
> Case 1: TEST on 11.2.0.1 DBs with ORDER BY ORDER BY gf_fee_apply_date
> Result: Choose incorrect execution plan.
>
> Connected to:
> Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production
> With the Partitioning, OLAP, Data Mining and Real Application Testing
> options
>
> SQL> set autotrace trace
> SQL> set timing on
> SQL>
> SQL> variable spc varchar2(15);
> SQL> variable bfd varchar2(40);
> SQL> variable efd varchar2(40);
> SQL> variable p1 varchar2(60);
> SQL> exec :spc:='SACRAMENTO';
>
> PL/SQL procedure successfully completed.
>
> Elapsed: 00:00:00.00
> SQL> exec :bfd:='2005-12-05';
>
> PL/SQL procedure successfully completed.
>
> Elapsed: 00:00:00.01
> SQL> exec :efd:='2008-12-04 23:59:59';
>
> PL/SQL procedure successfully completed.
>
> Elapsed: 00:00:00.00
> SQL> exec :p1:='SET07%'
>
> PL/SQL procedure successfully completed.
>
> Elapsed: 00:00:00.00
> SQL>
> SQL> SELECT xfi.serv_prov_code,
>   2         xfi.b1_per_id1,
>   3         xfi.b1_per_id2,
>   4         xfi.b1_per_id3,
>   5         xfi.feeitem_seq_nbr,
>   6         xfi.invoice_nbr,
>   7         xfi.gf_fee_period,
>   8         xfi.gf_fee,
>   9         xfi.gf_des,
>  10         xfi.gf_unit,
>  11         xfi.gf_udes,
>  12         finv.invoice_date AS gf_fee_apply_date,
>  13         xfi.feeitem_invoice_status,
>  14         xfi.gf_l1,
>  15         xfi.gf_l2,
>  16         xfi.gf_l3,
>  17         xfi.x4feeitem_invoice_udf1,
>  18         xfi.x4feeitem_invoice_udf2,
>  19         xfi.x4feeitem_invoice_udf3,
>  20         xfi.x4feeitem_invoice_udf4,
>  21         xfi.gf_fee_schedule,
>  22         xfi.fee_schedule_version,
>  23         xfi.rec_date,
>  24         xfi.rec_ful_nam,
>  25         xfi.rec_status,
>  26         f4.GF_COD,
>  27         f4.GF_PRIORITY
>  28    FROM x4feeitem_invoice xfi, setdetails sd, f4invoice finv,
> F4FEEITEM f4
>  29   WHERE sd.serv_prov_code = xfi.serv_prov_code
>  30     AND sd.b1_per_id1 = xfi.b1_per_id1
>  31     AND sd.b1_per_id2 = xfi.b1_per_id2
>  32     AND sd.b1_per_id3 = xfi.b1_per_id3
>  33     AND xfi.serv_prov_code = f4.serv_prov_code
>  34     AND xfi.b1_per_id1 = f4.b1_per_id1
>  35     AND xfi.b1_per_id2 = f4.b1_per_id2
>  36     AND xfi.b1_per_id3 = f4.b1_per_id3
>  37     And xfi.feeitem_seq_nbr = f4.feeitem_seq_nbr
>  38     AND finv.serv_prov_code = xfi.serv_prov_code
>  39     AND finv.invoice_nbr = xfi.invoice_nbr
>  40     AND sd.serv_prov_code = :spc
>  41     AND upper(sd.set_id) = :p1
>  42     AND xfi.rec_status = 'A'
>  43     AND xfi.feeitem_invoice_status = 'INVOICED'
>  44   ORDER BY gf_fee_apply_date
>  45  /
>
> no rows selected
>
> Elapsed: 00:02:15.28
>
> Execution Plan
> ----------------------------------------------------------
> Plan hash value: 3748720781
>
> ---------------------------------------------------------------------------­-----
> ----------------------------
>
> | Id  | Operation                       | Name                     |
> Rows  | Byt
> es | Cost (%CPU)| Time     |
>
> ---------------------------------------------------------------------------­-----
> ----------------------------
>
> |   0 | SELECT STATEMENT                |                          |
> 103 | 242
> 05 |     9   (0)| 00:00:01 |
>
> |   1 |  NESTED LOOPS                   |
> |       |
>    |            |          |
>
> |   2 |   NESTED LOOPS                  |                          |
> 103 | 242
> 05 |     9   (0)| 00:00:01 |
>
> |   3 |    NESTED LOOPS                 |
> |     3 |   5
> 79 |     8   (0)| 00:00:01 |
>
> |   4 |     NESTED LOOPS                |
> |    39 |  60
> 45 |     4   (0)| 00:00:01 |
>
> |   5 |      TABLE ACCESS BY INDEX ROWID| F4INVOICE                |
> 60771 |  14
> 24K|     1   (0)| 00:00:01 |
>
> |*  6 |       INDEX RANGE SCAN          | F4INVOICE_DATE_IX
> |    27 |
>    |     1   (0)| 00:00:01 |
>
> |*  7 |      TABLE ACCESS BY INDEX ROWID| X4FEEITEM_INVOICE
> |     1 |   1
> 31 |     1   (0)| 00:00:01 |
>
> |*  8 |       INDEX RANGE SCAN          | X4FEEITEM_INVOICE_NBR_IX
> |     1 |
>    |     1   (0)| 00:00:01 |
>
> |*  9 |     TABLE ACCESS BY INDEX ROWID | SETDETAILS
> |     1 |
> 38 |     1   (0)| 00:00:01 |
>
> |* 10 |      INDEX RANGE SCAN           | SETDETAILS_PID_IX
> |     1 |
>    |     1   (0)| 00:00:01 |
>
> |* 11 |    INDEX UNIQUE SCAN            | F4FEEITEM_PK
> |     1 |
>    |     1   (0)| 00:00:01 |
>
> |  12 |   TABLE ACCESS BY INDEX ROWID   | F4FEEITEM
> |    34 |  14
> 28 |     1   (0)| 00:00:01 |
>
> ---------------------------------------------------------------------------­-----
> ----------------------------
>
> Predicate Information (identified by operation id):
> ---------------------------------------------------
>
>    6 - access("FINV"."SERV_PROV_CODE"=:SPC)
>    7 - filter("XFI"."FEEITEM_INVOICE_STATUS"='INVOICED' AND
> "XFI"."REC_STATUS"='
> A')
>
>    8 - access("XFI"."SERV_PROV_CODE"=:SPC AND
> "FINV"."INVOICE_NBR"="XFI"."INVOIC
> E_NBR")
>
>    9 - filter(UPPER("SET_ID")=:P1)
>   10 - access("SD"."SERV_PROV_CODE"=:SPC AND
> "SD"."B1_PER_ID1"="XFI"."B1_PER_ID1
> " AND
>
>               "SD"."B1_PER_ID2"="XFI"."B1_PER_ID2" AND
> "SD"."B1_PER_ID3"="XFI"."
> B1_PER_ID3")
>
>   11 - access("F4"."SERV_PROV_CODE"=:SPC AND
> "XFI"."B1_PER_ID1"="F4"."B1_PER_ID1
> " AND
>
>               "XFI"."B1_PER_ID2"="F4"."B1_PER_ID2" AND
> "XFI"."B1_PER_ID3"="F4"."
> B1_PER_ID3" AND
>
>               "XFI"."FEEITEM_SEQ_NBR"="F4"."FEEITEM_SEQ_NBR")
>
> Statistics
> ----------------------------------------------------------
>           0  recursive calls
>           0  db block gets
>     2891740  consistent gets
>       25708  physical reads
>           0  redo size
>        1763  bytes sent via SQL*Net to client
>         380  bytes received via SQL*Net from client
>           1  SQL*Net roundtrips to/from client
>           0  sorts (memory)
>           0  sorts (disk)
> 0       rows processed
> SQL> exit

(snip)

Autotrace may lie - it does not necessarily show the actual execution plan. This is especially a problem when bind variables are used as bind variable peeking does not happen, and all bind variables are treated as VARCHAR2 type columns. To see the actual execution plan, disable autotrace and include the hint /*+ GATHER_PLAN_STATISTICS */ immediately after the SELECT keyword. Then use the following to display the actual execution plan with estimated and actual rows:   SELECT
    *
  FROM
    TABLE (DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST')); (If you do not use the hint, it is possible to specify NULL for the last parameter to return the actual execution plan with just the estimated cardinality and costs.)

Note the 2,891,740 consistent gets for the slow execution compared to the 3 consistent gets with the "fast" execution without the ORDER BY clause. It *could* very well be the case in the slow execution that a previous execution used different bind variable values which were "peeked" at, creating an appropriate execution plan for a query with a large number of rows to be processed. By removing the ORDER BY clause, you forced a hard parse of the SQL statement, which caused the optimizer again to peek at the bind variables to determine a good execution plan.

You will probably find on Oracle 11.1.0.6 and above that the optimizer will eventually re-hard parse the SQL statement when it recognizes that the execution plan should be bind variable sensitive - it might take a couple executions of the SQL statement before the optimizer switches to bind aware versions of the execution plans.

Note also that it is possible that the object statistics and optimizer parameters (FIRST_ROWS_n, for example) differ between the Oracle versions.

David's suggestion of a 10053 trace is a good one - just keep in mind that such traces only appear during a hard parse.

Charles Hooper
IT Manager/Oracle DBA
K&M Machine-Fabricating, Inc. Received on Tue Nov 03 2009 - 10:22:38 CST

Original text of this message