通过案例学调优之--10046事件
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 5SCOTT 40 587SYS 48 56914:31:33 SYS@ prod >desc dbms_systemPROCEDURE 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 DEFAULTPROCEDURE DIST_TXN_SYNC Argument Name Type In/Out Default? ------------------------------ ----------------------- ------ -------- INST_NUM NUMBER INPROCEDURE GET_ENV Argument Name Type In/Out Default? ------------------------------ ----------------------- ------ -------- VAR VARCHAR2 IN VAL VARCHAR2 OUTPROCEDURE KCFRMSPROCEDURE KSDDDTPROCEDURE KSDFLSPROCEDURE KSDIND Argument Name Type In/Out Default? ------------------------------ ----------------------- ------ -------- LVL BINARY_INTEGER INPROCEDURE KSDWRT Argument Name Type In/Out Default? ------------------------------ ----------------------- ------ -------- DEST BINARY_INTEGER IN TST VARCHAR2 INPROCEDURE READ_EV Argument Name Type In/Out Default? ------------------------------ ----------------------- ------ -------- IEV BINARY_INTEGER IN OEV BINARY_INTEGER OUTPROCEDURE REMOVE_PARAMETER_VALUE Argument Name Type In/Out Default? ------------------------------ ----------------------- ------ -------- PARNAME VARCHAR2 IN VALUE VARCHAR2 IN SCOPE VARCHAR2 IN DEFAULT SID VARCHAR2 IN DEFAULTPROCEDURE REMOVE_PARAMETER_VALUE Argument Name Type In/Out Default? ------------------------------ ----------------------- ------ -------- PARNAME VARCHAR2 IN POSITION BINARY_INTEGER IN SCOPE VARCHAR2 IN DEFAULT SID VARCHAR2 IN DEFAULTPROCEDURE SET_BOOL_PARAM_IN_SESSION Argument Name Type In/Out Default? ------------------------------ ----------------------- ------ -------- SID NUMBER IN SERIAL# NUMBER IN PARNAM VARCHAR2 IN BVAL BOOLEAN INPROCEDURE 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 INPROCEDURE SET_INT_PARAM_IN_SESSION Argument Name Type In/Out Default? ------------------------------ ----------------------- ------ -------- SID NUMBER IN SERIAL# NUMBER IN PARNAM VARCHAR2 IN INTVAL BINARY_INTEGER INPROCEDURE SET_SQL_TRACE_IN_SESSION Argument Name Type In/Out Default? ------------------------------ ----------------------- ------ -------- SID NUMBER IN SERIAL# NUMBER IN SQL_TRACE BOOLEAN INPROCEDURE 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
|
-- 开启TraceALTER SESSION SET sql_trace=true; -- 关闭TraceALTER 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》 P116CREATE OR REPLACE TRIGGER trace_test_user AFTER LOGON ON DATABASEBEGIN 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_IDFROM V$SESSION S, V$PROCESS PWHERE S.PADDR = P.ADDR AND S.USERNAME = UPPER(‘&‘); ;;amp==>USER_NAME |
得到PID之后就可以使用oradebug工具了，注意需要使用sysdba登陆到数据库：
|
1
2
3
4
5
6
7
8
|
-- 假设9999为会话的OS PIDoradebug setospid 9999;-- 设置Trace文件大小oradebug unlimit;-- 开启级别为12的Traceoradebug event 10046 trace name context forever ,level 12;--关闭traceOradebug 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 2017: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: scottold 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.trcPARSING 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=7369END OF STMTPARSE #2:c=1000,e=33930,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=2949544139,tim=1409132637617005EXEC #2:c=0,e=51,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2949544139,tim=1409132637617855WAIT #2: nam=‘SQL*Net message to client‘ ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=73181 tim=1409132637618005FETCH #2:c=0,e=31,p=0,cr=2,cu=0,mis=0,r=1,dep=0,og=1,plh=2949544139,tim=1409132637618085STAT #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=1409132637618606FETCH #2:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=2949544139,tim=1409132637618657WAIT #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.960WAIT #2: nam=‘SQL*Net message from client‘ ela= 5342205 driver id=1650815232 #bytes=1 p3=0 obj#=73181 tim=1409132642960914CLOSE #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
|
-- 开启TraceEXEC SYS.DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(:sid, :serial#, true); -- 关闭TraceEXEC 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的TraceEXEC SYS.DBMS_SYSTEM.SET_EV(:sid, :serial, 10046, 12, ‘‘); -- 关闭TraceEXEC 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/dbmssuppPackage created.Elapsed: 00:00:00.52Package 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 DEFAULTPROCEDURE STOP_TRACE -- 实例-- 开启级别为12的TraceEXEC SYS.DBMS_SUPPORT.START_TRACE(true, true); -- 关闭TraceEXEC 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 DEFAULTPROCEDURE STOP_TRACE_IN_SESSION Argument Name Type In/Out Default? ------------------------------ ----------------------- ------ -------- SID NUMBER IN SERIAL NUMBER IN -- 实例-- 开启级别为12的TraceEXEC SYS.DBMS_SUPPORT.START_TRACE_IN_SESSION(:sid, :serial, true, true); -- 关闭TraceEXEC 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 DEFAULTPROCEDURE 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的TraceSQL> 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 A10SQL> COL MODULE FOR A45SQL> COL SERVICE_NAME FOR A12SQL> COL SID FOR 999SQL> 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”的所有会话开启TraceEXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE(service_name => ‘SYS$USERS‘, waits => TRUE, binds => FALSE); -- 停止所开启的TraceEXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_DISABLE(service_name => ‘SYS$USERS‘); -- 针对特定的action开启TraceEXECUTE DBMS_MONITOR.SERV_MOD_ACT_TRACE_ENABLE(service_name=>‘SYS$USERS‘, module_name=>‘Trace Test‘, action_name => ‘Trace‘, waits => TRUE, binds => FALSE); -- 停止所开启的TraceEXECUTE 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 DEFAULTPROCEDURE 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的TraceEXEC DBMS_MONITOR.DATABASE_TRACE_ENABLE(true, true); -- 停止数据库级的TraceEXEC 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和actionSQL> EXEC DBMS_APPLICATION_INFO.SET_MODULE(‘Trace Test‘, ‘Trace‘); PL/SQL procedure successfully completed. -- 执行一个简单的查询SQL> select ‘trace‘ from dual; TRACE------trace -- 改变当前会话的actionSQL> 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 STMTEXEC #1:c=0,e=113,p=0,cr=0,cu=0,mis=1,r=1,dep=0,og=1,plh=0,tim=1271141724247201WAIT #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.913WAIT #1: nam=‘SQL*Net message from client‘ ela= 8666025 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1271141732913790CLOSE #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 dualEND OF STMTPARSE #2:c=1000,e=18805,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=1388734953,tim=1271141732932792EXEC #2:c=0,e=47,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1388734953,tim=1271141732932946WAIT #2: nam=‘SQL*Net message to client‘ ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1271141732932989FETCH #2:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=1388734953,tim=1271141732933035STAT #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=1271141732933287FETCH #2:c=0,e=3,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1388734953,tim=1271141732933331WAIT #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.413WAIT #2: nam=‘SQL*Net message from client‘ ela= 15480453 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1271141748413833CLOSE #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 STMTPARSE #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：当前行源的数据访问操作
