10046 事件
Oracle 10046是一个Oracle内部事件。最常用的是在Session级别设置sql_trace(alter session set sql_trace=true)即是开启了级别为1的10046调试事件。当设置了10046事件之后,Oracle 将产生一个dump文件。通过得到的dump文件进行进一步分析,可以得到Oracle 内部执行系统解析、调用、等待、绑定变量等详细的trace信息,对于分析系统的性能有着举足轻重的作用。
当SQL语句操作出现性能问题时,我们可以用SQL_TRACE 或者10046事件进行跟踪是最合适的。 如果是数据库整体性能下降,就需要使用statspack或者AWR对数据库进行分析。
1.10046事件的相关参数
该事件需要设置一些参数以控制dump文件的输出:
TIMED_STATISTICS
用于控制计时信息,可以设定为true和false。当设定为true时,计时信息将会被添加到trace文件中。
MAX_DUMP_FILE_SIZE
用于控制trace文件的最大尺寸。当使用10046事件时,建议将该参数设定为unlimited。
USER_DUMP_DEST
用于设定trace文件写入到哪个文件目录
STATISTICS_LEVEL
用于控制统计信息的收集度。此参数有3个选择,baisc,typical,all。
basic:仅收集满足trace所需的最基本的信息,象Timed statistics,Object level statistics,以及一些advisory会被忽略。
typical:此为缺省值。此设置将在basic的基础上增加一些额外的统计信息,象操作系统耗用时间的统计信息,执行计划的统计信息都会被收集
all:当设置为all时,所有与该session相关的信息全部会被收集。
TRACEFILE_IDENTIFIER
用于设置识别Trace文件的字符串,便于更快捷的找到生成的Trace文件。
以上参数可以基于系统级别以及会话级别进行修改。
ALTER SESSION/SYSTEM SET timed_statistics=true
ALTER SESSION/SYSTEM SET max_dump_file_size=unlimited
ALTER SESSION SET tracefile_identifier='trace_sql_example' -->仅session级别
2. 10046调试事件的等级
10046调试事件可以分为多个不同的等级,不同的等级输出不同的trace信息。
等级 作用
0 禁止调试事件
1 调试事件处于激活状态。针对每个被处理的数据库调用,输出SQL语句,APPNAME(应用程序名),PARSING IN CURSOR,PARSE ERROR(SQL解析)
,EXEC(执行),FETCH(获取数据),UNMAP,SORT UNMAP(排序,临时段),ERROR,STAT(执行计划),XCTEND(事务)等行。
4 包括等级1的输出,加上BIND行(绑定变量信息)
8 包括等级1的输出,加上WAIT行(等待事件信息)。对于处理过程中的每个等待,提供如下信息:等待时间的名字,持续时间,以及一些额外
的参数,可表明所等待的资源。
12 输出等级4以及等级8的所有信息
3. 生成trace文件
[oracle@server8 trace]$ sqlplus / as sysdba
SQL*Plus: Release 11.2.0.3.0 Production on Tue Feb 10 16:20:39 2015
sys@GHSJDB> alter session set tracefile_identifier='10046';
Session altered.
sys@GHSJDB>alter session set events '10046 trace name context forever,level 12';(如果没有权限赋予 alter session 权限)
Session altered.
sys@GHSJDB> select code,name,to_char(parent_code) parent,to_char(connect_by_isleaf) isleaf,lev
2 from ghsj_xm.v_organdataset
3 where level = 1 connect by prior code = parent_code start with code = '14142' order siblings by code
4 ;
CODE NAME
------------------------------------------------------------------------------------------ -----------------------------------
PARENT ISLEAF LEV
------------------------------------------------------------------------------------------ ---------------------------------------- ----------------------------------------
14142 国网湖北省电力公司
14000
sys@GHSJDB>alter session set events '10046 trace name context off';
Session altered.
4. 获取跟踪文件
方法1:
sys@GHSJDB> show parameter dump
NAME TYPE VALUE
------------------------------------ ----------- ------------------------------
background_core_dump string partial
background_dump_dest string /home/u01/app/oracle/diag/rdbm
s/ghsjdb/ghsjdb/trace
core_dump_dest string /home/u01/app/oracle/diag/rdbm
s/ghsjdb/ghsjdb/cdump
max_dump_file_size string unlimited
shadow_core_dump string partial
user_dump_dest string /home/u01/app/oracle/diag/rdbm
s/ghsjdb/ghsjdb/trace
去相应的目录下:
cd /home/u01/app/oracle/diag/rdbms/ghsjdb/ghsjdb/trace
查找标识符10046:
ls | grep 10046
ghsjdb_ora_9481_10046.trc
ghsjdb_ora_9481_10046.trm
方法2:
取得当前用户的sid,根据ID取得tracefile的地址
sys@GHSJDB> select * from v$mystat where rownum=1;
SID STATISTIC# VALUE
----- ---------- ----------
247 0 ##########
sys@GHSJDB> SELECT tracefile FROM v$process WHERE addr IN (SELECT paddr FROM v$session WHERE sid='247');
TRACEFILE
--------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
/home/u01/app/oracle/diag/rdbms/ghsjdb/ghsjdb/trace/ghsjdb_ora_9481_10046.trc
5. 格式化输出tkprof
[oracle@server8 ~]$ tkprof
Usage: 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 PLAN.
print=integer List only the first 'integer' SQL statements.
aggregate=yes|no
insert=filename List SQL statements and data inside INSERT statements.
sys=no TKPROF does not list SQL statements run as user SYS.
record=filename Record non-recursive statements found in the trace file.
waits=yes|no Record summary for any wait events 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
prscu number of buffers for current read during parse
prsmis number of misses in library cache during parse
execnt number of execute was called
execpu cpu time spent executing
exeela elapsed time executing
exedsk number of disk reads during execute
exeqry number of buffers for consistent read during execute
execu number of buffers for current read during execute
exerow number of rows processed during execute
exemis number of library cache misses during execute
fchcnt number of times fetch was called
fchcpu cpu time spent fetching
fchela elapsed time fetching
fchdsk number of disk reads during fetch
fchqry number of buffers for consistent read during fetch
fchcu number of buffers for current read during fetch
fchrow number of rows fetched
userid userid of user that parsed the cursor
tkprof /home/u01/app/oracle/diag/rdbms/ghsjdb/ghsjdb/trace/ghsjdb_ora_9481_10046.trc 10046.log sys=no
[oracle@server8 ~]$ more 10046.log
TKPROF: Release 11.2.0.3.0 - Development on Tue Feb 10 17:11:04 2015
Copyright (c) 1982, 2011, Oracle and/or its affiliates. All rights reserved.
Trace file: /home/u01/app/oracle/diag/rdbms/ghsjdb/ghsjdb/trace/ghsjdb_ora_11266_10046.trc
Sort options: default
********************************************************************************
count = number of times OCI procedure was executed
cpu = cpu time in seconds executing
elapsed = elapsed time in seconds executing
disk = number of physical reads of buffers from disk
query = number of buffers gotten for consistent read
current = number of buffers gotten in current mode (usually for update)
rows = number of rows processed by the fetch or execute call
********************************************************************************
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 4 0.00 0.00 0 0 0 0
Execute 4 0.00 0.00 0 0 0 2
Fetch 2 0.25 0.26 0 22123 0 1
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 10 0.25 0.26 0 22123 0 3
Misses in library cache during parse: 0
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 5 0.00 0.00
SQL*Net message from client 5 18.65 27.67
OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 0 0.00 0.00 0 0 0 0
Execute 0 0.00 0.00 0 0 0 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 0 0.00 0.00 0 0 0 0
Misses in library cache during parse: 0
3 user SQL statements in session.
0 internal SQL statements in session.
3 SQL statements in session.
********************************************************************************
Trace file: /home/u01/app/oracle/diag/rdbms/ghsjdb/ghsjdb/trace/ghsjdb_ora_11266_10046.trc
Trace file compatibility: 11.1.0.7
Sort options: default
1 session in tracefile.
3 user SQL statements in trace file.
0 internal SQL statements in trace file.
3 SQL statements in trace file.
3 unique SQL statements in trace file.
115 lines in trace file.
27 elapsed seconds in trace file.
: