【转载】如何直接阅读Oracle中的trace文件

大部分情况下，我们可以利用tkprof工具格式化trace文件，让trace文件便于阅读，但trkprof产生的是trace文件的汇总结果，如果需要知道sql每一步确切执行了什么，我们也只能直接阅读trace 
==============================================
APPNAME mod='%s' mh=%lu act='%s' ah=%lu 
==============================================
APPNAME：Application name setting。在Oracle 7.2和以上版本中出现。这个名称可以由DBMS_APPLICATION_INFO包来设定。
mod：模块名
mh：模块的散列值
act：动作，如DBMS_APPLICATION_INFO
ah：动作的散列值
示例 
APPNAME mod='SQL*Plus' mh=3669949024 act='' ah=4029777240
===============================================
PARSING IN 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,当前模式的用户id和lid不同。我们知道当使用alter session set current_schema=NEWUSER命令后，用户OLDUSER在执行需要NEWUSER的相关权限时才会切换为NEWUSER，则这时代UID即为OLDUSER，lib为NEWUSER
oct ：Oracle command type. oracle的命令类型
lid ：Privilege user id. 核对访问权限的id
tim ：Timestamp。在Oracle9i之前单位是1%秒，9i之后则是1/1,000,000秒。利用这个值可以计算一个SQL执行了到底多长时间。这个值就是当前行被写入trace文件时数据库V$TIMER视图的值。
hv ：Hash id. sql的散列id
ad ：SQLTEXT address，SQLTEXT的地址，跟V$SQLAREA和V$SQLTEXT视图中的ADDRESS字段值相等。
statement ：The actual SQL statement being parsed.实际的sql语句

示例 
PARSING IN CURSOR #2 len=60 dep=0 uid=55 oct=6 lid=55 tim=1303778511213906 hv=478751424 ad='2ce279a4'
update employees set salary=1.1*salary where employee_id=100
END OF STMT 
======================================================
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，CPU时间 (100th's of a second Oracle7, 8. Microseconds in Oracle 9 onwards).
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 Consistent reads，consistent模式下的读次数，个人认为可以理解为query模式下的读次数
cu：Number of buffers retrieved in current mode，current模式下的读次数
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
======================================================
当执行或者取数据发生错误
err ：Oracle error code (e.g. ORA-XXXXX) at the top of the stack，Oracle 错误代码(e.g. ORA-XXXXX)
tim ：Timestamp，时间戳
示例
ERROR #2:err=1013 tim=431155915 
======================================================
STAT # 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. 执行计划中，这一步的父ID
pos ：Position in explain plan，执行计划的位置
obj ：Object id of row source (if this is a base object)，引用对象的对象ID
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)，1表示回滚，0表示提交
rd_only：1 if transaction was read only, 0 if changes occurred，只读标记，1表示事务是只读的，0表示可以进行修改，提交或返回
示例
XCTEND rlbk=0, rd_only=0 
======================================================
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，绑定游标的位置，从0开始，0是第一个游标
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，缓冲区的chunk大小
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，绑定变量的实际值，有可能是16进制转储
示例 
BINDS #2:
kkscoacd
 Bind#0
  oacdty=11 mxl=16(16) mxlc=00 mal=00 scl=00 pre=00
  oacflg=18 fl2=0001 frm=00 csi=00 siz=16 off=0
  kxsbbbfp=b7f1b944  bln=16  avl=16  flg=05
  value=0000E899.0018.0001 
======================================================
WAIT #[CURSOR]: nam="event name" ela=0 p1=0 p2=0 p3=0 
======================================================
#CURSOR:游标号
WAIT ：An event that we waited for，表示正在进行等待某个事件
nam ：What was being waited for，等待事件名称
ela ：Elapsed time for the operation，等待事件所花的时间，以0.01秒为单位
p1 ：P1 for the given wait event，P1,P2,P3可查阅references文档
p2 ：P2 for the given wait event.
p3 ：P3 for the given wait event.
示例 
WAIT #1: nam='enq: TX - row lock contention' ela= 2961282 name|mode=1415053318 usn<<16 | slot=196643 sequence=435 obj#=51857 tim=1303778558416950