演示使用sql_trace和10046事件对其他会话进行跟踪，并给出trace结果

不念不忘少年蓝@ 2021-11-01 06:42 356阅读 0赞

**一、引言**

之前在[《\[转载\]---教大家如何玩转跟踪(to owner session、other session)》][---_to owner session_other session]中说到了使用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      SPID
    12 ---------- -------------
    13     26        6251
    14 
     ----在session 2中使用sys登录----
    15 SQL> conn /as sysdba
    16 Connected.
    17 
     ----查看一下当前登录到数据库所有用户的sid,serial#,username等信息----
    18 SQL> set linesize 150;
    19 SQL> select s.sid,s.serial#,s.username,s.osuser
    20   2    from v$session s,v$process p
    21   3  where s.paddr=p.addr;
    22 
    23     SID     SERIAL# USERNAME        OSUSER
    24 ---------- -------- --------- ------------------
    25      2        1                     oracle
    26      3        1                     oracle
    27      4        1                     oracle
    28      5        1                     oracle
    29      6        1                     oracle
    30      7        1                     oracle
    31      8        1                     oracle
    32      9        1                     oracle
    33     12        1                     oracle
    34     10        1                     oracle
    35     11        1                     oracle
    36 
    37     SID     SERIAL#  USERNAME       OSUSER
    38 ---------- --------- --------- ----------------
    39     13        1                     oracle
    40     14        1                     oracle
    41     15        1                     oracle
    42     16        1                     oracle
    43     38      203       SYS           oracle
    44     18        9                     oracle
    45     22        2                     oracle
    46     28        3                     oracle
    47     24        3                     oracle
    48     34       31                     oracle
    49     37       29                     oracle
    50 
    51     SID    SERIAL#  USERNAME        OSUSER
    52 ---------- -------- ------------ -----------
    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      SPID
    60 ---------- -----------
    61     26       6251
    62 
     ----对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      72449
    80 
     ----查看一下当前trace文件的路径，完毕后退出----
    81 SQL> select value from v$diag_info where name = 'Default Trace File';
    82 
    83 VALUE
    84 --------------------------------------------------------------------------------
    85 /u01/app/oracle/diag/rdbms/yft/yft/trace/yft_ora_6251.trc
    86 
    87 SQL> exit
    88 
     ----回到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 2009
    10 Machine:    i686
    11 Instance name: yft
    12 Redo thread mounted by this instance: 1
    13 Oracle process number: 26
    14 Unix process pid: 6251, image: oracle@yft (TNS V1-V3)
    15 
    16 
    17 *** 2013-02-05 12:09:42.946
    18 *** SESSION ID:(36.283) 2013-02-05 12:09:42.946
    19 *** CLIENT ID:() 2013-02-05 12:09:42.946
    20 *** SERVICE NAME:(SYS$USERS) 2013-02-05 12:09:42.946
    21 *** MODULE NAME:(SQL*Plus) 2013-02-05 12:09:42.946
    22 *** ACTION NAME:() 2013-02-05 12:09:42.946
    23  
    24 CLOSE #2:c=0,e=172,dep=0,type=1,tim=1360037382921991
    25 =====================
    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 jack
    28 END OF STMT
    29 PARSE #3:c=0,e=281,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1205023501,tim=1360037382946843
    30 EXEC #3:c=0,e=152,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1205023501,tim=1360037382947147
    31 FETCH #3:c=46993,e=47747,p=0,cr=1037,cu=0,mis=0,r=1,dep=0,og=1,plh=1205023501,tim=1360037382995052
    32 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=1360037382996276
    35 
    36 *** 2013-02-05 12:09:58.447
    37 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=1360044255100848
    100 EXEC #2:c=4000,e=3401,p=0,cr=0,cu=0,mis=1,r=1,dep=0,og=1,plh=0,tim=1360044255100984
    101 
    102 *** 2013-02-05 14:04:36.808
    103 WAIT #2: nam='SQL*Net message from client' ela= 21707623 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1360044276808772
    104 CLOSE #2:c=0,e=190,dep=0,type=0,tim=1360044276809209
    105 =====================
    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=:w
    108 END OF STMT
    109 PARSE #5:c=1999,e=2118,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1360044276811459
    110 。。。。。。
    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 STMT
    115 PARSE #2:c=999,e=1110,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1360044286576302
    116 BINDS #2:
    117  Bind#0
    118   oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
    119   oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0
    120   kxsbbbfp=00a34e24  bln=22  avl=02  flg=05
    121   value=1000
    122 WAIT #2: nam='SQL*Net message to client' ela= 6 driver id=1650815232 #bytes=1 p3=0 obj#=74560 tim=1360044286580498
    123 EXEC #2:c=3999,e=3796,p=0,cr=0,cu=0,mis=1,r=1,dep=0,og=1,plh=0,tim=1360044286580562
    124 
    125 *** 2013-02-05 14:04:48.044
    126 WAIT #2: nam='SQL*Net message from client' ela= 1463275 driver id=1650815232 #bytes=1 p3=0 obj#=74560 tim=1360044288043981
    127 CLOSE #2:c=0,e=53,dep=0,type=0,tim=1360044288051930
    128 =====================
    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=:w
    131 END OF STMT
    132 PARSE #4:c=0,e=182,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1205023501,tim=1360044288052209
    133 BINDS #4:
    134  Bind#0
    135   oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00
    136   oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0
    137   kxsbbbfp=00a34e24  bln=22  avl=02  flg=05
    138   value=10
    139 EXEC #4:c=1000,e=318,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1205023501,tim=1360044288052738
    140 WAIT #4: nam='SQL*Net message to client' ela= 6 driver id=1650815232 #bytes=1 p3=0 obj#=74560 tim=1360044288052868
    141 FETCH #4:c=14998,e=22195,p=0,cr=1037,cu=0,mis=0,r=1,dep=0,og=1,plh=1205023501,tim=1360044288075125
    142 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=1360044288075549
    145 FETCH #4:c=0,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=1205023501,tim=1360044288075633
    146 WAIT #4: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=74560 tim=1360044288075670
    147 
    148 *** 2013-02-05 14:05:11.532
    149 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.**

最后，在这里有一篇是eygle写的《使用SQL\_TRACE进行数据库诊断》的文章：[http://www.eygle.com/archives/2004/10/use\_sql\_trace\_to\_diagnose\_database.html][http_www.eygle.com_archives_2004_10_use_sql_trace_to_diagnose_database.html]

转载于:https://www.cnblogs.com/Richardzhu/archive/2013/02/05/2893162.html

[---_to owner session_other session]: http://www.cnblogs.com/Richardzhu/articles/2892264.html
[http_www.eygle.com_archives_2004_10_use_sql_trace_to_diagnose_database.html]: http://www.eygle.com/archives/2004/10/use_sql_trace_to_diagnose_database.html