Oracle 联机重做日志文件记录了数据库的所有变化(DML,DDL或管理员对数据所作的结构性更改等)，用于对于意外删除或宕机利用日志文件实现数据恢复来确保数据的完整性。但不合理的联机日志文件规划将引发日志相关的等待事件。下面是这样一个来自生产环境中的例子。
1、故障描述
--客户描述该数据库晚上用于实现数据同步以及汇总，以前一直工作的比较良好，随着需要同步的数量量的增大，最近变得越来越慢。
--下面我们首先取了客户晚8点至第二天7点的awr report。
WORKLOAD REPOSITORY report for
DB Name DB Id Instance Inst Num Release RAC Host
------------ ----------- ------------ -------- ----------- --- ------------
ST990 2152526631 ST990 1 10.2.0.3.0 NO v2011db02p
Snap Id Snap Time Sessions Curs/Sess
--------- ------------------- -------- ---------
Begin Snap: 21787 21-Feb-13 20:00:22 50 19.5
End Snap: 21798 22-Feb-13 07:00:47 44 20.0
Elapsed: 660.42 (mins)
DB Time: 928.06 (mins)
--从上面的awr report 可知，单实例，10.2.0.3版本，期间的会话数也不多
--Elapsed < DB Time
--Elapsed Time=(20130222 07:00:00 - 20130221 20:00:00)≈ 660
--DB Time=928.06 ,运行环境为16核CPU, 660*16=10560, cpu花费了928.06分钟在处理Oralce非空闲等待和运算上
--从上可知，整个系统还是比较空闲
--下面来看看top event
Top 5 Timed Events Avg %Total
~~~~~~~~~~~~~~~~~~ wait Call
Event Waits Time (s) (ms) Time Wait Class
------------------------------ ------------ ----------- ------ ------ ----------
CPU time 20,673 37.1
log file parallel write 27,399 4,797 175 8.6 System I/O
control file parallel write 13,428 4,688 349 8.4 System I/O
log file sync 19,564 3,795 194 6.8 Commit
db file scattered read 26,651,537 3,439 0 6.2 User I/O
--从上面的top event事件上来看，log file相关等待事件表现明显
--log file parallel write等待事件总等待次数27,399 总等待时间4,797/60=79.95(min),超出一个小时，相当可观
--其次是control file parallel write与log file sync事件的相关等待
--下面是等待事件的detail信息
Wait Events DB/Inst: ST1200/ST1200 Snaps: 21787-21798
-> s - second
-> cs - centisecond - 100th of a second
-> ms - millisecond - 1000th of a second
-> us - microsecond - 1000000th of a second
-> ordered by wait time desc, waits desc (idle events last)
%Time Total Wait wait Waits
Event Waits -outs Time (s) (ms) /txn
---------------------------- -------------- ------ ----------- ------- ---------
log file parallel write 27,399 .0 4,797 175 1.1
control file parallel write 13,428 .0 4,688 349 0.5
log file sync 19,564 10.6 3,795 194 0.8
db file scattered read 26,651,537 .0 3,439 0 1,049.4
db file sequential read 6,682,373 .0 1,567 0 263.1
log file switch (checkpoint 1,091 92.9 1,019 934 0.0
Datapump dump file I/O 633,458 .0 286 0 24.9
log file switch completion 332 31.6 183 552 0.0
log buffer space 255 47.8 155 608 0.0
free buffer waits 2,409 99.5 120 50 0.1
buffer busy waits 145 62.8 96 664 0.0