Oracle 10046 event詳解-轉載

標籤：

0046事件概述
Oracle的10046事件，可以跟蹤應用程式所執行的SQL語句，並且得到其解析次數.執行次數,CPU使用時間等資訊。這對我們分析、定位元據庫效能問題是非常有用的。

10046 event是oracle用於系統效能分析時的一個最重要的事件。當啟用這個事件後，將通知oracle kernel追蹤會話的相關即時資訊，並寫入到相應trace檔案中。這些有用的資訊主要包括sql是如何進行解析，綁定變數的使用方式，會話中發生的等待事件等

10046 event 可分成不同的層級（level），分別追蹤記錄不同程度的有用資訊。對於這些不同的層級，應當注意的是向下相容的，即高一級的trace資訊包含低於此級的所有資訊。

10046event的追蹤層級大致有：

level 1：跟蹤sql語句，包括解析、執行、提取、提交和復原等。

level 4：包括變數的詳細資料

level 8：包括等待事件

level 12：包括綁定變數與等待事件

其中，level 1相當於開啟了sql_trace

前提條件：
（先確保要event的會話環境符合條件）

1、必須確保timed_statistics為TRUE，這個參數可以在會話級上進行修改。關於參數timed_statistics的一段解釋
Without timed statistics, Oracle records the reason for each wait before it begins to wait, and when the wait is over, it records whether it timed out. But with timed statistics enabled, Oracle checks the time just before and after each wait, and also records the time waited. The time waited is recorded in hundredths of a second— that is, centiseconds. 
true
The statistics are collected and stored in trace files or displayed in the V$SESSTATS and V$SYSSTATS dynamic performance views.

false

The value of all time-related statistics is set to zero. This setting lets Oracle avoid the overhead of requesting the time from the operating system.

Starting with release 11.1.0.7.0, the value of the TIMED_STATISTICS parameter cannot be set to false if the value of STATISTICS_LEVEL is set to TYPICAL or ALL.

本人的理解是:參數timed_statistics設定為true的話.Oracle記錄等待事件的wait reason和等待事件開始和結束的時間點，以及該等待是否逾時。timed_statistics=false後，Oracle只記錄了等待事件和等待事件是否逾時的資訊。
在timed_statistics  = false時,我們只能夠知道這些等待時間的次數(records the reason for each wait ), 以及等待時間timed out的次數(records whether it timed out) 
在timed_statistics = true時,我們可以知道系統在某個具體的等待事件上等待的時間(records the time waited),這樣我們就可以判斷具體是什麼原因導致我們的系統變慢或者追蹤資料庫進行的操作，有了這些時間資訊可以確定等待事件在哪個時間段出現比較頻繁。時間的統計資訊會被更新到V$SESSTATS和V$SYSSTATS視圖中。11.1.0.7以後如果STATISTICS_LEVEL被設定為typical或者all，則不能將timed_statistics設定為false

2、為了確保trace輸出能夠完整進行，還要調整此會話對trace檔案大小的限制，一般將此限制取消，即將max_dump_file_size設定為UNLIMITED，或者設定為一個很大的闕值。

在滿足了上述條件後，就可以啟用10046 event對會話進行後台跟蹤了。 
使用10046事件

1、首先獲得spid、sid、serial#，machine為串連oracle的機器名
select b.spid,a.sid,a.serial#,a.machine from v$session a,v$process b where a.paddr =b.addr  and a.sid = ‘159‘

繼續往下看，就可以知道為什麼找到SPID了；

2、trace的開啟和關閉
使用sql_trace
SQL> alter system set sql_trace=true;   --開啟系統層級的sql_trace
SQL> alter session set sql_trace=true;   --開啟會話層級的sql_trace
SQL> execute dbms_system.set_sql_trace_in_session(267,996,true);  
PL/SQL 過程已成功完成。         -- 啟動其他會話的SQL_TRACE
SQL> alter system set sql_trace=false;  --關閉系統層級的sql_trace
SQL> alter session set sql_trace=false;  --關閉會話層級的sql_trace

SQL> execute dbms_system.set_sql_trace_in_session(267,996,false); 
PL/SQL 過程已成功完成。      -- 關閉其他會話的SQL_TRACE

使用10046 事件跟蹤

SQL> alter session set events ‘10046 trace name context forever ,level 12‘ ;    會話已更改。 --開啟本會話的10046事件

SQL> exec dbms_monitor.session_trace_enable(267,996,waits=>true,binds=>true);      
PL/SQL 過程已成功完成。       -- 開啟其他會話的10046事件

SQL> alter session set events ‘10046 trace name context off‘ ;

會話已更改。 --關閉本會話的10046事件

SQL> exec dbms_monitor.session_trace_disable(267,996); 
PL/SQL 過程已成功完成。            -- 關閉其他會話的10046事件

參數說明：
15:SID
196:SERIAL#

注意這裡必須以sysdba登入。

3、獲得產生的追蹤檔案所在的目錄
SQL> select value from v$parameter where name = ‘user_dump_dest‘;

轉到該目錄下可以看到產生了一個zftang_ora_596.trc檔案，此處的596即SPID的值。

4、使用tkprof命令，轉換TRC檔案
在命令列下執行oracle的tkprof命令，將zftang_ora_596.trc轉化為文字檔

如：
$ tkprof  ora9i_ora_24722.trc ora9i_ora_24722.sql

此時在zftang_ora_596.sql檔案中，就可以看到剛才執行應用程式時所執行的sql語句的執行次數、CPU使用時間等資料。

TRACE將消耗相當的系統資源，因此我們在使用TRACE的時候應當謹慎。對於正式的系統，應當只在必要的時候進行TRACE操作，並且應當及時關閉。

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

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

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

update test_01 set flag1 = ‘測試‘

call     count       cpu    elapsed       disk      query    current        rows

------- ------  -------- ---------- ---------- ---------- ----------  ----------

Parse        1      0.00       0.01          0          2          0           0

Execute      1      2.35       2.64        358       1865     220043       50782

Fetch        0      0.00       0.00          0          0          0           0

------- ------  -------- ---------- ---------- ---------- ----------  ----------

total        2      2.35       2.65        358       1867     220043       50782

Misses in library cache during parse: 1

Optimizer mode: ALL_ROWS

Parsing user id: 63       

如何使用tkprof
http://czmmiao.iteye.com/blog/1493765
查看原始trace檔案
http://czmmiao.iteye.com/blog/1493933
關於alter system event 
http://czmmiao.iteye.com/blog/1330430 
注意：如果一條SQL語句中包含了通過DBLINK進行的資料操作，我們想對這條SQL進行trace跟蹤，在本地只能夠trace到本地執行的SQL資訊，而對於遠端SQL語句，由於它運行在遠端的資料庫上，我們要獲得它的資訊，需要到遠端的資料庫上，找到運行這條SQL語句的session，然後對它做Trace。 另外，這條SQL語句的執行計畫也只能從遠端資料庫上捕獲到。
 

參考至:《讓Oracle跑得更快》譚懷遠著
            http://www.linuxidc.com/Linux/2011-04/35132p2.htm                   
            http://docs.oracle.com/cd/E11882_01/server.112/e25513/initparams255.htm#REFRN10218
本文原創，轉載請註明出處、作者 

http://czmmiao.iteye.com/blog/1497509

Oracle 10046 event詳解-轉載