10046 Event的追踪级别大致有:
level 1:跟踪sql语句,包括解析、执行、提取、提交和回滚等。等同于sql trace;
level 4:包括变量的详细信息;
level 8:包括等待事件;
level 12: 包括绑定变量与等待事件。
level 16: 针对sql的每次执行过程,产生统计信息
level 32: 针对sql的每次执行过程,不产生统计信息
level 64: 针对sql的每次执行过程,自适应产生统计信息。假设sql被执行超过1分钟,将产生统计信息。将自动针对消耗资源较大sql的执行过程收集更多的统计信息
10046 Event启用前的准备:
前提条件:(先确保实例或会话的环境符合条件)
1、 必须确保timed_statistics为TRUE,这个参数可以在会话级上进行修改。
2、 为了确保Event的Trace输出能够完整进行,还要调整此会话对Trace文件大小的限制,一般地,将max_dump_file_size设置为一个很大的阙值,或者取消此限制,即设置为UNLIMITED。(不建议设置为UNLIMITED,因为有可能会造成磁盘空间使用异常)
在设置完了上述条件后,就可以启用Event进行后台跟踪了。
Oracle event的启用可以在实例级或者会话级上来进行。其中,实例级的启用方式是在初始化参数文件中设置event参数的值。
如果想要在实例级启用10046 event,则可在初始化参数文件pfile中增加如下一行:
event=’10046 event trace name context forever, level n’
或者:
SQL >alter system set events ‘10046 trace name context forever, leveln’;
由于event的启用对系统资源消耗很大,因此,一般不建议在生产运行库中启用实例级上的event。实际情况中,也是没有必要对整个实例进行event的TRACE。下面就主要针对会话级10046 event的情况进行大致阐述。
启用10046 Event的几种方式:
一种是在当前会话启用event。可以利用alter session set events语句,如下:
SQL >alter session set events ‘10046 trace name context forever, leveln’;
一种是在当前会话中对别的会话启用event跟踪。可以利用oracle提供的包dbms_system来完成,如下:
SQL >exec dbms_system.set_ev(sid,serial#,10046,n,’’); —n代表级别,1/4/8/12/16/32/64
说明:
1、获取当前会话的sid和serial#可以通过下面语句来实现:
SQL >select sid, serial# from v$session where sid = (select sid from v$mystat where rownum=1);
2、SQL >exec dbms_system.set_sql_trace_in_session(sid,serial#,true);
相当于打开了sql_trace。
10046 Event的关闭:
可以通过下面的语句来关闭当前会话的event:
SQL >alter session set events ‘10046 trace name context off’;
也可以利用dbms_system包来关闭某个会话的event:
SQL >execute dbms_system.set_ev(sid,serial#,10046,0,’’); —n为0,代表关闭10046时间
这里应当注意的是,TRACE将消耗相当的系统资源,因此我们在使用TRACE的时候应当慎重。对于在线的生产系统,在必要时应当选择合适的时候进行TRACE操作,并且应当及时关闭。
Trace文件的查找:
当利用事件trace完当前或某个session后,接下来我们的工作就是找到oracle生成的trace文件了。Oracle的初始化参数文件中user_dump_dest的设置将决定trace文件的生成位置。我们可以通过查看参数文件,或者借助sqlplus来查询得出user_dump_dest所设定的路径:
SQL> show parameter user_dump_dest
NAME TYPE VALUE
---------------------- ----------- ------------------------------
user_dump_dest string /oracle/app/oracle/admin/SIDDB/udump
SQL> col name format a20
SQL> col value format a50
SQL> select name,value from v$parameter where name='user_dump_dest';
NAME VALUE
-------------------- --------------------------------------------------
user_dump_dest /oracle/app/oracle/admin/ SIDDB /udump
|
unix下,trace文件的命名规则一般是sid_ora_spid.trc。spid为该session对应的外部进程号。
TKPROF的用途和使用:
oracle提供了一个工具tkprof来对trace文件进行格式的翻译,以便trace文件中记录的信息能够被我们容易获取和理解。
基本用法:
tkprof tracefile outputfile [explain= ] [table= ] [print= ] [insert= ] [sys= ] [sort= ]
table=schema.tablename Use 'schema.tablename' with 'explain=' option.
explain=user/password Connect to ORACLE and issue EXPLAIN PLAIN.
print=integer List only the first 'integer' SQL statements.
aggregate=yes|no
insert=filename List SQL statements and data inside INSERT statements.
sys=no tkprofdoes not list SQL statements run as user SYS.
record=filename Record non-recursive statements found in the trace file.
sort=option Set of zero or more of the following sort options:
prscnt number of times parse was called
prscpu cpu time parsing
prsela elapsed time parsing
prsdsk number of disk reads during parse
prsqry number of buffers for consistent read during parse
从Trace文件中发现有用的信息,寻找必要的性能调整点:
大部分情况下,通过10046事件trace到文件里的信息包含了此会话中存在的性能问题,可以根据trace到的等待事件、SQL语句执行情况以及绑定变量的使用情况来进行分析和查找。
这部分的内容就要结合实际应用情况,具体情况具体分析了。
race文件内容:
分析(parse):SQL的分析阶段
执行(execute):SQL的执行阶段
数据提取(Fetch):数据提取阶段
横向的列除了call之外,还包含了一下信息:
count:计算器,表示当前的操作被执行了多少次。
cpu:当前的操作消耗的cpu时间(单位秒)
Elapsed: 当前的操作一共用时多少(包括cpu事件和等待时间)
Disk:当前操作的物理读(磁盘i/o次数)
Query:当前操作的一致性读方式读取的数据块数(通常是查询)
Current:当前操作的current的方式读取的数据库数(通常是修改数据块使用的方式)
Rows:当前操作处理的数据记录数
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 2 0.00 0.00 0 3 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 4 0.00 0.00 0 3 0 1
|
Rows 当前操作返回的实际返回的记录数。
Row Source Operation 表示当前操作的数据访问方式。
cr(consistent read)一致性读取的数据块,相当于query列上的fetch的值
pr(physical read)物理读取的数据块,相当于disk列上的fetch的值
pw(physical write) 物理写
time 当前操作执行时间
Rows Row Source Operation
------- ---------------------------------------------------
1 TABLE ACCESS BY INDEX ROWID TEST (cr=3 pr=0 pw=0 time=0 us cost=2 size=29 card=1)
1 INDEX UNIQUE SCAN SYS_C00399080 (cr=2 pr=0 pw=0 time=0 us cost=1 size=0 card=1)(object id 217036)
|
PARSING IN CURSOR 部分:
len:被分析sql的长度
dep:产生递归sql的深度
uid:user id
otc:Oracle command type命令的类型
lid:私有用的id
tim:时间戳
hv: hash value
ad: sql address
PARSE,EXEC,FETCH部分:
c: 消耗的cpu time
e:elapsed time 操作的用时
p:physical reads次数
cr:consistent reads数据的块
cu:current方式读取的数据块
mis:cursor miss in canche硬分析次数
r:rows处理的行数
dep:depth递归sql的深度
og:optimize goal优化器模式
tim:timstamp时间戳
stats部分:
id:执行计划的行源号
cnt:当前行源返回的行数
pid:当前行源的父号
pos:执行计划中的位置
obj:当前操作的对象id
op:当前行源的数据访问操作
PARSING IN CURSOR #1 len=31 dep=0 uid=0 oct=3 lid=0 tim=1381490108569206 hv=459648918 ad='6d9c7590' sqlid='d3gtqbsdqbbwq'
select * from test where id=100
END OF STMT
PARSE #1:c=1999,e=1757,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=4274779609,tim=1381490108569205
EXEC #1:c=0,e=41,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4274779609,tim=1381490108569319
FETCH #1:c=0,e=92,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=1,plh=4274779609,tim=1381490108569461
STAT #1 id=1 cnt=1 pid=0 pos=1 obj=217035 op='TABLE ACCESS BY INDEX ROWID TEST (cr=3 pr=0 pw=0 time=0 us cost=2 size=29 card=1)'
STAT #1 id=2 cnt=1 pid=1 pos=1 obj=217036 op='INDEX UNIQUE SCAN SYS_C00399080 (cr=2 pr=0 pw=0 time=0 us cost=1 size=0 card=1)'
FETCH #1:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=4274779609,tim=1381490108591269
|
来自 “ ITPUB博客 ” ,链接:http://blog.itpub.net/28572479/viewspace-2140794/,如需转载,请注明出处,否则将追究法律责任。
转载于:http://blog.itpub.net/28572479/viewspace-2140794/