经典10046剖析案例-4

Posted Mr.Oracle

tags:

篇首语:本文由小常识网(cha138.com)小编为大家整理,主要介绍了经典10046剖析案例-4相关的知识,希望对你有一定的参考价值。

sql_trace和10046事件都是我们在优化sql上面应用的非常多的工具,我们可以使用这两个工具知道当前正在执行的sql究竟在做什么

 

一,SQL_TRACE: SQL_TRACE命令会将执行的整个过程输出到一个trace文件,我通过阅读这个trace文件来了解这个sql在执行过程中Oracle究竟做了哪些事情

 

1)确定trace文件的路径

启用sql_trace前我们首先要确定跟踪文件的存放位置,即user_dump_dest下

SQL> show parameter user_dump_dest;

 

NAME TYPE VALUE

------------------------------------ ----------- ------------------------------

user_dump_dest string /u01/opt/oracle/admin/orcl

/udump

sql trace文件固定格式为<user_dump_dest>/<instance_name>_ora_<backgroudProcessID>.trc

其中user_dump_dest,instance_name的值可以通过show命令得到,backgroudProcessID的值就需要首先获取session的sid然后根据sid的值查询v$session中进程的地址,然后根据进程地址找到processID,在11G以前可以通过下面这个语句获取当前session的sql_trace文件的路径

SQL> select

a.value || ‘/‘ || b.instance_name || ‘_ora_‘ || c.spid || ‘.trc‘ trace_file

from

(select value from v$parameter where name= ‘user_dump_dest‘) a,

(select instance_name from v$instance) b,

(select spid from v$process where addr=(select paddr from v$session where sid=(select distinct sid from v$mystat))) c;

TRACE_FILE

--------------------------------------------------------------------------------

/u01/opt/oracle/admin/orcl/udump/orcl_ora_7810.trc

 

在11g以后v$process视图里面tracefile 字段直接给出了这个值,因此不需要写上面那么麻烦的语句

SQL> select tracefile from v$process where addr=(select paddr from v$session where sid=(select distinct sid from v$mystat));

 

TRACEFILE

--------------------------------------------------------------------------------

/u01/app/oracle/diag/rdbms/rbksafari/RBKSAFARI/trace/RBKSAFARI_ora_29991.trc

 

另外也可以手工更改产生trace文件的名称例如

SQL> alter session set tracefile_identifier=‘mytrace‘

执行这条语句后就会在原有的tracename上加上_mytrace例如前面查出来的/u01/opt/oracle/admin/orcl/udump/orcl_ora_7810.trc就会变成/u01/opt/oracle/admin/orcl/udump/orcl_ora_7810_mytrace.trc这时我们只需要到user_dump_dest的路径下通过ls命令匹配关键字mytrace就可以了,就没有必要去写sql查询了。

 

2)启用sql_trace

启用sql_trace可以通过从instance级别和session级别,我们知道每个session都会有一个trace文件,因此在实例级别启用如果session越多将暂用的系统资源越多,除非有特殊的需求。

下面的语句可以启用实例级别的trace

SQL> alter system set sql_trace=true

 

SQL> show parameter sql_trace

 

NAME TYPE VALUE

------------------------------------ ----------- ------------------------------

sql_trace boolean TURE

 

从session级别启动有两种方式,第一跟踪当前的session,第二跟踪其它的session,我们只需要确定备跟踪会话的sid和serial#的值就可以了

 

当前session:

SQL> alter system set sql_trace=ture;

 

其它session:

例如确定了session id=138然后查询v$session获取serial#

SQL> select sid,serial# from v$session where sid=138;

 

SID SERIAL#

---------- ----------

138 2397

然后执行下面的包来跟踪这个session

SQL> execute dmbs_system.set_sql_trace_in_session(138,2397,true)

停止:

SQL> execute dmbs_system.set_sql_trace_in_session(138,2397,false)

二,TKPROF工具

默认生成的trace文件的可读性是比较差的,我们通常会用TKPROF这个工具来格式化在个trace文件。tkprof工具是oracle自带的一个工具,用于处理原始的trace文件,它的主要作用是合并汇总trace文件中的一些项,规范化文件格式,使得文件具有可读性,下面是简单的格式化一个文件

[[email protected] trace]$ tkprof RBKSAFARI_ora_1302.trc new.txt

 

TKPROF: Release 11.2.0.1.0 - Development on Fri Oct 11 19:08:57 2013

 

Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.

-----------------------------------------------------

下面来执行一条sql语句使用,看看trace文件中的内容信息

SQL> select tracefile from v$process where addr=(select paddr from v$session where sid=(select distinct sid from v$mystat));

 

TRACEFILE

--------------------------------------------------------------------------------

/u01/app/oracle/diag/rdbms/rbksafari/RBKSAFARI/trace/RBKSAFARI_ora_30598.trc

 

SQL> alter session set sql_trace=true;

 

Session altered.

 

SQL> select * from test where id=100;

 

使用tkprof工具格式化RBKSAFARI_ora_30598.trc这个文件

[[email protected] trace]$ tkprof RBKSAFARI_ora_30598.trc mytrace.txt

 

TKPROF: Release 11.2.0.1.0 - Development on Fri Oct 11 19:17:25 2013

 

Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.

 

 

用vi打开如下

TKPROF: Release 11.2.0.1.0 - Development on Fri Oct 11 19:17:25 2013

 

Copyright (c) 1982, 2009, Oracle and/or its affiliates. All rights reserved.

 

Trace file: RBKSAFARI_ora_30598.trc

Sort options: default

 

********************************************************************************

count = number of times OCI procedure was executed

cpu = cpu time in seconds executing

elapsed = elapsed time in seconds executing

disk = number of physical reads of buffers from disk

query = number of buffers gotten for consistent read

current = number of buffers gotten in current mode (usually for update)

rows = number of rows processed by the fetch or execute call

********************************************************************************

trace文件头部的信息描述了tkprof的版本,以及报告中一些列的定义,在下面的报告中,每一条sql都包含了这条sql执行过程的所有信息,对于任何一条sql都应该包含3个步骤(对应下表的call列)

分析(parse):SQL的分析阶段

执行(execute):SQL的执行阶段

数据提取(Fetch):数据提取阶段

横向的列除了call之外,还包含了一下信息:

count:计算器,表示当前的操作被执行了多少次。

cpu:当前的操作消耗的cpu时间(单位秒)

Elapsed: 当前的操作一共用时多少(包括cpu事件和等待时间)

Disk:当前操作的物理读(磁盘i/o次数)

Query:当前操作的一致性读方式读取的数据块数(通常是查询)

Current:当前操作的current的方式读取的数据库数(通常是修改数据块使用的方式)

Rows:当前操作处理的数据记录数

 

SQL ID: 4tk6t8tfsfqbf

Plan Hash: 0

alter session set sql_trace=true

 

 

call count cpu elapsed disk query current rows

------- ------ -------- ---------- ---------- ---------- ---------- ----------

Parse 0 0.00 0.00 0 0 0 0

Execute 1 0.00 0.00 0 0 0 0

Fetch 0 0.00 0.00 0 0 0 0

------- ------ -------- ---------- ---------- ---------- ---------- ----------

total 1 0.00 0.00 0 0 0 0

 

Misses in library cache during parse: 0

Misses in library cache during execute: 1

Optimizer mode: ALL_ROWS

Parsing user id: SYS

********************************************************************************

 

下面才是我们需要的信息,我们执行的那条查询sql的trace信息

 

SQL ID: d3gtqbsdqbbwq

Plan Hash: 4274779609

select *

from

test where id=100

 

 

call count cpu elapsed disk query current rows

------- ------ -------- ---------- ---------- ---------- ---------- ----------

Parse 1 0.00 0.00 0 0 0 0

Execute 1 0.00 0.00 0 0 0 0

Fetch 2 0.00 0.00 0 3 0 1

------- ------ -------- ---------- ---------- ---------- ---------- ----------

total 4 0.00 0.00 0 3 0 1

 

我们看到,这条sql语句被分析了一次,执行了一次,数据提取了2次,cpu和elpased都为0是因为这个表暂用的数据比较少,可以看到一共查询3个块,没有物理读,说明这个3个块已经缓冲到了buffer cache中,最后返回了1行的记录

 

Misses in library cache during parse: 1 --说明在shared pool中没有命中,说明这是一次硬分析

Optimizer mode: ALL_ROWS --当前优化器模式为CBO ALL_ROS

Parsing user id: SYS --分析用户id

 

下面是这条sql语句的具体执行计划信息,这里注意,这个执行计划里面的信息不是CBO根据表分析数据估算出的数值,而是SQL语句实际执行过程中消耗的资源信息,其中:

Rows 当前操作返回的实际返回的记录数。

Row Source Operation 表示当前操作的数据访问方式。

cr(consistent read)一致性读取的数据块,相当于query列上的fetch的值

pr(physical read)物理读取的数据块,相当于disk列上的fetch的值

pw(physical write) 物理写

time 当前操作执行时间

 

Rows Row Source Operation

------- ---------------------------------------------------

1 TABLE ACCESS BY INDEX ROWID TEST (cr=3 pr=0 pw=0 time=0 us cost=2 size=29 card=1)

1 INDEX UNIQUE SCAN SYS_C00399080 (cr=2 pr=0 pw=0 time=0 us cost=1 size=0 card=1)(object id 217036)

 

 

下面部分是对这个sql_trace期间所有非递归sql语句的执行信息汇总

OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS

 

call count cpu elapsed disk query current rows

------- ------ -------- ---------- ---------- ---------- ---------- ----------

Parse 1 0.00 0.00 0 0 0 0

Execute 2 0.00 0.00 0 0 0 0

Fetch 2 0.00 0.00 0 3 0 1

------- ------ -------- ---------- ---------- ---------- ---------- ----------

total 5 0.00 0.00 0 3 0 1

 

Misses in library cache during parse: 1

Misses in library cache during execute: 1

 

下面是递归调用语句的信息统计,递归sql语句是指执行一条sql语句衍生执行其它的sql,这些衍生出来的sql语句叫做递归sql语句。比如Oracle为了执行我们发出的这条sql语句

select * from test where id=100

需要对这条sql语句进行分析,需要读取一些数据字典来获取相关信息,比如是否有权限,对象是否有存在,对象的存储信息,下面统计都为0是因为这条sql语句之前已经执行过,

 

OVERALL TOTALS FOR ALL RECURSIVE STATEMENTS

 

call count cpu elapsed disk query current rows

------- ------ -------- ---------- ---------- ---------- ---------- ----------

Parse 0 0.00 0.00 0 0 0 0

Execute 0 0.00 0.00 0 0 0 0

Fetch 0 0.00 0.00 0 0 0 0

------- ------ -------- ---------- ---------- ---------- ---------- ----------

total 0 0.00 0.00 0 0 0 0

 

Misses in library cache during parse: 0

 

2 user SQL statements in session.

0 internal SQL statements in session.

2 SQL statements in session.

 

上面是一个通过tkprof工具处理后的结果集,它真实的统计了sql在运行过程中的各种资源消耗,这个报告对于分析性能有问题的sql语句非常重要

 

如果你想确切地知道sql语句的每一步执行时如何操作的,就需要分析原始的trace文件,下面给出了这条sql语句的关键部分

PARSING IN CURSOR #1 len=31 dep=0 uid=0 oct=3 lid=0 tim=1381490108569206 hv=459648918 ad=‘6d9c7590‘ sqlid=‘d3gtqbsdqbbwq‘

select * from test where id=100

END OF STMT

PARSE #1:c=1999,e=1757,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=4274779609,tim=1381490108569205

EXEC #1:c=0,e=41,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4274779609,tim=1381490108569319

FETCH #1:c=0,e=92,p=0,cr=3,cu=0,mis=0,r=1,dep=0,og=1,plh=4274779609,tim=1381490108569461

STAT #1 id=1 cnt=1 pid=0 pos=1 obj=217035 op=‘TABLE ACCESS BY INDEX ROWID TEST (cr=3 pr=0 pw=0 time=0 us cost=2 size=29 card=1)‘

STAT #1 id=2 cnt=1 pid=1 pos=1 obj=217036 op=‘INDEX UNIQUE SCAN SYS_C00399080 (cr=2 pr=0 pw=0 time=0 us cost=1 size=0 card=1)‘

FETCH #1:c=0,e=2,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=4274779609,tim=1381490108591269

..........

 

我们看到Oracle首先对这条sql语句做分析,并且有一个游标号CURSOR #1,这个在整个trace文件中不是唯一的,当一条sql语句执行完毕后,这个号会被另外一个sql语句重用

我们还可以看到这条sql语句被分析了一次,执行了一次,fetch了2次,stat#1是对这条sql语句执行过程中的资源消耗的统计,这些输出顺序就是sql语句的执行顺序,通过这些顺序就可以了解到sql语句是如何一步一步执行的。

 

下面是列出了这些指标的解释

PARSING IN CURSOR 部分

 

len:被分析sql的长度

dep:产生递归sql的深度

uid:user id

otc:Oracle command type命令的类型

lid:私有用的id

tim:时间戳

hv: hash value

ad: sql address

 

PARSE,EXEC,FETCH部分:

 

c: 消耗的cpu time

e:elapsed time 操作的用时

p:physical reads次数

cr:consistent reads数据的块

cu:current方式读取的数据块

mis:cursor miss in canche硬分析次数

r:rows处理的行数

dep:depth递归sql的深度

og:optimize goal优化器模式

tim:timstamp时间戳

 

stats部分:

 

id:执行计划的行源号

cnt:当前行源返回的行数

pid:当前行源的父号

pos:执行计划中的位置

obj:当前操作的对象id

op:当前行源的数据访问操作

 

三 10046事件

 

10046事件按照收集信息的内容,可以分为4个级别

 

1)Level 1 等同于sql_trace的功能。

2)Level 4 在Level 1的基础上收集绑定变量的信息

3)level 8 在Level 1的基础上增加了等等事件的信息

4)level12 等同于Level 4 + Level *,集同时收集绑定变量和等待事件信息

可以看出level级别越高,收集的信息越全面,我们用下面例子来分别看下这几个级别的作用

(1)LEVEL 4

--首先查询trace文件路径

SQL> select tracefile from v$process where addr=(select paddr from v$session where sid=(select distinct sid from v$mystat));

 

TRACEFILE

--------------------------------------------------------------------------------

/u01/app/oracle/diag/rdbms/rbksafari/RBKSAFARI/trace/RBKSAFARI_ora_9493.trc

 

 

SQL> create table test as select * from dba_objects;

 

Table created.

 

 

SQL> exec dbms_stats.gather_table_stats(‘sys‘,‘test‘);

 

PL/SQL procedure successfully completed.

 

--设定10046事件的级别为4

SQL> alter session set events ‘10046 trace name context forever,level 4‘;

 

Session altered.

--定义2个变量x,y

SQL> var x number;

SQL> var y varchar2(10);

SQL> exec :x := 20;

 

PL/SQL procedure successfully completed.

 

SQL> exec :y :=‘TEST‘;

 

PL/SQL procedure successfully completed.

 

--通过绑定变量查询表

SQL> select object_id,object_name from test where object_id=:x or object_name=:y;

 

OBJECT_ID OBJECT_NAM

---------- ----------

20 ICOL$

221329 TEST

 

SQL> alter session set events ‘10046 trace name context off‘;

 

Session altered.

 

这样就完成了使用10046事件做SQL trace的工作,注意,LEVEL 4获取的绑定变量的信息只能在原始的trace文件里面获取,在通过tkprof工具格式化后是看不到的,下面是这条sql在原始文件中的关键部分

 

=====================

PARSING IN CURSOR #1 len=75 dep=0 uid=0 oct=3 lid=0 tim=1381546195913578 hv=2021462068 ad=‘74fc6200‘ sqlid=‘gkkf6ndw7u41n‘

select object_id,object_name from test where object_id=:x or object_name=:y

 

END OF STMT

PARSE #1:c=0,e=99,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1357081020,tim=1381546195913577

BINDS #1:

Bind#0

oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00

oacflg=03 fl2=1000000 frm=00 csi=00 siz=56 off=0

kxsbbbfp=7fb340f24728 bln=22 avl=02 flg=05

value=20

Bind#1

oacdty=01 mxl=32(30) mxlc=00 mal=00 scl=00 pre=00

oacflg=03 fl2=1000000 frm=01 csi=873 siz=0 off=24

kxsbbbfp=7fb340f24740 bln=32 avl=04 flg=01

value="TEST"

EXEC #1:c=0,e=139,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1357081020,tim=1381546195913782

FETCH #1:c=0,e=128,p=0,cr=4,cu=0,mis=0,r=1,dep=0,og=1,plh=1357081020,tim=1381546195913961

FETCH #1:c=10999,e=11326,p=0,cr=1052,cu=0,mis=0,r=1,dep=0,og=1,plh=1357081020,tim=1381546195925477

STAT #1 id=1 cnt=2 pid=0 pos=1 obj=221329 op=‘TABLE ACCESS FULL TEST (cr=1056 pr=0 pw=0 time=0 us cost=287 size=90 card=3)‘

 

我们清楚的看到CURSOR #1 运行了绑定变量BINDS #1:

Bind#0 表示第一个绑定变量,最后一个value=20,表示这个变量的值为20

Bind#1 表示第二个绑定变量,最后一个value="TEST",表示这个变量的值为TEST

2) LEVEL 8

 

SQL> select tracefile from v$process where addr=(select paddr from v$session where sid=(select distinct sid from v$mystat));

 

TRACEFILE

--------------------------------------------------------------------------------

/u01/app/oracle/diag/rdbms/rbksafari/RBKSAFARI/trace/RBKSAFARI_ora_9603.trc

 

--打开另外一个session 2 模拟TX - row lock contention等待事件

SQL> update test set object_id=10 where object_name=‘TEST‘;

 

1 row updated.

 

 

--回到这个session启用10046 level 8

SQL> alter session set events ‘10046 trace name context forever,level 8‘;

 

Session altered.

 

--更新同一行,这个时候session就被另外一个session阻塞了

SQL> update test set object_id=20 where object_name=‘TEST‘;

 

--等待1分钟后,在session 2 commit

 

SQL> commit;

 

Commit complete.

 

--回到session 通过绑定变量做查询

SQL> var x number;

SQL> var y varchar2(10);

SQL> exec :x := 20;

 

PL/SQL procedure successfully completed.

 

SQL> exec :y :=‘TEST‘;

 

PL/SQL procedure successfully completed.

 

SQL> col object_name for a10;

SQL> select object_id,object_name from test where object_id=:x or object_name=:y;

 

OBJECT_ID OBJECT_NAM

---------- ----------

20 ICOL$

20 TEST

 

SQL> alter session set events ‘10046 trace name context off‘;

 

Session altered.

 

 

下面是等待事件相关的类容

PARSING IN CURSOR #1 len=53 dep=0 uid=0 oct=6 lid=0 tim=1381547023329562 hv=902883731 ad=‘763c0908‘ sqlid=‘fm3f2m0ux1ucm‘

update test set object_id=20 where object_name=‘TEST‘

END OF STMT

PARSE #1:c=2000,e=2079,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=839355234,tim=1381547023329561

 

*** 2013-10-12 11:04:37.870

WAIT #1: nam=‘enq: TX - row lock contention‘ ela= 54462429 name|mode=1415053318 usn<<16 | slot=65562 sequence=9055 obj#=221329 tim=1381547077870603

EXEC #1:c=10997,e=54541351,p=0,cr=1057,cu=4,mis=0,r=1,dep=0,og=1,plh=839355234,tim=1381547077870989

STAT #1 id=1 cnt=0 pid=0 pos=1 obj=0 op=‘UPDATE TEST (cr=1057 pr=0 pw=0 time=0 us)‘

STAT #1 id=2 cnt=1 pid=1 pos=1 obj=221329 op=‘TABLE ACCESS FULL TEST (cr=1056 pr=0 pw=0 time=0 us cost=287 size=60 card=2)‘

WAIT #1: nam=‘SQL*Net message to client‘ ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1381547077871119

 

*** 2013-10-12 11:05:14.205

WAIT #1: nam=‘SQL*Net message from client‘ ela= 36334185 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1381547114205328

CLOSE #1:c=0,e=16,dep=0,type=0,tim=1381547114206287

 

可以清楚的看到在CURSOR #1有刚才模拟的等待事件enq: TX - row lock contention

 

下面是select的相关内容

PARSING IN CURSOR #6 len=75 dep=0 uid=0 oct=3 lid=0 tim=1381548130797812 hv=2021462068 ad=‘74fc6200‘ sqlid=‘gkkf6ndw7u41n‘

select object_id,object_name from test where object_id=:x or object_name=:y

END OF STMT

PARSE #6:c=0,e=299,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=0,tim=1381548130797811

EXEC #6:c=1000,e=751,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=1357081020,tim=1381548130798637

WAIT #6: nam=‘SQL*Net message to client‘ ela= 5 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1381548130798688

FETCH #6:c=0,e=48,p=0,cr=4,cu=0,mis=0,r=1,dep=0,og=1,plh=1357081020,tim=1381548130798766

WAIT #6: nam=‘SQL*Net message from client‘ ela= 180 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1381548130798986

WAIT #6: nam=‘SQL*Net message to client‘ ela= 8 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1381548130807489

FETCH #6:c=8999,e=8627,p=0,cr=1052,cu=0,mis=0,r=1,dep=0,og=1,plh=1357081020,tim=1381548130807646

STAT #6 id=1 cnt=2 pid=0 pos=1 obj=221329 op=‘TABLE ACCESS FULL TEST (cr=1056 pr=0 pw=0 time=0 us cost=287 size=90 card=3)‘

 

可以看出LEVEL 8 里面没有包含绑定变量的信息

 

3) LEVEL 12

操作步骤和LEVEL 8 一样

 

下面是等待事件信息

PARSING IN CURSOR #1 len=53 dep=0 uid=0 oct=6 lid=0 tim=1381548626071590 hv=3865385185 ad=‘7011bc50‘ sqlid=‘a30698vm6a671‘

update test set object_id=10 where object_name=‘TEST‘

END OF STMT

PARSE #1:c=0,e=1147,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=839355234,tim=1381548626071589

 

*** 2013-10-12 11:30:46.006

WAIT #1: nam=‘enq: TX - row lock contention‘ ela= 19930521 name|mode=1415053318 usn<<16 | slot=131092 sequence=12176 obj#=221329 tim=1381548646006494

EXEC #1:c=4999,e=19935098,p=0,cr=1057,cu=4,mis=0,r=1,dep=0,og=1,plh=839355234,tim=1381548646006763

STAT #1 id=1 cnt=0 pid=0 pos=1 obj=0 op=‘UPDATE TEST (cr=1057 pr=0 pw=0 time=0 us)‘

STAT #1 id=2 cnt=1 pid=1 pos=1 obj=221329 op=‘TABLE ACCESS FULL TEST (cr=1056 pr=0 pw=0 time=0 us cost=287 size=60 card=2)‘

WAIT #1: nam=‘SQL*Net message to client‘ ela= 4 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1381548646006926

 

*** 2013-10-12 11:30:49.893

WAIT #1: nam=‘SQL*Net message from client‘ ela= 3886351 driver id=1650815232 #bytes=1 p3=0 obj#=-1 tim=1381548649893302

 

下面是绑定变量信息

PARSING IN CURSOR #1 len=75 dep=0 uid=0 oct=3 lid=0 tim=1381548682580601 hv=2021462068 ad=‘74fc6200‘ sqlid=‘gkkf6ndw7u41n‘

select object_id,object_name from test where object_id=:x or object_name=:y

END OF STMT

PARSE #1:c=0,e=74,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1357081020,tim=1381548682580599

BINDS #1:

Bind#0

oacdty=02 mxl=22(22) mxlc=00 mal=00 scl=00 pre=00

oacflg=03 fl2=1000000 frm=00 csi=00 siz=56 off=0

kxsbbbfp=7f1296db5758 bln=22 avl=02 flg=05

value=20

Bind#1

oacdty=01 mxl=32(30) mxlc=00 mal=00 scl=00 pre=00

oacflg=03 fl2=1000000 frm=01 csi=873 siz=0 off=24

kxsbbbfp=7f1296db5770 bln=32 avl=04 flg=01

value="TEST"

EXEC #1:c=0,e=137,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1357081020,tim=1381548682580809

 

可以看出LEVEL 14 = LEVEL 4 + LEVEL 8

 

如同SQL_TRACE如果跟踪其它session,同样在获取session的sid和serial后即可通过下面的命令跟踪

SQL> exec dbms_monitor.session_trace_enable(100,11110,waits=>true,bind=>true); --启用

 

SQL> exec dbms_monitor.session_trace_disable(100,11110); --禁用

 

 

另外启用10046事件受下面两个参数的影响

 

SQL> show parameter timed_statistics

 

NAME TYPE VALUE

------------------------------------ ----------- ------------------------------

timed_statistics boolean TRUE

SQL> show parameter max_dump_file_size;

 

NAME TYPE VALUE

------------------------------------ ----------- ------------------------------

max_dump_file_size string unlimited

 

在oracle 10g后在两个参数保存默认就好了,简单知道就可以了。

 

以上是关于经典10046剖析案例-4的主要内容,如果未能解决你的问题,请参考以下文章

经典10046剖析案例-2

经典10046剖析案例-5

经典10046剖析案例-3

回溯算法入门及经典案例剖析(初学者必备宝典)

高并发和海量数据下的 9 个 Redis 经典案例剖析!

高并发和海量数据下的 9 个 Redis 经典案例剖析!