通过案例学调优之--10046事件
- WBOY原创
- 2016-06-07 14:51:561169浏览
通过案例学调优之--10046事件 10046 事件概述 Oracle 的 10046 事件，可以跟踪应用程序所执行的 SQL 语句，并且得到其解析次数 . 执行次数 ,CPU 使用时间等信息。这对我们分析、定位数据库性能问题是非常有用的。 10046 event 是 oracle 用于系统性能分析时
通过案例学调优之--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文件。
要在当前会话修改上述参数很简单，只要使用下面的命令即可：
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这个包了，设置方法如下
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 )
案例：
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。
-- 开启Trace ALTER SESSION SET sql_trace=true; -- 关闭Trace ALTER SESSION SET sql_trace=false;
使用set event开启Trace
使用set event打开10046事件Trace是最常用的了。
-- 开启级别为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触发器里面的。
-- 代码来自《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可以使用下面的语句得到：
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登陆到数据库：
-- 假设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;
案例：
查询用户会话当前的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使用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.
查询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是一样的：
-- 开启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事件，还能设置所有的其他的事件，使用方法为：
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
使用例子：
-- 开启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。
12:54:19 SYS@ prod >@?/rdbms/admin/dbmssupp Package created. Elapsed: 00:00:00.52 Package body created.
开启自身进程：
-- 使用方法 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：
-- 使用方法 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字段看到，使用方法如下：
-- 过程定义 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追踪
-- 找出要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等信息，使用方法如下：
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看到这些信息了：
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：
-- 针对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。
-- 定义 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信息也会停止输出，下面是一个简单的测试。
先在一个进程中开始针对