sql_trace 命令会将sql执行的整个过程输出到一个trace文件中，然后通过阅读这个trace文件了解整个sql执行过程中sql究竟做了些什么。
sql_trace 命令可以在会话级别设置（session），也可以在实例（system）级别设置
alter session set sql_trace=true; （会话级别）
alter system set sql_trace=true; （实例级别）
通常我们会在 session级别设置sql_trace ，不建议在 system级别设置，因为这样的代价太高了。
同时，设定生成的trace文件名 ，默认trace文件保存在 udump 中
C:\>sqlplus / as sysdba
SQL*Plus: Release 10.2.0.1.0 - Production on 星期二 5月 15 14:18:07 2012
Copyright (c) 1982, 2005, Oracle. All rights reserved.
连接到:
Oracle Database 10g Enterprise Edition Release 10.2.0.1.0 - Production
With the Partitioning, OLAP and Data Mining options
SQL>
SQL> show parameter user_dump;
SQL> show parameter user_dump;
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
user_dump_dest string C:\ORACLE\PRODUCT\10.2.0\ADMIN \ORCL\UDUMP
------------------------------------ ----------- ------------------------------
user_dump_dest string C:\ORACLE\PRODUCT\10.2.0\ADMIN \ORCL\UDUMP
例子如下：
SQL> alter session set tracefile_identifier='mytest'; // 设置 trace文件的名字
会话已更改。
SQL> alter session set sql_trace=true; // 设置会话级别的sql trace
会话已更改。
SQL> select * from scott.t where rownum<200 ;
SQL> alter session set sql_trace=false; // 终止sql_trace ，也可以直接退出SQLPLUS
话已更改。
然后到udump目录下，找到了新生成的trace文件
C:\oracle\product\10.2.0\admin\orcl\udump 路径下的 ： orcl_ora_2480_mytest.trc 文件
一般生成的 trace 文件可读性比较差，我们通常会用tkprof工具来处理这个trace文件
C:\>tkprof C:\oracle\product\10.2.0\admin\orcl\udump\orcl_ora_2480_mytest.trc out.txt
TKPROF: Release 10.2.0.1.0 - Production on 星期二 5月 15 14:06:41 2012
Copyright (c) 1982, 2005, Oracle. All rights reserved.
而新生成的out.txt 就在C:\ 目录下 ， 以下就是 out.txt 内容
TKPROF: Release 10.2.0.1.0 - Production on 星期二 5月 15 14:06:41 2012
Copyright (c) 1982, 2005, Oracle. All rights reserved.
Trace file: C:\oracle\product\10.2.0\admin\orcl\udump\orcl_ora_2480_mytest.trc
Sort options: default
Sort options: default
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
********************************************************************************
alter session set sql_trace=true
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 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 1 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
********************************************************************************
Misses in library cache during execute: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
********************************************************************************
select *
from
scott.t where rownum<200
from
scott.t where rownum<200
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.03 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 15 0.00 0.00 0 244 0 199
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 17 0.00 0.04 0 244 0 199
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Rows Row Source Operation
------- ---------------------------------------------------
199 COUNT STOPKEY (cr=244 pr=0 pw=0 time=2366 us)
199 TABLE ACCESS FULL T (cr=244 pr=0 pw=0 time=1562 us)
------- ---------------------------------------------------
199 COUNT STOPKEY (cr=244 pr=0 pw=0 time=2366 us)
199 TABLE ACCESS FULL T (cr=244 pr=0 pw=0 time=1562 us)
********************************************************************************
alter session set sql_trace=false
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: SYS
Optimizer mode: ALL_ROWS
Parsing user id: SYS
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.03 0 0 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 15 0.00 0.00 0 244 0 199
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 20 0.00 0.04 0 244 0 199
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 2 0.00 0.03 0 0 0 0
Execute 3 0.00 0.00 0 0 0 0
Fetch 15 0.00 0.00 0 244 0 199
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 20 0.00 0.04 0 244 0 199
Misses in library cache during parse: 2
Misses in library cache during execute: 1
Misses in library cache during execute: 1
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 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 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 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 0 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
3 user SQL statements in session.
0 internal SQL statements in session.
3 SQL statements in session.
********************************************************************************
Trace file: C:\oracle\product\10.2.0\admin\orcl\udump\orcl_ora_2480_mytest.trc
Trace file compatibility: 10.01.00
Sort options: default
0 internal SQL statements in session.
3 SQL statements in session.
********************************************************************************
Trace file: C:\oracle\product\10.2.0\admin\orcl\udump\orcl_ora_2480_mytest.trc
Trace file compatibility: 10.01.00
Sort options: default
0 session in tracefile.
3 user SQL statements in trace file.
0 internal SQL statements in trace file.
3 SQL statements in trace file.
3 unique SQL statements in trace file.
44 lines in trace file.
26 elapsed seconds in trace file.
3 user SQL statements in trace file.
0 internal SQL statements in trace file.
3 SQL statements in trace file.
3 unique SQL statements in trace file.
44 lines in trace file.
26 elapsed seconds in trace file.
========================================
========================================
注解：
count = number of times OCI procedure was executed
表示当前的操作被执行了多少次
cpu = cpu time in seconds executing
当前操作消耗了cpu的时间（单位秒）
elapsed = elapsed time in seconds executing
当前的操作一共用时多少（包括cpu时间和等待时间）
disk = number of physical reads of buffers from disk
当前操作的物理读（磁盘i/o次数）
query = number of buffers gotten for consistent read
当前操作的一致性读方式读取的数据块数
（通常是查询使用的是方式）
current = number of buffers gotten in current mode (usually for update)
当前操作的current的方式读取的数据块数
（通常是修改数据使用的方式）
rows = number of rows processed by the fetch or execute call
（当前操作处理的数据记录数）