第一篇 《oracle等待事件1分别用表和索引上数据的访问来产生db file scattered read等待事件》http://leonarding.blog.51cto.com/6045525/1105411
第二篇 《oracle等待事件2构造一个DB File Sequential Read等待事件和构造一个Direct Path Read等待事件》http://leonarding.blog.51cto.com/6045525/1105414
第三篇 《oracle等待事件3构造一个Direct Path write等待事件和构造一个Log File Sync等待事件》http://leonarding.blog.51cto.com/6045525/1105416
引言：其实等待事件我想大家都不会陌生，那么oracle研究出来等待事件是为了什么呢？它会告诉我们在什么情况数据库的性能是快还是慢，我们可以根据数据库在等待什么资源来进行性能优化（是否资源太忙 idle较多 latch争用严重 会话有阻塞了），解决方案例如是增加SGA 还是PGA 还是系统I/O等，我们在日常巡检的时候也要经常看看数据库等待事件来给oracle诊脉，是否超过了合理阀值，如果超过这时候就会有问题了，需要DBA出手干预。而有些是合理等待事件，这类等待事件是正常允许的，我们可以忽略，关键就是如何来区分是合理还是异常。
一 我们先从一个最简单的等待事件来进入oracle wait event world
实验环境
Oracle Database 11g Enterprise Edition Release 11.2.0.1.0 - 64bit Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
ORACLE_HOME = /u01/app/oracle/product/11.2.0/db_1
System name: Linux
Node name: leonarding1.oracle.com
Release: 2.6.32-200.13.1.el5uek
Version: #1 SMP Wed Jul 27 21:02:33 EDT 2011
Machine: x86_64
Instance name: LEO1
Redo thread mounted by this instance: 1
Oracle process number: 21
Unix process pid: 28039, image: oracle@leonarding1.oracle.com (TNS V1-V3)
搭建平台：Oracle 数据库性能优化艺术课程专用环境《VirtualBox+OELR5U7x86_64+Oracle11gR2》
http://f.dataguru.cn/forum.php?mod=viewthread&tid=31332&fromuid=303
LEO1@LEO1> select distinct sid from v$mystat; 我们要知道当前的会话id是什么，这样我们就可以在会话等待视图中查看对于id的等待事件是什么了
SID
-----------------
133
LEO1@LEO1> col wait_class for a10
LEO1@LEO1> col state for a15
LEO1@LEO1> select sid,event,wait_class,state,wait_time from v$session_wait;
SID EVENT WAIT_CLASS STATE WAIT_TIME
---------- ---------------------------------------------------------------- ---------- --------------- -------------------------
133 SQL*Net message to client Network WAITED SHORT TI -1
SQL*Net message to client 这是一个非常常见的等待事件，在oracle 11g中它算做一个短等待，当客户端与服务器建立起会话后，服务器就会等待客户端发送命令，如果此时没有命令传输就会产生这个等待事件。我们举个例子比较好理解
sqlplus leo1/leo1 我们通过sqlplus登录数据库，就会建立起会话，此时就会产生上述等待事件
pl/sql Developer 软件访问数据库（这也是客户端与服务器建立会话的过程），也会发生上述等待事件
SQL*Net（原来叫net8）是oracle自己的通信协议，只要安装了oracle客户端并通过客户端连接数据库就会走这个协议通信，当然就会产生基于这个协议的等待事件。（这个事件我们可以忽略）
二 分别用表和索引上数据的访问来产生db file scattered read等待事件，等待事件需要在v$session_wait和10046 trace文件中显示出来，贴出整个演示过程。
db file scattered read 等待事件：是由于多数据块读操作产生的，当我们检索数据时从磁盘上读数据到内存中，一次I/O读取多个数据块，而数据块在内存中是分散分布并不是连续的，当数据块读取到内存这个过程中会产生“db file scattered read”事件
多数据块读场景：FTS （full table scan） 全表扫描
IFFS （index fast full scan） 快速索引全扫描：把索引链切割成很多份，多块并行读取
LEO1@LEO1> drop table leo1 purge; 清理环境
Table dropped.
SYS@LEO1> show parameter memory_target SGA=652M
NAME TYPE VALUE
------------------------------------ ----------- ----------------------------------------------
memory_target big integer 652M
LEO1@LEO1> create table leo1 as select * from dba_objects; 创建一张新表没有索引
Table created.
LEO1@LEO1> select count(*) from leo1; 统计表数据71961行
COUNT(*)
--------------------
71961
LEO1@LEO1> set autotrace trace exp
FTS扫描
LEO1@LEO1> select count(*) from leo1; oracle进行FTS扫描
Execution Plan
----------------------------------------------------------
Plan hash value: 2716644435
--------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time |
--------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 75071 | 14M| 287 (1)| 00:00:04 |
| 1 | TABLE ACCESS FULL| LEO1 | 75071 | 14M| 287 (1)| 00:00:04 |
--------------------------------------------------------------------------
Note
-----
- dynamic sampling used for this statement (level=2)
由于这个动作非常的快，在v$session_wait视图中不容易捕捉到，其实我们还可以去10046事件中追踪一下看看
10046事件分析sql执行性能
解释：10046事件是发生在sql的执行过程中，它能够全面分析出sql执行过程和所消耗的资源，让你了解这条sql是否是最优的，10046事件有4个级别
LEVEL 1 等同于SQL_TRACE的功能
LEVEL 4 在LEVEL 1基础上增加绑定变量信息
LEVEL 8 在LEVEL 1基础上增加等待事件信息
LEVEL 12 等同于LEVEL 4+LEVEL 8，即有绑定变量信息又有等待事件信息
LEO1@LEO1> execute dbms_stats.gather_table_stats(ownname=>'LEO1',tabname=>'LEO1',cascade=>TRUE);
PL/SQL procedure successfully completed. 我们先做一个表分析，收集到更多的统计信息，方便10046正确评估
SYS@LEO1> alter system flush buffer_cache; 清空data_buffer_cache，好显示多块读效果
System altered.
LEO1@LEO1> alter session set events '10046 trace name context forever,level 12'; 启动10046事件定义级别12，这是最高级别，包括的信息最全面
LEO1@LEO1> select count(*) from leo1; FTS扫描
COUNT(*)
-------------------
71961
LEO1@LEO1> alter session set events '10046 trace name context off'; 关闭10046事件
Session altered.
[oracle@leonarding1 trace]$ pwd
/u01/app/oracle/diag/rdbms/leo1/LEO1/trace 11g 和 10g trace文件所在目录不同请注意
会话133
LEO1@LEO1> select name,value from v$diag_info where name='Default Trace File'; 当前会话写入trace文件名
NAME VALUE
-------------------------------------------------------- -------------------------------------------------------------------------------
Default Trace File /u01/app/oracle/diag/rdbms/leo1/LEO1/trace/LEO1_ora_28039.trc
LEO1@LEO1> !vim /u01/app/oracle/diag/rdbms/leo1/LEO1/trace/LEO1_ora_28039.trc 打开trace文件，选取部分有用信息
*** SESSION ID:(133.6542) 2012-12-27 23:51:54.342 会话133
*** MODULE NAME:(SQL*Plus) 2012-12-27 23:51:54.342 通过sqlplus登录
select count(*) from leo1
END OF STMT
PARSE #3:c=1000,e=1375,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=4191104944,tim=1356623522426980 解析资源
EXEC #3:c=0,e=71,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=4191104944,tim=1356623522427140 执行资源
WAIT #3: nam='SQL*Net message to client' ela= 12 driver id=1650815232 #bytes=1 p3=0 obj#=13482 tim=1356623522427305 第一个等待事件，原因上面已经都介绍了
WAIT #3: nam='Disk file operations I/O' ela= 49 FileOperation=2 fileno=5 filetype=2 obj#=73707 tim=1356623522427604
WAIT #3: nam='db file sequential read' ela= 19 file#=5 block#=1458 blocks=1 obj#=73707 tim=1356623522427658
WAIT #3: nam='db file scattered read' ela= 36 file#=5 block#=1459 blocks=5 obj#=73707 tim=1356623522427878
WAIT #3: nam='db file scattered read' ela= 35 file#=5 block#=1464 blocks=8 obj#=73707 tim=1356623522428146
WAIT #3: nam='db file scattered read' ela= 26 file#=5 block#=1473 blocks=7 obj#=73707 tim=1356623522428643
WAIT #3: nam='db file scattered read' ela= 27 file#=5 block#=1480 blocks=8 obj#=73707 tim=1356623522428908
WAIT #3: nam='db file scattered read' ela= 278 file#=5 block#=1489 blocks=7 obj#=73707 tim=1356623522429449
WAIT #3: nam='db file scattered read' ela= 28 file#=5 block#=1496 blocks=8 obj#=73707 tim=1356623522429728
参数解释：
File#：访问数据文件号
LEO1@LEO1> select file#,name from v$datafile where file#=5;
FILE# NAME
------------------------------------------------------------------------------------------------------------------------------------------
5 /u01/app/oracle/oradata/LEO1/leo1_01.dbf
Block#：访问起始数据块号
Blocks：读取了多少个数据块
例 1458+1=1459 –> 1459+5=1464 一直读取到1496号，可见这些数据块在文件中都是连续存放的，读取机制都是多块读，符合产生“db file scattered read”等待事件的条件
LEO1@LEO1> select sid,event,total_waits,time_waited from v$session_event; 显示累计会话等待事件统计信息
SID EVENT TOTAL_WAITS TIME_WAITED
---------- ---------------------------------------------------------------- ----------- ---------------
133 db file scattered read 31 0 等待了31次
可以看到这个会话生命周期中经历了哪些等待
小提示：当你长时间使用sqlplus登录数据库时在做上面的10046实验，你可能会发现在trace文件中只有SQL*Net message to client没有db file scattered read，解决方法是退出来重新登陆这样就可以看见db file scattered read了。
IFFS扫描
LEO1@LEO1> select distinct sid from v$mystat; 我的会话id还是133
SID
--------------------
133
LEO1@LEO1> create index idx_leo1 on leo1(object_id); 在表leo1字段object_id添加一个B-tree索引
Index created.
LEO1@LEO1> select table_name,index_name from user_indexes where table_name='LEO1';
TABLE_NAME INDEX_NAME
------------------------------ ------------------------------
LEO1 IDX_LEO1
LEO1@LEO1> execute dbms_stats.gather_table_stats(ownname=>'LEO1',tabname=>'LEO1',cascade=>TRUE);
PL/SQL procedure successfully completed.这次分析是把表和索引一起分析一遍，收集索引和表的统计信息，CBO评估
LEO1@LEO1> set autotrace trace exp
LEO1@LEO1> select count(object_id) from leo1; oracle进行IFFS扫描
Execution Plan
----------------------------------------------------------
Plan hash value: 1365721260
-----------------------------------------------------------------------------------------------------------------------------
| Id | Operation | Name | Rows | Bytes | Cost (%CPU)| Time
--------------------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 5 | 45 (0)| 00:00:01
| 1 | SORT AGGREGATE | | 1 | 5 | |
| 2 | INDEX FAST FULL SCAN| IDX_LEO1 | 71961 | 351K| 45 (0)| 00:00:01
-----------------------------------------------------------------------------------------------------------------------------
LEO1@LEO1> set autotrace off
当有索引之后就开始走IFFS快速索引全扫描了，原理是把这个索引链切割成多个区域，多块并行读取，既然是多块读那么也可以产生db file scattered read事件。
LEO1@LEO1> alter system flush buffer_cache; 再次清空data_buffer_cache
System altered.
LEO1@LEO1> set serveroutput on 打开屏幕输出
LEO1@LEO1> create or replace procedure p1 创建一个存储过程p1，循环3000次
as
leo number;
begin
for i in 1..3000
loop
select count(object_id) into leo from leo1;
end loop;
dbms_output.put_line('successfully');
end;
/
2 3 4 5 6 7 8 9 10 11
Procedure created.
LEO1@LEO1> alter system flush buffer_cache; 每次重新测试的时候一定要提前清空data_buffer_cache，因为如果数据已经在内存中那么就不会在去访问磁盘的文件了，也就发生不了“db file scattered read”这个等待事件，切记切记！
LEO1@LEO1> execute p1;
Successfully 当看到“successfully”表明这个p1执行完毕
PL/SQL procedure successfully completed.
会话157
LEO1@LEO1> select sid,event,wait_class,p1,p1text,p2,p2text,p3,p3text from v$session_wait where event like '% db file scattered read %';
SID EVENT WAIT_CLASS P1 P1TEXT P2 P2TEXT P3 P3TEXT
---------- ---------------------------------------------------------------- ----------------- ---------- ---------- ---------------
133 db file scattered read User I/O 5 file# 2562 block# 42 blocks
在157会话中当对133的存储过程p1执行过程中，马上查看v$session_wait视图，才能捕捉到“db file scattered read”，如果执行完毕了就看不到这个等待事件了，切记切记切记！
SID：133 会话号
EVENT：db file scattered read 等待事件名
P1：5 数据文件号
P1TEXT： 对p1参数的解释
P2：2562 访问起始数据块号
P2TEXT： 对p2参数的解释
P3：42 读取了42个数据块
P3TEXT： 对p3参数的解释
可知索引上数据的访问也会产生db file scattered read等待事件
LEO1@LEO1> alter system flush buffer_cache; 再次清空data_buffer_cache
System altered.
10046 trace文件中显示出来
LEO1@LEO1> alter session set events '10046 trace name context forever,level 12'; 启动10046事件
Session altered.
LEO1@LEO1> select count(object_id) from leo1; IFFS扫描
COUNT(OBJECT_ID)
---------------------------
71961
LEO1@LEO1> alter session set events '10046 trace name context off'; 关闭10046事件
Session altered.
LEO1@LEO1> select name,value from v$diag_info where name='Default Trace File'; 当前会话写入trace文件名
NAME VALUE
--------------------------------------------------------------------------------
Default Trace File /u01/app/oracle/diag/rdbms/leo1/LEO1/trace/LEO1_ora_6327.trc
LEO1@LEO1> !vim /u01/app/oracle/diag/rdbms/leo1/LEO1/trace/LEO1_ora_6327.trc 打开trace文件，看中间部分
PARSING IN CURSOR #2 len=33 dep=0 uid=85 oct=3 lid=85 tim=1356681643167307 hv=2452024216 ad='80fee680' sqlid='cvf96jk92duws' sql解析的资源
select count(object_id) from leo1
END OF STMT
PARSE #2:c=2000,e=1284,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=1365721260,tim=1356681643167301
EXEC #2:c=0,e=67,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=1,plh=1365721260,tim=1356681643167478
WAIT #2: nam='SQL*Net message to client' ela= 7 driver id=1650815232 #bytes=1 p3=0 obj#=0 tim=1356681643167583
sequential read：表示索引的入口（根 -> 分支 -> 叶子）逐步的深入，所以是顺序读
WAIT #2: nam='db file sequential read' ela= 20 file#=5 block#=7618 blocks=1 obj#=73708 tim=1356681643167705
scattered read：表示叶子批量多数据块读，数据块在文件中也是连续存放，可以一次读5块 8块 7块等
WAIT #2: nam='db file scattered read' ela= 100 file#=5 block#=7619 blocks=5 obj#=73708 tim=1356681643168128
WAIT #2: nam='db file scattered read' ela= 27 file#=5 block#=7624 blocks=8 obj#=73708 tim=1356681643168608
WAIT #2: nam='db file scattered read' ela= 30 file#=5 block#=7633 blocks=7 obj#=73708 tim=1356681643170140
WAIT #2: nam='db file scattered read' ela= 31 file#=5 block#=7640 blocks=8 obj#=73708 tim=1356681643170853
WAIT #2: nam='db file scattered read' ela= 25 file#=5 block#=7649 blocks=7 obj#=73708 tim=1356681643171787
WAIT #2: nam='db file scattered read' ela= 26 file#=5 block#=7656 blocks=8 obj#=73708 tim=1356681643172541
WAIT #2: nam='db file scattered read' ela= 28 file#=5 block#=7665 blocks=7 obj#=73708 tim=1356681643174215
WAIT #2: nam='db file scattered read' ela= 164 file#=5 block#=7672 blocks=8 obj#=73708 tim=1356681643175184
小结：可以看出不论FTS还是IFFS，只要走多数据块读就会产生“db file scattered read”等待事件，我们可以开多个并行来加快数据检索速度，尽量减少这种等待事件的发生，有资源消耗就会有等待事件，我们只能尽量减少而不可避免。
Leonarding
2012.12.28
天津&winter
分享技术~成就梦想
Blog：www.leonarding.com
扫一扫
7891
被折叠的 条评论
为什么被折叠?
到【灌水乐园】发言
