Xplan: now with “self” measures for row source operations

One of the most useful information that the Oracle kernel attaches to plans in the library cache are measures of various resource consumption figures, such as elapsed time, consistent and current gets, disk reads, etcetera. These can be made available for each plan line (aka "row source operation").

These figures are always cumulative, that is, include both the resource consumed by the line itself and all of its progeny. It is very often extremely useful to exclude the progeny from the measure, to get what we could name the "self" figure (following, of course, the terminology introduced by Cary Millsap and Jeff Holt in their famous book Optimizing Oracle Performance).

My sqlplus script xplan now implements the automatic calculation of the "self" for the most important measures, including elapsed time and buffer gets, the most used ones when tuning a statement.

Let's see an example, and then elaborate on their most important application: as a resource profile when tuning.

A simple example
Here's an illustrative example for the measure "elapsed time":

---------------------------------------------------
|Ela    |Ela+    |Id|Operation                    |
-last----last--------------------------------------
|801,097|       =| 0|SELECT STATEMENT             |
|801,097| +79,017| 1| HASH JOIN                   |
|673,010|+262,274| 2|  TABLE ACCESS BY INDEX ROWID|
|410,736| 410,736| 3|   INDEX FULL SCAN           |
| 49,070|  49,070| 4|  TABLE ACCESS FULL          |
-usec----usec--------------------------------------

The first column ("Ela"), whose values are read straight from v$sql_plan_statistics, is the cumulative elapsed time of each row source operation and all its progeny (children, grandchildren, etc). Hence for example, you can see that line#1 (HASH JOIN) run for 801msec, including the time spent by line #2,3,4 (its progeny).

The second column ("Ela+") is the corresponding "self" column, derived from "Ela" by subtracting the time spent by the children - line#1 has two children (#2 and #4), and hence we get 801-673-49=79msec.

Self measures as a resource profile for the plan
Having the "self" measures available makes extremely easy to identify the most expensive row source operations, which are (usually) the first worth considering when tuning (or studying) a SQL statement. Actually, the "self" set is the resource profile of the plan: it blames each consumer (here, the plan lines) for its share of the resource consumed.

For example, line#3 is the most expensive with its 410 msec worth of time - if we are lucky and can reduce its time consumption almost to zero, we would cut the consumption of the whole statement by (about) 50%. It is definitely a line on which to invest some of our tuning time - by e.g. investigating whether a predicate failed to being pushed down; try building a more optimal (e.g. smaller) index; try hinting it into a "FAST FULL SCAN", etc etc.

The second best option for tuning is line#2, a "TABLE ACCESS BY INDEX ROWID"... maybe we could eliminate it completely by adding the fetched columns at the end of the index read by line#3, thus possibly saving 262msec (about 25%) of time.

And so on.

I have found these "self" figures extremely useful in all my recent tuning projects - I hope that the same could turn true for some of you, and maybe that you could suggest me some way to improve xplan :)


  1. Galo Balda

    Monday, August 27, 2012

    Nice post Alberto. Good to have you back.

  2. Jagjeet Singh

    Tuesday, August 28, 2012

    Nice, Thanks for sharing.

  3. Max

    Monday, November 19, 2012

    Hi Alberto,

    i recently came across you blog and started using the XPLAN script. While playing around with it, i noticed the “self” measure output dose not show up in my output. Going thru your header of xplan, looks like self=y is the default behaviour and still do not get any output for ela/ela+…

    my DB version is 11.2.0.3(hp-ux itanium) and my client is 11.2.0.1(win 7)…. here is how i ran your script by passing the sql_id

    @xplan “” “sql_id=92kcxp7m7n2sk”

    also tried
    @xplan “” “sql_id=92kcxp7m7n2sk” “self=y”

    i am also trying to make my output smaller by getting rid of table info by saying tabinfos=n and still dose not work…maybe i am doing something wrong…here is what i am trying for that

    @xplan “” “sql_id=92kcxp7m7n2sk” “tabinfos=n”

  4. Alberto Dell'Era

    Monday, November 19, 2012

    Hi Max,

    ela is calculated by the kernel only if statistics_level is set to “all”, or if the corresponding hint is specified; have you checked this ?

    Try it for your session:
    alter session set statistics_level=all;

    the correct syntax for specifying more than one option is using a comma-separated list, for example:

    @xplan “%” “sql_id=xxxxxxxxxxx,tabinfos=n,objinfos=n”

    Bonus: you can specify ti and oi for tabinfos and objinfos, respectively

    Happy XPLAnning ;)

  5. Max

    Monday, November 19, 2012

    Thank you Sir for prompt response.

    Looks like statistics_level is set to typical at DB level. and obviously setting statistics_level=all at session level is not going to help me get info for other SQL_ID running in my system. So my question to you is, are there any bad implication of setting statistics_level=all at DB level. If so what are those.

    Also how is the SQL Monitor in OEM getting that same info(elapsed time for each step) with statistics_level=typical.

  6. Alberto Dell'Era

    Monday, November 19, 2012

    statististics_level=all means more resource consumption (CPU especially) to calculate the stats. Before 11g it was also expensive due to the increased number of system OS calls to get the time difference; in 11g that is managed (afaik) by the VKTM process and hence is less expensive. Hence, I wouldn’t recommend setting it instance-wise in production without testing first.

    I don’t know how OEM Sql Monitor is able to do that – unless of course for sessions that have run with the parameter set to all.

    Anyway, if ela is set in v$plan_statistics_all, XPLAN will display it alongside ela+ ; it just displays what it finds …

    ciao
    Al

  7. Max

    Monday, November 19, 2012

    Awesome and Thanks for sharing this with the community.

    God Bless you and your Family.

  8. Alex

    Sunday, March 23, 2014

    Alberto,
    I tried your xplan script for the first time. It doesn’t work for me. I’m always getting ‘no statement found’. I’m using 10.2.0.5 client and i tried the following immediately after running SQL:

    @xplan “sql_id=ghu0r7nfv8h3p”
    @xplan “SELECT%NIKU%”
    @xplan “parsed_by=dba_ora”

    Non of them worked.

    Regards,
    Alex

  9. Alberto Dell'Era

    Sunday, March 23, 2014

    Alex,

    you syntax is wrong, it should be

    @xplan “” “sql_id=ghu0r7nfv8h3p”
    @xplan “SELECT%NIKU%” “”
    @xplan “” “parsed_by=dba_ora”

    you can find documentation for xplan in the header of the main script (xplan.sql) and a detailed showcase in http://www.adellera.it/scripts_etcetera/xplan/index.html

    ciao
    Alberto

  10. Alex

    Sunday, March 23, 2014

    Alberto,

    Thanks a lot. Now it is working.

    Regards,
    Alex

Leave a Comment

Please enclose SQL code inside the tag pair [sql] ... [/sql]

Subscribe without commenting

Links (alphabetical order)

Blogroll (alphabetical order)

Blog Aggregators (alphabetical order)


Switch to our mobile site