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秒），而我單獨在後臺資料庫( )執行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--