|
99425457600:c=0,e=1,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1853518045,tim=1423560909046560
WAIT #140199425457600: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1423560909046581
*** 2015-02-10 17:35:27.589
WAIT #140199425457600: nam='SQL*Net message from client' ela= 18543034 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1423560927589630
CLOSE #140199425457600:c=0,e=10,dep=0,type=0,tim=1423560927589767
*** 2015-02-10 17:35:27.589
Processing Oradebug command 'event 10046 trace name context off'
*** 2015-02-10 17:35:27.590
Oradebug command 'event 10046 trace name context off' console output:
*** 2015-02-10 17:35:35.918
Processing Oradebug command 'tracefile_name'
*** 2015-02-10 17:35:35.918
Oradebug command 'tracefile_name' console output:
/u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_2551.trc
***************************解释******************************************************
第1部分:parse(解析)
PARSING IN CURSOR #140199425457600 len=37 dep=0 uid=0 oct=3 lid=0 tim=1423560909045924 hv=2120411436
ad='28d609c60' sqlid='23uhtxpz65u9c'
cursor cursor number
len sql 语句长度
dep sql 语句递归深度
uid user id
oct oracle command type
lid privilege user id
tim timestamp，时间戳
hv hash id
ad sql address 地址, 用在 v$sqltext
sqlid sql id
第2部分:exec(执行)
PARSE #140199425457600:c=1000,e=1393,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=1853518045,tim=1423560909045922
EXEC #140199425457600:c=0,e=54,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1853518045,tim=1423560909046084
c CPU 消耗的时间
e Elapsed time
p number of physical reads 物理读的次数
cr number of buffers retrieved for CR reads 逻辑读的数据块
cu number of buffers retrieved in current mode (current 模式读取的数据块)
mis cursor missed in the cache 库缓存中丢失的游标, 硬解析次数
r number of rows processed 处理的行数
dep 递归深度
og optimizer mode 【1：all_rows, 2：first_rows, 3：rule, 4：choose】
plh plan hash value
tim timestamp 时间戳
第3部分:执行过程中的发生的等待事件
WAIT #0: nam='SQL*Net message from client' ela= 20559954 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1423560909044435
nam an event that we waited for 等待事件
ela 此操作消耗的时间
p3 block 块号
trm timestamp 时间戳
第4部分:该游标的执行计划
STAT #140199425457600 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=1 pr=0 pw=0 time=110 us)'
STAT #140199425457600 id=2 cnt=167 pid=1 pos=1 obj=89045 op='INDEX FULL SCAN PK_ORDERID
(cr=1 pr=0 pw=0 time=76 us cost=1 size=0 card=167)'
cnt 当前行源返回的行数
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)
op the row source access operation
******************************************************************************************************************************************************************
*************************************************************
3.使用 tkprof 命令翻译 trace 文件
*************************************************************
tkprof /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_2551.trc ./test.trc
TKPROF: Release 11.2.0.4.0 - Development on 星期二 2月 10 17:47:28 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
Trace file: /u01/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_2551.trc
Sort options: default
************************************ |