今天浏览 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';
1<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 #
1<cursor> len=X dep=X uid=X oct=X lid=X tim=X hv=X ad='X' **
2
3<statement>
4
5** END OF STMT **
6
7\----------------------------------------------------------------------------
8
9<cursor> ： Cursor number
10
11len ： Length of SQL statement ， SQL 语句的长度
12
13dep ： Recursive depth of the cursor ，当前 SQL 语句的递规深度，如果为 0 则表示是用户提交的 SQL ，为 1 则是由于用户 SQL 而导致 Oracle 后台自己执行的 SQL ，为 2 则是由 1 级 SQL 继续诱发的下一级 SQL 。
14
15uid ： Schema user id of parsing user
16
17oct ： Oracle command type.
18
19lid ： Privilege user id.
20
21tim ： Timestamp 。在 Oracle9i 之前单位是 1/100 秒， 9i 则是 1/1,000,000 秒。利用这个值可以计算一个 SQL 执行了到底多长时间。这个值就是当前行被写入 trace 文件时数据库 V$TIMER 视图的值。
22
23hv ： Hash id.
24
25ad ： SQLTEXT address ， SQLTEXT 的地址，跟 V$SQLAREA 和 V$SQLTEXT 视图中的 ADDRESS 字段值相等。
26
27<statement> ： The actual SQL statement being parsed.
28
29\----------------------------------------------------------------------------
30
31** PARSE ERROR #%d:len=%ld dep=%d uid=%ld oct=%d lid=%ld tim=%lu err=%d **
32
33<statement> ...
34
35\----------------------------------------------------------------------------
36
37PARSE ERROR ：在 Oracle 7.2 以上版本中解析的错误会写入 trace 文件中。
38
39len ： Length of SQL statement.
40
41dep ： Recursive depth of the statement
42
43uid ： User id.
44
45oct ： Oracle command type (if known).
46
47lid ： Privilege user id.
48
49tim ： Timestamp.
50
51err ： Oracle error code (e.g. ORA-XXXXX) reported
52
53<statement> ： The SQL statement that errored.
54
55\----------------------------------------------------------------------------
56
57** PARSE #<cursor>:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=0 **
58
59** EXEC #<cursor>:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=0 **
60
61** FETCH #<cursor>:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=0 **
62
63** UNMAP #<cursor>:c=0,e=0,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=4,tim=0 **
64
65\----------------------------------------------------------------------------
66
67PARSE ： Parse a statement. 解析一个 SQL
68
69EXEC ： Execute a pre-parsed statement. 执行已经解析完毕的 SQL
70
71FETCH ： Fetch rows from a cursor. 从游标中得到数据 ， 通常指 select 返回记录
72
73UNMAP ： 如果游标使用了临时表 （ temporary table ） , 当游标关闭的时候将会看到 UNMAP
74
75c ： CPU time (100th's of a second in Oracle7 ,8 and 9).
76
77e ： Elapsed time (100th's of a second Oracle7, 8. Microseconds in Oracle 9 onwards).
78
79p ： Number of physical reads.
80
81cr ： Number of buffers retrieved for CR reads.
82
83cu ： Number of buffers retrieved in current mode.
84
85mis ： Cursor missed in the cache.
86
87r ： Number of rows processed.
88
89dep ： Recursive call depth (0 = user SQL, >0 = recursive).
90
91og ： Optimizer goal: 1=All_Rows, 2=First_Rows, 3=Rule, 4=Choose
92
93tim ： Timestamp (large number in 100ths of a second).
94
95比如 ： FETCH #2:c=0,e=106,p=0,cr=3,cu=0,mis=0,r=1,dep=1,og=4,tim=6005498548671
96
97\----------------------------------------------------------------------------
98
99** ERROR #%d:err=%d tim=%lu **
100
101\----------------------------------------------------------------------------
102
103执行或者 fetch 之后出现的 SQL Error
104
105err ： Oracle error code (e.g. ORA-XXXXX) at the top of the stack.
106
107tim ： Timestamp.
108
109\----------------------------------------------------------------------------
110
111** STAT #<cursor> id=N cnt=0 [pid=0 pos=0 obj=0 op='SORT AGGREGATE '] **
112
113\----------------------------------------------------------------------------
114
115<cursor> 的执行计划 .
116
117<cursor> ： Cursor which the statistics apply to.
118
119id ： Line of the explain plan which the row count applies to ( 从 1 开始 ).
120
121cnt ： Number of rows for this row source.
122
123pid ： Parent id of this row source.
124
125pos ： Position in explain plan.
126
127obj ： Object id of row source (if this is a base object).
128
129op ： The row source access operation.
130
131比如：
132
133STAT #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)'
134
135STAT #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)'
136
137\----------------------------------------------------------------------------
138
139** XCTEND rlbk=%d rd_only=%d **
140
141\----------------------------------------------------------------------------
142
143XCTEND 是事务结束的标志 .
144
145rlbk ： 1 if a rollback was performed, 0 if no rollback (commit).
146
147rd_only ： 1 if transaction was read only, 0 if changes occurred.
148
149\----------------------------------------------------------------------------
150
151** BINDS #%d: **
152
153** bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=03 oacfl2=0 size=24 offset=0 **
154
155** bfp=02fedb44 bln=22 avl=00 flg=05 **
156
157** value=10 **
158
159\----------------------------------------------------------------------------
160
161BIND ： Variables bound to a cursor.
162
163bind N ： The bind position being bound.
164
165dty ： Data type.
166
167mxl ： Maximum length of the bind variable (private max len in paren).
168
169mal ： Array length.
170
171scl ： Scale.
172
173pre ： Precision.
174
175oacflg ： Special flag indicating bind options
176
177oacflg2 ： Continuation of oacflg
178
179size ： Amount of memory to be allocated for this chunk
180
181offset ： Offset into this chunk for this bind buffer
182
183bfp ： Bind address.
184
185bln ： Bind buffer length.
186
187avl ： Actual value length (array length too).
188
189flg ： Special flag indicating bind status
190
191value ： The actual value of the bind variable.
192
193比如：
194
195BINDS #4:
196
197bind 0: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24 offset=0
198
199bfp=ffffffff7ce64ee0 bln=22 avl=01 flg=05
200
201value=0
202
203bind 1: dty=1 mxl=32(11) mal=00 scl=00 pre=00 oacflg=18 oacfl2=1 size=32 offset=0
204
205bfp=ffffffff7ce6b128 bln=32 avl=11 flg=05
206
207value="TABCOMPART$"
208
209bind 2: dty=2 mxl=22(22) mal=00 scl=00 pre=00 oacflg=08 oacfl2=1 size=24 offset=0
210
211bfp=ffffffff7ce6bae8 bln=24 avl=02 flg=05
212
213value=1
214
215\----------------------------------------------------------------------------
216
217** WAIT #<cursor>: nam="<event name="">" ela=0 p1=0 p2=0 p3=0 **
218
219\----------------------------------------------------------------------------
220
221WAIT ： An event that we waited for.
222
223nam ： What was being waited for.
224
225ela ： Elapsed time for the operation.
226
227p1 ： P1 for the given wait event.
228
229p2 ： P2 for the given wait event.
230
231p3 ： P3 for the given wait event.
232
233比如 (Full Table Scan):
234
235WAIT #1: nam="db file scattered read" ela= 5 p1=4 p2=1435 p3=25
236
237在游标 1 上经历了 "db file scattered read" 等待事件，一共等了 0.05 秒，在读取 File 4 ，从 1435 block 开始，读了 25 个 block
238
239比如 (Index Scan):
240
241WAIT #1: nam="db file sequential read" ela= 4 p1=4 p2=1224 p3=1
242
243在游标 1 上经历了 "db file sequential read" 等待事件，一共等了 0.04 秒，在读取 file 4 ， block 1224 ，读取了这一个 block
244
245对于每一个等待事件的含义和 p1,p2,p3 表示的意思，可以参考 Oracle Database Reference 文档的 Oracle Wait Events 章节。</event></cursor></cursor></cursor></cursor></cursor></cursor></cursor></cursor></statement></statement></statement></cursor></statement></cursor>