10046事件跟踪会话SQL背景知识：10046 事件按照收集信息内容，可以分成4个级别：Level 1：等同于SQL_TRACE 的功能Level 4：在Level 1的基础上增加收集绑定变量的信息Level 8：在Level 1 的基础上增加等待事件的信息Level 12：等同于Level 4+Level 8, 即同时收集绑定变量信息和等待事件信息。 一. 跟踪当前会话SQL1. sys用户给执行跟踪dblink用户授权SQL> grant alter session to dblink;Grant succeeded. 2. 返回dblink用户操作 SQL> show user;USER is "DBLINK" 3. 查询sid,serial#SQL> select sid,serial# from v$session where username='DBLINK';SID SERIAL#--- ----------45 14 4. 查询当前用户的trace文件SQL> select * from v$diag_info where name like 'Default%';INST_ID NAME VALUE--------- -------- ---------------------------------------------------1 Default Trace File/home/oracle/app/diag/rdbms/orcl/orcl/trace/orcl_ora_2823.trc 5. 启动10046事件SQL> alter session set events '10046 trace name context forever,level 12';Session altered. 6. 执行测试sql（即将被跟踪的SQL）SQL> variable a number; #含有绷定变量的SQLSQL> exec :a:=2;PL/SQL procedure successfully completed. SQL> select count(*) from dba_objects where object_id=:a;COUNT(*)---------- 7. 关闭10046事件 SQL> alter session set events '10046 trace name context off';Session altered. 8.1 查看原始10046后的trace文件注意：10046事件的trace文件内容是SQL按时间顺序执行的结果[oracle@11g ~]$ vim /home/oracle/app/diag/rdbms/orcl/orcl/trace/orcl_ora_2823.trcTrace file /home/oracle/app/diag/rdbms/orcl/orcl/trace/orcl_ora_2823.trcOracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit ProductionWith the Partitioning, OLAP, Data Mining and Real Application Testing optionsORACLE_HOME = /home/oracle/app/oracle/product/11.2.0/dbhome_1System name: LinuxNode name: 11gRelease: 2.6.32-573.el6.x86_64Version: #1 SMP Thu Jul 23 15:44:03 UTC 2015Machine: x86_64Instance name: orclRedo thread mounted by this instance: 1Oracle process number: 32Unix process pid: 2823, image: oracle@11g (TNS V1-V3) *** 2014-11-19 04:42:30.941*** SESSION ID:(45.14) 2014-11-19 04:42:30.941*** CLIENT ID:() 2014-11-19 04:42:30.941*** SERVICE NAME:(SYS$USERS) 2014-11-19 04:42:30.941*** MODULE NAME:(SQL*Plus) 2014-11-19 04:42:30.941*** ACTION NAME:() 2014-11-19 04:42:30.941 WAIT #2: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416390150940558 *** 2014-11-19 04:44:47.004WAIT #2: nam='SQL*Net message from client' ela= 136063164 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416390287004294CLOSE #2:c=0,e=3,dep=0,type=3,tim=1416390287004441=====================PARSING IN CURSOR #5 len=19 dep=0 uid=90 oct=47 lid=90 tim=1416390287005001 hv=3805855218 ad='87972f88' sqlid='1w9223jdjggk'BEGIN :a:=2; END;END OF STMTPARSE #5:c=0,e=467,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1416390287005001BINDS #5:Bind#0oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00oacflg=03 fl2=1000000 frm=00 csi=00 siz=24 off=0kxsbbbfp=7fd108695a28 bln=22 avl=00 flg=05WAIT #5: nam='SQL*Net message to client' ela= 2 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416390287006240EXEC #5:c=1999,e=1191,p=0,cr=0,cu=0,mis=1,r=1,dep=0,og=1,plh=0,tim=1416390287006261 *** 2014-11-19 04:56:00.212WAIT #5: nam='SQL*Net message from client' ela= 673206425 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1416390960212735CLOSE #5:c=0,e=49,dep=0,type=0,tim=1416390960212948=====================PARSING IN CURSOR #1 len=51 dep=0 uid=90 oct=3 lid=90 tim=1416390960213839 hv=3085049059 ad='87973410' sqlid='214vxnyvy4773'select count(*) from dba_objects where object_id=:aEND OF STMTPARSE #1:c=1000,e=844,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1416390960213838=====================PARSING IN CURSOR #6 len=37 dep=1 uid=0 oct=3 lid=0 tim=1416390960214450 hv=1398610540 ad='9a8c2c00' sqlid='grwydz59pu6mc'select text from view$ where rowid=:1END OF STMTPARSE #6:c=1000,e=408,p=0,cr=0,cu=0,mis=1,r=0,dep=1,og=4,plh=0,tim=1416390960214449=====================PARSING IN CURSOR #2 len=210 dep=2 uid=0 oct=3 lid=0 tim=1416390960215089 hv=864012087 ad='8a7b0300' sqlid='96g93hntrzjtr'select /*+ rule */ bucket_cnt, row_cnt, cache_cnt, null_cnt, timestamp#, sample_size, minimum, maximum, distcnt, lowval, hival, density, col#, spare1, spare2, avgcln from hist_head$ where obj#=:1 and intcol#=:2END OF STMTPARSE #2:c=0,e=292,p=0,cr=0,cu=0,mis=1,r=0,dep=2,og=3,plh=0,tim=1416390960215089BINDS #2:Bind#0oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0kxsbbbfp=7fd108751d48 bln=22 avl=02 flg=05value=69Bind#1oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0kxsbbbfp=7fd108751d18 bln=24 avl=03 flg=05value=1001EXEC #2:c=1000,e=9315,p=0,cr=0,cu=0,mis=1,r=0,dep=2,og=3,plh=2239883476,tim=1416390960224458FETCH #2:c=0,e=28,p=0,cr=2,cu=0,mis=0,r=0,dep=2,og=3,plh=2239883476,tim=1416390960224573STAT #2 id=1 cnt=0 pid=0 pos=1 obj=424 op='TABLE ACCESS BY INDEX ROWID HIST_HEAD$ (cr=2 pr=0 pw=0 time=0 us)'STAT #2 id=2 cnt=0 pid=1 pos=1 obj=426 op='INDEX RANGE SCAN I_HH_OBJ#_INTCOL# (cr=2 pr=0 pw=0 time=0 us)'CLOSE #2:c=0,e=2,dep=2,type=3,tim=1416390960224765=====================PARSING IN CURSOR #5 len=210 dep=2 uid=0 oct=3 lid=0 tim=1416390960224900 hv=864012087 ad='8a7b0300' sqlid='96g93hntrzjtr'select /*+ rule */ bucket_cnt, row_cnt, cache_cnt, null_cnt, timestamp#, sample_size, minimum, maximum, distcnt, lowval, hival, density, col#, spare1, spare2, avgcln from hist_head$ where obj#=:1 and intcol#=:2END OF STMTBINDS #5:Bind#0oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0kxsbbbfp=7fd108751d48 bln=22 avl=02 flg=05value=69Bind#1oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00oacflg=08 fl2=0001 frm=00 csi=00 siz=24 off=0kxsbbbfp=7fd108751d18 bln=24 avl=02 flg=05value=8EXEC #5:c=0,e=132,p=0,cr=0,cu=0,mis=0,r=0,dep=2,og=3,plh=2239883476,tim=1416390960225016FETCH #5:c=0,e=12,p=0,cr=2,cu=0,mis=0,r=0,dep=2,og=3,plh=2239883476,tim=1416390960225045CLOSE #5:c=0,e=1,dep=2,type=3,tim=1416390960225068BINDS #6:Bind#0oacdty=11 mxl=16(16) mxlc=00 mal=00 scl=00 pre=00oacflg=18 fl2=0001 frm=00 csi=00 siz=16 off=0kxsbbbfp=7fd1086aa078 bln=16 avl=16 flg=05。。。。。 省略大量输出"~/app/diag/rdbms/orcl/orcl/trace/orcl_ora_2823.trc" 148L, 8943C 8.2 使用tkprof工具查看10046时间的trace文件[oracle@11g ~]$ tkprof /home/oracle/app/diag/rdbms/orcl/orcl/trace/orcl_ora_2823.trc andy.txt sys=noTKPROF: Release 11.2.0.1.0 - Development on Wed Nov 19 05:00:35 2014Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.[oracle@11g ~]$ vim andy.txtfromdba_objects where object_id=:a call count cpu elapsed disk query current rows------- ------ -------- ---------- ---------- ---------- ---------- ----------Parse 1 0.00 0.00 0 0 0 0Execute 1 0.00 0.00 0 0 0 0Fetch 2 0.00 0.00 0 5 0 1------- ------ -------- ---------- ---------- ---------- ---------- ----------total 4 0.01 0.00 0 5 0 1 Misses in library cache during parse: 1Misses in library cache during execute: 1Optimizer mode: ALL_ROWSParsing user id: 90 Rows Row Source Operation # 执行计划------- ---------------------------------------------------1 SORT AGGREGATE (cr=5 pr=0 pw=0 time=0 us)1 VIEW DBA_OBJECTS (cr=5 pr=0 pw=0 time=0 us cost=5 size=26 card=2)1 UNION-ALL (cr=5 pr=0 pw=0 time=0 us)1 FILTER (cr=5 pr=0 pw=0 time=0 us)1 NESTED LOOPS (cr=5 pr=0 pw=0 time=0 us cost=5 size=71 card=1)1 NESTED LOOPS (cr=4 pr=0 pw=0 time=0 us cost=4 size=67 card=1)1 TABLE ACCESS BY INDEX ROWID OBJ$ (cr=3 pr=0 pw=0 time=0 us cost=3 size=45 card=1)1 INDEX RANGE SCAN I_OBJ1 (cr=2 pr=0 pw=0 time=0 us cost=2 size=0 card=1)(object id 36)1 INDEX RANGE SCAN I_USER2 (cr=1 pr=0 pw=0 time=0 us cost=1 size=22 card=1)(object id 47)1 INDEX RANGE SCAN I_USER2 (cr=1 pr=0 pw=0 time=0 us cost=1 size=4 card=1)(object id 47)0 TABLE ACCESS BY INDEX ROWID IND$ (cr=0 pr=0 pw=0 time=0 us cost=2 size=8 card=1)0 INDEX UNIQUE SCAN I_IND1 (cr=0 pr=0 pw=0 time=0 us cost=1 size=0 card=1)(object id 41)0 NESTED LOOPS (cr=0 pr=0 pw=0 time=0 us cost=2 size=29 card=1)0 INDEX FULL SCAN I_USER2 (cr=0 pr=0 pw=0 time=0 us cost=1 size=20 card=1)(object id 47)0 INDEX RANGE SCAN I_OBJ4 (cr=0 pr=0 pw=0 time=0 us cost=1 size=9 card=1)(object id 39)——————————————————————————————————————— 二. 跟踪指定会话（具体步骤参上面部分，这里简写）使用10046事件跟踪启动traceSQL> exec dbms_monitor.session_trace_enable(45,14,waits=>true,binds=>true)PL/SQL procedure successfully completed. 关闭traceSQL> exec dbms_monitor.session_trace_disable(45,14);PL/SQL procedure successfully completed.OK，结束。