Oracle 10046 event详解(原创)

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

10046 event是oracle用于系统性能分析时的一个最重要的事件。当激活这个事件后，将通知oracle kernel追踪会话的相关即时信息，并写入到相应trace文件中。这些有用的信息主要包括sql是如何进行解析，绑定变量的使用情况，会话中发生的等待事件等

10046 event 可分成不同的级别（level），分别追踪记录不同程度的有用信息。对于这些不同的级别，应当注意的是向下兼容的，即高一级的trace信息包含低于此级的所有信息。

10046event的追踪级别大致有：

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.

本人的理解是:参数timed_statistics设置为true的话.Oracle记录等待事件的wait reason和等待事件开始和结束的时间点，以及该等待是否超时。timed_statistics=false后，Oracle只记录了等待事件和等待事件是否超时的信息。
在timed_statistics  = false时,我们只能够知道这些等待时间的次数(records the reason for each wait ), 以及等待时间timed out的次数(records whether it timed out)
在timed_statistics = true时,我们可以知道系统在某个具体的等待事件上等待的时间(records the time waited),这样我们就可以判断具体是什么原因导致我们的系统变慢或者跟踪数据库进行的操作，有了这些时间信息可以确定等待事件在哪个时间段出现比较频繁。时间的统计信息会被更新到V$SESSTATS和V$SYSSTATS视图中。11.1.0.7以后如果STATISTICS_LEVEL被设置为typical或者all，则不能将timed_statistics设置为false

2、为了确保trace输出能够完整进行，还要调整此会话对trace文件大小的限制，一般将此限制取消，即将max_dump_file_size设置为UNLIMITED，或者设置为一个很大的阙值。

在满足了上述条件后，就可以启用10046 event对会话进行后台跟踪了。
使用10046事件

1、首先获得spid、sid、serial#，machine为连接oracle的机器名
select b.spid,a.sid,a.serial#,a.machine from v$session a,v$process b where a.paddr =b.addr  and a.sid = '159'

继续往下看，就可以知道为什么找到SPID了；

2、trace的开启和关闭
使用sql_trace
SQL> alter system set sql_trace=true;   --开启系统级别的sql_trace
SQL> alter session set sql_trace=true;   --开启会话级别的sql_trace
SQL> execute dbms_system.set_sql_trace_in_session(267,996,true); 
PL/SQL 过程已成功完成。         -- 启动其他会话的SQL_TRACE
SQL> alter system set sql_trace=false;  --关闭系统级别的sql_trace
SQL> alter session set sql_trace=false;  --关闭会话级别的sql_trace

SQL> execute dbms_system.set_sql_trace_in_session(267,996,false);
PL/SQL 过程已成功完成。      -- 关闭其他会话的SQL_TRACE

使用10046 事件跟踪

SQL> alter session set events '10046 trace name context forever ,level 12' ;    会话已更改。 --开启本会话的10046事件

SQL> exec dbms_monitor.session_trace_enable(267,996,waits=>true,binds=>true);      
PL/SQL 过程已成功完成。       -- 开启其他会话的10046事件

SQL> alter session set events '10046 trace name context off' ;

会话已更改。 --关闭本会话的10046事件

SQL> exec dbms_monitor.session_trace_disable(267,996);
PL/SQL 过程已成功完成。            -- 关闭其他会话的10046事件

参数说明：
15:SID
196:SERIAL#

注意这里必须以sysdba登录。

3、获得产生的跟踪文件所在的目录
SQL> select value from v$parameter where name = 'user_dump_dest';

转到该目录下可以看到生成了一个zftang_ora_596.trc文件，此处的596即SPID的值。

4、使用tkprof命令，转换TRC文件
在命令行下执行oracle的tkprof命令，将zftang_ora_596.trc转化为文本文件

如：
$ tkprof  ora9i_ora_24722.trc ora9i_ora_24722.sql

此时在zftang_ora_596.sql文件中，就可以看到刚才执行应用程序时所执行的sql语句的执行次数、CPU使用时间等数据。

TRACE将消耗相当的系统资源，因此我们在使用TRACE的时候应当慎重。对于正式的系统，应当只在必要的时候进行TRACE操作，并且应当及时关闭。

********************************************************************************

count    = number of times OCI procedure was executed

cpu      = cpu time in seconds executing

elapsed  = elapsed time in seconds executing

disk     = number of physical reads of buffers from disk

query    = number of buffers gotten for consistent read

current  = number of buffers gotten in current mode (usually for update)

rows     = number of rows processed by the fetch or execute call

********************************************************************************

update test_01 set flag1 = '测试'

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.01          0          2          0           0

Execute      1      2.35       2.64        358       1865     220043       50782

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        2      2.35       2.65        358       1867     220043       50782

Misses in library cache during parse: 1

Optimizer mode: ALL_ROWS

Parsing user id: 63       

如何使用tkprof
http://czmmiao.iteye.com/blog/1493765
查看原始trace文件
http://czmmiao.iteye.com/blog/1493933
关于alter system event
http://czmmiao.iteye.com/blog/1330430 
注意：如果一条SQL语句中包含了通过DBLINK进行的数据操作，我们想对这条SQL进行trace跟踪，在本地只能够trace到本地执行的SQL信息，而对于远程的SQL语句，由于它运行在远端的数据库上，我们要获得它的信息，需要到远端的数据库上，找到运行这条SQL语句的session，然后对它做Trace。 另外，这条SQL语句的执行计划也只能从远端数据库上捕获到。
 

参考至:《让Oracle跑得更快》谭怀远著
            http://www.linuxidc.com/Linux/2011-04/35132p2.htm                  
            http://docs.oracle.com/cd/E11882_01/server.112/e25513/initparams255.htm#REFRN10218
本文原创，转载请注明出处、作者
如有错误，欢迎指正

邮箱:[e-mail]