大部分情况下,我们可以利用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
参考至:《Oracle专家高级编程》Thomas kyte著
《让Oracle跑得更快》谭怀远著
https://support.oracle.com/CSP/main/article?cmd=show&type=NOT&id=39817.1
http://dbaoracle.itpub.net/post/901/5547
http://dbaoracle.itpub.net/post/901/5547