19. 10046 事件

10046 事件是用來對 Oracle 資料庫做 SQL Trace ，設置 10046 事件大致上有四個 Level 可以使用 :

• Level 1

進行標準的 SQL Trace ，內容只有 SQL Statement 以及執行計畫 :

• Level 4

進行標準的 SQL Trace + Bind Variables 數值 :

• Level 8

進行標準的 SQL Trace + SQL 的等待事件 :

• Level 12

進行標準的 SQL Trace + Bind Variables 數值 + SQL 的等待事件，等於 Level 4 + Level 8 的資訊 :

10046 事件有以下幾種收集方式 :

• 使用 alter session 進行當前 session 的 SQL Trace :

SQL> alter session set events '10046 trace name context forever, level 12';       (開啟 10046 trace) SQL> <--SQL STATEMENT-->; (執行 SQL 語句) SQL> alter session set events '10046 trace name context off';       (關閉 trace) SQL> select value from v$diag_info where name='Default Trace File';  (查詢 trace file 名稱)

若使用 alter system 則是對整個資料庫的 SQL Statement 做 Trace ，一般不太會使用 alter system 這個層級。

• 使用 oradebug 收集某個 session 的 SQL Trace :

SQL> oradebug setospid <spid>;  (設置要收集 session 的 os process id) SQL> oradebug unlimit; SQL> oradebug event 10046 trace name context forever, level 12; (開啟 trace) SQL> oradebug event 10046 trace name context off; (關閉 trace) SQL> oradebug tracefile_name; (查詢 trace file 名稱)

• 使用 dbms_system 收集某個 session 的 SQL Trace :

SQL> exec sys.dbms_system.set_ev(sid,serial#,10046,12,''); (開啟 trace) SQL> exec sys.dbms_system.set_ev(sid,serial#,10046,0,''); (關閉 trace) SQL> select value from v$diag_info where name='Default Trace File';

• 使用 set event 針對某個特定的 SQL ID 做 Trace :

SQL> alter system set events 'sql_trace[sql: cjrha4bzuupzf] level=12';       (針對 cjrha4bzuupzf 這個 sql id 做 10046 trace) SQL> alter system set events 'sql_trace[sql: cjrha4bzuupzf] off';       (關閉 trace) SQL> select value from v$diag_info where name='Default Trace File';

10046 trace 所收集出來的原始檔雖然內容豐富但是不容易解讀， Oracle 提供了 tkprof 這個工具幫助我們格式化 10046 trace ，使用 tkprof <trace_file_name> <output_file_name> 就可以格式化 Trace ，例如 :

$ tkprof ORA11_ora_6248.trc ORA_ora_6248.txt

打開 tkprof 格式化後的文件，就可以簡單看到 SQL Statement 以及其相關資訊 :

由格式化文件顯示出 b9dad7fucmpxu 這個 SQL ID 的內容，以及這句 SQL 在 Parse 、 Execute ， Fetch 各個階段所執行的次數 (count) 、消耗的 cpu 以及執行時間 、 進行 disk I/O 以及查詢的次數，最後是執行時所撈取的資料筆數 (rows) 。

當我們 Trace 一個 Session ，裡面可能執行了很多 SQL Statement ，透過 tkprof 可以幫助我們分析某個 Session 所執行眾多的 SQL 當中，哪一些所消耗的時間是比較久的，針對這些有效能問題的 SQL 進行調整。

雖然 tkprof 格式化後的 Trace 可讀性比較高，但是裡面所揭露的資訊沒有原始 10046 trace 檔來的完整，因此我們還是要學習如何解讀 10046 trace 的原始檔。

我們所認知的每一句 SQL Statement 對於資料庫來說都稱作為一個 Cursor ，所以從 10046 原始 trace 檔中，我們要閱讀的 SQL Statement 就先找 CURSOR # 開頭的 :

找到 CURSOR # 之後可以看到這個 CURSOR 的 SQL 語句以及 Parsing 的資訊 :

len : 表示 SQL 本文長度   dep: 表示進行了幾個 recursive sql   uid / lid : user id oct : 命令類型 (1–create table 2–insert 3–select 6–update 7–delete 9–create index 11–alter index 26–lock table 42–alter session 44–commit  45–rollback 46–savepoint 47–pl/sql block or begin/declare  48–set transaction 50–explain 62–analyze table 90–set constraints 170–call 189-merge) tim : 時間戳記   hv : 表示 v$sql 中的 hash_value 欄位 ad : 表示 v$sql 中的 address 欄位   sqlid : 表示 sql id

接下來底下是 PARSE 、 EXEC ， FETCH 各階段的資訊 :

c : 表示 cpu cost   e : execute time   p : physical read    cr : consistent read   cu : current read mis : 0 for soft parse, 1 for hard parse r : rows affect   og : optimizer mode (1-all_rows 2-first_rows 3-rule  4-choose)   plh : 表示 v$sql_plan 中的 plan_hash_value 欄位

其次我們可以分析這句 SQL 的等待事件，從中找到最花時間的等待事件，判斷是否此事件為造成效能的主要原因 :

其中 tim= 表示此等待事件所發生的時間點，我們可以透過 date -u –d 命令來轉換此事件所發生的實際時間，例如 : 

[oracle@db11gr2 ~]$ date -u -d '@1459091649714524'

經由時間格式的轉換，我們就可以找出哪一個階段的 Wait Event 消耗了比較多的時間，這邊就有可能是影響到 SQL 效能的關鍵因素。

最後由 CURSOR # 我們可以找到這句 SQL 所有的 Bind Variables 數值，只要從 CURSOR # 去對應到 BIND # 號碼就可以了 :

其中oacdty 表示數據類型 、 mxl 表示數據最大長度， value 表示此 bind variable 的數值。

oacdty 數據類型 : 1 – varchar2,nvarchar2 2 – number 12 – date 96 – char,nchar 112 – clob, nclob 113 – blob 180 – timestamp

10046 可以幫助我們抓取並且分析 SQL 的效能問題，是 Oracle DBA 都必須要會的一個技能。