Oracle中打开10046 Trace的各种方法
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信息,因此在实际中也是用的最多的。
top与SQL Trace相关的参数
在打开10046时间的SQL Trace之前,要先设置好下面几个参数。
timed_statistics
这个参数决定了是否收集与时间相关的统计信息,如果这个参数为FALSE的话,那么SQL Trace的结果基本没有多大的用处,默认情况下这个参数设置为TRUE。
max_dump_file_size
dump文件的大小,也就是决定是否限制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是无法在别的会话中修改的(至少我到现在没有找到一个可以设置的方法)。
top10046 Trace启动方法
top开启当前会话的10046 Trace
top使用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;
top使用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'
top开启其他会话的10046 Trace
top使用登陆触发器开启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;
/
top使用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;
top使用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, '');
top使用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);
top使用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 (TNS V1-V3)
72 (TNS V1-V3)
75 (TNS V1-V3)
-- 假设要Trace client_identifier是”的所有会话
-- 使用下面的语句即可,开启一个level 12的Trace
SQL> EXECUTE DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE(, true, true);
PL/SQL procedure successfully completed.
-- 使用下面语句停止
EXECUTE DBMS_MONITOR.CLIENT_ID_TRACE_DISABLE();
根据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<>&#39;BACKGROUND&#39;;
SID SERVICE_NAME MODULE ACTION
---- ------------ --------------------------------------------- ----------
67 SYS$USERS SQL Developer
71 SYS$USERS (TNS V1-V3)
72 SYS$USERS Trace Test No Trace
知道了相应的信息再使用DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE来启用对相应会话的Trace&#xff1a;
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 &#61;> &#39;SYS$USERS&#39;,
waits &#61;> TRUE, binds &#61;> FALSE);
-- 停止所开启的Trace
EXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_DISABLE(service_name &#61;> &#39;SYS$USERS&#39;);
-- 针对特定的action开启Trace
EXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE(service_name&#61;>&#39;SYS$USERS&#39;,
module_name&#61;>&#39;Trace Test&#39;,
action_name &#61;> &#39;Trace&#39;,
waits &#61;> TRUE, binds &#61;> FALSE);
-- 停止所开启的Trace
EXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_DISABLE(service_name&#61;>&#39;SYS$USERS&#39;,
module_name&#61;>&#39;Trace Test&#39;,
action_name &#61;> &#39;Trace&#39;)
开启数据库级的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();
这个功能影响整个数据库&#xff0c;很强大&#xff0c;慎用&#xff01;
top开启多个会话Trace的注意点
使用DBMS_MONITOR开启多个会话的Trace是动态的&#xff0c;比如说当你要追踪某个特定的action的Trace的时候&#xff0c;你并不需要先确定那个特定的action对应的会话正在运行中才能开启相应的Trace&#xff0c;相反的是一旦某个进程的action满足当前开启的Trace的条件的时候&#xff0c;那个会话就会开始输出Trace信息&#xff0c;当会话的action发生改变之后&#xff0c;Trace信息也会停止输出&#xff0c;下面是一个简单的测试。
先在一个进程中开始针对module为“Trace Test”&#xff0c;action为“Trace”的Trace&#xff1a;
1
2
3
4
5
6 SQL> EXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE(service_name&#61;>&#39;SYS$USERS&#39;,
module_name&#61;>&#39;Trace Test&#39;,
action_name &#61;> &#39;Trace&#39;,
waits &#61;> TRUE, binds &#61;> FALSE);
PL/SQL procedure successfully completed.
然后在另外一个进程中执行下面的一序列语句&#xff1a;
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(&#39;Trace Test&#39;, &#39;Trace&#39;);
PL/SQL procedure successfully completed.
-- 执行一个简单的查询
SQL> select &#39;trace&#39; from dual;
TRACE
------
trace
-- 改变当前会话的action
SQL> EXEC DBMS_APPLICATION_INFO.SET_MODULE(&#39;Trace Test&#39;, &#39;No Trace&#39;);
PL/SQL procedure successfully completed.
-- 再执行另一个查询
SQL> select &#39;no trace&#39; from dual;
NOTRACE
--------
no trace
执行完毕之后打开Trace文件就会发现第一次执行module、action设置的语句和第二次执行的“select ‘no trace’ from dual;”都没有出现在Trace文件&#xff0c;Trace文件内容如下&#xff1a;
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: (TNS V1-V3)
*** 2010-04-13 06:55:24.247
*** SESSION ID:(72.604) 2010-04-13 06:55:24.247
*** CLIENT ID:() 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
&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;
PARSING IN CURSOR #1 len&#61;69 dep&#61;0 uid&#61;0 ct&#61;47 lid&#61;0 tim&#61;1271141724247208 hv&#61;297401484 ad&#61;&#39;9eb182c8&#39; sqlid&#61;&#39;1ckkjdn8vmz4c&#39;
BEGIN DBMS_APPLICATION_INFO.SET_MODULE(&#39;Trace Test&#39;, &#39;Trace&#39;); END;
END OF STMT
EXEC #1:c&#61;0,e&#61;113,p&#61;0,cr&#61;0,cu&#61;0,mis&#61;1,r&#61;1,dep&#61;0,og&#61;1,plh&#61;0,tim&#61;1271141724247201
WAIT #1: nam&#61;&#39;SQL*Net message to client&#39; ela&#61; 6 driver id&#61;1650815232 #bytes&#61;1 p3&#61;0 obj#&#61;-1 tim&#61;1271141724247735
*** 2010-04-13 06:55:32.913
WAIT #1: nam&#61;&#39;SQL*Net message from client&#39; ela&#61; 8666025 driver id&#61;1650815232 #bytes&#61;1 p3&#61;0 obj#&#61;-1 tim&#61;1271141732913790
CLOSE #1:c&#61;0,e&#61;43,dep&#61;0,type&#61;0,tim&#61;1271141732913937
&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;
PARSING IN CURSOR #2 len&#61;25 dep&#61;0 uid&#61;0 ct&#61;3 lid&#61;0 tim&#61;1271141732932795 hv&#61;660028772 ad&#61;&#39;9eb12b10&#39; sqlid&#61;&#39;70t5xg4mpfgb4&#39;
select &#39;trace &#39; from dual
END OF STMT
PARSE #2:c&#61;1000,e&#61;18805,p&#61;0,cr&#61;0,cu&#61;0,mis&#61;1,r&#61;0,dep&#61;0,og&#61;1,plh&#61;1388734953,tim&#61;1271141732932792
EXEC #2:c&#61;0,e&#61;47,p&#61;0,cr&#61;0,cu&#61;0,mis&#61;0,r&#61;0,dep&#61;0,og&#61;1,plh&#61;1388734953,tim&#61;1271141732932946
WAIT #2: nam&#61;&#39;SQL*Net message to client&#39; ela&#61; 4 driver id&#61;1650815232 #bytes&#61;1 p3&#61;0 obj#&#61;-1 tim&#61;1271141732932989
FETCH #2:c&#61;0,e&#61;17,p&#61;0,cr&#61;0,cu&#61;0,mis&#61;0,r&#61;1,dep&#61;0,og&#61;1,plh&#61;1388734953,tim&#61;1271141732933035
STAT #2 id&#61;1 cnt&#61;1 pid&#61;0 pos&#61;1 bj&#61;0 p&#61;&#39;FAST DUAL (cr&#61;0 pr&#61;0 pw&#61;0 time&#61;0 us cost&#61;2 size&#61;0 card&#61;1)&#39;
WAIT #2: nam&#61;&#39;SQL*Net message from client&#39; ela&#61; 151 driver id&#61;1650815232 #bytes&#61;1 p3&#61;0 obj#&#61;-1 tim&#61;1271141732933287
FETCH #2:c&#61;0,e&#61;3,p&#61;0,cr&#61;0,cu&#61;0,mis&#61;0,r&#61;0,dep&#61;0,og&#61;0,plh&#61;1388734953,tim&#61;1271141732933331
WAIT #2: nam&#61;&#39;SQL*Net message to client&#39; ela&#61; 2 driver id&#61;1650815232 #bytes&#61;1 p3&#61;0 obj#&#61;-1 tim&#61;1271141732933364
*** 2010-04-13 06:55:48.413
WAIT #2: nam&#61;&#39;SQL*Net message from client&#39; ela&#61; 15480453 driver id&#61;1650815232 #bytes&#61;1 p3&#61;0 obj#&#61;-1 tim&#61;1271141748413833
CLOSE #2:c&#61;0,e&#61;26,dep&#61;0,type&#61;0,tim&#61;1271141748413963
&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;&#61;
PARSING IN CURSOR #1 len&#61;72 dep&#61;0 uid&#61;0 ct&#61;47 lid&#61;0 tim&#61;1271141748415935 hv&#61;2176830839 ad&#61;&#39;9eb0ec80&#39; sqlid&#61;&#39;ar765n60vzmbr&#39;
BEGIN DBMS_APPLICATION_INFO.SET_MODULE(&#39;Trace Test&#39;, &#39;No Trace&#39;); END;
END OF STMT
PARSE #1:c&#61;1999,e&#61;1919,p&#61;0,cr&#61;0,cu&#61;0,mis&#61;1,r&#61;0,dep&#61;0,og&#61;1,plh&#61;0,tim&#61;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&#61;0,e&#61;93,p&#61;0,cr&#61;0,cu&#61;0,mis&#61;0,r&#61;1,dep&#61;0,og&#61;1,plh&#61;0,tim&#61;1271141748416134