了解raw trace文件的各项内容

今天浏览metalink,看到这篇Interpreting Raw SQL_TRACE,比较老的一篇文章了,但是确实很有用,所以决定大略翻译一下吧。

我们知道有几种方法可以得到一个SQL语句执行时后台的trace文件,一个是用SQL_TRACE,一个是用DBMS_SUPPORT包或者DBMS_SYSTEM包,还有一种就是直接使用10046 event。

使用10046 event的方法大致如下:

alter session set events '10046 trace name context forever, level 12';<BR>

your sql statement...

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

其中的level有1,4,8,12几个选项,其中1相当于设置SQL_TRACE=TRUE之后的结果,4包括1的结果和绑定变量的实际值,8包括1的结果和等待事件的情况,12则同时包含1的结果,绑定变量的实际值和等待事件情况,所以可以说level 12是最为详细的trace了。

同时我们也知道,对于trace结果,oracle提供了tkprof实用程序用来格式化trace文件,提供一份更容易读懂的trace结果。

那么为什么还要直接读取trace文件呢?最重要的是tkprof的结果是不包含绑定变量值的,同时也不包括真正的SQL执行顺序,而trace文件中我们则可以看到按照时间排列的parse,binds,executes,fetch等等,这在某西场合下是很有用处的。还有就是,如果你能够直接读取这些让人看得眼晕的trace,是不是会有一种很爽,很大师的感觉:-)

当然如果我们要根据一些标准(比如CPU时长,磁盘读取量等)进行trace中的SQL排序,那么tkprof是我们唯一的选择,可以参看coolyl的Tkprof工具介绍和分析。

 

下面是metalink中的这篇文章的大体翻译,大部分名词用英文反而更好,就不强加翻译了,相信大家都看得懂。当然也是比较懒的原因:-)

 

文本总结了trace结果原始输出文件中的内容。

 

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

APPNAME mod='%s' mh=%lu act='%s' ah=%lu

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

 

APPNAME:Application name setting。在Oracle 7.2和以上版本中出现。这个名称可以由DBMS_APPLICATION_INFO包来设定。

mod:Module name

mh:Module hash value

act:Action

ah:Action hash value

 

比如:APPNAME mod='SQL*Plus' mh=3669949024 act='' ah=4029777240

 

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

PARSING IN CURSOR #<CURSOR> len=X dep=X uid=X oct=X lid=X tim=X hv=X ad='X'

<statement>

END OF STMT

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

 

<CURSOR>:Cursor number

len :Length of SQL statement,SQL语句的长度

dep :Recursive depth of the cursor,当前SQL语句的递规深度,如果为0则表示是用户提交的SQL,为1则是由于用户SQL而导致Oracle后台自己执行的SQL,为2则是由1级SQL继续诱发的下一级SQL。

uid :Schema user id of parsing user

oct :Oracle command type.

lid :Privilege user id.

tim :Timestamp。在Oracle9i之前单位是1/100秒,9i则是1/1,000,000秒。利用这个值可以计算一个SQL执行了到底多长时间。这个值就是当前行被写入trace文件时数据库V$TIMER视图的值。

hv :Hash id.

ad :SQLTEXT address,SQLTEXT的地址,跟V$SQLAREA和V$SQLTEXT视图中的ADDRESS字段值相等。

<statement> :The actual SQL statement being parsed.

 

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

PARSE ERROR #%d:len=%ld dep=%d uid=%ld oct=%d lid=%ld tim=%lu err=%d

<statement> ...

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

 

PARSE ERROR :在Oracle 7.2以上版本中解析的错误会写入trace文件中。

len :Length of SQL statement.

dep :Recursive depth of the statement

uid :User id.

oct :Oracle command type (if known).

lid :Privilege user id.

tim :Timestamp.

err :Oracle error code (e.g. ORA-XXXXX) reported

<statement> :The SQL statement that errored.

 

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

PARSE #<CURSOR>:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=0

EXEC #<CURSOR>:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=0

FETCH #<CURSOR>:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=0

UNMAP #<CURSOR>:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=0

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

 

PARSE :Parse a statement. 解析一个SQL

EXEC :Execute a pre-parsed statement. 执行已经解析完毕的SQL

FETCH :Fetch rows from a cursor. 从游标中得到数据,通常指select返回记录

UNMAP :如果游标使用了临时表(temporary table), 当游标关闭的时候将会看到UNMAP

c :CPU time (100th's of a second in Oracle7 ,8 and 9).

e :Elapsed time (100th's of a second Oracle7, 8. Microseconds in Oracle 9 onwards).

p :Number of physical reads.

cr :Number of buffers retrieved for CR reads.

cu :Number of buffers retrieved in current mode.

mis :Cursor missed in the cache.

r :Number of rows processed.

dep :Recursive call depth (0 = user SQL, >0 = recursive).

og :Optimizer goal: 1=All_Rows, 2=First_Rows, 3=Rule, 4=Choose

tim :Timestamp (large number in 100ths of a second).

 

比如:FETCH #2:c=0,e=106,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=4,tim=6005498548671

 

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

ERROR #%d:err=%d tim=%lu

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

 

执行或者fetch之后出现的SQL Error

err :Oracle error code (e.g. ORA-XXXXX) at the top of the stack.

tim :Timestamp.

 

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

STAT #<CURSOR> id=N cnt=0 [pid=0 pos=0 obj=0 op='SORT AGGREGATE ']

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

 

<CURSOR>的执行计划.

<CURSOR> :Cursor which the statistics apply to.

id :Line of the explain plan which the row count applies to (从1开始).

cnt :Number of rows for this row source.

pid :Parent id of this row source.

pos :Position in explain plan.

obj :Object id of row source (if this is a base object).

op : The row source access operation.

 

比如:

STAT #2 id=2 cnt=0 pid=1 pos=1 obj=510 op='TABLE ACCESS BY INDEX ROWID OBJECT_USAGE (cr=2 r=0 w=0 time=83 us)'

STAT #2 id=3 cnt=1 pid=2 pos=1 obj=511 op='INDEX RANGE SCAN I_STATS_OBJ# (cr=1 r=0 w=0 time=43 us)'

 

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

XCTEND rlbk=%d rd_only=%d

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

 

XCTEND是事务结束的标志.

rlbk :1 if a rollback was performed, 0 if no rollback (commit).

rd_only :1 if transaction was read only, 0 if changes occurred.

 

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

BINDS #%d:

bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=03 oacfl2=0 size=24 offset=0

bfp=02fedb44 bln=22 avl=00 flg=05

value=10

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

 

BIND :Variables bound to a cursor.

bind N :The bind position being bound.

dty :Data type.

mxl :Maximum length of the bind variable (private max len in paren).

mal :Array length.

scl :Scale.

pre :Precision.

oacflg :Special flag indicating bind options

oacflg2 :Continuation of oacflg

size :Amount of memory to be allocated for this chunk

offset :Offset into this chunk for this bind buffer

bfp :Bind address.

bln :Bind buffer length.

avl :Actual value length (array length too).

flg :Special flag indicating bind status

value :The actual value of the bind variable.

 

比如:

BINDS #4:

 bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24 offset=0

   bfp=ffffffff7ce64ee0 bln=22 avl=01 flg=05

   value=0

 bind 1: dty=1 mxl=32(11) mal=00 scl=00 pre=00 oacflg=18 oacfl2=1 size=32 offset=0

   bfp=ffffffff7ce6b128 bln=32 avl=11 flg=05

   value="TABCOMPART$"

 bind 2: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24 offset=0

   bfp=ffffffff7ce6bae8 bln=24 avl=02 flg=05

   value=1

 

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

WAIT #<CURSOR>: nam="<event name>" ela=0 p1=0 p2=0 p3=0

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

 

WAIT :An event that we waited for.

nam :What was being waited for.

ela :Elapsed time for the operation.

p1 :P1 for the given wait event.

p2 :P2 for the given wait event.

p3 :P3 for the given wait event.

 

比如 (Full Table Scan):

WAIT #1: nam="db file scattered read" ela= 5 p1=4 p2=1435 p3=25

在游标1上经历了"db file scattered read"等待事件,一共等了0.05秒,在读取File 4,从1435 block开始,读了25个block

 

比如 (Index Scan):

WAIT #1: nam="db file sequential read" ela= 4 p1=4 p2=1224 p3=1

在游标1上经历了"db file sequential read"等待事件,一共等了0.04秒,在读取file 4,block 1224,读取了这一个block

 

对于每一个等待事件的含义和p1,p2,p3表示的意思,可以参考Oracle Database Reference文档的Oracle Wait Events章节。

 

时间: 2016-02-09

了解raw trace文件的各项内容的相关文章

Trace文件过量生成问题解决

  随着Oracle技术本身的不断发展,"自动化"和"智能化"的数据库时代已经来临.无论是运维管理.开发调试,传统DBA们的工作内容都已经发生了很大变化.一些诸如内存池划分调整.归档日志管理等功能,都已经被Oracle自动或者半自动的特性所解决.对新一代DBA而言,保持不断学习的精神,接受新问题,发现属于自己的一片新天地,才是当务之急. 今天,和一个朋友解决了一个运维环境问题.笔者感觉很有意思,记录下来,供需要的朋友不时之需.   1.问题说明   今天,一个朋友从

android文件操作——读取assets和raw文件下的内容_Android

来自Resources和Assets 中的文件只可以读取而不能进行写的操作. assets文件夹里面的文件都是保持原始的文件格式,需要用AssetManager以字节流的形式读取文件. 1. 先在Activity里面调用getAssets() 来获取AssetManager引用. 2. 再用AssetManager的open(String fileName, int accessMode) 方法则指定读取的文件以及访问模式就能得到输入流InputStream. 3. 然后就是用已经open fi

android文件操作——读取assets和raw文件下的内容

来自Resources和Assets 中的文件只可以读取而不能进行写的操作. assets文件夹里面的文件都是保持原始的文件格式,需要用AssetManager以字节流的形式读取文件. 1. 先在Activity里面调用getAssets() 来获取AssetManager引用. 2. 再用AssetManager的open(String fileName, int accessMode) 方法则指定读取的文件以及访问模式就能得到输入流InputStream. 3. 然后就是用已经open fi

通过Android trace文件分析死锁ANR实例过程_Android

对于从事Android开发的人来说,遇到ANR(Application Not Responding)是比较常见的问题.一般情况下,如果有ANR发生,系统都会在/data/anr/目录下生成trace文件,通过分析trace文件,可以定位产生ANR的原因.产生ANR的原因有很多,比如CPU使用过高.事件没有得到及时的响应.死锁等,下面将通过一次因为死锁导致的ANR问题,来说明如何通过trace文件分析ANR问题. 对应的部分trace文件内容如下: "PowerManagerService&qu

【Oracle】一款非常好用的trace文件分析工具之一

介绍一款非常好用的10046分析工具--trca(Trace Analyzer),以前分析10046跟踪文件的时候都是使用tkprof 工具,但是trca 比tkprof要简单的多而且分析的结果更全面: 可以从ML的文章:Trace Analyzer TRCANLZR - Interpreting Raw SQL Traces with Binds and/or Waits generated by EVENT 10046 [ID 224270.1] 来下载此工具! trca.zip 主要包括一

【Oracle】一款非常好用的trace文件分析工具之二

前一篇文章介绍了如何安装trca,接下来介绍如何使用trca:必须进入 trca/run 目录里面 或者把 /home/oracle/software/trca/run 放到SQL_PATH环境变量里面: 使用trcanlzr.sql的时候可以直接跟trace 文件名字,该工具默认会到user_dump_dest 里面去找(对于10g以前的,会到bdump_dest 里面去找跟踪文件) sys@RAC> show parameter user_dump_dest NAME            

如何分析SQL Server Trace文件

1.问题引出 老鸟为了重点栽培菜鸟,决定交给菜鸟一个艰巨而光荣的任务.这天,菜鸟刚到公司还未坐下,老鸟便劈头盖脸的问道:"你知道,我们如何Trace SQL Server执行语句吗?怎么手动分析这些Trace文件?如何将Trace File与Windows的性能监视器结合,看到每个语句执行时的性能开销?以及如何自动分析SQL Server Trace文件?". 菜鸟还没有反应过来,就被杀死了99%的老细胞,下意识的回答:"啊?". "去研究下吧"

Oracle 事件之10046 跟踪的trace文件相关解释 tkprof

Oracle事件之10046 跟踪的trace文件相关解释 tkprof 优化       sql_trace/10046事件是oracle提供的用于进行sql跟踪的手段,其内容包括sql的解析过程.sql的执行计划.绑定变量的使用.会话发生的等待事件.          在使用sql_trace/10046事件前,有两个参数需要注意:    >                                                                            

java-Java 的 .class 文件里面的内容复制到另外一个TXT文件里面还能执行吗?

问题描述 Java 的 .class 文件里面的内容复制到另外一个TXT文件里面还能执行吗? 就是把 *.class文件里面的内容复制到一个文本文档里面,然后再把文件的后缀名改成.class,那么这个新的.class文件还可以运行吗? 解决方案 当然可以喽,运行的本来就是文件嘛,亲测没问题 解决方案二: 用的记事本喽,ansi 解决方案三: 测试过了,不可以.在EditPlus下以Hex viewer编码打开,将内容复制后保存成ANSI编码,文件就变大了.运行java命令报异常不兼容的默数值.理