运行时执行计划与explain plan(一)

包括我在内的很多人可能都遇到过这样的情况，用explain plan、autotrace生成的执行计划与运行时的执行计划大相径庭，但是什么原因导致了这种情况的发生呢？Tkyte在其blog中用实例给出了解释。原文地址http://tkyte.blogspot.com/2007/04/when-explanation-doesn-sound-quite.html

When the explanation doesn't sound quite right...

I was asked recently

Under what conditions, autotrace & explain plan can not give the correct execution plan of a sql?

The question came in email - not via asktom.  But I found it of enough general interest to write about it here.  As an aside, I rarely, if ever, answer questions emailed to me directly.  It just isn't a scalable solution.  This is my attempt to make this answer "scale"...

To start with the answer to this - we need to understand that autotrace is just a feature of SQL Plus that automates an explain plan for us - so, autotrace and explain plan are sort of synonymous in this regard.  I'll be using Oracle 10g Release 2 in these examples and will be using autotrace or sql_trace=true and TKPROF - you can get the same results in 9i and later using EXPLAIN PLAN and DBMS_XPLAN.DISPLAY to see the results.

Explain Plan is in the here and now...

This is the first problem with explain plan - it is in the "here and now".  It uses the current optimizer environment, the current set of statistics and so on.  That means the explain plan you see in a tkprof could differ from the REAL PLAN used 5 minutes ago (when performance was 'bad').  For example:

ops$tkyte%ORA10GR2> create table t

  2  as

  3  select a.*, 1 id

  4    from all_objects a

  5   where rownum = 1;

Table created.

ops$tkyte%ORA10GR2> create index t_idx on t(id);

Index created.

ops$tkyte%ORA10GR2> alter session set sql_trace=true;

Session altered.

ops$tkyte%ORA10GR2> select id, object_name from t where id = 1;

        ID OBJECT_NAME

---------- ------------------------------

         1 ICOL$

ops$tkyte%ORA10GR2> insert into t select a.*, 1 from all_objects a;

50338 rows created.

ops$tkyte%ORA10GR2> select id, object_name from t where id = 1;

        ID OBJECT_NAME

---------- ------------------------------

         1 ICOL$

...

         1 WRH$_TABLESPACE_STAT

50339 rows selected.

ops$tkyte%ORA10GR2> alter session set sql_trace=false;

Session altered.

Now, running TKPROF:

$ tkprof /home/ora10gr2/admin/ora10gr2/udump/ora10gr2_ora_12173.trc ./tk.prf

aggregate=no sys=no explain=/

 

We will discover (in 10g, where dynamic sampling will kick in!) this conundrum:

select id, object_name from t where id = 1

 

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     3357      0.33       0.28          0       7490          0       50339

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total     3359      0.33       0.28          0       7490          0       50339

 

Rows     Row Source Operation

-------  ---------------------------------------------------

  50339  TABLE ACCESS BY INDEX ROWID T (cr=7490 pr=0 pw=0 time=402830 us)

  50339   INDEX RANGE SCAN T_IDX (cr=3478 pr=0 pw=0 time=151058 us)(object id 70390)

 

Rows     Execution Plan

-------  ---------------------------------------------------

      0  SELECT STATEMENT   MODE: ALL_ROWS

  50339   TABLE ACCESS (FULL) OF 'T' (TABLE)

Note how the "Row Source Operation" (what I like to call 'reality') differs from the "Execution Plan"  (I'll call that the 'guess').  What happened here was that the row source operation is captured in the trace file at the time of execution - it reflects what REALLY took place as that query executed.  We followed this sequence of operations:

1.      loaded a single row into the table T

2.      ran a query against T - that did a hard parse.  At the time of the hard parse, Oracle 10g dynamically sampled the table and found it to be very small - and id=1 to be rather selective.  Based on that - it said "let's range scan the index"

3.      loaded a lot more data into the table.  All with the same ID=1 value however. 

4.      ran the same query from step 2 - this was a soft parse and just reused the plan generated back when only one row existed in the table.  As you can see however - that lead to inefficient execution.  We read every row from that table via the index.

5.      Executing TKPROF with explain= shows an entirely different plan.  That is because explain plan always does a hard parse, it evaluated the query plan "in the here and now, as of this moment in time".  It dynamically sampled the table again - found it to be large and ID=1 to not be selective.  Explain plan shows us that if we hard parsed that query right now - it would full scan.  However, all executions of that query in "real life" will index range scan as long as that plan is cached in the shared pool...(explain plan总是进行硬解析，因此可能会带来与library cache缓存的执行计划不同)

An important note for this example - the placement of the ALTER SESSION SET SQL_TRACE=TRUE is important.  I needed to set it before running the query the first time.  As an exercise - move it to just be before the second execution of the query and you'll find (from the tkprof) that the query is hard parsed the second time - and the row source operation in the tkprof will be a full scan.  That is because the first time a query is executed with sql_trace=true (as opposed to the default of false), it will be hard parsed - as of right now. (设置SQL_TRACE会导致SQL重新进行硬解析)

第二部分：http://space.itpub.net/16689238/viewspace-551805

第三部分：http://space.itpub.net/16689238/viewspace-551806

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/16689238/viewspace-551803/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/16689238/viewspace-551803/