深入理解Oracle调试事件：10046事件详解

今天，Think想和大家一起共同深入去理解一下Oracle的这些调试事件

   10046事件是SQL_TRACE的扩展，被戏称为"吃了兴奋剂的SQL_TRACE"
   有效的追踪级别：
   
   ① 0级：SQL_TRACE=FASLE
   ② 1级：SQL_TRACE=TRUE，这是缺省级别
   ③ 4级：1级+绑定变量
   ④ 8级：4级+等待事件
   ⑤ 12级：4级+8级
   
   对于4级的10046，若用tkprof格式化，则会隐藏每一点SQL语句在做什么以及怎么做
   对于8级的10046，等待事件散得到处多是，此时我们不妨用tkprof对等待事件进行汇总
   所以，理解扩展SQL跟踪文件的格式，是每一个面临性能问题或故障排除任务的DBA的必备技能
      
   ㈠ 为什么需要10046？
 
      对一个拥有alter session权限但是没有被授权DBA角色的数据库用户
      alter session set events是在他自己会话中启动扩展SQL跟踪的唯一方法
      通过这种方法将等待事件或者绑定变量包含在SQL跟踪文件中，然后进行优化或者错误诊断   

例如：
SQL> alter session set events ‘10046 trace name context forever, level 12’;
Session altered.
session（当前会话） 可以换成 system（所有会话）

生成的trc文件名为orcl_ora_4884.trc 4884是进程号

SQL> alter session set events ‘10046 trace name context off’; 关闭事件跟踪
Session altered.

show parameter count 可以看到每次读的块数

格式化trace：
tkprof orcl_ora_4884.trc a.txt 显示递归调用语句和其他
tkprof orcl_ora_4884.trc b.txt sys=no 不显示递归调用语句
不能跨区读块

      10046 看到语句的执行过程，知道语句的执行计划，包括各种步骤，关联方式，分别在哪些步骤耗时多少，有哪些等待事件等
      这些都是优化的基础，知道这些，就知道该如何优化以及troubleshoting
      
   
 
   ㈡ 如何获取trc文件？

      这里主要介绍3种方法
      
      ① 使用tracefile_identifier，比如：
         alter session set tracefile_identifier=\'Think\'

      ② oradebug,详细请请参看Think之前的一篇博客：oradebug

      ③ 使用下面的脚本：

hr@ORCL> ed
Wrote file afiedt.buf

1 select
2 d.value||’/’||lower(rtrim(i.instance, chr(0)))||‘ora’||p.spid||’.trc’ trace_file_name
3 from
4 ( select p.spid
5 from v$mystatm,v$session s,vKaTeX parse error: Expected 'EOF', got '#' at position 43: …ere m.statistic#̲ = 1 and s.sid …thread t,vKaTeX parse error: Can't use function '\'' in math mode at position 47: …where v.name = \̲'̲thread\' and (v…parameter where name = ‘user_dump_dest’) d
hr@ORCL> /

TRACE_FILE_NAME

/u01/app/oracle/admin/orcl/udump/orcl_ora_4012.trc

   ㈢ 如何读懂10046事件的文件？
   
   ① 数据库调用
   
   含3个子分类：解析，执行和获取
   这3个分类与通过调用DBMS_SQL的子例程DBMS_SQL.PARSE,DBMS_SQL.EXECUTE,DBMS_SQL.FETCH_ROWS来跑SQL的步调相一致
   
   解析
   解析在跟踪文件中通常通过两个相邻的条目表示
   第一个是PARSING IN CURSOR,第二个是PARSE

PARSING IN CURSOR #9 len=28 dep=0 uid=55 oct=2 lid=55 tim=1327904235010505 hv=119728103 ad=‘2fc6ae84’
insert into t values(‘ooxx’)
END OF STMT
PARSE #9:c=52003,e=65698,p=0,cr=30,cu=0,mis=1,r=0,dep=0,og=1,tim=1327904235010494

   执行和获取同解析在格式上是一样的，这里就不赘述了

   ② commit和rollback和XCTEND条目格式

XCTEND rlbk=0, rd_only=0

   Oracle不需要客户端显示地开始一个事务，DBMS在第一个数据项目被修改或分布式操作执行后会自动打开一个事务
   比如，通过dblink从一个表执行select
   在trc中事务的边界通过XCTEND条目标记，格式如下：
   XCTEND rlbk=[0-1],rd_only=[0-1]
 


  


   ③ 执行计划，统计信息与STAT条目格式
   
   STAT条目报告了执行计划和统计信息

STAT #6 id=1 cnt=0 pid=0 pos=1 obj=18 op=‘TABLE ACCESS BY INDEX ROWID OBJ$ (cr=2 pr=0 pw=0 time=194 us)’
STAT #6 id=2 cnt=0 pid=1 pos=1 obj=37 op=‘INDEX RANGE SCAN I_OBJ2 (cr=2 pr=0 pw=0 time=95 us)’

   一组STAT条目的每一行代表了形成语句结果的行源
   所谓的行源，指从索引或表中检索的数据或者多表连接的中间结果(因为必须先进行两表连接)
   
   10g以后，STAT条目仅在TIMED_STATISTICS=TRUE,并且SQL_TRACE=TRUE时才被写入
   请注意，若STATISTICS_LEVEL=BASIC(缺省为TYPICAL)时会隐式设置TIMED_STATISTICS=FASLE
 


 


   ④ 等待事件和WAIT条目格式

WAIT #9: nam=‘SQLNet message to client’ ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=52523 tim=1327922883350249
WAIT #9: nam='SQLNet message from client’ ela= 301 driver id=1650815232 #bytes=1 p3=0 obj#=52523 tim=1327922883350743

WAIT #11: nam=‘db file sequential read’ ela= 253 file#=1 block#=420 blocks=1 obj#=355 tim=1327923455671258
WAIT #11: nam=‘db file sequential read’ ela= 7073 file#=1 block#=43998 blocks=1 obj#=355 tim=1327923455678537
WAIT #11: nam=‘db file sequential read’ ela= 91 file#=1 block#=43999 blocks=1 obj#=355 tim=1327923455678836
WAIT #11: nam=‘db file sequential read’ ela= 14433 file#=1 block#=53521 blocks=1 obj#=355 tim=1327923455693393

   ⑤ 绑定变量和BINDS条目格式
   
   绑定变量的详细信息包括绑定变量的数据类型和值
   通过这些信息我们可以得到最大化的诊断
   例如，索引列的数据类型与绑定变量的数据类型不匹配，导致索引失效，CPU使用率增加，因为还存在隐式数据类型转换
   一个BINDS条目的结构由后面跟着游标编号的单词BINDS和每一个绑定变量单独的子部分组成

BINDS #9:
kkscoacd
Bind#0
oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
kxsbbbfp=b7ee5a5c bln=22 avl=02 flg=05
value=20
Bind#1
oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0
kxsbbbfp=b7ee5a38 bln=24 avl=02 flg=05
value=3

   当将绑定变量与子部分相关联时，不用关心数字，他们会被包含在绑定变量的名称中，例如 ":B1"

hr@ORCL> select dump(employee_id) from employees where rownum=1;

DUMP(EMPLOYEE_ID)

Typ=2 Len=2: 194,2