使用 Tkprof 分析 ORACLE 跟蹤檔案
Tkprof是一個用於分析Oracle跟蹤檔案並且產生一個更加清晰合理的輸出結果的可執行工具。如果一個系統的執行效率比較低,一個比較好的方法是通過跟蹤使用者的會話並且使用Tkprof工具使用排序功能格式化輸出,從而找出有問題的SQL語句。
一. TKPROF 命令語法:TKPROF filename1, filename2 [ SORT = [ opion][,option] ] [ PRINT = integer ] [ AGGREGATE = [ YES | NO ] ] [ INSERT = filename3 ] [ SYS = [ YES | NO ] ] [ [ TABLE = schema.table ] | [ EXPLAIN = user/password ] ]
相關說明:filename1 指定的輸入檔案,可以是多個檔案聯起來。Filename2 格式化輸出檔案。SORT 在輸出到輸出檔案前,先程序排序。如果省去,則按照實際使用的順序輸出到檔案中。排序選項有以下多種: 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
PRINT 只列出輸出檔案的第一個integer 的SQL語句。預設為所有的SQL語句。AGGREGATE 如果= NO ,則不對多個相同的SQL進行彙總。INSERT SQL 語句的一種,用於將跟蹤檔案的統計資訊儲存到資料庫中。在TKPROF建立指令碼後,在將結果輸入到資料庫中。SYS 禁止或啟用 將SYS使用者所釋出的SQL語句列表到輸出檔案中。TABLE 在輸出到輸出檔案前,用於存放臨時表的使用者名稱和表名。EXPLAIN 對每條SQL 語句確定其執行規劃。並將執行規劃寫到輸出檔案中。
其中比較有用的一個排序選項是fchela,即按照elapsed time fetching來對分析的結果排序(記住要設定初始化引數timed_statistics=true),生成的檔案將把最消耗時間的sql放在最前面顯示。另外一個有用的引數就是sys,這個引數設定為no可以阻止所有以sys使用者執行的sql被顯示出來,這樣可以減少分析出來的檔案的複雜度,便於檢視。
二. 對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這步。
三. Tkprof的使用步驟基本上遵循以下幾步:1、設定TIMED_STATISTICS為True,可以在會話級別,也可以在例項級別。會話級:SQL> alter session set timed_statistics=True;例項級:SQL> alter system set timed_statistics=True scope=both;2、 設定SQL_TRACE,可以在會話級,也可以在資料庫級。會話級:SQL> alter session set sql_trace=true;或者:SQL>EXEC DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(SID,SERIAL#,TRUE);例項級:SQL> alter system set sql_trace=true scope=both;
四.舉例說明:--啟用SQL_TRACESQL> alter session set sql_trace=true;會話已更改。SQL> select count(*) from bigtab;
COUNT(*)
----------
1922423--啟用timed_statisticsSQL> alter session set timed_statistics=true;
會話已更改。
SQL> select count(*) from bigtab;
COUNT(*)
----------
1922423
SQL> alter session set sql_trace =false;
會話已更改。
--查詢此會話產生的TRACE檔案SQL> select username,sid,serial# from v$session where username='SYS';
USERNAME SID SERIAL#
------------------------------ ---------- ----------
SYS 19 2518
SQL> select 'orcl_ora_'||spid||'.trc' from v$process where addr = (select paddr from v$session where sid=19);
'DSS_ORA_'||SPID||'.TRC'
------------------------------------
orcl_ora_7240.trc
也可以通過下面的函式來獲取當前的trace檔案:
create or replace function gettracename return varchar2 is v_result varchar2(200);begin SELECT d.VALUE || '/' || LOWER (RTRIM (i.INSTANCE, CHR (0))) || '_ora_' || p.spid || '.trc' into v_result 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; return v_result;end gettracename;執行SQL> select gettracename() from dual;即可SQL> select gettracename() from dual;
GETTRACENAME()
--------------------------------------------------------------------------
d:/app/administrator/diag/rdbms/orcl/orcl/trace/orcl_ora_7240.trc
--使用tkprof分析trace檔案C:/Users/Administrator.DavidDai>tkprof d:/app/administrator/diag/rdbms/orcl/orcl
/trace/orcl_ora_7240.trc D:/orcl_ora_7240.txt aggregate=yes sys=no waits=yes sor
t=fchela
TKPROF: Release 11.2.0.1.0 - Development on 星期五 5月 28 16:48:49 2010
Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.
--tkprocf輸出了以下檔案:D:/orcl_ora_7240.txt
TKPROF: Release 11.2.0.1.0 - Development on 星期五 5月 28 16:48:49 2010
Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.
Trace file: d:/app/administrator/diag/rdbms/orcl/orcl/trace/orcl_ora_7240.trc
Sort options: fchela
********************************************************************************
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 5 0.00 0.00 0 0 0 0
Fetch 4 0.79 7.45 57075 57082 0 2
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 13 0.79 7.45 57075 57082 0 2
Misses in library cache during parse: 3
Misses in library cache during execute: 1
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
5 user SQL statements in session.
0 internal SQL statements in session.
5 SQL statements in session.
********************************************************************************
Trace file: d:/app/administrator/diag/rdbms/orcl/orcl/trace/orcl_ora_7240.trc
Trace file compatibility: 11.1.0.7
Sort options: fchela
1 session in tracefile.
5 user SQL statements in trace file.
0 internal SQL statements in trace file.
5 SQL statements in trace file.
5 unique SQL statements in trace file.
73 lines in trace file.
75 elapsed seconds in trace file.
五. 分析會話的示例:先從os上利用top命令找到當前佔用cpu資源最高的一個程序的PID號:14483然後在資料庫中根據PID號找到相應的sid號和serial#:SQL> select s.sid,s.serial# from v$session s,v$process pwhere s.paddr=p.addr and p.spid='14483'; SID SERIAL#---------- ---------- 101 25695
使用dbms_system.set_sql_trace_in_session包來對這個session進行trace:SQL> exec DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION(101,25695,true);PL/SQL procedure successfully completed.
到user_dump_dest定義的路徑下查詢剛剛最近生成的trace檔案,可以根據時間來排序,找最近的trace檔案,也可以根據SID_ORA_SPID.TRC的規則,即ORCL_ORA_14483.TRC找到TRACE檔案。
接著使用tkprof工具對此trace檔案進行格式化分析,生成分析後的trace檔案。$tkprof orcl_ora_14483.trc allan.txt explain=system/manager aggregate=yes sys=no waits=yes sort=fchela
TKPROF: Release 11.2.0.1.0 - Development on 星期五 5月 28 16:48:49 2010
Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.
這裡生成的allan.txt檔案就是我們最終得到的格式化後的trace檔案了,然後開啟這個檔案進行分析。最後總的統計:OVERALL TOTALS FOR ALL RECURSIVE STATEMENTScall count cpu elapsed disk query current rows------- ------ -------- ---------- ---------- ---------- ---------- --------Parse 20 0.01 0.02 0 58 0 0Execute 13197 0.81 0.90 17 7436 6316 1484Fetch 12944 22.86 22.10 20 2205941 0 8972------- ------ -------- ---------- ---------- ---------- ---------- --------total 26161 23.68 23.02 37 2213435 6316 10456