Mohamed Houri’s Oracle Notes

December 22, 2011

On tuning via explain plan

Filed under: explain plan — hourim @ 4:46 pm

Explain plan taken from memory, i.e. explain plan generated by the dbms_xplan.display_cursor () function, contains important information such as where time is most spent by the related query operations and, hence, on which operations the tuning effort should be concentrated.   As far as it is well known that a picture is worth a thousand words, let me then present you with a real life explain plan I have used to diagnose the cause of a query performing badly in production and which I have used also to tune this query using the valuable information delivered by this explain plan (I have edited a little bit this explain plan for clarity):


-------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                                     | Name                          | Starts | E-Rows | A-Rows A-Time       |
---------------------------------------------------------------------------------------------------------------------------------
|   1 |  SORT UNIQUE                                  |                               |      1 |      2 |   3494 |00:00:11.41 |
|   2 |   UNION-ALL                                   |                               |      1 |        |   3497 |00:00:11.38 |
|*  3 |    FILTER                                     |                               |      1 |        |   3482 |00:00:11.29 |
|*  4 |     FILTER                                    |                               |      1 |        |   4309 |00:00:11.27 |
|*  5 |      HASH JOIN OUTER                          |                               |      1 |      1 |   4309 |00:00:11.27 |
|   6 |       NESTED LOOPS OUTER                      |                               |      1 |      1 |   4309 |00:00:11.15 |
|   7 |        NESTED LOOPS                           |                               |      1 |      1 |   4309 |00:00:11.03 |
|   8 |         NESTED LOOPS OUTER                    |                               |      1 |      1 |   4309 |00:00:10.90 |
|   9 |          NESTED LOOPS OUTER                   |                               |      1 |      1 |   4309 |00:00:10.76 |
|  10 |           NESTED LOOPS                        |                               |      1 |      1 |   3482 |00:00:10.57 |
|  11 |            NESTED LOOPS OUTER                 |                               |      1 |      1 |   3482 |00:00:10.00 |
|  12 |             TABLE ACCESS BY GLOBAL INDEX ROWID| SXPS_P_ACCNT_AMPM_J_ICIPD     |      1 |      1 |   1534 |00:00:03.27 |
|* 13 |              INDEX RANGE SCAN                 | SXPS_JTPP_PTC_DAT_ACC_HR_NI   |      1 |      1 |   1534 |00:00:00.20 |
|  14 |             PARTITION RANGE ITERATOR          |                               |   1534 |      1 |   3222 |00:00:06.73 |
|* 15 |              TABLE ACCESS BY LOCAL INDEX ROWID| SXPS_SIGNALIS                 |   1534 |      1 |   3222 |00:00:06.71 |
|* 16 |               INDEX RANGE SCAN                | SXPS_SIG_NUI_FK_I             |   1534 |      3 |  59193 |00:00:05.58 |
|  17 |            TABLE ACCESS BY GLOBAL INDEX ROWID | SXPS_ACCNT_AMPM_J             |   3482 |      1 |   3482 |00:00:00.56 |
|* 18 |             INDEX UNIQUE SCAN                 | SXPS_NUI_PK                   |   3482 |      1 |   3482 |00:00:00.40 |
|  19 |           PARTITION RANGE ITERATOR            |                               |   3482 |      1 |   1437 |00:00:00.19 |
|  20 |            TABLE ACCESS BY LOCAL INDEX ROWID  | SXPS_ACCNT_COMMENTS           |   3482 |      1 |   1437 |00:00:00.17 |
|* 21 |             INDEX RANGE SCAN                  | SXPS_TRC_NUI_FK_I             |   3482 |      2 |   1437 |00:00:00.14 |
|* 22 |          TABLE ACCESS BY INDEX ROWID          | SXPS_PTREF                    |   4309 |      1 |   4006 |00:00:00.13 |
|* 23 |           INDEX RANGE SCAN                    | SXPS_PTF_PK                   |   4309 |      3 |  17910 |00:00:00.04 |
|* 24 |         TABLE ACCESS BY INDEX ROWID           | SXPS_ICIPD                    |   4309 |      1 |   4309 |00:00:00.12 |
|* 25 |          INDEX RANGE SCAN                     | SXPS_PTC_PK                   |   4309 |      3 |  30163 |00:00:00.04 |
|* 26 |        TABLE ACCESS BY INDEX ROWID            | SXPS_PTREF                    |   4309 |      1 |   4018 |00:00:00.11 |
|* 27 |         INDEX RANGE SCAN                      | SXPS_PTF_PK                   |   4309 |      3 |  18416 |00:00:00.03 |
|  28 |       VIEW                                    |                               |      1 |     28 |   1955 |00:00:00.08 |
|  29 |        HASH GROUP BY                          |                               |      1 |     28 |   1955 |00:00:00.08 |
|  30 |         TABLE ACCESS BY GLOBAL INDEX ROWID    | SXPS_ACCNT_COMMENTS           |      1 |     28 |   1955 |00:00:00.08 |
|* 31 |          INDEX RANGE SCAN                     | SXPS_TRC_COM_FR_NI            |      1 |     29 |   1955 |00:00:00.04 |
|  32 |     SORT AGGREGATE                            |                               |    232 |      1 |    232 |00:00:00.01 |
|  33 |      PARTITION RANGE SINGLE                   |                               |    232 |      1 |    528 |00:00:00.01 |
|* 34 |       TABLE ACCESS BY LOCAL INDEX ROWID       | SXPS_ACCNT_COMMENTS           |    232 |      1 |    528 |00:00:00.01 |
|* 35 |        INDEX RANGE SCAN                       | SXPS_TRC_NUI_FK_I             |    232 |      1 |    528 |00:00:00.01 |
|* 36 |    FILTER                                     |                               |      1 |        |     15 |00:00:00.08 |
|* 37 |     FILTER                                    |                               |      1 |        |     15 |00:00:00.08 |
|* 38 |      HASH JOIN OUTER                          |                               |      1 |      1 |     15 |00:00:00.08 |
|  39 |       NESTED LOOPS OUTER                      |                               |      1 |      1 |     15 |00:00:00.07 |
|  40 |        NESTED LOOPS                           |                               |      1 |      1 |     15 |00:00:00.07 |
|  41 |         NESTED LOOPS                          |                               |      1 |      1 |     15 |00:00:00.07 |
|  42 |          NESTED LOOPS OUTER                   |                               |      1 |      1 |     15 |00:00:00.07 |
|  43 |           NESTED LOOPS OUTER                  |                               |      1 |      1 |     15 |00:00:00.05 |
|  44 |            NESTED LOOPS OUTER                 |                               |      1 |      1 |     15 |00:00:00.03 |
|  45 |             TABLE ACCESS BY GLOBAL INDEX ROWID| SXPS_P_ACCNT_AMPM_J_ICIPD_SUP |      1 |      1 |     14 |00:00:00.03 |
|* 46 |              INDEX RANGE SCAN                 | SXPS_PTPS_PTC_HR_NI           |      1 |      1 |     14 |00:00:00.03 |
|  47 |             PARTITION RANGE ITERATOR          |                               |     14 |     33 |      8 |00:00:00.01 |
|* 48 |              TABLE ACCESS BY LOCAL INDEX ROWID| SXPS_SIGNALIS                 |     14 |     33 |      8 |00:00:00.01 |
|* 49 |               INDEX RANGE SCAN                | SXPS_SIG_NUI_FK_I             |     14 |      3 |    390 |00:00:00.01 |
|* 50 |            TABLE ACCESS BY INDEX ROWID        | SXPS_PTREF                    |     15 |      1 |      8 |00:00:00.02 |
|* 51 |             INDEX RANGE SCAN                  | SXPS_PTF_PK                   |     15 |      3 |     65 |00:00:00.01 |
|* 52 |           TABLE ACCESS BY INDEX ROWID         | SXPS_PTREF                    |     15 |      1 |      8 |00:00:00.02 |
|* 53 |            INDEX RANGE SCAN                   | SXPS_PTF_PK                   |     15 |      3 |     63 |00:00:00.01 |
|  54 |          TABLE ACCESS BY GLOBAL INDEX ROWID   | SXPS_ACCNT_AMPM_J             |     15 |      1 |     15 |00:00:00.01 |
|* 55 |           INDEX UNIQUE SCAN                   | SXPS_NUI_PK                   |     15 |      1 |     15 |00:00:00.01 |
|* 56 |         TABLE ACCESS BY INDEX ROWID           | SXPS_ICIPD                    |     15 |      1 |     15 |00:00:00.01 |
|* 57 |          INDEX RANGE SCAN                     | SXPS_PTC_PK                   |     15 |      3 |    105 |00:00:00.01 |
|  58 |        PARTITION RANGE ITERATOR               |                               |     15 |      1 |      0 |00:00:00.01 |
|  59 |         TABLE ACCESS BY LOCAL INDEX ROWID     | SXPS_ACCNT_COMMENTS           |     15 |      1 |      0 |00:00:00.01 |
|* 60 |          INDEX RANGE SCAN                     | SXPS_TRC_NUI_FK_I             |     15 |      2 |      0 |00:00:00.01 |
|  61 |       VIEW                                    |                               |      1 |     28 |   1955 |00:00:00.01 |
|  62 |        HASH GROUP BY                          |                               |      1 |     28 |   1955 |00:00:00.01 |
|  63 |         TABLE ACCESS BY GLOBAL INDEX ROWID    | SXPS_ACCNT_COMMENTS           |      1 |     28 |   1955 |00:00:00.01 |
|* 64 |          INDEX RANGE SCAN                     | SXPS_TRC_COM_FR_NI            |      1 |     29 |   1955 |00:00:00.01 |
|  65 |     SORT AGGREGATE                            |                               |      0 |      1 |      0 |00:00:00.01 |
|  66 |      PARTITION RANGE SINGLE                   |                               |      0 |      1 |      0 |00:00:00.01 |
|* 67 |       TABLE ACCESS BY LOCAL INDEX ROWID       | SXPS_ACCNT_COMMENTS           |      0 |      1 |      0 |00:00:00.01 |
|* 68 |        INDEX RANGE SCAN                       | SXPS_TRC_NUI_FK_I             |      0 |      1 |      0 |00:00:00.01 |
-------------------------------------------------------------------------------------------------------------------------------

The corresponding SQL query has not been shown intentionally because what I intend to show here is how to enhance a query execution time using exclusively its corresponding explain plan. The predicate part is left outside the picture for the moment.   I will get back to it later in this article. In addition, looking at the Estimations (E-Rows) done by the CBO and the real returned rows (A-Rows), shows clearly that statistics are not up-to-date and should be collected again. However, I am not going to concentrate my effort here on the stale statistics but either on how to point out operations that need to be tuned. It could be that stale statistics are the main problem here, but we will suppose that they aren’t and we will focus our attention on reading explain plan operations.

Having said that, from where are we going to start investigating this complex explain plan?  Well, there are several points in this explain plan to be emphasized:

  1. The total execution time of the query is 11,41 seconds and it returned 3494 rows
---------------------------------------------------------------------------------------------------
| Id  | Operation         | Name                          | Starts | E-Rows | A-Rows |   A-Time   |
---------------------------------------------------------------------------------------------------
|   1 |  SORT UNIQUE      |                               |      1 |      2 |   3494 |00:00:11.41 |

2. There are two sets of operations that are mainly contributing to this 11,41 seconds:

-----------------------------------------------------------------------------------------------------------------
| Id  | Operation                         | Name             | Starts | E-Rows | A-Rows |   A-Time
-----------------------------------------------------------------------------------------------------------------
|  14 |     PARTITION RANGE ITERATOR           |                    |   1534 |   1      |   3222   |00:00:06.73 |
|* 15 |      TABLE ACCESS BY LOCAL INDEX ROWID | SXPS_SIGNALIS      |   1534 |   1      |   3222   |00:00:06.71 |
|* 16 |        INDEX RANGE SCAN                | SXPS_SIG_NUI_FK_I  |   1534 |   3      |  59193   |00:00:05.58 |

-----------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name                     | Starts | E-Rows | A-Rows |   A-Time
-----------------------------------------------------------------------------------------------------------------
|  12 | TABLE ACCESS BY GLOBAL INDEX ROWID| SXPS_P_ACCNT_AMPM_J_ICIPD   |   1     |  1      |   1534 |00:00:03.27|
|* 13 |   INDEX RANGE SCAN                | SXPS_JTPP_PTC_DAT_ACC_HR_NI |   1     |  1      |   1534 |00:00:00.20|

These two sets of operations consume 90% of the total response time which is 10 seconds (6,73+3,27). Let’s now think about how to tune them. Looking at operation 16(INDEX RANGE SCAN) we can notice that it generates 59193 records and feeds back it parent operation 16 (TABLE ACCESS BY GLOBAL INDEX ROWID|) with the corresponding rowid of these 59193 records. The anomaly here is that the parent operation 16 visits the table SXPS_SIGNALIS and discards 55971 records letting only 3222 records to be sent back to its parent operation 14. That is an enormous waste of time and energy which is very often an indication of a non precise index. How would we remedy to this anomaly? And here where the Predicate part of the explain plan comes into play. Each time you see an asterisk in front of an operation Id (|* 15 |) this means that this operation has a predicate part which has to be investigated:

15 - filter("R"."NUM_OR"="P"."NUM_OR")
16 - access("R"."ACCNT_ID"="P"."ACCNT_ID" AND "R"."DAT_ACC"="P"."DAT_ACC")

There is an access predicate on operation 16 (INDEX RANGE SCAN   SXPS_SIG_NUI_FK_I) with ACCNT_ID and DAT_ACC followed by a filter predicate on NUM_OR column done by operation 15 (TABLE ACCESS BY LOCAL INDEX ROWID). The index SXPS_SIG_NUI_FK_I is defined on (ACCNT_ID, DAT_ACC); why not create a precise index with these three critical columns (ACCNT_ID, DAT_ACC, NUM_OR)?

create index MHO_SXPS_REP on SXPS_SIGNALIS(DAT_ACC, ACCNT_ID, NUM_OR);

Now that the new index is in place, queering again gives the new explain plan (in which I am showing only interested operations)

--------------------------------------------------------------------------------------------------------
| Id  | Operation                             | Name             | Starts | E-Rows | A-Rows |   A-Time
--------------------------------------------------------------------------------------------------------
|  15 |    TABLE ACCESS BY GLOBAL INDEX ROWID | SXPS_SIGNALIS    |   1534 |     1  |   3222 |00:00:00.60
|* 16 |      INDEX RANGE SCAN                 | MHO_SXPS_REP     |   1534 |     1  |   3222 |00:00:00.17

With the corresponding predicate part reported here below:

16 - access("R"."DAT_ACC"="P"."DAT_ACC" AND "R"."ACCNT_ID"="P"."ACCNT_ID" AND "R"."NUM_OR"="P"."NUM_OR")

Observe the difference:  the infamous filter on SXPS_SIGNALIS table has gone! The index MHO_SXPS_REP is very precise because all the 3222 rowid passed to its parent operation have been kept and no time has been spent throwing out unnecessary records. The effect of this object change on the execution time is worth noticing: from 6,73 seconds to 0,6 seconds.

What, now, if the access to SXPS_SIGNALIS table is totally eliminated from the query operations?  To do so, we need to know the number of columns that are  selected from this table.  Observing the query reveals that, in addition to the three indexed columns, the query selects from SXPS_SIGNALIS table two supplementary columns, ACC_ID_ORG and ACC_ID_DEST. Let’s then re-create the above index with those two supplementary columns as shown below:

create index SXPS_SIG_NUM_OR_ptf_ni on SXPS_SIGNALIS(DAT_ACC,ACCNT_id, NUM_OR,ACC_ID_ORG, ACC_ID_DEST) compress 2;

I added a compress 2 clause to the creation of this index in order to make it small and to favor its placement on the data buffer cash generating less physical I/O. Compressing an index is a very interesting option that I will discuss about it in another occasion.  Re-executing the same query gives the following new situation:

------------------------------------------------------------------------------------------------------
| Id  | Operation            | Name                          | Starts | E-Rows | A-Rows |   A-Time
------------------------------------------------------------------------------------------------------
|* 14 |  INDEX RANGE SCAN    | SXPS_JTPP_PTC_DAT_ACC_HR_NI   |    1   |    1   |   1534 |00:00:00.26 |
|* 15 |  INDEX RANGE SCAN    | MHO_SXPS_REP                  |   1534 |    1   |   3222 |00:00:00.10 |

15 - access("R"."DAT_ACC"="P"."DAT_ACC" AND "R"."ACCNT_ID"="P"."ACCNT_ID" AND "R"."NUM_OR"="P"."NUM_OR")

Access to the SXPS_SIGNALIS table has gone away. Remains only the access to the new MHO_SXPS_REP index which is completed in 0.1 seconds

At this tuning point, let’s summarise where we stand. We succeed via the creation of a precise index to replace two operations by one operation and to reduce the execution time from 6,73 to 0.1 seconds. No let’s now go further and try to find other oddities in the original explain plan. Look at the following operation and spot the problem:

-----------------------------------------------------------------------------------------------
| Id  | Operation                    | Name           | Starts | E-Rows | A-Rows |   A-Time
-----------------------------------------------------------------------------------------------
|* 24 | TABLE ACCESS BY INDEX ROWID  | SXPS_ICIPD     |   4309 |      1 |   4309 |00:00:00.12 |
|* 25 |  INDEX RANGE SCAN            | SXPS_PTC_PK    |   4309 |      3 |   30163|00:00:00.04 |

24 - filter("S"."VALID_TO_DATE">=SYSDATE@!)
25 - access("S"."ICIPD_NO"="P"."ICIPD_NO" AND "S"."VALID_FROM_DATE"<=SYSDATE@!)

In close comparison to what has been said above, there is here also a waste of time and energy consumed by the parent operation throwing out 25854(30163-4309) records. Generally speaking, each time you see such a kind of situation, you should immediately think about a non precise index. The index used here is, as its name clearly indicates it, the primary key index defined as (ICIPD_NO , VALID_FROM_DATE ) while the query involves (ICIPD_NO , VALID_FROM_DATE, VALID_TO_DATE ).  It seems that there is no such a kind of three columns index. An investigation shows however a presence of the following index SXPS_PTC_DAT_NI(VALID_FROM_DATE, VALID_TO_DATE , ICIPD_NO ). So, why this precise index has not been used?  There is a fairly simple answer to this question: the existing index has not been used because its leading column is used in a range based predicate (“S”.”VALID_TO_DATE”>=SYSDATE@!)and not in the equality ((“S”.”ICIPD_NO”=”P”.”ICIPD_NO”). It is worth advising not to put a column, on which you are going to apply range predicates (>, <), at the leading edge of the index.

To demonstrate this let’s create a new index (SXPS_PTC_PTCNO_VDAT_NI) in which we will change the order of its columns to be (ICIPD_NO , VALID_FROM_DATE , VALID_TO_DATE) and re-execute the query

--------------------------------------------------------------------------------------------------
| Id  | Operation           | Name                     | Starts | E-Rows | A-Rows |   A-Time
--------------------------------------------------------------------------------------------------
|* 17 |  INDEX RANGE SCAN   | SXPS_PTC_PTCNO_VDAT_NI   | 4309   |    3   | 4309   |00:00:00.03   |

17 - access("S"."ICIPD_NO"="P"."ICIPD_NO" AND "S"."VALID_TO_DATE">=SYSDATE@! AND "S"."VALID_FROM_DATE"<=SYSDATE@!)
filter("S"."VALID_TO_DATE">=SYSDATE@!)

The access to the table has gone away and the new index became very precise because its leading column (ICIPD_NO) is the one used in the equality predicate.

The bottom line from this article is

  1. Know how to locate in explain plans operations that are worth considering in the tuning process
  2. Each time a big number of rows is discarded between an index operation and its parent table operation think about creating a precise index. The predicate part of the explain plan will help you finding the appropriate columns that are candidate to be in the precise index
  3. Think carefully when designing a composite index to start this index by columns figuring in an equality predicate and not in a range based predicate.

3 Comments »

  1. Thanks Mohamed!
    Great explanation! A keypoint of the tuning processes finely explained : sharp and detailed!
    It’s been a great help for me and some of my colleagues.

    Mourad

    Comment by Mourad — December 23, 2011 @ 2:08 pm | Reply

  2. Mohamed,
    I have read many times an explain plan and was almost lost with the figures there and also not knew the way how to use it to enhance the perf.
    Your example is straight and the insight is very interesting.
    Thanks a lot for that.

    Younes

    Comment by Younes IDRISSI, PMP — December 23, 2011 @ 2:29 pm | Reply

  3. Mourad, Younes,

    Thanks for your nice and encouraging comments.

    Comment by hourim — December 23, 2011 @ 2:33 pm | Reply


RSS feed for comments on this post. TrackBack URI

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Create a free website or blog at WordPress.com.

Tony's Oracle Tips

Tony Hasler's light hearted approach to learning about Oracle

Richard Foote's Oracle Blog

Focusing Specifically On Oracle Indexes, Database Administration and Some Great Music

Hatem Mahmoud Oracle's blog

Just another Oracle blog : Database topics and techniques

Mohamed Houri’s Oracle Notes

Qui se conçoit bien s’énonce clairement

Oracle Diagnostician

Performance troubleshooting as exact science

Raheel's Blog

Things I have learnt as Oracle DBA

Coskan's Approach to Oracle

What I learned about Oracle

So Many Oracle Manuals, So Little Time

“Books to the ceiling, Books to the sky, My pile of books is a mile high. How I love them! How I need them! I'll have a long beard by the time I read them”—Lobel, Arnold. Whiskers and Rhymes. William Morrow & Co, 1988.

EU Careers info

Your career in the European Union

Carlos Sierra's Tools and Tips

Tools and Tips for Oracle Performance and SQL Tuning

Oracle Scratchpad

Just another Oracle weblog

OraStory

Dominic Brooks on Oracle Performance, Tuning, Data Quality & Sensible Design ... (Now with added Sets Appeal)

%d bloggers like this: