Scripts for showing execution plans via plain SQL and also in Oracle 9i

Hi all,

Here are few scripts which allow you to query SQL execution plans and their execution statistics out from V$SQL_PLAN and V$SQL_PLAN_STATISTICS yourself.

Why would you want to do this as there’s the DBMS_XPLAN.DISPLAY_CURSOR() function in Oracle 10g?

Well, my scripts work also on Oracle 9.2. Also they give you better detail (and flexibility) compared to DBMS_XPLAN.DISPLAY_CURSOR.

Of course in 9i there’s the DBMS_XPLAN.DISPLAY function which you can use in conjuction with EXPLAIN PLAN FOR command, but that approach has problems. EXPLAIN PLAN treats all bind variables as varchar2 datatype, possibly causing the reported execution plan to be different from reality. Also, if you have a long running report from last night and you run explain plan today morning, then if optimizer statistics have changed meanwhile, the explain plan command might come up with a different execution plan again, which is different from reality.

So that’s why in 10g we have the DBMS_XPLAN.DISPLAY_CURSOR which goes directly to required library cache child cursor and extracts (unparses) the execution plan from there. The function uses V$SQL_PLAN% views as its data source. And guess what – these views are there in version 9.2 already! And thats’ where my scripts come in:

Here’s an example. Let’s set statistics_level=all so we get rowsource level execution stats for the cursor (note that this parameter makes your query consume much more CPU so it should only be used at session level for troubleshooting a specific performance issue):

SQL> alter session set statistics_level = all;

Session altered.

SQL> select count(*) from all_users;

  COUNT(*)
----------
        36

I know the hash value of this query, so lets report its execution plan, directly from library cache. This is the REAL execution plan inside that child cursor, not some estimate like EXPLAIN PLAN command gives:

SQL> @xm 3416239794 %

Ch Pr   Op                                                         Objcect                        Optimizer Optim rows Optim bytes Optimizer
ld ed   ID Operation                                               Name                                Cost  from step   from step Mode
-- -- ---- ------------------------------------------------------- ------------------------------ --------- ---------- ----------- ----------
 0       0 SELECT STATEMENT                                                                              14                        ALL_ROWS
         1  SORT AGGREGATE                                                                                           1          15
   A     2   HASH JOIN                                                                                   14         36         540
   A     3    HASH JOIN                                                                                   9         36         432
         4     TABLE ACCESS FULL                                   TS$                                    5         13          39
    F    5     TABLE ACCESS FULL                                   USER$                                  3         36         324
         6    TABLE ACCESS FULL                                    TS$                                    5         13          39

7 rows selected.

Ch Op
ld ID     Predicate Information (identified by operation id):
-- ------ ----------------------------------------------------------------------------------------------------
 0     2  - access("U"."TEMPTS#"="TTS"."TS#")
       3  - access("U"."DATATS#"="DTS"."TS#")
       5  - filter("U"."TYPE#"=1)

XM means eXplain from Memory :)

As we had enabled rowsource level execution stats collection, we can use another script to report the response time and resource consumption at execution plan line level (if you’re interested how Oracle achieves this, check the last part of this blog post)

SQL> @xmsh 3416239794 %

SQL hash value:          3416239794    Cursor address:                  00000003A41E5290    |   Statement first parsed at: 2009-05-26/23:02:16  |  200 seconds ago

 Ch Pr   Op                                                         Object                           ms spent in     Estimated Real #rows  Rowsource Consistent    Current   Physical   Physical    Optimizer
 ld ed   ID Operation                                               Name                               operation   output rows   returned     starts       gets       gets      reads     writes         Cost
--- -- ---- ------------------------------------------------------- ------------------------------ ------------- ------------- ---------- ---------- ---------- ---------- ---------- ---------- ------------
  0       0 SELECT STATEMENT                                                                                                                                                                               14
          1  SORT AGGREGATE                                                                                 2.49             1          1          1         42          0          0          0
    A     2   HASH JOIN                                                                                     2.43            36         36          1         42          0          0          0           14
    A     3    HASH JOIN                                                                                    1.87            36         36          1         24          0          0          0            9
          4     TABLE ACCESS FULL                                   TS$                                      .12            13         13          1         18          0          0          0            5
     F    5     TABLE ACCESS FULL                                   USER$                                    .06            36         36          1          6          0          0          0            3
          6    TABLE ACCESS FULL                                    TS$                                      .05            13         13          1         18          0          0          0            5

 Ch Op
 ld ID     Predicate Information (identified by operation id):
--- ------ ----------------------------------------------------------------------------------------------------
  0     2  - access("U"."TEMPTS#"="TTS"."TS#")
        3  - access("U"."DATATS#"="DTS"."TS#")
        5  - filter("U"."TYPE#"=1)

XMSH means eXplain from Memory with Statistics by Hash value (well it did make sense to me when I wrote the script, you can rename it to something else if you like :)

You may need to make your browser window pretty wide to see the full output to see all the columns reported. I normally run sqlplus in Windows cmd.exe and make the screen buffer wide, so the output doesn’t wrap.

If you want to read what these output columns mean, read my presentation about how SQL plan execution works.

As I mentioned, the above scripts run also on Oracle 9.2 (that’s why I wrote them years ago).

Also there’s one more script, xms.sql which doesn’t take any parameters and shows you the execution plan of the latest SQL executed in current session. It uses v$session.prev_hash_value for determining this. However on Oracle 9.2 the prev_hash_value seems to be incorrectly reset and my script would display you wrong SQL statements execution plan. In 10g onwards Oracle has fixed this problem though. In 9i you need to identify the hash value of the statement and use xmsh.sql instead.

In 10g the xms works ok:

SQL> select count(*) from all_tables;

  COUNT(*)
----------
      1739

1 row selected.

SQL> @xms

SQL hash value:          3565202713    Cursor address:                  00000003A4311930    |   Statement first parsed at: 2009-05-26/23:05:59  |  2 seconds ago

 Ch Pr   Op                                          Object                             ms spent   Estimated Real #rows  Rowsource Consistent    Current   Physical   Physical  Optimizer
 ld ed   ID Operation                                Name                                 in op. output rows   returned     starts       gets       gets      reads     writes       Cost
--- -- ---- ---------------------------------------- ------------------------------ ------------ ----------- ---------- ---------- ---------- ---------- ---------- ---------- ----------
  0       0 SELECT STATEMENT                                                                                                                                                          558
          1  SORT AGGREGATE                                                               418.63           1          1          1       4559          0          1          0
     F    2   FILTER                                                                      416.78                   1739          1       4559          0          1          0
    A     3    HASH JOIN RIGHT OUTER                                                      387.23        1750       1739          1       2568          0          0          0        558
          4     TABLE ACCESS FULL                    USER$                                   .12          74         74          1          6          0          0          0          3
    A     5     HASH JOIN OUTER                                                           377.55        1750       1739          1       2562          0          0          0        555
          6      NESTED LOOPS OUTER                                                       225.00        1750       1739          1       1913          0          0          0        410
    A     7       HASH JOIN                                                               218.02        1750       1739          1       1819          0          0          0        410
          8        TABLE ACCESS FULL                 USER$                                   .11          74         74          1          6          0          0          0          3
    A     9        HASH JOIN                                                              206.61        1750       1739          1       1813          0          0          0        406
    A    10         HASH JOIN RIGHT OUTER                                                  41.63        1750       1750          1       1164          0          0          0        260
         11          TABLE ACCESS FULL               SEG$                                   5.28        5249       5249          1        156          0          0          0         35
    A    12          HASH JOIN                                                             17.97        1750       1750          1       1008          0          0          0        224
         13           MERGE JOIN CARTESIAN                                                  6.62          13         13          1         18          0          0          0          6
    A    14            HASH JOIN                                                            6.40           1          1          1          0          0          0          0          1
     F   15             FIXED TABLE FULL             X$KSPPI                                 .95           1          1          1          0          0          0          0          0
         16             FIXED TABLE FULL             X$KSPPCV                               1.45        1440       1440          1          0          0          0          0          0
         17            BUFFER SORT                                                           .20          13         13          1         18          0          0          0          6
         18             TABLE ACCESS FULL            TS$                                     .09          13         13          1         18          0          0          0          5
     F   19           TABLE ACCESS FULL              TAB$                                   3.55        1750       1750          1        990          0          0          0        218
     F   20         TABLE ACCESS FULL                OBJ$                                  55.26       53718      53716          1        649          0          0          0        146
    A    21       INDEX UNIQUE SCAN                  I_OBJ1                                 3.36           1         92       1739         94          0          0          0          0
         22      TABLE ACCESS FULL                   OBJ$                                   1.26       53728      53727          1        649          0          0          0        144
         23    NESTED LOOPS                                                                25.93           1         69        995       1991          0          1          0          2
    A    24     INDEX RANGE SCAN                     I_OBJAUTH1                            22.25           1        149        995       1991          0          1          0          2
     F   25     FIXED TABLE FULL                     X$KZSRO                                 .91           1         69        149          0          0          0          0          0
     F   26      FIXED TABLE FULL                    X$KZSPR                                 .05          14          1          1          0          0          0          0          0

 Ch Op
 ld ID     Predicate Information (identified by operation id):
--- ------ ----------------------------------------------------------------------------------------------------
  0     2  - filter(("O"."OWNER#"=USERENV('SCHEMAID') OR  IS NOT NULL OR  IS NOT NULL))
        3  - access("CX"."OWNER#"="CU"."USER#")
        5  - access("T"."DATAOBJ#"="CX"."OBJ#")
        7  - access("O"."OWNER#"="U"."USER#")
        9  - access("O"."OBJ#"="T"."OBJ#")
       10  - access("T"."FILE#"="S"."FILE#" AND "T"."BLOCK#"="S"."BLOCK#" AND "T"."TS#"="S"."TS#")
       12  - access("T"."TS#"="TS"."TS#")
       14  - access("KSPPI"."INDX"="KSPPCV"."INDX")
       15  - filter("KSPPI"."KSPPINM"='_dml_monitoring_enabled')
       19  - filter(BITAND("T"."PROPERTY",1)=0)
       20  - filter(BITAND("O"."FLAGS",128)=0)
       21  - access("T"."BOBJ#"="CO"."OBJ#")
       24  - access("OA"."OBJ#"=:B1)
       25  - filter("GRANTEE#"="KZSROROL")
       26  - filter((((-"KZSPRPRV")=(-45) OR (-"KZSPRPRV")=(-47) OR (-"KZSPRPRV")=(-48) OR (-"KZSPRPRV")=(-49)
           OR (-"KZSPRPRV")=(-50)) AND "INST_ID"=USERENV('INSTANCE')))

I haven’t had a need to adjust the scripts to fix the problem what Jonathan Lewis has described earlier, but it should be easily doable (just need to make sure that the connect by recursive loop is done against a materialized resultset of v$sql_plan, not the view itself to avoid excessive latching).

The scripts are downloadable from here:

  • xm.sql – explain from Memory
  • xmsh.sql – eXplain from Memory lookup by Hash value
  • xms.sql – eXplain from Memory (latest SQL in current session)

Update:

If you are on 10g and want to know how to convert SQL_ID’s to hash values for use with my XM scripts, read this:

http://blog.tanelpoder.com/2009/02/22/sql_id-is-just-a-fancy-representation-of-hash-value/

This entry was posted in Oracle and tagged , , , . Bookmark the permalink.

14 Responses to Scripts for showing execution plans via plain SQL and also in Oracle 9i

  1. Timur Akhmadeev says:

    Hello Tanel,

    It’s just amazing that you made all the work I planned to do this week! I had a problem recently with a big query in 9iR2, and since GATHER_PLAN_STATISTICS is not available there, I had to use 10046 trace. But Row Source Operation in a trace processed by tkprof was not accurate: indentations in a plan were completely a mess and not clear. That happens sometimes. I fixed it manually :) but decided to write a script or function similar to DISPLAY_CURSOR. Now I don’t have to, so thank you very much for saving my time!

    About excessive latching with CONNECT BY over v$sql_plan: I guess you mean this (http://orainternals.wordpress.com/2009/03/13/dynamic_plan_table-xkqlfxpl-and-extreme-library-cache-latch-contention/) issue. It may be avoided quite simple with correct CONNECT BY conditions as explained in Bug# 2941533 (Not a bug).

  2. Tanel Poder says:

    Hi Timur,

    It’s great to hear that!

    In 9.2 you can use alter session set statistics_level=all (or alter session set “_rowsource_execution_statistics”=true) to get the stats in v$sql_plan_statistics). Note that I’ve seen a problem in 9.2.0.6 where these stats werent populated even after setting the parameters (for cursors opened from PL/SQL I think). The workaroud is to enable sql_trace as well to get v$sql_plan_statistics populated and then you can use xmsh to report it again.

    Feel free to give any feedback & improvement requests!

  3. Tanel Poder says:

    Regarding the connect by issue, yes the “bug” describes something similar. What needs to be done is that using a WITH subquery (with no_merge and perhaps materialize hint) I would fetch everything relevant to my child cursor only and then run connect by on that. the benefits are that:

    a) we fetch data form v$sql_plan once and revisit the fetched data later. that way we don’t need so much library cache latching if we used connect by directly on the v$sql_plan

    b) the connect by would have less data to walk through

  4. Timur Akhmadeev says:

    Tanel,

    Thanks for the information about issues in 9.2.0.6, I have never seen that behavior.

    >Regarding the connect by issue, yes the “bug” describes something similar
    I would say this is exactly what happens with incrrectly written CONNECT BY, and v$sql_plan is not an exception – something similar is typical for hierarchical queries against complex trees. Yes, data set materialization and subsequent CONNECT BY against it is also a thing to make it work correctly. But MATERIALIZE would require additional work to be done (create in memory GTT, direct path insert plus FTS) + it may not work as expected since MATERIALIZE is undocumented and there are cases when it does not work. I think it should be measured which approach is better, but I prefer straight CONNECT BY.

    Regarding feeadback. I have not used scripts yet, and my first impression is based on your example.
    1) *Maybe* it’s better to have the same naming conventions for columns as DBMS_XPLAN has (E-Rows, A-Rows, etc.)
    2) Your idea about additional information (cursor address, first parsed at + time ago) is quite useful and info sits in right place
    3) Placing additional character(s) to identify type of a predicate (F/A) in a plan is brilliant! It is so good that I think it should be moved to DBMS_XPLAN via enhancement request.

  5. Timur Akhmadeev says:

    >create in memory GTT
    I mean in memory *metadata*

  6. Tanel Poder says:

    The reason why I was thinking about materialize is that if you do that, the connect by will be revisiting in-memory GTT, causing “only” logical IOs. But if you revisit the X$ table you will need to take corresponding library cache latches every time the fixed table rowsource fetches rows from library cache, potentially causing library cache contention and slowing others down.

  7. Timur Akhmadeev says:

    Tanel,

    I’ve tested a little bit queries against v$sql_plan: pure hierarchical query vs. CSE (with + materialize) and subsequent CONNECT BY. Here are some results:
    1) when materialization kicks in everything works perfect (fast, minimum CPU used)
    2) CONNECT BY is slower and more CPU expensive
    3) as I was afraid of, materialization (with a query selecting from v$sql_plan) is not happening in some versions. (+) – works, (-) – no:
    (+) 9.2.0.8 Linux 64bit with RBO (no stats for SYS schema)
    (+) 11.1.0.7 Win XP 32bit
    (-) 10.2.0.3 Linux 32bit
    (-) 10.2.0.4 Win 2000 32bit
    (-) 11.1.0.6 Win 2000 32bit
    It means that there still will be problems accessing v$sql_plan using CONNECT BY in some Oracle versions. They may be avoided using additional “self-made” materialization using additional INSERT into previously created table. This will work always as expected.

  8. Dakshin says:

    is there a way to get older SQL Plans from history tables? Thanks.

  9. JC Dauchy says:

    Just a wee thing, I’ve just spent one day trying to understand why the “xms.sql” script was not finding the right last SQL, I noticed that setting :

    => set serveroutput off

    Correct the problem, otherwise the previous SQL was always ‘DBMS_OUTPUT…’
    This migth help someone..
    Anyway, awesome scripts.

  10. Tanel Poder says:

    @JC Dauchy

    Thanks,

    The problem is not really in xms.sql, it does what it’s supposed to do – it shows the plan for last cursor executed in the session. If you enable dbms_output buffer fetching using set serveroutput on (or some of the scripts do this) then sqlplus will always try to fetch the dbms_output buffer using a call to DBMS_OUTPUT.GET_LINES… and xms ends up showing that as it’s the last command executed by sqlplus.

    So, yep, “set serveroutput off” will disable that behaviour and xms will see the right statement in prev_hash_value…

    Also, on 9i xms won’t work at all as the prev_hash_value doesn’t work properly on 9i. On 9i you’d have to identify the hash value of statement of interest yourself and run @xmsh

  11. JC Dauchy says:

    I noticed the comment about 9i, I saw also a page on Jonathan Lewis website about this behaviour. It took me time since I could believe there was a problem on xms script.

    Thanks

  12. D Owen says:

    Hi Tanel,
    has the link to the scripts been changed, I get a 404 whilst looking for them here and on your e2sn site.

    Thanks

  13. Venkat says:

    Hi tanel,

    Do you have that xmsh & xm scripts. i have downloaded long back and misplaced. We need it for 9i db tuning.

    Thanks
    Venkat

Leave a Reply

Your email address will not be published. Required fields are marked *

You may use these HTML tags and attributes: <a href="" title=""> <abbr title=""> <acronym title=""> <b> <blockquote cite=""> <cite> <code> <del datetime=""> <em> <i> <q cite=""> <strike> <strong>