10046是每一個研究Oracle、進行SQL調優的朋友非常熟悉的工具。10046和10053兩個診斷事件，可以方便的幫助我們瞭解Oracle CBO最佳化器行為和SQL執行行為。在商業非開源的Oracle情況下，我們很多的Internal知識都是源於這兩個利器。

進入11g之後，Oracle提供了10046的替代Trace方法，原有event方法依然支援。本篇就著重介紹一下新的SQL Trace手段。

1、環境和背景介紹

我們依然選擇Oracle 11gR2作為實驗物件，同時建立實驗資料表T。

SQL> select * from v$version;

BANNER

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

Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production

PL/SQL Release 11.2.0.1.0 - Production

CORE 11.2.0.1.0 Production

TNS for Linux: Version 11.2.0.1.0 - Production

NLSRTL Version 11.2.0.1.0 – Production

建立資料表，並且清理shared pool和buffer cache資訊。

SQL> create table t as select * from dba_objects;

Table created

SQL> create index idx_t_id on t(object_id);

Index created

SQL> exec dbms_stats.gather_table_stats(user,'T',cascade => true);

PL/SQL procedure successfully completed

SQL> alter system flush shared_pool;

System altered

SQL> alter system flush buffer_cache;

System altered

2、SQL_TRACE方法

首先我們檢視新介面方法的預設手段。在之前的Oracle版本中，我們有大致上下面幾種手段。

ü Alter session set events；

ü Dbms_跟蹤包；

ü Oradebug設定跟蹤事件；

ü 初始化引數sql_trace；

應該說，這幾種方法對於Oracle的跟蹤非常徹底。在事件10046作用的範圍內，所有的SQL，除了目標SQL還有recursive SQL，都會被記錄下來到跟蹤檔案。所以，我們明明發出了一條SQL語句，但是跟蹤檔案裡面包括了很多對資料字典的檢索。由此，我們經常需要使用tkprof進行raw檔案處理。

我們先看下新介面方法使用。先定位到Trace檔案位置。

SQL> select value from v$diag_info where name='Default Trace File';

VALUE

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

/u01/diag/rdbms/wilson/wilson/trace/wilson_ora_3663.trc

開啟跟蹤。

--標記

SQL> alter session set tracefile_identifier='10046';

會話已更改。

SQL> alter session set timed_statistics = true;

會話已更改。

SQL> alter session set statistics_level=all;

會話已更改。

SQL> alter session set max_dump_file_size = unlimited;

會話已更改。

--跟蹤介面

SQL> alter session set events 'sql_trace level 12';

會話已更改。

SQL> select /*+demo*/count(*) from t where object_id=1000;

COUNT(*)

----------

1

SQL> alter session set events 'sql_trace off';

會話已更改。

10046有若干的跟蹤level，其中level 12包括了所有資訊，一般我們作為初學者，把儘可能多的資訊獲取到比較方便。在sql_trace跟蹤介面中，我們可以設定level取值。

目標SQL在其中執行。在我們看SQL Trace檔案之前，我們先從shared pool中找到這個快取SQL的sql_id。這個id做什麼用，我們先留一個話頭。

SQL> select sql_id, executions from v$sqlarea where sql_text like 'select /*+demo*/count(*)%';

SQL_ID EXECUTIONS

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

94wk1cqs4g2f5 1

我們可以在目錄中找到Trace File了。

[root@bspdev ~]# su - oracle

[oracle@bspdev ~]$ cd /u01/diag/rdbms/wilson/wilson/trace/

[oracle@bspdev trace]$ ls -l | grep 3663

-rw-r----- 1 oracle oinstall 16783 Aug 22 05:55 wilson_ora_3663_10046.trc

-rw-r----- 1 oracle oinstall 158 Aug 22 05:55 wilson_ora_3663_10046.trm

開啟Trace檔案，可以發現與目標SQL相關的Recursive SQL都在其中。

*** 2013-08-22 05:54:47.257

WAIT #1: nam='SQL*Net message from client' ela= 66502048 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1377122087257296

CLOSE #1:c=0,e=10,dep=0,type=1,tim=1377122087257461

=====================

PARSING IN CURSOR #2 len=202 dep=1 uid=0 ct=3 lid=0 tim=1377122087259383 hv=3819099649 ad='525e44f4' sqlid='3nkd3g3ju5ph1'

select obj#,type#,ctime,mtime,stime, status, dataobj#, flags, oid$, spare1, spare2 from obj$ where owner#=:1 and name=:2 and namespace=:3 and remoteowner is null and linkname is null and subname is null

END OF STMT

（省略……）

CLOSE #2:c=0,e=14391,dep=1,type=3,tim=1377122087295194

=====================

PARSING IN CURSOR #1 len=52 dep=0 uid=0 ct=3 lid=0 tim=1377122087365631 hv=2957478341 ad='525a33fc' sqlid='94wk1cqs4g2f5'

select /*+demo*/count(*) from t where object_id=1000

END OF STMT

（省略……）

CLOSE #1:c=0,e=36,dep=0,type=0,tim=1377122102531891

至此，SQL_TRACE新介面和原來的10046方法就相同了。SQL_TRACE的新功能體現在有針對性SQL語句的跟蹤上。

3、特定SQL語句跟蹤

藉助新功能，我們可以對特定一個SQL語句進行跟蹤，而不是全部SQL的跟蹤。

我們重新登入，定位跟蹤檔案。

SQL> select value from v$diag_info where name='Default Trace File';

VALUE

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

/u01/diag/rdbms/wilson/wilson/trace/wilson_ora_3858.trc

跟蹤過程。

SQL> alter session set tracefile_identifier='10046';

會話已更改。

SQL> alter session set timed_statistics = true;

會話已更改。

SQL> alter session set statistics_level=all;

會話已更改。

SQL> alter session set max_dump_file_size = unlimited;

會話已更改。

SQL> alter session set events 'sql_trace [sql:94wk1cqs4g2f5] level 12';

會話已更改。

SQL> select /*+demo*/count(*) from t where object_id=1000;

COUNT(*)

----------

1

SQL> alter session set events 'sql_trace off';

會話已更改。

我們在sql_trace後面寫上SQL_ID，就可以實現對特定SQL的跟蹤。如果是多條SQL，可以使用|分割。

目錄上已經形成了Trace檔案。

[oracle@bspdev trace]$ ls -l | grep 3858

-rw-r----- 1 oracle oinstall 2592 Aug 22 06:03 wilson_ora_3858_10046.trc

-rw-r----- 1 oracle oinstall 98 Aug 22 06:03 wilson_ora_3858_10046.trm

跟蹤檔案中只有目標SQL。

*** 2013-08-22 06:03:02.369

=====================

PARSING IN CURSOR #1 len=52 dep=0 uid=0 ct=3 lid=0 tim=1377122582369595 hv=2957478341 ad='525a33fc' sqlid='94wk1cqs4g2f5'

select /*+demo*/count(*) from t where object_id=1000

END OF STMT

EXEC #1:c=0,e=79,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1700799834,tim=1377122582369592

WAIT #1: nam='SQL*Net message to client' ela= 3 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1377122582369804

FETCH #1:c=0,e=162,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=1,plh=1700799834,tim=1377122582370006

STAT #1 id=1 cnt=1 pid=0 pos=1 bj=0 p='SORT AGGREGATE (cr=2 pr=0 pw=0 time=0 us)'

STAT #1 id=2 cnt=1 pid=1 pos=1 bj=78013 p='INDEX RANGE SCAN IDX_T_ID (cr=2 pr=0 pw=0 time=0 us cost=1 size=5 card=1)'

FETCH #1:c=0,e=3,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1700799834,tim=1377122582370884

WAIT #1: nam='SQL*Net message to client' ela= 2 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1377122582370936

*** 2013-08-22 06:03:08.802

WAIT #1: nam='SQL*Net message from client' ela= 6431961 driver id=1413697536 #bytes=1 p3=0 obj#=-1 tim=1377122588802921

CLOSE #1:c=0,e=34,dep=0,type=0,tim=1377122588803099

跟蹤目標成功。

4、結論

Oracle 11g推出了新的跟蹤介面，為我們進一步瞭解執行過程，進行調優提供了基礎。

Oracle 11g新SQL Trace 10046方法

相關文章