Oracle 10046事件

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.