Thursday, January 26, 2012

Autotrace Polluting The Shared Pool?

Introduction

Another random note that I made during the sessions attended at OOW was about the SQL*Plus AUTOTRACE feature. As you're hopefully already aware of this feature has some significant shortcomings, the most obvious being that it doesn't pull the actual execution plan from the Shared Pool after executing the statement but simply runs an EXPLAIN PLAN on the SQL text which might produce an execution plan that is different from the actual one for various reasons.

Now the claim was made that in addition to these shortcomings the plan generated by the AUTOTRACE feature will stay in the Shared Pool and is eligible for sharing, which would mean that other statement executions could be affected by a potentially bad execution plan generated via AUTOTRACE rather then getting re-optimized on their own.

Now that claim initially struck me as odd because so far I was under the impression that the shortcoming of AUTOTRACE was the fact that it simply used the EXPLAIN PLAN facility to get the execution plan details - and I don't think that any plan generated by EXPLAIN PLAN is eligible for sharing with actual statement execution. After thinking about it for a while I realized however that there are some interesting side effects possible, but it depends on how you actually use AUTOTRACE.

Using Default AUTOTRACE

So in order to see what AUTOTRACE does behind the scenes I've decided to trace AUTOTRACE. Here is what I've tried:


set echo on timing on

alter session set tracefile_identifier = 'autotrace';

alter session set sql_trace = true;

set autotrace on

var n number

exec :n := 1

select * from dual where 1 = :n;

select * from dual where dummy = 'X';


And that's a snippet from the corresponding SQL trace file:


.
.
.
=====================
PARSING IN CURSOR #7 len=31 dep=0 uid=91 oct=3 lid=91 tim=651497870527 hv=868568466 ad='7ff0ce23638' sqlid='b9j0230twamck'
select * from dual where 1 = :n
END OF STMT
PARSE #7:c=0,e=460,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=651497870525
=====================
.
.
.
EXEC #7:c=0,e=1306,p=1,cr=3,cu=0,mis=0,r=0,dep=0,og=1,plh=3752461848,tim=651497871918
FETCH #7:c=0,e=654,p=2,cr=3,cu=0,mis=0,r=1,dep=0,og=1,plh=3752461848,tim=651497872660
STAT #7 id=1 cnt=1 pid=0 pos=1 obj=0 op='FILTER (cr=3 pr=2 pw=0 time=0 us)'
STAT #7 id=2 cnt=1 pid=1 pos=1 obj=116 op='TABLE ACCESS FULL DUAL (cr=3 pr=2 pw=0 time=0 us cost=2 size=2 card=1)'
FETCH #7:c=0,e=3,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=3752461848,tim=651497873015
CLOSE #7:c=0,e=16,dep=0,type=0,tim=651497876511
.
.
.
=====================
PARSING IN CURSOR #9 len=79 dep=0 uid=91 oct=3 lid=91 tim=651497880846 hv=3377064296 ad='7ff0ce196a8' sqlid='1tfgxbv4nmub8'
EXPLAIN PLAN SET STATEMENT_ID='PLUS6499083' FOR select * from dual where 1 = :n
END OF STMT
PARSE #9:c=0,e=583,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=651497880843
=====================
.
.
.
=====================
PARSING IN CURSOR #2 len=74 dep=0 uid=91 oct=3 lid=91 tim=651497888595 hv=920998108 ad='7ff0cdd8b00' sqlid='3s1hh8cvfan6w'
SELECT PLAN_TABLE_OUTPUT FROM TABLE(DBMS_XPLAN.DISPLAY('PLAN_TABLE', :1))
END OF STMT
PARSE #2:c=0,e=264,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=651497888593
=====================
.
.
.
PARSING IN CURSOR #7 len=36 dep=0 uid=91 oct=3 lid=91 tim=651498044006 hv=3267611628 ad='7ff0cdbd0f8' sqlid='4k6g7vr1c7kzc'
select * from dual where dummy = 'X'
END OF STMT
PARSE #7:c=0,e=1071,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=272002086,tim=651498044003
EXEC #7:c=0,e=34,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=272002086,tim=651498044138
FETCH #7:c=0,e=60,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=1,plh=272002086,tim=651498044289
STAT #7 id=1 cnt=1 pid=0 pos=1 obj=116 op='TABLE ACCESS FULL DUAL (cr=3 pr=0 pw=0 time=0 us cost=2 size=2 card=1)'
FETCH #7:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=272002086,tim=651498044616
CLOSE #7:c=0,e=28,dep=0,type=0,tim=651498062083
.
.
.
=====================
PARSING IN CURSOR #2 len=84 dep=0 uid=91 oct=50 lid=91 tim=651498073656 hv=290419607 ad='7ff0cdb8a28' sqlid='5jx46tw8nywwr'
EXPLAIN PLAN SET STATEMENT_ID='PLUS6499083' FOR select * from dual where dummy = 'X'
END OF STMT
PARSE #2:c=0,e=1295,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=272002086,tim=651498073653
=====================
.
.
.
=====================
PARSING IN CURSOR #9 len=74 dep=0 uid=91 oct=3 lid=91 tim=651498076015 hv=920998108 ad='7ff0cdd8b00' sqlid='3s1hh8cvfan6w'
SELECT PLAN_TABLE_OUTPUT FROM TABLE(DBMS_XPLAN.DISPLAY('PLAN_TABLE', :1))
END OF STMT
PARSE #9:c=0,e=254,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=651498076013
=====================
.
.
.


So that looks pretty much like the expected behaviour I've mentioned above - AUTOTRACE executes the statements and afterwards runs an EXPLAIN PLAN to show the execution plan.

As a side note it's interesting that the SQL trace doesn't contain the queries used to gather the delta of the session statistics. The reason is simple: They are not issued by this session. SQL*Plus establishes temporarily a second session for that purpose, using one of the modes provided by the OCI allowing to create a second session on the same connection / process. You can tell this by looking at the corresponding V$SESSION.PADDR resp. the entry in V$PROCESS: For both sessions the same process entry will be used (dedicated server model). By the way I've adopted the same approach for SQLTools++, the GUI that I maintain, for all activities that potentially could interfere with the main session, like collecting session statistics delta or calling DBMS_XPLAN.DISPLAY_CURSOR.

So when using AUTOTRACE in this way the only potential threat comes from the actual execution of the statement - but this is no different from executing a statement in any other way. Of course you'll appreciate that using an odd bind value in the execution as part of the AUTOTRACE activity could theoretically lead to issues with the shared usage of such a cursor afterwards - again this is nothing that is special to AUTOTRACE.

The potentially "wrong" execution plan that can be reported via the EXPLAIN PLAN cannot cause problems for other cursors, simply because it is generated via EXPLAIN PLAN. To make this point clear, here is another script that demonstrates:

- How AUTOTRACE can lie
- How EXPLAIN PLAN cursors are unshared by default


-- Demonstrate that AUTOTRACE can lie
set echo on linesize 200 pagesize 0 trimspool on tab off

drop table t;

purge table t;

create table t
as
select
rownum as id
, rpad('x', 100) as filler
from
dual
connect by
level <= 1000000
;

exec dbms_stats.gather_table_stats(null, 't')

create index t_idx on t (id);

-- Compare the execution plan
-- reported by AUTOTRACE
-- to the one reported by DBMS_XPLAN.DISPLAY_CURSOR
set autotrace on

var n number

exec :n := 500000

select /* FIND_ME */ * from (
select * from t where id > :n
)
where rownum > 1;

set autotrace off

select /* FIND_ME */ * from (
select * from t where id > :n
)
where rownum > 1;

select * from table(dbms_xplan.display_cursor(null, null));

-- Demonstrate that EXPLAIN PLAN cursors get special treatment
-- They are unshared by default
set echo off timing off feedback off long 1000000 longchunksize 1000000

spool %TEMP%\explain_plan_example.sql

select * from (
select
sql_fulltext
from
v$sqlstats
where
sql_text like 'EXPLAIN PLAN%/* FIND_ME */%rownum > 1%'
and sql_text not like '%v$sql%'
order by
last_active_time desc
)
where
rownum <= 1
;

spool off

-- Each execution of the same parent EXPLAIN PLAN cursor
-- leads to a new child cursor
set echo on feedback on timing on pagesize 999

@%TEMP%\explain_plan_example
/

/

column sql_id new_value sql_id

select * from (
select
sql_id
from
v$sqlstats
where
sql_text like 'EXPLAIN PLAN%/* FIND_ME */%rownum > 1%'
and sql_text not like '%v$sql%'
order by
last_active_time desc
)
where
rownum <= 1
;

select
sql_id
, child_number
, explain_plan_cursor
from
v$sql_shared_cursor
where
sql_id = '&sql_id';

set serveroutput on

@sql_shared_cursor &sql_id


So if you run this script you'll see an example where AUTOTRACE gets it wrong because the plan generated via EXPLAIN PLAN is different from the actual plan used. Furthermore the plan generated via EXPLAIN PLAN can only match other EXPLAIN PLAN cursors, and on top these are then unshared by default - so no threat to any other SQL issued possible.

Here's a sample output I got from 11.2.0.1:


SQL> -- Demonstrate that AUTOTRACE can lie
SQL> set echo on linesize 200 pagesize 0 trimspool on tab off
SQL>
SQL> drop table t;

Table dropped.

Elapsed: 00:00:00.03
SQL>
SQL> purge table t;

Table purged.

Elapsed: 00:00:00.04
SQL>
SQL> create table t
2 as
3 select
4 rownum as id
5 , rpad('x', 100) as filler
6 from
7 dual
8 connect by
9 level <= 1000000
10 ;

Table created.

Elapsed: 00:00:02.38
SQL>
SQL> exec dbms_stats.gather_table_stats(null, 't')

PL/SQL procedure successfully completed.

Elapsed: 00:00:02.40
SQL>
SQL> create index t_idx on t (id);

Index created.

Elapsed: 00:00:01.63
SQL>
SQL> -- Compare the execution plan
SQL> -- reported by AUTOTRACE
SQL> -- to the one reported by DBMS_XPLAN.DISPLAY_CURSOR
SQL> set autotrace on
SQL>
SQL> var n number
SQL>
SQL> exec :n := 500000

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.01
SQL>
SQL> select /* FIND_ME */ * from (
2 select * from t where id > :n
3 )
4 where rownum > 1;

no rows selected

Elapsed: 00:00:01.51

Execution Plan
----------------------------------------------------------
Plan hash value: 2383791439

---------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 50000 | 5175K| 162 (0)| 00:00:02 |
| 1 | COUNT | | | | | |
|* 2 | FILTER | | | | | |
| 3 | TABLE ACCESS BY INDEX ROWID| T | 50000 | 5175K| 162 (0)| 00:00:02 |
|* 4 | INDEX RANGE SCAN | T_IDX | 9000 | | 23 (0)| 00:00:01 |
---------------------------------------------------------------------------------------

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

2 - filter(ROWNUM>1)
4 - access("ID">TO_NUMBER(:N))


Statistics
----------------------------------------------------------
1 recursive calls
0 db block gets
15390 consistent gets
15385 physical reads
0 redo size
304 bytes sent via SQL*Net to client
349 bytes received via SQL*Net from client
1 SQL*Net roundtrips to/from client
0 sorts (memory)
0 sorts (disk)
0 rows processed

SQL>
SQL> set autotrace off
SQL>
SQL> select /* FIND_ME */ * from (
2 select * from t where id > :n
3 )
4 where rownum > 1;

no rows selected

Elapsed: 00:00:00.98
SQL>
SQL> select * from table(dbms_xplan.display_cursor(null, null));
SQL_ID 8q13ghbwgsmkv, child number 0
-------------------------------------
select /* FIND_ME */ * from ( select * from t where id > :n ) where
rownum > 1

Plan hash value: 4220795399

----------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
----------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 4204 (100)| |
| 1 | COUNT | | | | | |
|* 2 | FILTER | | | | | |
|* 3 | TABLE ACCESS FULL| T | 500K| 50M| 4204 (1)| 00:00:51 |
----------------------------------------------------------------------------

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

2 - filter(ROWNUM>1)
3 - filter("ID">:N)


22 rows selected.

Elapsed: 00:00:00.12
SQL>
SQL> -- Demonstrate that EXPLAIN PLAN cursors get special treatment
SQL> -- They are unshared by default
SQL> set echo off timing off feedback off long 1000000 longchunksize 1000000
EXPLAIN PLAN SET STATEMENT_ID='PLUS6552708' FOR select /* FIND_ME */ * from (
select * from t where id > :n
)
where rownum > 1

SQL>
SQL> @%TEMP%\explain_plan_example
SQL> EXPLAIN PLAN SET STATEMENT_ID='PLUS6552708' FOR select /* FIND_ME */ * from (
2 select * from t where id > :n
3 )
4 where rownum > 1
5
SQL> /

Explained.

Elapsed: 00:00:00.00
SQL>
SQL> /

Explained.

Elapsed: 00:00:00.00
SQL>
SQL> column sql_id new_value sql_id
SQL>
SQL> select * from (
2 select
3 sql_id
4 from
5 v$sqlstats
6 where
7 sql_text like 'EXPLAIN PLAN%/* FIND_ME */%rownum > 1%'
8 and sql_text not like '%v$sql%'
9 order by
10 last_active_time desc
11 )
12 where
13 rownum <= 1
14 ;

SQL_ID
-------------
ctms62wkwp7nz

1 row selected.

Elapsed: 00:00:00.03
SQL>
SQL> select
2 sql_id
3 , child_number
4 , explain_plan_cursor
5 from
6 v$sql_shared_cursor
7 where
8 sql_id = '&sql_id';

SQL_ID CHILD_NUMBER E
------------- ------------ -
ctms62wkwp7nz 0 N
ctms62wkwp7nz 1 Y
ctms62wkwp7nz 2 Y

3 rows selected.

Elapsed: 00:00:00.03
SQL>
SQL> set serveroutput on
SQL>
SQL> @sql_shared_cursor &sql_id
SQL> declare
2 c number;
3 col_cnt number;
4 col_rec dbms_sql.desc_tab;
5 col_value varchar2(4000);
6 ret_val number;
7 begin
8 c := dbms_sql.open_cursor;
9 dbms_sql.parse(c,
10 'select q.sql_text, s.*
11 from v$sql_shared_cursor s, v$sql q
12 where s.sql_id = q.sql_id
13 and s.child_number = q.child_number
14 and q.sql_id = ''&1''',
15 dbms_sql.native);
16 dbms_sql.describe_columns(c, col_cnt, col_rec);
17
18 for idx in 1 .. col_cnt loop
19 dbms_sql.define_column(c, idx, col_value, 4000);
20 end loop;
21
22 ret_val := dbms_sql.execute(c);
23
24 while(dbms_sql.fetch_rows(c) > 0) loop
25 for idx in 1 .. col_cnt loop
26 dbms_sql.column_value(c, idx, col_value);
27 if col_rec(idx).col_name in ('SQL_ID', 'ADDRESS', 'CHILD_ADDRESS',
28 'CHILD_NUMBER', 'SQL_TEXT') then
29 dbms_output.put_line(rpad(col_rec(idx).col_name, 30) ||
30 ' = ' || col_value);
31 elsif col_value = 'Y' then
32 dbms_output.put_line(rpad(col_rec(idx).col_name, 30) ||
33 ' = ' || col_value);
34 end if;
35 end loop;
36 dbms_output.put_line('--------------------------------------------------');
37 end loop;
38
39 dbms_sql.close_cursor(c);
40 end;
41 /
SQL_TEXT = EXPLAIN PLAN SET STATEMENT_ID='PLUS6552708' FOR select /* FIND_ME */ * from ( select * from t where id > :n ) where rownum > 1
SQL_ID = ctms62wkwp7nz
ADDRESS = 000007FF0DD90180
CHILD_ADDRESS = 000007FF0DD87E70
CHILD_NUMBER = 0
--------------------------------------------------
SQL_TEXT = EXPLAIN PLAN SET STATEMENT_ID='PLUS6552708' FOR select /* FIND_ME */ * from ( select * from t where id > :n ) where rownum > 1
SQL_ID = ctms62wkwp7nz
ADDRESS = 000007FF0DD90180
CHILD_ADDRESS = 000007FF0DCD0D10
CHILD_NUMBER = 1
EXPLAIN_PLAN_CURSOR = Y
--------------------------------------------------
SQL_TEXT = EXPLAIN PLAN SET STATEMENT_ID='PLUS6552708' FOR select /* FIND_ME */ * from ( select * from t where id > :n ) where rownum > 1
SQL_ID = ctms62wkwp7nz
ADDRESS = 000007FF0DD90180
CHILD_ADDRESS = 000007FF0DCAAA20
CHILD_NUMBER = 2
EXPLAIN_PLAN_CURSOR = Y
--------------------------------------------------

PL/SQL procedure successfully completed.

Elapsed: 00:00:00.10
SQL>


Other Autotrace Options

The perhaps less expected aspect comes into the picture if you attempt to use AUTOTRACE differently - there are various options and when using a particular combination AUTOTRACE doesn't really execute the statement but reports only the execution plan, so if you change the first example above from:

SET AUTOTRACE ON

to

SET AUTOTRACE TRACEONLY EXPLAIN

then have a close look at the SQL trace generated:


.
.
.
=====================
PARSING IN CURSOR #2 len=45 dep=0 uid=91 oct=3 lid=91 tim=416642144779 hv=3626603586 ad='7ff13a1c8b0' sqlid='9pj321gc2m522'
select /* FIND_ME */ * from dual where 1 = :n
END OF STMT
PARSE #2:c=0,e=64,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=3752461848,tim=416642144777
CLOSE #2:c=0,e=14,dep=0,type=0,tim=416642145372
=====================
.
.
.
=====================
PARSING IN CURSOR #3 len=93 dep=0 uid=91 oct=3 lid=91 tim=416642148753 hv=2987003528 ad='7ff13cd8ea0' sqlid='fu0myxft0n3n8'
EXPLAIN PLAN SET STATEMENT_ID='PLUS6510526' FOR select /* FIND_ME */ * from dual where 1 = :n
END OF STMT
PARSE #3:c=0,e=689,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=416642148749
=====================
.
.
.
=====================
PARSING IN CURSOR #6 len=50 dep=0 uid=91 oct=3 lid=91 tim=416642233676 hv=37196885 ad='7ff138c8570' sqlid='f8cyn9w13g52p'
select /* FIND_ME */ * from dual where dummy = 'X'
END OF STMT
PARSE #6:c=0,e=116,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=272002086,tim=416642233673
CLOSE #6:c=0,e=32,dep=0,type=0,tim=416642237105
=====================
.
.
.
=====================
PARSING IN CURSOR #3 len=98 dep=0 uid=91 oct=50 lid=91 tim=416642243694 hv=390050481 ad='7ff1374bcf8' sqlid='8vvq0ncbmzcpj'
EXPLAIN PLAN SET STATEMENT_ID='PLUS6510526' FOR select /* FIND_ME */ * from dual where dummy = 'X'
END OF STMT
PARSE #3:c=0,e=1261,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=272002086,tim=416642243691
=====================
.
.
.


Can you spot the difference? SQL*Plus now only parses the SQL before actually running the EXPLAIN PLAN command.

Let's see what happens if the second example from above gets executed with the AUTOTRACE TRACEONLY EXPLAIN option:


-- Demonstrate that AUTOTRACE TRACEONLY EXPLAIN
-- can cause problems for other SQL executions
set echo on linesize 200 pagesize 0 trimspool on tab off

drop table t;

purge table t;

create table t
as
select
rownum as id
, rpad('x', 100) as filler
from
dual
connect by
level <= 1000000
;

exec dbms_stats.gather_table_stats(null, 't')

create index t_idx on t (id);

set autotrace traceonly explain

var n number

exec :n := 500000

select /* FIND_ME */ * from (
select * from t where id > :n
)
where rownum > 1;

set autotrace off

select /* FIND_ME */ * from (
select * from t where id > :n
)
where rownum > 1;

-- Now the execution plan generated by the PARSE call issued by SQL*Plus
-- will be re-used by the subsequent executions
select * from table(dbms_xplan.display_cursor(null, null));


Here's again a sample output from 11.2.0.1:


SQL> drop table t;

Table dropped.

SQL>
SQL> purge table t;

Table purged.

SQL>
SQL> create table t
2 as
3 select
4 rownum as id
5 , rpad('x', 100) as filler
6 from
7 dual
8 connect by
9 level <= 1000000
10 ;

Table created.

SQL>
SQL> exec dbms_stats.gather_table_stats(null, 't')

PL/SQL procedure successfully completed.

SQL>
SQL> create index t_idx on t (id);

Index created.

SQL>
SQL> set autotrace traceonly explain
SQL>
SQL> var n number
SQL>
SQL> exec :n := 500000

PL/SQL procedure successfully completed.

SQL>
SQL> select /* FIND_ME */ * from (
2 select * from t where id > :n
3 )
4 where rownum > 1;

Execution Plan
----------------------------------------------------------
Plan hash value: 2383791439

---------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 50000 | 5175K| 162 (0)| 00:00:02 |
| 1 | COUNT | | | | | |
|* 2 | FILTER | | | | | |
| 3 | TABLE ACCESS BY INDEX ROWID| T | 50000 | 5175K| 162 (0)| 00:00:02 |
|* 4 | INDEX RANGE SCAN | T_IDX | 9000 | | 23 (0)| 00:00:01 |
---------------------------------------------------------------------------------------

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

2 - filter(ROWNUM>1)
4 - access("ID">TO_NUMBER(:N))

SQL>
SQL> set autotrace off
SQL>
SQL> select /* FIND_ME */ * from (
2 select * from t where id > :n
3 )
4 where rownum > 1;

no rows selected

SQL>
SQL> -- Now the execution plan generated by the PARSE call issued by SQL*Plus
SQL> -- will be re-used by the subsequent executions
SQL> select * from table(dbms_xplan.display_cursor(null, null));
SQL_ID 8q13ghbwgsmkv, child number 0
-------------------------------------
select /* FIND_ME */ * from ( select * from t where id > :n ) where
rownum > 1

Plan hash value: 2383791439

---------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
---------------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | | | 162 (100)| |
| 1 | COUNT | | | | | |
|* 2 | FILTER | | | | | |
| 3 | TABLE ACCESS BY INDEX ROWID| T | 50000 | 5175K| 162 (0)| 00:00:02 |
|* 4 | INDEX RANGE SCAN | T_IDX | 9000 | | 23 (0)| 00:00:01 |
---------------------------------------------------------------------------------------

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

2 - filter(ROWNUM>1)
4 - access("ID">:N)


23 rows selected.

SQL>


So that's interesting: By using the TRACEONLY EXPLAIN option I now ended up with a potentially "wrong" execution plan that is actually eligible for sharing with other executions.

What surprised me most was the fact that I expected a bind variable type mismatch (CHAR vs. NUMBER, check the "Predicate Information" section) between the parse and the execution and therefore a re-optimization that actually peeked at the bind variables rather than re-using and sharing the existing cursor, but obviously the cursor was eligible for sharing. Very likely this is due to the fact that the parse call didn't actually bind any variables hence the mentioned mismatch wasn't possible.

Summary

So in summary I think what can be said is this:

- Don't use AUTOTRACE if you want to get the actual execution plan

- The potentially "wrong" execution plans reported by AUTOTRACE usually do not represent a threat because these are EXPLAIN PLAN cursor

- The potential threat of AUTOTRACE variants that actually execute the statement is the fact that the plan used by this actual execution is definitely eligible for sharing with other executions, but this no different from any other execution, so nothing special about AUTOTRACE here either

- There is a potential threat when using the AUTOTRACE TRACEONLY EXPLAIN option - the PARSE only but not execute behaviour could leave undesirable cursors behind that are eligible for sharing. This applies in particular to SQL statements using bind variables

No comments:

Post a Comment