Distinguish real SQL execution plans from fake ones!

Written by Pythian Marketing | Nov 3, 2016 4:00:00 AM

Distinguish Real Execution Plans from Fake Ones!

As an Oracle DBA, one of our daily tasks is to optimize bad SQL statements that are affecting the system and causing performance degradation. First we identify the culprit SQL, then we extract the execution plan, after that, we start the cycle of SQL tuning and optimization as appropriate. There are many methods to extract the execution plan for a specific SQL statement, however, not all these methods will provide the actual or real plan that optimizer follows, rather than a suggestion or expectation of the execution plan, which is not always accurate and can be misleading. In the following blog, I will demonstrate various execution plan extraction methods, and create a scenario to test these methods then see which ones provide the actual execution plan that optimizer really follows to execute a specific SQL, and which methods provide a suggestion of the execution plan, that is not necessarily used by Oracle optimizer. So first things first, what is an "execution plan"? An execution plan is a set of steps that the optimizer performs when executing a SQL statement and performing an operation. There are many ways to extract the execution plan for a specific SQL, like:

Enterprise Manager
SQL*Plus AUTOTRACE
EXPLAIN PLAN command
SQL Trace (event 10046) with tkprof
DBMS_XPLAN package to view plans from:

Automatic Workload Repository
V$SQL_PLAN
SQL Tuning Sets
Plan table

Some of these methods will provide the “ actual” execution plan, while other methods will provide a “suggestion” of the execution plan, that is, the steps that Oracle expects optimizer to follow in order to execute a SQL statement, which may not always be true. In this test case, I will create a table with two columns, and insert skewed data into one column, then I will build an index and histogram on that column. I will then query that column using bind variables and see if Oracle will use the index or not. It should be mentioned that any method that provides suggestion of the execution plan, is just a synonym of EXPLAIN PLAN command, and because this command does not use the feature of Bind Variable Peeking, it will not generate optimal plan for each different value in this test case, and that will be the crucial bit that this test case depends on.

So... without further ado, let’s see that in action:

> Environment preparation for scenario testing:

[code language="sql"] [oracle@testhost ~]$ sqlplus / as sysdba SQL> alter system flush shared_pool; System altered. SQL> alter system flush buffer_cache; System altered. SQL> drop user xp_test cascade; User dropped. SQL> grant dba to xp_test identified by xp_test; Grant succeeded. SQL> conn xp_test/xp_test SQL> create table xp_table (emp_id varchar2(10), team varchar2(10)) pctfree 99; Table created. SQL> insert into xp_table select * from (SELECT 'EMP' || level , 'TEAM1' from dual connect by Level = 1000); 1000 rows created. SQL> insert into xp_table select * from (SELECT 'EMP' || (level + 1000) , 'TEAM2' from dual connect by Level = 10); 10 rows created. SQL> commit; Commit complete. SQL> create index index_test on xp_table (team); Index created. SQL> exec dbms_stats.gather_table_stats('XP_TEST','XP_TABLE',method_opt='FOR ALL COLUMNS SIZE AUTO FOR COLUMNS SIZE 254 TEAM',cascade=TRUE); PL/SQL procedure successfully completed. SQL> select TABLE_NAME,COLUMN_NAME,HISTOGRAM from dba_tab_columns where table_name = 'XP_TABLE'; TABLE_NAME COLUMN_NAME HISTOGRAM -------------------- ------------------------------ --------------- XP_TABLE TEAM FREQUENCY XP_TABLE EMP_ID NONE SQL> select count(*),team from xp_table group by team order by 2 asc; COUNT(*) TEAM ---------- ---------- 1000 TEAM1 10 TEAM2 [/code] Ok, We have our environment ready for testing, let’s test each execution plan gathering method. First , let’s extract the actual execution plan: > DBMS_XPLAN. DISPLAY_CURSOR : Using this method, we will extract the execution plan directly from the shared pool, which will always be the real execution plan: [code language="sql"] -- Define a bind variable: SQL> variable x varchar2(10); SQL> exec :x:='TEAM2'; PL/SQL procedure successfully completed. SQL> set lines 200 SQL> col PLAN_TABLE_OUTPUT for a100 SQL> select count(emp_id) from xp_table where team = :x; COUNT(EMP_ID) ------------- 10 SQL> select * from table(dbms_xplan.display_cursor()); PLAN_TABLE_OUTPUT ---------------------------------------------------------------------------------------------------- SQL_ID 31gbpz4ncsvp3, child number 0 ------------------------------------- select count(emp_id) from xp_table where team = :x Plan hash value: 726202289 ------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | | | 4 (100)| | | 1 | SORT AGGREGATE | | 1 | 13 | | | PLAN_TABLE_OUTPUT ---------------------------------------------------------------------------------------------------- | 2 | TABLE ACCESS BY INDEX ROWID| XP_TABLE | 10 | 130 | 4 (0)| 00:00:01 | |* 3 | INDEX RANGE SCAN | INDEX_TEST | 10 | | 1 (0)| 00:00:01 | ------------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 3 - access("TEAM"=:X) 20 rows selected. [/code] We see clearly that optimizer accessed table using index range scan, which is good, so now are 100% sure that the real execution plan used an INDEX RANGE SCAN, let’s compare this result with other results. > SQL*Plus AUTOTRACE : Autotrace is very useful way to get SQL statistics, but will it provide the real execution plan? [code language="sql"] SQL> set autotrace on explain; SQL> select count(emp_id) from xp_table where team = :x; COUNT(EMP_ID) ------------- 10 Execution Plan ---------------------------------------------------------- Plan hash value: 3545047802 ------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | 13 | 102 (0)| 00:00:02 | | 1 | SORT AGGREGATE | | 1 | 13 | | | |* 2 | TABLE ACCESS FULL| XP_TABLE | 505 | 6565 | 102 (0)| 00:00:02 | ------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 2 - filter("TEAM"=:X) SQL> set autotrace off [/code] Ops!, AUTOTRACE suggests that optimizer will use a full table scan to access the table, which is different from the execution plan provided in previous step, so AUTOTRACE will provide a suggestion of the execution plan, which may not always be true, now let’s continue with the next method. > EXPLAIN PLAN: Explain Plan command will provide the execution plan without even running the SQL, so we can derive easily that we will get a suggestion of the execution plan: [code language="sql"] SQL> explain plan for select count(emp_id) from xp_table where team = :x; Explained. SQL> select * from table(dbms_xplan.display()); PLAN_TABLE_OUTPUT ---------------------------------------------------------------------------------------------------- Plan hash value: 3545047802 ------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | 13 | 102 (0)| 00:00:02 | | 1 | SORT AGGREGATE | | 1 | 13 | | | |* 2 | TABLE ACCESS FULL| XP_TABLE | 505 | 6565 | 102 (0)| 00:00:02 | ------------------------------------------------------------------------------- Predicate Information (identified by operation id): PLAN_TABLE_OUTPUT ---------------------------------------------------------------------------------------------------- 2 - filter("TEAM"=:X) 14 rows selected. [/code] Confirmed, this method also suggests that optimizer will do full table scan, which is not true as we know from the first method, let’s continue. > SQL Trace (event 10046) with tkprof SQL Trace (event 10046) with tkprof will always provide the real execution plan, optionally, we can use the keyword “ explain” with tkprof to also include the suggested plan as well: [code language="sql"] SQL> alter session set tracefile_identifier='xp_test'; Session altered. SQL> alter session set events '10046 trace name context forever, level 20'; Session altered. SQL> select count(emp_id) from xp_table where team = :x; COUNT(EMP_ID) ------------- 10 SQL> alter session set events '10046 trace name context off'; Session altered. SQL> select value from v$diag_info where name like '%Trace%'; VALUE ------------------------------------------------------------------------------------------------------------------ /u01/app/oracle/diag/rdbms/orcl/orcl/trace /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_24595_xp_test.trc SQL> ! $ tkprof /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_24595_xp_test.trc sys=no explain=xp_test/xp_test output=/tmp/with_explain $ cat /tmp/with_explain.prf Rows (1st) Rows (avg) Rows (max) Row Source Operation ---------- ---------- ---------- --------------------------------------------------- 1 1 1 SORT AGGREGATE (cr=5 pr=0 pw=0 time=67 us) 10 10 10 TABLE ACCESS BY INDEX ROWID XP_TABLE (cr=5 pr=0 pw=0 time=60 us cost=4 size=130 card=10) 10 10 10 INDEX RANGE SCAN INDEX_TEST (cr=2 pr=0 pw=0 time=44 us cost=1 size=0 card=10)(object id 81349) Rows Execution Plan ------- --------------------------------------------------- 0 SELECT STATEMENT MODE: ALL_ROWS 1 SORT (AGGREGATE) 10 TABLE ACCESS MODE: ANALYZED (FULL) OF 'XP_TABLE' (TABLE) [/code] As we can see, tkprof output shows both real and suggested plans. So far, we have tested four execution plan methods, AUTOTRACE and EXPLAIN PLAN methods which will provide suggestions of the execution plan, DBMS_XPLAN.DISPLAY_CURSOR which will always provide the real execution plan, and SQL Trace which can provide both suggested and real execution plan.

> Creating SQL Plan Baseline and repeating the test for AUTOTRACE and EXPLAIN PLAN:

[code language="sql"] -- Checking for SQL plan baselines: SQL> select sql_handle, plan_name, sql_text, enabled, accepted, fixed from dba_sql_plan_baselines; no rows selected --Let’s create a baseline: SQL> show parameter baseline NAME TYPE VALUE ------------------------------------ ----------- ------------------------------ optimizer_capture_sql_plan_baselines boolean FALSE optimizer_use_sql_plan_baselines boolean TRUE SQL> alter session set optimizer_capture_sql_plan_baselines = TRUE; Session altered. SQL> select count(emp_id) from xp_table where team = :x; COUNT(EMP_ID) ------------- 10 SQL> select sql_handle, plan_name, sql_text, enabled, accepted, fixed from dba_sql_plan_baselines; SQL_HANDLE PLAN_NAME SQL_TEXT ENA ACC FIX ---------------------- --------------------------------- ---------------------------------------------------- ------ ----- ------ SQL_65dc367505be1804 SQL_PLAN_6br1qfn2vw604bc04bcd8 select count(emp_id) from xp_table where team = :x YES YES NO SQL> alter session set optimizer_capture_sql_plan_baselines = FALSE; Session altered. SQL> alter system flush buffer_cache; System altered. SQL> alter system flush shared_pool; System altered. [/code] > SQL*Plus AUTOTRACE Trying AUTOTRACE tool after creating SQL Plan Baseline: [code language="sql"] SQL> set autotrace on explain; SQL> select count(emp_id) from xp_table where team = :x; COUNT(EMP_ID) ------------- 10 Execution Plan ---------------------------------------------------------- Plan hash value: 726202289 ------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | 13 | 129 (0)| 00:00:02 | | 1 | SORT AGGREGATE | | 1 | 13 | | | | 2 | TABLE ACCESS BY INDEX ROWID| XP_TABLE | 505 | 6565 | 129 (0)| 00:00:02 | |* 3 | INDEX RANGE SCAN | INDEX_TEST | 505 | | 2 (0)| 00:00:01 | ------------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 3 - access("TEAM"=:X) Note ----- - SQL plan baseline "SQL_PLAN_6br1qfn2vw604bc04bcd8" used for this statement SQL> set autotrace off [/code] Notice that AUTOTRACE this time is aware about the baseline, hence, it is showing that optimizer will perform index range scan. Next, Let’s try EXPLAIN PLAN command: > EXPLAIN PLAN: Trying EXPLAIN PLAN tool after creating SQL Plan Baseline: [code language="sql"] SQL> explain plan for select count(emp_id) from xp_table where team = :x; Explained. SQL> select * from table(dbms_xplan.display()); PLAN_TABLE_OUTPUT ---------------------------------------------------------------------------------------------------- Plan hash value: 726202289 ------------------------------------------------------------------------------------------- | Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time | ------------------------------------------------------------------------------------------- | 0 | SELECT STATEMENT | | 1 | 13 | 129 (0)| 00:00:02 | | 1 | SORT AGGREGATE | | 1 | 13 | | | | 2 | TABLE ACCESS BY INDEX ROWID| XP_TABLE | 505 | 6565 | 129 (0)| 00:00:02 | |* 3 | INDEX RANGE SCAN | INDEX_TEST | 505 | | 2 (0)| 00:00:01 | ------------------------------------------------------------------------------------------- PLAN_TABLE_OUTPUT ---------------------------------------------------------------------------------------------------- Predicate Information (identified by operation id): --------------------------------------------------- 3 - access("TEAM"=:X) Note ----- - SQL plan baseline "SQL_PLAN_6br1qfn2vw604bc04bcd8" used for this statement 19 rows selected. [/code] As we can see, EXPLAIN PLAN is aware of the baseline and showing that optimizer will perform index scan. Summary:

There are many methods to extract the execution plan, some methods will provide the actual execution plan, while other methods will provide just a suggestion that optimizer may not follow in real time. In this test case we have tested four methods for execution plan extraction (DBMS_XPLAN, AUTOTRACE, EXPLAIN PLAN, and SQL Trace), we have then created an SQL Baseline and performed the test again on some methods to confirm that all methods are always aware of the SQL Baseline.

View full post