1. Introduction
In order to tune a query you need first to get its real execution plan that describes the operations dictated by the Oracle optimizer and followed by the SQL engine to execute this query. It can’t be enough emphasized that getting the exact explain plan (and not the expected one) represents an important step when troubleshooting query performance problems. This document aims to describe in detail how to obtain the real explain plan followed by the SQL engine.
2. Obtaining Explain plans
First of all it’s worth mentioning to avoid using tools like TOAD to get the explain plan of your query because, more often than not, it does not provide all the information you need for a thorough analysis. This is why I am going to present only tools that have been developed by Oracle Corporation. Among those tools the first one is the classical explain plan for as shown in the below example:
2.1 Explain plan for command and its limitation
Unfortunately there exist situations where the ‘explain plan for’ command may not report the real explain plan followed by the Oracle Optimizer to execute the query. This situation occurs particularly when using bind variables. You should know that the ‘explain plan for’ command treats all bind variables as of a VARCHAR2 data type; this is why an implicit data type conversion might happen during the ‘explain plan for’ command while there is no implicit data type conversion when the query is executed. And that’s where the limit of the ‘explain plan for’ command comes from.
mhouri.world> create table t (id varchar2(10), name varchar2(100));
Table created.
mhouri.world> insert into t select to_char(object_id), object_name from user_objects;
1004 rows created.
mhouri.world> create index i on t(id);
Index created.
mhouri.world> exec dbms_stats.gather_table_stats(user,'T',cascade=>true);
PL/SQL procedure successfully completed.
mhouri.world> var x number
mhouri.world> exec :x:=99999
PL/SQL procedure successfully completed.
mhouri.world> explain plan for select sum(length(name)) from t where id >:x;
Explained.
mhouri.world> select * from table(dbms_xplan.display) ;
-------------------------------------------------------------------------------------
Plan hash value: 1188118800
-------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
-------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 24 | 4 (0)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | 24 | | |
| 2 | TABLE ACCESS BY INDEX ROWID| T | 50 | 1200 | 4 (0)| 00:00:01 |
|* 3 | INDEX RANGE SCAN | I | 9 | | 2 (0)| 00:00:01 |
-------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
3 - access("ID">:X)
Remember that the id column has been declared as varchar2 and that we issued our ‘explain plan for’ command using a bind variable declared as number (var x number). As far as the ‘explain plan for’ command treats all bind variables as VARCHAR2 it has reported that the index has been used; which is, unfortunately, completely false. And that is the topic of the next paragraph.
2.2 dbms_xplan.display_cursor
In order to get the real explain plan we need to use the display_cursor function of the dbms_xplan package as shown below:
mhouri.world> select sum (length (name)) from t where id >:x;
SUM (LENGTH (NAME))
-----------------
8145
mhouri.world> select * from table (dbms_xplan.display_cursor);
PLAN_TABLE_OUTPUT
---------------------------------------------------------------------------
SQL_ID 7zm570j6kj597, child number 0
-------------------------------------
select sum(length(name)) from t where id > :x
Plan hash value: 1842905362
--------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 5 (100)| |
| 1 | SORT AGGREGATE | | 1 | 24 | | |
|* 2 | TABLE ACCESS FULL| T | 50 | 1200 | 5 (0)| 00:00:01 |
---------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
2 - filter(TO_NUMBER("ID")>:X)
Notice how the dbms_xplan.display_cursor() function has correctly reported a TABLE ACCESS FULL instead of the INDEX RANGE SCAN path (initially reported by the ‘explain plan for’ command) due to the TO_NUMBER (see the predicate information) conversion that occurred during the query execution.
2.3 dbms_xplan.display_cursor (null, null, ‘ALLSTATS LAST’)
Now that we are quite confident with the use of dbms_xplan.display_cursor function instead of the approximate ‘explain plan for’ function, It is worth mentioning that the function dbms_xplan.display_cursor when invoked via specific parameters, can give extra valuable information that might be of a great help for explaining query performance problems and very often to show stale statistics. Let’s look to that through the following example:
mhouri.world> select /*+ gather_plan_statistics */
2 ename, hiredate, sal, deptno
3 from emp
4 where deptno = 20;
ENAME HIREDATE SAL DEPTNO
---------- --------- ---------- ----------
allen 30-MAR-10 815 20
jones 02-APR-81 2975 20
scott 09-DEC-82 3000 20
adams 12-JAN-83 1100 20
ford 03-DEC-81 3000 20
mhouri.world> select * from table(dbms_xplan.display_cursor(null,null,'ALLSTATS LAST'));
PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
SQL_ID 7xs5xf4bnkmgs, child number 0
-------------------------------------
select /*+ gather_plan_statistics */ ename, hiredate, sal, deptno from emp where
deptno = 20
Plan hash value: 2872589290
----------------------------------------------------------------------------------
PLAN_TABLE_OUTPUT
-------------------------------------------------------------------------------------------
| Id | Operation | Name | Starts | E-Rows | A-Rows | A-Time | Buffers| Reads |
--------------------------------------------------------------------------------------------
|* 1 | TABLE ACCESS FULL| EMP | 1 | 5 | 5 |00:00:00.01 | 16 | 14 |
--------------------------------------------------------------------------------------------
Predicate Information (identified by operation id):
---------------------------------------------------
1 - filter("DEPTNO"=20)
The new extra information together with their explanations are shown here below:
- Starts : the number of time the operation has been started or executed
- E-Rows : the number of Estimated Rows for the current Operation
- A-Rows : the number of Actual Rows retrieved by the current Operation
It is well known that the Optimizer will do a good job only if E-Rows and A-Rows have close values. When, instead, these two cardinalities present two largely different values, then this is a clear indication of inefficient execution plan probably due to stale statistics on related tables and indexes. However, be aware that, before jumping to conclusions, you need always to compare E-Rows with round (A-Rows/Starts).
3 Grants and privileges
In order to be able to call the dbms_xplan.display_cursor() function you need to access to the following dynamic performance views
- v$session
- v$sql
- v$sql_plan
- v$sql_plan_statistics_all
And if you don’t supply the sql_id or the child_number to the dbms_xplan.display_cursor() function, it will reports the last executed SQL statement.
Hi, Great explanations. It’s the answer that below conversation:
Manager: Your query is very slow.
Developer: But explain plan of my query was good in TOAD, I had controlled it before production.
Thanks.
Comment by Savaş Külah — January 2, 2012 @ 7:16 am |
Savas,
Thanks for your nice comments.
Comment by hourim — January 2, 2012 @ 7:30 am |