SQLPLUS:AUTOTRACE是如何工作的

autotrace是sqlplus为我们提供的跟踪sql执行的优秀工具。其语法格式如下：

SQL> set autotrace
用法: SET AUTOT[RACE] {OFF | ON | TRACE[ONLY]} [EXP[LAIN]] [STAT[ISTICS]]

举例：
SET AUTOT[RACE] OFF 停止AutoTrace
SET AUTOT[RACE] ON 开启AutoTrace，显示AUTOTRACE信息和SQL执行结果
SET AUTOT[RACE] TRACEONLY 开启AutoTrace，仅显示AUTOTRACE信息
SET AUTOT[RACE] ON EXPLAIN 开启AutoTrace，仅显示AUTOTRACE的EXPLAIN信息
SET AUTOT[RACE] ON STATISTICS开启AutoTrace，仅显示AUTOTRACE的STATISTICS信息

从语法上可以看出，autotrace主要可以提供执行计划和统计信息的跟踪。那么这些信息是如何获取的那？

为了使用autotrace，我们首先需要执行安装脚本：$ORACLE_HOME/sqlplus/admin/plustrce.sql,脚本内容如下：

-- DESCRIPTION
--   Creates a role with access to Dynamic Performance Tables
--   for the SQL*Plus SET AUTOTRACE ... STATISTICS command.
--   After this script has been run, each user requiring access to
--   the AUTOTRACE feature should be granted the PLUSTRACE role by
--   the DBA.
--
-- USAGE
--   sqlplus "sys/knl_test7 as sysdba" @plustrce
--
--   Catalog.sql must have been run before this file is run.
--   This file must be run while connected to a DBA schema.

set echo on

drop role plustrace;
create role plustrace;

grant select on v_$sesstat to plustrace;
grant select on v_$statname to plustrace;
grant select on v_$mystat to plustrace;
grant plustrace to dba with admin option;

set echo off

可以看出，要使用autotrace功能，首先需要创建角色PLUSTRACE，这个角色的权限主要是可以读取与统计信息相关的字典表。因此我们猜测：autotrace的统计信息是从与v_$sesstat,v_$statname,v$mystat相关的数据字典获取的。这也就导致如果我们需要查看统计信息，相应的sql语句必须先被执行，即便执行结果没有被显示。

下面我们看一下，执行计划信息是如何获取的。

SQL> alter session set events '10046 trace name context forever,level 10';

会话已更改。

SQL> alter session set sql_trace=true;

会话已更改。

SQL> set autotrace traceonly exp

查看跟踪文件：

SQL ID: 3y2ghhcs36h3y Plan Hash: 2927627013

EXPLAIN PLAN SET STATEMENT_ID='PLUS374164' FOR update t1 set skew=skew-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        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          0          0           0

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 83

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00

从跟踪文件可以看出，执行计划是通过EXPLAIN PLAN语句来获取的。

通过前面的解释我们可以知道：在查看统计信息时，sql语句是必须要执行的。那么在traceonly模式下只查看执行计划时，sql语句是否会执行那？

session 1：

SQL> set autotrace traceonly exp
SQL> select * from t1;

执行计划
----------------------------------------------------------
Plan hash value: 3617692013

--------------------------------------------------------------------------
| Id  | Operation	  | Name | Rows  | Bytes | Cost (%CPU)| Time	 |
--------------------------------------------------------------------------
|   0 | SELECT STATEMENT  |	 |  3240 |  1278K|    57   (0)| 00:00:01 |
|   1 |  TABLE ACCESS FULL| T1	 |  3240 |  1278K|    57   (0)| 00:00:01 |
--------------------------------------------------------------------------

SQL> update t1 set skew=skew-1;

--已更新3240行。


执行计划
----------------------------------------------------------
Plan hash value: 2927627013

---------------------------------------------------------------------------
| Id  | Operation	   | Name | Rows  | Bytes | Cost (%CPU)| Time	  |
---------------------------------------------------------------------------
|   0 | UPDATE STATEMENT   |	  |  3240 |  1278K|    57   (0)| 00:00:01 |
|   1 |  UPDATE 	   | T1   |	  |	  |	       |	  |
|   2 |   TABLE ACCESS FULL| T1   |  3240 |  1278K|    57   (0)| 00:00:01 |
---------------------------------------------------------------------------

SQL> commit;

提交完成。

SQL> 

session2：

SQL> l
  1* select max(skew) from t1
SQL> /

 MAX(SKEW)
----------
	82

SQL> /

 MAX(SKEW)
----------
	81

跟踪文件：

********************************************************************************

SQL ID: 27uhu2q2xuu7r Plan Hash: 0

select *
from
 t1


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0          -- 0
Execute      0      0.00       0.00          0          0          0          -- 0
Fetch        0      0.00       0.00          0          0          0          -- 0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        1      0.00       0.00          0          0          0           0

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

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00
********************************************************************************

SQL ID: 1uyzazqr6rs12 Plan Hash: 3617692013

EXPLAIN PLAN SET STATEMENT_ID='PLUS374164' FOR select * from t1


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        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          0          0           0

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 83

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message from client                     2      498.36        498.36
  SQL*Net message to client                       1        0.00          0.00
********************************************************************************

SQL ID: 8brhpuhjaa12w Plan Hash: 2927627013

update t1 set skew=skew-1


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      1      0.06       0.06          0        194       3672      --  3240
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.06       0.06          0        194       3672        3240

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 83
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
         0          0          0  UPDATE  T1 (cr=194 pr=0 pw=0 time=63859 us)
      3240       3240       3240   TABLE ACCESS FULL T1 (cr=194 pr=0 pw=0 time=6736 us cost=57 size=1308960 card=3240)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00
********************************************************************************

SQL ID: 3y2ghhcs36h3y Plan Hash: 2927627013

EXPLAIN PLAN SET STATEMENT_ID='PLUS374164' FOR update t1 set skew=skew-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        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          0          0           0

Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 83

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       1        0.00          0.00
  SQL*Net message from client                     1        0.00          0.00
********************************************************************************

SQL ID: 23wm3kz7rps5y Plan Hash: 0

commit


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          1           0
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        2      0.00       0.00          0          0          1           0

Misses in library cache during parse: 0
Parsing user id: 83

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  log file sync                                   1        0.00          0.00
  SQL*Net message to client                       1        0.00          0.00



********************************************************************************

从上面可以看出，在traceonly exp模式下，select语句并没有真正执行，而update语句确执行了，相信insert和delete也会执行（未测试）