Oracle执行语句跟踪 使用sql trace实现语句追踪

1、SQL_Plus自动跟踪：
set autotrace on explain          // 显示执行计划
set autotrace traceonly explain // 仅显示执行计划
set autotrace on                    // 显示执行计划、和统计数字
set timing on                         // 显示已用时间
set autotrace traceonly          //显示执行计划、和统计数字；但不显示sql结果

2、还可以利用10046事件来跟踪SQL,它比SQL_TRACE提供更详细的信息.它有LEVEL 1,4,8,12四个级别.
其中Level 1 相当于 SQL_TRACE.下面是10046使用的例子
alter session set events '10046 trace name context forever, level 4'; --跟踪SQL语句并显示绑定变量
alter session set events '10046 trace name context forever, level 8'; --跟踪SQL语句并显示等待事件
10046：SQL到底是如何执行的。
10053：SQL为什么要这样执行。

SQL> alter session set events '10046 trace name context forever,level 4';
Session altered.
.... some SQL statements
SQL> alter session set events '10046 trace name context off';
Session altered.

3、SQL> alter session set sql_trace=true;
SQL>alter session set sql_trace=false;

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

系统上的某个接口提交数据经常超时（超过3秒），而我单独在后台数据库(Oracle)执行insert，只需要17ms。提交数据的客户端没有任何的调试日志，只能通过跟踪后台语句记录实际调用过程中的数据库执行时间。从而发现问题耗时最多的阶段。

安装dbms_support包

SQL> @?\rdbms\admin\dbmssupp.sql
SQL> grant execute on dbms_support to test;

找到需要跟踪的会话，一个接口可能会建立多个会话，需要根据会话建立的时间来判断真正需要跟踪的会话。

SQL> alter session set nls_date_format='YYYY-MM-DD HH24:MI:SS';
SQL> select sid,serial#,logon_time from v$session where username=&name and program=&program;
输入 name 的值: 'test' 输入 program 的值: 'test.exe'

使用start_trace_in_session进行跟踪

SQL>exec dbms_support.start_trace_in_session(1157,59729,TRUE,TRUE);

开始跟踪后，在客户端进行对应的操作。

使用stop_trace_in_session结束跟踪

SQL> exec dbms_support.stop_trace_in_session(1157,59729);

使用以下的语句获得trace文件的位置。

SELECT    d.VALUE 
          || '\' 
          || LOWER (RTRIM (i.INSTANCE, CHR (0))) 
          || '_ora_' 
          || p.spid 
          || '.trc' trace_file_name 
     FROM (SELECT p.spid 
             FROM v$mystat m, v$session s, v$process p 
            WHERE m.statistic# = 1 AND s.SID = &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 
用文本编辑器可以直接打开trace文件

图中的这一段就是对一个语句的从解析到返回数据的整个过程，如果统计从开始请求到消息返回客户端的时间，直接将红框中的两个tim相减就可以了，11592216806504-11592199796058=17010446,其单位是1/1000000秒。若要单独获取执行时间，可以EXEC的TIM减掉PARSE的TIM，差值即为执行的时间。其它字段的说明可以参照这个文档。

另外也可以使用TKPROF将trace文件转换成为执行计划解析的文本。

 D:\app\oracle\diag\rdbms\wxmesdb\wxmesdb\trace>tkprof wxmesdb_ora_6520.trc trace_1.txt

TKPROF: Release 12.1.0.1.0 - Development on 星期三 1月 6 08:30:11 2016 Copyright (c) 1982, 2013, Oracle and/or its affiliates.  All rights reserved. 

如上图所示，可以得到执行时间为17秒，与上一步中通过TIM相减的差值一致。

--EOF--

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/29209863/viewspace-2131672/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/29209863/viewspace-2131672/