一、引言
之前在中说到了使用DBMS_SYSTEM包和ORADEBUG对其他会话进行跟踪，但是演示的示例都是跟踪当前的会话，因此在这里做一个演示，使用它们如何对其他会话进行跟踪。
二、DBMS_SYSTEM
2.1、sql_trace
----在session 1中使用jack用户登录---- 1 SQL> conn jack/jack 2 Connected. ----查看一下sid和serial#---- 3 SQL> select sid, serial# from v$session where sid = (select sid from v$mystat where rownum=1); 4 5 SID SERIAL# 6 ---------- ---------- 7 36 283 8 ----再查看一下pid和spid，其中可以利用spid找到trace文件---- 9 SQL> select pid, spid from v$process p, v$session s where p.addr = s.paddr and s.sid=(select sid from v$mystat where rownum=1);10 11 PID SPID12 ---------- -------------13 26 625114 ----在session 2中使用sys登录---- 15 SQL> conn /as sysdba16 Connected.17 ----查看一下当前登录到数据库所有用户的sid,serial#,username等信息---- 18 SQL> set linesize 150;19 SQL> select s.sid,s.serial#,s.username,s.osuser20 2 from v$session s,v$process p21 3 where s.paddr=p.addr;22 23 SID SERIAL# USERNAME OSUSER24 ---------- -------- --------- ------------------ 25 2 1 oracle26 3 1 oracle27 4 1 oracle28 5 1 oracle29 6 1 oracle30 7 1 oracle31 8 1 oracle32 9 1 oracle33 12 1 oracle34 10 1 oracle35 11 1 oracle36 37 SID SERIAL# USERNAME OSUSER38 ---------- --------- --------- ----------------39 13 1 oracle40 14 1 oracle41 15 1 oracle42 16 1 oracle43 38 203 SYS oracle44 18 9 oracle45 22 2 oracle46 28 3 oracle47 24 3 oracle48 34 31 oracle49 37 29 oracle50 51 SID SERIAL# USERNAME OSUSER52 ---------- -------- ------------ -----------53 36 283 JACK oracle ----找了需要跟踪的对象54 55 23 rows selected.56 ----我的办法比较笨，从sid入手找到spid，这样就能找到trace文件啦---- 57 SQL> select pid, spid from v$process p, v$session s where p.addr = s.paddr and s.sid=36;58 59 PID SPID60 ---------- -----------61 26 625162 ----对session 1进行跟踪设置---- 63 SQL> exec dbms_system.set_bool_param_in_session(36,283,'timed_statistics',true);64 65 PL/SQL procedure successfully completed.66 67 SQL> exec dbms_system.set_int_param_in_session(36,283,'max_dump_file_size',20000000);68 69 PL/SQL procedure successfully completed.70 71 SQL> exec dbms_system.set_sql_trace_in_session(36,283,true);72 73 PL/SQL procedure successfully completed.74 ----在session 1中执行一个查询---- 75 SQL> select count(*) from jack;76 77 COUNT(*)78 ----------79 7244980 ----查看一下当前trace文件的路径，完毕后退出---- 81 SQL> select value from v$diag_info where name = 'Default Trace File';82 83 VALUE84 --------------------------------------------------------------------------------85 /u01/app/oracle/diag/rdbms/yft/yft/trace/yft_ora_6251.trc86 87 SQL> exit88 ----回到session 2中，关闭跟踪，其实在session中已经exit，如果不关闭也得到什么内容---- 89 SQL> exec dbms_system.set_sql_trace_in_session(36,283,false);90 91 PL/SQL procedure successfully completed.
----这是刚才跟踪到的trace文件的部分内容---- 1 [oracle@yft ~]$ cat /u01/app/oracle/diag/rdbms/yft/yft/trace/yft_ora_6251.trc 2 Trace file /u01/app/oracle/diag/rdbms/yft/yft/trace/yft_ora_6251.trc 3 Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - Production 4 With the Partitioning, OLAP, Data Mining and Real Application Testing options 5 ORACLE_HOME = /u01/app/oracle/product/11.2.0/db_1 6 System name: Linux 7 Node name: yft 8 Release: 2.6.18-164.el5 9 Version: #1 SMP Tue Aug 18 15:51:54 EDT 200910 Machine: i68611 Instance name: yft12 Redo thread mounted by this instance: 113 Oracle process number: 2614 Unix process pid: 6251, image: oracle@yft (TNS V1-V3)15 16 17 *** 2013-02-05 12:09:42.94618 *** SESSION ID:(36.283) 2013-02-05 12:09:42.94619 *** CLIENT ID:() 2013-02-05 12:09:42.94620 *** SERVICE NAME:(SYS$USERS) 2013-02-05 12:09:42.94621 *** MODULE NAME:(SQL*Plus) 2013-02-05 12:09:42.94622 *** ACTION NAME:() 2013-02-05 12:09:42.94623 24 CLOSE #2:c=0,e=172,dep=0,type=1,tim=136003738292199125 =====================26 PARSING IN CURSOR #3 len=25 dep=0 uid=91 oct=3 lid=91 tim=1360037382946854 hv=2169573763 ad='2e6883cc' sqlid='937fmby0p24c3'27 select count(*) from jack28 END OF STMT29 PARSE #3:c=0,e=281,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1205023501,tim=136003738294684330 EXEC #3:c=0,e=152,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1205023501,tim=136003738294714731 FETCH #3:c=46993,e=47747,p=0,cr=1037,cu=0,mis=0,r=1,dep=0,og=1,plh=1205023501,tim=136003738299505232 STAT #3 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=1037 pr=0 pw=0 time=0 us)'33 STAT #3 id=2 cnt=72449 pid=1 pos=1 obj=74560 op='TABLE ACCESS FULL JACK (cr=1037 pr=0 pw=0 time=216449 us cost=288 size=0 card=54647)'34 FETCH #3:c=0,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1205023501,tim=136003738299627635 36 *** 2013-02-05 12:09:58.44737 CLOSE #3:c=0,e=94,dep=0,type=1,tim=1360037398447719
2.2、10046事件
----在session 1中使用jack用户登录---- 1 SQL> conn jack/jack 2 Connected. 3 SQL> select sid, serial# from v$session where sid = (select sid from v$mystat where rownum=1); 4 5 SID SERIAL# 6 ---------- ---------- 7 38 278 8 9 SQL> select pid, spid from v$process p, v$session s where p.addr = s.paddr and s.sid=(select sid from v$mystat where rownum=1); 10 11 PID SPID 12 ---------- --------- 13 25 6692 14 ----在session 2中使用sys登录---- 15 SQL> conn /as sysdba 16 Connected. 17 SQL> set linesize 150; 18 SQL> select sid,serial#,username from v$session where username is not null; 19 20 SID SERIAL# USERNAME 21 ---------- ---------- ------------ 22 33 158 SYS 23 38 278 JACK 24 25 SQL> select pid, spid from v$process p, v$session s where p.addr = s.paddr and s.sid=38; 26 27 PID SPID 28 ---------- --------- 29 25 6692 30 ----使用10046事件跟踪session 1---- 31 SQL> exec dbms_system.set_bool_param_in_session(38,278,'timed_statistics',true) 32 33 PL/SQL procedure successfully completed. 34 35 SQL> exec dbms_system.set_int_param_in_session(38,278,'max_dump_file_size',20000000) 36 37 PL/SQL procedure successfully completed. 38 39 SQL> exec dbms_system.set_ev(38,278,10046,12,''); ----在这里要说明一下'',当使用'jack'时发现无法生成trace文件，当''时可以生成文件。 40 41 PL/SQL procedure successfully completed. 42 ----在session 1中先清空buffer_cache,shared_pool---- 43 SQL> alter system flush buffer_cache; 44 45 System altered. 46 47 SQL> alter system flush buffer_cache; 48 49 System altered. 50 51 SQL> alter system flush shared_pool; 52 53 System altered. 54 55 SQL> alter system flush shared_pool; 56 57 System altered. 58 59 SQL> variable w number; 60 SQL> exec :w:=1000 61 62 PL/SQL procedure successfully completed. 63 64 SQL> select count(*) from jack where object_id=:w; 65 66 COUNT(*) 67 ---------- 68 1 69 70 SQL> exec :w:=10 71 72 PL/SQL procedure successfully completed. 73 74 SQL> select count(*) from jack where object_id=:w; 75 76 COUNT(*) 77 ---------- 78 1 79 80 SQL> select value from v$diag_info where name = 'Default Trace File'; 81 82 VALUE 83 -------------------------------------------------------------------------------- 84 /u01/app/oracle/diag/rdbms/yft/yft/trace/yft_ora_6692.trc 85 ----关闭10046事件---- 86 SQL> exec dbms_system.set_ev(38,278,10046,0,''); 87 88 PL/SQL procedure successfully completed. 89 ----trace文件内容，可以看到有等待事件和绑定变量信息---- 90 PARSING IN CURSOR #2 len=22 dep=0 uid=91 oct=47 lid=91 tim=1360044255097438 hv=2136470701 ad='336f8d84' sqlid='3krnzsxzpgx5d' 91 BEGIN :w:=1000; END; 92 END OF STMT 93 PARSE #2:c=4999,e=9685,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1360044255097435 94 BINDS #2: 95 Bind#0 96 oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00 97 oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0 98 kxsbbbfp=00a58f04 bln=22 avl=00 flg=05 99 WAIT #2: nam='SQL*Net message to client' ela= 7 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1360044255100848100 EXEC #2:c=4000,e=3401,p=0,cr=0,cu=0,mis=1,r=1,dep=0,og=1,plh=0,tim=1360044255100984101 102 *** 2013-02-05 14:04:36.808103 WAIT #2: nam='SQL*Net message from client' ela= 21707623 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1360044276808772104 CLOSE #2:c=0,e=190,dep=0,type=0,tim=1360044276809209105 =====================106 PARSING IN CURSOR #5 len=44 dep=0 uid=91 oct=3 lid=91 tim=1360044276811465 hv=2817092406 ad='33633780' sqlid='2cmywaamykutq'107 select count(*) from jack where object_id=:w108 END OF STMT109 PARSE #5:c=1999,e=2118,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1360044276811459110 。。。。。。111 =====================112 PARSING IN CURSOR #2 len=20 dep=0 uid=91 oct=47 lid=91 tim=1360044286576308 hv=1276778704 ad='2e7260c8' sqlid='4nbsfbp61n66h'113 BEGIN :w:=10; END;114 END OF STMT115 PARSE #2:c=999,e=1110,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1360044286576302116 BINDS #2:117 Bind#0118 oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00119 oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0120 kxsbbbfp=00a34e24 bln=22 avl=02 flg=05121 value=1000122 WAIT #2: nam='SQL*Net message to client' ela= 6 driver id=1650815232 #bytes=1 p3=0 obj#=74560 tim=1360044286580498123 EXEC #2:c=3999,e=3796,p=0,cr=0,cu=0,mis=1,r=1,dep=0,og=1,plh=0,tim=1360044286580562124 125 *** 2013-02-05 14:04:48.044126 WAIT #2: nam='SQL*Net message from client' ela= 1463275 driver id=1650815232 #bytes=1 p3=0 obj#=74560 tim=1360044288043981127 CLOSE #2:c=0,e=53,dep=0,type=0,tim=1360044288051930128 =====================129 PARSING IN CURSOR #4 len=44 dep=0 uid=91 oct=3 lid=91 tim=1360044288052214 hv=2817092406 ad='33633780' sqlid='2cmywaamykutq'130 select count(*) from jack where object_id=:w131 END OF STMT132 PARSE #4:c=0,e=182,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1205023501,tim=1360044288052209133 BINDS #4:134 Bind#0135 oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00136 oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0137 kxsbbbfp=00a34e24 bln=22 avl=02 flg=05138 value=10139 EXEC #4:c=1000,e=318,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1205023501,tim=1360044288052738140 WAIT #4: nam='SQL*Net message to client' ela= 6 driver id=1650815232 #bytes=1 p3=0 obj#=74560 tim=1360044288052868141 FETCH #4:c=14998,e=22195,p=0,cr=1037,cu=0,mis=0,r=1,dep=0,og=1,plh=1205023501,tim=1360044288075125142 STAT #4 id=1 cnt=1 pid=0 pos=1 obj=0 op='SORT AGGREGATE (cr=1037 pr=0 pw=0 time=0 us)'143 STAT #4 id=2 cnt=1 pid=1 pos=1 obj=74560 op='TABLE ACCESS FULL JACK (cr=1037 pr=0 pw=0 time=0 us cost=289 size=156 card=12)'144 WAIT #4: nam='SQL*Net message from client' ela= 235 driver id=1650815232 #bytes=1 p3=0 obj#=74560 tim=1360044288075549145 FETCH #4:c=0,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1205023501,tim=1360044288075633146 WAIT #4: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=74560 tim=1360044288075670147 148 *** 2013-02-05 14:05:11.532149 WAIT #4: nam='SQL*Net message from client' ela= 23456541 driver id=1650815232 #bytes=1 p3=0 obj#=74560 tim=1360044311532234
三、ORADEBUG
3.1、10046事件
因为在10046事件中level=1等同于SQL_TRACE的功能，所以在这里只演示了Level=12.
----在session 1中使用jack用户登录---- 1 SQL> conn jack/jack 2 Connected. 3 SQL> select sid, serial# from v$session where sid = (select sid from v$mystat where rownum=1); 4 5 SID SERIAL# 6 ---------- ---------- 7 39 390 8 9 SQL> select pid, spid from v$process p, v$session s where p.addr = s.paddr and s.sid=(select sid from v$mystat where rownum=1); 10 11 PID SPID 12 ---------- --------- 13 25 6886 14 ----在session 2中使用sys登录---- 15 SQL> conn /as sysdba 16 Connected. 17 SQL> set linesize 150; 18 SQL> select sid,serial#,username from v$session where username is not null; 19 20 SID SERIAL# USERNAME 21 ---------- ---------- ------------- 22 33 167 SYS 23 39 390 JACK 24 25 SQL> select pid, spid from v$process p, v$session s where p.addr = s.paddr and s.sid=39; 26 27 PID SPID 28 ---------- -------- 29 25 6886 30 ----指定跟踪SESSION的SPID(OS process) 31 SQL> oradebug setospid 6886 32 Oracle pid: 25, Unix process pid: 6886, image: oracle@yft (TNS V1-V3) 33 SQL> oradebug unlimit 34 Statement processed. 35 SQL> oradebug event 10046 trace name context forever,level 12 36 Statement processed. 37 ----在session 1中进行一些操作---- 38 SQL> alter system flush buffer_cache; 39 40 System altered. 41 42 SQL> alter system flush buffer_cache; 43 44 System altered. 45 46 SQL> alter system flush shared_pool; 47 48 System altered. 49 50 SQL> alter system flush shared_pool; 51 52 System altered. 53 54 SQL> exec :i:=50; 55 56 PL/SQL procedure successfully completed. 57 58 SQL> select * from jack where object_id=:i; 59 60 OWNER 61 ------------------------------ 62 OBJECT_NAME 63 -------------------------------------------------------------------------------- 64 SUBOBJECT_NAME OBJECT_ID DATA_OBJECT_ID OBJECT_TYPE 65 ------------------------------ ---------- -------------- ------------------- 66 CREATED LAST_DDL_ TIMESTAMP STATUS T G S NAMESPACE 67 --------- --------- ------------------- ------- - - - ---------- 68 EDITION_NAME 69 ------------------------------ 70 SYS 71 I_COL3 72 50 50 INDEX 73 74 OWNER 75 ------------------------------ 76 OBJECT_NAME 77 -------------------------------------------------------------------------------- 78 SUBOBJECT_NAME OBJECT_ID DATA_OBJECT_ID OBJECT_TYPE 79 ------------------------------ ---------- -------------- ------------------- 80 CREATED LAST_DDL_ TIMESTAMP STATUS T G S NAMESPACE 81 --------- --------- ------------------- ------- - - - ---------- 82 EDITION_NAME 83 ------------------------------ 84 13-AUG-09 13-AUG-09 2009-08-13:23:00:54 VALID N N N 4 85 ----关闭10046事件---- 86 SQL> oradebug event 10046 trace name context off; 87 Statement processed. 88 SQL> oradebug tracefile_name 89 /u01/app/oracle/diag/rdbms/yft/yft/trace/yft_ora_6886.trc 90 ----trace文件内容---- 91 ===================== 92 PARSING IN CURSOR #4 len=20 dep=0 uid=91 oct=47 lid=91 tim=1360047844436331 hv=138812846 ad='335ecfac' sqlid='9n837ms44c7df' 93 BEGIN :i:=50; END; 94 END OF STMT 95 PARSE #4:c=1000,e=1204,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1360047844436326 96 BINDS #4: 97 Bind#0 98 oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00 99 oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0100 kxsbbbfp=012d97a0 bln=22 avl=00 flg=05101 WAIT #4: nam='SQL*Net message to client' ela= 7 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1360047844441224102 EXEC #4:c=4999,e=4775,p=0,cr=0,cu=0,mis=1,r=1,dep=0,og=1,plh=0,tim=1360047844441357103 104 *** 2013-02-05 15:04:28.017105 WAIT #4: nam='SQL*Net message from client' ela= 23575295 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1360047868016889106 CLOSE #4:c=0,e=51,dep=0,type=0,tim=1360047868017359107 =====================108 。。。。。。109 PARSING IN CURSOR #6 len=37 dep=0 uid=91 oct=3 lid=91 tim=1360047868084354 hv=792666545 ad='3351bf14' sqlid='7mvbn4crmy8dj'110 select * from jack where object_id=:i111 END OF STMT112 PARSE #6:c=18997,e=66904,p=10,cr=26,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1360047868084351113 =====================
最后，在这里有一篇是eygle写的《使用SQL_TRACE进行数据库诊断》的文章：
