sql 跟蹤

1：?jiǎn)⒂脴?biāo)準(zhǔn)的SQL_TRACE功能 ( 默認(rèn)) 包含了 SQL語句、響應(yīng)時(shí)間、服務(wù)時(shí)間、處理的行數(shù)，物理讀和寫的數(shù)目、執(zhí)行計(jì)劃以及其他一些額外信息。到版本10.2中執(zhí)行計(jì)劃寫入到 trace 的條件是僅當(dāng)相關(guān)游標(biāo) 已經(jīng)關(guān)閉時(shí)，且與之相關(guān)的執(zhí)行統(tǒng)計(jì)信息是所有執(zhí)行次數(shù)的總和數(shù)據(jù)。到版本11.1中僅在每次游標(biāo)的第一次執(zhí)行后將執(zhí)行計(jì)劃寫入到trace ，執(zhí)行統(tǒng)計(jì)信息僅僅和這第一次執(zhí)行相關(guān)

4：比level 1時(shí)多出綁定變量的 trace

8 ：比level 1多出等待事件

16：在11g中為每一次執(zhí)行生成STAT信息，僅在11.1之后可用

32：比level 1少執(zhí)行計(jì)劃，在11.1以后可用

64：和level 1 相比在第一次執(zhí)行后還可能生成執(zhí)行計(jì)劃信息；條件是某個(gè)游標(biāo)在前一次執(zhí)行的前提下運(yùn)行耗時(shí)變長(zhǎng)了一分鐘。僅在 11.2.0.2中可用

其他補(bǔ)充

level 12（4+8）代表同事啟用level 4、level8

Level 28 (4 + 8 + 16) 代表同時(shí)啟用 level 4 、level 8、level 16

level 68 ( 64 + 4 ) 代表同時(shí)啟用 level 64、level 4

最常用的跟蹤模式level 12

1.1 alter session

開啟跟蹤

alter session set sql_trace=true，相當(dāng)level 1；

建議采用10046在指定如，啟用

ALTER SESSION SET events '10046 trace name context forever, level 12'；

關(guān)閉

ALTER SESSION SET events '10046 trace name context off'；

整個(gè)數(shù)據(jù)庫(kù)啟用跟蹤，session級(jí)別調(diào)整system就可以了。

1.2 DBMS_MONITOR

oracle 10g數(shù)據(jù)庫(kù)提供dbms_monitor包，你可以啟用和禁用sql跟蹤。還有一些擴(kuò)展的跟蹤屬性：

client identifier, service name, module name, action name，沒有獨(dú)立會(huì)話，采用連接池的模式，就無法指定具體的sessionid

使用dbms_MOINTOR包，你不能直接指定10046事件的級(jí)別，替換有三個(gè)參數(shù)可以配置。默認(rèn)級(jí)別是8

level 4：對(duì)應(yīng) binds =true
level 8：對(duì)應(yīng)wait=true
level 16：plan_stat=all_executions
level 32: plan_stat=nerver
level 64: 不支持

session level處理

可以確認(rèn)跟蹤哪個(gè)會(huì)話的

本會(huì)話

SQL> EXEC DBMS_MONITOR.session_trace_enable;
SQL> EXEC DBMS_MONITOR.session_trace_enable(waits=>TRUE, binds=>FALSE);
SQL> EXEC DBMS_MONITOR.session_trace_disable;

其他會(huì)話

開啟：dbms_monitor.session_trace_enable(session_id => 127,serial_num => 29,waits => TRUE,binds => FALSE,plan_stat => 'first_execution')

plan_stat：默認(rèn)null相等于first_execution

SELECT sql_trace, sql_trace_waits, sql_trace_binds, sql_trace_plan_stats FROM v$session WHERE sid = 127;

禁用：dbms_monitor.session_trace_disable(session_id => 127,serial_num => 29)

客戶端級(jí)別

無法通過單一的會(huì)話來處理，client_ID可以通過程序或者PL/SQL來指定

PL/SQL:dbms_session.set_identifier(client_id => 'helicon.antognini.ch');

dbms_monitor.client_id_trace_enable(client_id => 'helicon.antognini.ch',waits => TRUE,binds => TRUE,plan_stat => 'first_execution')

client_id來源于：V$SESSION.CLIENT_IDENTIFIER，是區(qū)分大小寫的

可以通過視圖來查看開啟的情況

SELECT primary_id AS client_id, waits, binds, plan_stats FROM dba_enabled_traces  WHERE trace_type = 'CLIENT_ID';

禁用：dbms_monitor.client_id_trace_disable(client_id => 'helicon.antognini.ch')

組件級(jí)別

service_name 、module_name、action_name可以通過程序或者PL/SQL來指定

PL/SQL:

dbms_application_info.set_module(module_name => 'mymodule',
action_name => 'myaction');

dbms_monitor.serv_mod_act_trace_enable(service_name => 'DBM11203.antognini.ch',module_name => 'mymodule',
action_name => 'myaction',waits => TRUE,binds => TRUE,instance_name => NULL,plan_stat => 'all_executions')

service_name 、module_name、action_name:來源V$SESSION

查詢開啟的情況
SELECT primary_id AS service_name, qualifier_id1 AS module_name,
 qualifier_id2 AS action_name, waits, binds, plan_stats
 FROM dba_enabled_traces
 WHERE trace_type IN ('SERVICE', 'SERVICE_MODULE', 'SERVICE_MODULE_ACTION');

禁用：dbms_monitor.serv_mod_act_trace_disable(service_name => 'DBM11203.antognini.ch',module_name => 'mymodule',
action_name => 'myaction',instance_name => NULL)

數(shù)據(jù)庫(kù)級(jí)別

dbms_monitor.database_trace_enable(waits => TRUE,binds => TRUE,instance_name => 'DBM11203',plan_stat => 'first_execution')

查看開啟情況

SELECT instance_name, waits, binds, plan_stats FROM dba_enabled_traces WHERE trace_type = 'DATABASE';

禁用：dbms_monitor.database_trace_disable(instance_name => 'DBM11203')

1.3 DBMS_SESSION

在oracle 10g之前，DBMS_MONTITOR是不能使用的，可以采用DBMS_SESSION包來處理，而且有限制只能是自己的會(huì)話

BEGIN
dbms_session.session_trace_enable(waits => TRUE,
binds => TRUE,
plan_stat => 'all_executions');
END;
 /

SELECT sql_trace, sql_trace_waits, sql_trace_binds, sql_trace_plan_stats
FROM v$session
WHERE sid = sys_context('userenv','sid');

BEGIN
dbms_session.session_trace_disable;
END;
/

1.4 oradebug模式

oradebug 需要SYSDBA權(quán)限，自己日常測(cè)試處理比較方便

本會(huì)話
CONN sys/password AS SYSDBA;
ORADEBUG SETMYPID;
ORADEBUG EVENT 10046 TRACE NAME CONTEXT FOREVER, LEVEL 12;
--輸出跟蹤文件路徑
ORADEBUG TRACEFILE_NAME;
ORADEBUG EVENT 10046 TRACE NAME CONTEXT OFF;

其他會(huì)話
--可以指定OS pid對(duì)應(yīng)v$process.spid
ORADEBUG SETOSPID 1234;
--或者指定oracle processid 對(duì)應(yīng)v$process.pid
ORADEBUG SETORAPID 123456;
ORADEBUG EVENT 10046 TRACE NAME CONTEXT FOREVER, LEVEL 12;
--輸出跟蹤文件路徑
ORADEBUG TRACEFILE_NAME;
ORADEBUG EVENT 10046 TRACE NAME CONTEXT OFF;

1.5 觸發(fā)器的模式啟用sql 跟蹤

針對(duì)個(gè)別用戶的全部會(huì)話都要開啟跟蹤，可以新增一個(gè)角色，創(chuàng)建一個(gè)登錄的觸發(fā)器來處理

CREATE ROLE sql_trace;
CREATE OR REPLACE TRIGGER enable_sql_trace AFTER LOGON ON DATABASE
BEGIN
IF (dbms_session.is_role_enabled('SQL_TRACE'))
THEN
EXECUTE IMMEDIATE 'ALTER SESSION SET timed_statistics = TRUE';
EXECUTE IMMEDIATE 'ALTER SESSION SET max_dump_file_size = unlimited';
dbms_session.session_trace_enable;
END IF;
END;

1.6 跟蹤文件中時(shí)間信息

cpu、實(shí)時(shí)時(shí)間記錄到跟蹤文件中，都需timed_statistics 設(shè)置為true，默認(rèn)是true。調(diào)整的方式

ALTER SESSION SET timed_statistics = TRUE

1.7 跟蹤文件限制大小

跟蹤文件的大小通過max_dump_file_size這個(gè)參數(shù)，默認(rèn)值unlimited，如果是其他值的話，建議調(diào)整為默認(rèn)值

ALTER SESSION SET max_dump_file_size = 'unlimited'

1.8 查找跟蹤文件

SELECT
        pa.value || '/' || LOWER(SYS_CONTEXT('userenv','instance_name')) ||
        '_ora_' || p.spid || '.trc' AS trace_file
 FROM   v$session s,
        v$process p,
        v$parameter pa
 WHERE  pa.name = 'user_dump_dest'
 AND    s.paddr = p.addr
 AND    s.audsid = SYS_CONTEXT('USERENV', 'SESSIONID');

11g以后也可以采用

SELECT value
 FROM v$diag_info
 WHERE name = 'Default Trace File';

oradebug模式的，可以直接采用oradebug tracefile_name;

2 跟蹤內(nèi)容說明

打開跟蹤內(nèi)容，類似以下的輸出，還是不容易查看

PARSING IN CURSOR 到 END OF STMT是sql 文本的內(nèi)容

PARSE,EXEC,FETCH,CLOSE分別對(duì)應(yīng)是解析、執(zhí)行、獲取、關(guān)閉調(diào)用

BINGS:對(duì)應(yīng)的是綁定變量

WAIT：表示的具體的等待事件

STAT:表示執(zhí)行計(jì)劃

了解詳細(xì)的細(xì)節(jié)，可以參考：

3 TKPROF使用

tkprof可以格式化跟蹤文件，查看問題的友好性

使用方法:

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

參數(shù)詳細(xì)說明：

tracefile：跟蹤文件路徑

outputfile：輸出的文件路徑

explain=user/password 使用哪個(gè)用戶鏈接數(shù)據(jù)庫(kù)，發(fā)出explain plan

table=schema.tablename 配合explain一起使用

print=integer 是整數(shù)，只是羅列前多少個(gè)sql語句

aggregate=yes|no 相同的sql語句是否需要匯總

insert=filename 羅列SQL語句和數(shù)據(jù)包含在insert語句中

sys=no 不羅列以sys用戶運(yùn)行的sql語句

record=filename 在跟蹤文件中查詢非遞歸的語句到文件中

waits=yes|no 跟蹤文件中記錄任何等待事件

sort=option 設(shè)置0或者以下值

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

常用的轉(zhuǎn)換說明

直接轉(zhuǎn)換

tkprof kthis_ora_3335.trc kthis_ora_3335.log

增加執(zhí)行計(jì)劃輸出

tkprof kthis_ora_3335.trc kthis_ora_3335.log sys=no explain=hr/hr

相同sql語句合并并不輸出sys用戶下的運(yùn)行的表

tkprof kthis_ora_3335.trc kthis_ora_3335_ag.log aggregate=yes sys=no

只是輸出執(zhí)行的sql語句

tkprof kthis_ora_3335.trc kthis_ora_3335_record.log record=0335record.log

輸出排序模式，解析、執(zhí)行時(shí)間、獲取時(shí)間累加排在最上面

tkprof kthis_ora_3335.trc kthis_ora_3335_ag.log sort=prsela,exeela,fchela

內(nèi)容說明，如以下內(nèi)容

SQL ID: 6599sqasxy094 Plan Hash: 2292431634

select *
from
 mzsfxx where kpry=999


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        1      3.88      89.12     317839     317885          0         104
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        3      3.88      89.12     317839     317885          0         104

Misses in library cache during parse: 0
Optimizer mode: ALL_ROWS
Parsing user id: 87
Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max)  Row Source Operation
---------- ---------- ----------  ---------------------------------------------------
       104        104        104  PARTITION RANGE ALL PARTITION: 1 21 (cr=317885 pr=317839 pw=0 time=27318096 us cost=87923 size=16708926 card=214217)
       104        104        104   TABLE ACCESS FULL MZSFXX PARTITION: 1 21 (cr=317885 pr=317839 pw=0 time=79035643 us cost=87923 size=16708926 card=214217)


Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       1        0.00          0.00
  Disk file operations I/O                        2        0.00          0.00
  db file sequential read                        44        0.03          0.37
  direct path read                             2611        0.41         85.72
  db file scattered read                         13        0.02          0.23
  SQL*Net more data to client                     3        0.00          0.00
  SQL*Net message from client                     1       16.25         16.25
********************************************************************************

parse	解析該游標(biāo)并生成執(zhí)行計(jì)劃的統(tǒng)計(jì)信息
execute	執(zhí)行該游標(biāo)的統(tǒng)計(jì)信息
fetch	獲取數(shù)據(jù)行的統(tǒng)計(jì)信息
count	指該游標(biāo)的相關(guān)操作的次數(shù) ，如parse count：1，該游標(biāo)被解析了1次
cpu	消耗cpu的時(shí)間，單位s
elapsed	實(shí)際消耗的時(shí)間，單位s
disk	消耗的物理讀
query	消耗一致性邏輯讀 consistenr logical read=》一個(gè)select 查詢，query一般沒有current
current	當(dāng)前的邏輯讀，current logical read ，針對(duì)的是insert、update、delete
row	返回的行數(shù)
Misses in library cache during parse	在解析階段library cache發(fā)生了miss，則說明本次解析是硬解析
cr	一致性模式下的邏輯讀塊數(shù)量
pr	從磁盤物理讀的塊數(shù)量
pw	從磁盤物理寫的塊數(shù)量
time	操作中花費(fèi)時(shí)間，采用微妙
cost	評(píng)估操作的代價(jià)，11.1版本后提供
Size	評(píng)估這個(gè)操作返回的數(shù)據(jù)量（字節(jié)）
card	評(píng)估這個(gè)操作返回的行數(shù)
times waited	等待事件發(fā)生的次數(shù)
max. wait	單次等待事件最大等待事件，秒為單位
Total Waited	這個(gè)等待事件總的等待事件，秒為單位

最后面還有匯總的信息sys遞歸的語句(ALL RECURSIVE STATEMENTS)和非遞歸(ALL NON-RECURSIVE STATEMENTS)

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        3      0.00       0.04          0          0          0           0
Execute      3      0.00       0.07          2         57          0           2
Fetch        1      3.88      89.12     317839     317885          0         104
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total        7      3.89      89.24     317841     317942          0         106

Misses in library cache during parse: 2
Misses in library cache during execute: 1

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  SQL*Net message to client                       3        0.00          0.00
  SQL*Net message from client                     3       53.75         70.01
  db file sequential read                        44        0.03          0.37
  Disk file operations I/O                        2        0.00          0.00
  direct path read                             2611        0.41         85.72
  db file scattered read                         13        0.02          0.23
  SQL*Net more data to client                     3        0.00          0.00


OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call     count       cpu    elapsed       disk      query    current        rows
------- ------  -------- ---------- ---------- ---------- ----------  ----------
Parse        5      0.00       0.00          0          0          0           0
Execute    183      0.02       0.35          0          0          0           0
Fetch      244      0.00       0.22         32        564          0         564
------- ------  -------- ---------- ---------- ---------- ----------  ----------
total      432      0.03       0.58         32        564          0         564

Misses in library cache during parse: 5
Misses in library cache during execute: 5

Elapsed times include waiting on following events:
  Event waited on                             Times   Max. Wait  Total Waited
  ----------------------------------------   Waited  ----------  ------------
  db file sequential read                        32        0.03          0.21

用戶執(zhí)行的語句和內(nèi)部執(zhí)行的語句的數(shù)量

   4  user  SQL statements in session.
   19  internal SQL statements in session.
   23  SQL statements in session

總體情況說明

 1  session in tracefile.
       4  user  SQL statements in trace file.
      19  internal SQL statements in trace file.
      23  SQL statements in trace file.
      22  unique SQL statements in trace file.
    5664  lines in trace file.
     159  elapsed seconds in trace file.

4 TRCESS使用

可以使用命令行工具從一個(gè)或多個(gè)跟蹤文件中抽取一部分的信息，輸出的文件還需要通過tkprof來轉(zhuǎn)換查看，使用方式

trcsess [output=<output file name >] [session=<session ID>] [clientid=<clientid>]
[service=<service name>] [action=<action name>] [module=<module name>]
<trace file names>

output：輸出文件路徑

session：哪個(gè)會(huì)話被跟蹤，session id為（id,serial#）

clientid:客戶端被跟蹤

service：服務(wù)被跟蹤

module：模塊被跟蹤

<trace_file_name>：跟蹤文件以空白來分隔

使用：trcsess output=trcess_3607.trc module="TOAD 11.0.0.116" kthis_ora_3335.trc

5 客戶端從服務(wù)器端取文件

跟蹤文件在服務(wù)器上的，獲取存在不方便，我們可以事先通過創(chuàng)建一個(gè)函數(shù)來獲取

創(chuàng)建類型，通過管道表的功能讀取指定的跟蹤文件

CREATE TYPE hr.t_trace_tab AS TABLE OF VARCHAR2(32767);
/

CREATE OR REPLACE FUNCTION hr.get_trace_file (p_trace_file IN VARCHAR2)
RETURN trace_user.t_trace_tab PIPELINED
AS
l_file UTL_FILE.file_type;
l_text VARCHAR2(32767);
BEGIN
l_file := UTL_FILE.fopen('TRACE_DIR', p_trace_file, 'r', 32767);
BEGIN
LOOP
UTL_FILE.get_line(l_file, l_text);
PIPE ROW (l_text);
END LOOP;
EXCEPTION
WHEN NO_DATA_FOUND THEN
NULL;
END;
UTL_FILE.fclose(l_file);
RETURN;
EXCEPTION
WHEN OTHERS THEN
PIPE ROW ('ERROR: ' || SQLERRM);
IF UTL_FILE.is_open(l_file) THEN
UTL_FILE.fclose(l_file);
END IF;
RETURN;
END;
/

--可以提供給其他的用戶來執(zhí)行
GRANT EXECUTE ON hr.t_trace_tab TO PUBLIC;
GRANT EXECUTE ON hr.get_trace_file TO PUBLIC;
CREATE PUBLIC SYNONYM get_trace_file FOR hr.get_trace_file;

-- Create a directory object to the trace location.
CREATE OR REPLACE DIRECTORY trace_dir AS '/u01/app/oracle/diag/rdbms/gull/gull/trace/';
GRANT READ ON DIRECTORY trace_dir TO HR;

測(cè)試執(zhí)行

EXEC DBMS_MONITOR.session_trace_enable;
 select * from  EMPLOYEES;
 EXEC DBMS_MONITOR.session_trace_disable;
采用sqlplus 緩存到本地文件
SET PAGESIZE 0 FEEDBACK OFF TRIMSPOOL ON TAB OFF
SPOOL C:\tracefile.trc

SELECT * FROM   TABLE(get_trace_file('gull_ora_4322.trc'));

SPOOL OFF
SET PAGESIZE 14 FEEDBACK ON

6 參考

《Troubleshooting-Oracle-Performance-2nd-Edition》

https://oracle-base.com/articles/misc/sql-trace-10046-trcsess-and-tkprof

posted @ 2018-03-08 14:06 gull Views(524) Comments(0) 收藏舉報(bào)

刷新頁面返回頂部

gull