如何直接閱讀Oracle中的trace檔案(原創)

大部分情況下，我們可以利用tkprof工具格式化trace檔案，讓trace檔案便于閱讀，但trkprof産生的是trace檔案的彙總結果，如果需要知道sql每一步确切執行了什麼，我們也隻能直接閱讀trace

==============================================
 APPNAME mod='%s' mh=%lu act='%s' ah=%lu    ============================================== 
 APPNAME：Application name setting。在Oracle 7.2和以上版本中出現。這個名稱可以由DBMS_APPLICATION_INFO包來設定。 
 mod：子產品名
 mh：子產品的散列值
 act：動作，如DBMS_APPLICATION_INFO
 ah：動作的散列值
 示例 
 APPNAME mod='SQL*Plus' mh=3669949024 act='' ah=4029777240 
===============================================
PARSING IN 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,目前模式的使用者id和lid不同。我們知道當使用alter session set current_schema=NEWUSER指令後，使用者OLDUSER在執行需要NEWUSER的相關權限時才會切換為NEWUSER，則這時代UID即為OLDUSER，lib為NEWUSER
 oct ：Oracle command type. oracle的指令類型
 lid ：Privilege user id. 核對通路權限的id
 tim ：Timestamp。在Oracle9i之前機關是1%秒，9i之後則是1/1,000,000秒。利用這個值可以計算一個SQL執行了到底多長時間。這個值就是目前行被寫入trace檔案時資料庫V$TIMER視圖的值。 
 hv ：Hash id. sql的散列id
 ad ：SQLTEXT address，SQLTEXT的位址，跟V$SQLAREA和V$SQLTEXT視圖中的ADDRESS字段值相等。 
 statement ：The actual SQL statement being parsed.實際的sql語句示例 
 PARSING IN CURSOR #2 len=60 dep=0 uid=55 oct=6 lid=55 tim=1303778511213906 hv=478751424 ad='2ce279a4'
 update employees set salary=1.1*salary where employee_id=100
 END OF STMT  ======================================================
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，CPU時間 (100th's of a second Oracle7, 8. Microseconds in Oracle 9 onwards).
 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 Consistent reads，consistent模式下的讀次數，個人認為可以了解為query模式下的讀次數
 cu：Number of buffers retrieved in current mode，current模式下的讀次數
 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 
 ====================================================== 
 當執行或者取資料發生錯誤 
 err ：Oracle error code (e.g. ORA-XXXXX) at the top of the stack，Oracle 錯誤代碼(e.g. ORA-XXXXX) 
 tim ：Timestamp，時間戳
 示例
 ERROR #2:err=1013 tim=431155915  ======================================================
STAT # 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. 執行計劃中，這一步的父ID
 pos ：Position in explain plan，執行計劃的位置
 obj ：Object id of row source (if this is a base object)，引用對象的對象ID
 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)，1表示復原，0表示送出
 rd_only：1 if transaction was read only, 0 if changes occurred，隻讀标記，1表示事務是隻讀的，0表示可以進行修改，送出或傳回
 示例
 XCTEND rlbk=0, rd_only=0  ======================================================
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，綁定遊标的位置，從0開始，0是第一個遊标
 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，緩沖區的chunk大小
 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，綁定變量的實際值，有可能是16進制轉儲
 示例 
 BINDS #2:
 kkscoacd
  Bind#0
   oacdty=11 mxl=16(16) mxlc=00 mal=00 scl=00 pre=00
   oacflg=18 fl2=0001 frm=00 csi=00 siz=16 off=0
   kxsbbbfp=b7f1b944  bln=16  avl=16  flg=05
   value=0000E899.0018.0001  ======================================================
WAIT #[CURSOR]: nam="event name" ela=0 p1=0 p2=0 p3=0  ====================================================== 
 #CURSOR:遊标号
 WAIT ：An event that we waited for，表示正在進行等待某個事件
 nam ：What was being waited for，等待事件名稱
 ela ：Elapsed time for the operation，等待事件所花的時間，以0.01秒為機關
 p1 ：P1 for the given wait event，P1,P2,P3可查閱references文檔
 p2 ：P2 for the given wait event. 
 p3 ：P3 for the given wait event.