基于以前开发的一个用于监控线程的cpu使用状况的小工具，topshow，我开发了一个用于追踪oracle内部函数调用的追踪器——oratracer. 你可以用该工具追踪监控oracle多个内部函数的调用情况，还可以尝试探测函数的输入参数的值，也可以打印追踪点被触发时的调用堆栈。追踪可以设置在整个oracle进程的级别，也可以设置在某个线程以追踪特定的会话。例子 1：
捕获oracle整个实例中被执行的sql语句。
首先，在与可执行文件相同的目录下设置追踪点文件”tracepoints.txt”，内容如下：
_opiprs 6*1
_rpisplu 6*2
_kprbprs 6
与函数名用空格相隔的数值为探测的参数数量，如果再加上”*n”，则表示尝试将双字节数字作为指针对待，递归获取其执行的值，后面的数字为递归深度。例如，对于第一个追踪点，函数名为”_opiprs”，探测6个参数，递归探测指针数据的深度为1。
注意：”#”为注释符。
然后从进程列表中选择”oracle.exe”，不要选择任何线程：
最后，点击”trace”按钮。一旦有语句被上述函数调用，你就可以从监控窗口看到这些语句：
sql代码
…
[2010-5-28 3:53:23.426]user call: _rpisplu (tid: 5276)
[args(6)]:
6
0
0
“select privilege#,level from sysauth$ connect by grantee#=prior privilege# and privilege#>0 start with grantee#=:1 and privilege#>0“
0×84(=>null)
0
[2010-5-28 3:53:23.442]user call: _rpisplu (tid: 5276)
[args(6)]:
6
0
0
“alter session set nls_language=’american’ nls_territory=’america’ nls_currency=’$’ nls_iso_currency=’america’ nls_numeric_characters=’.,’ nls_date_format=’dd-mon-rr’ nls_date_language=’american’ nls_sort=’binary’“
0xd4(=>null)
0
[2010-5-28 3:53:23.473]user call: _opiprs (tid: 5276)
[args(6)]:
0×70cce00(=>0×4000000)
“alter session set nls_language=’american’ nls_territory=’america’ nls_currency=’$’ nls_iso_currency=’america’ nls_numeric_characters=’.,’ nls_date_format=’dd-mon-rr’ nls_date_language=’american’ nls_sort=’binary’“
0xd5(=>null)
0×4bfe214(=>0×18)
0
6
[2010-5-28 3:53:23.504]user call: _rpisplu (tid: 5276)
[args(6)]:
3
0×20(=>null)
0×20(=>null)
“select sysdate + 1 / (24 * 60) from dual“
0×28(=>null)
1
[2010-5-28 3:53:23.520]user call: _rpisplu (tid: 5276)
[args(6)]:
5
0×20(=>null)
0×20(=>null)
“declare job binary_integer := :job; next_date date := :mydate; broken boolean := false; begin emd_maintenance.execute_em_dbms_job_procs(); :mydate := next_date; if broken then :b := 1; else :b := 0; end if; end; “
0xd5(=>null)
0
…
点击”stop”按钮，停止追踪。
例子 2:
理解sql是如何被执行计划驱动执行的。
我们知道，查询计划实际上就是驱动oracle通过特定函数及顺序来获取数据。我们可以通过追踪这些函数来理解执行计划。
首先下载以下文件，解压，重命名为”tracepoints.txt”，放到oratracer.exe所在目录：
http://www.hellodba.com/download/tracepoints_all_query_calls.zip
然后获取到你需要追踪的会话的spid：
sql代码
hellodba.com>select distinct spid from v$mystat m, v$session s, v$process p where s.sid=m.sid and s.paddr=p.addr;
spid
————
11076
从进程列表中选择oracle.exe => 从线程列表中选择tid为11076的线程 => 点击”trace”按钮
在被追踪的会话中执行一条语句：
sql代码
hellodba.com>select * from demo.t_test1 where owner=‘demo’ and object_name like ‘t_test%’;
owner object_name subobject_name object_id data_object_id object_type created
last_ddl_time timestamp status t g s
—————————— —————————— —————————— ———- ————– ——————- ———–
——– ——————- ——————- ——- - - -
demo t_test1 aaa 97819 97819 table 2007-06-07
13:48:08 2007-06-07 13:48:08 2007-06-07:13:48:08 valid n n n
注意：为了避免回滚调用也被追踪，你最好在追踪之前先运行一次该语句。
我们可以从追踪窗口看到数据fetch调用情况：
sql代码
[2010-5-28 6:28:29.649]user call: _qertbfetchbyrowid (tid: 11076)
[2010-5-28 6:28:29.711]user call: _qerixtfetch (tid: 11076)
[2010-5-28 6:28:29.727]user call: _qertbfetchbyrowid (tid: 11076)
[2010-5-28 6:28:29.727]user call: _qerixtfetch (tid: 11076)
有了这样的追踪记录，你可以尝试将他们与执行计划中节点映射：sql代码
hellodba.com>select * from demo.t_test1 where owner=‘demo’ and object_name like ‘t_test%’;
execution plan
———————————————————-
plan hash value: 698582444
——————————————————————————————-
| id | operation | name | rows | bytes | cost (%cpu)| time |
——————————————————————————————-
| 0 | select statement | | 5 | 495 | 4 (0)| 00:00:04 |
| 1 | table access by index rowid| t_test1 | 5 | 495 | 4 (0)| 00:00:04 | ==> _qertbfetchbyrowid
|* 2 | index range scan | t_test_idx7 | 5 | | 1 (0)| 00:00:02 | ==> _qerixtfetch
例子 3:
打印某个特定函数被调用时的线程调用堆栈。
我们这里追踪”_kkeadjsingtabcard”。设置追踪点：
sql代码
_kkeadjsingtabcard*-1 6
函数名后的”*n”指定输出的调用个数，-1为无限制。
然后获取到你需要追踪的会话的spid：
sql代码
hellodba.com>select distinct spid from v$mystat m, v$session s, v$process p where s.sid=m.sid and s.paddr=p.addr;
spid
————
11076
从进程列表中选择oracle.exe => 从线程列表中选择tid为11076的线程 => 点击”trace”按钮
在被追踪的会话中解释一条语句：
sql代码
hellodba.com>explain plan for select /*+full(t)*/ count(*) from demo.t_test2 t;
explained.
我们就可以从监控窗口获取到该函数被调用时的整个调用堆栈的情况：
sql代码
[2010-5-28 6:51:55.591]user call: _kkeadjsingtabcard (tid: 11076)
call stacks(-1):
0×1460029 (oracle.exe!_kkoitbp+757)
0×144c44d (oracle.exe!_kkoijbad+8869)
0×1445d8b (oracle.exe!_kkocopypreds+851)
0×143ee0a (oracle.exe!_kkosta+1694)
0×1d17f6c (oracle.exe!__pgosf443__aparequestbindcapture+156)
0×1d18398 (oracle.exe!_apagcp+388)
0×1d1683c (oracle.exe!_apafbr+464)
0xea6682 (oracle.exe!_opitcancp+1450)
0×5b4eb0 (oracle.exe!_kksminimaltypecheck+20)
0×84d939 (oracle.exe!_rpidrus+429)
0×5b8ce8 (oracle.exe!_kkssetnlshandle+5888)
0×87732e (oracle.exe!_kxsreleaseruntimelock+1366)
0×831815 (oracle.exe!_kkscbt+7237)
0×82e3cf (oracle.exe!_kksparsecursor+2099)
0×82f1b8 (oracle.exe!_kksxsccompat+148)
0×201683e (oracle.exe!_opibrp+1970)
0×13cd5ed (oracle.exe!_kpodrd+237)
0×13cba7c (oracle.exe!_kpocrs+780)
0×85174e (oracle.exe!_opirip+1102)
0×60feff90 (oracommon10.dll!_ttcpro+1276)
0×850a69 (oracle.exe!_opiodr+1017)
0×1221350 (oracle.exe!_opiino3+1092)
0×85174e (oracle.exe!_opirip+1102)
0×420e58 (oracle.exe!_opidcl+824)
0×42164a (oracle.exe!_ksdwri+50)
0×401171 (oracle.exe!_ssthrnfy+117)
0×401061 (oracle.exe!_opimai_init+97)
0×401905 (oracle.exe!_osnsoiint+713)
0×7c80b729 (kernel32.dll!getmodulefilenamea+442)
[args(6)]:
0×81e58d0
0×81e5da8
0
0×40a03000
0×8559500
0