Oracle 10046事件详解

Oracle的10046事件，可以跟踪应用程序所执行的SQL语句，并且得到其解析次数.执行次数,CPU使用时间等信息。这对我们分析、定位数据库性能问题是非常有用的。
10046event是oracle用于系统性能分析时的一个最重要的事件。当激活这个事件后，将通知oracle kernel追踪会话的相关即时信息，并写入到相应trace文件中。这些有用的信息主要包括sql是如何进行解析，绑定变量的使用情况，会话中发生的等待事件等
10046event 可分成不同的级别（level），分别追踪记录不同程度的有用信息。对于这些不同的级别，应当注意的是向下兼容的，即高一级的trace信息包含低于此级的所有信息。
10046event的追踪级别大致有：
level 1：跟踪sql语句，包括解析、执行、提取、提交和回滚等。
level 4：包括变量的详细信息
level 8：包括等待事件
level 12：包括绑定变量与等待事件
其中，level 1相当于打开了sql_trace
前提条件：
（先确保要event的会话环境符合条件）
1、必须确保timed_statistics为TRUE，这个参数可以在会话级上进行修改。
2、为了确保trace输出能够完整进行，还要调整此会话对trace文件大小的限制，一般将此限制取消，即将max_dump_file_size设置为UNLIMITED，或者设置为一个很大的阙值。

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

获取当前会话SID

select sid from v$mystat where rownum<2

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、10046事件启动
SQL>execute sys.dbms_system.set_ev(15,196,10046,1,'');
PL/SQL procedure successfully completed.
参数说明：
15:SID
196:SERIAL#
注意这里必须以sysdba登录。
或者会话级别的跟踪：
SQL> alter session set events '10046 trace name context forever ,level 12' ;
会话已更改。
3、在应用程序中执行对数据库的操作
比如性能较差的一些查询、插入、删除操作等。
4、10046事件的关闭
SQL>execute sys.dbms_system.set_ev(15,196,10046,0,'');
PL/SQL procedure successfully completed.
或者对应上面的，在会话级别关闭
SQL> alter session set events '10046 trace name context off' ;
会话已更改。
5、获得产生的跟踪文件所在的目录
SQL> select value from v$parameter where name = 'user_dump_dest';

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

6、使用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       


timed_statistics的理解
关于参数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.


本人的理解是:参数timed_statistics没有设置的话.Oracle只记录wait开始和wait结束这一段时间内的wait reason和wait结束是否是因为timed out.而设置timed_statistics=true后.Oracle就记录了wait的时间信息.有了这些时间信息可以确定等待事件在哪个时间段出现比较频繁.   请指正


在timed_statistics  = false时,我们只能够知道这些等待时间的次数(records the reason for each wait ), 以及等待时间timed out的次数(records whether it timed out)


在timed_statistics = true时,我们可以知道系统在某个具体的等待事件上等待的时间(records the time waited),这样我们就可以判断具体是什么原因导致我们的系统变慢或者.