Oracle中開啟10046 Trace的各種方法[轉]

zhouxianwang發表於2013-01-05
Oracle

10046 trace的跟蹤等級

10046是一個Oracle的內部事件(event)，透過設定這個事件可以得到Oracle內部執行系統解析、呼叫、等待、繫結變數等詳細的trace資訊，對於分析系統的效能有著非常重要的作用。

設定10046事件的不同級別能得到不同詳細程度的trace資訊，下面就列出各個不同級別的對應作用：

等級 二進位制 作用
0 0000 無輸出
1 0001 輸出 ****,APPNAME（應用程式名）,PARSING IN CURSOR,PARSE ERROR（SQL解析）,EXEC（執行）,FETCH（獲取資料）,UNMAP,SORT UNMAP（排序，臨時段）,ERROR,STAT（執行計劃）,XCTEND（事務）等行
2 0011 與等級1完全一樣
4 0101 包括等級1的輸出，加上BIND行（繫結變數資訊）
8 1001 包括等級1的輸出，加上WAIT行（等待事件資訊）
12 1101 輸出等級1、等級4以及等級8的所有資訊

等級1的10046 trace被視為是普通的SQL Trace，而等級4、等級8以及等級12則被稱為Extended SQL Trace，Extended SQL Trace裡面包括了最有用的WAIT資訊，因此在實際中也是用的最多的。

與SQL Trace相關的引數

在開啟10046時間的SQL Trace之前，要先設定好下面幾個引數。

timed_statistics這個引數決定了是否收集與時間相關的統計資訊，如果這個引數為FALSE的話，那麼SQL Trace的結果基本沒有多大的用處，預設情況下這個引數設定為TRUE。max_dump_file_sizedump檔案的大小，也就是決定是否限制SQL Trace檔案的大小，在一個很忙的系統上面做SQL Trace的話可能會生成很多的資訊，因此最好在會話級別將這個引數設定成unlimited。tracefile_identifier給Trace檔案設定識別字串，這是個非常有用的引數，設定一個易讀的字串能更快的找到Trace檔案。

要在當前會話修改上述引數很簡單，只要使用下面的命令即可：

1
2
3
ALTER SESSION SET timed_statistics=true
ALTER SESSION SET max_dump_file_size=unlimited
ALTER SESSION SET tracefile_identifier='my_trace_session

當然，這些引數可以在系統級別修改的，也可以載入init檔案中或是spfile中，讓系統啟動時自動做全域性設定。

要是在系統執行時動態的修改別的會話的這些引數就需要藉助DBMS_SYSTEM這個包了，設定方法如下：

1
2
3
4
5
6
7
8
9
SYS.DBMS_SYSTEM.SET_BOOL_PARAM_IN_SESSION(
  :sid, :serial,
  'timed_statistics', true
)
 
SYS.DBMS_SYSTEM.SET_INT_PARAM_IN_SESSION(
  :sid, :serial,
  'max_dump_file_size', 2147483647
)

注意，Oracle並沒有提供一個set_string_param_in_session的函式在dbms_system包中，因此tracefile_identifier是無法在別的會話中修改的（至少我到現在沒有找到一個可以設定的方法）。

10046 Trace啟動方法

開啟當前會話的10046 Trace

使用sql_trace引數

sql_trace應該是簡單快捷的開啟Trace的方法了，不過透過sql_trace只能開啟級別為1的Trace，而無法開啟其他更高階的Trace。

1
2
3
4
5
-- 開啟Trace
ALTER SESSION SET sql_trace=true;
 
-- 關閉Trace
ALTER SESSION SET sql_trace=false;

使用set event開啟Trace

使用set event開啟10046事件Trace是最常用的了。

1
2
3
4
5
-- 開啟級別為12的Trace，level後面的數字設定了Trace的級別
ALTER SESSION SET EVENTS '10046 trace name context forever, level 12'
 
-- 關閉Trace，任何級別
ALTER SESSION SET EVENTS '10046 trace name context off'

開啟其他會話的10046 Trace

使用登陸觸發器開啟Trace

我們可以透過編寫登陸觸發器來開啟10046 Trace，使用這種方法開啟Trace的程式碼和開啟當前會話的是一樣的，不同的就是這些開啟程式碼是包含在一個after logon觸發器裡面的。

1
2
3
4
5
6
7
8
9
10
-- 程式碼來自《Optimazing Oracle Performance》 P116
CREATE OR REPLACE TRIGGER trace_test_user AFTER LOGON ON DATABASE
BEGIN
  IF USER LIKE '%\_test' ESCAPE '\' THEN
    EXECUTE IMMEDIATE 'ALTER SESSION SET timed_statistics=true';
    EXECUTE IMMEDIATE 'ALTER SESSION SET max_dump_file_size=unlimited';
    EXECUTE IMMEDIATE 'ALTER SESSION SET EVENTS ''10046 trace name context forever, level 8'' ';
  END IF;
END;
/

使用oradebug工具

使用oradebug工具必須要知道所要處理的程式的OS程式PID，OS PID可以使用下面的語句得到：

1
2
3
4
5
6
SELECT S.USERNAME,
    P.SPID OS_PROCESS_ID,
    P.PID ORACLE_PROCESS_ID
FROM V$SESSION S, V$PROCESS P
WHERE S.PADDR = P.ADDR
    AND S.USERNAME = UPPER('&USER_NAME');

得到PID之後就可以使用oradebug工具了，注意需要使用sysdba登陸到資料庫：

1
2
3
4
5
6
7
8
-- 假設9999為會話的OS PID
oradebug setospid 9999;
-- 設定Trace檔案大小
oradebug unlimit;
-- 開啟級別為12的Trace
oradebug event 10046 trace name context forever ,level 12;
--關閉trace
Oradebug event 10046 trace name context off;

使用DBMS_SYSTEM包

DBMS_SYSTEM包提供了兩個開啟10046 Trace的方法，一個是使用SET_SQL_TRACE_IN_SESSION過程，不過使用這個過程的效果和sql_trace是一樣的：

1
2
3
4
5
-- 開啟Trace
EXEC SYS.DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(:sid, :serial#, true);
 
-- 關閉Trace
EXEC SYS.DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(:sid, :serial#, false);

另一個方法是使用SET_EV過程，當然這個過程不僅僅用來設定10046事件，還能設定所有的其他的事件，使用方法為：

1
2
3
4
5
6
7
8
PROCEDURE SET_EV
 Argument Name                  Type                    In/Out Default?
 ------------------------------ ----------------------- ------ --------
 SI                             BINARY_INTEGER          IN
 SE                             BINARY_INTEGER          IN
 EV                             BINARY_INTEGER          IN
 LE                             BINARY_INTEGER          IN
 NM                             VARCHAR2                IN

使用例子：

1
2
3
4
5
-- 開啟level 12的Trace
EXEC SYS.DBMS_SYSTEM.SET_EV(:sid, :serial, 10046, 12, '');
 
-- 關閉Trace
EXEC SYS.DBMS_SYSTEM.SET_EV(:sid, :serial, 10046, 0, '');

使用DBMS_SUPPORT包

DBMS_SUPPORT包預設情況下並沒有包含在資料庫中，需要透過執行$ORACLE_HOME/rdbms/admin/dbmssupp.sql安裝之後才能使用。

可以DBMS_SUPPORT包來開啟自身程式或者是別的程式的Trace。

開啟自身程式：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
-- 使用方法
DESC DBMS_SUPPORT
 
PROCEDURE START_TRACE
 Argument Name                  Type                    In/Out Default?
 ------------------------------ ----------------------- ------ --------
 WAITS                          BOOLEAN                 IN     DEFAULT
 BINDS                          BOOLEAN                 IN     DEFAULT
PROCEDURE STOP_TRACE
 
-- 例項
-- 開啟級別為12的Trace
EXEC SYS.DBMS_SUPPORT.START_TRACE(true, true);
 
-- 關閉Trace
EXEC SYS.DBMS_SUPPORT.STOP_TRACE();

開啟其他程式的Trace：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
-- 使用方法
PROCEDURE START_TRACE_IN_SESSION
 Argument Name                  Type                    In/Out Default?
 ------------------------------ ----------------------- ------ --------
 SID                            NUMBER                  IN
 SERIAL                         NUMBER                  IN
 WAITS                          BOOLEAN                 IN     DEFAULT
 BINDS                          BOOLEAN                 IN     DEFAULT
PROCEDURE STOP_TRACE_IN_SESSION
 Argument Name                  Type                    In/Out Default?
 ------------------------------ ----------------------- ------ --------
 SID                            NUMBER                  IN
 SERIAL                         NUMBER                  IN
 
-- 例項
-- 開啟級別為12的Trace
EXEC SYS.DBMS_SUPPORT.START_TRACE_IN_SESSION(:sid, :serial, true, true);
 
-- 關閉Trace
EXEC SYS.DBMS_SUPPORT.STOP_TRACE_IN_SESSION(:sid, :serial);

使用DBMS_MONITOR包

Oracle 10g中DBMS_MONITOR包的出現改變了以往一次只能開啟一個會話的歷史，開啟了一個批次啟用10046 Trace的新紀元。

追蹤單個會話

首先看看與前面類似的開啟單個會話的Trace的方法，這個時候與DBMS_SUPPORT包是幾乎沒有區別的：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
-- 過程定義
PROCEDURE SESSION_TRACE_DISABLE
 Argument Name                  Type                    In/Out Default?
 ------------------------------ ----------------------- ------ --------
 SESSION_ID                     BINARY_INTEGER          IN     DEFAULT
 SERIAL_NUM                     BINARY_INTEGER          IN     DEFAULT
PROCEDURE SESSION_TRACE_ENABLE
 Argument Name                  Type                    In/Out Default?
 ------------------------------ ----------------------- ------ --------
 SESSION_ID                     BINARY_INTEGER          IN     DEFAULT
 SERIAL_NUM                     BINARY_INTEGER          IN     DEFAULT
 WAITS                          BOOLEAN                 IN     DEFAULT
 BINDS                          BOOLEAN                 IN     DEFAULT
 PLAN_STAT                      VARCHAR2                IN     DEFAULT
 
-- 例項
-- 開啟級別為12的Trace，當前會話
EXEC DBMS_MONITOR.SESSION_TRACE_ENABLE(WAITS=>true,BINDS=>true);
-- 開啟級別為12的Trace，其他會話
EXEC DBMS_MONITOR.SESSION_TRACE_ENABLE(:sid, :serial, true, true);
 
-- 關閉Trace，當前會話
EXEC DBMS_MONITOR.SESSION_TRACE_DISABLE();
-- 關閉Trace，其他會話
EXEC DBMS_MONITOR.SESSION_TRACE_DISABLE(:sid, :serial);

根據Client Identifier追蹤

使用DBMS_MONITOR包也許同根據client identifier來Trace多個不同的會話，client identifier可以透過V$SESSION裡面client_identifier欄位看到，使用方法如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
-- 找出要Trace的client_identifier資訊
SQL> SELECT sid, program, client_identifier FROM V$SESSION;
 
       SID PROGRAM                                          CLIENT_IDENTIFIER
---------- ------------------------------------------------ ----------------------------------------
        71 sqlplus@orainst.desktop.mycompany.com (TNS V1-V3)     oracle@orainst.desktop.mycompany.com
        72 rman@orainst.desktop.mycompany.com (TNS V1-V3)        oracle@orainst.desktop.mycompany.com
        75 rman@orainst.desktop.mycompany.com (TNS V1-V3)        oracle@orainst.desktop.mycompany.com
 
-- 假設要Trace client_identifier是“oracle@orainst.desktop.mycompany.com”的所有會話
-- 使用下面的語句即可，開啟一個level 12的Trace
SQL> EXECUTE DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE('oracle@orainst.desktop.mycompany.com', true, true);
PL/SQL procedure successfully completed.
 
-- 使用下面語句停止
EXECUTE DBMS_MONITOR.CLIENT_ID_TRACE_DISABLE('oracle@orainst.desktop.mycompany.com');

根據Service, Module和Action追蹤

DBMS_MONITOR包的SERV_MOD_ACT_TRACE_ENABLE過程用來根據Service, Module和Action三個屬性開啟多個會話的Trace。

在進行Trace之前要確保你的應用程式設定了這三個相應的屬性，Oracle提供了包DBMS_APPLICATION_INFO用來設定module、action等資訊，使用方法如下：

1
2
3
EXEC dbms_application_info.SET_MODULE('Trace Test', 'No Trace');
EXEC DBMS_APPLICATION_INFO.SET_ACTION(''No Trace');
EXEC DBMS_APPLICATION_INFO.SET_CLIENT_INFO('A Haaaa');

設定完成之後我們就可以在V$SESSION看到這些資訊了：

1
2
3
4
5
6
7
8
9
10
11
SQL> COL ACTION FOR A10
SQL> COL MODULE FOR A45
SQL> COL SERVICE_NAME FOR A12
SQL> COL SID FOR 999
SQL> SELECT SID , service_name, module, action FROM v$session WHERE TYPE<>'BACKGROUND';
 
 SID SERVICE_NAME MODULE                                        ACTION
---- ------------ --------------------------------------------- ----------
  67 SYS$USERS    SQL Developer
  71 SYS$USERS    sqlplus@orainst.desktop.mycompany.com (TNS V1-V3)
  72 SYS$USERS    Trace Test                                    No Trace

知道了相應的資訊再使用DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE來啟用對相應會話的Trace：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
-- 針對service name為“SYS$USERS”的所有會話開啟Trace
EXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE(service_name => 'SYS$USERS',
        waits => TRUE, binds => FALSE);
 
-- 停止所開啟的Trace
EXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_DISABLE(service_name => 'SYS$USERS');
 
-- 針對特定的action開啟Trace
EXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE(service_name=>'SYS$USERS',
    module_name=>'Trace Test',
    action_name => 'Trace',
    waits => TRUE, binds => FALSE);
 
-- 停止所開啟的Trace
EXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_DISABLE(service_name=>'SYS$USERS',
    module_name=>'Trace Test',
    action_name => 'Trace')

開啟資料庫級的Trace

DBMS_MONITOR還能開啟資料庫級別的Trace。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
-- 定義
PROCEDURE DATABASE_TRACE_DISABLE
 Argument Name                  Type                    In/Out Default?
 ------------------------------ ----------------------- ------ --------
 INSTANCE_NAME                  VARCHAR2                IN     DEFAULT
PROCEDURE DATABASE_TRACE_ENABLE
 Argument Name                  Type                    In/Out Default?
 ------------------------------ ----------------------- ------ --------
 WAITS                          BOOLEAN                 IN     DEFAULT
 BINDS                          BOOLEAN                 IN     DEFAULT
 INSTANCE_NAME                  VARCHAR2                IN     DEFAULT
 PLAN_STAT                      VARCHAR2                IN     DEFAULT
 
-- 開啟資料庫級的level 12的Trace
EXEC DBMS_MONITOR.DATABASE_TRACE_ENABLE(true, true);
 
-- 停止資料庫級的Trace
EXEC DBMS_MONITOR.DATABASE_TRACE_DISABLE();

這個功能影響整個資料庫，很強大，慎用！

開啟多個會話Trace的注意點

使用DBMS_MONITOR開啟多個會話的Trace是動態的，比如說當你要追蹤某個特定的action的Trace的時候，你並不需要先確定那 個特定的action對應的會話正在執行中才能開啟相應的Trace，相反的是一旦某個程式的action滿足當前開啟的Trace的條件的時候，那個會 話就會開始輸出Trace資訊，當會話的action發生改變之後，Trace資訊也會停止輸出，下面是一個簡單的測試。

先在一個程式中開始針對module為“Trace Test”，action為“Trace”的Trace：

1
2
3
4
5
6
SQL> EXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE(service_name=>'SYS$USERS',
module_name=>'Trace Test',
action_name => 'Trace',
waits => TRUE, binds => FALSE);
 
PL/SQL procedure successfully completed.

然後在另外一個程式中執行下面的一序列語句：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
-- 設定當前會話的module和action
SQL> EXEC DBMS_APPLICATION_INFO.SET_MODULE('Trace Test', 'Trace');
 
PL/SQL procedure successfully completed.
 
-- 執行一個簡單的查詢
SQL> select 'trace' from dual;
 
TRACE
------
trace
 
-- 改變當前會話的action
SQL> EXEC DBMS_APPLICATION_INFO.SET_MODULE('Trace Test', 'No Trace');
 
PL/SQL procedure successfully completed.
 
-- 再執行另一個查詢
SQL> select 'no trace' from dual;
 
NOTRACE
--------
no trace

執行完畢之後開啟Trace檔案就會發現第一次執行module、action設定的語句和第二次執行的“select ‘no trace’ from dual;”都沒有出現在Trace檔案，Trace檔案內容如下：

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
Unix process pid: 8900, image: oracle@orainst.desktop.mycompany.com (TNS V1-V3)
 
 
*** 2010-04-13 06:55:24.247
*** SESSION ID:(72.604) 2010-04-13 06:55:24.247
*** CLIENT ID:(oracle@orainst.desktop.mycompany.com) 2010-04-13 06:55:24.247
*** SERVICE NAME:(SYS$USERS) 2010-04-13 06:55:24.247
*** MODULE NAME:(Trace Test) 2010-04-13 06:55:24.247
*** ACTION NAME:(Trace) 2010-04-13 06:55:24.247
 
=====================
PARSING IN CURSOR #1 len=69 dep=0 uid=0 ct=47 lid=0 tim=1271141724247208 hv=297401484 ad='9eb182c8' sqlid='1ckkjdn8vmz4c'
BEGIN DBMS_APPLICATION_INFO.SET_MODULE('Trace Test', 'Trace'); END;
END OF STMT
EXEC #1:c=0,e=113,p=0,cr=0,cu=0,mis=1,r=1,dep=0,og=1,plh=0,tim=1271141724247201
WAIT #1: nam='SQL*Net message to client' ela= 6 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1271141724247735
 
*** 2010-04-13 06:55:32.913
WAIT #1: nam='SQL*Net message from client' ela= 8666025 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1271141732913790
CLOSE #1:c=0,e=43,dep=0,type=0,tim=1271141732913937
=====================
PARSING IN CURSOR #2 len=25 dep=0 uid=0 ct=3 lid=0 tim=1271141732932795 hv=660028772 ad='9eb12b10' sqlid='70t5xg4mpfgb4'
select 'trace ' from dual
END OF STMT
PARSE #2:c=1000,e=18805,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=1388734953,tim=1271141732932792
EXEC #2:c=0,e=47,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1388734953,tim=1271141732932946
WAIT #2: nam='SQL*Net message to client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1271141732932989
FETCH #2:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=1388734953,tim=1271141732933035
STAT #2 id=1 cnt=1 pid=0 pos=1 bj=0 p='FAST DUAL  (cr=0 pr=0 pw=0 time=0 us cost=2 size=0 card=1)'
WAIT #2: nam='SQL*Net message from client' ela= 151 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1271141732933287
FETCH #2:c=0,e=3,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1388734953,tim=1271141732933331
WAIT #2: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1271141732933364
 
*** 2010-04-13 06:55:48.413
WAIT #2: nam='SQL*Net message from client' ela= 15480453 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1271141748413833
CLOSE #2:c=0,e=26,dep=0,type=0,tim=1271141748413963
=====================
PARSING IN CURSOR #1 len=72 dep=0 uid=0 ct=47 lid=0 tim=1271141748415935 hv=2176830839 ad='9eb0ec80' sqlid='ar765n60vzmbr'
BEGIN DBMS_APPLICATION_INFO.SET_MODULE('Trace Test', 'No Trace'); END;
END OF STMT
PARSE #1:c=1999,e=1919,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1271141748415932
*** MODULE NAME:(Trace Test) 2010-04-13 06:55:48.416
*** ACTION NAME:(No Trace) 2010-04-13 06:55:48.416
 
EXEC #1:c=0,e=93,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=0,tim=1271141748416134

source:

來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/27036311/viewspace-752137/，如需轉載，請註明出處，否則將追究法律責任。

相關文章