“log file sync”等待事件处理

IT那活儿发布于2023-01-11 13:19 / 2366人阅读

点击上方“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云服务器等待事件等待处理事件处理程序待处理事件

文章版权归作者所有，未经允许请勿转载,若此文章存在违规行为，您可以联系管理员删除。

转载请注明本文地址：https://www.ucloud.cn/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