透過10046事件跟蹤分析執行計劃，便於效能最佳化。其中sql_trace有分三個不同方式的跟蹤。

1、全域性模式的10046:這種跟蹤需要在引數檔案設定10046引數；

event="10046 trace name context forever,level 12"

2、會話模式的10046:這隻能個跟蹤DBA角色使用者開啟的會話；

開啟與關閉跟蹤(12為最高階別的)：

alter session set events '10046 trace name context forever, level 12';

alter session set events '10046 trace name context off';

3、針對某個使用者模式的10046:這個透過呼叫包dbms_system.set_ev：

來跟蹤，需要設定包的相關引數，就可以針對某個使用者開啟的會話進行收集會話詳細的操作過程。

啟用：Exec dbms_system.set_ev(41,829,10046,12,'');

關閉：Exec dbms_system.set_ev(41,829,10046,0,'');

#.set_ev裡面5個引數檢視：
PROCEDURE SET_EV
Argument Name Type In/Out Default?
------------------------------ ----------------------- ------ --------
SI BINARY_INTEGER IN
SE BINARY_INTEGER IN
EV BINARY_INTEGER IN
LE BINARY_INTEGER IN
NM VARCHAR2 IN

Si為sid,se為seria#,ev為event，此處是10046事件，LE為level,NM為username（使用者名稱）。

#以上的引數說明都比較詳細，相信大家都看得懂。但是，上面的5個引數中，有一個引數username，
最容易誤導。說實話，自己開始使用的時候，也犯了這個錯誤，被套進了這個陷阱，而且不容易發現所犯的錯誤。
開始參考的例子是這樣的：
#開啟跟蹤：Exec dbms_system.set_ev(26,35,10046,12,’HR’);
#等去檢視它出發生成“最新的trace檔案”的時候，並沒有生成新的trace檔案。
#這時候，我們聯想SQL_TRACE觸發生成新trace檔案的方法：
exec dbms_system.SET_SQL_TRACE_IN_SESSION(26,35,true);
exec dbms_system.SET_SQL_TRACE_IN_SESSION(26,35,false);
即有開啟則有關閉才會觸發生成新的trace檔案。可現在對於跟蹤針對某個使用者的會話的10046事件沒有
完整的觸發機制，沒有start/stop,也沒有begin/end，更沒有TRUE/FALSE等引數值。那該怎麼辦呢？

#透過檢視先前探索者們的資料敘述，大家都開始針對NM這個引數下手。我就嘗試了三種NM的可能引數值：
1、NM=SUXING --當前會話的資料庫使用者名稱
2、NM=null --空值
3、NM='' --空值（與2、中的空值表示法不一樣）
#最後發現，1、2兩種的引數值都不能使10046事件觸發生成新的trace檔案，只有3方法觸發生成了新的trace檔案。這樣才得以讓我的測試順利完成。

以下是我的測試過程：

----10046事件跟蹤檔案：

---檢視會話的SID：

sys@PROD>select sid,serial#,username from v$session

2 where username in ('SUXING','SUSU');

SID SERIAL# USERNAME

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

41 829 SUXING

44 417 SUSU

---最先方法呼叫跟蹤包：

sys@PROD>Exec dbms_system.set_ev(41,829,10046,12,'SUXING');

PL/SQL procedure successfully completed.

#後面發現該呼叫不能觸發生成新的trace檔案。

---最新的呼叫方法：

---開啟跟蹤：

sys@PROD>Exec dbms_system.set_ev(41,829,10046,12,'');

PL/SQL procedure successfully completed.

---使用者會話的系列操作：

suxing@PROD>delete from yourtest where id =127;

5 rows deleted.

suxing@PROD>insert into yourtest values

2 (127,'haha',sysdate,'man');

1 row created.

suxing@PROD>commit;

Commit complete.

suxing@PROD>select * from yourtest;

ID NAME CREATED SEX

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

125 susu 02-NOV-16 man

123 yyyy 02-NOV-16 man

124 hhhh 10-NOV-16 man

126 wwww 10-NOV-16 man

125 dddd 11-NOV-16 woman

123 yyyy 24-NOV-16 man

127 haha 06-DEC-16 man

7 rows selected.

#總共1條刪除，1條插入，1條查詢操作。

---禁用（關閉）跟蹤：

sys@PROD>Exec dbms_system.set_ev(41,829,10046,0,'');

PL/SQL procedure successfully completed.

---檢視最新生成的trace檔案：

[oracle@enmo trace]$ ls -lrt

... ...

-rw-r--r-- 1 oracle oinstall 6801 Dec 6 17:59 my15504.sql

-rw-r----- 1 oracle oinstall 1376 Dec 6 18:24 PROD_mmon_4603.trm

-rw-r----- 1 oracle oinstall 13945 Dec 6 18:24 PROD_mmon_4603.trc

-rw-r----- 1 oracle oinstall 498 Dec 6 18:25 PROD_ora_15504.trm

-rw-r----- 1 oracle oinstall 81204 Dec 6 18:25 PROD_ora_15504.trc

---轉換trace檔案容易讀取的檔案格式：

[oracle@enmo trace]$ tkprof PROD_ora_15504.trc my10046_15504_20161206.sql

TKPROF: Release 11.2.0.4.0 - Development on Tue Dec 6 18:29:02 2016

---讀取新生成trace檔案的內容：

[oracle@enmo trace]$ ls my10046_15504_20161206.sql

my10046_15504_20161206.sql

[oracle@enmo trace]$

[oracle@enmo trace]$ cat my10046_15504_20161206.sql

... ...

SQL ID: ftj9uawt4wwzb Plan Hash: 1884964958

select condition

from

cdef$ where rowid=:1

call count cpu elapsed disk query current rows

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

Parse 4 0.00 0.00 0 0 0 0

Execute 4 0.00 0.00 0 0 0 0

Fetch 4 0.00 0.00 0 8 0 4

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

total 12 0.00 0.00 0 8 0 4

Misses in library cache during parse: 2

Misses in library cache during execute: 2

Optimizer mode: CHOOSE

Parsing user id: SYS (recursive depth: 1)

Number of plan statistics captured: 3

Rows (1st) Rows (avg) Rows (max) Row Source Operation

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

1 1 1 TABLE ACCESS BY USER ROWID CDEF$ (cr=1 pr=0 pw=0 time=8 us cost=1 size=15 card=1)

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

SQL ID: c75j1y27gdy77 Plan Hash: 1899096591

delete from yourtest

where

id =127

call count cpu elapsed disk query current rows

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

Parse 1 0.00 0.00 0 262 0 0

Execute 1 0.00 0.00 0 8 13 5

Fetch 0 0.00 0.00 0 0 0 0

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

total 2 0.00 0.00 0 270 13 5

Misses in library cache during parse: 1

Optimizer mode: ALL_ROWS

Parsing user id: 90

Number of plan statistics captured: 1

Rows (1st) Rows (avg) Rows (max) Row Source Operation

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

0 0 0 DELETE YOURTEST (cr=8 pr=0 pw=0 time=413 us)

5 5 5 TABLE ACCESS FULL YOURTEST (cr=6 pr=0 pw=0 time=105 us cost=4 size=9 card=1)

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

SQL*Net message from client 1 16.19 16.19

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

SQL ID: 23wm3kz7rps5y Plan Hash: 0

commit

call count cpu elapsed disk query current rows

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

Parse 2 0.00 0.00 0 0 0 0

Execute 2 0.00 0.00 0 0 2 0

Fetch 0 0.00 0.00 0 0 0 0

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

total 4 0.00 0.00 0 0 2 0

Misses in library cache during parse: 0

Parsing user id: 90

Elapsed times include waiting on following events:

Event waited on Times Max. Wait Total Waited

---------------------------------------- Waited ---------- ------------

log file sync 1 0.00 0.00

SQL*Net message to client 1 0.00 0.00

SQL*Net message from client 1 6.11 6.11

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

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows

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

Parse 7 0.00 0.00 0 264 0 0

Execute 7 0.00 0.00 0 14 35 7

Fetch 4 0.00 0.00 0 14 0 18

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

total 18 0.00 0.00 0 292 35 25

Misses in library cache during parse: 5

Elapsed times include waiting on following events:

Event waited on Times Max. Wait Total Waited

---------------------------------------- Waited ---------- ------------

SQL*Net message to client 5 0.00 0.00

SQL*Net message from client 4 16.19 25.26

log file sync 1 0.00 0.00

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

call count cpu elapsed disk query current rows

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

Parse 15 0.00 0.00 0 0 0 0

Execute 89 0.02 0.02 0 0 0 0

Fetch 97 0.00 0.00 0 266 0 719

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

total 201 0.03 0.03 0 266 0 719

Misses in library cache during parse: 12

Misses in library cache during execute: 12

7 user SQL statements in session.

14 internal SQL statements in session.

21 SQL statements in session.

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

Trace file: PROD_ora_15504.trc

Trace file compatibility: 11.1.0.7

Sort options: default

1 session in tracefile.

7 user SQL statements in trace file.

14 internal SQL statements in trace file.

21 SQL statements in trace file.

16 unique SQL statements in trace file.

1613 lines in trace file.

1661 elapsed seconds in trace file.

[oracle@enmo trace]$

#該博文篇幅較長，但是總體條理還比較清晰，謝謝您的查閱！

2016/12/06 nanning

使用10046事件跟蹤分析執行計劃

相關文章