鸿 网 互 联 www.68idc.cn

当前位置 : 主页 > 数据库 > >

通过案例学调优之--10046事件

来源:互联网 作者:佚名 时间:2016-03-03 12:32
通过案例学调优之--10046事件 10046 事件概述 Oracle 的 10046 事件,可以跟踪应用程序所执行的 SQL 语句,并且得到其解析次数 . 执行次数 ,CPU 使用时间等信息。这对我们分析、定位数据库性能问题是非常有用的。 10046 event 是 oracle 用于系统性能分析时

通过案例学调优之--10046事件

10046事件概述
      Oracle
10046事件,可以跟踪应用程序所执行的SQL语句,并且得到其解析次数.执行次数,CPU使用时间等信息。这对我们分析、定位数据库性能问题是非常有用的。

      10046 eventoracle用于系统性能分析时的一个最重要的事件。当激活这个事件后,将通知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_statisticsTRUE,这个参数可以在会话级上进行修改。

关于参数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只能开启级别为1Trace,而无法开启其他更高级的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进程PIDOS 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');
 
 ;;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('&amp')
Enter value for amp: scott
old   6:     AND S.USERNAME = UPPER('&amp')
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 10gDBMS_MONITOR包的出现改变了以往一次只能开启一个会话的历史,开启了一个批量启用10046 Trace的新纪元。


追踪单个会话

首先看看与前面类似的开启单个会话的Trace的方法,这个时候与DBMS_SUPPORT包是几乎没有区别的:

使用DBMS_MONITOR包也许同根据client identifierTrace多个不同的会话,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, ModuleAction追踪

DBMS_MONITOR包的SERV_MOD_ACT_TRACE_ENABLE过程用来根据Service, ModuleAction三个属性开启多个会话的Trace

在进行Trace之前要确保你的应用程序设置了这三个相应的属性,Oracle提供了包DBMS_APPLICATION_INFO用来设置moduleaction等信息,使用方法如下:

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是动态的,比如说当你要追踪某个特定的actionTrace的时候,你并不需要先确定那个特定的action对应的会话正在运行中才能开启相应的Trace,相反的是一旦某个进程的action满足当前开启的Trace的条件的时候,那个会话就会开始输出Trace信息,当会话的action发生改变之后,Trace信息也会停止输出,下面是一个简单的测试。

先在一个进程中开始针对module“Trace Test”action“Trace”Trace

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.

然后在另外一个进程中执行下面的一序列语句:

-- 设置当前会话的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文件就会发现第一次执行moduleaction设置的语句和第二次执行的“select ‘no trace’ from dual;”都没有出现在Trace文件,Trace文件内容如下:

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的深度

                Uiduser id

                Oct: Oracle command type 命令的类型

                Lid: 私有用户id

                Tim:时间戳

                Hv hash value

                AdSQL address

 

PARSE,EXEC,FETCH 部分

                C: 消耗的CPU time

                Eelapsed time 操作的用时

                P: physical reads 物理读的次数

                Cr: consistent reads 一致性方式读取的数据块

                Cucurrent 方式读取的数据块

                Miscursor misss in cache 硬分析次数

                R: -rows 处理的行数

                Dep: depth 递归SQL的深度

                Og optimizer goal 优化器模式

                Timtimestamp时间戳

 

STATS 部分:

                Id: 执行计划的行源号

                Cnt:当前行源返回的行数

                Pid:当前行源号的父号

                Pos:执行计划中的位置

                Obj:当前操作的对象id(如果当前行原始一个对象的话)

                Op:当前行源的数据访问操作



网友评论