續上篇:http://blog.csdn.net/bisal/article/details/39225373
4. 10046事件
通過10046事件也可以檢視目标SQL的執行計劃。像10046這種事件,都不是Oracle官方文檔中可以查詢到的,這些事件一般用于調試目的,是以往往可以使用他們找到問題更詳細的資訊。
10046事件和之前的explain plan、DBMS_XPLAN包以及AUTOTRACE開關的差別在于,10046事件産生的trc檔案中明确顯示了目标SQL實際執行計劃中每一步所消耗的邏輯讀、實體讀和花費的時間,執行計劃的成本分析,進而可以看出為什麼Oracle對于SQL選擇了這樣的執行計劃,而不是那樣的執行計劃,之是以說是實際的執行計劃,從10046事件執行的過程就可以看出來:
(a) 在目前session激活10046事件。
(b) 在此session中執行SQL。
(c)
關閉此session的10046事件。
真正執行的SQL,對應的執行計劃可以在trc檔案中找到。這個trc檔案會記錄SQL的執行計劃和資源消耗,命名格式“執行個體名_ora_目前session的spid.trc”。
(1). 激活10046事件:
有兩種方法:
(a) alter session set events '10046
trace name context forever, level 12';
(b)
oradebug setmypid/oradebug setospid SPID;
oradebug
event 10046 trace name context forever, level 12;
(2).
檢視10046産生的trc檔案名和路徑的方法:
(a)
show parameter USER_DUMP_DEST顯示trc檔案存儲的路徑 -> 查找對應目前session的trc檔案(若目前是單使用者,則是最新産生的檔案)。
實驗:
(b) 使用上述(b)的ordebug産生trc檔案,可以用oradebug tracefile_name得到trc檔案名和路徑。
oradebug有很多需要說的,首先這是sqlplus特有的指令,在PLSQL Developer中執行會提示無效的SQL語句,例如:
其次它是sysdba角色的指令,使用非sysdba執行會提示ORA-01031權限不足,例如:
使用sysdba登入後,可以檢視oradebug的幫助:
盡管oradebug用的時候需要使用sysdba登入,看似有些麻煩,但和第一種alter
session的方法相比,最大的好處就是alter
session隻能針對目前會話或系統級,即alter session或alter system設定,如果設定非本會話的跟蹤,此時就可以用oradebug了,(據說dbms_system、dbms_monitor和dbms_support也可以實作相同的需求,但沒有試過)。
使用oradebug設定10046事件之前需要首先設定待跟蹤的會話:
(a) 跟蹤本會話,使用:oradebug
setmypid即可。
(b) 跟蹤非本會話,使用:oradebug
setospid SPID(來自v$process)。
查找SPID的方法:
select * from v$session a where audsid = userenv('sessionid');傳回SID值。
select s.USERNAME,
s.OSUSER,
s.SID,
s.PADDR,
s.PROCESS,
p.spid os_process_id,
p.pid oracle_process_id
from v$session s, v$process p
where s.paddr = p.addr
and s.username = upper('待跟蹤session使用者名')
and s.SID = (a)傳回的SID;
例如:
其中:
v$process中的SPID是指作業系統的程序,即作業系統的PID。
v$session中的pid, serial#是oracle配置設定的PID。
此時如果需要跟蹤24061這個session執行的SQL,可以用oradebug setospid 24061,然後oradebug
event 10046 trace name context forever, level 12;就打開了10046事件。
接着可以通過oradebug tracefile_name檢視trace檔案名和路徑,例如:
看下petest_ora_22756.trc的内容:
除了機器、執行個體、程序等基本資訊外,真正寫入的内容:
Received ORADEBUG command 'tracefile_name' from process Unix process pid: 22235, image:
表示接收到來自Unix的作業系統程序PID是22235的ORADEBUG指令,參數tracefile_name。
顯然22235這個程序是sqlplus登陸後執行ORADEBUG的用戶端,例如:
(3).
關閉10046的方法:
(a) alter session set events '10046 trace name context off';
(b) oradebug event
10046 trace name context off;
分别對應兩種打開10046事件的方法。
(4). 再說說oradebug和alter
session打開10046事件産生trace檔案的差別:
(a) 使用alter session打開10046事件時,如果未執行SQL,則不會産生trace檔案。
(b) 使用oradebug event 10046 trace name context forever, level 12;打開10046事件,此時就已經産生trace檔案,除基本資訊外,主要是一行:
WAIT #0: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1379395297285576
當使用oradebug event 10046 trace name context off;關閉10046事件,會寫入一行:
WAIT #0: nam='SQL*Net message from client' ela= 30946429 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1379395328232564
(5). trace跟蹤檔案:
上面說了打開和關閉10046的兩種常用方法,下面簡單看看trace檔案都包含了什麼,為什麼說10046這種事件是用于調試的,我現在不能精通所有内容,大概談談了解。
首先執行指令打開10046事件、執行SQL、關閉10046事件,例如:
檢視産生的trace檔案:
兩個"============"之前的内容,是執行SQL産生的資訊,之前和之後的内容,應該是打開和關閉10046事件的資訊。
紅線框内的是這條SQL用的執行計劃,從檔案中看,一共有5步,括号内的是相關消耗:
執行計劃第一步:MERGE JOIN,邏輯讀(cr)是11,實體讀(pr)是0,時間(time)是378微秒。
執行計劃第二步:TABLE ACCESS BY INDEX ROWID TEST1,邏輯讀(cr)是4,實體讀(pr)是0,時間(time)是139微秒。
執行計劃第三步:INDEX FULL SCAN SYS_C0016790,邏輯讀(cr)是2,實體讀(pr)是0,時間(time)是86微秒。
執行計劃第四步:SORT JOIN,邏輯讀(cr)是7,實體讀(pr)是0,時間(time)是266微秒。
執行計劃第五步:TABLE ACCESS FULL TEST2,邏輯讀(cr)是7,實體讀(pr)是0,時間(time)是128微秒。
這裡trc檔案是一種裸trace檔案,内容可看,但不是那麼直覺,可以使用tkprof指令翻譯trc檔案。例如:
檢視生成的tkprof檔案:
從這裡可以更清楚地看到每步執行計劃傳回的行數,以及順序關系,按照@dbsnake的執行計劃讀取口訣:
“先從最開頭一直連續往右看,直到看到最右邊的并列的地方;對于不并列的,靠右的先執行;如果見到并列的,就從上往下看,對于并列的部分,靠上的先執行”。簡單分析下:
INDEX
FULL ...
先使用SYS_C0016790主鍵索引進行索引快速全掃描,這裡SYS_C0016790是TEST1的主鍵,即t1id列。
TABLE ACCESS FULL
...
全表掃描TEST2表。
TABLE
ACCESS BY ...
根據TEST1主鍵索引傳回的ROWID,查詢對應資料項。産生結果集1。
(d)
SORT
JOIN
按照TEST2的t2id列排序。産生結果集2。
(e)
MERGE
周遊結果集1,即取出結果集1的第1條記錄,和結果集2中按照t1.t1id=t2.t2id的條件判斷是否存在比對記錄,再取出結果集1的第2條記錄繼續判斷,直到周遊完成結果集1。
這裡用到的是“排序合并連接配接”,執行計劃中對應的關鍵字是“MERGE
JOIN”和“SORT JOIN”,正常來講,兩個表第二步都應該是SORT JOIN,但這裡表TEST1卻是TABLE ACCESS BY INDEX ROWID TEST1,我想原因應該是:
對TEST2表的掃描使用的是INDEX FULL SCAN SYS_C0016790,即使用的索引快速全掃描,掃描t1id的主鍵索引資料塊。
索引都是有序的,是以INDEX
FULL SCAN SYS_C0016790的結果也是相當于排序的。
既然之前已經是排序的結果,那麼按照有序索引對應的ROWID,找到對應的記錄也是有序的,TABLE ACCESS BY INDEX ROWID TEST1,是以不用顯示SORT JOIN再次排序了。
未完待續。。。
To Be Continued ...