在Oracle中利用SQL_TRACE跟蹤SQL的執行

當你在執行一條SQL語句非常慢的時候,你是不是想問Oracle怎么執行這條語句的呢?
Oracle提供的SQL_TRACE工具可以讓你知道你執行的SQL究竟做了什么.執行的過程會被
輸出到trace文件中.
下面用例子來跟蹤一個SQL語句的執行情況:
SQL> create table t as select rownum as id,object_name from dba_objects;
Table created.
SQL> create index t_ind on t(id);
Index created.
SQL> alter session set tracefile_identifier='mysession';
Session altered.
生成的trace文件的路徑是$ORACLE_BASE/admin/SID/udump目錄.
上面的語句是讓生產trace文件名包括mysession,如本例中在
D:\oracle\product\10.2.0\admin\orcl\udump生成了orcl_ora_5732_mysession.trc
SQL> alter session set sql_trace=true;
Session altered.
SQL> select * from t where id=123;
ID     OBJECT_NAME
123    I_ACCESS1
SQL> alter session set sql_trace=false;
Session altered.
一般來講生成的trace文件比較難讀,可以用tkprof來生成一個更可讀的文件.
注意tkprof是Oracle帶的一個命令行工具,不是SQLPLUS命令.
在另外一個命令行中進入D:\oracle\product\10.2.0\admin\orcl\udump目錄
D:\oracle\product\10.2.0\admin\orcl\udump>tkprof orcl_ora_5732_mysession.trc orcl_ora_5732_mysession.txt
TKPROF: Release 10.2.0.1.0 - Production on Fri Sep 14 16:59:12 2012
Copyright (c) 1982, 2005, Oracle.  All rights reserved.
打開 orcl_ora_5732_mysession.txt文件,可以看到執行SQL的信息:
select *
from
 t where id=123
call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.04       0.30          0          2          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        2      0.00       0.00          0          4          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.04       0.30          0          6          0           1
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 61  
Rows     Row Source Operation
-------  ---------------------------------------------------
      1  TABLE ACCESS BY INDEX ROWID T (cr=4 pr=0 pw=0 time=86 us)
      1   INDEX RANGE SCAN T_IND (cr=3 pr=0 pw=0 time=67 us)(object id 57205)
********************************************************************************
對於每一條SQL語句,都包含3個步驟:
Parse:SQL的分析階段.
Execute:SQL的執行階段.
Fetch:數據提取階段.(對於一次SQL操作,Fetch可能多次)
橫向的標題頭為:
count:當前的操作執行的次數.
cpu:當前操作消耗的CPU時間(秒).
elapsed:當前操作消耗的時間(CPU時間加等待時間).
disk:磁盤的IO次數.
query:當前操作的一致性讀取的數據塊數.
current:前操作的current讀取的數據塊數(通常在update操作時發生).
rows:處理的記錄行數.

Misses in library cache during parse是指是不是重用了執行計划,如果同一條SQL語句第二次執行,
其值為零,這里是1,表示在共享池里沒有這一條SQL的執行計划,發生了一次硬解析.
Optimizer:優化器模式.
Parsing user id:分析的用戶ID.
Row Source Operation部分包含的實際消耗的資源.
cr:一致性讀取的數據塊,相當於Fetch的query.
pr:物理讀, 相當於Fetch的disk.
pw:物理寫.
time:當前操作的執行時間.

同時我們在trace文件里還會發現對系統表的訪問的SQL,這就是通常說的遞歸SQL.

還可以利用10046事件來跟蹤SQL,它比SQL_TRACE提供更詳細的信息.它有LEVEL 1,4,8,12四個級別.
其中Level 1 相當於 SQL_TRACE.下面是10046使用的例子
SQL> alter session set events '10046 trace name context forever,level 4';
Session altered.
.... some SQL statements
SQL> alter session set events '10046 trace name context off';
Session altered.