背景

??“log file sync”是Oracle中的經典等待事件之一，做為DBA 經常在AWR報告Top 5 Timed Foreground Events版塊，發現它的存在。
??在之前面試的時候也有考官問過這樣的問題，引起log file sync等待事件有哪幾種情況，當時腦袋里一堆問號，“log file sync不是因為頻繁事務commit/rollback引導的嗎？”當時我是這樣回答的，考官說：“你只回答上了一部分，回頭自己多查查資料吧！”。
??后來自己也查詢許多的資料，想著做個整理，正好借著學習張維照老師的《Oracle DBA日常運維及應急故障處理手冊》第1.1就是講的《Oracle redo file on SSD wait event ‘log file sync’》做個筆記總結。

現象

• 課程示例：
  
  數據庫的log file sync： Avg wait (ms)達500ms以上，并且CPU 負載相對空閑，IO吞吐量并不大，top event還有其它數據文件相關的I/O class wait event, 并且都是ms級別，這樣的負載對于SSD存儲通常應該就是在us級。

• 我的環境：
  
  我這log file sync： Avg wait (ms)也就1。一般log file sycn的等待時間都非常短 1-5ms，不會有什么問題。

log file sync理論

• 官方的definition如下：
  When a user session(foreground process) COMMITs (or rolls back), the session’s redo information needs to be flushed to the redo logfile. The user session will post the LGWR to write all redo required from the log buffer to the redo log file. When the LGWR has finished it will post the user session. The user session waits on this wait event while waiting for LGWR to post it back to confirm all redo changes are safely on disk.

??大概的意思指前臺進程從提交或回滾事務通知lgwr寫redo開始，直到確認redo已成功寫入redo logfile為止，期間這個過程就是log file sync等待的過程。
??所以，log file sync是每個事務commit或rollback操作都必經的過程，是否被判為異常等待，主要參考等待時間的長短、等待次數的多少。
??由于需要等待lgwr寫redo logfile，因此，log file sync的等待時間涵蓋了log file parallel write的時間。

原因分析匯總

1、小事務頻繁提交引起：

官方的經驗值是：
如果：user calls÷(user commits+user rollbacks)?< 30?，那么可以算事務太過頻繁。
以我的環境為例：

SQL> select 10316411/(963806+31450) from dual;
10316411/(963806+31450)
-----------------------
             10.3655853 < 30?，那么可以算事務太過頻繁。

2、Bug

commit的過程可以分為兩個階段：
第一階段為lgwr將redo從log buffer寫到redo logfile的過程；
第二階段lgwr和user session(foreground process)?之間關于寫redo logfile結果的信息交互過程。
對于第二階段，Oracle自從11g R2開始引入了Adaptive Log File Sync的特性，該特性由參數隱含參數“?_use_adaptive_log_file_sync”?控制，決定著前臺進程和lgwr之間的交互使用何種方式。
在 Oracle 11201 和 Oracle 11202的版本中，該參數默認設置為 false。從 11.2.0.3 開始默認是 true。
當設置為true啟用時，Oracle 可以在兩種方法之間自行切換：
Post/wait，傳統發布寫重做日志完成的方法。
Polling，一種新的方法，其中前臺進程會檢查 LGWR 是否已寫完成。
本環境為11.2.0.3 隱含參數： _use_adaptive_log_file_sync

      INDX NAME                           KSPPDESC                                           KSPPSTVL
---------- ------------------------------ -------------------------------------------------- ----------
      1060 _use_adaptive_log_file_sync    Adaptively switch between post/wait and polling    TRUE

詳細可查：Bug 13707904? – LGWR sometimes uses polling,sometimes post/wait.

該BUG可通過設置隱藏參數_use_adaptive_log_file_sync的默認值解決問題。

ALTER?SYSTEM?SET?"_use_adaptive_log_file_sync"=?FALSE??scope=both;

同時，此bug開始在oracle 11.2.0.4以及12.1.0.1版本中得到解決。

3、結合：log file parallel write 事件分析

??log file parallel write 事件是LGWR進程專屬的等待事件，發生在LGWR將日志緩沖區（log_buffer）中的重做日志信息寫入聯機重做日志文件組的成員文件，LGWR在該事件上等待該寫入過程的完成。該事件的等待表示重做日志所處的磁盤設備緩慢或存在爭用。

• log file parallel write出現原因
  意味著重做日志(redo log)所處的磁盤設備I/O緩慢或存在爭用：

1. 磁盤I/O性能比較差
2. REDO文件的分布導致了I/O爭用，例如，同一組的REDO成員文件放在相同的磁盤上。

• 查看log file parallel write等待事件

select s.event as event_name
 ,s.time_waited/100 as time_waited
,s.average_wait as averge_wait
from v$system_event s
where s.event in ('log file parallel write','log file sync');

EVENT_NAME                                                       TIME_WAITED AVERGE_WAIT
---------------------------------------------------------------- ----------- -----------
log file parallel write                                           2408236.83         .03
log file sync                                                     2503386.33         .06

來自網絡匯總：

1. log file sync的平均IO較高，log file parallel write的平均IO較高，可能的IO系統問題；
2. log file sync的平均IO較高，log file parallel write的平均IO低于5ms，遠低于log file sync：可以確定IO無問題，有可能是CPU瓶頸。
3. log file sync等待次數很高，log file parallel write的平均IO較低，可能是大量小事務頻繁提交導致，這時候通常伴隨著CPU使用率較高的現象出現。
4. log file sync和log file parallel write的平均IO都較低，這不一定就代表系統沒有問題，有可能是刷redo過程中出現了間隙性的性能問題，IO時間被平均了，這個需要進一步通過OS的信息診斷。

張維照老師的《Oracle DBA日常運維及應急故障處理手冊》里面的第1.1就是講的《Oracle redo file on SSD wait event ‘log file sync’》請的就是關于系統IO引起的log file sync，在此不再重復，有興趣可以學習：http://www.sunline.cc/course/article/160?lsId=6885&catalogId=1