最近一个压力较大的数据库log file sync等待TOP 1.经过处理后也趁着这个时间把这个等待事件的一些信息整理一次。
什么是’log file sync’等待事件？
当一个用户session commit，会话事务相关生成的redo entry会从内存刷新到redo onlinelog。
在提交时，用户会话会通知 LGWR 把日志缓冲区中的信息写到重做日志文件（当前所有未被写入磁盘的 redo 信息，包括本次会话的 redo 信息）。当 LGWR 完成写操作后，它会通知用户会话。当等待 LGWR 通知确认所有 redo 已经全部保存到磁盘的过程时，用户会话会等待’log file sync’此时用户session显示等待’log file sync’，它是用户会话通知 LGWR 和 LGWR 通知用户的写操作完成之间的时间。
应该搜集那些信息来分析’log file sync’等待事件？
1.发生log file sync时间段的AWR/SP报告
2.当时的系统负载信息（最好有OSWATCH）
3.对应时间段的Alert.log日志信息
很高的’log file sync’等待的可能原因？
通常造成这类现象的原因有3个，具体如下：
1.Oracle 已知的bug造成
2.磁盘的IO负载过高，导致LGWR将REDO写入logfile的速度受影响
3.用户提交（commit）过于频繁
原因1：关于log file sync同步的bug
| NB | Bug | Fixed | Description |
| 14823372 | 11.2.0.3.BP23, 11.2.0.4, 12.1.0.1 | Adaptive “log file sync” picks inaccurate polling interval on RAC | |
| 13707904 | 11.2.0.4, 12.1.0.1 | LGWR sometimes uses polling, sometimes post/wait | |
| 12614085 | 11.2.0.4, 12.1.0.1 | Diagnostic enhancement to add new statistics for investigating “log file sync” and “log file parallel write” relationship | |
| P | 16102401 | 11.2.0.3.BP16, 11.2.0.4, 12.1.0.1 | identify correct effective mutiplier for sparc t5 processor |
| 13551402 | 11.2.0.3.9, 11.2.0.3.BP22, 11.2.0.4, 12.1.0.1 | High “log file parallel write” and “log file sync” after upgrading 11.2 with Veritas/Symantec ODM | |
| P | 12951619 | 11.2.0.4, 12.1.0.1 | Solaris: Enhancement to allow database to use critical threads feature in Solaris |
| 12378147 | 11.2.0.2.7, 11.2.0.2.BP10, 11.2.0.3, 12.1.0.1 | Long broadcast ack warning messages, and/or many Log File Sync timeouts in foregrounds in RAC | |
| 9095696 | 11.2.0.3.7, 11.2.0.3.BP08, 11.2.0.4, 12.1.0.1 | “log file sync” wait time spikes with ARCHIVE_LAG_TARGET set | |
| 13074706 | 11.2.0.3.BP14, 11.2.0.4, 12.1.0.1 | Long “log file sync” waits in RAC not correlated with slow writes | |
| 8490879 | 10.2.0.4.4, 10.2.0.5, 11.1.0.7.3, 11.2.0.1 | Long “log file sync” latencies due to broadcast on commit scheme | |
| 8220734 | 10.2.0.4.4, 10.2.0.5, 11.1.0.7.3, 11.2.0.1 | Long “log file sync” wait in RAC | |
| 7716356 | 10.2.0.5, 11.2.0.1 | Long “log file sync” latencies with broadcast on commit scheme in RAC | |
| 7643632 | 10.2.0.4.1, 10.2.0.5, 11.1.0.7.4, 11.2.0.1 | High log file sync in Data Guard maximum availability (sync) mode | |
| 7610362 | 10.2.0.4.4, 10.2.0.5, 11.1.0.7.3, 11.2.0.1 | Long “log file sync” waits in RAC with broadcast on commit in RAC | |
| P | 7568734 | 10.2.0.5, 11.2.0.1 | AIX: Sporadic spikes of ‘log file sync’ on AIX with heavy commit concurrency |
| 7452373 | 10.2.0.5, 11.1.0.7.1, 11.2.0.1 | “log file sync” timeout is not configurable | |
| 6319685 | 10.2.0.4, 11.1.0.7, 11.2.0.1 | LGWR posts do not scale on some platforms | |
| 6193945 | 10.2.0.4.1, 10.2.0.5, 11.1.0.7, 11.2.0.1 | High LGWR CPU use and long ‘log file sync’ latency in RAC | |
| 9776431 | 11.1.0.7.4 | 11.1.0.7.3 fix for 8220734 is incomplete – “log file sync” timeout set to 1 second | |
| 5896963 | 10.2.0.4, 11.1.0.6 | High LGWR CPU and longer “log file sync” with fix for bug 5065930 | |
| 5147386 | 10.2.0.4.1, 10.2.0.5, 11.1.0.6 | Long waits on “log file sync” /random ORA-27152 “attempt to post process failed” | |
| 5087592 | 10.2.0.4, 11.1.0.6 | “log file sync” waits from read only commits | |
| 5065930 | 10.2.0.3, 11.1.0.6 | “log file sync” timeouts can occur | |
| 5061068 | 10.2.0.3, 11.1.0.6 | RAC using “broadcast on commit” can see delayed commit times | |
| 3311210 | 9.2.0.5, 10.1.0.2 | Unnecessary 0.5 seconds waits for “Broadcast on commit” SCN scheme | |
| 2663122 | 9.2.0.5, 10.1.0.2 | Unneccessarily long waits on “log file sync” can occur | |
| 2640686 | 9.2.0.5, 10.1.0.2 | Long waits for “log file sync” with broadcast SCN in RAC |
原因2：磁盘的IO负载过高，导致LGWR将REDO写入logfile的速度受影响
情况1.比较’log file sync’和’log file parallel write’的平均等待时间结合诊断
等待事件’log file parallel write’表示 LGWR 正在等待写 redo 操作。该事件的持续时间就是等待 IO 操作部分的时间。结合事件“log file sync”看同步操作消耗在 IO 的时间，由此推断，有多少处理时间消耗在 CPU 上。
如果’log file sync’ 和 ‘log file parallel write’ 都有很高的等待时间，而且’log file sync’的时间消耗在’log file parallel write’上的比例高，那么大部分的等待时间是由于 IO（等待 redo 写入）。应该检查 LGWR 在 IO 方面的性能。Oracle官方的一个经验法则，’log file parallel write’平均时间超过 20 毫秒, 意味着 IO 子系统有问题。
这种情况下建议
- 降低redolog所在的文件系统其他不必要的IO开销。
- 建议redolog不放在raid5阵列上的卷组中，众所周知raid5的写惩罚是最高的。
- 建议redolog不放在 SSD硬盘中，虽然通常情况下，SSD 写入性能好于平均水平，但是可能会遇到写峰值,从而导致大量的增加’log file sync’等待
- 监控其他可能需要写到相同目录卷组的进程，确保该磁盘具有足够的IO吞吐量，足以应付所要求的容量。
- 确保 LOG_BUFFER 不要太大，一个非常大的 log_buffer 的不利影响就是刷新需要更长的等待时间。当缓冲区满了的时候，它必须将所有数据写入到重做日志文件。LGWR 将一直等待,直到最后的 I/O 完成。
- 避免redol log file member超过1个
尽管’log file parallel write’的平均等待时间可能在一个合理的区间范围内，在峰值时刻写操作时间还是可能会很长进而影响’log file sync’的等待时间。从10.2.0.4 开始如果写操作超过 500 毫秒我们会在 LGWR 的 trace 中写警告信息。这个阀值很高所以就算没有警告也不代表没有问题。警告信息如下：
*** 2012-11-13 20:13:41.718 Warning: log write elapsed time 21130ms, size 1KB (set event 10468 level 4 to disable this warning) *** 2012-11-13 20:13:42.929 Warning: log write elapsed time 4916ms, size 1KB (set event 10468 level 4 to disable this warning)
注意：上面的峰值如果时间间隔的很远,可能不会对’log file parallel wait’有大的影响。 但是，如果有 100 个会话等待’log file parallel wait’完成，’log file sync’总等待可能就会很高，因为等待时间将被乘以会话的个数 100。因此，需要重点关注日志写 IO 高峰的原因。
此时建议：
- 检查其他正在发生的可能会导致 LGWR 写磁盘峰值的操作，比如大量的导入操作，插入，或者系统级别的文件拷贝，以及大量的trace文件产生的情况
- 当 LGWR 进程慢的时候，对其进行 Truss 操作会帮助确定时间消耗在什么方面
这些警告信息对于预防潜在问题的发生很有帮助。就算平均等待时间没问题，通过找到 I/O 性能峰值点，可以知道 LGWR 会间歇性的遇到性能问题，进而在它引发更大问题前将其解决。
情况2.redolog file 大小是否足够，这里和LGWR switch等待事件一起结合诊断
每次redolog切换到下一个日志时，会执行’log file sync’操作，以确保下一个日志开始写之前redo信息都写完。如果日志切换频繁，则预示着会产生更多的log file sync等待，这个时候就需要考虑增加redo logfile的大小，控制redolog file的切换频率保持在15分钟到20分钟左右一个。
