mysql i o 高_经典案例：磁盘I/O巨高排查全过程
原標題：經典案例：磁盤I/O巨高排查全過程
前言
是什么原因導致線上數據庫服務器磁盤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 STATUSG 查看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 number和Last checkpoint at**值相等)，此時才能放心的修改 innodb_log_file_size選項配置并重啟。確認生效后再關閉 skip-networking選項對業務提供服務。
經過一番優化調整后，再來看下服務器和數據庫的負載。 
可以看到，服務器的磁盤I/O壓力再也不會那么大了，數據庫中也不會頻繁出現大量行鎖等待或回滾的事務了。
[root@yejr.me]> SHOW ENGINE INNODB STATUSg
Log sequence number 565749866400449
Log flushed up to 565749866400449
Pages flushed up to 565749866318224
Last checkpoint at 565749866315740
[root@yejr.me]> SHOW ENGINE INNODB STATUSg
Log sequence number 565749866414660
Log flushed up to 565749866400449
Pages flushed up to 565749866320827
Last checkpoint at 565749866315740
[root@yejr.me]> SHOW ENGINE INNODB STATUSg
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 高_经典案例：磁盘I/O巨高排查全过程的全部內容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： 360安全浏览器HD变身观赛利器 安全.
- 下一篇： 缝纫机织出的漂亮衣服缝纫机织出的漂亮衣服