SQL trace 10046事件

10046事件的启用和关闭

前提条件

1>必须确保timed_statistics 为true，该参数也可以在会话级上设置

2>为了确保trace输出能够完整进行，还要跳槽会话对trace文件大小的限制，一般将此限制 取消。Max_dump_file_size 设置为unlimited。

10046事件主要用来跟踪sql语句

收集内容，4个等级

 Level 1： 等同于SQL_TRACE 的功能

 Level 4： 在Level 1的基础上增加收集绑定变量的信息

 Level 8： 在Level 1 的基础上增加等待事件的信息

 Level 12：等同于Level 4+Level 8, 即同时收集绑定变量信息和等待事件信息。

启用10046事件的方法

1>对当前session使用10046事件

--执行

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

执行相关事务

--关闭

SQL>alter session set events '10046 trace name context off'

2>对其他会话进行跟踪 ,2种方式

第一种:SQL_TRACE跟踪

--查询sid，serial#

SQL>select sid,serial# from v$session where sid=267

--开启，关闭。相当于打开，关闭sql_trace

exec dbms_system.set_ev(sid,serial#,10046,12,’’); 

SQL>execute dbms_system.set_sql_trace_in_sesson(267,996,true);

SQL>execute dbms_system.set_sql_trace_in_sesson(267,996,false);

第二种：使用10046事件。

--启动trace

SQL> exec dbms_monitor.session_trace_enable(986,160,waits=>true,binds=>true); 

--关闭trace 

SQL> exec dbms_monitor.session_trace_disable(267,996);  

PL/SQL 过程已成功完成。

注意：

    如果一条SQL语句中包含了通过DBLINK进行的数据操作，我们想对这条SQL进行trace跟踪，在本地只能够trace到本地执行的SQL信息，而对于远程的SQL语句，由于它运行在远端的数据库上，我们要获得它的信息，需要到远端的数据库上，找到运行这条SQL语句的session，然后对它做Trace。 另外，这条SQL语句的执行计划也只能从远端数据库上捕获到。

总之，当SQL语句操作出现性能问题时，我们可以用SQL_TRACE 或者10046事件进行跟踪是最合适的。 如果是数据库整体性能下降，就需要使用statspack或者AWR对数据库进行分析。

例子

1>sql语句出现问题，用sql_trace命令将sql执行的整个过程数据到一个trace文件中

启动sql_trace

SQL>alter session set sql_trace=true ; 只对session进行跟踪

SQL>alter database set sql_trace=true; 实例级别，跟踪的sqL太多，代价大

事务处理

SQL>Select * from tab

关闭sql_trace

SQL>alter session set sql_trace=false;

确定当前的trace文件

SQL>alter session set tracefile_identifier='ktrace';

Oracle SQL_TRACE生成的trace文件默认路劲是$ORACLE_BASE/admin/SID/udump.  

Oracle 11g，trace 默认路径在：$ORACLE_BASE\diag\rdbms\orcl\orcl\trace目录下.

SQL查找当前的trace文件名

SELECT      d.VALUE

         || '/'

         || LOWER (RTRIM (i.INSTANCE, CHR (0)))

         || '_ora_'

         || p.spid

         || '.trc'

            AS "trace_file_name"

  FROM   (SELECT   p.spid

            FROM   v$mystat m, v$session s, v$process p

           WHERE   m.statistic# = 1 AND s.SID = m.SID AND p.addr = s.paddr) p,

         (SELECT   t.INSTANCE

            FROM   v$thread t, v$parameter v

           WHERE   v.NAME = 'thread'

                   AND (v.VALUE = 0 OR t.thread# = TO_NUMBER (v.VALUE))) i,

         (SELECT   VALUE

            FROM   v$parameter

           WHERE   NAME = 'user_dump_dest') d;

使用tkprof工具分析

该工具只能分析SQL_trace和10046事件产生的trace

explain=user/password

在trace文件中输入SQL的执行计划，

如果不使用explain，在trace文件中看到的是SQL实际的执行路径

如果使用了explain，在tkprof文件中不但输入SQL的实际执行路径，还会生成该SQL的执行那个计划

sys=no

如果设置yes（默认），在trace文件中将输入索引的sys用户的操作，也会包含用户SQL语句引发的递归SQL

如果设置no，则不输出这些信息

一般设置成no

aggregate=yes|no

设置yes（默认），将索引相同的SQL在输入文件中作合并

设置no，分布列出每个SQL的信息，一般合并后比较简洁，

如果要查看单独每一个SQL信息，可以吧aggregate设置为no

查看trace文件

tkprof orcl_ora_3048_安庆怀宁.trc 安徽安庆怀宁.txt sys=no

Aggregate=yes |no,tkprof 将所有相同的sql在输入文件中作合并。

[oracle@node1 udump]$ tkprof dgt_ora_9227.trc tkout sys=no

TKPROF: Release 10.2.0.1.0 - Production on Fri Aug 13 18:01:05 2010

Copyright (c) 1982, 2005, Oracle.  All rights reserved.

Trace file: anktest_ora_18305_anktrace.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 //非递归sql语句

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        6      0.19       0.22          0          0          0           0

Execute      7      0.00       0.00          0          0          0           0

Fetch      251      0.56       3.38       1077       8612          0        3649

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total      264      0.75       3.61       1077       8612          0        3649

Misses in library cache during parse: 4 #shared pool 中没有命令，说明做了4次硬解析，软解析此处为0 

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse       23      0.03       0.09          0          0          0           0

Execute     31      0.02       0.13          0          0          0           0

Fetch       38      0.00       0.08          8         81          0          14

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total       92      0.06       0.31          8         81          0          14

Misses in library cache during parse: 14

Misses in library cache during execute: 8

    6  user  SQL statements in session.

   37  internal SQL statements in session.

   43  SQL statements in session.

********************************************************************************

Trace file: anktest_ora_18305_anktrace.trc

Trace file compatibility: 10.01.00

Sort options: default

       0  session in tracefile.

       6  user  SQL statements in trace file.

      37  internal SQL statements in trace file.

      43  SQL statements in trace file.

      18  unique SQL statements in trace file.

     699  lines in trace file.

     365  elapsed seconds in trace file.

更具体详看原始trace文件

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 misss in cache 硬分析次数

                R: -rows 处理的行数

                Dep: depth 递归SQL的深度

                Og： optimizer goal 优化器模式

                Tim：timestamp时间戳

 

STATS 部分：

                Id: 执行计划的行源号

                Cnt：当前行源返回的行数

                Pid：当前行源号的父号

                Pos：执行计划中的位置

                Obj：当前操作的对象id（如果当前行原始一个对象的话）

                Op：当前行源的数据访问操作