sql 跟蹤

目錄

1 sql跟蹤

1.1 alter session

1.2 DBMS_MONITOR

1.3 DBMS_SESSION

1.4 oradebug模式

1.5 觸發器的模式啓用sql 跟蹤

1.6 跟蹤文件中時間信息

1.7 跟蹤文件限制大小

1.8 查找跟蹤文件

2 跟蹤內容說明

3 TKPROF使用

4 TRCESS使用

5 客戶端從服務器端取文件

6 參考

---

1 sql跟蹤

sql 跟蹤能夠清晰看到一條或多條語句資源消耗狀況：如CPU、邏輯讀、物理讀的狀況

sql語句清晰看到一條或多條語句是parse/execute/fetch在等問題

也能夠清晰語句具體的等待事件是什麼，瞭解是SQL層面的問題仍是軟件自己問題

瞭解create table,drop、exp內部的原理

sql 跟蹤有許多個級別

0：表示禁用

1：啓用標準的SQL_TRACE功能 ( 默認) 包含了 SQL語句、響應時間、服務時間、處理的行數，物理讀和寫的數目、執行計劃以及其餘一些額外信息。 到版本10.2中 執行計劃寫入到 trace 的條件是僅當相關遊標 已經關閉時， 且與之相關的執行統計信息是全部執行次數的總和數據。 到版本11.1中僅在每次遊標的第一次執行後將執行計劃寫入到trace ， 執行統計信息僅僅和這第一次執行相關

4：比level 1時多出 綁定變量的 trace

8 ：比level 1多出等待事件

16： 在11g中爲每一次執行生成STAT信息，僅在11.1以後可用

32： 比level 1少執行計劃，在11.1之後可用

64：和level 1 相比 在第一次執行後還可能生成執行計劃信息 ； 條件是某個遊標在前一次執行的前提下 運行耗時變長了一分鐘。僅在 11.2.0.2中可用

其餘補充

level 12（4+8）表明同事啓用level 四、level8

Level 28 (4 + 8 + 16) 表明 同時啓用 level 4 、level 八、level 16

level 68 ( 64 + 4 ) 表明 同時啓用 level 6四、level 4

最經常使用的跟蹤模式level 12

1.1 alter session

開啓跟蹤

alter session set sql_trace=true，至關level 1；

建議採用10046在指定如，啓用

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

關閉

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

整個數據庫啓用跟蹤，session級別調整system就能夠了。

1.2 DBMS_MONITOR

oracle 10g數據庫提供dbms_monitor包，你能夠啓用和禁用sql跟蹤。還有一些擴展的跟蹤屬性：

client identifier, service name, module name,  action name，沒有獨立會話，採用鏈接池的模式，就沒法指定具體的sessionid

使用dbms_MOINTOR包，你不能直接指定10046事件的級別，替換有三個參數能夠配置。默認級別是8

• level 4：對應 binds =true
• level 8：對應wait=true
• level 16：plan_stat=all_executions
• level 32: plan_stat=nerver
• level 64: 不支持

session level處理

能夠確認跟蹤哪一個會話的

本會話

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;

其餘會話

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

plan_stat：默認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)

客戶端級別

沒法經過單一的會話來處理，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，是區分大小寫的

能夠經過視圖來查看開啓的狀況

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')

組件級別

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)

數據庫級別

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包來處理，並且有限制只能是本身的會話

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權限，本身平常測試處理比較方便

本會話
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;

其餘會話
--能夠指定OS pid對應v$process.spid
ORADEBUG SETOSPID 1234;
--或者指定oracle processid 對應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 觸發器的模式啓用sql 跟蹤

針對個別用戶的所有會話都要開啓跟蹤，能夠新增一個角色，建立一個登陸的觸發器來處理

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 跟蹤文件中時間信息

cpu、實時時間記錄到跟蹤文件中，都需timed_statistics 設置爲true，默認是true。調整的方式

ALTER SESSION SET timed_statistics = TRUE

1.7 跟蹤文件限制大小

跟蹤文件的大小經過max_dump_file_size這個參數，默認值unlimited，若是是其餘值的話，建議調整爲默認值

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 跟蹤內容說明

打開跟蹤內容，相似如下的輸出，仍是不容易查看

PARSING IN CURSOR 到 END OF STMT是sql 文本的內容

PARSE,EXEC,FETCH,CLOSE分別對應是解析、執行、獲取、關閉調用

BINGS:對應的是綁定變量

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

STAT:表示執行計劃

瞭解詳細的細節，能夠參考：

3 TKPROF使用

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

使用方法:

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

參數詳細說明：

tracefile：跟蹤文件路徑

outputfile：輸出的文件路徑

explain=user/password 使用哪一個用戶連接數據庫，發出explain plan

table=schema.tablename 配合explain一塊兒使用

print=integer 是整數，只是羅列前多少個sql語句

aggregate=yes|no 相同的sql語句是否須要彙總

insert=filename 羅列SQL語句和數據包含在insert語句中

sys=no 不羅列以sys用戶運行的sql語句

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

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

sort=option 設置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

經常使用的轉換說明

直接轉換

tkprof kthis_ora_3335.trc kthis_ora_3335.log

增長執行計劃輸出

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

相同sql語句合併並不輸出sys用戶下的運行的表

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

只是輸出執行的sql語句

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

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

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

內容說明，如如下內容

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	解析該遊標並生成執行計劃的統計信息
execute	執行該遊標的統計信息
fetch	獲取數據行的統計信息
count	指該遊標的相關操做的次數 ，如parse count：1，該遊標被解析了1次
cpu	消耗cpu的時間，單位s
elapsed	實際消耗的時間，單位s
disk	消耗的物理讀
query	消耗一致性邏輯讀 consistenr logical read=》一個select 查詢，query通常沒有current
current	當前的邏輯讀，current logical read ，針對的是insert、update、delete
row	返回的行數
Misses in library cache during parse	在解析階段library cache發生了miss，則說明本次解析是硬解析
cr	一致性模式下的邏輯讀塊數量
pr	從磁盤物理讀的塊數量
pw	從磁盤物理寫的塊數量
time	操做中花費時間，採用微妙
cost	評估操做的代價，11.1版本後提供
Size	評估這個操做返回的數據量（字節）
card	評估這個操做返回的行數
times waited	等待事件發生的次數
max. wait	單次等待事件最大等待事件，秒爲單位
Total Waited	這個等待事件總的等待事件，秒爲單位

最後面還有彙總的信息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

用戶執行的語句和內部執行的語句的數量

   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使用

可使用命令行工具從一個或多個跟蹤文件中抽取一部分的信息，輸出的文件還須要經過tkprof來轉換查看，使用方式

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

output：輸出文件路徑

session：哪一個會話被跟蹤，session id爲（id,serial#）

clientid:客戶端被跟蹤

service：服務被跟蹤

module：模塊被跟蹤

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

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

5 客戶端從服務器端取文件

跟蹤文件在服務器上的，獲取存在不方便，咱們能夠事先經過建立一個函數來獲取

建立類型，經過管道表的功能讀取指定的跟蹤文件

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;
/

--能夠提供給其餘的用戶來執行
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;

測試執行

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