经典案例：磁盘I/O巨高排查全过程

做者：叶金荣，知数堂联合创始人，3306pai社区联合创始人

前言

是什么缘由致使线上数据库服务器磁盘I/O的util和iowait持续飚高？

1. 问题描述

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

无论3721，先采集现场的必要信息再说。

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

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

b. 活跃事务列表

能够看到，有几个活跃的事务代价很高，锁定了不少行。其中有两个由于过久超时被回滚了。

再看一次活跃事务列表，发现有个事务锁定的行更多了，说明活跃业务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     4705977O
ld 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 = 4Ginnodb_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 number和Last checkpoint at**值相等），此时才能放心的修改 innodb_log_file_size 选项配置并重启。确认生效后再关闭 skip-networking 选项对业务提供服务。

通过一番优化调整后，再来看下服务器和数据库的负载。

能够看到，服务器的磁盘I/O压力不再会那么大了，数据库中也不会频繁出现大量行锁等待或回滚的事务了。

[root@yejr.me]> SHOW ENGINE INNODB STATUS\g
Log sequence number 565749866400449
Log flushed up to   565749866400449
Pages flushed up to 565749866318224
Last checkpoint at  565749866315740
[root@yejr.me]> SHOW ENGINE INNODB STATUS\g
Log sequence number 565749866414660
Log flushed up to   565749866400449
Pages flushed up to 565749866320827
Last checkpoint at  565749866315740
[root@yejr.me]> SHOW ENGINE INNODB STATUS\g
Log sequence number 565749866414660
Log flushed up to   565749866414660
Pages flushed up to 565749866322135
Last checkpoint at  565749866315740
[root@yejr.me]> select (565749866400449-565749866315740)/1024;
+----------------------------------------+
| (565749866400449-565749866315740)/1024 |
+----------------------------------------+
|                                82.7236 |
+----------------------------------------+
1 row in set (0.00 sec)
[root@yejr.me]> select (565749866414660-565749866315740)/1024;
+----------------------------------------+
| (565749866414660-565749866315740)/1024 |
+----------------------------------------+
|                                96.6016 |
+----------------------------------------+

很明显，redo log checkpoint lag几乎没有了。

完美搞定！

写在最后

遇到数据库性能瓶颈，负载飚高这类问题，咱们只须要根据一套完整的方法论 优化系列：实例解析MySQL性能瓶颈排查定位，根据现场的各类蛛丝马迹，逐一进行分析，基本上都是能找出来问题的缘由的。本案其实并不难，就是按照这套方法来作的，最后连perf top都没用上就很快能大体肯定问题缘由了。

延伸阅读

• 是什么致使MySQL数据库服务器磁盘I/O高
• 实例解析MySQL性能瓶颈排查定位
• 重要的MySQL开发规范都在这了
• MySQL全面快速优化参考
• 实例解析MySQL性能瓶颈排查定位