在SQL*PLUS下使用10046事件例子

sys@ORCL> select spid from v$process p, v$session s where p.addr=s.paddr and sid=(select sid from v$mystat where rownum=1);

SPID
------------------------
6411

NUMBER

sys@ORCL> oradebug setospid 6411
Oracle pid: 32, Unix process pid: 6411, image: oracle@zjtdbrac1 (TNS V1-V3)
sys@ORCL> oradebug unlimit
Statement processed.
sys@ORCL> oradebug event 10046 trace name context forever,level 12
Statement processed.
sys@ORCL> select count(*) from t;

  COUNT(*)
----------
     73285

sys@ORCL> oradebug event 10046 trace name context off
Statement processed.
sys@ORCL> oradebug tracefile_name
/app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_6411.trc
sys@ORCL> quit
Disconnected from Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, Oracle Label Security, OLAP, Data Mining,
Oracle Database Vault and Real Application Testing options
[oracle@zjtdbrac1 ~]vi /app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_6411.trcc

Trace file /app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_6411.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, Oracle Label Security, OLAP, Data Mining,
Oracle Database Vault and Real Application Testing options
ORACLE_HOME = /app/oracle/product/11g/dbname_1
System name:    Linux
Node name:      zjtdbrac1
Release:        2.6.32-279.el6.x86_64
Version:        #1 SMP Wed Jun 13 18:24:36 EDT 2012
Machine:        x86_64
Instance name: orcl
E486: Pattern not found: count(*)                                                                          1,11          Top
Trace file /app/oracle/diag/rdbms/orcl/orcl/trace/orcl_ora_6411.trc
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, Oracle Label Security, OLAP, Data Mining,
Oracle Database Vault and Real Application Testing options
ORACLE_HOME = /app/oracle/product/11g/dbname_1
System name:    Linux
Node name:      zjtdbrac1
Release:        2.6.32-279.el6.x86_64
Version:        #1 SMP Wed Jun 13 18:24:36 EDT 2012
Machine:        x86_64
Instance name: orcl
Redo thread mounted by this instance: 1
Oracle process number: 38
Unix process pid: 6411, image: oracle@zjtdbrac1

*** 2012-12-16 11:24:48.160
*** SESSION ID:(47.10) 2012-12-16 11:24:48.160
*** CLIENT ID:() 2012-12-16 11:24:48.160
*** SERVICE NAME:(orcl) 2012-12-16 11:24:48.160
*** MODULE NAME:(OEM.CacheModeWaitPool) 2012-12-16 11:24:48.160
*** ACTION NAME:() 2012-12-16 11:24:48.160

--------Dumping Sorted Master Trigger List --------
Trigger Owner : SYSMAN
Trigger Name : MGMT_JOB_EXEC_UPDATE
--------Dumping Trigger Sublists --------
/count                                                                                                    
Oradebug command 'unlimit' console output:

*** 2012-12-30 15:29:34.689
Processing Oradebug command 'event 10046 trace name context forever,level 12'

*** 2012-12-30 15:29:34.883
Oradebug command 'event 10046 trace name context forever,level 12' console output:
WAIT #0: nam='SQL*Net message to client' ela= 16 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1356852574883890

*** 2012-12-30 15:29:47.672
WAIT #0: nam='SQL*Net message from client' ela= 12788609 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1356852587672589
=====================
PARSING IN CURSOR #12 len=22 dep=0 uid=0 ct=3 lid=0 tim=1356852587837435 hv=2763161912 ad='850f0cd8' sqlid='cyzznbykb509s'
select count(*) from t
END OF STMT
PARSE #12:c=7999,e=164516,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=2966233522,tim=1356852587837415
EXEC #12:c=1999,e=10441,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2966233522,tim=1356852587848245
WAIT #12: nam='SQL*Net message to client' ela= 15 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1356852587848566
WAIT #12: nam='db file sequential read' ela= 431 file#=1 block#=89064 blocks=1 obj#=75659 tim=1356852587866841
WAIT #12: nam='db file scattered read' ela= 700 file#=1 block#=89065 blocks=7 obj#=75659 tim=1356852587877279
WAIT #12: nam='db file scattered read' ela= 18818 file#=1 block#=89072 blocks=8 obj#=75659 tim=1356852587897304
WAIT #12: nam='db file scattered read' ela= 1576 file#=1 block#=89120 blocks=8 obj#=75659 tim=1356852587899573
WAIT #12: nam='db file scattered read' ela= 531 file#=1 block#=89128 blocks=8 obj#=75659 tim=1356852587900974
WAIT #12: nam='db file scattered read' ela= 4781 file#=1 block#=89136 blocks=8 obj#=75659 tim=1356852587906362
WAIT #12: nam='db file scattered read' ela= 16435 file#=1 block#=89144 blocks=8 obj#=75659 tim=1356852587923824
WAIT #12: nam='db file scattered read' ela= 1279 file#=1 block#=89152 blocks=8 obj#=75659 tim=1356852587925925
WAIT #12: nam='db file scattered read' ela= 300 file#=1 block#=89160 blocks=8 obj#=75659 tim=1356852587927015
WAIT #12: nam='db file scattered read' ela= 58690 file#=1 block#=89168 blocks=8 obj#=75659 tim=1356852587986584
WAIT #12: nam='db file scattered read' ela= 1706 file#=1 block#=89184 blocks=8 obj#=75659 tim=1356852587989030
WAIT #12: nam='db file scattered read' ela= 172 file#=1 block#=89192 blocks=8 obj#=75659 tim=1356852587990140
WAIT #12: nam='db file scattered read' ela= 550 file#=1 block#=89200 blocks=8 obj#=75659 tim=1356852587991474
WAIT #12: nam='db file scattered read' ela= 845 file#=1 block#=89208 blocks=8 obj#=75659 tim=1356852587992800
WAIT #12: nam='db file scattered read' ela= 27550 file#=1 block#=89984 blocks=8 obj#=75659 tim=1356852588021143
WAIT #12: nam='db file scattered read' ela= 14293 file#=1 block#=89992 blocks=8 obj#=75659 tim=1356852588036282
WAIT #12: nam='db file scattered read' ela= 7858 file#=1 block#=90000 blocks=8 obj#=75659 tim=1356852588044796
WAIT #12: nam='db file scattered read' ela= 162263 file#=1 block#=90112 blocks=65 obj#=75659 tim=1356852588208739

*** 2012-12-30 15:29:48.309
WAIT #12: nam='db file scattered read' ela= 97295 file#=1 block#=90177 blocks=63 obj#=75659 tim=1356852588309942
WAIT #12: nam='db file scattered read' ela= 135833 file#=1 block#=90240 blocks=65 obj#=75659 tim=1356852588449849
WAIT #12: nam='db file scattered read' ela= 660 file#=1 block#=90305 blocks=8 obj#=75659 tim=1356852588453572
FETCH #12:c=117982,e=605374,p=329,cr=332,cu=0,mis=0,r=1,dep=0,og=1,plh=2966233522,tim=1356852588454007
STAT #12 id=1 cnt=1 pid=0 pos=1 bj=0 p='SORT AGGREGATE (cr=332 pr=329 pw=0 time=0 us)'
STAT #12 id=2 cnt=73285 pid=1 pos=1 bj=75659 p='TABLE ACCESS FULL T (cr=332 pr=329 pw=0 time=15859 us cost=61 size=0 card=73285)'
WAIT #12: nam='SQL*Net message from client' ela= 342 driver id=1650815232 #bytes=1 p3=0 obj#=75659 tim=1356852588574230
FETCH #12:c=0,e=4,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=2966233522,tim=1356852588574563
WAIT #12: nam='SQL*Net message to client' ela= 5 driver id=1650815232 #bytes=1 p3=0 obj#=75659 tim=1356852588574608
WAIT #12: nam='SQL*Net message from client' ela= 402 driver id=1650815232 #bytes=1 p3=0 obj#=75659 tim=1356852588575085
=====================
PARSING IN CURSOR #6 len=52 dep=0 uid=0 ct=47 lid=0 tim=1356852588575215 hv=1029988163 ad='7fb99238' sqlid='9babjv8yq8ru3'
BEGIN DBMS_OUTPUT.GET_LINES(:LINES, :NUMLINES); END;
END OF STMT
PARSE #6:c=0,e=47,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=0,tim=1356852588575214