Oracle Event 10046
我们在分析应用程序性能问题的时候，更多地需要关注其中SQL语句的执行情况，通常因为应用程序的SQL语句写的不规范而使性能瓶颈落在数据库这边，因此数据库的SQL语句是我们优化的重点。一般情况下我们可以通过初始化参数SQL_TRACE=TRUE来设置SQL跟踪。我们也可以通过设置10046事件来进行SQL跟踪, 10046事件是ORACLE用于系统性能分析时的一个最重要的事件。当激活这个事件后，将通知ORACLE内核追踪会话的相关即时信息，并写入到相应TRACE文件中，利用ORACLE的10046事件，可以跟踪应用程序所执行的SQL语句，并且得到其解析次数.执行次数,CPU使用时间等信息，这对我们分析、定位数据库性能问题是非常有用的。
追踪级别
10046事件来进行SQL跟踪，可以设置不同的跟踪级别，比使用SQL_TRACE获得更多的信息。
Level 0：停用SQL跟踪，相当于SQL_TRACE=FALSE
Level 1：标准SQL跟踪，相当于SQL_TRACE=TRUE，此级别调试事件处于激活状态。针对每个被处理的数据库调用，输出SQL语句,APPNAME（应用程序名）,PARSING IN CURSOR,PARSE ERROR（SQL解析）,EXEC（执行）,FETCH（获取数据）,UNMAP,SORT UNMAP（排序，临时段）,ERROR,STAT（执行计划）,XCTEND（事务）等信息。
Level 4：在level 1的基础上增加BIND（绑定变量信息）
Level 8：在level 1的基础上增加WAIT（等待事件信息）。对于处理过程中的每个等待，提供等待时间的名字，持续时间，以及一些额外的参数，可表明所等待的资源等信息。
Level 12：在level 1的基础上增加绑定变量和等待事件的信息，也就是Level 4及Level 8的所有信息。
10046事件不但可以跟踪用户会话(trace文件位于USER_DUMP_DEST )，也可以跟踪background进程(trace文件位于BACKGROUND_DUMP_DEST )。trace文件的大小决定于4个因素：跟踪级别，跟踪时长，会话的活动级别和MAX_DUMP_FILE_SIZE参数。
10046事件相关参数
在启动10046事件之前，通常会需要修改以下几个参数：
1.TIMED_STATISTICS
用于控制计时信息，可以设定为true和false。当设定为true时，计时信息将会被添加到trace文件中。
2.MAX_DUMP_FILE_SIZE
用于控制trace文件的最大尺寸。当使用10046事件时，建议将该参数设定为unlimited或较大的阀值。
3.USER_DUMP_DEST
用于设定trace文件写入到哪个文件目录。
4.STATISTICS_LEVEL
用于控制统计信息的收集度。此参数有3个选择，baisc，typical，all。
basic:仅收集满足trace所需的最基本的信息。
typical:此为缺省值。此设置将在basic的基础上增加一些额外的统计信息，象操作系统耗用时间的统计信息，执行计划的统计信息都会被收集
all:当设置为all时，所有与该session相关的信息全部会被收集。
5.TRACEFILE_IDENTIFIER 用于设置识别Trace文件的字符串，便于更快捷的找到生成的Trace文件。
10046事件启动级别
10046事件的启动级别大致分为当前会话级、其他会话级和全局级。
10046事件的启动与关闭
1.当前会话级：
在开启10046事件之前，先检查相关的参数设置，修改不满足条件的参数。
SQL> select * from v$version; BANNER ---------------------------------------------------------------- Oracle Database 10g Enterprise Edition Release 10.2.0.5.0 - Prod PL/SQL Release 10.2.0.5.0 - Production CORE 10.2.0.5.0 Production TNS for Linux: Version 10.2.0.5.0 - Production NLSRTL Version 10.2.0.5.0 - Production SQL> show parameter timed_statistics NAME TYPE VALUE ---------------------------- ------- ----- timed_statistics boolean TRUE SQL> show parameter max_dump_file_size NAME TYPE VALUE --------------------- ------ --------- max_dump_file_size string UNLIMITED SQL> show parameter tracefile_identifier NAME TYPE VALUE -------------------- ----------- ------ tracefile_identifier string
为了方便查找生成的trace文件，这里设置tracefile_identifier参数为find10046，这个参数只能在SESSION级修改。
SQL> ALTER SESSION SET tracefile_identifier=find10046; Session altered. SQL> show parameter tracefile_identifier NAME TYPE VALUE -------------------- ------ --------- tracefile_identifier string FIND10046
追踪当前会话比较简单，通过以下SQL即可开启10046事件
SQL> ALTER SESSION SET EVENTS '10046 trace name context forever, level 12';
Session altered.
SQL> select * from t_test;
ID CODE IDENTIFIER
---------- ----- --------------------
1 01 01-01-0001-000001
2 02 02-01-0001-000001
3 03 03-01-0001-000001
4 04 04-01-0001-000001
5 05 05-01-0001-000001
SQL> ALTER SESSION SET EVENTS '10046 trace name context off';
Session altered.
查找trace文件
由于设置了tracefile_identifier参数，在udump目录下名字包含FIND10046的trace文件就是10046追踪文件。
SQL> show parameter user_dump NAME TYPE VALUE --------------- ----------- ---------------------------------- user_dump_dest string /u01/app/oracle/admin/ora10g/udump [oracle@dbdream ~]$ cd /u01/app/oracle/admin/ora10g/udump/ [oracle@dbdream udump]$ ls *FIND* ora10g_ora_4203_FIND10046.trc
2.其他会话级
追踪其他会话级的SQL相对繁琐，首先要查到要追踪会话的SID和SERIAL#，本案例用SYS用户追踪STREAM用户执行的SQL。
SQL> select sid,serial# from v$session where username='STREAM';
SID SERIAL#
---------- ----------
158 91
追踪其他会话的SQL需使用dbms_system包，实验步骤如下：
为了方便查找trace文件，设置tracefile_identifier参数：
SQL> ALTER SESSION SET tracefile_identifier='dbms_system_10046'; Session altered.
描述下dbms_system包，看下具体参数：
SQL> desc dbms_system 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
使用dbms_system包追踪stream用户会话的SQL：
SQL> execute sys.dbms_system.set_ev(158,91,10046,12,''); PL/SQL procedure successfully completed.
stream用户执行SQL：
SQL> select * from t_test;
ID CODE IDENTIFIER
---------- ----- --------------------
1 01 01-01-0001-000001
2 02 02-01-0001-000001
3 03 03-01-0001-000001
4 04 04-01-0001-000001
5 05 05-01-0001-000001
sys用户关闭10046追踪：
SQL> execute sys.dbms_system.set_ev(158,91,10046,0,''); PL/SQL procedure successfully completed.
由于之前设置tracefile_identifier参数为’dbms_system_10046’，udump目录下名字包含dbms_system_10046的文件即为10046的追踪文件。
[oracle@dbdream udump]$ ls *dbms* ora10g_ora_6737_dbms_system_10046.trc
3.全局追踪
全局追踪需修改数据库初始化参数event，这是个静态参数，修改后需重启数据库。
SQL> alter system set event="10046 trace name context forever, level 12"scope=spfile; System altered.
开启10046全局SQL追踪，重启数据库后所有登录会话的SQL都会被追踪，保存到udump目录下，以操作系统的进程号区分，如下实验：
SQL> shutdown immediate
SQL> startup
stream用户登录，并执行SQL：
SQL> select * from t_test;
ID CODE IDENTIFIER
---------- ----- --------------------
1 01 01-01-0001-000001
2 02 02-01-0001-000001
3 03 03-01-0001-000001
4 04 04-01-0001-000001
5 05 05-01-0001-000001
查看stream用户的操作系统进程号：
SQL> select s.username, p.spid os_process_id, p.pid oracle_process_id 2 from v$session s, v$process p 3 where s.paddr = p.addr and s.username ='STREAM'; USERNAME OS_PROCESS_I ORACLE_PROCESS_ID ------------------------------ ------------ ----------------- STREAM 7713 21
可见，这个会话的进程号是7713，到udump目录下查找名字包含7713的文件。
[oracle@dbdream udump]$ ls *7713* ora10g_ora_7713.trc
分析trace文件
ORACLE直接生成的trace文件一般很难看懂，使用ORACLE提供的工具tkprof工具格式化后，就比较人性化，也比较容易看懂。
[oracle@dbdream ~]$ tkprof /u01/app/oracle/admin/ora10g/udump/ ora10g_ora_7713.trc /home/oracle/tk_10046.txt sys=no TKPROF: Release 10.2.0.5.0 - Production on Wed Aug 15 11:16:40 2012 Copyright (c) 1982, 2007, Oracle. All rights reserved.
tkprof格式化后会在指定目录生成格式化后的文件：
[oracle@dbdream ~]$ ls tk_10046.txt tk_10046.txt
用编辑器打开格式化后的tk_10046.txt文件，就可以看到10046追踪的信息，也可以看到这个会话都干了哪些事情，以及执行一个SQL，递归调用了哪些SQL，本案例只拆去测试SQL。
[oracle@dbdream ~]$ vi tk_10046.txt ****************************************************************************** select * from t_test call count cpu elapsed disk query current rows ------- ----- ------ -------- ------- ------- -------- ------- Parse 1 0.00 0.05 2 287 0 0 Execute 1 0.00 0.00 0 0 0 0 Fetch 2 0.00 0.00 0 19 0 5 ------- ----- ------ -------- ------- ------- -------- ------- total 4 0.00 0.05 2 306 0 5 Misses in library cache during parse: 1 Optimizer mode: ALL_ROWS Parsing user id: 31 (STREAM)
以上部分列出了这个SQL解析多少次，执行多少次等概述信息，一般我们关注的是DISK,QUERY和CURRENT等信息。
Rows Execution Plan
------- ---------------------------------------------------
0 SELECT STATEMENT MODE: ALL_ROWS
0 PARTITION LIST (ALL) PARTITION: START=1 STOP=5
0 TABLE ACCESS (FULL) OF 'T_TEST' (TABLE) PARTITION: START=1
STOP=5
以上部分为该SQL的执行计划信息。
Elapsed times include waiting on following events: Event waited on Times Max. Wait Total Waited ---------------------------------------- Waited ---------- ------------ SQL*Net message to client 2 0.00 0.00 SQL*Net message from client 1 0.00 0.00 ******************************************************************************
以上部分为该SQL执行过程的等待事件信息。
10046事件的这些功能，利用dbms_monitor包和dbms_support包及oradebug工具也都可以实现，有关dbms_monitor包可参考我之前写的一篇《使用dbms_monitor跟踪其他SESSION的信息》文章，有关oradebug工具的使用，我在《Hanganalyze学习笔记》中略有介绍，oradebug工具和dbms_support包的使用，我会在下一篇文章介绍。
本文固定链接: https://www.dbdream.com.cn/2012/08/oracle-event-10046/ | 信春哥，系统稳，闭眼上线不回滚！
Oracle Event 10046：目前有2 条留言
发表评论
写的还行全的，
2012-10-12 12:46@summer
2012-10-12 12:59也挺浅的，呵呵