使用10046事件查看Oracle執行計畫

使用10046事件查看Oracle執行計畫

使用10046事件查看Oracle資料庫中的執行計畫，能夠得到SQL執行計畫中每一個執行步驟所消耗的邏輯讀，物理讀，和花費的時間。這種細粒度的明細顯示在我們診斷複雜SQL的效能問題時尤為重要，而且這也是explain plan命令，autotrace命令所不能提供的。不過實際上，我們還可以通過gather_plan_sstatistics Hint 配合dbms_xplan 包一起使用得到和10046事件類別似細粒度的明細的執行計畫。

我們只需3個步驟就可以容易的通過10046事件獲得SQL的執行計畫。

1.首先在當前session 中啟用10046事件。
2.在當前session 中執行SQL語句。
3.最後當前session 中關閉10046事件。
 當執行完上述步驟後，oracle就會將目標SQL的執行計畫和明細資源消耗寫入此session對應的trace檔案中。
oracle會在user_dump_dest參數設定的目錄下產生這個trace檔案。
 我們有兩種方法在當前session中啟用10046事件。
1.在當前session中執行alter session set events '10046 trace naem context forever,level 12'
 2.在當前session中執行oradebug event 10046 trace name context forever,level 12'
上述命令中的關鍵字”level“後的數字是標識設定的10046時間的level值，這個值是可以修改的，我們
 通常使用的值為12，表示在產生的trace檔案中除了有目標sql的執行計畫和資源消耗明細外，還包含
SQL使用的綁定變數的值以及該session所經曆的等待事件，除了level值外，其他的部分是固定的文法，
 是無法修改的。
 我推薦使用第2種方法，因為可以在啟用10046事件後執行命令oradebug tracefile_name可以獲得當前
session 所對應的trace檔案的具體路徑名稱。
 我們可以在當前session中關閉10046事件的兩種方法：
1.在當前session中執行alter session set events '10046 trace name context off'
 2.在當前session中執行oradebug event 10046 trace naem context off

我們使用一個例子來說明下

1.我們先啟用10046事件，我們是oradebug命令來啟用。
SQL>oradebug setmypid
 SQL>oradebug event 10046 trace name context forver,level 12
 2.在當前session中啟用了10046事件後，我們執行一個SQL語句
SQL>SELECT * FROM hr.test;
 3.使用oradebug tracefile_name 命令查看當前session所對應的trace檔案路徑和名稱
SQL>oradebug tracefile_name
 /app/oracle/diag/rdbms/pxboracle/pxboracle/trace/pxboracle_ora_18565.trc
 4.關閉當前session 中的10046事件：
SQL>oradebug event 10046 trace name context off

下面的內容就是trace檔案中的內容

=====================
PARSING IN CURSOR #47006443926880 len=27 dep=0 uid=0 oct=3 lid=0 tim=2879240721898379 hv=2413634929 ad='9e709620' sqlid='4wn49u27xu9bj'
 select * from hr.test
 END OF STMT
 PARSE #47006443926880:c=378943,e=2562085,p=13,cr=721,cu=0,mis=1,r=0,dep=0,og=1,plh=121040406,tim=2879240721898378
 EXEC #47006443926880:c=0,e=81,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=121040406,tim=2879240721898787
 WAIT #47006443926880: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=2879240721898965
 WAIT #47006443926880: nam='Disk file operations I/O' ela= 175 FileOperation=2 fileno=5 filetype=2 obj#=18841 tim=2879240721899603
 WAIT #47006443926880: nam='db file sequential read' ela= 15398 file#=5 block#=138826 blocks=1 obj#=18841 tim=2879240721915091
 WAIT #47006443926880: nam='db file sequential read' ela= 10745 file#=5 block#=138827 blocks=1 obj#=18841 tim=2879240721935221
 FETCH #47006443926880:c=1000,e=36278,p=2,cr=2,cu=0,mis=0,r=1,dep=0,og=1,plh=121040406,tim=2879240721935413
 WAIT #47006443926880: nam='SQL*Net message from client' ela= 6148 driver id=1650815232 #bytes=1 p3=0 obj#=18841 tim=2879240721941743
 WAIT #47006443926880: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=18841 tim=2879240721941899
 FETCH #47006443926880:c=999,e=178,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=1,plh=121040406,tim=2879240721942058
 WAIT #47006443926880: nam='SQL*Net message from client' ela= 407527 driver id=1650815232 #bytes=1 p3=0 obj#=18841 tim=2879240722349676
 WAIT #47006443926880: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=18841 tim=2879240722349821
 FETCH #47006443926880:c=1000,e=201,p=0,cr=1,cu=0,mis=0,r=7,dep=0,og=1,plh=121040406,tim=2879240722350005
 STAT #47006443926880 id=1 cnt=23 pid=0 pos=1 obj=18841 op='TABLE ACCESS FULL LBBNF (cr=4 pr=2 pw=0 time=36197 us cost=3 size=3036 card=23)'
 WAIT #47006443926880: nam='SQL*Net message from client' ela= 21195539 driver id=1650815232 #bytes=1 p3=0 obj#=18841 tim=2879240743545997
 CLOSE #47006443926880:c=0,e=14,dep=0,type=0,tim=2879240743546441

*** 2061-03-28 21:05:43.546
 Processing Oradebug command 'tracefile_name'

*** 2061-03-28 21:05:43.546
 Oradebug command 'tracefile_name' console output:
 /app/oracle/diag/rdbms/pxboracle/pxboracle/trace/pxboracle_ora_18565.trc
 WAIT #0: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=18841 tim=2879240743547147
 WAIT #0: nam='SQL*Net message from client' ela= 18525364 driver id=1650815232 #bytes=1 p3=0 obj#=18841 tim=2879240762072687

*** 2061-03-28 21:06:02.072
 Processing Oradebug command 'event 10046 trace name context off'

*** 2061-03-28 21:06:02.073
 Oradebug command 'event 10046 trace name context off' console output: <none>