第一篇 《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
Dear All:
历经5天的oracle等待事件系列大功告成，不容易a多少个不眠之夜，多少次无尽猜想，在此做首打油诗留念
《2012终日有感》
壮志未酬oracle
夜点明灯苦用功
只为不白少年头
报答老师抱mm
五 构造一个Direct Path write等待事件，等待事件需要在v$session_wait和10046 trace文件中显示出来，贴出整个演示过程。
Direct path write 等待事件：发生在“写入磁盘”的时候，因为写也是一种中间状态，只要是中间状态数据就没有必要共享给其他用户，所以这些数据也不会放在SGA中共享，从PGA中 -> 直接写入 -> 磁盘。
场景： append方式插入数据，这种方式插入数据的时候会跳过SGA的data_buffer_cache，直接插入数据文件，并且还不会扫描数据文件中的空闲空间直接插入到文件尾所以效率较高
当数据排序时候，如果PGA被装满，就会被写入到磁盘的temp表空间里，因为排序的数据是中间状态也不会经过SGA，所以会产生“direct path write”等待事件
LEO1@LEO1> select table_name,index_name from user_indexes where table_name='LEO1'; 利用leo1表
TABLE_NAME INDEX_NAME
------------------------------ -------------------------------------------
LEO1 IDX_LEO1
LEO1@LEO1> select count(*) from leo1; 有71959行记录
COUNT(*)
------------------
71959
LEO1@LEO1> execute dbms_stats.gather_table_stats(ownname=>'LEO1',tabname=>'LEO1',cascade=>TRUE);
PL/SQL procedure successfully completed. 统计分析
v$session_wait视图中显示出来
LEO1@LEO1> set serveroutput on
LEO1@LEO1> create or replace procedure p4
as
begin
for i in 1..8
loop
insert /*+ append */ into leo1 select * from leo1;
rollback;
end loop;
dbms_output.put_line('successfully');
end;
/
2 3 4 5 6 7 8 9 10 11
Procedure created.
创建存储过程p4循环8次，添加了append hint执行直接插入，在这个期间会发生“direct path write”等待事件
Append 注意事项
Append方式叫做直接路径加载，使用这种方式是因为oracle不会在扫描freelist链表中的空闲块，直接在高水线之后插入数据，所以速度比较快。
（1）append方式不记录redo，一旦在插入的过程中没有保存到磁盘或者发生掉电情况那么插入的数据不能恢复
（2）由于不在利用表的空闲空间，那么这种方式比较浪费存储空间，就是以空间换时间
（3）insert /*+ append */ into leo1 select * from leo1;会对这个表添加一个6级锁，意味着在没有commit/rollback前提下任何会话 insert update delete select 等操作都不允许，否则会报错
ORA-12838: cannot read/modify an object after modifying it in parallel
解释如下：
ORA-12838 cannot read/modify an object after modifying it in parallel
Cause: Within the same transaction, an attempt was made to add read or modification statements on a table after it had been modified in parallel or with direct load. This is not permitted.
Action: Rewrite the transaction, or break it up into two transactions: one containing the initial modification and the second containing the parallel modification operation
会话133
LEO1@LEO1> execute p4; 当看到“successfully”表明这个p4执行完毕
successfully
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 '%direct%';
SID EVENT WAIT_CLASS P1 P1TEXT P2 P2TEXT P3 P3TEXT
---------- ---------------------------------------------------------------- ---------- ---------- ---------- ---------- --------------- ---------- ---------------
133 direct path write User I/O 5 file numbe 10528 first dba 32 block cnt
133 direct path write User I/O 5 file numbe 11232 first dba 32 block cnt
P1：写入的数据文件 即 5号数据文件
P2：写入起始数据块号 即 10528 11232号数据块
P3：写入了多少个数据块 即 32个数据块
同理
会话133
LEO1@LEO1> create or replace procedure p5
as
begin
for i in 1..5
loop
insert /*+ append */ into leo1 select * from leo1 order by object_name;
rollback;
end loop;
dbms_output.put_line('successfully');
end;
/
2 3 4 5 6 7 8 9 10 11
Procedure created.
创建存储过程p5循环5次，先进行order by操作在插入，这会就有更多的“direct path write”等待事件
LEO1@LEO1> execute p5; 当看到“successfully”表明这个p5执行完毕
successfully
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 '%direct%';
SID EVENT WAIT_CLASS P1 P1TEXT P2 P2TEXT P3 P3TEXT
---------- ---------------------------------------------------------------- ---------- ---------- ---------- ---------- --------------- ---------- ---------------
133 direct path write User I/O 5 file numbe 18816 first dba 32 block cnt
133 direct path write User I/O 5 file numbe 17984 first dba 32 block cnt
133 direct path write User I/O 5 file numbe 17856 first dba 32 block cnt
产生的密度大
10046 trace文件中显示出来
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_19807.trc
[oracle@leonarding1 trace]$ > LEO1_ora_19807.trc
先把这个19807trace文件清空，方便看新生成的内容
LEO1@LEO1> alter session set events '10046 trace name context forever,level 12'; 启动10046事件
Session altered.
LEO1@LEO1> insert /*+ append */ into leo1 select * from leo1; 直接路径加载
143918 rows created.
LEO1@LEO1> rollback; 回滚
Rollback complete.
LEO1@LEO1> insert /*+ append */ into leo1 select * from leo1 order by object_name; 先排序在加载
143918 rows created.
LEO1@LEO1> rollback; 再回滚
Rollback complete.
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';
NAME VALUE
-------------------------------------------------------------------------------------------------------------------------------------------------
Default Trace File /u01/app/oracle/diag/rdbms/leo1/LEO1/trace/LEO1_ora_19807.trc
LEO1@LEO1> !vim /u01/app/oracle/diag/rdbms/leo1/LEO1/trace/LEO1_ora_19807.trc 查看trace文件内容
====================================================================================================
insert /*+ append */ into leo1 select * from leo1 直接路径加载
END OF STMT
PARSE #4:c=3999,e=76261,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3641460699,tim=1356802437870566
WAIT #4: nam='direct path write' ela= 207 file number=5 first dba=17028 block cnt=28 obj#=-1 tim=1356802437889828
WAIT #4: nam='direct path write' ela= 160 file number=5 first dba=17056 block cnt=32 obj#=-1 tim=1356802437895744
WAIT #4: nam='direct path write' ela= 166 file number=5 first dba=17088 block cnt=32 obj#=-1 tim=1356802437900674
WAIT #4: nam='direct path write' ela= 392 file number=5 first dba=17120 block cnt=32 obj#=-1 tim=1356802437905561
====================================================================================================
insert /*+ append */ into leo1 select * from leo1 order by object_name 先排序在加载
END OF STMT
PARSE #13:c=1000,e=945,p=0,cr=0,cu=0,mis=1,r=0,dep=0,og=1,plh=3541504125,tim=1356802457804803
WAIT #13: nam='db file sequential read' ela= 29628 file#=5 block#=9334 blocks=1 obj#=73717 tim=1356802457932078
WAIT #13: nam='db file sequential read' ela= 1211 file#=5 block#=9336 blocks=1 obj#=73717 tim=1356802457933541
WAIT #13: nam='db file scattered read' ela= 1015 file#=5 block#=9338 blocks=6 obj#=73717 tim=1356802457934811
WAIT #13: nam='db file scattered read' ela= 6766 file#=5 block#=9346 blocks=77 obj#=73717 tim=1356802457942608
WAIT #13: nam='db file scattered read' ela= 2076 file#=5 block#=9423 blocks=49 obj#=73717 tim=1356802457951133
WAIT #13: nam='db file scattered read' ela= 4840 file#=5 block#=9474 blocks=77 obj#=73717 tim=1356802457960205
WAIT #13: nam='db file scattered read' ela= 1960 file#=5 block#=9551 blocks=49 obj#=73717 tim=1356802457968629
WAIT #13: nam='db file scattered read' ela= 5017 file#=5 block#=9602 blocks=77 obj#=73717 tim=1356802457976948
WAIT #13: nam='db file scattered read' ela= 2079 file#=5 block#=9679 blocks=49 obj#=73717 tim=1356802457984742
WAIT #13: nam='db file scattered read' ela= 4975 file#=5 block#=9730 blocks=77 obj#=73717 tim=1356802457994911
WAIT #13: nam='db file scattered read' ela= 4289 file#=5 block#=9807 blocks=49 obj#=73717 tim=1356802458005146
WAIT #13: nam='db file scattered read' ela= 29 file#=5 block#=9858 blocks=4 obj#=73717 tim=1356802458009596
WAIT #13: nam='direct path write' ela= 177 file number=5 first dba=17028 block cnt=28 obj#=73717 tim=1356802458061160
WAIT #13: nam='direct path write' ela= 300 file number=5 first dba=17056 block cnt=32 obj#=73717 tim=1356802458069767
WAIT #13: nam='direct path write' ela= 116 file number=5 first dba=17088 block cnt=32 obj#=73717 tim=1356802458078466
WAIT #13: nam='direct path write' ela= 1237 file number=5 first dba=17120 block cnt=32 obj#=73717 tim=1356802458087435
WAIT #13: nam='direct path write' ela= 358 file number=5 first dba=17152 block cnt=32 obj#=73717 tim=1356802458095653
WAIT #13: nam='direct path write' ela= 174 file number=5 first dba=17184 block cnt=32 obj#=73717 tim=1356802458103262
WAIT #13: nam='direct path write' ela= 187 file number=5 first dba=17216 block cnt=32 obj#=73717 tim=1356802458113053
WAIT #13: nam='direct path write' ela= 180 file number=5 first dba=17248 block cnt=32 obj#=73717 tim=1356802458120071
WAIT #13: nam='direct path write' ela= 166 file number=5 first dba=17280 block cnt=32 obj#=73717 tim=1356802458126193
小结：trace文件中也能看到db file sequential read和db file scattered read，当然更多的是direct path write事件！
六 构造一个Log File Sync等待事件，并从相关视图中找到等待事件的信息，贴出整个演示过程。
Log File Sync等待事件：发生在“写入redo log file”的时候，既然要写入文件那么就会有磁盘I/O，有磁盘I/O就需要时间，有时间就会发生等待。
场景： commit/rollback 操作会做2个动作
（1）触发LGWR进程把log_buffer中重做日志数据写入到log_file中。
（2）然后会同步在线日志文件与控制文件的scn号，此时会发生“log file sync”等待事件
注：commit一次就会发生一次“log file sync”事件
我们还是利用Leo1表来实验，都是现成的，比较方便了，有个表有个索引
LEO1@LEO1> select table_name,index_name from user_indexes where table_name='LEO1';
TABLE_NAME INDEX_NAME
------------------------------------------------------------------------
LEO1 IDX_LEO1
我们先做个小实验，修改数据块（就会产生redo数据）然后commit提交看看v$session_event视图的统计值是不是根据commit一次提交-> log file sync的值增加了一个
会话157
LEO1@LEO1> select sid,event,total_waits,time_waited from v$session_event where event like '%log file sync%';
SID EVENT TOTAL_WAITS TIME_WAITED
-------------------------------------------------------------------------------------------------------------------------------------------------------
133 log file sync 45 206
会话133
删除11220行 -> 修改了数据块内容 -> 也就产生了redo数据
LEO1@LEO1> delete from leo1 where object_type='leonarding';
11220 rows deleted.
LEO1@LEO1> commit; 提交
Commit complete.
会话157
LEO1@LEO1> select sid,event,total_waits,time_waited from v$session_event where event like '%log file sync%';
SID EVENT TOTAL_WAITS TIME_WAITED
-------------------------------------------------------------------------------------------------------------------------------------------------------
133 log file sync 46 209
log file sync总次数增加了1次，等待时间增加了3秒
会话133
LEO1@LEO1> update leo1 set object_type='leonarding' where object_type='VIEW'; 修改了表内容也当然于修改数据块
20112 rows updated.
LEO1@LEO1> commit; 提交
Commit complete.
会话157
LEO1@LEO1> select sid,event,total_waits,time_waited from v$session_event where event like '%log file sync%';
SID EVENT TOTAL_WAITS TIME_WAITED
-------------------------------------------------------------------------------------------------------------------------------------------------------
133 log file sync 47 209
总次数又增加了1次，由于很快所以时间没有变
注：有时update一次不一定会增加TOTAL_WAITS次数，可以多操作几遍就会有反应的（因为1次数据量太少oracle的LGWR进程立刻就处理完了还来不及生成log file sync等待事件，所以总次数没有变化）
会话133
LEO1@LEO1> insert into leo1 select * from leo1; 插入记录改变数据块内容
276616 rows created.
LEO1@LEO1> commit; 提交
Commit complete.
会话157
LEO1@LEO1> select sid,event,total_waits,time_waited from v$session_event where event like '%log file sync%';
SID EVENT TOTAL_WAITS TIME_WAITED
-------------------------------------------------------------------------------------------------------------------------------------------------------
133 log file sync 48 215
log file sync总次数增加了1次，等待时间增加了6秒，这次时间长了一点
如果有频繁的DML操作而且伴随着频繁的commit动作，LGWR进程处理不过来，等待事件就会经常发生。
会话133 测试rollback动作产生log file sync事件
LEO1@LEO1> insert into leo1 select * from leo1;
553232 rows created.
LEO1@LEO1> rollback;
Rollback complete.
会话157
LEO1@LEO1> select sid,event,total_waits,time_waited from v$session_event where event like '%log file sync%';
SID EVENT TOTAL_WAITS TIME_WAITED
-------------------------------------------------------------------------------------------------------------------------------------------------------
133 log file sync 49 550
我们看到在v$session_event视图中TOTAL_WAITS又增加了1次，等待时间累加到550
10046事件
====================================================================================================
rollback
END OF STMT
PARSE #11:c=0,e=190,p=0,cr=0,cu=0,mis=0,r=0,dep=0,og=0,plh=0,tim=1356716970693590
XCTEND rlbk=1, rd_only=0, tim=1356716970693691
WAIT #11: nam='db file sequential read' ela= 33 file#=201 block#=3329 blocks=1 obj#=-1 tim=1356716970798534
EXEC #11:c=71989,e=105375,p=1,cr=35,cu=8914,mis=0,r=0,dep=0,og=0,plh=0,tim=1356716970799035
WAIT #11: nam='log file sync' ela= 18162 buffer#=6808 sync scn=1478996 p3=0 obj#=73718 tim=1356716970817237
WAIT #11: nam='SQL*Net message to client' ela= 10 driver id=1650815232 #bytes=1 p3=0 obj#=73718 tim=1356716970817390
WAIT #11: nam='SQL*Net message from client' ela= 652 driver id=1650815232 #bytes=1 p3=0 obj#=73718 tim=1356716970818072
小结：10046的trace文件中我们也看到rollback操作导致的log file sync等待事件，完结！如有建议务必提，共同学习共进步
Leonarding
2012.12.30
天津&winter
分享技术~成就梦想
Blog：www.leonarding.com
©著作权归作者所有：来自51CTO博客作者leonarding1的原创作品，如需转载，请注明出处，否则将追究法律责任
oracle等待事件性能优化
随时随地看视频
