oracle trace文件解读

oracle trace文件解析



    =====================

    PARSING IN CURSOR #1 len=68 dep=0 uid=59 oct=42 lid=59 tim=12047812267 hv=570864185 ad='66bd0bc4'

    alter session set events '10046 trace name context forever,level 12'

    END OF STMT

    EXEC #1:c=0,e=89,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=12047812255

    WAIT #1: nam='SQL*Net message to client' ela= 5 p1=1111838976 p2=1 p3=0

    WAIT #1: nam='SQL*Net message from client' ela= 3350384 p1=1111838976 p2=1 p3=0

    =====================

    PARSING IN CURSOR #1 len=57 dep=0 uid=59 oct=3 lid=59 tim=12051164358 hv=1391558827 ad='66bfe7d8'

    select count（*） from emp a,dept b where a.deptno=b.deptno

    END OF STMT

    PARSE #1:c=0,e=76,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=12051164349

    BINDS #1:

    EXEC #1:c=0,e=192,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=12051165308

    WAIT #1: nam='SQL*Net message to client' ela= 7 p1=1111838976 p2=1 p3=0

    FETCH #1:c=0,e=140,p=0,cr=5,cu=0,mis=0,r=1,dep=0,og=4,tim=12051165720

    WAIT #1: nam='SQL*Net message from client' ela= 302 p1=1111838976 p2=1 p3=0

    FETCH #1:c=0,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,tim=12051166486

    WAIT #1: nam='SQL*Net message to client' ela= 4 p1=1111838976 p2=1 p3=0

    WAIT #1: nam='SQL*Net message from client' ela= 3248265 p1=1111838976 p2=1 p3=0

    STAT #1 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE '

    STAT #1 id=2 cnt=14 pid=1 pos=1 obj=0 op='NESTED LOOPS '

    STAT #1 id=3 cnt=14 pid=2 pos=1 obj=30139 op='TABLE ACCESS FULL EMP '

    STAT #1 id=4 cnt=14 pid=2 pos=2 obj=30138 op='INDEX UNIQUE SCAN PK_DEPT '

    =====================

    PARSING IN CURSOR #1 len=55 dep=0 uid=59 oct=42 lid=59 tim=12054418195 hv=3381932903 ad='66bd7b34'

    alter session set events '10046 trace name context off'

    END OF STMT

    PARSE #1:c=15625,e=703,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,

    tim=12054418182

    BINDS #1:

    EXEC #1:c=0,e=321,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=12054419670

    #######################################

    PARSING IN CURSOR #1 len=68 dep=0 uid=59 oct=42 lid=59 tim=12047812267 hv=570864185 ad='66bd0bc4'

   PARSING IN CURSOR 部分
    ------------------------------------------
    Cursor# 游标号

    len SQL语句的长度

    dep SQL语句的递归深度

    Uid 当前模式中的用户ID

    Oct Oracle命令类型

    Lid 用于核对访问权限的用户ID

    Tim 一个计时器，精度以1%秒为单位

    Ha SQL语句的散列ID号

    Ad 指向SQL语句的V$SQLAREA的ADDR列

   PARSING  EXEC,FETCH  部分
    ------------------------------------------
    EXEC Cursor#:c=%d,e=%d,p=%d,cr=%d,cu=%d,mis=%d,r=%d,dep=%d,og=%d,tim=%d

    EXEC #1:c=0,e=89,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=12047812255

    Cursor# 光标号

    c：    以1%秒为单位的CPU运行时间

    e ：   以1%秒为单位的经过的时间

    p ：   所执行的物理读的数量

    cr ：  Consistent模式下的读（逻辑输入/输出）

    cu ： Current模式下的读（逻辑输入/输出）

    mis ：硬分析次数

    r ：    处理的行数

    dep ：SQL语句的递归深度

    og ：  优化器目标，1=所有行，2=起始行，3=规则，4=选择

    tim：  计时器，精度以1%秒为单位的时间

    PARSE 分析一个语句

    FETCH 从游标中取出所需行时

    UNMAP 用以从程序运行中间结果中释放一些不再用到的临时段

    SORT UNMAP 和unmap类似，只不过用于排序段

    WAIT Cursor#:nam='%s' ela=%d p1=%ul p2=%ul p3=%ul

    WAIT #1: nam='SQL*Net message to client' ela= 5 p1=1111838976 p2=1 p3=0

    WAIT #1: nam='SQL*Net message from client' ela= 3350384 p1=1111838976 p2=1 p3=0

    Cursor# 游标号

    nam 等待事件的名称。Oracle Server Reference中列出了全部等待事件，并有详细解释

    ela 以1%秒为单位的事件经过的时间

    p1,p2,p3 专门用于等待事件的参数。每一个事件都有它自己的一套参数。

    参考Oracle Server Reference中关于特定等待事件的参数p1,p2,p3的含义


BINDS #4:

    bind 0:dty=2 mxl=22（21） mal=00 scl=00 pre=00 oacflg=03 oacf12=1 size=24 offset=0

    bfp=07425360 bln=22 avl=03 flg=05

    value=7698

    cursor # 游标号

    bind N 绑定位置，从0开始（0是第一个绑定变量）

    dty 数据类型，dty数据类型的数字用USER_TAB_COLUMNS视图的信息来解码

    mxl 绑定变量的最大长度

    mal 最大最组的长度（当用到数组绑定变量或批操作时）

    scl 比例

    pre 精度

    oacflg 内部标记，这个数字若是奇数，绑定变量就是空（允许有空值）

    ocaf12 内部标记的扩展

    size 缓冲区的大小

    bfp 绑定地址

    bln 绑定缓冲区的长度

    avl 实际值的长度

    flg 内部标记

    value 绑定值的字符串的表示（如果可能，是16进制转储），这正是想要得到的

    如何解析等待资源？

    WAIT #4: nam='enqueue' ela=308 p1=1415053318 p2=393290 p3=2947

    create or replace function enqueue_decode（l_p1 in number） return varchar2

    as

    l_str varchar2（25）；

    begin

    select chr（bitand（l_p1,-16777216）/16777215） ||

    chr（bitand（l_p1,16711680）/65535） || ' ' ||

    decode（bitand（l_p1,65535），

    0,'No lock',

    1,'No lock',

    2,'Row-Share',

    3,'Row-Exclusive',

    4,'Share',

    5,'Share Row-Excl',

    6,'Exclusive'）

    into l_str

    from dual;

    return l_str;

    end;

    /
   STATS  部分
    ------------------------------------------

    select enqueue_decode（1415053318） from dual;

    XCTEND rlbk=0,rd_only=0

    rlbk 返回标记，0表示提交过了，1表示返回

    rd_only 只读标记，1表示事务是只读的，0可以进行改动，提交或返回

    WAIT #0:nam='log file sync' ela=0 p1=988 p2=0 p3=0

    STAT #4 id=1 cnt=1 pid=0 pos=0 obj=0 op='UPDATE EMP'

    STAT #4 id=1 cnt=1 pid=1 pos=1 obj=24767 op='TABLE ACCESS FULL EMP'

    cursor # 游标号

    id 解释方案中的行，从1到该方案中的行数

    cnt 通过查询方案此阶段的行数

    pid 方案中这一步的父ID。用于以缩进恰当地反映方案的层次结构

    pos 解释方案中的位置

    obj 可用情况下，引用对象的目标ID

    op 已执行操作的原文描述

    PARSE ERROR #3:len=15 dep=0 uid=69 oct=3 lid=69 tim=7160573 err=903

    Cursor# 游标号

    len SQL语句的长度

    dep SQL语句的递归深度

    Uid 当前模式中的用户ID

    Oct Oracle命令类型

    Lid 用于核对访问权限的用户ID

    Tim 一个计时器，精度以1%秒为单位

    err ORA错误代码，可以执行如下方式得到错误的内容：

    EXEC DBMS_OUTPUT.PUT_LINE（SQLERRM（-903））；