调优实践03–使用SQL_TRACE和10046事件跟踪SQL的执行

6月 15th, 2014
使用SQL_TRACE和10046事件跟踪SQL的执行

  1. 当在数据库中启动SQL_TRACE或者设置10046事件之后,Oracle将会启动内核跟踪程序,持续记录会话的相关信息,并写入到相应的trace文件中;跟踪记录的内容包括SQL的解析过程,执行计划,绑定变量的使用和会话中发生的等待事件等;
  2. SQL_TRACE和10046事件介绍:
    1. SQL_TRACE:
      1. 是一个静态的初始化参数,可以设置为TRUE/FALSE,用于开启/关闭SQL TRACE工具默认为FALSE;
      2. 设置SQL_TRACE=TRUE的话可以收集信息用于性能优化(DBMS_SYSTEM包可以实现相同的功能),但是对数据库会产生严重的性能问题,生产环境一定不要打开此参数,如果一定要在全局打开,要做到以下几点:
        1. 保证25%的CPU idle;
        2. 为USER_DUMP_DEST分配足够的空间:ALTER SYSTEM SET max_dump_file_size=UNLIMITED;
        3. 条带化磁盘,减轻IO负担;
        4. 设置timed_statistics打开:ALTER SYSTEM SET timed_statistics=TRUE;
      3. 打开SQL_TRACE功能:
        1. 全局打开:ALTER SYSTEM SET SQL_TRACE=TRUE SCOPE=SPFILE;重启数据库服务,会跟踪所有进程的活动,包括用户进程和后台进程;可以通过跟踪文件的实时变化来分析各个进程之间的协作关系;
        2. Session级别打开:ALTER SESSION SET SQL_TRACE=TRUE/FALSE;通过跟踪当前进程,来发现后台数据库的递归活动,用于研究SQL执行和发现后台错误等;
        3. 如果要跟踪其它用户的进程,可以通过DBMS_SYSTEM.SET_SQL_TRACE_IN_SESSION来完成,所需要的sid和serial#参数可以通过v$session视图查看得到;
        4. 如果要针对其它用户的参数进行设置,可以通过DBMS_SYSTEM.SET_INI_PARAM_IN_SESSION过程或者DBMS_SYSTEM.SET_BOOL_PARAM_IN_SESSION过程来完成;
      4. 其它方式:EXEC DBMS_SESSION.SET_SQL_TRACE(sql_trace=>TRUE/FALSE);
    2. 10046事件:
      1. 是Oracle提供的内部事件,是对SQL_TRACE的增强;
      2. 10046分为四个级别:
        1. level 1:启用标准的sql_trace功能,等于sql_trace(包含了SQL语句,响应事件,服务时间,处理的行数,物理读和写的数目,执行计划以及其它一些额外信息);
        2. level 4:level 1加上绑定值;
        3. level 8:level 1加上等待事件;
        4. level 12:level 1 + level 4 + level 8;
      3. 设置10046事件:
        1. 全局开启:在spfile中添加events=”10046 trace name context forever, level 12″:ALTER SYSTEM SET EVENTS ‘10046 trace name context forever, level 12’;
        2. 全局关闭:ALTER SYSTEM SET EVENTS ‘10046 trace name context off’;
        3. 针对当前session的开启:ALTER SESSION SET EVENTS ‘10046 trace name context forever, level 12’;
        4. 针对当前session的关闭:ALTER SESSION SET EVENTS ‘10046 trace name context off’;
        5. 针对其它用户session的开启:使用DBMS_SYSTEM.SET_EV(si in integer, se in integer, ev in integer, le in integer, nm in varchar):EXEC DBMS_SYSTEM.SET_EV(38,25,10046,12,’HR’);
          1. si:sid;
          2. se:serial#;
          3. ev:event number;
          4. le:level;
          5. nm:username;
          6. 可以通过v$session视图查询:SELECT sid, serial#, username FROM v$session WHERE username IS NOT NULL;
        6. 针对其它用户session的关闭:EXEC DBMS_SYSTEM.SET_EV(38,25,10046,0,’HR’);
    3. 也可以使用oradebug工具或者DBMS_MONITOR包;
    4. 获取跟踪文件的脚本;
    5. 获取当前session设置的参数的脚本;
  3. 实例分析步骤:
    1. 隐式转换与索引失效:
      1. 问题描述:反应前端程序某个功能非常慢;
      2. 首先检查并跟踪数据库进程:SELECT sid, serial#, username FROM v$session WHERE username IS NOT NULL AND username <> ‘SYS’;
      3. 然后对这几个进程开启sql trace:EXEC dbms_system.set_sql_trace_in_session(sid, serial#, TRUE);等待一段时间后关闭:EXEC dbms_system.set_sql_trace_in_session(sid, serial#, FALSE);
      4. 针对产生的trace文件使用tkprof工具进行格式化,然后查看内容;
      5. 一般发生索引失效或者是隐式转换的话就会发现返回少量的数据但是却产生特别多的物理读(也有可能是汇总操作);
      6. 可以查看关键列的索引和索引列的类型:SELECT index_name, table_name, column_name FROM user_ind_columns WHERE table_name = upper(‘tb_name’);DESC tb_name;
      7. 然后可以针对发现的问题做相应的处理,比如创建索引,手动处理隐式转换等问题;
    2. 对数据库进行操作时(如drop table/user)发生错误:
      1. 问题描述:对数据库操作后发生了ORA错误;
      2. 首先在当前的会话开启一个标识符:ALTER SESSION SET TRACEFILE_IDENTIFIER='<TRACEFILE_IDENTIFIER>’;
      3. 然后打开sql trace功能:ALTER SESSION SET SQL_TRACE=TRUE;
      4. 重现错误,即再执行当前操作;
      5. 关闭sql trace功能;
      6. 然后查看trace文件,找到具体的错误并解决;
  4. 10046查看等待事件的例子;
  5. db_file_multiblock_read_count:
    1. 表示全表扫描时,ORACLE一次I/O可以读取的数据库的数据块数,Oracle的一次I/O操作不能跨extent;
    2. 最大值为((max OS I/O size)/db_block_size),一般操作系统一次I/O最大读取1M,db_block_size=8k,所以这个参数最大为128;
    3. 这个参数也会受到SSTIOMAX的参数影响,这是一个内核参数,不能被修改,同时db_file_multiblock_read_count也不能超过db_block_buffer/4;
    4. 在OLTP系统中一般设置为4-16,在DSS系统中可以根据需要设置更大的值;
    5. 增大db_file_multiblock_read_count参数会使全表扫面的成本降低,但是在CBO下,Oracle会更倾向于使用全表扫面而不是索引扫描,db_file_multiblock_read_count与执行计划选择的例子;
  6. 为什么要使用10046事件:
    1. 10046事件可以帮助我们解析SQL语句的运行状态(包括Parse/Fetch/Execute三个阶段中遇到的等待事件,消耗的物理和逻辑读,CPU时间,执行计划等等);
    2. 即10046为我们揭示了SQL语句的运行情况,对于以点入手的SQL调优是很好的辅助工具,特别是在10g之前没有ASH的情况下;但整体系统调优不是10046所擅长的,需要用到AWR;
    3. 10046还能帮助我们分析一些DDL维护命令的内部工作原理,比如RMAN,expdp/impdp等工具的缓慢问题等;
  7. 10046事件和10053事件的区别:
    1. 10053事件是最常用的Oracle优化器optimizer跟踪trace,10053可以作为我们解释优化器为什么选择某个执行计划,但并不告诉我们这个执行计划到底运行地如何;
    2. 10046并不解释optimizer优化器的工作,但它同样说明了在SQL解析parse阶段所遇到的等待事件和所消耗的CPU等资源,以及Execute执行和Fetch阶段的各项指标;
    3. 简而言之10046告诉我们SQL(执行计划)运行地如何,10053告诉我们优化器为什么为这个SQL选择某个执行计划;
  8. 10046跟踪文件的阅读;
———————————– 获取跟踪文件的脚本 ———————————–
— 1.解析阶段;
PARSING IN CURSOR #11328540 len=56 dep=0 uid=84 oct=3 lid=84 tim=1396508012619901 hv=3963517665 ad=’4464298c’ sqlid=’25vmrurq3wyr1′
SELECT COUNT(*) FROM HR.EMPLOYEES WHERE DEPARTMENT_ID=20
END OF STMT
PARSE #11328540:c=6999,e=6974,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=2271004725,tim=1396508012619893
PARSING
1.#11328540:表示游标号,非常重要,后面的PARSE,EXEC,WAIT,FETCH,STAT,CLOSE阶段都需要使用这个游标号和前面的sql关联起来;
2.这个过程之后可能会产生很多的递归sql,一般是用来查询一些数据字典的,所消耗的资源和时间都非常的少;
3.len=56:表示sql的长度;
4.dep=0:表示Recursive Depth,即sql递归的深度;如果为0表示不是递归sql,如果大于0表示递归sql;
5.uid=84:表示解析这个游标的用户的UID,如果是0表示是sys;通过dba_users/user$查看;
6.oct=3:表示Oracle Command Type,即Oracle中的命令类型,与v$sql中的command_type列对应,可以通过查询v$sqlcommand视图查看具体的定义;
7.lid=84:表示Privilege User Id,即权限用户ID;
8.tim:表示timestamp时间戳,9i之后单位是ms,用来判断trace中两个点的时间差;来自v$timer视图,一个Oracle的内部时钟;
9.hv:表示sql的hash value,10g之前没有sqlid就使用hash value来定位一个sql;
10.ad:表示sqltext的地址,来自于v$sql的address列;
11.sqlid:表示对应的sql id;
12.err:如果有错误的话,代表错误代码,可以通过oerr ora xxx;
PARSE:是sql运行的第一个阶段,解析SQL语句;
1.c:表示cpu time,即消耗cpu的时间,9i之后单位是ms;
2.e:表示elapsed time,即消耗的自然时间,9i之后单位是ms;
3.p:表示physcial read,即物理的数目;
4.cr:表示consist read,即一致性读引起的buffer get数目;
5.cu:表示current read,即当前读取引起的buffer get数目;
6.mis:表示读取library cache的miss的数目,如果=0的话表示使用软解析或者更好的方式;如果大于0表示发生了硬结析;
7.r:表示rows,即处理的行数;
8.dep:表示Recursive Depth,即sql递归的深度;如果为0表示不是递归sql,如果大于0表示递归sql;
9.og:表示optimizer_mode,对应关系为:0-游标不可见/优化器环境未合理创建;1-ALL_ROWS;2-FIRST_ROWS;3-RULE;4-CHOOSE;
EXEC:sql运行的第二个阶段,执行sql语句;
FETCH:从游标中fetch数据行;
UNMAP:当游标使用临时表时,若游标关闭则使用UNMAP释放临时表相关的资源;
— 2.执行阶段;
EXEC #11328540:c=0,e=102,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=2271004725,tim=1396508012620426
— 3.相关的等待;

WAIT #11328540: nam=’db file sequential read’ ela= 25707 file#=5 block#=243 blocks=1 obj#=76349 tim=1396508012647378
1.Nam:等待针对的事件名字,它的P1/P2/P3可以参考视图V$EVENT_NAME,也可以从V$SESSION/ASH中观察到等待事件;
2.ela:本操作的耗时,单位是ms;
3.p1,p2,p3:针对该事件的三个描述参数,见V$EVENT_NAME;
4.obj#:相关的对象id;
— 4.获取数据;

FETCH #11328540:c=4000,e=27513,p=1,cr=1,cu=0,mis=0,r=1,dep=0,og=1,plh=2271004725,tim=1396508012648208
— 5.相关的统计;
STAT #11328540 id=1 cnt=1 pid=0 pos=1 obj=0 op=’SORT AGGREGATE (cr=1 pr=1 pw=0 time=27520 us)’
STAT #11328540 id=2 cnt=2 pid=1 pos=1 obj=76349 op=’INDEX RANGE SCAN EMP_DEPARTMENT_IX (cr=1 pr=1 pw=0 time=27485 us cost=1 size=6 car
d=2)’
STAT:相关行反应解释执行计划的统计信息
1.id:执行计划的行数,从1开始;
2.cnt:该数据源的行数;
3.pid:该数据源的父ID;
4.pos:在执行计划中的位置;
5.obj:对应数据源的object id;
6.op:数据源的访问操作,例如FULL TABLE SCAN;
7.cr:代表一致性读的数量
8.pr:代表物理读的数量
9.pw:代表物理写的数量
10.time:单位为ms,本步骤的耗时间;
11.cost:本操作的优化器成本;
12.size:评估的数据源大小,单位为字节;
13.card:评估的优化器基数Cardinality;
— 6.关闭游标;

CLOSE #11328540:c=0,e=21,dep=0,type=0,tim=1396508016737280

CLOSE:关闭游标;
type:关闭游标的操作类型;
0-该游标从未被缓存且执行次数小于3次,也叫hard close;
1-该游标从未被缓存但执行次数至少3次,若在session cached cursor中有free slot,则将该游标放入session cached cursor;
2-该游标从未被缓存但执行次数至少3次,该游标置入session cached cursor的条件是讲老的缓存age out掉;
3-该游标已经在缓存里;
— 7.其它,如果有绑定变量的话;
BINDS:
1.kkscoacd:是绑定变量相关的描述符;
2.Bind#0:说明是第0个变量;
3.oacdty:data type,96是ANSI fixed char;
4.oacflg:代表绑定选项的特殊标志位;
5.size:为该内存chunk分配的内存大小;
6.mxl:绑定变量的最大长度;
7.pre:precision;
8.scl:Scale;
9.kxsbbbfp:buffer point;
10.bln:bind buffer length;
11.avl:实际的值的长度;
12.flg:代表绑定状态;
13.value:实际的绑定值;
———————————– 获取跟踪文件的脚本 ———————————–
———————————– 获取跟踪文件的脚本 ———————————–
SELECT a.VALUE || b.symbol || c.instance_name || ‘_ora_’ || d.spid || ‘.trc’ trace_file
FROM (SELECT VALUE FROM v$parameter WHERE NAME = ‘user_dump_dest’) a,
(SELECT substr(VALUE, -6, 1) symbol FROM v$parameter WHERE NAME = ‘user_dump_dest’) b,
(SELECT instance_name FROM v$instance) c,
(SELECT spid
FROM v$session s, v$process p, v$mystat m
WHERE s.paddr = p.addr AND
s.sid = m.sid AND
m.statistic# = 0) d;
11g later:SELECT VALUE FROM v$diag_info WHERE NAME = ‘Default Trace File’;

———————————– 获取跟踪文件的脚本 ———————————–
———————————– 获取当前session设置的参数的脚本 ———————————–

DECLARE
event_level NUMBER;
BEGIN
FOR event_number IN 10000 .. 10999 LOOP
sys.dbms_system.read_ev(event_number, event_level);
IF (event_level > 0) THEN
sys.dbms_output.put_line(‘Event ‘ || to_char(event_number) || ‘ is set at level ‘ || to_char(event_level));
END IF;
END LOOP;
END;

———————————– 获取当前session设置的参数的脚本 ———————————–
———————————– 10046查看等待事件的例子 ———————————–
— 1.查看系统参数;
show parameter db_block_size; — 8192;
show parameter db_file_multiblock_read_count; — 128;
SELECT tablespace_name, block_size, initial_extent / block_size, next_extent / block_size
FROM dba_tablespaces
WHERE tablespace_name IN (‘SYSTEM’, ‘TBS32B’);
SYSTEM     8192     8
TBS32B     8192     32     32
— 2.创建一个测试表;
sqlplus / as sysdba
CREATE TABLE TB10046 AS SELECT * FROM dba_objects;
SELECT file_id, block_id, blocks FROM dba_extents WHERE segment_name = ‘TB10046’;
   FILE_ID   BLOCK_ID     BLOCKS
———- ———- ———-
1      93784          8
1      93792          8
1      93800          8
1      93808          8
1      93816          8
1     104832          8
1     104840          8
1     104848          8
1     104856          8
1     104864          8
1     104872          8

FILE_ID   BLOCK_ID     BLOCKS
———- ———- ———-
1     104880          8
1     104888          8
1     104896          8
1     104904          8
1     104912          8
1     104960        128
1     105088        128
1     105216        128
1     105344        128
1     105472        128
1     105600        128

FILE_ID   BLOCK_ID     BLOCKS
———- ———- ———-
1     105728        128
1     105856        128

24 rows selected.

— 3.生成trace文件;
ALTER SESSION SET TRACEFILE_IDENTIFIER=’t1′;
ALTER SESSION SET EVENTS ‘10046 trace name context forever, level 12’;
SELECT event, total_waits FROM V$system_EVENT WHERE EVENT = ‘db file scattered read’; — 146913315
SELECT COUNT(*) FROM TB10046; — 发生全表扫描;
SELECT event, total_waits FROM V$system_EVENT WHERE EVENT = ‘db file scattered read’; — 146913412
— 4.查看trace文件,发现一次读取8个blocks,因为扫描不能跨extent,此时一个extent中是8个块;(trace中的file#,block#和blocks是与等待事件中参数一一对应的:SELECT NAME, parameter1, parameter2, parameter3 FROM v$event_name WHERE NAME = ‘db file scattered read’;)
WAIT #1: nam=’db file scattered read’ ela= 82 file#=1 block#=104961 blocks=8 obj#=95923 tim=1389859838564653
WAIT #1: nam=’db file scattered read’ ela= 66 file#=1 block#=104986 blocks=8 obj#=95923 tim=1389859838565112
WAIT #1: nam=’db file scattered read’ ela= 64 file#=1 block#=105009 blocks=8 obj#=95923 tim=1389859838565556
WAIT #1: nam=’db file scattered read’ ela= 65 file#=1 block#=105017 blocks=8 obj#=95923 tim=1389859838565951
WAIT #1: nam=’db file scattered read’ ela= 66 file#=1 block#=105059 blocks=8 obj#=95923 tim=1389859838566301
WAIT #1: nam=’db file scattered read’ ela= 77 file#=1 block#=105070 blocks=8 obj#=95923 tim=1389859838566646
WAIT #1: nam=’db file scattered read’ ela= 62 file#=1 block#=105106 blocks=8 obj#=95923 tim=1389859838567210
WAIT #1: nam=’db file scattered read’ ela= 65 file#=1 block#=105118 blocks=8 obj#=95923 tim=1389859838567565
WAIT #1: nam=’db file scattered read’ ela= 71 file#=1 block#=105163 blocks=8 obj#=95923 tim=1389859838567961
WAIT #1: nam=’db file scattered read’ ela= 65 file#=1 block#=105185 blocks=8 obj#=95923 tim=1389859838568283
WAIT #1: nam=’db file scattered read’ ela= 65 file#=1 block#=105200 blocks=8 obj#=95923 tim=1389859838568635
WAIT #1: nam=’db file scattered read’ ela= 68 file#=1 block#=105226 blocks=8 obj#=95923 tim=1389859838568997
WAIT #1: nam=’db file scattered read’ ela= 65 file#=1 block#=105236 blocks=8 obj#=95923 tim=1389859838569331
WAIT #1: nam=’db file scattered read’ ela= 67 file#=1 block#=105264 blocks=8 obj#=95923 tim=1389859838569659
WAIT #1: nam=’db file scattered read’ ela= 67 file#=1 block#=105291 blocks=8 obj#=95923 tim=1389859838569972
WAIT #1: nam=’db file scattered read’ ela= 65 file#=1 block#=105303 blocks=8 obj#=95923 tim=1389859838570278
WAIT #1: nam=’db file scattered read’ ela= 79 file#=1 block#=105325 blocks=8 obj#=95923 tim=1389859838570640
WAIT #1: nam=’db file scattered read’ ela= 63 file#=1 block#=105371 blocks=8 obj#=95923 tim=1389859838571135
WAIT #1: nam=’db file scattered read’ ela= 65 file#=1 block#=105425 blocks=8 obj#=95923 tim=1389859838571486
WAIT #1: nam=’db file scattered read’ ela= 69 file#=1 block#=105474 blocks=8 obj#=95923 tim=1389859838571855
WAIT #1: nam=’db file scattered read’ ela= 65 file#=1 block#=105516 blocks=8 obj#=95923 tim=1389859838572204
WAIT #1: nam=’db file scattered read’ ela= 64 file#=1 block#=105528 blocks=8 obj#=95923 tim=1389859838572530
WAIT #1: nam=’db file scattered read’ ela= 66 file#=1 block#=105601 blocks=8 obj#=95923 tim=1389859838572887
WAIT #1: nam=’db file scattered read’ ela= 65 file#=1 block#=105617 blocks=8 obj#=95923 tim=1389859838573215
WAIT #1: nam=’db file scattered read’ ela= 65 file#=1 block#=105644 blocks=8 obj#=95923 tim=1389859838573561
WAIT #1: nam=’db file scattered read’ ela= 64 file#=1 block#=105676 blocks=8 obj#=95923 tim=1389859838573917
WAIT #1: nam=’db file scattered read’ ela= 66 file#=1 block#=105700 blocks=8 obj#=95923 tim=1389859838574251
WAIT #1: nam=’db file scattered read’ ela= 66 file#=1 block#=105712 blocks=8 obj#=95923 tim=1389859838574650
WAIT #1: nam=’db file scattered read’ ela= 64 file#=1 block#=105759 blocks=8 obj#=95923 tim=1389859838575214
WAIT #1: nam=’db file scattered read’ ela= 66 file#=1 block#=105779 blocks=8 obj#=95923 tim=1389859838575545
WAIT #1: nam=’db file scattered read’ ela= 65 file#=1 block#=105795 blocks=8 obj#=95923 tim=1389859838575886
WAIT #1: nam=’db file scattered read’ ela= 65 file#=1 block#=105820 blocks=8 obj#=95923 tim=1389859838576234
WAIT #1: nam=’db file scattered read’ ela= 63 file#=1 block#=105828 blocks=8 obj#=95923 tim=1389859838576565
WAIT #1: nam=’db file scattered read’ ela= 65 file#=1 block#=105842 blocks=8 obj#=95923 tim=1389859838576902
WAIT #1: nam=’db file scattered read’ ela= 64 file#=1 block#=105871 blocks=8 obj#=95923 tim=1389859838577386
WAIT #1: nam=’db file scattered read’ ela= 66 file#=1 block#=105879 blocks=8 obj#=95923 tim=1389859838577723
— 5.创建一个256k大小extent的表空间,即一个extent可以存放32个块;
CREATE TABLESPACE TBS32B DATAFILE ‘/u01/app/oracle/oradata/ORCL/tbs32b.dbf’ SIZE 50M AUTOEXTEND ON MAXSIZE UNLIMITED EXTENT MANAGEMENT LOCAL UNIFORM SIZE 256K;
ALTER TABLE TB10046 MOVE TABLESPACE TBS32B;
SELECT file_id, block_id, blocks FROM dba_extents WHERE segment_name = ‘TB10046’;
   FILE_ID   BLOCK_ID     BLOCKS
———- ———- ———-
8        128         32
8        160         32
8        192         32
8        224         32
8        256         32
8        288         32
8        320         32
8        352         32
8        384         32
8        416         32
8        448         32

FILE_ID   BLOCK_ID     BLOCKS
———- ———- ———-
8        480         32
8        512         32
8        544         32
8        576         32
8        608         32
8        640         32
8        672         32
8        704         32
8        736         32
8        768         32
8        800         32

FILE_ID   BLOCK_ID     BLOCKS
———- ———- ———-
8        832         32
8        864         32
8        896         32
8        928         32
8        960         32
8        992         32
8       1024         32
8       1056         32
8       1088         32
8       1120         32
8       1152         32

FILE_ID   BLOCK_ID     BLOCKS
———- ———- ———-
8       1184         32
8       1216         32

35 rows selected.

ALTER SYSTEM FLUSH BUFFER_CACHE;
ALTER SESSION SET TRACEFILE_IDENTIFIER=’t2′;
ALTER SESSION SET EVENTS ‘10046 trace name context forever, level 12’;
SELECT COUNT(*) FROM TB10046; — 发生全表扫描;
— 6.查看trace文件,发现一次读取32个blocks;
WAIT #1: nam=’db file scattered read’ ela= 114 file#=8 block#=132 blocks=28 obj#=95923 tim=1389860294615193
WAIT #1: nam=’db file scattered read’ ela= 118 file#=8 block#=162 blocks=30 obj#=95923 tim=1389860294616423
WAIT #1: nam=’db file scattered read’ ela= 109 file#=8 block#=194 blocks=30 obj#=95923 tim=1389860294617528
WAIT #1: nam=’db file scattered read’ ela= 111 file#=8 block#=225 blocks=31 obj#=95923 tim=1389860294618635
WAIT #1: nam=’db file scattered read’ ela= 117 file#=8 block#=256 blocks=32 obj#=95923 tim=1389860294619776
WAIT #1: nam=’db file scattered read’ ela= 133 file#=8 block#=289 blocks=31 obj#=95923 tim=1389860294620942
WAIT #1: nam=’db file scattered read’ ela= 142 file#=8 block#=320 blocks=32 obj#=95923 tim=1389860294622095
WAIT #1: nam=’db file scattered read’ ela= 115 file#=8 block#=353 blocks=31 obj#=95923 tim=1389860294623268
WAIT #1: nam=’db file scattered read’ ela= 117 file#=8 block#=384 blocks=32 obj#=95923 tim=1389860294624399
WAIT #1: nam=’db file scattered read’ ela= 113 file#=8 block#=417 blocks=31 obj#=95923 tim=1389860294625493
WAIT #1: nam=’db file scattered read’ ela= 114 file#=8 block#=448 blocks=32 obj#=95923 tim=1389860294626569
WAIT #1: nam=’db file scattered read’ ela= 112 file#=8 block#=481 blocks=31 obj#=95923 tim=1389860294627654
WAIT #1: nam=’db file scattered read’ ela= 117 file#=8 block#=512 blocks=32 obj#=95923 tim=1389860294628730
WAIT #1: nam=’db file scattered read’ ela= 113 file#=8 block#=545 blocks=31 obj#=95923 tim=1389860294629788
WAIT #1: nam=’db file scattered read’ ela= 139 file#=8 block#=576 blocks=32 obj#=95923 tim=1389860294631207
WAIT #1: nam=’db file scattered read’ ela= 123 file#=8 block#=609 blocks=31 obj#=95923 tim=1389860294632340
WAIT #1: nam=’db file scattered read’ ela= 191 file#=8 block#=640 blocks=32 obj#=95923 tim=1389860294633470
WAIT #1: nam=’db file scattered read’ ela= 193 file#=8 block#=673 blocks=31 obj#=95923 tim=1389860294634671
WAIT #1: nam=’db file scattered read’ ela= 131 file#=8 block#=704 blocks=32 obj#=95923 tim=1389860294635781
WAIT #1: nam=’db file scattered read’ ela= 119 file#=8 block#=737 blocks=31 obj#=95923 tim=1389860294636852
WAIT #1: nam=’db file scattered read’ ela= 125 file#=8 block#=768 blocks=32 obj#=95923 tim=1389860294637924
WAIT #1: nam=’db file scattered read’ ela= 126 file#=8 block#=801 blocks=31 obj#=95923 tim=1389860294638974
WAIT #1: nam=’db file scattered read’ ela= 119 file#=8 block#=832 blocks=32 obj#=95923 tim=1389860294640007
WAIT #1: nam=’db file scattered read’ ela= 123 file#=8 block#=865 blocks=31 obj#=95923 tim=1389860294641040
WAIT #1: nam=’db file scattered read’ ela= 116 file#=8 block#=896 blocks=32 obj#=95923 tim=1389860294642112
WAIT #1: nam=’db file scattered read’ ela= 114 file#=8 block#=929 blocks=31 obj#=95923 tim=1389860294643170
WAIT #1: nam=’db file scattered read’ ela= 135 file#=8 block#=960 blocks=32 obj#=95923 tim=1389860294644287
WAIT #1: nam=’db file scattered read’ ela= 183 file#=8 block#=993 blocks=31 obj#=95923 tim=1389860294645459
WAIT #1: nam=’db file scattered read’ ela= 131 file#=8 block#=1024 blocks=32 obj#=95923 tim=1389860294646588
WAIT #1: nam=’db file scattered read’ ela= 116 file#=8 block#=1057 blocks=31 obj#=95923 tim=1389860294647669
WAIT #1: nam=’db file scattered read’ ela= 116 file#=8 block#=1088 blocks=32 obj#=95923 tim=1389860294648735
WAIT #1: nam=’db file scattered read’ ela= 114 file#=8 block#=1121 blocks=31 obj#=95923 tim=1389860294649806
WAIT #1: nam=’db file scattered read’ ela= 119 file#=8 block#=1152 blocks=32 obj#=95923 tim=1389860294650864
WAIT #1: nam=’db file scattered read’ ela= 113 file#=8 block#=1185 blocks=31 obj#=95923 tim=1389860294651919
———————————– 10046查看等待事件的例子 ———————————–
———————————– db_file_multiblock_read_count与执行计划选择的例子 ———————————–
— 1.准备工作;
SELECT owner, count(*) FROM TB10046 GROUP BY owner ORDER BY 2;

OWNER                            COUNT(*)
—————————— ———-
OWBSYS                                  2
APPQOSSYS                               3
SCOTT                                   6
ORACLE_OCM                              8
SI_INFORMTN_SCHEMA                      8
BI                                      8
OUTLN                                   9
ORDPLUGINS                             10
OWBSYS_AUDIT                           12
FLOWS_FILES                            12
PM                                     27

OWNER                            COUNT(*)
—————————— ———-
HR                                     34
IX                                     55
DBSNMP                                 65
OE                                    127
ORDDATA                               248
SH                                    306
EXFSYS                                310
WMSYS                                 316
CTXSYS                                366
SYSTEM                                529
OLAPSYS                               719

OWNER                            COUNT(*)
—————————— ———-
XDB                                   844
MDSYS                                1509
PV                                   2161
APEX_030200                          2406
ORDSYS                               2532
SYSMAN                               3491
PUBLIC                              27702
SYS                                 31132

30 rows selected.

CREATE INDEX IDX_TB10046_HR ON TB10046(owner);

EXEC DBMS_STATS.GATHER_TABLE_STATS(USER, ‘TB10046’, cascade=>TRUE);
— 2.设置db_file_multiblock_read_count参数为8,查看表的执行计划;
ALTER SYSTEM SET db_file_multiblock_read_count=8;
SET AUTOT TRACE EXP;
SQL> SELECT * FROM tb10046 WHERE OWNER=’SYSMAN’;
Execution Plan
———————————————————-
Plan hash value: 3379381082

——————————————————————————–
————–

| Id  | Operation                   | Name           | Rows  | Bytes | Cost (%CP
U)| Time     |

——————————————————————————–
————–

|   0 | SELECT STATEMENT            |                |  3268 |   315K|    95   (
0)| 00:00:02 |

|   1 |  TABLE ACCESS BY INDEX ROWID| TB10046        |  3268 |   315K|    95   (
0)| 00:00:02 |

|*  2 |   INDEX RANGE SCAN          | IDX_TB10046_HR |  3268 |       |     8   (
0)| 00:00:01 |

——————————————————————————–
————–

Predicate Information (identified by operation id):
—————————————————

2 – access(“OWNER”=’SYSMAN’)

— 3.设置db_file_multiblock_read_count参数为128,查看表的执行计划;
ALTER SYSTEM SET db_file_multiblock_read_count=;128
SQL> SELECT * FROM tb10046 WHERE OWNER=’SYSMAN’;
Execution Plan
———————————————————-
Plan hash value: 3237706262

—————————————————————————–
| Id  | Operation         | Name    | Rows  | Bytes | Cost (%CPU)| Time     |
—————————————————————————–
|   0 | SELECT STATEMENT  |         | 3268  |   315K|    99   (1)| 00:00:03 |

|*  1 |  TABLE ACCESS FULL| TB10046 | 3268  |   315K|    99   (1)| 00:00:03 |
—————————————————————————–

Predicate Information (identified by operation id):
—————————————————

1 – filter(“OWNER”=’SYSMAN’)

———————————– db_file_multiblock_read_count与执行计划选择的例子 ———————————–
标签:
本文的评论功能被关闭了.