Execution Plans – What is the Plan, and Where Do I Find It?

30 01 2010

January 30, 2010

(Forward to the Next Post in the Series)

So, what is the plan?  There are a lot of resources available to help with understanding execution plans, some of which are much more effective than others.  The most effective explanations that I have found are in the “Troubleshooting Oracle Performance” book, but the documentation (documentation2) is also helpful from time to time.  There are also a lot of ways to look at execution plans, including directly examining V$SQL_PLAN in recent Oracle releases.  This article shows some of the ways for generating execution plans, and some of the problems that might be encountered when attempting to obtain the “correct” execution plan.

For this blog article, the following script to create test tables will be used:

CREATE TABLE T1 (
  C1 NUMBER,
  C2 VARCHAR2(255),
  PRIMARY KEY (C1));

CREATE TABLE T2 (
  C1 NUMBER,
  C2 VARCHAR2(255),
  PRIMARY KEY (C1));

CREATE TABLE T3 (
  C1 NUMBER,
  C2 VARCHAR2(255));

CREATE TABLE T4 (
  C1 NUMBER,
  C2 VARCHAR2(255));

INSERT INTO
  T1
SELECT
  ROWNUM,
  RPAD(TO_CHAR(ROWNUM),255,'A')
FROM
  DUAL
CONNECT BY
  LEVEL<=1000000;

INSERT INTO
  T2
SELECT
  ROWNUM,
  RPAD(TO_CHAR(ROWNUM),255,'A')
FROM
  DUAL
CONNECT BY
  LEVEL<=1000000;

INSERT INTO
  T3
SELECT
  ROWNUM,
  RPAD(TO_CHAR(ROWNUM),255,'A')
FROM
  DUAL
CONNECT BY
  LEVEL<=1000000;

INSERT INTO
  T4
SELECT
  ROWNUM,
  RPAD(TO_CHAR(ROWNUM),255,'A')
FROM
  DUAL
CONNECT BY
  LEVEL<=1000000;

COMMIT;

EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T1',CASCADE=>TRUE)
EXEC DBMS_STATS.GATHER_TABLE_STATS(OWNNAME=>USER,TABNAME=>'T3',CASCADE=>TRUE)

The above script creates four tables with 1,000,000 rows each.  The first two tables have indexes on the primary key column due to the declared primary key column.  Additionally, the script collects statistics for the first and third tables, but not the second and fourth tables (to help with a couple of demonstrations).

If you are running Oracle 10.1.0.1 or higher, you can use the DBMS_XPLAN.DISPLAY_CURSOR function to display execution plans.  This function is called automatically, starting in Oracle 10.1.0.1, when AUTOTRACE is enabled in SQL*Plus.  DBMS_XPLAN.DISPLAY_CURSOR is the preferred method for displaying execution plans, so we will start with that method.

First, we will generate an execution plan for a SQL statement with the OPTIMIZER_MODE set to ALL_ROWS:

SET LINESIZE 150
ALTER SESSION SET OPTIMIZER_MODE='ALL_ROWS';

SELECT
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN 1 AND 10;

 C1 C2
--- ----------
  1 1AAAAAAAAA
  2 2AAAAAAAAA
  3 3AAAAAAAAA
  4 4AAAAAAAAA
  5 5AAAAAAAAA
  6 6AAAAAAAAA
  7 7AAAAAAAAA
  8 8AAAAAAAAA
  9 9AAAAAAAAA
 10 10AAAAAAAA

The typical way to display an execution plan for a SQL statement that was just executed is as follows (note that the third parameter, the FORMAT parameter, could have also been set to NULL to produce the same result):

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));

SQL_ID  9dq71tc7vasgu, child number 0
-------------------------------------
SELECT   T3.C1,   SUBSTR(T1.C2,1,10) C2 FROM   T3,   T1 WHERE   T1.C1=T3.C1   AND
T1.C1 BETWEEN 1 AND 10

Plan hash value: 1519387310

---------------------------------------------------------------------------------------------
| Id  | Operation                    | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |              |       |       |  1893 (100)|          |
|*  1 |  HASH JOIN                   |              |     9 |  2385 |  1893   (4)| 00:00:09 |
|*  2 |   TABLE ACCESS FULL          | T3           |    10 |    50 |  1888   (4)| 00:00:09 |
|   3 |   TABLE ACCESS BY INDEX ROWID| T1           |    10 |  2600 |     4   (0)| 00:00:01 |
|*  4 |    INDEX RANGE SCAN          | SYS_C0020554 |    10 |       |     3   (0)| 00:00:01 |
---------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - access("T1"."C1"="T3"."C1")
   2 - filter(("T3"."C1"<=10 AND "T3"."C1">=1))
   4 - access("T1"."C1">=1 AND "T1"."C1"<=10)

In the above, note that the calculated cost of the execution plan is 1893.  Now, a little more experimentation, setting OPTIMIZER_MODE to FIRST_ROWS (Oracle assumes that only the first row will be retrieved, and the rest will likely be discarded):

ALTER SESSION SET OPTIMIZER_MODE='FIRST_ROWS_1';

SELECT
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN 1 AND 10;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'TYPICAL'));

SQL_ID  9dq71tc7vasgu, child number 1
-------------------------------------
SELECT   T3.C1,   SUBSTR(T1.C2,1,10) C2 FROM   T3,   T1 WHERE   T1.C1=T3.C1   AND
T1.C1 BETWEEN 1 AND 10

Plan hash value: 2674910673

---------------------------------------------------------------------------------------------
| Id  | Operation                    | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |              |       |       |   575 (100)|          |
|   1 |  NESTED LOOPS                |              |     2 |   530 |   575   (4)| 00:00:03 |
|*  2 |   TABLE ACCESS FULL          | T3           |     7 |    35 |   568   (4)| 00:00:03 |
|   3 |   TABLE ACCESS BY INDEX ROWID| T1           |     1 |   260 |     2   (0)| 00:00:01 |
|*  4 |    INDEX UNIQUE SCAN         | SYS_C0020554 |     1 |       |     1   (0)| 00:00:01 |
---------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - filter(("T3"."C1"<=10 AND "T3"."C1">=1))
   4 - access("T1"."C1"="T3"."C1")
       filter(("T1"."C1"<=10 AND "T1"."C1">=1))

In the above, notice that by changing the optimizer mode from ALL_ROWS to FIRST_ROWS_1 a new execution plan was created (the child number has increased by 1 and the Plan hash value has changed) that now uses a nested loops join, rather than a hash join, and the calculated cost has decreased.  You might be wondering why Oracle did not pick this execution plan with the nested loops join, rather than the hash join when the OPTIMIZER_MODE was set to ALL_ROWS, since this plan has a lower calculated cost – we will leave that for another blog article (unless, of course, someone knows the answer and wants to share).  Oddly, the estimated number of rows to be returned from table T3 has decreased when compared to the execution plan with the hash join, and the estimated execution time has also decreased.  But, we really do not know anything about performance from just looking at the above plans.  So, let’s repeat the test again, changing the SQL statement so that we are able to pass in ‘ALLSTATS LAST’ as the format parameter for the DBMS_XPLAN call:

ALTER SESSION SET OPTIMIZER_MODE='ALL_ROWS';

SELECT /*+ GATHER_PLAN_STATISTICS */
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN 1 AND 10;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  ddnbt67ftu9ds, child number 0
-------------------------------------
SELECT /*+ GATHER_PLAN_STATISTICS */   T3.C1,   SUBSTR(T1.C2,1,10) C2 FROM   T3,
   T1 WHERE   T1.C1=T3.C1   AND T1.C1 BETWEEN 1 AND 10

Plan hash value: 1519387310

-------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name         | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |  OMem |  1Mem | Used-Mem |
-------------------------------------------------------------------------------------------------------------------------------------------
|*  1 |  HASH JOIN                   |              |      1 |      9 |     10 |00:00:04.92 |   37144 |  37125 |  1452K|  1452K| 1328K (0)|
|*  2 |   TABLE ACCESS FULL          | T3           |      1 |     10 |     10 |00:00:00.01 |   37138 |  37125 |       |       |          |
|   3 |   TABLE ACCESS BY INDEX ROWID| T1           |      1 |     10 |     10 |00:00:00.01 |       6 |      0 |       |       |          |
|*  4 |    INDEX RANGE SCAN          | SYS_C0020554 |      1 |     10 |     10 |00:00:00.01 |       4 |      0 |       |       |          |
-------------------------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - access("T1"."C1"="T3"."C1")
   2 - filter(("T3"."C1"<=10 AND "T3"."C1">=1))
   4 - access("T1"."C1">=1 AND "T1"."C1"<=10)

The query completed in 4.92 seconds, retrieved 10 rows, and used 1,328 * 1,024 bytes of memory during the in-memory hash join.  Wow, the full table scan of table T3 completed in 0.01 seconds while reading 37,125 blocks from disk.  If each multiblock disk read were 128 blocks, that would be 290.04 multiblock reads in 0.01 seconds, for an average of  0.000034 seconds per 1MB multiblock read – who needs SSD when you can just read an execution plan incorrectly and make assumptions.  :-)  (Keep reading)

ALTER SESSION SET OPTIMIZER_MODE='FIRST_ROWS_1';

SELECT /*+ GATHER_PLAN_STATISTICS */
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN 1 AND 10;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  ddnbt67ftu9ds, child number 1
-------------------------------------
SELECT /*+ GATHER_PLAN_STATISTICS */   T3.C1,   SUBSTR(T1.C2,1,10) C2 FROM   T3,
   T1 WHERE T1.C1=T3.C1   AND T1.C1 BETWEEN 1 AND 10

Plan hash value: 2674910673

----------------------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name         | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |
----------------------------------------------------------------------------------------------------------------
|   1 |  NESTED LOOPS                |              |      1 |      2 |     10 |00:00:00.02 |   37171 |  37125 |
|*  2 |   TABLE ACCESS FULL          | T3           |      1 |      7 |     10 |00:00:00.02 |   37139 |  37125 |
|   3 |   TABLE ACCESS BY INDEX ROWID| T1           |     10 |      1 |     10 |00:00:00.01 |      32 |      0 |
|*  4 |    INDEX UNIQUE SCAN         | SYS_C0020554 |     10 |      1 |     10 |00:00:00.01 |      22 |      0 |
----------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - filter(("T3"."C1"<=10 AND "T3"."C1">=1))
   4 - access("T1"."C1"="T3"."C1")
       filter(("T1"."C1"<=10 AND "T1"."C1">=1))

As shown above, with the FIRST_ROWS_1 optimizer mode, the query completed in 0.02 seconds.  But, something is wrong.  The execution plan shows that there were 37,125 blocks read from disk, just like the previous execution plan, which would mean that each of the 1MB physical reads required 0.000068 seconds if we only look at the A-Time column of ID 1.  Who needs SSD when you can just read an execution plan incorrectly and make assumptions – oh, wait, I just said that.

The GATHER_PLAN_STATISTICS hint is helpful because it allows DBMS_XPLAN to output the actual execution statistics for the previous SQL statement.  If you do not want to use that hint, it is also possible to change the STATISTICS_LEVEL to ALL at the session level level, as the following demonstrates:

ALTER SESSION SET OPTIMIZER_MODE='ALL_ROWS';
ALTER SESSION SET STATISTICS_LEVEL='ALL';

SELECT
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN 1 AND 10;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  9dq71tc7vasgu, child number 2
-------------------------------------
SELECT   T3.C1,   SUBSTR(T1.C2,1,10) C2 FROM   T3,   T1 WHERE   T1.C1=T3.C1   AND T1.C1 BETWEEN 1 AND 10

Plan hash value: 1519387310

-------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name         | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |  OMem |  1Mem | Used-Mem |
-------------------------------------------------------------------------------------------------------------------------------------------
|*  1 |  HASH JOIN                   |              |      1 |      9 |     10 |00:00:05.59 |   37144 |  37125 |  1452K|  1452K| 1324K (0)|
|*  2 |   TABLE ACCESS FULL          | T3           |      1 |     10 |     10 |00:00:05.59 |   37138 |  37125 |       |       |          |
|   3 |   TABLE ACCESS BY INDEX ROWID| T1           |      1 |     10 |     10 |00:00:00.01 |       6 |      0 |       |       |          |
|*  4 |    INDEX RANGE SCAN          | SYS_C0020554 |      1 |     10 |     10 |00:00:00.01 |       4 |      0 |       |       |          |
-------------------------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - access("T1"."C1"="T3"."C1")
   2 - filter(("T3"."C1"<=10 AND "T3"."C1">=1))
   4 - access("T1"."C1">=1 AND "T1"."C1"<=10)

Note that the change to the STATISTICS_LEVEL caused another hard parse for the SQL statement, and the child number is now listed as 2.  Unlike the case where the GATHER_PLAN_STATISTICS hint was used, this time we see the actual time for the full table scan, rather than 0.01 seconds.  If you look closely, you will also notice that the execution time increased from 4.92 seconds to 5.59 seconds as a result of changing the STATISTICS_LEVEL parameter.

Let’s try again with the FIRST_ROWS_1 value specified for OPTIMIZER_MODE.

ALTER SESSION SET OPTIMIZER_MODE='FIRST_ROWS_1';

SELECT
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN 1 AND 10;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  9dq71tc7vasgu, child number 3
-------------------------------------
SELECT   T3.C1,   SUBSTR(T1.C2,1,10) C2 FROM   T3,   T1 WHERE   T1.C1=T3.C1   AND T1.C1 BETWEEN 1 AND 10

Plan hash value: 2674910673

----------------------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name         | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |
----------------------------------------------------------------------------------------------------------------
|   1 |  NESTED LOOPS                |              |      1 |      2 |     10 |00:00:04.79 |   37171 |  37125 |
|*  2 |   TABLE ACCESS FULL          | T3           |      1 |      7 |     10 |00:00:04.79 |   37139 |  37125 |
|   3 |   TABLE ACCESS BY INDEX ROWID| T1           |     10 |      1 |     10 |00:00:00.01 |      32 |      0 |
|*  4 |    INDEX UNIQUE SCAN         | SYS_C0020554 |     10 |      1 |     10 |00:00:00.01 |      22 |      0 |
----------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   2 - filter(("T3"."C1"<=10 AND "T3"."C1">=1))
   4 - access("T1"."C1"="T3"."C1")
       filter(("T1"."C1"<=10 AND "T1"."C1">=1))

Note again that there was a hard parse, and the child number increased by 1.  This time, rather than completing in 0.02 seconds, the query required 4.79 seconds, with most of that time attributed to the full table scan.  It is odd that the optimizer predicted that only 2 rows would be returned, rather than 9 or 10 rows.

Let’s try again, this time using bind variables rather than constants (literals):

ALTER SESSION SET OPTIMIZER_MODE='ALL_ROWS';
ALTER SESSION SET STATISTICS_LEVEL='TYPICAL';

VARIABLE N1 NUMBER
VARIABLE N2 NUMBER
EXEC :N1:=1
EXEC :N2:=10

SELECT /*+ GATHER_PLAN_STATISTICS */
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN :N1 AND :N2;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  cvq22z77c8fww, child number 0
-------------------------------------
SELECT /*+ GATHER_PLAN_STATISTICS */   T3.C1,   SUBSTR(T1.C2,1,10) C2 FROM   T3,
   T1 WHERE   T1.C1=T3.C1   AND T1.C1 BETWEEN :N1 AND :N2

Plan hash value: 3807353021

--------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name         | Starts | E-Rows | A-Rows|   A-Time   | Buffers | Reads  |  OMem |  1Mem | Used-Mem |
--------------------------------------------------------------------------------------------------------------------------------------------
|*  1 |  FILTER                       |              |      1 |        |     10|00:00:05.60 |   37144 |  37125 |       |       |          |
|*  2 |   HASH JOIN                   |              |      1 |      9 |     10|00:00:05.60 |   37144 |  37125 |  1452K|  1452K| 1328K (0)|
|*  3 |    TABLE ACCESS FULL          | T3           |      1 |     10 |     10|00:00:00.69 |   37138 |  37125 |       |       |          |
|   4 |    TABLE ACCESS BY INDEX ROWID| T1           |      1 |     10 |     10|00:00:00.01 |       6 |      0 |       |       |          |
|*  5 |     INDEX RANGE SCAN          | SYS_C0020554 |      1 |     10 |     10|00:00:00.01 |       4 |      0 |       |       |          |
--------------------------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(:N1<=:N2)
   2 - access("T1"."C1"="T3"."C1")
   3 - filter(("T3"."C1"<=:N2 AND "T3"."C1">=:N1))
   5 - access("T1"."C1">=:N1 AND "T1"."C1"<=:N2)

Same execution plan as we saw earlier, with the same cardinality estimates due to bind variable peeking, except now there is a FILTER operation AT ID 1 with a predicate that states that the N1 bind variable must be less than or equal to the N2 bind variable – this is an automatically generated predicate caused by the BETWEEN syntax in the SQL statement.

Now we change the value of the second bind variable to a much larger value:

EXEC :N2:=500000

SELECT /*+ GATHER_PLAN_STATISTICS */
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN :N1 AND :N2;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  cvq22z77c8fww, child number 0
-------------------------------------
SELECT /*+ GATHER_PLAN_STATISTICS */   T3.C1,   SUBSTR(T1.C2,1,10) C2 FROM   T3,
   T1 WHERE   T1.C1=T3.C1   AND T1.C1 BETWEEN :N1 AND :N2

Plan hash value: 3807353021

--------------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name         | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  | Writes |  OMem |  1Mem | Used-Mem |Used-Tmp|
--------------------------------------------------------------------------------------------------------------------------------------------------------------
|*  1 |  FILTER                       |              |      1 |        |    500K|00:00:18.48 |     105K|  61283 |   4995 |       |       |          |        |
|*  2 |   HASH JOIN                   |              |      1 |      9 |    500K|00:00:17.98 |     105K|  61283 |   4995 |    15M|  3722K|   18M (1)|  43008 |
|*  3 |    TABLE ACCESS FULL          | T3           |      1 |     10 |    500K|00:00:01.51 |   37138 |  37125 |      0 |       |       |          |        |
|   4 |    TABLE ACCESS BY INDEX ROWID| T1           |      1 |     10 |    500K|00:00:11.50 |   68480 |  19163 |      0 |       |       |          |        |
|*  5 |     INDEX RANGE SCAN          | SYS_C0020554 |      1 |     10 |    500K|00:00:01.00 |   25893 |    648 |      0 |       |       |          |        |
--------------------------------------------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(:N1<=:N2)
   2 - access("T1"."C1"="T3"."C1")
   3 - filter(("T3"."C1"<=:N2 AND "T3"."C1">=:N1))
   5 - access("T1"."C1">=:N1 AND "T1"."C1"<=:N2)

In the above, notice that there was no hard parse (same SQL_ID and child number as we saw earlier), and the E-Rows column is the same for the two DBMS_XPLAN outputs.  The Used-Tmp column indicates that the hash join spilled to disk during the previous execution, using 43008 * 1024 bytes of space in the TEMP tablespace.  Let’s repeat the test with the altered OPTIMIZER_MODE:

EXEC :N2:=10
ALTER SESSION SET OPTIMIZER_MODE='FIRST_ROWS_1';

SELECT /*+ GATHER_PLAN_STATISTICS */
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN :N1 AND :N2;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  cvq22z77c8fww, child number 1
-------------------------------------
SELECT /*+ GATHER_PLAN_STATISTICS */   T3.C1,   SUBSTR(T1.C2,1,10) C2 FROM   T3,
   T1 WHERE T1.C1=T3.C1   AND T1.C1 BETWEEN :N1 AND :N2

Plan hash value: 3268213130

----------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name         | Starts | E-Rows | A-Rows|   A-Time   | Buffers | Reads  |
----------------------------------------------------------------------------------------------------------------
|*  1 |  FILTER                       |              |      1 |        |     10|00:00:00.01 |   37171 |  37125 |
|   2 |   NESTED LOOPS                |              |      1 |      2 |     10|00:00:00.01 |   37171 |  37125 |
|*  3 |    TABLE ACCESS FULL          | T3           |      1 |      7 |     10|00:00:00.01 |   37139 |  37125 |
|   4 |    TABLE ACCESS BY INDEX ROWID| T1           |     10 |      1 |     10|00:00:00.01 |      32 |      0 |
|*  5 |     INDEX UNIQUE SCAN         | SYS_C0020554 |     10 |      1 |     10|00:00:00.01 |      22 |      0 |
----------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(:N1<=:N2)
   3 - filter(("T3"."C1"<=:N2 AND "T3"."C1">=:N1))
   5 - access("T1"."C1"="T3"."C1")
       filter(("T1"."C1"<=:N2 AND "T1"."C1">=:N1))

EXEC :N2:=500000

SELECT /*+ GATHER_PLAN_STATISTICS */
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN :N1 AND :N2;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  cvq22z77c8fww, child number 1
-------------------------------------
SELECT /*+ GATHER_PLAN_STATISTICS */   T3.C1,   SUBSTR(T1.C2,1,10) C2 FROM   T3,
   T1 WHERET1.C1=T3.C1   AND T1.C1 BETWEEN :N1 AND :N2

Plan hash value: 3268213130

-----------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name         | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |
-----------------------------------------------------------------------------------------------------------------
|*  1 |  FILTER                       |              |      1 |        |    500K|00:00:18.03 |    1603K|  56267 |
|   2 |   NESTED LOOPS                |              |      1 |      2 |    500K|00:00:17.53 |    1603K|  56267 |
|*  3 |    TABLE ACCESS FULL          | T3           |      1 |      7 |    500K|00:00:04.51 |   70472 |  37125 |
|   4 |    TABLE ACCESS BY INDEX ROWID| T1           |    500K|      1 |    500K|00:00:13.43 |    1533K|  19142 |
|*  5 |     INDEX UNIQUE SCAN         | SYS_C0020554 |    500K|      1 |    500K|00:00:04.21 |    1033K|    637 |
-----------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(:N1<=:N2)
   3 - filter(("T3"."C1"<=:N2 AND "T3"."C1">=:N1))
   5 - access("T1"."C1"="T3"."C1")
       filter(("T1"."C1"<=:N2 AND "T1"."C1">=:N1))

18.03 seconds to execute the SQL statement with OPTIMIZER_MODE set to FIRST_ROWS_1 and 18.48 seconds with OPTIMIZER_MODE set to ALL_ROWS (and 0.01 seconds compared to 5.60 seconds for the execution retrieving 10 rows).  Obviously, this means that we should be running with OPTIMIZER_MODE set to FIRST_ROWS_1 if we want to optimize performance, right?  Well, in short No.  Maybe this will be something that will be investigated in a later blog article.

Now, turning to the unanalyzed tables.  We modify the original SQL statement using bind variables to point to the two tables without up-to-date statistics on the tables and their indexes:

EXEC :N2:=10
ALTER SESSION SET OPTIMIZER_MODE='ALL_ROWS';

SELECT /*+ GATHER_PLAN_STATISTICS */
  T4.C1,
  SUBSTR(T2.C2,1,10) C2
FROM
  T4,
  T2
WHERE
  T2.C1=T4.C1
  AND T2.C1 BETWEEN :N1 AND :N2;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  94bv1jwkzcc38, child number 0
-------------------------------------
SELECT /*+ GATHER_PLAN_STATISTICS */   T4.C1,   SUBSTR(T2.C2,1,10) C2 FROM   T4,
   T2 WHERE   T2.C1=T4.C1   AND T2.C1 BETWEEN :N1 AND :N2

Plan hash value: 3374068464

-------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name         | Starts | E-Rows | A-Rows|   A-Time   | Buffers | Reads  |  OMem |  1Mem | Used-Mem |
-------------------------------------------------------------------------------------------------------------------------------------------
|*  1 |  FILTER                       |              |      1 |        |     10|00:00:00.01 |   74124 |  36361 |       |       |          |
|*  2 |   HASH JOIN                   |              |      1 |     10 |     10|00:00:00.01 |   74124 |  36361 |   711K|   711K| 1087K (0)|
|   3 |    TABLE ACCESS BY INDEX ROWID| T2           |      1 |     10 |     10|00:00:00.01 |       5 |      1 |       |       |          |
|*  4 |     INDEX RANGE SCAN          | SYS_C0020555 |      1 |     10 |     10|00:00:00.01 |       3 |      0 |       |       |          |
|*  5 |    TABLE ACCESS FULL          | T4           |      1 |    408 |     10|00:00:00.01 |   74119 |  36360 |       |       |          |
-------------------------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(:N1<=:N2)
   2 - access("T2"."C1"="T4"."C1")
   4 - access("T2"."C1">=:N1 AND "T2"."C1"<=:N2)
   5 - filter(("T4"."C1">=:N1 AND "T4"."C1"<=:N2))

Note
-----
   - dynamic sampling used for this statement

The only change here is that Oracle is now estimating that 10 rows will be returned rather than the 9 we saw earlier, and the note below the predicate information heading that states that dynamic sampling was used, oh – and the order of the row sources directly below the HASH JOIN line in the plan has changed (is this a problem?).  Maybe dynamic sampling will be a topic for another blog article, but the topic is discussed in various books and articles on the Internet.

ALTER SESSION SET OPTIMIZER_MODE='FIRST_ROWS_1';

SELECT /*+ GATHER_PLAN_STATISTICS */
  T4.C1,
  SUBSTR(T2.C2,1,10) C2
FROM
  T4,
  T2
WHERE
  T2.C1=T4.C1
  AND T2.C1 BETWEEN :N1 AND :N2;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  94bv1jwkzcc38, child number 1
-------------------------------------
SELECT /*+ GATHER_PLAN_STATISTICS */   T4.C1,   SUBSTR(T2.C2,1,10) C2 FROM   T4,
   T2 WHERE   T2.C1=T4.C1   AND T2.C1 BETWEEN :N1 AND :N2

Plan hash value: 3374068464

--------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name         | Starts | E-Rows | A-Rows|   A-Time   | Buffers | Reads  |  OMem |  1Mem | Used-Mem |
--------------------------------------------------------------------------------------------------------------------------------------------
|*  1 |  FILTER                       |              |      1 |        |     10|00:00:00.01 |   37143 |  37120 |       |       |          |
|*  2 |   HASH JOIN                   |              |      1 |     10 |     10|00:00:00.01 |   37143 |  37120 |   711K|   711K| 1087K (0)|
|   3 |    TABLE ACCESS BY INDEX ROWID| T2           |      1 |     10 |     10|00:00:00.01 |       4 |      0 |       |       |          |
|*  4 |     INDEX RANGE SCAN          | SYS_C0020555 |      1 |     10 |     10|00:00:00.01 |       3 |      0 |       |       |          |
|*  5 |    TABLE ACCESS FULL          | T4           |      1 |   2307 |     10|00:00:00.01 |   37139 |  37120 |       |       |          |
--------------------------------------------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(:N1<=:N2)
   2 - access("T2"."C1"="T4"."C1")
   4 - access("T2"."C1">=:N1 AND "T2"."C1"<=:N2)
   5 - filter(("T4"."C1">=:N1 AND "T4"."C1"<=:N2))

Note
-----
   - dynamic sampling used for this statement

OK, this plan changed a bit from when the SQL statement referenced tables T1 and T3.  The execution plan is no longer using a nested loops join – in fact it is using the same plan as was used when the OPTIMIZER_MODE was set to ALL_ROWS.

Oracle 9i and earlier Oracle releases had a default OPTIMIZER_MODE of CHOOSE, so let’s see what happens when we use that optimizer mode with the same two tables:

ALTER SESSION SET OPTIMIZER_MODE='CHOOSE';

SELECT /*+ GATHER_PLAN_STATISTICS */
  T4.C1,
  SUBSTR(T2.C2,1,10) C2
FROM
  T4,
  T2
WHERE
  T2.C1=T4.C1
  AND T2.C1 BETWEEN :N1 AND :N2;

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR(NULL,NULL,'ALLSTATS LAST'));

SQL_ID  94bv1jwkzcc38, child number 2
-------------------------------------
SELECT /*+ GATHER_PLAN_STATISTICS */   T4.C1,   SUBSTR(T2.C2,1,10) C2 FROM   T4,
   T2 WHERE T2.C1=T4.C1   AND T2.C1 BETWEEN :N1 AND :N2

Plan hash value: 1544755769

-------------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name         | Starts | A-Rows |   A-Time   | Buffers | Reads  |
-------------------------------------------------------------------------------------------------------
|   1 |  NESTED LOOPS                |              |      1 |     10 |00:00:00.02 |    2039K|  39001 |
|   2 |   TABLE ACCESS FULL          | T4           |      1 |   1000K|00:00:02.02 |   37139 |  37125 |
|   3 |   TABLE ACCESS BY INDEX ROWID| T2           |   1000K|     10 |00:00:06.80 |    2001K|   1876 |
|*  4 |    INDEX UNIQUE SCAN         | SYS_C0020555 |   1000K|     10 |00:00:04.78 |    2001K|   1876 |
-------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   4 - access("T2"."C1"="T4"."C1")
       filter(("T2"."C1"<=:N2 AND "T2"."C1">=:N1))

Note
-----
   - rule based optimizer used (consider using cbo)

Note that the Note section indicates that the rule based optimizer was used, even though the documentation for Oracle 10.2 states that as of Oracle 10.1 the RULE based optimizer is no longer supported.  Also note that the execution plan is now using a nested loops join, the FILTER operation no longer appears, and the full table scan is listed first below the NESTED LOOPS operation, just as it was when the OPTIMIZER_MODE was set to FIRST_ROWS_1 and the query accessed tables T1 and T3.

Let’s say that we are bored, and did not read chapter 15 by Pete Finnigan in the “Expert Oracle Practices” book… assume that column C1 contains a credit card number.  Now for an experiment, we will retrieve all child cursors for SQL_ID cvq22z77c8fww with the bind variables that were submitted on the initial hard parse - be careful with who has access to this feature in a production environment, as it could expose sensitive information:

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY_CURSOR('cvq22z77c8fww',NULL,'ALLSTATS LAST +PEEKED_BINDS'));

PLAN_TABLE_OUTPUT                                                                                                                                    
------------------------------------------------------------------------------------------------------------------------------------------------------
SQL_ID  cvq22z77c8fww, child number 0                                                                                                                
-------------------------------------                                                                                                                
SELECT /*+ GATHER_PLAN_STATISTICS */   T3.C1,   SUBSTR(T1.C2,1,10) C2 FROM   T3,   T1 WHERE   T1.C1=T3.C1   AND T1.C1 BETWEEN :N1 AND :N2            

Plan hash value: 3807353021                                                                                                                          

------------------------------------------------------------------------------------------------------------------------------------------------------
| Id  | Operation                     | Name         | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |  OMem |  1Mem | Used-Mem | Used-Tmp|
------------------------------------------------------------------------------------------------------------------------------------------------------
|*  1 |  FILTER                       |              |      1 |        |     10 |00:00:04.28 |   37144 |  37125 |       |       |          |         |
|*  2 |   HASH JOIN                   |              |      1 |      9 |     10 |00:00:04.28 |   37144 |  37125 |  1452K|  1452K| 2315K (0)|         |
|*  3 |    TABLE ACCESS FULL          | T3           |      1 |     10 |     10 |00:00:00.01 |   37138 |  37125 |       |       |          |         |
|   4 |    TABLE ACCESS BY INDEX ROWID| T1           |      1 |     10 |     10 |00:00:00.01 |       6 |      0 |       |       |          |         |
|*  5 |     INDEX RANGE SCAN          | SYS_C0020554 |      1 |     10 |     10 |00:00:00.01 |       4 |      0 |       |       |          |         |
------------------------------------------------------------------------------------------------------------------------------------------------------

Peeked Binds (identified by position):                                                                                                               
--------------------------------------                                                                                                               
   1 - (NUMBER): 1                                                                                                                                   
   2 - (NUMBER): 10                                                                                                                                  

Predicate Information (identified by operation id):                                                                                                  
---------------------------------------------------                                                                                                  
   1 - filter(:N1<=:N2)                                                                                                                              
   2 - access("T1"."C1"="T3"."C1")                                                                                                                   
   3 - filter(("T3"."C1"<=:N2 AND "T3"."C1">=:N1))                                                                                                   
   5 - access("T1"."C1">=:N1 AND "T1"."C1"<=:N2)                                                                                                     

-

SQL_ID  cvq22z77c8fww, child number 1                                                                                                                
-------------------------------------                                                                                                                
SELECT /*+ GATHER_PLAN_STATISTICS */   T3.C1,   SUBSTR(T1.C2,1,10) C2 FROM   T3,   T1 WHERE                                                          
T1.C1=T3.C1   AND T1.C1 BETWEEN :N1 AND :N2                                                                                                          

Plan hash value: 3268213130                                                                                                                          
 -----------------------------------------------------------------------------------------------------------------                                    
| Id  | Operation                     | Name         | Starts | E-Rows | A-Rows |   A-Time   | Buffers | Reads  |                                    
-----------------------------------------------------------------------------------------------------------------                                    
|*  1 |  FILTER                       |              |      1 |        |    500K|00:00:18.03 |    1603K|  56267 |                                    
|   2 |   NESTED LOOPS                |              |      1 |      2 |    500K|00:00:17.53 |    1603K|  56267 |                                    
|*  3 |    TABLE ACCESS FULL          | T3           |      1 |      7 |    500K|00:00:04.51 |   70472 |  37125 |                                    
|   4 |    TABLE ACCESS BY INDEX ROWID| T1           |    500K|      1 |    500K|00:00:13.43 |    1533K|  19142 |                                    
|*  5 |     INDEX UNIQUE SCAN         | SYS_C0020554 |    500K|      1 |    500K|00:00:04.21 |    1033K|    637 |                                    
-----------------------------------------------------------------------------------------------------------------                                    

Peeked Binds (identified by position):                                                                                                               
--------------------------------------                                                                                                               
   1 - (NUMBER): 1                                                                                                                                   
   2 - (NUMBER): 10                                                                                                                                  

Predicate Information (identified by operation id):                                                                                                  
---------------------------------------------------                                                                                                  
   1 - filter(:N1<=:N2)                                                                                                                              
   3 - filter(("T3"."C1"<=:N2 AND "T3"."C1">=:N1))                                                                                                   
   5 - access("T1"."C1"="T3"."C1")                                                                                                                   
       filter(("T1"."C1"<=:N2 AND "T1"."C1">=:N1)) 

-

SQL_ID  94bv1jwkzcc38, child number 2
-------------------------------------
SELECT /*+ GATHER_PLAN_STATISTICS */   T4.C1,   SUBSTR(T2.C2,1,10) C2 FROM   T4,
   T2 WHERET2.C1=T4.C1   AND T2.C1 BETWEEN :N1 AND :N2

Plan hash value: 1544755769

-------------------------------------------------------------------------------------------------------
| Id  | Operation                    | Name         | Starts | A-Rows |   A-Time   | Buffers | Reads  |
-------------------------------------------------------------------------------------------------------
|   1 |  NESTED LOOPS                |              |      1 |     10 |00:00:00.02 |    2039K|  39001 |
|   2 |   TABLE ACCESS FULL          | T4           |      1 |   1000K|00:00:02.02 |   37139 |  37125 |
|   3 |   TABLE ACCESS BY INDEX ROWID| T2           |   1000K|     10 |00:00:06.80 |    2001K|   1876 |
|*  4 |    INDEX UNIQUE SCAN         | SYS_C0020555 |   1000K|     10 |00:00:04.78 |    2001K|   1876 |
-------------------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   4 - access("T2"."C1"="T4"."C1")
       filter(("T2"."C1"<=:N2 AND "T2"."C1">=:N1))

Note
-----
   - rule based optimizer used (consider using cbo)

To learn more about DBMS_XPLAN.DISPLAY_CURSOR, see the documenation.

So, what if we want to know why the child cursors were created?  We could do something like this:

DESC V$SQL_SHARED_CURSOR

SET LINESIZE 200
SET HEADING ON
BREAK ON SQL_ID SKIP 1 

SELECT
  *
FROM
  V$SQL_SHARED_CURSOR
WHERE
  SQL_ID='94bv1jwkzcc38';

SQL_ID        ADDRESS          CHILD_ADDRESS    CHILD_NUMBER USOOSLSEBPISTABDLTRIIRLIOSMUTNFAITDLDBPCSRPTMBMROPMFL
------------- ---------------- ---------------- ------------ -----------------------------------------------------
94bv1jwkzcc38 000007FF9829D308 000007FFA68C1038            0 NNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNN
              000007FF9829D308 000007FF94E0D950            1 NNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNYNNNN
              000007FF9829D308 000007FF98046318            2 NNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNNYNNNN

The above shows that the child cursors were created because of an optimizer mode mismatch (yes, we changed the OPTIMIZER_MODE).  We could also check the bind variable definitions (not needed in this case because we used the undocumented PEEKED_BINDS format parameter with DBMS_XPLAN to see most of this information):

SELECT
  S.CHILD_NUMBER CN,
  SBM.*
FROM
  V$SQL_BIND_METADATA SBM,
  V$SQL S
WHERE
  S.SQL_ID='94bv1jwkzcc38'
  AND S.CHILD_ADDRESS=SBM.ADDRESS
ORDER BY
  S.CHILD_NUMBER,
  SBM.POSITION;

 CN ADDRESS            POSITION   DATATYPE MAX_LENGTH  ARRAY_LEN BIND_NAME
--- ---------------- ---------- ---------- ---------- ---------- ---------
  0 000007FFA68C1038          1          2         22          0 N1
  0 000007FFA68C1038          2          2         22          0 N2
  1 000007FF94E0D950          1          2         22          0 N1
  1 000007FF94E0D950          2          2         22          0 N2
  2 000007FF98046318          1          2         22          0 N1
  2 000007FF98046318          2          2         22          0 N2

OK, now that we have moved off on a tangent, let’s return again to the topic of viewing execution plans.  The above examples show the actual execution plan that was used, which may be different from that produced by explain plan.  So, for fun, let’s look at the EXPLAIN PLAN FOR syntax (DBMS_XPLAN.DISPLAY is valid on Oracle 9.2.0.1 and higher):

ALTER SYSTEM FLUSH SHARED_POOL;

ALTER SESSION SET OPTIMIZER_MODE='ALL_ROWS';

EXPLAIN PLAN FOR
SELECT
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN 1 AND 10;

Explained.

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY());

Plan hash value: 1519387310

---------------------------------------------------------------------------------------------
| Id  | Operation                    | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
---------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT             |              |     9 |  2385 |  1893   (4)| 00:00:09 |
|*  1 |  HASH JOIN                   |              |     9 |  2385 |  1893   (4)| 00:00:09 |
|*  2 |   TABLE ACCESS FULL          | T3           |    10 |    50 |  1888   (4)| 00:00:09 |
|   3 |   TABLE ACCESS BY INDEX ROWID| T1           |    10 |  2600 |     4   (0)| 00:00:01 |
|*  4 |    INDEX RANGE SCAN          | SYS_C0020554 |    10 |       |     3   (0)| 00:00:01 |
---------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - access("T1"."C1"="T3"."C1")
   2 - filter("T3"."C1"<=10 AND "T3"."C1">=1)
   4 - access("T1"."C1">=1 AND "T1"."C1"<=10)

The above plan appears to be identical to that of the first of the actual plans.  Now a test with bind variables:

VARIABLE N1 NUMBER
VARIABLE N2 NUMBER
EXEC :N1:=1
EXEC :N2:=10

EXPLAIN PLAN FOR
SELECT
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN :N1 AND :N2;

Explained.

SELECT
  *
FROM
  TABLE(DBMS_XPLAN.DISPLAY());

Plan hash value: 3807353021

----------------------------------------------------------------------------------------------
| Id  | Operation                     | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |              |  2499 |   646K|  2084   (5)| 00:00:10 |
|*  1 |  FILTER                       |              |       |       |            |          |
|*  2 |   HASH JOIN                   |              |  2499 |   646K|  2084   (5)| 00:00:10 |
|*  3 |    TABLE ACCESS FULL          | T3           |  2500 | 12500 |  1905   (5)| 00:00:10 |
|   4 |    TABLE ACCESS BY INDEX ROWID| T1           |  2500 |   634K|   178   (0)| 00:00:01 |
|*  5 |     INDEX RANGE SCAN          | SYS_C0020554 |  4500 |       |    11   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(TO_NUMBER(:N1)<=TO_NUMBER(:N2))
   2 - access("T1"."C1"="T3"."C1")
   3 - filter("T3"."C1">=TO_NUMBER(:N1) AND "T3"."C1"<=TO_NUMBER(:N2))
   5 - access("T1"."C1">=TO_NUMBER(:N1) AND "T1"."C1"<=TO_NUMBER(:N2))

Notice in the above that there are TO_NUMBER entries surrounding each of the bind variables in the Predicate Information section, even though those bind variables were declared as a NUMBER data type.  The cost has also increased a bit.

Let’s use AUTOTRACE to see the execution plan (AUTOTRACE starting in Oracle 10.1.0.1 uses DBMS_XPLAN to output the formatted execution plan).

SET AUTOTRACE TRACEONLY EXPLAIN

SELECT
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN :N1 AND :N2;

Execution Plan
----------------------------------------------------------
Plan hash value: 3807353021

----------------------------------------------------------------------------------------------
| Id  | Operation                     | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |              |  2499 |   646K|  2084   (5)| 00:00:10 |
|*  1 |  FILTER                       |              |       |       |            |          |
|*  2 |   HASH JOIN                   |              |  2499 |   646K|  2084   (5)| 00:00:10 |
|*  3 |    TABLE ACCESS FULL          | T3           |  2500 | 12500 |  1905   (5)| 00:00:10 |
|   4 |    TABLE ACCESS BY INDEX ROWID| T1           |  2500 |   634K|   178   (0)| 00:00:01 |
|*  5 |     INDEX RANGE SCAN          | SYS_C0020554 |  4500 |       |    11   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(TO_NUMBER(:N1)<=TO_NUMBER(:N2))
   2 - access("T1"."C1"="T3"."C1")
   3 - filter("T3"."C1">=TO_NUMBER(:N1) AND "T3"."C1"<=TO_NUMBER(:N2))
   5 - access("T1"."C1">=TO_NUMBER(:N1) AND "T1"."C1"<=TO_NUMBER(:N2))

OK, the same as the previous example on Oracle 10.1.0.1 and above, complete with the incorrect Predicate Information section.  Again, displaying the runtime statistics and explain plan:

SET AUTOTRACE TRACEONLY STATISTICS EXPLAIN

SELECT
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN :N1 AND :N2;

10 rows selected.

Execution Plan
----------------------------------------------------------
Plan hash value: 3807353021

----------------------------------------------------------------------------------------------
| Id  | Operation                     | Name         | Rows  | Bytes | Cost (%CPU)| Time     |
----------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT              |              |  2499 |   646K|  2084   (5)| 00:00:10 |
|*  1 |  FILTER                       |              |       |       |            |          |
|*  2 |   HASH JOIN                   |              |  2499 |   646K|  2084   (5)| 00:00:10 |
|*  3 |    TABLE ACCESS FULL          | T3           |  2500 | 12500 |  1905   (5)| 00:00:10 |
|   4 |    TABLE ACCESS BY INDEX ROWID| T1           |  2500 |   634K|   178   (0)| 00:00:01 |
|*  5 |     INDEX RANGE SCAN          | SYS_C0020554 |  4500 |       |    11   (0)| 00:00:01 |
----------------------------------------------------------------------------------------------

Predicate Information (identified by operation id):
---------------------------------------------------
   1 - filter(TO_NUMBER(:N1)<=TO_NUMBER(:N2))
   2 - access("T1"."C1"="T3"."C1")
   3 - filter("T3"."C1">=TO_NUMBER(:N1) AND "T3"."C1"<=TO_NUMBER(:N2))
   5 - access("T1"."C1">=TO_NUMBER(:N1) AND "T1"."C1"<=TO_NUMBER(:N2))

Statistics
----------------------------------------------------------
          0  recursive calls
          0  db block gets
      37144  consistent gets
      37125  physical reads
          0  redo size
        579  bytes sent via SQL*Net to client
        334  bytes received via SQL*Net from client
          2  SQL*Net roundtrips to/from client
          0  sorts (memory)
          0  sorts (disk)
         10  rows processed

Note that the above plan is not necessarily the actual plan, even though we are looking at the actual runtime statistics.  This could be confusing since we are seeing a rough guess for an execution plan with the actual execution statistics.

For more information about Using EXPLAIN PLAN, see the documentation.

Now, another test.  This time we will instruct Oracle to write the actual execution plan to a trace file every time Oracle must perform a hard parse.  We will force a hard parse by adding a comment to the SQL statement:

ALTER SESSION SET TRACEFILE_IDENTIFIER = '10132_HARD_PARSE';
ALTER SESSION SET EVENTS '10132 TRACE NAME CONTEXT FOREVER, LEVEL 1';

SELECT /* TEST */
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN :N1 AND :N2;

ALTER SESSION SET EVENTS '10132 TRACE NAME CONTEXT OFF';

If we take a look at the output in the trace file, we might see something like this:

sql_id=3g3fc5qyju0j3.
Current SQL statement for this session:
SELECT /* TEST */
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN :N1 AND :N2

============
Plan Table
============
-----------------------------------------------------+-----------------------------------+
| Id  | Operation                      | Name        | Rows  | Bytes | Cost  | Time      |
-----------------------------------------------------+-----------------------------------+
| 0   | SELECT STATEMENT               |             |       |       |  1893 |           |
| 1   |  FILTER                        |             |       |       |       |           |
| 2   |   HASH JOIN                    |             |     9 |  2385 |  1893 |  00:00:09 |
| 3   |    TABLE ACCESS FULL           | T3          |    10 |    50 |  1888 |  00:00:09 |
| 4   |    TABLE ACCESS BY INDEX ROWID | T1          |    10 |  2600 |     4 |  00:00:01 |
| 5   |     INDEX RANGE SCAN           | SYS_C0020554|    10 |       |     3 |  00:00:01 |
-----------------------------------------------------+-----------------------------------+
Predicate Information:
----------------------
1 - filter(:N1<=:N2)
2 - access("T1"."C1"="T3"."C1")
3 - filter(("T3"."C1"<=:N2 AND "T3"."C1">=:N1))
5 - access("T1"."C1">=:N1 AND "T1"."C1"<=:N2)

Content of other_xml column
===========================
  db_version     : 10.2.0.2
  parse_schema   : TESTUSER
  plan_hash      : 3807353021
Peeked Binds
============
  Bind variable information
    position=1
    datatype(code)=2
    datatype(string)=NUMBER
    precision=0
    scale=0
    max length=22
    value=1
  Bind variable information
    position=2
    datatype(code)=2
    datatype(string)=NUMBER
    precision=0
    scale=0
    max length=22
    value=10
  Outline Data:
  /*+
    BEGIN_OUTLINE_DATA
      IGNORE_OPTIM_EMBEDDED_HINTS
      OPTIMIZER_FEATURES_ENABLE('10.2.0.1')
      ALL_ROWS
      OUTLINE_LEAF(@"SEL$1")
      FULL(@"SEL$1" "T3"@"SEL$1")
      INDEX(@"SEL$1" "T1"@"SEL$1" ("T1"."C1"))
      LEADING(@"SEL$1" "T3"@"SEL$1" "T1"@"SEL$1")
      USE_HASH(@"SEL$1" "T1"@"SEL$1")
    END_OUTLINE_DATA
  */

Optimizer environment:
  optimizer_mode_hinted               = false
  optimizer_features_hinted           = 0.0.0
  parallel_execution_enabled          = false
  parallel_query_forced_dop           = 0
  parallel_dml_forced_dop             = 0
  parallel_ddl_forced_degree          = 0
  parallel_ddl_forced_instances       = 0
  _query_rewrite_fudge                = 90
  optimizer_features_enable           = 10.2.0.1
  _optimizer_search_limit             = 5
  cpu_count                           = 4
  active_instance_count               = 1
  parallel_threads_per_cpu            = 2
  hash_area_size                      = 131072
  bitmap_merge_area_size              = 1048576
  sort_area_size                      = 65536
  sort_area_retained_size             = 0
  _sort_elimination_cost_ratio        = 0
  _optimizer_block_size               = 8192
  _sort_multiblock_read_count         = 2
  _hash_multiblock_io_count           = 0
  _db_file_optimizer_read_count       = 128
  _optimizer_max_permutations         = 2000
  pga_aggregate_target                = 204800 KB
  _pga_max_size                       = 204800 KB
  _query_rewrite_maxdisjunct          = 257
  _smm_auto_min_io_size               = 56 KB
  _smm_auto_max_io_size               = 248 KB
  _smm_min_size                       = 204 KB
  _smm_max_size                       = 40960 KB
  _smm_px_max_size                    = 102400 KB
  _cpu_to_io                          = 0
  _optimizer_undo_cost_change         = 10.2.0.1
  parallel_query_mode                 = enabled
  parallel_dml_mode                   = disabled
  parallel_ddl_mode                   = enabled
  optimizer_mode                      = all_rows
  sqlstat_enabled                     = false
  _optimizer_percent_parallel         = 101
  _always_anti_join                   = choose
  _always_semi_join                   = choose
  _optimizer_mode_force               = true
  _partition_view_enabled             = true
  _always_star_transformation         = false
  _query_rewrite_or_error             = false
  _hash_join_enabled                  = true
  cursor_sharing                      = exact
  _b_tree_bitmap_plans                = true
  star_transformation_enabled         = false
  _optimizer_cost_model               = choose
  _new_sort_cost_estimate             = true
  _complex_view_merging               = true
  _unnest_subquery                    = true
  _eliminate_common_subexpr           = true
  _pred_move_around                   = true
  _convert_set_to_join                = false
  _push_join_predicate                = true
  _push_join_union_view               = true
  _fast_full_scan_enabled             = true
  _optim_enhance_nnull_detection      = true
  _parallel_broadcast_enabled         = true
  _px_broadcast_fudge_factor          = 100
  _ordered_nested_loop                = true
  _no_or_expansion                    = false
  optimizer_index_cost_adj            = 100
  optimizer_index_caching             = 0
  _system_index_caching               = 0
  _disable_datalayer_sampling         = false
  query_rewrite_enabled               = true
  query_rewrite_integrity             = enforced
  _query_cost_rewrite                 = true
  _query_rewrite_2                    = true
  _query_rewrite_1                    = true
  _query_rewrite_expression           = true
  _query_rewrite_jgmigrate            = true
  _query_rewrite_fpc                  = true
  _query_rewrite_drj                  = true
  _full_pwise_join_enabled            = true
  _partial_pwise_join_enabled         = true
  _left_nested_loops_random           = true
  _improved_row_length_enabled        = true
  _index_join_enabled                 = true
  _enable_type_dep_selectivity        = true
  _improved_outerjoin_card            = true
  _optimizer_adjust_for_nulls         = true
  _optimizer_degree                   = 0
  _use_column_stats_for_function      = true
  _subquery_pruning_enabled           = true
  _subquery_pruning_mv_enabled        = false
  _or_expand_nvl_predicate            = true
  _like_with_bind_as_equality         = false
  _table_scan_cost_plus_one           = true
  _cost_equality_semi_join            = true
  _default_non_equality_sel_check     = true
  _new_initial_join_orders            = true
  _oneside_colstat_for_equijoins      = true
  _optim_peek_user_binds              = true
  _minimal_stats_aggregation          = true
  _force_temptables_for_gsets         = false
  workarea_size_policy                = auto
  _smm_auto_cost_enabled              = true
  _gs_anti_semi_join_allowed          = true
  _optim_new_default_join_sel         = true
  optimizer_dynamic_sampling          = 2
  _pre_rewrite_push_pred              = true
  _optimizer_new_join_card_computation = true
  _union_rewrite_for_gs               = yes_gset_mvs
  _generalized_pruning_enabled        = true
  _optim_adjust_for_part_skews        = true
  _force_datefold_trunc               = false
  statistics_level                    = typical
  _optimizer_system_stats_usage       = true
  skip_unusable_indexes               = true
  _remove_aggr_subquery               = true
  _optimizer_push_down_distinct       = 0
  _dml_monitoring_enabled             = true
  _optimizer_undo_changes             = false
  _predicate_elimination_enabled      = true
  _nested_loop_fudge                  = 100
  _project_view_columns               = true
  _local_communication_costing_enabled = true
  _local_communication_ratio          = 50
  _query_rewrite_vop_cleanup          = true
  _slave_mapping_enabled              = true
  _optimizer_cost_based_transformation = linear
  _optimizer_mjc_enabled              = true
  _right_outer_hash_enable            = true
  _spr_push_pred_refspr               = true
  _optimizer_cache_stats              = false
  _optimizer_cbqt_factor              = 50
  _optimizer_squ_bottomup             = true
  _fic_area_size                      = 131072
  _optimizer_skip_scan_enabled        = true
  _optimizer_cost_filter_pred         = false
  _optimizer_sortmerge_join_enabled   = true
  _optimizer_join_sel_sanity_check    = true
  _mmv_query_rewrite_enabled          = true
  _bt_mmv_query_rewrite_enabled       = true
  _add_stale_mv_to_dependency_list    = true
  _distinct_view_unnesting            = false
  _optimizer_dim_subq_join_sel        = true
  _optimizer_disable_strans_sanity_checks = 0
  _optimizer_compute_index_stats      = true
  _push_join_union_view2              = true
  _optimizer_ignore_hints             = false
  _optimizer_random_plan              = 0
  _query_rewrite_setopgrw_enable      = true
  _optimizer_correct_sq_selectivity   = true
  _disable_function_based_index       = false
  _optimizer_join_order_control       = 3
  _optimizer_cartesian_enabled        = true
  _optimizer_starplan_enabled         = true
  _extended_pruning_enabled           = true
  _optimizer_push_pred_cost_based     = true
  _sql_model_unfold_forloops          = run_time
  _enable_dml_lock_escalation         = false
  _bloom_filter_enabled               = true
  _update_bji_ipdml_enabled           = 0
  _optimizer_extended_cursor_sharing  = udo
  _dm_max_shared_pool_pct             = 1
  _optimizer_cost_hjsmj_multimatch    = true
  _optimizer_transitivity_retain      = true
  _px_pwg_enabled                     = true
  optimizer_secure_view_merging       = true
  _optimizer_join_elimination_enabled = true
  flashback_table_rpi                 = non_fbt
  _optimizer_cbqt_no_size_restriction = true
  _optimizer_enhanced_filter_push     = true
  _optimizer_filter_pred_pullup       = true
  _rowsrc_trace_level                 = 0
  _simple_view_merging                = true
  _optimizer_rownum_pred_based_fkr    = true
  _optimizer_better_inlist_costing    = all
  _optimizer_self_induced_cache_cost  = false
  _optimizer_min_cache_blocks         = 10
  _optimizer_or_expansion             = depth
  _optimizer_order_by_elimination_enabled = true
  _optimizer_outer_to_anti_enabled    = true
  _selfjoin_mv_duplicates             = true
  _dimension_skip_null                = true
  _force_rewrite_enable               = false
  _optimizer_star_tran_in_with_clause = true
  _optimizer_complex_pred_selectivity = true
  _optimizer_connect_by_cost_based    = false
  _gby_hash_aggregation_enabled       = true
  _globalindex_pnum_filter_enabled    = false
  _fix_control_key                    = 0
  _optimizer_skip_scan_guess          = false
  _enable_row_shipping                = false
  *********************************
  Bug Fix Control Environment
  ***************************
  fix  4611850 = disabled
  fix  4663804 = disabled
  fix  4663698 = disabled
  fix  4545833 = disabled
  fix  3499674 = disabled
  fix  4584065 = disabled
  fix  4602374 = disabled
  fix  4569940 = enabled
  fix  4631959 = disabled
  fix  4519340 = disabled
  fix  4550003 = enabled
  fix  4488689 = disabled
  fix  3118776 = enabled
  fix  4519016 = enabled
  fix  4487253 = enabled
  fix  4556762 = 0      
  fix  4728348 = disabled
  fix  4723244 = disabled
  fix  4554846 = disabled
  fix  4175830 = enabled
  fix  5240607 = disabled
  fix  4722900 = enabled
Query Block Registry:
*********************
SEL$1 0x122d9358 (PARSER) [FINAL]
Optimizer State Dump: call(in-use=53568, alloc=81816), compile(in-use=76816, alloc=126256)

Note in the above that we are able to see the actual execution plan, the peeked bind variables, the set of hints that will reproduce the execution plan, and a large number of normal and hidden optimizer parameters.

We could generate a 10053 trace at level 1 to determine why the above plan was selected, but we will skip that for now.

An example with a 10046 trace at level 4 (we must execute another SQL statement after the SQL statement under investigation so that the STAT lines for our SQL statement are written to the trace file):

ALTER SESSION SET TRACEFILE_IDENTIFIER = '10046_EXECUTION_PLAN';
ALTER SESSION SET EVENTS '10046 TRACE NAME CONTEXT FOREVER, LEVEL 4';

SELECT /* TEST */
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN :N1 AND :N2;

SELECT SYSDATE FROM DUAL;

The resulting trace file looks something like this (you did read Chapter 15 of the book, didn’t you – so be sure to delete the trace files when no longer needed):

=====================
PARSING IN CURSOR #34 len=118 dep=0 uid=31 oct=3 lid=31 tim=2087403486 hv=3172794915 ad='9811b110'
SELECT /* TEST */
  T3.C1,
  SUBSTR(T1.C2,1,10) C2
FROM
  T3,
  T1
WHERE
  T1.C1=T3.C1
  AND T1.C1 BETWEEN :N1 AND :N2
END OF STMT
PARSE #34:c=0,e=162,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=2087403479
BINDS #34:
kkscoacd
 Bind#0
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=1000000 frm=00 csi=00 siz=48 off=0
  kxsbbbfp=13beb440  bln=22  avl=02  flg=05
  value=1
 Bind#1
  oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
  oacflg=03 fl2=1000000 frm=00 csi=00 siz=0 off=24
  kxsbbbfp=13beb458  bln=22  avl=02  flg=01
  value=10
EXEC #34:c=0,e=170,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,tim=2087403808
FETCH #34:c=1078125,e=3875649,p=37124,cr=37142,cu=0,mis=0,r=1,dep=0,og=1,tim=2091279513
FETCH #34:c=0,e=180,p=0,cr=2,cu=0,mis=0,r=9,dep=0,og=1,tim=2091280273
STAT #34 id=1 cnt=10 pid=0 pos=1 obj=0 op='FILTER  (cr=37144 pr=37124 pw=0 time=3875627 us)'
STAT #34 id=2 cnt=10 pid=1 pos=1 obj=0 op='HASH JOIN  (cr=37144 pr=37124 pw=0 time=3875620 us)'
STAT #34 id=3 cnt=10 pid=2 pos=1 obj=114232 op='TABLE ACCESS FULL T3 (cr=37138 pr=37124 pw=0 time=19345 us)'
STAT #34 id=4 cnt=10 pid=2 pos=2 obj=114228 op='TABLE ACCESS BY INDEX ROWID T1 (cr=6 pr=0 pw=0 time=66 us)'
STAT #34 id=5 cnt=10 pid=4 pos=1 obj=114229 op='INDEX RANGE SCAN SYS_C0020554 (cr=4 pr=0 pw=0 time=37 us)'
=====================

We could, of course, just read the actual plan direct from the 10046 trace file, as well as the bind variable values and data types.  But, we will use TKPROF instead (we will not be able to see the bind variable values when using TKPROF).

C:\> tkprof test_ora_4436_10046_execution_plan.trc test_ora_4436_10046_execution_plan.txt

The output might look like this:

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      1.07       3.87      37124      37144          0          10
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      1.07       3.87      37124      37144          0          10

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 31 

Rows     Row Source Operation
-------  ---------------------------------------------------
     10  FILTER  (cr=37144 pr=37124 pw=0 time=3875627 us)
     10   HASH JOIN  (cr=37144 pr=37124 pw=0 time=3875620 us)
     10    TABLE ACCESS FULL T3 (cr=37138 pr=37124 pw=0 time=19345 us)
     10    TABLE ACCESS BY INDEX ROWID T1 (cr=6 pr=0 pw=0 time=66 us)
     10     INDEX RANGE SCAN SYS_C0020554 (cr=4 pr=0 pw=0 time=37 us)(object id 114229)

Of course, it seems to be a little too common that some people will try using EXPLAIN in TKPROF rather than just working with the Row Source Operation lines (what really happened – most of the time, unless of course you read this article):

C:\>tkprof test_ora_4436_10046_execution_plan.trc test_ora_4436_10046_execution_plan.txt EXPLAIN=TESTUSER/TESTPASS

Note that the resulting output could be very confusing if the “Row Source Operation” plan is completely different from the “Execution Plan”, since the first plan is the actual execution plan, while the second is essentially just an EXPLAIN PLAN FOR type of execution plan:

Rows     Row Source Operation
-------  ---------------------------------------------------
     10  FILTER  (cr=37144 pr=37124 pw=0 time=3875627 us)
     10   HASH JOIN  (cr=37144 pr=37124 pw=0 time=3875620 us)
     10    TABLE ACCESS FULL T3 (cr=37138 pr=37124 pw=0 time=19345 us)
     10    TABLE ACCESS BY INDEX ROWID T1 (cr=6 pr=0 pw=0 time=66 us)
     10     INDEX RANGE SCAN SYS_C0020554 (cr=4 pr=0 pw=0 time=37 us)(object id 114229)

Rows     Execution Plan
-------  ---------------------------------------------------
      0  SELECT STATEMENT   MODE: ALL_ROWS
     10   FILTER
     10    HASH JOIN
     10     TABLE ACCESS   MODE: ANALYZED (FULL) OF 'T3' (TABLE)
     10     TABLE ACCESS   MODE: ANALYZED (BY INDEX ROWID) OF 'T1'
                (TABLE)
     10      INDEX   MODE: ANALYZED (RANGE SCAN) OF 'SYS_C0020554'
                 (INDEX (UNIQUE))

So hopefully, you now know what is the plan, how to find it, and what types of messes (faulty information) you do not accidentally step in.


Actions

Information

2 responses

5 03 2010
Blogroll Report 29/01/2009 – 05/02/2010 « Coskan’s Approach to Oracle

[...] Shallahamer – Gotta low latch class 19-All about gathering execution plans Charles Hooper-Execution Plans – What is the Plan, and Where Do I Find It? Charles Hooper-Execution Plans – What is the Plan, and Where Do I Find It 2? Charles [...]

6 03 2013
Understanding Oracle traces and plan | oraclebits

[...] http://hoopercharles.wordpress.com/2010/01/30/execution-plans-what-is-the-plan-and-where-do-i-find-i… (3 part series)http://hoopercharles.wordpress.com/2009/12/01/10046-extended-sql-trace-interpretation/ (2 part series)http://hoopercharles.wordpress.com/2010/01/11/explain-plan-lies-autotrace-lies-tkprof-lies-what-is-the-plan/ [...]

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




Follow

Get every new post delivered to your Inbox.

Join 139 other followers

%d bloggers like this: