參考故障排除:"log file sync"等待 (Doc ID 1626301.1)
適用於
Oracle Database - Standard Edition - 版本 8.0.6.0 到 11.2.0.3 [發行版 8.0.6 到 11.2]
Oracle Database Exadata Cloud Machine - 版本 N/A 和更高版本
Oracle Cloud Infrastructure - Database Service - 版本 N/A 和更高版本
Oracle Database Cloud Exadata Service - 版本 N/A 和更高版本
Oracle Database Exadata Express Cloud Service - 版本 N/A 和更高版本
本文檔所含信息適用於所有平台
用途
本文旨在幫助診斷存在大量'log file sync'等待事件的問題。
排錯步驟
什么是'log file sync'等待事件?
當一個用戶會話提交,那個用戶產生的所有redo需要從內存刷新到重做日志文件,使事務對數據庫的修改永久化。
在提交時,用戶會話會通知 LGWR 把日志緩沖區中的信息寫到重做日志文件(當前所有未被寫入磁盤的 redo 信息,包括本次會話的 redo 信息)。當 LGWR 發現寫操作完成后,它會通知用戶會話。當等待 LGWR 通知確認所有 redo 已經安全的保存到磁盤的過程時,用戶會話會等待'log file sync'。
用戶會話顯示等待'log file sync',是用戶會話通知 LGWR 和 LGWR 通知用戶的寫操作完成之間的時間。
注意在11.2及以上版本,LGWR會在默認的post/wait模式和polling模式之間自動切換。在polling模式下,寫操作的進展會維護在一個內存結構中,等待'log file sync'的會話可以不時檢查這個內存結構看是否自己所發起的事務對應的redo已經寫入磁盤。這時,等待時間會從用戶會話通知 LGWR開始到會話自己發現對應的redo已經寫入磁盤結束。
需要注意的是,如果已有一個正在進行的同步,其他需要提交的會話(為了保存日志信息)也需等待 LGWR,進而也將等待'log file sync'?
用戶應該搜集那些信息,來初步分析'log file sync'等待事件?
初步分析等待'log file sync',下面的信息是有幫助的:
- 'log file sync'等待在可接受范圍的類似時間的 AWR 報告,作為用於比較的性能基線
- 'log file sync'等待很嚴重期間的 AWR 報告 注:2 個報告應在 10-30 分鍾之間。
- LGWR 日志文件(在12.2版本以上還需收集LGnn日志文件)當日志寫入較慢的時候,LGWR 日志文件將會顯示警告信息
什么原因造成了很高的’log file sync’等待?
‘log file sync’可以在用戶會話通知 LGWR 寫日志,和 LGWR 寫完日志后通知用戶會話(本地重做日志以及同步模式下的遠程備庫的日志),及用戶會話被喚醒間來接受LGWR的通知或者poll LGWR的寫入的日志的進展的任何一個點發生。
其中的最常見的原因:
- 影響 LGWR 的 I/O 性能問題
- 過多的應用程序 commit
影響 LGWR 的 IO 性能問題
我們在這里回答的主要問題是“是否 LGWR 寫入磁盤慢?”,下面的步驟可以幫助確定是否是這個導致的
比較'log file sync'和'log file parallel write'的平均等待時間。
等待事件'log file parallel write'表示 LGWR 正在等待寫 redo 操作。該事件的持續時間就是等待 IO 操作部分的時間。關於'log file parallel write'的更多信息,請參閱:
Document:34583.1 WAITEVENT: "log file parallel write" Reference Note
結合事件“log file sync”看同步操作消耗在 IO 的時間,由此推斷,有多少處理時間消耗在 CPU 上。
上面的例子顯示了'log file sync' 和 'log file parallel write' 都有很高的等待時間
如果'log file sync'的時間消耗在'log file parallel write'上的比例高,那么大部分的等待時間是由於 IO(等待 redo 寫入)。應該檢查 LGWR 在 IO 方面的性能。作為一個經驗法則,'log file parallel write'平均時間超過 20 毫秒, 意味着 IO 子系統有問題。(當然這個時間對於擁有更多cache的現代的存儲系統以及SSD, NVRAM來說會更小)
建議
- 與系統管理員一起檢查重做日志所在的文件系統以及本地卷的位置,以提高 IO 性能。
- 不要把重做日志放在需要額外計算的較老的或者復雜的RAID上,比如 RAID-5或者RAID-6或者只有很少cache部件的存儲上
- 不要把重做日志放在上一代或者較老的Solid State Disk (SSD)磁盤上,雖然通常情況下,SSD 寫入性能好於平均水平,他們可能會遇到寫峰值,從而導致大量的嚴重'log file sync'等待並引發數據庫性能不穩定或者hung住(關於這一點您需要詳盡的測試,因為我們也碰到一些即使SSD的寫性能不穩定但數據庫性能仍然可以接受的系統)(Engineered Systems (Exadata, SuperCluster 和 Oracle Database Appliance) 除外,因為在這些系統上已經為使用SSD來存放重做日志而做了額外的優化)
- 監控其他可能需要寫到相同路徑的進程,確保該磁盤具有足夠的帶寬,足以應付所要求的容量。如果不能滿足,增加硬盤或者更快的磁盤設備或者把這些文件分散到不同的磁盤設備。
- 確保 LOG_BUFFER 不要太大,一個非常大的 log_buffer 的不利影響就是刷新需要更長的等待時間。當緩沖區滿了的時候,它必須將所有數據寫入到重做日志文件。LGWR 將一直等待,直到最后的 I/O 完成。
間歇性物理IO緩慢對 'log file sync' 等待事件的影響
LGWR傾向於做很多小的IO操作,而不是大塊的IO操作。大部分的磁盤配置並不能在這種場景下很好的工作,可能會發生間歇性物理IO緩慢。但是從平均等待時間來看,IO等待的時間並不長(它們僅僅是不善於處理這種小而多的IO負載),磁盤設備提供商據此斷定沒有磁盤問題。 因為系統里還有其它的IO操作,這些正常的IO操作的等待時間很短,所有這些IO操作平均起來的等待時間並不長,這就掩蓋了間歇性物理IO緩慢(IO異常值)的問題。 但是間歇性物理IO緩慢的問題會造成很高的'log file sync', 雖然平均的'log file parallel write'是處於正常性能的范圍。
如果你發現系統的'log file sync'很高,但是'log file parallel write'是處於正常的范圍,那么這可能是由於間歇性物理IO緩慢導致的。可以檢查AWR的部分,也可以使用一些像OSWatcher一樣的工具(參照 Document 301137.1)來確定是否系統中存在間歇性物理IO緩慢。如果可以確定存在間歇性物理IO緩慢, 那么你需要與磁盤提供商一起來解決這個問題。
檢查 LGWR trace
盡管'log file parallel write'的平均等待時間可能在一個合理的區間范圍內,在峰值時刻寫操作時間還是可能會很長進而影響’log file sync’的等待時間。從10.2.0.4 開始如果寫操作超過 500 毫秒我們會在 LGWR 的 trace 中寫警告信息。這個閥值很高所以就算沒有警告也不代表沒有問題。警告信息如下:
*** 2011-10-26 10:14:41.718
Warning: log write elapsed time 21130ms, size 1KB
(set event 10468 level 4 to disable this warning)
*** 2011-10-26 10:14: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 高峰的原因。
請參閱:
Document:601316.1 LGWR Is Generating Trace file with "Warning: Log Write Time 540ms, Size 5444kb" In 10.2.0.4 Database
建議
- 與系統管理員一起檢查其他正在發生的可能會導致 LGWR 寫磁盤峰值的操作
- 當 LGWR 進程慢的時候,對其進行 Truss 操作會幫助確定時間消耗在什么地方
注意:這些警告信息對於預防潛在問題的發生很有幫助。就算平均等待時間沒問題,通過找到 I/O 性能峰值點,DBA 可以知道 LGWR 會間歇性的遇到性能問題,進而在它引發更大問題前將其解決。
檢查在線重做日志是否足夠大
每次重做日志切換到下一個日志時,會執行'log file sync'操作,以確保下一個日志開始之前信息都寫完。 標准建議是日志切換最多 15 至 20 分鍾一次。 如果切換比這更頻繁,那么將發生更多的'log file sync'操作,意味着更多的會話等待。
- 檢查 alert.log 日志文件切換的時間
Thu Jun 02 14:57:01 2011
Thread 1 advanced to log sequence 2501 (LGWR switch)
Current log# 5 seq# 2501 mem# 0: /opt/oracle/oradata/<SID>/redo05a.log
Current log# 5 seq# 2501 mem# 1: /opt/oracle/logs/<SID>/redo05b.log
Thu Nov 03 14:59:12 2011
Thread 1 advanced to log sequence 2502 (LGWR switch)
Current log# 6 seq# 2502 mem# 0: /opt/oracle/oradata/<SID>/redo06a.log
Current log# 6 seq# 2502 mem# 1: /opt/oracle/logs/<SID>/redo06b.log
Thu Nov 03 15:03:01 2011
Thread 1 advanced to log sequence 2503 (LGWR switch)
Current log# 4 seq# 2503 mem# 0: /opt/oracle/oradata/<SID>/redo04a.log
Current log# 4 seq# 2503 mem# 1: /opt/oracle/logs/<SID>/redo04b.log
在上面的例子中,我們看到每 2 到 4 分鍾進行日志切換,這比建議值的5倍還高。
- 您也可以檢查 AWR 報告日志切換的平均時間
在上面的例子中基於 AWR 中的信息,每小時有 29.98 次重做日志切換:每 2 分鍾切換一次。這個比每 15-20 分鍾切換一次的建議值要高,並將影響前台進程需要等待'log file sync'完成的時間,因為發起同步操作的開銷比必要的多。
建議
增加redo logs的大小
Document:602066.1 How To Maintain and/or Add Redo Logs
Document:779306.1 How To Add/Increase The Size Of Redo Log Files In Rac Environment?
應用程序提交過多
在這種情況下,要回答的問題是“是否應用程序 commit 過於頻繁? ”。
如果是,那么過多的 commit 活動可能會導致性能問題,因為把 redo 從日志緩沖區刷新到重做日志可能會導致等待'log file sync'。
如果’log file sync’的平均等待時間比’log file parallel write’高很多,這意味着大部分時間等待不是由於等待 redo 的寫入,因而問題的原因不是 IO 慢導致。 剩余時間是 CPU 活動,而且是過多的 commit 導致的最常見的競爭。
此外,如果'log file sync'的平均等待時間低,但等待次數高,那么應用程序可能 commit 過於頻繁。
比較 user commit/rollback 同 user calls 比值的平均值
在 AWR 或 Statspack 報告中,如果每次 commit/rollback 的平均 user calls("user calls/(user commits+user rollbacks)") 小於 30, 表明 commit 過於頻繁
在上面的例子中,我們看到,平均每 5.76 次 user calls 就會有一次 commit, 大約高出建議值 5 倍。基於經驗,我們期望 user calls/user commit 至少是 25。當然,這取決於應用程序設計。
建議
- 如果有很多短事務,看是否可能把這些事務組合在一起,從而減少 commit 操作。 因為每一個 commit 都必須收到相關 REDO 已寫到磁盤上的確認,額外的 commit 會顯著的增加開銷。雖然 Oracle 可以將某些 commit 組合在一起,通過事務的批處理來減少commit的總體數量還是可以帶來非常有益的效果。
- 看看是否有操作可以使用 COMMIT NOWAIT 選項 (務必在使用前應明白語義)。
- 看看是否有操作可以安全地使用 NOLOGGING/ UNRECOVERABLE 選項完成。
其他可能相關的等待事件
檢查 AWR 報告,看是否有跟 LGWR 相關的,顯示占用了顯著數量時間的其他事件,因為這可能會給出導致這個問題的一個線索。前台和后台事件都應該進行檢查。
例如下面的 AWR 顯示某些其他前台和后台等待事件等待高,意味着傳輸重做日志到遠程位置的問題,這可能會導致 fore gorund 進程等待"log file sync"。
Adaptive Log File Sync
11.2 中引入了 Adaptive Log File sync,由參數 _use_adaptive_log_file_sync 控制,在 11.2.0.1 和 11.2.0.2 默認設置為 false。從 11.2.0.3 開始默認是 true。 當啟用時,Oracle 可以在兩種方法之間切換:
- Post/wait,傳統發布寫重做日志完成的方法
- Polling,一種新的方法,其中前台進程會檢查 LGWR 是否已寫完成。
更多關於這個特性的信息,請參閱:
Document 1541136.1 Waits for "log file sync" with Adaptive Polling vs Post/Wait Choice Enabled
Redo Synch Time Overhead
統計值'redo synch time overhead'在11.2.0.4和12c被引入,記錄了理想的log file sync時間以及真正的log file sync時間的差值。
如果這個差值很小,說明log file sync等待次數可能是log file parallel write等待之外的原因導致的
其他診斷程序來幫助分析'log file sync'等待?
下面的腳本着眼於與'log file sync'等待有關的重要參數,'log file sync'等待直方圖數據和相關信息。
Document:1064487.1 Script to Collect Log File Sync Diagnostic Information (lfsdiag.sql)
Data Guard 和'log file sync'
當使用 Data Guard SYNC 和 commit WAIT 默認配置時,可能需要更多的時間。在 Data Guard 環境中,雖然上述調整步驟仍然適用,網絡寫和 RFS/redo 寫入備用重做日志的時間也需要加以考慮。下面的白皮書解釋了'Log File Sync'如何適用於 Data Guard:
Document:387174.1 MAA - Data Guard Redo Transport and Network Best Practices.
其他問題故障排除
對於排除其他性能問題的指導, 請參閱:
Document:1377446.1 Troubleshooting Performance Issues