New scripts: xb.sql and xbi.sql - Explain Oracle Execution Plans Better! (Part 1)

2019-10-04

As I promised in my previous post, I’m going to blog more frequently for a change. So here’s a blog entry about some “new” Oracle execution plan displaying scripts that I’ve had since 2011 or so - I just tidied them up recently and added some improvements too. My aim in this blog post is not to go deep into SQL tuning topics, but just show what these scripts can do.

The new scripts xb.sql and xbi.sql (eXplain Better and eXplain Better, by sqlId) are in my GitHub repo. Make sure you pull the latest changes as I uploaded v1.00 there today. These tools deserve their own hacking session, but for start I’ll just cover three new aspects of them:

  1. More detailed access/filter predicate info next to plan tree data (Part 1, this post)
  2. More intelligent row-source level execution statistics presentation (Part 2, coming soon)
  3. Calculate Optimizer Cost misestimation factor and demo its effects (Part 3, coming soon)

Before I show these scripts in action, here’s a query plan generated by the built-in DBMS_XPLAN package, some stuff removed for brevity:

SQL> @xi 7hk2m2702ua0g 1

---------------------------------------------------------------------------------------------------
| Id  | Operation                                | Name             | E-Rows |E-Bytes| Cost (%CPU)|
---------------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT                         |                  |        |       |    75 (100)|
|   1 |  NESTED LOOPS OUTER                      |                  |     27 |  3483 |    75   (0)|
|   2 |   NESTED LOOPS                           |                  |      9 |   981 |    48   (0)|
|   3 |    NESTED LOOPS                          |                  |      9 |   531 |    30   (0)|
|   4 |     VIEW                                 |                  |      9 |   117 |    12   (0)|
|*  5 |      COUNT STOPKEY                       |                  |        |       |            |
|   6 |       TABLE ACCESS BY INDEX ROWID BATCHED| ORDERS           |      9 |   117 |    12   (0)|
|*  7 |        INDEX RANGE SCAN                  | ORD_WAREHOUSE_IX |   9705 |       |     3   (0)|
|   8 |     TABLE ACCESS BY INDEX ROWID          | ORDERS           |      1 |    46 |     2   (0)|
|*  9 |      INDEX UNIQUE SCAN                   | ORDER_PK         |      1 |       |     1   (0)|
|  10 |    TABLE ACCESS BY INDEX ROWID           | CUSTOMERS        |      1 |    50 |     2   (0)|
|* 11 |     INDEX UNIQUE SCAN                    | CUSTOMERS_PK     |      1 |       |     1   (0)|
|  12 |   TABLE ACCESS BY INDEX ROWID BATCHED    | ORDER_ITEMS      |      3 |    60 |     3   (0)|
|* 13 |    INDEX RANGE SCAN                      | ORDER_ITEMS_PK   |      3 |       |     2   (0)|
---------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------

   5 - filter(ROWNUM<10)
   7 - access("WAREHOUSE_ID"=:B1 AND "ORDER_STATUS"<=4)
   9 - access("NTP"."ORDER_ID"="O"."ORDER_ID")
  11 - access("C"."CUSTOMER_ID"="O"."CUSTOMER_ID")
  13 - access("OI"."ORDER_ID"="O"."ORDER_ID")

The asterisk (”*“) before a plan line shows that there is some kind of a predicate applied within that row source. You’ll have to scroll down to the “Predicate Information” section to see what kind of a predicate it is (filter, access or storage) and see the actual expressions used.

Read my old blog entry to learn about the difference between filter, access and storage predicates.

Now the same output with my new eXplain Better xbi.sql script. I have truncated quite a few columns from the initial output, we’ll get to the others later.

SQL> @xbi 7hk2m2702ua0g 0
-- xbi.sql: eXplain Better v0.99 for sql_id=7hk2m2702ua0g child=0 - by Tanel Poder (https://blog.tanelpoder.com)

         SQL_ID         CHLD ADDRESS          Plan Hash Value First Load Time
-------- ------------- ----- ---------------- --------------- -----------------------------------------------------------------
Cursor:  7hk2m2702ua0g     0 0000000063A2C488      2048963432 Statement first parsed at: 2019-09-18/22:26:59 - 1325 seconds ago

 Pred   Op Par.   #Sib                                                                          Query Block           
 #Col   ID ID     ling Row Source                                                               name                
----- ---- ----- ----- ------------------------------------------------------------------------ -------------------- 
         0  root       SELECT STATEMENT
         1     0     1  NESTED LOOPS OUTER                                                      SEL$2
         2     1     1   NESTED LOOPS
         3     2     1    NESTED LOOPS
         4     3     1     VIEW                                                                 SEL$1
    F    5     4     1      COUNT STOPKEY                                                       SEL$1
         6     5     1       TABLE ACCESS BY INDEX ROWID BATCHED [ORDERS]                       SEL$1
  A#2    7     6     1        INDEX RANGE SCAN [ORD_WAREHOUSE_IX]                               SEL$1
         8     3     2     TABLE ACCESS BY INDEX ROWID [ORDERS]                                 SEL$2
  A#1    9     8     1      INDEX UNIQUE SCAN [ORDER_PK]                                        SEL$2
        10     2     2    TABLE ACCESS BY INDEX ROWID [CUSTOMERS]                               SEL$2
  A#1   11    10     1     INDEX UNIQUE SCAN [CUSTOMERS_PK]                                     SEL$2
        12     1     2   TABLE ACCESS BY INDEX ROWID BATCHED [ORDER_ITEMS]                      SEL$2
  A#1   13    12     1    INDEX RANGE SCAN [ITEM_ORDER_IX]                                      SEL$2

   Op Query Block
   ID name                   Predicate Information (identified by operation id):
----- -------------------- - ---------------------------------------------------------------------------------------
    5 SEL$1                - filter(ROWNUM<10)
    7 SEL$1                - access("WAREHOUSE_ID"=:B1 AND "ORDER_STATUS"<=4)
    9 SEL$2                - access("NTP"."ORDER_ID"="O"."ORDER_ID")
   11 SEL$2                - access("C"."CUSTOMER_ID"="O"."CUSTOMER_ID")
   13 SEL$2                - access("OI"."ORDER_ID"="O"."ORDER_ID")

What are those F and A letters in the first column? Filter and Access. On Exadata you could also see S for Storage on some lines. This makes interpreting large plans a little bit easier as the top section of the plan displays more detail without taking much more space.

What is this number #2 in the A#2 access predicate on line 7? When you look into the actual predicate expression access("WAREHOUSE_ID"=:B1 AND "ORDER_STATUS"<=4), you see it has two conditions that the SQL statement wants to traverse the index with. Let’s see how many columns this ORD_WAREHOUSE_IDX has:

SQL> @ind SOE.ORD_WAREHOUSE_IX
Display indexes where table or index name matches %SOE.ORD_WAREHOUSE_IX%...

TABLE_OWNER   TABLE_NAME          INDEX_NAME              POS# COLUMN_NAME                    DSC
------------- ------------------- ----------------------- ---- ------------------------------ ----
SOE           ORDERS              ORD_WAREHOUSE_IX           1 WAREHOUSE_ID
                                                             2 ORDER_STATUS


INDEX_OWNER   TABLE_NAME          INDEX_NAME              IDXTYPE    UNIQ STATUS   PART TEMP  H     LFBLKS           NDK   NUM_ROWS       CLUF LAST_ANALYZED       DEGREE VISIBILIT
------------- ------------------- ----------------------- ---------- ---- -------- ---- ---- -- ---------- ------------- ---------- ---------- ------------------- ------ ---------
SOE                  ORDERS                         ORD_WAREHOUSE_IX               NORMAL     NO   VALID    NO   N     3      51331          5109   17663470   17509522 2019-09-18 23:36:55 4      VISIBLE

Indeed we have two columns in that particular index and since both of them are the columns used in the access predicate, we can traverse through the index optimally, using both columns’ values at once. And this is why we had A#2 and not A#1 above. So, displaying this “access path efficiency” number for every qualified plan line is very useful in databases with large plans and multi-column indexes. You’d easily see how many columns of your index is this access predicate actually using to navigate to exactly the needed slice of your data, before having to start the inefficient index leaf block linked list hopping to get all the relevant keys. Since all 2 columns of my 2 column index were used in this case and the leading column was searched using an equality condition, the index scan itself was structurally optimal.

Typically you’d want to have less indexes with more columns combined in each to avoid having a single-purpose “personal index” for each different query and report. I’m talking about B-tree/OLTP world here and the exact balance of course depends.

By the way, the numeric part of the A#2 section comes from V$SQL_PLAN.SEARCH_COLUMNS. Oracle docs describe it like this: Number of index columns with start and stop keys (that is, the number of columns with matching predicates).

I won’t go deeper into the index access topic here to keep this article short. But I’ll paste a bit larger plan with more complexity and wider multi-column indexes, so hopefully the value of such detail becomes more obvious. It’s just some random data dictionary query that you can also run. And this time I’m using @xb.sql to report whatever was the last query executed in my own session, so I don’t have to look up the SQL_ID and child number for @xbi.sql:

SQL> SELECT SUM(LENGTH(text)) FROM dba_source WHERE owner = 'SCOTT';

SUM(LENGTH(TEXT))
-----------------


SQL> @xb
-- xb.sql: eXplain Better v0.99 for prev SQL in the current session - by Tanel Poder (https://blog.tanelpoder.com)

         SQL_ID         CHLD ADDRESS          Plan Hash Value First Load Time
-------- ------------- ----- ---------------- --------------- -------------------------------------------------------------------
Cursor:  dwbzd3ktmddzx     0 00000000639462B0      4155363705 Statement first parsed at: 2019-09-19/22:48:13 - 8 seconds ago

 Pred   Op  Par.  #Sib                                                                          Query Block          
 #Col   ID    ID  ling Row Source                                                               name                 
----- ---- ----- ----- ------------------------------------------------------------------------ -------------------- 
         0  root       SELECT STATEMENT                                                                                          
         1     0     1  SORT AGGREGATE                                                          SEL$F5BB74E1
         2     1     1   VIEW  [INT$DBA_SOURCE]                                                 SET$1                            
         3     2     1    UNION-ALL                                                             SET$1
    F    4     3     1     FILTER                                                               SEL$07BDC5B4
         5     4     1      NESTED LOOPS                                                                                         
         6     5     1       NESTED LOOPS                                                                                        
    A    7     6     1        HASH JOIN                                                                                          
         8     7     1         INDEX FULL SCAN [I_USER2]                                        SEL$07BDC5B4                     
         9     7     2         NESTED LOOPS                                                                                      
        10     9     1          TABLE ACCESS BY INDEX ROWID [USER$]                             SEL$07BDC5B4                     
  A#1   11    10     1           INDEX UNIQUE SCAN [I_USER1]                                    SEL$07BDC5B4                     
        12     9     2          TABLE ACCESS BY INDEX ROWID BATCHED [OBJ$]                      SEL$07BDC5B4                     
 FA#1   13    12     1           INDEX RANGE SCAN [I_OBJ5]                                      SEL$07BDC5B4                     
  A#1   14     6     2        INDEX RANGE SCAN [I_SOURCE1]                                      SEL$07BDC5B4                     
        15     5     2       TABLE ACCESS BY INDEX ROWID [SOURCE$]                              SEL$07BDC5B4                     
    F   16     4     2      TABLE ACCESS BY INDEX ROWID BATCHED [USER_EDITIONING$]              SEL$5                            
  A#1   17    16     1       INDEX RANGE SCAN [I_USER_EDITIONING]                               SEL$5                            
    F   18     4     3      TABLE ACCESS BY INDEX ROWID BATCHED [USER_EDITIONING$]              SEL$6                            
  A#1   19    18     1       INDEX RANGE SCAN [I_USER_EDITIONING]                               SEL$6                            
        20     4     4      NESTED LOOPS SEMI                                                   SEL$7                            
 FA#2   21    20     1       INDEX SKIP SCAN [I_USER2]                                          SEL$7                            
  A#3   22    20     2       INDEX RANGE SCAN [I_OBJ4]                                          SEL$7                            
    F   23     3     2     FILTER                                                               SEL$CF5359D5
        24    23     1      NESTED LOOPS                                                                                         
        25    24     1       NESTED LOOPS                                                                                        
        26    25     1        NESTED LOOPS                                                                                       
        27    26     1         TABLE ACCESS BY INDEX ROWID [USER$]                              SEL$CF5359D5                     
  A#1   28    27     1          INDEX UNIQUE SCAN [I_USER1]                                     SEL$CF5359D5                     
        29    26     2         TABLE ACCESS BY INDEX ROWID BATCHED [OBJ$]                       SEL$CF5359D5                     
 FA#2   30    29     1          INDEX RANGE SCAN [I_OBJ5]                                       SEL$CF5359D5         
  A#1   31    25     2        INDEX RANGE SCAN [I_USER2]                                        SEL$CF5359D5                     
    F   32    24     2       FIXED TABLE FIXED INDEX [X$JOXSCD (ind:1)]                         SEL$CF5359D5                     
    F   33    23     2      TABLE ACCESS BY INDEX ROWID BATCHED [USER_EDITIONING$]              SEL$10                           
  A#1   34    33     1       INDEX RANGE SCAN [I_USER_EDITIONING]                               SEL$10                           
    F   35    23     3      TABLE ACCESS BY INDEX ROWID BATCHED [USER_EDITIONING$]              SEL$11                           
  A#1   36    35     1       INDEX RANGE SCAN [I_USER_EDITIONING]                               SEL$11                           
        37    23     4      NESTED LOOPS SEMI                                                   SEL$12                           
 FA#2   38    37     1       INDEX SKIP SCAN [I_USER2]                                          SEL$12                           
  A#3   39    37     2       INDEX RANGE SCAN [I_OBJ4]                                          SEL$12                           

   Op Query Block
   ID name                   Predicate Information (identified by operation id):
----- -------------------- - ----------------------------------------------------------------------------------------------------
    4 SEL$07BDC5B4         - filter((BITAND("U"."SPARE1",16)=0 OR BITAND("O"."FLAGS",1048576)=1048576 OR ("O"."TYPE#"<>88 AND  IS
                             NULL) OR ( IS NOT NULL AND ((SYS_CONTEXT('userenv','current_edition_name')='ORA$BASE' AND
                             "U"."TYPE#"<>2) OR ("U"."TYPE#"=2 AND
                             "U"."SPARE2"=TO_NUMBER(SYS_CONTEXT('userenv','current_edition_id'))) OR  IS NOT NULL))))

    7                      - access("O"."OWNER#"="U"."USER#")
   11 SEL$07BDC5B4         - access("U"."NAME"='SCOTT')
   13 SEL$07BDC5B4         - access("O"."SPARE3"="U"."USER#")
   13 SEL$07BDC5B4         - filter((("O"."TYPE#"=13 AND "O"."SUBNAME" IS NULL) OR INTERNAL_FUNCTION("O"."TYPE#")))
   14 SEL$07BDC5B4         - access("O"."OBJ#"="S"."OBJ#")
   16 SEL$5                - filter("TYPE#"=:B1)
   17 SEL$5                - access("UE"."USER#"=:B1)
   18 SEL$6                - filter("UE"."TYPE#"=:B1)
   19 SEL$6                - access("UE"."USER#"=:B1)
   21 SEL$7                - access("U2"."TYPE#"=2 AND "U2"."SPARE2"=TO_NUMBER(SYS_CONTEXT('userenv','current_edition_id')))
   21 SEL$7                - filter(("U2"."TYPE#"=2 AND "U2"."SPARE2"=TO_NUMBER(SYS_CONTEXT('userenv','current_edition_id'))))
   22 SEL$7                - access("O2"."DATAOBJ#"=:B1 AND "O2"."TYPE#"=88 AND "O2"."OWNER#"="U2"."USER#")
   23 SEL$CF5359D5         - filter((BITAND("U"."SPARE1",16)=0 OR BITAND("O"."FLAGS",1048576)=1048576 OR ("O"."TYPE#"<>88 AND  IS
                             NULL) OR ( IS NOT NULL AND ((SYS_CONTEXT('userenv','current_edition_name')='ORA$BASE' AND
                             "U"."TYPE#"<>2) OR ("U"."TYPE#"=2 AND
                             "U"."SPARE2"=TO_NUMBER(SYS_CONTEXT('userenv','current_edition_id'))) OR  IS NOT NULL))))

   28 SEL$CF5359D5         - access("U"."NAME"='SCOTT')
   30 SEL$CF5359D5         - access("O"."SPARE3"="U"."USER#" AND "O"."TYPE#"=28)
   30 SEL$CF5359D5         - filter("O"."TYPE#"=28)
   31 SEL$CF5359D5         - access("O"."OWNER#"="U"."USER#")
   32 SEL$CF5359D5         - filter("O"."OBJ#"="S"."JOXFTOBN")
   33 SEL$10               - filter("TYPE#"=:B1)
   34 SEL$10               - access("UE"."USER#"=:B1)
   35 SEL$11               - filter("UE"."TYPE#"=:B1)
   36 SEL$11               - access("UE"."USER#"=:B1)
   38 SEL$12               - access("U2"."TYPE#"=2 AND "U2"."SPARE2"=TO_NUMBER(SYS_CONTEXT('userenv','current_edition_id')))
   38 SEL$12               - filter(("U2"."TYPE#"=2 AND "U2"."SPARE2"=TO_NUMBER(SYS_CONTEXT('userenv','current_edition_id'))))
   39 SEL$12               - access("O2"."DATAOBJ#"=:B1 AND "O2"."TYPE#"=88 AND "O2"."OWNER#"="U2"."USER#")

I have highlighted some plan lines of interest above. Let’s start from the line 22 - INDEX RANGE SCAN [I_OBJ4]. It shows A#3 as the predicate summary - it’s passing 3 columns into the index range scan operator:

22 - access("O2"."DATAOBJ#"=:B1 AND "O2"."TYPE#"=88 AND "O2"."OWNER#"="U2"."USER#")

The last expression "O2"."OWNER#"="U2"."USER#" happens to be a dynamic lookup based on a join condition, not a single constant. This is how nested loop joins work if there are suitable indexes on the inner tables of the join.

Let’s describe the index:

SQL> @ind sys.i_obj4
Display indexes where table or index name matches %sys.i_obj4%...

TABLE_OWNER          TABLE_NAME                     INDEX_NAME                     POS# COLUMN_NAME                    DSC
-------------------- ------------------------------ ------------------------------ ---- ------------------------------ ----
SYS                  OBJ$                           I_OBJ4                            1 DATAOBJ#
                                                                                      2 TYPE#
                                                                                      3 OWNER#

This index has 3 columns, exactly the ones used by the SQL predicate. So everything is perfect, we end up with only an access predicate on that line, no further filtering needed. The index scan will return us all the requested and only the requested records.

Now let’s go down to line 30 - INDEX RANGE SCAN [I_OBJ5]. The predicate overview shows FA#2, so there’s some filtering going on in addition to access lookups and two columns are searched via the index access predicate:

30 - access("O"."SPARE3"="U"."USER#" AND "O"."TYPE#"=28)
30 - filter("O"."TYPE#"=28)

Note that there are duplicate predicates, access on O.TYPE# and also filter on O.TYPE# column. Let’s look into the index definition to make sense of this:

SQL> @ind sys.i_obj5
Display indexes where table or index name matches %sys.i_obj5%...

TABLE_OWNER  TABLE_NAME  INDEX_NAME  POS# COLUMN_NAME          DSC
------------ ----------- ----------- ---- -------------------- ----
SYS          OBJ$        I_OBJ5         1 SPARE3
                                        2 NAME
                                        3 NAMESPACE
                                        4 TYPE#
                                        5 OWNER#
                                        6 REMOTEOWNER
                                        7 LINKNAME
                                        8 SUBNAME
                                        9 OBJ#

Wow, this is actually a 9-column index, but the query only uses the two highlighted columns in it. By navigating from root, through branches to a leaf block, we can find exactly where the relevant SPARE3 values start in this index, but since there are a couple of “missing” columns in that index before the TYPE# we are looking for, we can’t just jump to the right TYPE# location, without scanning through a bunch of index leaf blocks organized as a linked list. We will potentially scan (and ignore) lots of different NAMEs, NAMESPACEs and different TYPE#-s until we find the first TYPE#=28 under whatever NAME/NAMESPACE range we happen to be in. And then the process continues, we potentially go to a next NAME/NAMESPACE and scan/discard index entries until we find another TYPE=#28 key.

I once wrote about the unique dynamic lookup capability that only nested loop joins have.

On line 21 (INDEX SKIP SCAN [I_USER2]) we see FA#2 as the predicate summary. Why do we have both filter and access predicates on a single plan line? This is an index access, so it looks like Oracle was able to use two columns for intelligently navigating through the index tree. Let’s see how many columns (and in which order!) do we have in that index:

SQL> @ind sys.I_USER2
Display indexes where table or index name matches %sys.I_USER2%...

TABLE_OWNER     TABLE_NAME      INDEX_NAME         POS# COLUMN_NAME      DSC
--------------- --------------- ------------------ ---- ---------------- ----
SYS             USER$           I_USER2               1 USER#
                                                      2 TYPE#
                                                      3 SPARE1
                                                      4 SPARE2

We have 4 columns in that index. Now let’s look into the actual predicate expressions on that plan line 21:

   21 SEL$7 - access("U2"."TYPE#"=2 AND "U2"."SPARE2"=TO_NUMBER(SYS_CONTEXT('userenv','current_edition_id')))
   21 SEL$7 - filter(("U2"."TYPE#"=2 AND "U2"."SPARE2"=TO_NUMBER(SYS_CONTEXT('userenv','current_edition_id'))))

So, this execution plan is able to pass two non-leading (and non-adjacent) column values into the index skip scan operator according to the access predicate. However, having both of these access predicate columns also show up as filter predicates tells us that this is not a “perfect index scan” that never visits any unnecessary blocks - this is what you get with non-equality predicates on leading index columns, like range scans, between and like% conditions or completely missing predicates that may end up using an index skip scan.

History

Back in Oracle 9i days I also wrote some new scripts called xm.sql and xmsh.sql for displaying Oracle execution plans and published them a few years later. The scripts used V$SQL_PLAN and V$SQL_PLAN_STATISTICS views directly instead of calling DBMS_XPLAN.DISPLAY_CURSOR.

One immediate reason for writing them was that Oracle 9i didn’t even have DBMS_XPLAN.DISPLAY_CURSOR that read the actual plan from library cache, but only DBMS_XPLAN.DISPLAY that required explain plan to be used under the hood, with all its problems. However, the V$SQL_PLAN_STATISTICS[_ALL] views were introduced in Oracle 9i already, so one could easily display actual plans and row-source level statistics easily already in that version.

In the Part 2, I will show the eXplain Better improvements to row source level statistics display, stay tuned! If you want to learn how the row-source dataflow and plan line level statistics measurement works internally, read this article or play my old hacking session video:

That’s all for today!


NB! Check out my 2019 and 2020 online training classes here! Advanced Oracle SQL Tuning training, Practical Linux Performance & Application Troubleshooting training (new), Advanced Oracle Troubleshooting training. In addition to the online classes, all attendees will receive personal downloadable video recordings too!