10046事件概述
Oracle的10046事件，可以跟踪应用程序所执行的SQL语句，并且得到其解析次数.执行次数,CPU使用时间等信息。这对我们分析、定位数据库性能问题是非常有用的。
10046 event是oracle用于系统性能分析时的一个最重要的事件。当激活这个事件后，将通知Oracle kernel追踪会话的相关即时信息，并写入到相应trace文件中。这些有用的信息主要包括sql是如何进行解析，绑定变量的使用情况，会话中发生的等待事件等
10046 event 可分成不同的级别（level），分别追踪记录不同程度的有用信息。对于这些不同的级别，应当注意的是向下兼容的，即高一级的trace信息包含低于此级的所有信息。
10046 event的追踪级别大致有：
level 1：跟踪sql语句，包括解析、执行、提取、提交和回滚等。
level 4：包括变量的详细信息
level 8：包括等待事件
level 12：包括绑定变量与等待事件
其中，level 1相当于打开了sql_trace
前提条件：
（先确保要event的会话环境符合条件）
1、必须确保timed_statistics为TRUE，这个参数可以在会话级上进行修改。
关于参数timed_statistics的一段解释
Without timed statistics, Oracle records the reason for each wait before it begins to wait, and when the wait is over, it records whether it timed out. But with timed statistics enabled, Oracle checks the time just before and after each wait, and also records the time waited. The time waited is recorded in hundredths of a second— that is, centiseconds.
true
The statistics are collected and stored in trace files or displayed in the V$SESSTATS and V$SYSSTATS dynamic performance views.
false
The value of all time-related statistics is set to zero. This setting lets Oracle avoid the overhead of requesting the time from the operating system.
Starting with release 11.1.0.7.0, the value of the TIMED_STATISTICS parameter cannot be set to false if the value of STATISTICS_LEVEL is set to TYPICAL or ALL.
与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文件。
要在当前会话修改上述参数很简单，只要使用下面的命令即可：
|
当然，这些参数可以在系统级别修改的，也可以加载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
)
|
案例：
|
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
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
|
13
:
55
:
30
SYS@ prod >select username,sid,serial#
from
v$session
where
username is
not
null
;
USERNAME SID SERIAL#
------------------------------ ---------- ----------
SYS
1
5
SCOTT
40
587
SYS
48
569
14
:
31
:
33
SYS@ prod >desc dbms_system
PROCEDURE ADD_PARAMETER_VALUE
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
PARNAME VARCHAR2 IN
VALUE VARCHAR2 IN
SCOPE VARCHAR2 IN DEFAULT
SID VARCHAR2 IN DEFAULT
POSITION BINARY_INTEGER IN DEFAULT
PROCEDURE DIST_TXN_SYNC
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
INST_NUM NUMBER IN
PROCEDURE GET_ENV
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
VAR VARCHAR2 IN
VAL VARCHAR2 OUT
PROCEDURE KCFRMS
PROCEDURE KSDDDT
PROCEDURE KSDFLS
PROCEDURE KSDIND
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
LVL BINARY_INTEGER IN
PROCEDURE KSDWRT
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
DEST BINARY_INTEGER IN
TST VARCHAR2 IN
PROCEDURE READ_EV
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
IEV BINARY_INTEGER IN
OEV BINARY_INTEGER OUT
PROCEDURE REMOVE_PARAMETER_VALUE
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
PARNAME VARCHAR2 IN
VALUE VARCHAR2 IN
SCOPE VARCHAR2 IN DEFAULT
SID VARCHAR2 IN DEFAULT
PROCEDURE REMOVE_PARAMETER_VALUE
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
PARNAME VARCHAR2 IN
POSITION BINARY_INTEGER IN
SCOPE VARCHAR2 IN DEFAULT
SID VARCHAR2 IN DEFAULT
PROCEDURE SET_BOOL_PARAM_IN_SESSION
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
SID NUMBER IN
SERIAL# NUMBER IN
PARNAM VARCHAR2 IN
BVAL BOOLEAN IN
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
PROCEDURE SET_INT_PARAM_IN_SESSION
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
SID NUMBER IN
SERIAL# NUMBER IN
PARNAM VARCHAR2 IN
INTVAL BINARY_INTEGER IN
PROCEDURE SET_SQL_TRACE_IN_SESSION
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
SID NUMBER IN
SERIAL# NUMBER IN
SQL_TRACE BOOLEAN IN
PROCEDURE WAIT_FOR_EVENT
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
EVENT VARCHAR2 IN
EXTENDED_ID BINARY_INTEGER IN
TIMEOUT BINARY_INTEGER IN
14
:
28
:
02
SYS@ prod >exec dbms_system.set_bool_param_in_session(
40
,
587
,
'time_statistics'
,
true
);
PL/SQL procedure successfully completed.
14
:
33
:
59
SYS@ prod >exec dbms_system.set_int_param_in_session(
40
,
587
,
'max_dump_file_size'
,
2147364847
);
PL/SQL procedure successfully completed.
|
10046 Trace启动方法
注意，Oracle并没有提供一个set_string_param_in_session的函数在dbms_system包中，因此tracefile_identifier是无法在别的会话中修改的（至少我到现在没有找到一个可以设置的方法）。
开启当前会话的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'
|
使用登陆触发器开启Trace开启其他会话的10046 Trace
我们可以通过编写登陆触发器来开启10046 Trace，使用这种方法开启Trace的代码和开启当前会话的是一样的，不同的就是这些开启代码是包含在一个after logon触发器里面的。
|
1
2
3
4
5
6
7
8
9
10
11
12
|
-- 代码来自《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
7
8
|
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(
'&'
);
;;amp==>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;
|
案例：
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
|
查询用户会话当前的OS PID:
17
:
40
:
46
SCOTT@ prod >select *
from
emp
where
empno=
7788
;
EMPNO ENAME JOB MGR HIREDATE SAL COMM DEPTNO
---------- ---------- --------- ---------- --------- ---------- ---------- ----------
7788
SCOTT ANALYST
7566
19
-APR
-87
3000
20
17
:
41
:
03
SYS@ prod >SELECT S.USERNAME,
2
P.SPID OS_PROCESS_ID,
3
P.PID ORACLE_PROCESS_ID
4
FROM V$SESSION S, V$PROCESS P
5
WHERE S.PADDR = P.ADDR
6
* AND S.USERNAME = UPPER(
'&'
)
Enter value
for
amp: scott
old
6
: AND S.USERNAME = UPPER(
'&'
)
new
6
: AND S.USERNAME = UPPER(
'scott'
)
USERNAME OS_PROCESS_ID ORACLE_PROCESS_ID
------------------------------ ------------------------ -----------------
SCOTT
2574
31
|
|
1
2
3
4
5
6
7
8
9
|
使用oradebug工具：
17
:
41
:
32
SYS@ prod >oradebug setospid
2574
;
Oracle pid:
31
, Unix process pid:
2574
, image: oracle@rh6.cuug.net (TNS V1-V3)
17
:
42
:
52
SYS@ prod >oradebug unlimit;
Statement processed.
17
:
43
:
10
SYS@ prod >oradebug event
10046
trace name context forever,level
12
;
Statement processed.
17
:
43
:
43
SYS@ prod >oradebug event
10046
trace name context off;
Statement processed.
|
|
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
|
查询scott会话生成的trace文件:
[oracle@rh6 ~]$ ls -lt /u01/app/oracle/diag/rdbms/prod/prod/trace/|grep
2574
-rw-r-----
1
oracle oinstall
4238
Aug
27
17
:
44
prod_ora_2574.trc
[oracle@rh6 ~]$ more /u01/app/oracle/diag/rdbms/prod/prod/trace/prod_ora_2574.trc
PARSING IN CURSOR #
2
len=
34
dep=
0
uid=
84
oct=
3
lid=
84
tim=
1409132637617007
hv=
85843297
ad=
'3ee9c8ec'
sqlid=
'9gs6uhh2jvrb1'
select *
from
emp
where
empno=
7369
END OF STMT
PARSE #
2
:c=
1000
,e=
33930
,p=
0
,cr=
0
,cu=
0
,mis=
1
,r=
0
,dep=
0
,og=
1
,plh=
2949544139
,tim=
1409132637617005
EXEC #
2
:c=
0
,e=
51
,p=
0
,cr=
0
,cu=
0
,mis=
0
,r=
0
,dep=
0
,og=
1
,plh=
2949544139
,tim=
1409132637617855
WAIT #
2
: nam=
'SQL*Net message to client'
ela=
4
driver id=
1650815232
#bytes=
1
p3=
0
obj#=
73181
tim=
1409132637618005
FETCH #
2
:c=
0
,e=
31
,p=
0
,cr=
2
,cu=
0
,mis=
0
,r=
1
,dep=
0
,og=
1
,plh=
2949544139
,tim=
1409132637618085
STAT #
2
id=
1
cnt=
1
pid=
0
pos=
1
obj=
73181
op=
'TABLE ACCESS BY INDEX ROWID EMP (cr=2 pr=0 pw=0 time=0 us cost=1 size=38 card=1)'
STAT #
2
id=
2
cnt=
1
pid=
1
pos=
1
obj=
73182
op=
'INDEX UNIQUE SCAN PK_EMP (cr=1 pr=0 pw=0 time=0 us cost=0 size=0 card=1)'
WAIT #
2
: nam=
'SQL*Net message from client'
ela=
349
driver id=
1650815232
#bytes=
1
p3=
0
obj#=
73181
tim=
1409132637618606
FETCH #
2
:c=
0
,e=
1
,p=
0
,cr=
0
,cu=
0
,mis=
0
,r=
0
,dep=
0
,og=
0
,plh=
2949544139
,tim=
1409132637618657
WAIT #
2
: nam=
'SQL*Net message to client'
ela=
1
driver id=
1650815232
#bytes=
1
p3=
0
obj#=
73181
tim=
1409132637618687
***
2014
-08
-27
17
:
44
:
02.960
WAIT #
2
: nam=
'SQL*Net message from client'
ela=
5342205
driver id=
1650815232
#bytes=
1
p3=
0
obj#=
73181
tim=
1409132642960914
CLOSE #
2
:c=
0
,e=
23
,dep=
0
,type=
0
,tim=
1409132642961076
|
使用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包默认情况下并没有包含在数据库中，需要通过运行$ORACLE_HOME/rdbms/admin/dbmssupp.sql安装之后才能使用。
使用DBMS_SUPPORT包
可以DBMS_SUPPORT包来开启自身进程或者是别的进程的Trace。
|
1
2
3
4
|
12
:
54
:
19
SYS@ prod >@?/rdbms/admin/dbmssupp
Package created.
Elapsed:
00
:
00
:
00.52
Package body created.
|
开启自身进程：
|
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包是几乎没有区别的：
使用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
17
18
19
20
21
22
23
24
25
26
|
-- 过程定义
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追踪
|
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
|
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
oct=
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
oct=
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
obj=
0
op=
'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
oct=
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
|
参数信息：
PARSING IN CURSOR 部分：
Len: 被解析SQL的长度
Dep: 产生递归SQL的深度
Uid：user id
Oct: Oracle command type 命令的类型
Lid: 私有用户id
Tim：时间戳
Hv： hash value
Ad：SQL address
PARSE,EXEC,FETCH 部分
C: 消耗的CPU time
E：elapsed time 操作的用时
P: physical reads 物理读的次数
Cr: consistent reads 一致性方式读取的数据块
Cu：current 方式读取的数据块
Mis：cursor misss in cache 硬分析次数
R: -rows 处理的行数
Dep: depth 递归SQL的深度
Og： optimizer goal 优化器模式
Tim：timestamp时间戳
STATS 部分：
Id: 执行计划的行源号
Cnt：当前行源返回的行数
Pid：当前行源号的父号
Pos：执行计划中的位置
Obj：当前操作的对象id（如果当前行原始一个对象的话）
Op：当前行源的数据访问操作
