瞭解raw trace檔案的各項內容

來源:互聯網
上載者:User

今天瀏覽metalink,看到這篇Interpreting Raw SQL_TRACE,比較老的一篇文章了,但是確實很有用,所以決定大略翻譯一下吧。

我們知道有幾種方法可以得到一個SQL語句執行時背景trace檔案,一個是用SQL_TRACE,一個是用DBMS_SUPPORT包或者DBMS_SYSTEM包,還有一種就是直接使用10046 event。

使用10046 event的方法大致如下:

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

your sql statement...

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

其中的level有1,4,8,12幾個選項,其中1相當於設定SQL_TRACE=TRUE之後的結果,4包括1的結果和綁定變數的實際值,8包括1的結果和等待事件的情況,12則同時包含1的結果,綁定變數的實際值和等待事件情況,所以可以說level 12是最為詳細的trace了。

同時我們也知道,對於trace結果,oracle提供了tkprof公用程式用來格式化trace檔案,提供一份更容易讀懂的trace結果。

那麼為什麼還要直接讀取trace檔案呢?最重要的是tkprof的結果是不包含綁定變數值的,同時也不包括真正的SQL執行順序,而trace檔案中我們則可以看到按照時間排列的parse,binds,executes,fetch等等,這在某西場合下是很有用處的。還有就是,如果你能夠直接讀取這些讓人看得眼暈的trace,是不是會有一種很爽,很大師的感覺:-)

當然如果我們要根據一些標準(比如CPU時間長度,磁碟讀取量等)進行trace中的SQL排序,那麼tkprof是我們唯一的選擇,可以參看coolyl的Tkprof工具介紹和分析。

 

下面是metalink中的這篇文章的大體翻譯,大部分名詞用英文反而更好,就不強加翻譯了,相信大家都看得懂。當然也是比較懶的原因:-)

 

文本總結了trace結果原始輸出檔案中的內容。

 

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

APPNAME mod='%s' mh=%lu act='%s' ah=%lu

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

 

APPNAME:Application name setting。在Oracle 7.2和以上版本中出現。這個名稱可以由DBMS_APPLICATION_INFO包來設定。

mod:Module name

mh:Module hash value

act:Action

ah:Action hash value

 

比如:APPNAME mod='SQL*Plus' mh=3669949024 act='' ah=4029777240

 

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

PARSING IN CURSOR #<CURSOR> len=X dep=X uid=X oct=X lid=X tim=X hv=X ad='X'

<statement>

END OF STMT

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

 

<CURSOR>:Cursor number

len :Length of SQL statement,SQL語句的長度

dep :Recursive depth of the cursor,當前SQL語句的遞規深度,如果為0則表示是使用者提交的SQL,為1則是由於使用者SQL而導致Oracle後台自己執行的SQL,為2則是由1級SQL繼續誘發的下一級SQL。

uid :Schema user id of parsing user

oct :Oracle command type.

lid :Privilege user id.

tim :Timestamp。在Oracle9i之前單位是1/100秒,9i則是1/1,000,000秒。利用這個值可以計算一個SQL執行了到底多長時間。這個值就是當前行被寫入trace檔案時資料庫V$TIMER視圖的值。

hv :Hash id.

ad :SQLTEXT address,SQLTEXT的地址,跟V$SQLAREA和V$SQLTEXT視圖中的ADDRESS欄位值相等。

<statement> :The actual SQL statement being parsed.

 

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

PARSE ERROR #%d:len=%ld dep=%d uid=%ld oct=%d lid=%ld tim=%lu err=%d

<statement> ...

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

 

PARSE ERROR :在Oracle 7.2以上版本中解析的錯誤會寫入trace檔案中。

len :Length of SQL statement.

dep :Recursive depth of the statement

uid :User id.

oct :Oracle command type (if known).

lid :Privilege user id.

tim :Timestamp.

err :Oracle error code (e.g. ORA-XXXXX) reported

<statement> :The SQL statement that errored.

 

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

PARSE #<CURSOR>:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=0

EXEC #<CURSOR>:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=0

FETCH #<CURSOR>:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=0

UNMAP #<CURSOR>:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=0

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

 

PARSE :Parse a statement. 解析一個SQL

EXEC :Execute a pre-parsed statement. 執行已經解析完畢的SQL

FETCH :Fetch rows from a cursor. 從遊標中得到資料,通常指select返回記錄

UNMAP :如果遊標使用了暫存資料表(temporary table), 當遊標關閉的時候將會看到UNMAP

c :CPU time (100th's of a second in Oracle7 ,8 and 9).

e :Elapsed time (100th's of a second Oracle7, 8. Microseconds in Oracle 9 onwards).

p :Number of physical reads.

cr :Number of buffers retrieved for CR reads.

cu :Number of buffers retrieved in current mode.

mis :Cursor missed in the cache.

r :Number of rows processed.

dep :Recursive call depth (0 = user SQL, >0 = recursive).

og :Optimizer goal: 1=All_Rows, 2=First_Rows, 3=Rule, 4=Choose

tim :Timestamp (large number in 100ths of a second).

 

比如:FETCH #2:c=0,e=106,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=4,tim=6005498548671

 

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

ERROR #%d:err=%d tim=%lu

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

 

執行或者fetch之後出現的SQL Error

err :Oracle error code (e.g. ORA-XXXXX) at the top of the stack.

tim :Timestamp.

 

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

STAT #<CURSOR> id=N cnt=0 [pid=0 pos=0 obj=0 op='SORT AGGREGATE ']

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

 

<CURSOR>的執行計畫.

<CURSOR> :Cursor which the statistics apply to.

id :Line of the explain plan which the row count applies to (從1開始).

cnt :Number of rows for this row source.

pid :Parent id of this row source.

pos :Position in explain plan.

obj :Object id of row source (if this is a base object).

op : The row source access operation.

 

比如:

STAT #2 id=2 cnt=0 pid=1 pos=1 obj=510 op='TABLE ACCESS BY INDEX ROWID OBJECT_USAGE (cr=2 r=0 w=0 time=83 us)'

STAT #2 id=3 cnt=1 pid=2 pos=1 obj=511 op='INDEX RANGE SCAN I_STATS_OBJ# (cr=1 r=0 w=0 time=43 us)'

 

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

XCTEND rlbk=%d rd_only=%d

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

 

XCTEND是事務結束的標誌.

rlbk :1 if a rollback was performed, 0 if no rollback (commit).

rd_only :1 if transaction was read only, 0 if changes occurred.

 

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

BINDS #%d:

bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=03 oacfl2=0 size=24 offset=0

bfp=02fedb44 bln=22 avl=00 flg=05

value=10

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

 

BIND :Variables bound to a cursor.

bind N :The bind position being bound.

dty :Data type.

mxl :Maximum length of the bind variable (private max len in paren).

mal :Array length.

scl :Scale.

pre :Precision.

oacflg :Special flag indicating bind options

oacflg2 :Continuation of oacflg

size :Amount of memory to be allocated for this chunk

offset :Offset into this chunk for this bind buffer

bfp :Bind address.

bln :Bind buffer length.

avl :Actual value length (array length too).

flg :Special flag indicating bind status

value :The actual value of the bind variable.

 

比如:

BINDS #4:

 bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24 offset=0

   bfp=ffffffff7ce64ee0 bln=22 avl=01 flg=05

   value=0

 bind 1: dty=1 mxl=32(11) mal=00 scl=00 pre=00 oacflg=18 oacfl2=1 size=32 offset=0

   bfp=ffffffff7ce6b128 bln=32 avl=11 flg=05

   value="TABCOMPART$"

 bind 2: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24 offset=0

   bfp=ffffffff7ce6bae8 bln=24 avl=02 flg=05

   value=1

 

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

WAIT #<CURSOR>: nam="<event name>" ela=0 p1=0 p2=0 p3=0

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

 

WAIT :An event that we waited for.

nam :What was being waited for.

ela :Elapsed time for the operation.

p1 :P1 for the given wait event.

p2 :P2 for the given wait event.

p3 :P3 for the given wait event.

 

比如 (Full Table Scan):

WAIT #1: nam="db file scattered read" ela= 5 p1=4 p2=1435 p3=25

在遊標1上經曆了"db file scattered read"等待事件,一共等了0.05秒,在讀取File 4,從1435 block開始,讀了25個block

 

比如 (Index Scan):

WAIT #1: nam="db file sequential read" ela= 4 p1=4 p2=1224 p3=1

在遊標1上經曆了"db file sequential read"等待事件,一共等了0.04秒,在讀取file 4,block 1224,讀取了這一個block

 

對於每一個等待事件的含義和p1,p2,p3表示的意思,可以參考Oracle Database Reference文檔的Oracle Wait Events章節。

 


相關文章

Beyond APAC's No.1 Cloud

19.6% IaaS Market Share in Asia Pacific - Gartner IT Service report, 2018

Learn more >

Apsara Conference 2019

The Rise of Data Intelligence, September 25th - 27th, Hangzhou, China

Learn more >

Alibaba Cloud Free Trial

Learn and experience the power of Alibaba Cloud with a free trial worth $300-1200 USD

Learn more >

聯繫我們

該頁面正文內容均來源於網絡整理,並不代表阿里雲官方的觀點,該頁面所提到的產品和服務也與阿里云無關,如果該頁面內容對您造成了困擾,歡迎寫郵件給我們,收到郵件我們將在5個工作日內處理。

如果您發現本社區中有涉嫌抄襲的內容,歡迎發送郵件至: info-contact@alibabacloud.com 進行舉報並提供相關證據,工作人員會在 5 個工作天內聯絡您,一經查實,本站將立刻刪除涉嫌侵權內容。