经典案例:磁盘I/O巨高排查全过程(1)

本文涉及的产品
RDS MySQL Serverless 基础系列,0.5-2RCU 50GB
云数据库 RDS MySQL,集群系列 2核4GB
推荐场景:
搭建个人博客
RDS MySQL Serverless 高可用系列,价值2615元额度,1个月
简介: 经典案例:磁盘I/O巨高排查全过程

前言

是什么原因导致线上数据库服务器磁盘I/O的util和iowait持续飚高?

1. 问题描述

朋友小明的线上数据库突发严重告警,业务方反馈写入数据一直堵住,很多锁超时回滚了,不知道怎么回事,就找到我了。

不管3721,先采集现场的必要信息再说。

a. 系统负载,主要是磁盘I/O的负载数据

image.png

该服务器的磁盘是由6块2T SSD硬盘组成的RAID-5阵列。从上面的截图来看,I/O %util已经基本跑满了,iowait也非常高,很明显磁盘I/O压力太大了。那就再查查什么原因导致的这么高压力。

b. 活跃事务列表

image.png

可以看到,有几个活跃的事务代价很高,锁定了很多行。其中有两个因为太久超时被回滚了。

image.png

再看一次活跃事务列表,发现有个事务锁定的行更多了,说明活跃业务SQL的效率不太好,需要进行优化。这个算是原因之一,先记下。

c. 查看InnoDB状态

执行 SHOW ENGINE INNODB STATUS\G 查看InnoDB状态,这里只展示了几个比较关键的地方:

...
0x7f8f700e9700 INNODB MONITOR OUTPUT
...
LATEST DETECTED DEADLOCK
------------------------
...
*** (2) TRANSACTION:
TRANSACTION 52970892097, ACTIVE 1 sec starting index read
mysql tables in use 2, locked 2
80249 lock struct(s), heap size 9691344, 351414 row lock(s),
 undo log entries 30005
### 这里很明显,发生死锁的事务之一持有很多行锁,需要优化SQL
...
update a inner join b on a.uid=b.uid set a.kid=if(b.okid=0,b.kid,b.okid),a.aid=b.aid where
 a.date='2020-02-10'
...
TRANSACTIONS
------------
Trx id counter 52971738624
Purge done for trx's n:o < 52971738461 undo n:o < 0
 state: running but idle
History list length 81
...
---TRANSACTION 52971738602, ACTIVE 0 sec inserting
mysql tables in use 1, locked 1
1 lock struct(s), heap size 1136, 0 row lock(s),
 undo log entries 348
### 同样滴,也是有很多行锁
...
LOG
---
Log sequence number 565123876918590
Log flushed up to   565123858946703
Pages flushed up to 565121518602442
Last checkpoint at  565121518602442
...
### 注意到Last checkpoint和LSN之间的差距非常大,约为2249MB
### 说明redo log的checkpoint有延迟比较厉害,有可能是因为磁盘I/O太慢,
### 也有可能是因为产生的脏页太多太快,来不及刷新
----------------------
BUFFER POOL AND MEMORY
----------------------
Total large memory allocated 201200762880
Dictionary memory allocated 130361859
Internal hash tables (constant factor + variable factor)
    Adaptive hash index 3930999872      (3059599552 + 871400320)
    Page hash           23903912 (buffer pool 0 only)
    Dictionary cache    895261747       (764899888 + 130361859)
    File system         16261960        (812272 + 15449688)
    Lock system         478143288       (478120568 + 22720)
    Recovery system     0       (0 + 0)
Buffer pool size   11795040
Buffer pool size, bytes 193249935360
Free buffers       7035886
Database pages     4705977
Old database pages 1737005
Modified db pages  238613
### 脏页比例约为2%,看着还好嘛,而且还有挺多free page的
...

d. 查看MySQL的线程状态*

+---------+------+--------------+---------------------
| Command | Time | State        | Info                                                                                                 |
+---------+------+--------------+---------------------
| Query   |    1 | update       | insert xxx
| Query   |    0 | updating     | update xxx
| Query   |    0 | updating     | update xxx
| Query   |    0 | updating     | update xxx
| Query   |    0 | updating     | update xxx
+---------+------+--------------+---------------------



可以看到几个事务都处于updating状态。意思是正在扫描数据并准备更新,肉眼可见这些事务状态时,一般是因为系统负载比较高,所以事务执行起来慢;或者该事务正等待行锁释放。

2. 问题分析及优化工作

分析上面的各种现场信息,我们可以得到以下几点结论:

a. 磁盘I/O压力很大。先把阵列卡的cache策略改成WB,不过由于已经是SSD盘,这个作用并不大,只能申请更换成RAID-10阵列的新机器了,还需等待资源调配。

b. 需要优化活跃SQL,降低加锁代价

[root@yejr.me]> desc  select * from a inner join b on
 a.uid=b.uid where a.date='2020-02-10';
+-------+--------+------+---------+----------+-------+----------+-----------------------+
| table | type   | key  | key_len | ref      | rows  | filtered | Extra                 |
+-------+--------+------+---------+----------+-------+----------+-----------------------+
| a     | ref    | date | 3       | const    | 95890 |   100.00 | NULL                  |
| b     | eq_ref | uid  | 4       | db.a.uid |     1 |   100.00 | Using index condition |
+-------+--------+------+---------+----------+-------+----------+-----------------------+
[root@yejr.me]> select count(*) from a inner join b on
 a.uid=b.uid where a.date='2020-02-10';
+----------+
| count(*) |
+----------+
|    40435 |
+----------+
1 row in set (0.22 sec)

执行计划看起来虽然能用到索引,但效率还是不高。检查了下,发现a表的uid列竟然没加索引,我汗。。。

c. InnoDB的redo log checkpoint延迟比较大,有2249MB之巨。先检查redo log的设置:

innodb_log_file_size = 2G
innodb_log_files_in_group = 2

这个问题就大了,redo log明显太小,等待被checkpoint的redo都超过2G了,那肯定要疯狂刷脏页,所以磁盘I/O的写入才那么高,I/O %util和iowait也很高。

建议把redo log size调整成4G、3组。

innodb_log_file_size = 4G
innodb_log_files_in_group = 2

此外,也顺便检查了InnoDB其他几个重要选项

innodb_thread_concurrency = 0
# 建议维持设置0不变
innodb_max_dirty_pages_pct = 50
# 由于这个实例每秒写入量较大,建议先调整到75,降低刷脏页的频率,
# 顺便缓解redo log checkpoint的压力。
# 在本案例,最后我们把这个值调整到了90。

特别提醒

从MySQL 5.6版本起,修改redo log设置后,实例重启时会自动完成redo log的再次初始化,不过前提是要先干净关闭实例。因此建议在第一次关闭时,修改以下两个选项:

innodb_max_dirty_pages_pct = 0
innodb_fast_shutdown = 0

并且,再加上一个新选项,防止实例启动后,会有外部应用连接进来继续写数据:

skip-networking

在确保所有脏页(上面看到的Modified db pages为0)都刷盘完毕后,并且redo log也都checkpoint完毕(上面看到的Log sequence numberLast checkpoint at**值相等),此时才能放心的修改 innodb_log_file_size 选项配置并重启。确认生效后再关闭 skip-networking 选项对业务提供服务。

相关实践学习
如何在云端创建MySQL数据库
开始实验后,系统会自动创建一台自建MySQL的 源数据库 ECS 实例和一台 目标数据库 RDS。
全面了解阿里云能为你做什么
阿里云在全球各地部署高效节能的绿色数据中心,利用清洁计算为万物互联的新世界提供源源不断的能源动力,目前开服的区域包括中国(华北、华东、华南、香港)、新加坡、美国(美东、美西)、欧洲、中东、澳大利亚、日本。目前阿里云的产品涵盖弹性计算、数据库、存储与CDN、分析与搜索、云通信、网络、管理与监控、应用服务、互联网中间件、移动服务、视频服务等。通过本课程,来了解阿里云能够为你的业务带来哪些帮助 &nbsp; &nbsp; 相关的阿里云产品:云服务器ECS 云服务器 ECS(Elastic Compute Service)是一种弹性可伸缩的计算服务,助您降低 IT 成本,提升运维效率,使您更专注于核心业务创新。产品详情: https://www.aliyun.com/product/ecs
相关文章
|
6月前
|
SQL 存储 监控
实用技巧:排查数据异常/数据波动问题,该如何下手?
在我做开发的这些年,让我很头痛的一类问题,不是线上故障,而是数据异常,不知道有没有程序员跟我感同身受。大多数的服务故障都有较为直观的异常日志,再结合产品表象,相对排查起来还有迹可循,但数据异常的原因就太多了,很多时候连报错日志都没有,排查起来简直无从下手。
实用技巧:排查数据异常/数据波动问题,该如何下手?
|
11天前
|
消息中间件 数据采集 运维
一份运维监控的终极秘籍!监控不到位,宕机两行泪
【10月更文挑战第25天】监控指标的采集分为基础监控和业务监控。基础监控涉及CPU、内存、磁盘等硬件和网络信息,而业务监控则关注服务运行状态。常见的监控数据采集方法包括日志、JMX、REST、OpenMetrics等。Google SRE提出的四个黄金指标——错误、延迟、流量和饱和度,为监控提供了重要指导。错误监控关注系统和业务错误;延迟监控关注服务响应时间;流量监控关注系统和服务的访问量;饱和度监控关注服务利用率。这些指标有助于及时发现和定位故障。
51 1
|
3月前
|
运维 安全 Java
主机入侵痕迹排查指导手册(一)排查概述、排查思路
【8月更文挑战第11天】此文档提供了一线服务交付人员在攻防演练期间对主机进行入侵痕迹排查的指导。主要内容包括:1) 排查概述,明确了手册的目标是传递知识与经验,帮助一线人员高效完成排查工作;2) 排查思路,首先介绍排查流程,强调从网络连接、进程信息等多角度入手;其次提出注意事项,如避免误操作导致业务中断,以及在发现疑似异常文件时应谨慎处理。该指南适用于Windows与Linux系统,并关注Web应用的安全检查。
91 0
|
域名解析 网络协议 网络安全
网络 | 排错五大步骤,没有解决不了的网络故障准达信息准达信息
网络 | 排错五大步骤,没有解决不了的网络故障准达信息准达信息
99 0
|
运维 监控 前端开发
记一次线上 bug 的排查分析过程及总结
记一次线上 bug 的排查分析过程及总结
记一次线上 bug 的排查分析过程及总结
|
消息中间件 运维 监控
线上踩坑记:项目中一次OOM的分析定位排查过程!
线上踩坑记:项目中一次OOM的分析定位排查过程!
b站每天收集经验,升级LV6(半自动化)
b站每天收集经验,升级LV6(半自动化)
b站每天收集经验,升级LV6(半自动化)
|
SQL 固态存储 关系型数据库
经典案例:磁盘I/O巨高排查全过程(1)
经典案例:磁盘I/O巨高排查全过程
296 0
经典案例:磁盘I/O巨高排查全过程(1)
|
消息中间件 监控 算法
JVM技术之旅-线上分析排查问题
JVM技术之旅-线上分析排查问题
303 0
JVM技术之旅-线上分析排查问题
|
JSON 运维 网络协议
平稳运行半年的系统宕机了,记录一次排错调优的全过程!
最近发生了一件很让人头疼的事情,已经上线半年且平稳运行半年系统在年后早高峰的使用时发生了濒临宕机的情况。访问速度特别慢,后台查到大量time_wait的连接,从代码层面到架构层面到网络层面排查了几天几夜,总算是有了结果。
下一篇
无影云桌面