SQL跟蹤工具和TKPROF使用
1 為跟蹤檔案設定初始引數
1.檢查設定 TIMED_STATISTICS, MAX_DUMP_FILE_SIZE, and USER_DUMP_DEST：
timed_statistics boolean TRUE
max_dump_file_size string UNLIMITED
user_dump_dest string /u01/app/oracle/admin/EMREP/udump
檢視以上三個引數：
Set linesize 1500;
col value for a50;
Col name for a30;
select name,type,value from v$parameter where name in ('timed_statistics','max_dump_file_size','user_dump_dest');
2 為客戶端ID啟用跟蹤
DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE程式為資料庫指定的使用者ID啟用跟蹤，
DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE(
client_id IN
VARCHAR2,
waits IN
BOOLEAN DEFAULT TRUE,
binds IN
BOOLEAN DEFAULT FALSE);
Ａ. 為v$session中的client_identifier列附值:
預設v$session中的client_identifier列的值為空，可以透過建立trigger來給client_identifier列附加一個值:
CREATE OR REPLACE TRIGGER logon_trigger
AFTER LOGON ON DATABASE
DECLARE
uid VARCHAR2(64);
BEGIN
SELECT ora_login_user || '.' || SYS_CONTEXT('USERENV', 'OS_USER')
INTO uid
FROM dual;
dbms_session.set_identifier(uid);
END logon_trigger;
/
檢視：
COL TRIGGERING_EVENT FOR A30;
select owner,trigger_name, TRIGGERING_EVENT，TABLE_NAME from dba_triggers where TRIGGER_NAME='LOGON_TRIGGER';
Ｂ.檢視client_identifier列附值：
select username,SID, SERIAL#, CLIENT_identifier from v$session where username='TEST'；
EXECUTE DBMS_MONITOR.CLIENT_ID_TRACE_ENABLE(client_id => 'TEST.oracle',waits => TRUE, binds => FALSE);
EXECUTE DBMS_MONITOR.CLIENT_ID_TRACE_DISABLE(client_id => 'TEST.oracle');
３ 跟蹤會話：
select sid,serial#,username from v$session where username is not null;
SID SERIAL# USERNAME
---------- ---------- ------------------------------
139 9726 TEST
140 43245 SYS
給指定的會話使用適當的值啟用跟蹤：
SQL>EXECUTE DBMS_MONITOR.SESSION_TRACE_ENABLE(session_id =>139, serial_num => 9726,waits => TRUE, binds => FALSE);
TEST使用者執行SQL：
SQL> create table test6 as select * from test2;
SQL> set linesize 1500;
SQL> col object_name for a40;
SQL> select * from test6;
SQL> update test6 set object_name='TEST' WHERE OBJECT_ID<20;
SQL> select * from test6;
SQL>EXECUTE DBMS_MONITOR.SESSION_TRACE_DISABLE(session_id =>139, serial_num =>9726);
279 10 TEST
EXECUTE DBMS_MONITOR.SESSION_TRACE_DISABLE(session_id =>279, serial_num =>10);
使用10046 事件跟蹤：
Level 0 tracing被關閉。這相當於設定sql_trace=false。
Level 1 跟蹤sql語句，包括解析、執行、提取、提交和回滾等（SQL_TRACE=TRUE）。這是預設級別。
Level 4 SQL trace資訊加繫結變數值(包括變數的詳細資訊)。
Level 8 SQL trace資訊加等待事件資訊。
Level 12 SQL trace 資訊，等待事件資訊，和繫結變數值。
跟蹤當前的會話：
SQL> grant alter session to test;
SQL> conn test/test;
SQL> alter session set events '10046 trace name context forever ,level 12';
SQL> alter session set events '10046 trace name context off' ;
跟蹤指定的會話：
SQL> select sid,serial#,username,status from v$session where username='TEST';
SID SERIAL# USERNAME
---------- ---------- ------------------------------
124 26742 TEST
方法一:
執行跟蹤:
SQL> exec dbms_system.set_ev(148,2028,10046,8,''); ------------注意最後一個引數'',必須是這樣的,而沒有使用者名稱
TEST使用者執行SQL：
SQL> create table test6 as select * from test2;
SQL> set linesize 1500;
SQL> col object_name for a40;
SQL> select * from test6;
SQL> update test6 set object_name='TEST' WHERE OBJECT_ID<20;
SQL> select * from test6;
結束跟蹤：
SQL> exec dbms_system.set_ev(148,2028,10046,0,'');
方法二（略過）:
SQL> select sid,serial#,username,status from v$session where username ='TEST';
SID SERIAL# USERNAME STATUS
---------- ---------- ------------------------------ --------
124 26742 TEST KILLED
140 61014 TEST INACTIVE
148 2028 TEST KILLED
Session 1:
conn /as sysdba
exec dbms_system.set_ev(140,61014,10046,8,'test');
執行了這一步以後 只是對其他的會話設定了跟蹤事件的等級，並非開始跟蹤
開始跟蹤
exec dbms_system.set_sql_trace_in_session(140,61014,true);
....
在Session 2:
Conn test/test
中執行SQL 語句:
Select count(*) from user_tables;
Session 1:
結束跟蹤
exec dbms_system.set_sql_trace_in_session(140,61014,false);
關閉會話設定
exec dbms_system.set_ev(140,61014,10046,0,'test');
使用10053事件跟蹤：
如果想了解CBO的內部，還得透過10053事件，從10053事件的trace檔案中，我們可以深入的瞭解CBO的內部，瞭解CBO是如何工作的，根據什麼依據得出最終的執行計劃。(10053事件的trace檔案,我們只能直接閱讀原始的trace檔案,不能使用tkprof工具來處理)
10053事件有兩個級別：
Level 2：2級是1級的一個子集
Level 1： 1級比2級更詳細，它包含2級的所有內容.
設定本session的10053
開啟：
Alter session set events’10053 trace name context forever[,level {1/2}]’;
關閉：
Alter session set events’10053 trace name context off’;
設定其他session的10053
開啟：
SYS.DBMS_SYSTEM.SET_EV (
關閉：
SYS.DBMS_SYSTEM.SET_EV (
啟動10053事件
SQL> grant alter session to test;
SQL> conn test/test;
SQL> ALTER SESSION SET EVENTS='10053 trace name context forever, level 1';
執行事務
SQL> select * from test2;
關閉10053事件
SQL> ALTER SESSION SET EVENTS '10053 trace name context off';
查詢跟蹤檔案：
A:透過指令碼查詢(只能查詢當前使用者下的)：
select d.value||'/'||lower(rtrim(i.instance, chr(0)))||'_ora_'||p.spid||'.trc' trace_file_name from ( select p.spid from sys.v$mystat m,sys.v$session s,sys.v$process p where m.statistic# = 1 and s.sid = m.sid and p.addr = s.paddr) p, ( select t.instance from sys.v$thread t,sys.v$parameter v where v.name = 'thread' and (v.value = 0 or t.thread# = to_number(v.value))) i, ( select value from sys.v$parameter where name = 'user_dump_dest') d ;
Ｂ:使用linux命令查詢：
進入“ user_dump_dest”目錄中：ll -t 命令，按時間顯示最新產生的TRACE檔案.跟蹤檔案格式為:“例項名_ora_程式號.trc”,user_dump_dest目錄下查詢對應程式的跟蹤檔案:
select spid from v$process where addr =(select paddr from v$session where sid='148' and serial#='2028');
４ 使用tkprof工具對trace檔案進行分析。
一般來說，使用tkprof得到的輸出檔案中包含三個部分：
a.SQL語句本身。
b.相關的診斷資訊，包括cpu時間、總共消耗的時間、讀取磁碟數量、邏輯讀的數量、以及查詢中返回的記錄數目。
c.列出這個語句的執行計劃。
[oracle@secdb2 udump]$ tkprof
Usage: tkprof tracefile outputfile [explain= ] [table= ]
[print= ] [insert= ] [sys= ] [sort= ]
table=schema.tablename Use 'schema.tablename' with 'explain=' option.
explain=user/password Connect to ORACLE and issue EXPLAIN PLAN.
print=integer List only the first 'integer' SQL statements.
aggregate=yes|no
insert=filename List SQL statements and data inside INSERT statements.
sys=no TKPROF does not list SQL statements run as user SYS.
record=filename Record non-recursive statements found in the trace file.
waits=yes|no Record summary for any wait events found in the trace file.
sort=option Set of zero or more of the following sort options:
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
其中比較有用的一個排序選項是fchela，即按照elapsed time fetching來對分析的結果排序（記住要設定初始化引數time_statistics=true），生成的.prf檔案將把最消耗時間的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這步。
SQL語句的等待事件，對每種型別的等待事件提供瞭如下值。
Times Waited是等待事件佔用時間。
Max. Wait是單個等待事件最大等待時間，單位為秒。
Total Waited是針對一個等待事件總的等待秒數。理想情況下，所有等待事件的等待時間總量應該等於執行統計提供的流逝時間與CPU時間的差值。該差值，如果存在，叫做未說明的時間（unaccounted for time）。
[oracle@secdb2 udump]$ tkprof emrep_ora_25724.trc ora_25724.prf sys=no SORT=FCHELA,PRSDSK,EXEDSK,FCHDSK PRINT = 10
TKPROF: Release 10.2.0.1.0 - Production on Sat Jan 26 07:29:37 2013
Copyright (c) 1982, 2005, Oracle. All rights reserved.
[oracle@secdb2 udump]$ cat ora_25724.prf |more
TKPROF: Release 10.2.0.1.0 - Production on Sat Jan 26 07:29:37 2013
Copyright (c) 1982, 2005, Oracle. All rights reserved.
Trace file: emrep_ora_25724.trc
Sort options: fchela prsdsk exedsk fchdsk
********************************************************************************
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
********************************************************************************
select *
from
t
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 0.00 0.00 0 0 0 0
Fetch 3613 0.27 0.27 753 4324 0 54177
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 3615 0.28 0.28 753 4324 0 54177
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: 62
Rows Row Source Operation
------- ---------------------------------------------------
54177 TABLE ACCESS FULL T (cr=4324 pr=753 pw=0 time=162999 us)
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 3613 0.00 0.00
db file sequential read 1 0.00 0.00
db file scattered read 57 0.00 0.01
SQL*Net message from client 3613 1.30 160.52
********************************************************************************
…………...
********************************************************************************
Trace file: emrep_ora_25724.trc
Trace file compatibility: 10.01.00
Sort options: fchela prsdsk exedsk fchdsk
1 session in tracefile.
3 user SQL statements in trace file.
78 internal SQL statements in trace file.
81 SQL statements in trace file.
14 unique SQL statements in trace file.
11679 lines in trace file.
199 elapsed seconds in trace file.
說明：
cr為一致方式讀取，顯示一致讀取數(邏輯I/O) pr 是物理讀取 pw為物理寫入 time=(以百萬分之一秒計佔用時間)。
來自 “ ITPUB部落格 ” ，連結：http://blog.itpub.net/27036311/viewspace-753091/，如需轉載，請註明出處，否則將追究法律責任。
相關文章
- 使用sql trace工具和tkprof來跟會話SQL會話
- 使用TKPROF檢視跟蹤檔案
- 使用 Tkprof 分析 ORACLE 跟蹤檔案Oracle
- 轉：使用 Tkprof 分析 ORACLE 跟蹤檔案Oracle
- tkprof: 分析ORACLE跟蹤檔案Oracle
- sql_trace跟蹤工具(轉)SQL
- 跟蹤使用者的SQLSQL
- ORACLE中SQL TRACE和TKPROF的使用OracleSQL
- sql_trace 和 events 跟蹤事件SQL事件
- sql_trace 及 tkprof 工具SQL
- ORACLE 跟蹤工具Oracle
- 使用sqltrace跟蹤session執行的sqlSQLSession
- 使用10046跟蹤sql語句SQL
- oracle跟蹤檔案和跟蹤事件(zt)Oracle事件
- SQLServer進行SQL跟蹤SQLServer
- 會話級SQL跟蹤會話SQL
- SQL 的跟蹤方法traceSQL
- 使用SQL TRACE和TKPROF觀察SQL語句執行結果SQL
- Tkprof工具介紹和分析
- SQL TRACE和TKPROF,10046的使用步驟SQL
- 使用DBMS_TRACE對PL/SQL進行跟蹤SQL
- 使用 Python 和 Prometheus 跟蹤天氣PythonPrometheus
- 使用SQL TRACE和TKPROF——效能調整手冊和參考SQL
- Oracle資料庫跟蹤SQLOracle資料庫SQL
- phalcon:跟蹤sql語句SQL
- sql server跟蹤資料庫SQLServer資料庫
- 跟蹤 sql 的trace檔案SQL
- TCP流嗅探和連線跟蹤工具tcpickTCP
- Tkprof工具介紹和分析[轉]]
- Oracle執行語句跟蹤 使用sql trace實現語句追蹤OracleSQL
- 路由跟蹤工具0trace路由
- 使用oracle的10046事件跟蹤SQL語句Oracle事件SQL
- 跟蹤SQL - SQL Trace 及 10046 事件SQL事件
- SQL 跟蹤方法相關介紹SQL
- SQL SERVER 跟蹤標記總結SQLServer
- sqlplus 跟蹤sql語句SQL
- Oracle跟蹤事件和dumpOracle事件
- sql server關於跟蹤日誌查詢使用說明SQLServer