使用10046事件查看Oracle数据库中的执行计划,能够得到SQL执行计划中每一个执行步骤所消耗的逻辑读,物理读,和花费的时间。这种细粒度的明细显示在我们诊断复杂SQL的性能问题时尤为重要,而且这也是explain plan命令,autotrace命令所不能提供的。不过实际上,我们还可以通过gather_plan_sstatistics Hint 配合dbms_xplan 包一起使用得到和10046事件类似细粒度的明细的执行计划。
我们只需3个步骤就可以容易的通过10046事件获得SQL的执行计划。
1.首先在当前session 中激活10046事件。
2.在当前session 中执行SQL语句。
3.最后当前session 中关闭10046事件。
当执行完上述步骤后,oracle就会将目标SQL的执行计划和明细资源消耗写入此session对应的trace文件中。
oracle会在user_dump_dest参数设置的目录下产生这个trace文件。
我们有两种方法在当前session中激活10046事件。
1.在当前session中执行alter session set events '10046 trace naem context forever,level 12'
2.在当前session中执行oradebug event 10046 trace name context forever,level 12'
上述命令中的关键字”level“后的数字是标识设置的10046时间的level值,这个值是可以修改的,我们
通常使用的值为12,表示在产生的trace文件中除了有目标sql的执行计划和资源消耗明细外,还包含
SQL使用的绑定变量的值以及该session所经历的等待事件,除了level值外,其他的部分是固定的语法,
是无法修改的。
我推荐使用第2种方法,因为可以在激活10046事件后执行命令oradebug tracefile_name可以获得当前
session 所对应的trace文件的具体路径名称。
我们可以在当前session中关闭10046事件的两种方法:
1.在当前session中执行alter session set events '10046 trace name context off'
2.在当前session中执行oradebug event 10046 trace naem context off
我们使用一个例子来说明下
1.我们先激活10046事件,我们是oradebug命令来激活。
SQL>oradebug setmypid
SQL>oradebug event 10046 trace name context forver,level 12
2.在当前session中激活了10046事件后,我们执行一个SQL语句
SQL>SELECT * FROM hr.test;
3.使用oradebug tracefile_name 命令查看当前session所对应的trace文件路径和名称
SQL>oradebug tracefile_name
/app/oracle/diag/rdbms/pxboracle/pxboracle/trace/pxboracle_ora_18565.trc
4.关闭当前session 中的10046事件:
SQL>oradebug event 10046 trace name context off
下面的内容就是trace文件中的内容
=====================
PARSING IN CURSOR #47006443926880 len=27 dep=0 uid=0 oct=3 lid=0 tim=2879240721898379 hv=2413634929 ad='9e709620' sqlid='4wn49u27xu9bj'
select * from hr.test
END OF STMT
PARSE #47006443926880:c=378943,e=2562085,p=13,cr=721,cu=0,mis=1,r=0,dep=0,og=1,plh=121040406,tim=2879240721898378
EXEC #47006443926880:c=0,e=81,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=121040406,tim=2879240721898787
WAIT #47006443926880: nam='SQL*Net message to client' ela= 3 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=2879240721898965
WAIT #47006443926880: nam='Disk file operations I/O' ela= 175 FileOperation=2 fileno=5 filetype=2 obj#=18841 tim=2879240721899603
WAIT #47006443926880: nam='db file sequential read' ela= 15398 file#=5 block#=138826 blocks=1 obj#=18841 tim=2879240721915091
WAIT #47006443926880: nam='db file sequential read' ela= 10745 file#=5 block#=138827 blocks=1 obj#=18841 tim=2879240721935221
FETCH #47006443926880:c=1000,e=36278,p=2,cr=2,cu=0,mis=0,r=1,dep=0,og=1,plh=121040406,tim=2879240721935413
WAIT #47006443926880: nam='SQL*Net message from client' ela= 6148 driver id=1650815232 #bytes=1 p3=0 obj#=18841 tim=2879240721941743
WAIT #47006443926880: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=18841 tim=2879240721941899
FETCH #47006443926880:c=999,e=178,p=0,cr=1,cu=0,mis=0,r=15,dep=0,og=1,plh=121040406,tim=2879240721942058
WAIT #47006443926880: nam='SQL*Net message from client' ela= 407527 driver id=1650815232 #bytes=1 p3=0 obj#=18841 tim=2879240722349676
WAIT #47006443926880: nam='SQL*Net message to client' ela= 1 driver id=1650815232 #bytes=1 p3=0 obj#=18841 tim=2879240722349821
FETCH #47006443926880:c=1000,e=201,p=0,cr=1,cu=0,mis=0,r=7,dep=0,og=1,plh=121040406,tim=2879240722350005
STAT #47006443926880 id=1 cnt=23 pid=0 pos=1 obj=18841 op='TABLE ACCESS FULL LBBNF (cr=4 pr=2 pw=0 time=36197 us cost=3 size=3036 card=23)'
WAIT #47006443926880: nam='SQL*Net message from client' ela= 21195539 driver id=1650815232 #bytes=1 p3=0 obj#=18841 tim=2879240743545997
CLOSE #47006443926880:c=0,e=14,dep=0,type=0,tim=2879240743546441
*** 2061-03-28 21:05:43.546
Processing Oradebug command 'tracefile_name'