天天看點

ORACLE SQL_TRACE的使用

引用 :http://blog.csdn.net/huzia/article/details/9119469

“SQL TRACE”是Oracle提供的用于進行SQL跟蹤的手段,是強有力的輔助診斷工具。在日常的資料庫問題診斷和解決中,“SQL TRACE”是非常常用的方法。

一般,一次跟蹤可以分為以下幾步:

1、界定需要跟蹤的目标範圍,并使用适當的指令啟用所需跟蹤。

2、經過一段時間後,停止跟蹤。此時應該産生了一個跟蹤結果檔案。

3、找到跟蹤檔案,并對其進行格式化,然後閱讀或分析。

本文就“SQL TRACE”的這些使用作簡單探讨,并通過具體案例對SQL_TRACE的使用進行說明。

一、“SQL TRACE”的啟用。

(A)SQL_TRACE說明

SQL_TRACE可以作為初始化參數在全局啟用,也可以通過指令行方式在具體session啟用。

1.在全局啟用

在參數檔案(pfile/spfile)中指定: SQL_TRACE = true

   在全局啟用SQL_TRACE會導緻所有程序的活動被跟蹤,包括背景程序及所有使用者程序,這通常會導緻比較嚴重的性能問題,是以在生産環境中要謹慎使用。

提示: 通過在全局啟用SQL_TRACE,我們可以跟蹤到所有背景程序的活動,很多在文檔中的抽象說明,通過跟蹤檔案的實時變化,我們可以清晰的看到各個程序之間的緊密協調。

2.在目前session級設定

大多數時候我們使用SQL_TRACE跟蹤目前會話的程序。通過跟蹤目前程序可以發現目前操作的背景資料庫遞歸活動(這在研究資料庫新特性時尤其有效),研究SQL執行,發現背景錯誤等。

在session級啟用和停止SQL_TRACE方式如下:

啟用目前session的跟蹤:

SQL> alter session set SQL_TRACE=true;

Session altered.

此時的SQL操作将被跟蹤:

SQL> select count(*) from dba_users;

 COUNT(*)

----------

       34

結束跟蹤:

SQL> alter session set SQL_TRACE=false;

Session altered.

3.跟蹤其它使用者程序

   在很多時候我們需要跟蹤其他使用者的程序,而不是目前使用者,這可以通過Oracle提供的系統包DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION來完成

通過v$session我們可以獲得sid、serial#等資訊:

獲得程序資訊,選擇需要跟蹤的程序:

SQL> select sid,serial#,username from v$session where username =’***’

      SID   SERIAL# USERNAME

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

        8      2041 SYS

        9       437 EYGLE

設定跟蹤:

SQL> exec dbms_system.set_SQL_TRACE_in_session(9,437,true)

PL/SQL procedure successfully completed.

….

可以等候片刻,跟蹤session執行任務,捕獲sql操作…

….

停止跟蹤:

SQL> exec dbms_system.set_SQL_TRACE_in_session(9,437,false)

PL/SQL procedure successfully completed.

(B) 10046事件說明

10046事件是Oracle提供的内部事件,是對SQL_TRACE的增強.

10046事件可以設定以下四個級别:

1 - 啟用标準的SQL_TRACE功能,等價于SQL_TRACE。

4 - Level 1 加上綁定值(bind values)

8 - Level 1 + 等待事件跟蹤

12 - Level 1 + Level 4 + Level 8

類似SQL_TRACE方法,10046事件可以在全局設定,也可以在session級設定。

對于10046事件的設定,涉及到了oracle的“診斷事件”的概念。

可以參考以下連結了解詳情。http://www.itpub.net/323537,1.html 

1. 在全局設定

在參數檔案中增加:

EVENT="10046 trace name context forever,level 12"

此設定對所有使用者的所有程序生效、包括背景程序.

2. 對目前session設定

通過alter session的方式修改,需要alter session的系統權限:

SQL> alter session set events '10046 trace name context forever';

Session altered.

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

Session altered.

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

Session altered.

3. 對其他使用者session設定

通過DBMS_SYSTEM.SET_EV系統包來實作:

SQL> desc DBMS_SYSTEM.SET_EV;

Parameter Type          Mode Default?

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

SI       BINARY_INTEGER IN           

SE       BINARY_INTEGER IN           

EV       BINARY_INTEGER IN           

LE       BINARY_INTEGER IN           

NM       VARCHAR2      IN  

其中的參數SI、SE來自v$session視圖:

查詢獲得需要跟蹤的session資訊:

SQL> select sid,serial#,username from v$session where username is not null;

SID SERIAL# USERNAME

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

8 2041 SYS

9 437 EYGLE

執行跟蹤:

SQL> exec dbms_system.set_ev(9,437,10046,8,'eygle');

PL/SQL procedure successfully completed.

結束跟蹤:

SQL> exec dbms_system.set_ev(9,437,10046,0,'eygle');

PL/SQL procedure successfully completed.

(C)對啟用方法的一些總結。

因為trace的目标範圍不同,導緻必須使用不同的方法。

?nbsp;       作用于資料庫全局的,就改初始化參數。

?nbsp;       隻作用于本session的,就用alter session 指令。

?nbsp;       作用于其它session的,就用DBMS_SYSTEM包。

再加上10046診斷事件,是SQL_TRACE的增強,又多了一套方法。

二、擷取跟蹤檔案

以上生成的跟蹤檔案位于“user_dump_dest”參數所指定的目錄中,位置及檔案名可以通過以下SQL查詢獲得:

1.如果是查詢目前session的跟蹤檔案,使用如下查詢:

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 = 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

TRACE_FILE_NAME

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

D:\ORACLE\PRODUCT\10.2.0\ADMIN\MYORACLE\UDUMP\hsjf_ora_1026.trc

2.如果是查詢其他使用者session的跟蹤檔案,則根據使用者的sid和#serial使用如下查詢:

SELECT d.value||'/'||lower(rtrim(i.instance, chr(0)))||'_ora_'||p.spid||'.trc' trace_file_name 

from 

   ( select p.spid from v$session s, v$process p 

     where s.sid=’’ and s. SERIAL#='' 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_FILE_NAME

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

D:\ORACLE\PRODUCT\10.2.0\ADMIN\MYORACLE\UDUMP\hsjf_ora_1026.trc

三、格式化跟蹤檔案。

原始的跟蹤檔案是很難讀懂的。需要使用oracle自帶的tkprof指令行工具格式化一下。

SQL>$tkprof D:\ORACLE\PRODUCT\10.2.0\ADMIN\MYORACLE\UDUMP\hsjf_ora_1026.trc D:\ORACLE\PRODUCT\10.2.0\ADMIN\MYORACLE\UDUMP\hsjf_ora_1026.txt

這個就可以友善的閱讀了。可以在hsjf_ora_1026.txt檔案中看到所有的sql語句執行次數,CPU使用時間等資料。

備注:可以通過以下方法讀取目前已經設定的參數

對于全局的SQL_TRACE參數的設定,可以通過show parameter指令獲得。

當我們通過alter session的方式設定了SQL_TRACE,這個設定是不能通過show parameter的方式得到的,我們需要通過dbms_system.read_ev來擷取:

SQL> set feedback off

SQL> set serveroutput on

SQL> declare

2 event_level number;

3 begin

4 for event_number in 10000..10999 loop

5 sys.dbms_system.read_ev(event_number, event_level);

6 if (event_level > 0) then

7 sys.dbms_output.put_line(

8 'Event ' ||

9 to_char(event_number) ||

10 ' is set at level ' ||

11 to_char(event_level)

12 );

13 end if;

14 end loop;

15 end;

16 /

Event 10046 is set at level 1

如何讀懂tkprof 

CALL :每次SQL語句的處理都分成以下三個部分 

Parse:這步将SQL語句轉換成執行計劃,包括檢查是否有正确的授權和所需要用到的表、列以及其他引用到的對象是否存在。 

Execute:這步是真正的由Oracle來執行語句。對于insert、update、delete操作,這步會修改資料,對于select操作,這步就隻是确定選擇的記錄。 

Fetch:傳回查詢語句中所獲得的記錄,這步隻有select語句會被執行。 

COUNT:這個語句被parse、execute、fetch的次數。 

CPU:這個語句對于所有的parse、execute、fetch所消耗的cpu的時間,以秒為機關。 

ELAPSED:這個語句所有消耗在parse、execute、fetch的總的時間。 

DISK:從磁盤上的資料檔案中實體讀取的塊的數量。一般來說更想知道的是正在從緩存中讀取的資料而不是從磁盤上讀取的資料。 

QUERY:在一緻性讀模式下,所有parse、execute、fetch所獲得的buffer的數量。一緻性模式的buffer是用于給一個長時間運作的事務提供一個一緻性讀的快照,緩存實際上在頭部存儲了狀态。 

CURRENT:在current模式下所獲得的buffer的數量。一般在current模式下執行insert、update、delete操作都會擷取buffer。在current模式下如果在高速緩存區發現有新的緩存足夠給目前的事務使用,則這些buffer都會被讀入了緩存區中。 

ROWS: 所有SQL語句傳回的記錄數目,但是不包括子查詢中傳回的記錄數目。對于select語句,傳回記錄是在fetch這步,對于insert、update、delete操作,傳回記錄則是在execute這步。 

A、query+current/rows 平均每行所需的block數,太大的話(超過20)SQL語句效率太低 

B、Parse count/Execute count parse count應盡量接近1,如果太高的話,SQL會進行不必要的reparse 

C、rows Fetch/Fetch Fetch Array的大小,太小的話就沒有充分利用批量Fetch的功能,增加了資料在用戶端和伺服器之間的往返次數。 

D、disk/query+current 磁盤IO所占邏輯IO的比例,太大的話有可能是db_buffer_size過小(也跟SQL的具體特性有關) 

E、elapsed/cpu 太大表示執行過程中花費了大量的時間等待某種資源 

F、cpu Or elapsed 太大表示執行時間過長,或消耗了了大量的CPU時間,應該考慮優化 

G、執行計劃中的Rows 表示在該處理階段所通路的行數,要盡量減少

補充點tkprof的使用方法 

Tkprof工具可用來格式化sql trace産生的檔案,讓你更容易看懂trace的内容 

用法: 

tkprof tracefile outputfile [explain= ] [table= ] [print= ] [insert= ] [sys= ] [sort= ] ... 

參數說明: 

tracefile:你要分析的trace檔案 

outputfile:格式化後的檔案 

explain=user/[email protected] 

table=schema.tablename 

注1:這兩個參數是一起使用的,通過連接配接資料庫對在trace檔案中出現的每條sql語句檢視執行計劃,并将之輸出到outputfile中 

注2:該table必須是資料庫中不存在的,如果存在會報錯 

print=n:隻列出最初N個sql執行語句 

insert=filename:會産生一個sql檔案,運作此檔案可将收集到的資料insert到資料庫表中 

sys=no:過濾掉由sys執行的語句 

record=filename:可将非嵌套執行的sql語句過濾到指定的檔案中去 

waits=yes|no:是否統計任何等待事件 

aggregate=yes|no:是否将相同sql語句的執行資訊合計起來,預設為yes 

sort= option:設定排序選項,選項如下: 

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 

可根據自己的需要設定排序 

舉例: 

1.列出前2條sql語句的執行情況: 

C:\>tkprof c:\oc_ora_2892.trc c:\cc.txt print=2 

2.将資料儲存到資料庫: 

C:\>tkprof c:\oc_ora_2892.trc c:\cc.txt insert=c:\insert.sql 

執行後會在c:\産生insert.sql檔案,執行該檔案即可将資料儲存到資料庫,以下為insert.sql部分内容: 

REM Edit and/or remove the following CREATE TABLE 

REM statement as your needs dictate. 

CREATE TABLE tkprof_table 

date_of_insert DATE 

,cursor_num NUMBER 

,depth NUMBER 

,user_id NUMBER 

,parse_cnt NUMBER 

,parse_cpu NUMBER 

,parse_elap NUMBER 

,parse_disk NUMBER 

,parse_query NUMBER 

,parse_current NUMBER 

,parse_miss NUMBER 

,exe_count NUMBER 

,exe_cpu NUMBER 

,exe_elap NUMBER 

,exe_disk NUMBER 

,exe_query NUMBER 

,exe_current NUMBER 

,exe_miss NUMBER 

,exe_rows NUMBER 

,fetch_count NUMBER 

,fetch_cpu NUMBER 

,fetch_elap NUMBER 

,fetch_disk NUMBER 

,fetch_query NUMBER 

,fetch_current NUMBER 

,fetch_rows NUMBER 

,ticks NUMBER 

,sql_statement LONG 

); 

INSERT INTO tkprof_table VALUES 

SYSDATE, 1, 0, 61, 1, 0, 418, 0, 0, 0, 1 

, 1, 15625, 1435, 0, 0, 0, 0, 0 

, 4, 0, 4417, 0, 24, 0, 36, 13450151 

, ’select * from tblinventoryhistory 

‘); 

3.提取sql執行語句: 

C:\>tkprof c:\oc_ora_2892.trc c:\cc.txt record=sqlstr.sql 

sqlstr.sql中的内容: 

alter session set sql_trace=true ; 

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

select * from tblinventoryhistory ; 

select * from tblorder ; 

select * from tblproduct ; 

select * from tbluser ; 

select * from tblroute ; 

4.産生執行計劃: 

C:\>tkprof c:\oc_ora_2892.trc c:\ff.txt explain=ocuser/ocuser table=ocuser.test1 

在産生的ff.txt檔案中會展現其執行計劃: 

Rows Execution Plan 

——- ————————————————— 

0 SELECT STATEMENT GOAL: CHOOSE 

0 TABLE ACCESS (FULL) OF 'TBLROUTE'