10046 trace介绍及跟踪等级
10046是一个Oracle的内部事件(event),通过设置这个事件可以得到Oracle内部执行系统解析、调用、等待、绑定变量等详细的trace信息,对于分析系统的性能有着非常重要的作用。
设置10046事件的不同级别能得到不同详细程度的trace信息,下面就列出各个不同级别的对应作用:
等级二进制作用00000无输出10001输出 ****,APPNAME(应用程序名),PARSING IN CURSOR,PARSE ERROR(SQL解析),EXEC(执行),FETCH(获取数据),UNMAP,SORT UNMAP(排序,临时段),ERROR,STAT(执行计划),XCTEND(事务)等行20011与等级1完全一样40101包括等级1的输出,加上BIND行(绑定变量信息)81001包括等级1的输出,加上WAIT行(等待事件信息)121101输出等级1、等级4以及等级8的所有信息等级1的10046 trace被视为是普通的SQL Trace,而等级4、等级8以及等级12则被称为Extended SQL Trace,Extended SQL Trace里面包括了最有用的WAIT信息,因此在实际中也是用的最多的。
?
在打开10046时间的SQL Trace之前,要先设置好下面几个参数。
timed_statistics这个参数决定了是否收集与时间相关的统计信息,如果这个参数为FALSE的话,那么SQL Trace的结果基本没有多大的用处,默认情况下这个参数设置为TRUE。max_dump_file_sizedump文件的大小,也就是决定是否限制SQL Trace文件的大小,在一个很忙的系统上面做SQL Trace的话可能会生成很多的信息,因此最好在会话级别将这个参数设置成unlimited。tracefile_identifier给Trace文件设置识别字符串,这是个非常有用的参数,设置一个易读的字串能更快的找到Trace文件。要在当前会话修改上述参数很简单,只要使用下面的命令即可:
123456789101112131415161718192021222324252627282930313233343536373839404142434445Unix process pid: 8900, image: oracle@orainst.desktop.mycompany.com (TNS V1-V3)??*** 2010-04-13 06:55:24.247*** SESSION ID:(72.604) 2010-04-13 06:55:24.247*** CLIENT ID:(oracle@orainst.desktop.mycompany.com) 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 STMTEXEC #1:c=0,e=113,p=0,cr=0,cu=0,mis=1,r=1,dep=0,og=1,plh=0,tim=1271141724247201WAIT #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.913WAIT #1: nam='SQL*Net message from client' ela= 8666025 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1271141732913790CLOSE #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 dualEND OF STMTPARSE #2:c=1000,e=18805,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=1388734953,tim=1271141732932792EXEC #2:c=0,e=47,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1388734953,tim=1271141732932946WAIT #2: nam='SQL*Net message to client' ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1271141732932989FETCH #2:c=0,e=17,p=0,cr=0,cu=0,mis=0,r=1,dep=0,og=1,plh=1388734953,tim=1271141732933035STAT #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=1271141732933287FETCH #2:c=0,e=3,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1388734953,tim=1271141732933331WAIT #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.413WAIT #2: nam='SQL*Net message from client' ela= 15480453 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1271141748413833CLOSE #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 STMTPARSE #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