使用sql trace工具和tkprof來跟會話

eric0435發表於2012-02-18
使用sql trace工具和tkprof
1.給跟蹤檔案設定初始化引數
2.對你所有跟蹤的會話和程式啟用sql trace功能.這個步驟會將這個程式使用的sql語句的統計輸出到一個跟蹤檔案中.
3.執行tkprof來翻譯第二步輸出的跟蹤檔案成為一個可讀的檔案袋.這一步也可以建立一個sql指令碼在資料庫中儲存統計
4.解釋說明第三步生成的輸出檔案.
5.可以在第三步執行一個sql指令碼將統計儲存在資料庫

給跟蹤檔案設定初始化引數
當對會話啟用sql trace功能後,oracle會對這個會話跟蹤的sql語句生成一個跟蹤檔案.跟蹤檔案包括統計資訊.當對整個例項啟用sql  trace時,oracle會對每一個程式生成一個跟蹤檔案.在啟用sql trace功能前需要做以下檢查.
1.檢查timed_statistics,max_dump_file_size和user_dump_dest初始化引數
timed_statistics:這個引數是用來是否啟用或禁用收集時間統計,象cpu和執行時間,透過sql trace功能也能收集動態效能表中的各 種統計.這個引數預設值是false禁用收集時間統計.當為true時啟用時間統計收集,啟用時間統計收集會對低階別的操作造成額外的調 用時間,這是一個動態引數.也是一個會話級別的引數.

max_dump_file_size:當在例項級別啟用sql trace功能時每一個呼叫都會生成一個作業系統文字格式的文字檔案.這些檔案的大小是 由這個引數的引數值決定的.這個引數預設值是500,如果你發現一個跟蹤輸出被截段了,那麼在生成另一個跟蹤檔案之前可以增加這個 引數值.這是一個動態引數,也是一會話級別的引數.

user_dump_dest:這個引數是給跟蹤檔案指定一個輸出目錄.這個引數的預設值是系統目錄.這個引數可以使用alter system set  user_dump_dest=newdir語句來修改,這是一個動態引數,也是一個會話級別的引數.

設計一種方法來識別輸出的跟蹤檔案
要確定你知道怎樣透過名字來識別跟蹤檔案.oracle透過user_dump_dest引數來寫這些跟蹤檔案到你指定的這個目錄下.然而這個目錄 下會很快就會使用生成的名字產生幾百個跟蹤檔案,使用這些跟蹤檔案很難找到他建軍這些跟蹤檔案和會話或過程.在你的程式中可以 使用象select 'program_name' from dual的語句加入到跟蹤檔案中.那麼就能跟蹤這些檔案是由哪個過程建立的.
你也能設定tracefile_identifier初始化引數來指定一個客戶識別符號作業跟蹤檔名的一部分.例如,可以簡單加一個my_trace_id到 這個跟蹤檔名進行簡單的識別.
alter session set tracefile_identifier='my_trace_id';

如果作業系統保留的多個版本的檔案,那麼要確保版本限制高足以容納你所期望sql trace所生成的跟蹤檔案資料量.

生成的跟蹤檔案除了你自己還可能由一個作業系統使用者進行操作.在你使用tkprof來格式化它前之前這個作業系統使用者必須確保你能 使用這些跟蹤檔案.


啟用sql trace功能
對會話啟用sql trace可以使用下面的任何一種方式來執行
1.dbms_session.set_sql_trace
2.alter session set sql_trace=true;
注意:因為執行sql trace功能會增加系統開銷,僅僅只有當調整sql語句時才啟用sql trace,當調整完以後禁用sql trace建議使用 dbms_session或dbms_monitor包來對會話或例項啟用sql跟蹤來代替alter 語句.
為了對會話禁用sql trace可以執行以下語句
alter session set sql_trace=false;

當應用程式從oracle斷開後對這個會話的sql trace也會自動禁用

也能透過設定sql_trace初始化引數來對整個例項來啟用sql trace功能.
sql_trace=true
在更新這個引數後例項要重新啟動.當例項啟用sql trace會收集所有會話的統計.可以設定sql_trace=false來禁用sql trace

使用tkprof來格式化跟蹤檔案
tkprof能訪問透過sql trace功能產生的跟蹤檔案生成一個格式的輸出檔案.tkprof也能用來生成執行計劃.
在sql trace功能已經生成了一些跟蹤資料夾後你可以執行以下操作
1.在每個單獨的跟蹤檔案上執行tkprof,為每一個會話的生成一個格式輸出檔案.
2.能聯合所有的跟蹤檔案,執行tkprof對整個例項生成一個格式化輸出檔案.
3.執行trcsess命令列工具來聯合多個跟蹤檔案的資訊然後執行tkprof生成格式化的結果.
在跟蹤檔案中tkprof不支援commit和rollback命令.

tkprof格式化輸出的例子如下
select c.*,
       (select d.corp_join_no
          from bs_corp_insure d
         where d.corp_id = b.corp_id
           and d.insr_detail_code = c.insr_detail_code) corp_join_no_dw
  from bs_corp_pres b, bs_pres_insur c
 where b.indi_id = c.indi_id
   and b.corp_id = c.corp_id and b.corp_id=:"SYS_B_0"

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.00       0.00          0         17          0           2
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.01       0.00          0         17          0           2

Misses in library cache during parse: 1
Optimizer mode: FIRST_ROWS
Parsing user id: 57

Rows     Row Source Operation
-------  ---------------------------------------------------
      2  TABLE ACCESS BY INDEX ROWID BS_CORP_INSURE (cr=6 pr=0 pw=0 time=40 us)
      2   INDEX RANGE SCAN IDX_BS_CORP_INSURE_1 (cr=4 pr=0 pw=0 time=26 us)(object id 230781)
      2  TABLE ACCESS BY INDEX ROWID BS_PRES_INSUR (cr=11 pr=0 pw=0 time=143 us)
      4   NESTED LOOPS  (cr=9 pr=0 pw=0 time=307 us)
      1    INDEX RANGE SCAN PK_BS_CORP_PRES (cr=3 pr=0 pw=0 time=44 us)(object id 230787)
      2    BITMAP CONVERSION TO ROWIDS (cr=6 pr=0 pw=0 time=66 us)
      1     BITMAP AND  (cr=6 pr=0 pw=0 time=63 us)
      1      BITMAP CONVERSION FROM ROWIDS (cr=3 pr=0 pw=0 time=28 us)
      2       INDEX RANGE SCAN INDX_BS_PRES_INSUR_INDI_ID (cr=3 pr=0 pw=0 time=13 us)(object id 231131)
      1      BITMAP CONVERSION FROM ROWIDS (cr=3 pr=0 pw=0 time=21 us)
      2       INDEX RANGE SCAN INDX_BS_PRES_INSUR_CORP_ID (cr=3 pr=0 pw=0 time=16 us)(object id 231129)

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        5      0.01       0.00          0          0          0           0
Execute      6      0.00       0.00          0          0          0           3
Fetch        2      0.00       0.00          0         17          0           3
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       13      0.01       0.00          0         17          0           6

Misses in library cache during parse: 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: /oracle/admin/RLZY/udump/rlzy_ora_16831_my_trace_id.trc
Trace file compatibility: 10.01.00
Sort options: default

       0  session in tracefile.
       5  user  SQL statements in trace file.
       0  internal SQL statements in trace file.
       5  SQL statements in trace file.
       3  unique SQL statements in trace file.
      57  lines in trace file.
      39  elapsed seconds in trace file.




對於這個語句,tkprof的輸出包括以下資訊
1.sql語句的文字
2.表格形式的sql跟蹤統計
3.解析和執行這個語句庫快取丟失的情況
4.呼叫解析該語句的使用者
5.透過explain plan生成的執行計劃.

tkprof還提供了使用者級別語句和遞迴語句呼叫的摘要資訊.

使用tkprof的語法
tkprof是在作業系統命令提示下執行的,它的語法如下
tkprof filename1 filename2 [waits=yes|no] [sort=option] [print=n]
[aggregate=yes|no] [insert=filename3] [sys=yes|no] [table=schema.table]
[explain=user/password] [record=filename4] [width=n]

在上面的語法中只有filename1(輸入檔名)和filename2輸出檔名是必須指定的.
tkprof引數如下
filename1:指定輸入檔案(由sql trace功能生成的包括了統計的檔案),這個檔案可以是一個跟蹤檔案,也可以是多個會話的跟蹤檔案 合併成的一個檔案.
filename2:指定tkprof格式化的輸出檔名
waits:指示在這個跟蹤檔案中是否有任何等待事件的記錄摘要,這引數的值有yes或no 預設的是yes.
sorts:在將格式化的內容寫入輸出檔案之前可以指定排序選項將跟蹤的語句按降序排列.如果排序選項指定了多個值,那麼就會按這 些排序項的合計值來進行降序排序.如果你沒有指定這個引數,那麼tkprof會按輸出檔案中的列出的引數順序來排序,下面是排序選項 的列表.
[
1:prscnt 解析時間
2:prscpu 解析使用的cpu時間
3:prsela 解析執行時間
4:prsdsk 在解析時從磁碟執行的物理讀取數
5:prsqry 在解析時一至讀取資料塊數
6:prscu  在解析時當前模式下資料塊讀取數
7:prsmis 在解析時庫快取丟失數
8:execnt 執行次數
9:exeela 執行時間
10:exedsk 執行時從磁碟執行物理讀取數
11:exeqry 執行時一至讀取資料塊數
12:execu  執行時當前模式下讀取資料塊數
13:exerow 執行時處理的行數
14:exemis 執行時庫快取丟失數
15:fchcnt 獲取資料數
16:fchcpu 獲取資料花費的cpu時間
17:fchela 獲取資料花費的執行時間
18:fchdsk 獲取資料時從磁碟讀取資料數
19:fchqry 獲取資料時一至性讀取資料塊數
20:fchcu  獲取資料時當前模式下讀取資料塊數
21:fchrow 獲取資料的行數
22:userid 解析使用者遊標的使用者ID
]
print:只從輸出檔案中顯示排序後的第一個sql語句,如果沒有指定這個引數,那麼tkprof將會顯示出所有的sql語句.這個引數不會影 響可選的sql指令碼.這個指令碼總是會生成所有跟蹤的sql語句的資料.
aggregate:如果指定aggregate=no時,那麼tkprof不會對相同的sql文字的多個使用者進行聚合操作.
insert:在資料庫中建立一個指令碼來儲存這個跟蹤檔案的統計.tkprof使用name filename3來建立這個指令碼.這個指令碼將會建立一個表 並向這個表中給每一個跟蹤的sql語句插入一條統計記錄.
sys:透過使用者sys來啟用或禁用是否將sql語句或遞迴sql語句寫入到輸出檔案中.這個預設值是yes,那麼tkprof會將所有的sql語句寫 入到輸出檔案中.如果為no時那麼tkprof將會忽略它們.這個引數不會影響可選的指令碼,這個sql指令碼總是會插入所有跟蹤sql語句的統 計包括遞迴sql語句.
table:指定表的方案和表名那麼tkprof在將它們寫入到輸出檔案中之前會將這個執行計劃臨時儲存在這個表中.如果指定的表已經存 在了,那麼tkprof刪除表中的所有記錄.使用它來explain plan 解析語句.然後刪除這些行.如果這個表不存在,那麼tkprof建立表,然 後刪除表.

指定的使用者必須能夠對這個表使用insert,select和delete語句.如果這個表不存在,那麼使用者必須能使用create table 和drop table 語句.
這個選項允許在explain時多個個同時使用相同的使用者執行tkprof,這些個人能指定不同的表名在臨時儲存計劃表時避免各個使用者相互 影響.
如果使用explain引數時沒有指定table引數,那麼tkprof使用prof$plan_table.如果使用table引數沒有使用explain引數時,那麼 tkprof會忽略這個table引數
如果沒有執行計劃表存在,tkprof會建立一個prof$plan_table在最後刪除它.

explain:在跟蹤檔案中判斷每一個sql語句的執行計劃並將這些執行計劃寫到輸出檔案中.tkprof判斷每一個sql語句的執行計劃是通 過指定使用者名稱和密碼引數連線到oracle資料庫後使用explain plan語句來生成的.指定的使用者必須有create session系統許可權.tkprof 如果使用explain選項時能長時間的處理一個很大的跟蹤檔案.

record:使用指定的filename4這個引數建立一個sql指令碼檔案將所有的不是遞迴的sql語句寫入到跟蹤檔案中.從跟蹤檔案中回放使用者事件.
width:一個整數值用來控制某些tkprof輸出的寬度象執行計劃.這個引數是用來後期處理tkprof的輸出的.

例子
一.先設定timed_statistics,max_dump_file_size和user_dump_dest初始化引數
timed_statistics=true
max_dump_file_size=UNLIMITED
user_dump_dest=/oracle/admin/RLZY/udump
二.啟用會話跟蹤:alter session set sql_trace=true
三.給生成的跟蹤檔案加入識別符號用於與區分其它的檔案:alter session set tracefile_identifier='my_trace_id';
四.在這個會話中執行查詢語句
select c.*,
       (select d.corp_join_no
          from bs_corp_insure d
         where d.corp_id = b.corp_id
           and d.insr_detail_code = c.insr_detail_code) corp_join_no_dw
  from bs_corp_pres b, bs_pres_insur c
 where b.indi_id = c.indi_id
   and b.corp_id = c.corp_id and b.corp_id=349;

 INDI_JOIN_NO INSR_DETAIL_CODE       CORP_ID  CORP_JOIN_NO       INDI_ID BEGIN_DATE  END_DATE    ALI_PAY_MONS TO_PAY_MONS FAC_PAY_MONS IF_INDI_ACCO HANDLE_MAN           HANDLE_DATE INDI_JOIN_STA LOST_PAY_SUM PAY_MODE_CODE TRANALI_PAY_MONS INDI_CHARGE_STA LOST_ENJOY_SUM DEAL_BEGIN_DATE FREEZE_STA FREEZE_REASON                                                                    TOPAY_BEGIN_PRD LACK_MONTHS MOD_TIMESTAMP                                                                    CORP_JOIN_NO_DW
------------- ---------------- ------------- ------------- ------------- ----------- ----------- ------------ ----------- ------------ ------------ -------------------- ----------- ------------- ------------ ------------- ---------------- --------------- -------------- --------------- ---------- -------------------------------------------------------------------------------- --------------- ----------- -------------------------------------------------------------------------------- ---------------
       121255                3           349          2484         12338 2009-11-1                                                                1 轉資料               2011-4-8 10             1                                                           1                                         0                                                                                                                                                                                                          2484
        12323                2           349           593         12338 2009-11-1       and b.corp_id = c.corp_id and b.corp_id=349;

 INDI_JOIN_NO INSR_DETAIL_CODE       CORP_ID  CORP_JOIN_NO       INDI_ID BEGIN_DATE  END_DATE    ALI_PAY_MONS TO_PAY_MONS FAC_PAY_MONS IF_INDI_ACCO HANDLE_MAN           HANDLE_DATE INDI_JOIN_STA LOST_PAY_SUM PAY_MODE_CODE TRANALI_PAY_MONS INDI_CHARGE_STA LOST_ENJOY_SUM DEAL_BEGIN_DATE FREEZE_STA FREEZE_REASON                                                                    TOPAY_BEGIN_PRD LACK_MONTHS MOD_TIMESTAMP                                                                    CORP_JOIN_NO_DW
------------- ---------------- ------------- ------------- ------------- ----------- ----------- ------------ ----------- ------------ ------------ -------------------- ----------- ------------- ------------ ------------- ---------------- --------------- -------------- --------------- ---------- -------------------------------------------------------------------------------- --------------- ----------- -------------------------------------------------------------------------------- ---------------
       121255                3           349          2484         12338 2009-11-1                                                                1 轉資料               2011-4-8 10             1                                                           1                                         0                                                                                                                                                                                                          2484
        12323                2           349           593         12338 2009-11-1

五.檢查生成的跟蹤檔案,在/oracle/admin/RLZY/udump目錄下生成了一個叫rlzy_ora_16831_my_trace_id.trc的檔案
六.使用tkprof來格式化跟檔案rlzy_ora_16831_my_trace_id.trc
$ tkprof /oracle/admin/RLZY/udump/rlzy_ora_16831_my_trace_id.trc
output = /oracle/admin/RLZY/udump/jy_02_07.trc
insert= /oracle/admin/RLZY/udump/jy_02_07.sql
七.檢查輸出檔案jy_02_07.trc的內容如下

TKPROF: Release 10.2.0.1.0 - Production on Tue Feb 7 16:42:51 2012

Copyright (c) 1982, 2005, Oracle.  All rights reserved.

Trace file: /oracle/admin/RLZY/udump/rlzy_ora_16831_my_trace_id.trc
Sort options: default

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

begin :id := sys.dbms_transaction.local_transaction_id; end;


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        3      0.00       0.00          0          0          0           0
Execute      3      0.00       0.00          0          0          0           3
Fetch        0      0.00       0.00          0          0          0           0
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        6      0.00       0.00          0          0          0           3

Misses in library cache during parse: 0
Optimizer mode: FIRST_ROWS
Parsing user id: 57
********************************************************************************

select :"SYS_B_0"
from
 dual


call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.00       0.00          0          0          0           0
Execute      2      0.00       0.00          0          0          0           0
Fetch        1      0.00       0.00          0          0          0           1
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        4      0.00       0.00          0          0          0           1

Misses in library cache during parse: 0
Optimizer mode: FIRST_ROWS
Parsing user id: 57

Rows     Row Source Operation
-------  ---------------------------------------------------
      1  FAST DUAL  (cr=0 pr=0 pw=0 time=3 us)

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

select c.*,
       (select d.corp_join_no
          from bs_corp_insure d
         where d.corp_id = b.corp_id
           and d.insr_detail_code = c.insr_detail_code) corp_join_no_dw
  from bs_corp_pres b, bs_pres_insur c
 where b.indi_id = c.indi_id
   and b.corp_id = c.corp_id and b.corp_id=:"SYS_B_0"

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        1      0.01       0.00          0          0          0           0
Execute      1      0.00       0.00          0          0          0           0
Fetch        1      0.00       0.00          0         17          0           2
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      0.01       0.00          0         17          0           2

Misses in library cache during parse: 1
Optimizer mode: FIRST_ROWS
Parsing user id: 57

Rows     Row Source Operation
-------  ---------------------------------------------------
      2  TABLE ACCESS BY INDEX ROWID BS_CORP_INSURE (cr=6 pr=0 pw=0 time=40 us)
      2   INDEX RANGE SCAN IDX_BS_CORP_INSURE_1 (cr=4 pr=0 pw=0 time=26 us)(object id 230781)
      2  TABLE ACCESS BY INDEX ROWID BS_PRES_INSUR (cr=11 pr=0 pw=0 time=143 us)
      4   NESTED LOOPS  (cr=9 pr=0 pw=0 time=307 us)
      1    INDEX RANGE SCAN PK_BS_CORP_PRES (cr=3 pr=0 pw=0 time=44 us)(object id 230787)
      2    BITMAP CONVERSION TO ROWIDS (cr=6 pr=0 pw=0 time=66 us)
      1     BITMAP AND  (cr=6 pr=0 pw=0 time=63 us)
      1      BITMAP CONVERSION FROM ROWIDS (cr=3 pr=0 pw=0 time=28 us)
      2       INDEX RANGE SCAN INDX_BS_PRES_INSUR_INDI_ID (cr=3 pr=0 pw=0 time=13 us)(object id 231131)
      1      BITMAP CONVERSION FROM ROWIDS (cr=3 pr=0 pw=0 time=21 us)
      2       INDEX RANGE SCAN INDX_BS_PRES_INSUR_CORP_ID (cr=3 pr=0 pw=0 time=16 us)(object id 231129)




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

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        5      0.01       0.00          0          0          0           0
Execute      6      0.00       0.00          0          0          0           3
Fetch        2      0.00       0.00          0         17          0           3
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total       13      0.01       0.00          0         17          0           6

Misses in library cache during parse: 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: /oracle/admin/RLZY/udump/rlzy_ora_16831_my_trace_id.trc
Trace file compatibility: 10.01.00
Sort options: default

       0  session in tracefile.
       5  user  SQL statements in trace file.
       0  internal SQL statements in trace file.
       5  SQL statements in trace file.
       3  unique SQL statements in trace file.
      57  lines in trace file.
      39  elapsed seconds in trace file.

八.檢查輸出檔案jy_02_07.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
);
set sqlterminator off
set sqlterminator on
建立一個tkprof_table的語句

來自 “ ITPUB部落格 ” ,連結:http://blog.itpub.net/26015009/viewspace-716718/,如需轉載,請註明出處,否則將追究法律責任。

相關文章