“log file sync”等待事件處理

IT那活兒發布于2023-01-11 13:19 / 2376人閱讀

點擊上方“IT那活兒”公眾號，關注后了解更多內容，不管IT什么活兒，干就完了！！！

問題背景

客戶反應某系統IO很高，系統很卡。

登陸系統首先看哪類等待事件高

按照wait_class分類查詢系統當前等待事件：

set line 200
col event for a50
col WAIT_CLASS for a15
select inst_id,event,wait_class,count(*)
from gv$session a
where a.status=ACTIVE
and not (a.type = BACKGROUND and a.state=WAITING and  a.wait_class=Idle)
group by inst_id,event,wait_class
order by a.inst_id,count(*) desc;

看到系統有大量的“log file sync ”等待事件。

查看等事件的詳細信息

set line 200
col USERNAME for a10
col MACHINE for a10
col PROGRAM for a20
col EVENT for a30
col WAIT_CLASS for a20
set line 200
col USERNAME for a10
col MACHINE for a10
col PROGRAM for a20
col EVENT for a30
col WAIT_CLASS for a20
select a.inst_id,
a.sid,
a.serial#,
a.status,
a.username,
a.machine,
a.program,
a.event,
a.wait_class,
a.sql_id,
a.sql_exec_start,
a.last_call_et,
a.blocking_session
from gv$session a
where a.wait_class <> Idle
order by event desc;

告警日志（alert log）

查看問題發生期間，實例相關的警告日志輸出內容:

Mon Aug 30 13:58:08 2021
Thread 1 advanced to log sequence 544211 (LGWR switch)
Current log# 2 seq# 544211 mem# 0: E:APPORADATAWINDWINDREDO02.LOG
Mon Aug 30 13:58:52 2021
Archived Log entry 523277 added for thread 1 sequence 544210 ID 0x2b753fc0 dest 1:
Mon Aug 30 14:20:41 2021
Thread 1 advanced to log sequence 544212 (LGWR switch)
Current log# 3 seq# 544212 mem# 0: E:APPORADATAWINDWINDREDO03.LOG
Mon Aug 30 14:21:17 2021
Archived Log entry 523278 added for thread 1 sequence 544211 ID 0x2b753fc0 dest 1:
Mon Aug 30 14:43:10 2021
Thread 1 advanced to log sequence 544213 (LGWR switch)
Current log# 1 seq# 544213 mem# 0: E:APPORADATAWINDWINDREDO01.LOG
Mon Aug 30 14:43:52 2021
Archived Log entry 523279 added for thread 1 sequence 544212 ID 0x2b753fc0 dest 1:
Mon Aug 30 15:07:24 2021
Thread 1 advanced to log sequence 544214 (LGWR switch)
Current log# 2 seq# 544214 mem# 0: E:APPORADATAWINDWINDREDO02.LOG
Mon Aug 30 15:08:09 2021
Archived Log entry 523280 added for thread 1 sequence 544213 ID 0x2b753fc0 dest 1:
Mon Aug 30 15:33:09 2021
Thread 1 advanced to log sequence 544215 (LGWR switch)
Current log# 3 seq# 544215 mem# 0: E:APPORADATAWINDWINDREDO03.LOG
Mon Aug 30 15:34:07 2021
Archived Log entry 523281 added for thread 1 sequence 544214 ID 0x2b753fc0 dest 1:
Mon Aug 30 15:59:05 2021
Thread 1 advanced to log sequence 544216 (LGWR switch)
Current log# 1 seq# 544216 mem# 0: E:APPORADATAWINDWINDREDO01.LOG
Mon Aug 30 16:00:01 2021

查看awr報告

4.1 摘要信息

通過AWR的摘要信息，我們可以看到數據庫及服務器的基本狀況。其中，CPU數有8個，DB Time為486.22 (mins)，486.22/8=60.77 雖然有一點大，但是并不是特別的突出（沒有發生問題時的DB Time也差不多，有時甚至更長），所以數據庫負載沒啥問題。

4.2 查看awr報告中load profile部分

一秒數據量是75K，系統比較閑，跑的業務并不多。

4.3 等待事件

但是Top 10的前臺等待事件中，”log file sync”等待成為最多的等待事件（占DB Time的71.4%），并且等待總時間（Total）為57413s （約956mins），平均等待（Avg ）為362.83 ms,顯然是不正常的。

（通過獲取其他時間段AWR報告看到，正常時”log file sync”的平均等待Avg 為2ms）

另外Top 10 foregound events前四的等待事件都是關于I/O的，初步懷疑存儲的I/O出現了問題。

（log file sync是前臺等待事件，log file parallel write是后臺等待事件）

上面的顯示了log file sync （362.83ms）和 log file parallel write（247.33ms）都有很高的等待時間。

這里log file parallel write的avg wait達到了247.33ms，初步判斷磁盤的I/O出現了問題。

后來客戶反饋，該時間段存儲設備出了點問題，導致存儲IO性能嚴重下降。

參考MOS原文（Doc ID 1626301.1）：

如果log file sync的時間消耗在log file parallel write上的比例高，那么大部分的等待時間是由于 IO（等待 redo 寫入）。應該檢查 LGWR 在 IO 方面的性能。

作為一個經驗法則，log file parallel write平均時間超過 20 毫秒, 意味著 IO 子系統有問題。（當然這個時間對于擁有更多cache的現代的存儲系統以及SSD, NVRAM來說會更小）

實例統計信息

查看數據庫實例的redo相關的各種統計信息。

5.1 Compare the average user commits and user rollbacks to user calls

其衡量方法一般為比較 user commit/rollback 同 user calls 比值的平均值，即”user calls/(user commits+user rollbacks)” 本次平均值為28.95= 28.95/(0.79+0.21) ，commit 稍微有點頻繁，但是猜測也不應該引起非常嚴重的整體數據庫問題。（通常，我們期望 user calls/user commit 大于 25；user calls/(user commits+user rollbacks)大于30。）

5.2 歸檔日志文件切換（LGWR switch）狀況

per hour是切換次數，這里每小時切換了2次。60分鐘/1.97=30分鐘，說明每30分鐘切換一次，所以這里日志文件大小不存在問題。

oracle的推薦值是每15-20分鐘切換一次，也就是每小時切換3-4次。如果per Hour大于3-4次，則說明日志文件過小。

參考：

Document:1376916.1 Troubleshooting: Log file sync Waits

END

本文作者：劉玉川

本文來源：IT那活兒（上海新炬王翦團隊）

GPU云服務器云服務器等待事件等待處理事件處理程序待處理事件

文章版權歸作者所有，未經允許請勿轉載,若此文章存在違規行為，您可以聯系管理員刪除。

轉載請注明本文地址：http://specialneedsforspecialkids.com/yun/129490.html

JavaScript單線程事件循環(Event Loop)那些事

摘要：概述本篇主要介紹的運行機制單線程事件循環結論先在中利用運行至完成和非阻塞完成單線程下異步任務的處理就是先處理主模塊主線程上的同步任務再處理異步任務異步任務使用事件循環機制完成調度涉及的內容有單線程事件循環同步執行異步執行定時器的事件循環開始 1.概述本篇主要介紹JavaScript的運行機制:單線程事件循環(Event Loop). 結論先: 在JavaScript中, 利用運行至...

Shisui 2019-08-20 16:50 評論0 收藏0
Nodejs高性能原理(上) --- 異步非阻塞事件驅動模型

摘要：使用了一個事件驅動非阻塞式的模型，使其輕量又高效。的包管理器，是全球最大的開源庫生態系統。按照這個定義，之前所述的阻塞，非阻塞，多路復用信號驅動都屬于同步。系列文章 Nodejs高性能原理(上) --- 異步非阻塞事件驅動模型Nodejs高性能原理(下) --- 事件循環詳解前言終于開始我nodejs的博客生涯了,先從基本的原理講起.以前寫過一篇瀏覽器執行機制的文章,和nodej...

yy736044583 2019-08-26 10:42 評論0 收藏0
JS 異步的實現

摘要：由于引擎同一時間只執行一段代碼這是由單線程的性質決定的，所以每個代碼塊阻塞了其它異步事件的進行。這意味著瀏覽器將等待著一個新的異步事件發生。異步的任務執行的順序是不固定的，主要看返回的速度。我們經常說JS是單線程的，比如node.js研討會上大家都說JS的特色之一是單線程的，這樣使JS更簡單明了，可是大家真的理解所謂JS的單線程機制嗎？單線程時，基于事件的異步機制又該當如何，這些知識...

sihai 2019-08-22 11:14 評論0 收藏0