【新炬網路名師大講堂】關於LOG FILE SYNC的解惑

最近我收到一封郵件，有個同事管的一套系統出現很嚴重的log file sync，然後他透過DBA_HIST_ACTIVE_SESS_HISTORY想查詢是什麼語句導致的這麼嚴重的等待。最後查詢出來的結果讓他大吃一驚。在他關注的那幾分鐘內。有很多程式在等待log file sync，這些語句的SQL_ID是select。他提出了兩個疑問，send email給我。那麼我們來看看他提出的兩個問題。

一、為什麼select 語句也會遇到log file sync？
二、如何找出真正造成log file sync的語句？

首先，在回答這兩個問題之前，我們要先要了解一下log file sync產生的原因。這裡我拿出Tanel Pader大師的一副圖來。

如圖所示，Log file sync是分成6部分的。

  √ 前臺程式，也就是使用者程式發起一個提交或者回滾的操作。
  √ 前臺程式會通知Lgwr去寫日誌。
  √ LGWR會進行物理寫的系統呼叫。
  √ 物理寫呼叫完成。
  √ LGWR通知前臺程式寫入操作已完成。
  √ 前臺程式顯示提交已經完成。

我們的步驟1-6是log file sync的過程，在3-4是log file parallel write的過程。所以log file sync包含了log file parallel write這個過程。弄明白log file sync是如何發生的之後，我們在來談談它的觸發機制。

只要進行提交，就會產生log file sync。
  √ 使用者程式提交。
  √ DDL操作，我們執行了一些事務，然後執行一個DDL，他會隱式的進行提交。
  √ 某些操作遞迴產生對資料字典的DML操作。

當然回滾也會產生log file sync
  √ 使用者程式回滾，發起rollback命令。
  √ 事務回滾，一些程式遇到ORA-錯誤，kill session等等。

瞭解了這些機制後，我們來回答第一個問題，為什麼select 語句也會遇到log file sync？其實這個可能有三種情況。
第一種情況是因為檢視DBA_HIST_ACTIVE_SESS_HISTORY的資料是取樣獲得的，可能會話發起了DML語句，再發起SELECT語句，最後執行了提交。這種情況很普遍，按照正常人的思維都是執行一個Update之後，我們在檢視一下Update是否成功了，看到成功修改之後我們就提交。只不過在取樣的時候採到了Select語句，因為最後執行的COMMIT這種語句是不會出現在SQL_ID當中的。

第二種情況是因為Select會產生延遲塊清除。如果一個事務commit後，由於某些block在commit之前已經寫回datafile, 或者事務影響到的block數過多，則commi的時候只會清理undo segment header中的事務表資訊，data block上的事務標誌不會清除，否則代價過高。那麼在下一次讀取這些block時，需要將這些事務標誌進行清除，就是延遲塊清除。延遲塊清除也是需要Lgwr寫redo的。

第三種情況是構造CR塊，在我們執行了一個DML語句之後，我們另外一個會話再執行查詢的操作，它會在記憶體中構造CR塊，構造CR會在記憶體中對塊進行修改，所以它會透過Lgwr記錄到redo log當中。

這就解釋了我們Select會產生log file sync的一個原因。至於第二個問題，如何找出引起log file sync的語句？我覺得這個根本就沒有必要去找。我們解決log file sync的思路是要判斷產生的原因。這個我推薦大家去看MOS上的文件。Troubleshooting: “log file sync” Waits (Doc ID 1376916.1)。這篇文件會告訴你從哪裡入手去判斷log file sync產生的原因。我們並不能簡單的因為幾個語句，就說它產生了log file sync,畢竟文件中提到了也會有I/O效能的問題，CPU爭用導致寫完redo之後LGWR無法post前臺程式，提交過於頻繁，redo log太小。log buffer過小等等，這些都有可能造成log file sync。所以最重要的還是先把這篇文件通讀一遍，按照上面的思路去進行處理。我相信只要你按照文件中的思路去找，一定會找出一些蛛絲馬跡出來。就算是一些疑難雜症，我們也還是可以透過Tanel Pader大師的snapper指令碼對LGWR各種等待進行測量。最終定位出問題。
參考文件：
Troubleshooting: “log file sync” Waits (Doc ID 1376916.1