通过案例学调优之--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 [email protected] 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 [email protected] 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 [email protected] prod >exec dbms_system.set_bool_param_in_session(40,587,‘time_statistics‘,true);
PL/SQL procedure successfully completed.

14:33:59 [email protected] 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‘);
 
 ;;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 [email protected] 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 [email protected] 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 [email protected] prod >oradebug setospid 2574;
Oracle pid: 31, Unix process pid: 2574, image: [email protected] (TNS V1-V3)
17:42:52 [email protected] prod >oradebug unlimit;
Statement processed.
17:43:10 [email protected] prod >oradebug event 10046 trace name context forever,level 12;
Statement processed.
17:43:43 [email protected] prod >oradebug event 10046 trace name context off;
Statement processed.
查询scott会话生成的trace文件:
[[email protected] ~]$ 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

[[email protected] ~]$ 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。

开启自身进程:

-- 使用方法
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 [email protected] (TNS V1-V3)     [email protected]
        72 [email protected] (TNS V1-V3)        [email protected]
        75 [email protected] (TNS V1-V3)        [email protected]
 
-- 假设要Trace client_identifier是“[email protected]”的所有会话
-- 使用下面的语句即可,开启一个level 12的Trace
SQL> EXECUTE DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE(‘[email protected]‘, true, true);
PL/SQL procedure successfully completed.
 
-- 使用下面语句停止
EXECUTE DBMS_MONITOR.CLIENT_ID_TRACE_DISABLE(‘[email protected]‘);

根据Service, ModuleAction追踪

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    [email protected] (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信息也会停止输出,下面是一个简单的测试。

先在一个进程中开始针对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文件就会发现第一次执行module、action设置的语句和第二次执行的“select ‘no trace’ from dual;”都没有出现在Trace文件,Trace文件内容如下:

Unix process pid: 8900, image: [email protected] (TNS V1-V3)
*** 2010-04-13 06:55:24.247
*** SESSION ID:(72.604) 2010-04-13 06:55:24.247
*** CLIENT ID:([email protected]) 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

Otc: 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:当前行源的数据访问操作

时间: 2024-10-12 09:08:22

通过案例学调优之--10046事件的相关文章

存储过程调优之“10046”事件

一.前言 前段时间应需求,写存储过程,以满足避免在大数据量的原始表中进行直接的查询工作.从而生成一张中间表,用于以后各个维度的报表统计 从而提高每张报表的查询效率.久而久之,随着存储过程越来越多,每天的任务耗时也越来越大,从而不得不考虑对存储过程进行优化. 二."10046"事件 Oracle的10046事件,它可以跟踪应用程序所执行的SQL语句,从而得到每条SQL的解析次数,执行次数,CPU使用时间,每条SQL中每个部位的耗时等.这样,我们 就可以根据这些信息来分析.定位数据库的性能

通过案例学调优之--模拟buffer busy waits事件

通过案例学调优之--模拟buffer busy waits事件 buffer busy waits等待事件     Wait occurs when a session attempts to access a block in memory, is denied and must wait until the buffer becomes available. This event happens because a buffer is either being read into the b

通过案例学调优之--Oracle参数(db_file_multiblock_read_count)

通过案例学调优之--Oracle参数(db_file_multiblock_read_count) 应用环境: 操作系统: RedHat EL55 Oracle:   Oracle 10gR2   Oracle DB_FILE_MULTIBLOCK_READ_COUNT是Oracle比较重要的一个全局性参数,可以影响系统级别及sessioin级别.主要是用于设置最小化表扫描时Oracle一次按顺序能够读取的数据块数.通常情况下,我们看到top events中的等待事件db file scatte

通过案例学调优之--RECORDS_PER_BLOCK参数

通过案例学调优之--RECORDS_PER_BLOCK参数      RECORDS_PER_BLOCK参数用于设定每个BLOCK中记录数的最大值,其先找到当前表所有BLOCK中容纳的最大行数,并会把这个数字记录到数据字典,以后任何导致BLOCK行数超过这个数字的插入都会被拒绝. RECORDS_PER_BLOCK参数是为位图索引而生的,能够改善位图索引的存储,减小位图索引的长度.这样,利用该位图索引的时候,就能获得比较好的效率了.     测试案例: 1.表默认的存储分析 15:45:46 [

通过案例学调优之--Oracle Time Model(时间模型)

通过案例学调优之--Oracle Time Model(时间模型) 数据库时间  优化不仅仅是缩短等待时间.优化旨在缩短最终用户响应时间和(或)尽可能减少每个请求占用的平均资源.有时这些目标可同时实现,而有时则需要进行折衷(如在并行查询时).通常可以认为,优化就是避免以浪费的方式占用或保留资源. 对数据库发出的任何请求都由两个不同的段组成:等待时间(数据库等待时间)和服务时间(数据库 CPU 时间).等待时间是各种数据库实例资源的所有等待时间的总和.CPU 时间是实际处理请求时消耗的时间的总和.

通过案例学调优之--AWR BaseLine管理

通过案例学调优之--AWR BaseLine管理 BaseLine Baseline 是指一个特定时间段内的性能数据,保留这些数据是为了在性能问题产生时与其他类似的工作负载时间段进行比较.Baseline 中包含的快照将从自动 AWR 清理进程中排除,并无限期的保留. 在 Oracle Database 中存在多种类型的 baseline:      Fixed Baseline:fixed baseline 表示的是您指定的一个固定的.连续的时间段.在创建 fixed baseline 之前,

通过案例学调优之--SQL Profile

通过案例学调优之--SQL Profile 一.什么是SQL Profile(概要) SQL Profile在性能优化中占有一个重要的位置. MOS里这么描述SQL Profile: SQL Profile是10g中的新特性,作为自动SQL调整过程的一部分,由Oracle企业管理器来管理.除了OEM,SQL Profile可以通过DBMS_SQLTUNE包来进行管理. 查询优化器有时候会因为缺乏足够的信息,而对一条SQL语句做出错误的估计,生成糟糕的执行计划.而自动SQL调整通过SQL概要分析来

通过案例学调优之--AWR基本概念

通过案例学调优之--AWR基本概念 一.Automatic Workload Repository 概念详解 Automatic Workload Repository (AWR) 收集.处理和维护用于问题诊断的性能统计信息.该数据既存在于数据块中,也存在于内存中.AWR 收集的数据可以通过报告和视图进行查看. AWR 处理和收集的统计信息包括: 1.确定数据块 segment 访问路径和使用情况的对象统计信息 2.基于数据库活动的时间使用情况的时间模型统计信息,可在 V$SYS_TIME_MO

通过案例学调优之--AWR baseline对比生成AWR报告

通过案例学调优之--AWR Baseline对比生成AWR报告 一.建立Baseline 查看snapshot: 16:46:08 [email protected] prod >select SNAP_ID,BEGIN_INTERVAL_TIME from dba_hist_snapshot;    SNAP_ID BEGIN_INTERVAL_TIME ---------- -----------------------------------------------------------