【Mysql】JDB2导致磁盘io使用率高导致mysql延迟过高

最新推荐文章于 2022-07-22 12:06:34 发布

cml2016

最新推荐文章于 2022-07-22 12:06:34 发布

阅读量1k

点赞数

文章标签：数据库操作系统

参考连接：http://www.bubuko.com/infodetail-971804.html

背景：某项目slave数据库的延迟非常大

mysql> show slave status\G;
*************************** 1. row ***************************
Slave_IO_State: Queueing master event to the relay log
Master_Host: 192.168.10.2
Master_User: repluser
Master_Port: 3306
Connect_Retry: 60
Master_Log_File: mysql-bin.000047
Read_Master_Log_Pos: 1029469531 -----读取的位置也在不停增大
Relay_Log_File: mysqlrelay.000201
Relay_Log_Pos: 614671683
Relay_Master_Log_File: mysql-bin.000047
Slave_IO_Running: Yes
Slave_SQL_Running: Yes
Replicate_Do_DB:
Replicate_Ignore_DB:
Replicate_Do_Table:
Replicate_Ignore_Table:
Replicate_Wild_Do_Table:
Replicate_Wild_Ignore_Table:
Last_Errno: 0
Last_Error:
Skip_Counter: 0
Exec_Master_Log_Pos: 614671473 ---执行的位置在不停增大，通过这个现象基本可以排除卡在主库大事务的这个原因了
Relay_Log_Space: 1029471060
Until_Condition: None
Until_Log_File:
Until_Log_Pos: 0
Master_SSL_Allowed: No
Master_SSL_CA_File:
Master_SSL_CA_Path:
Master_SSL_Cert:
Master_SSL_Cipher:
Master_SSL_Key:
Seconds_Behind_Master: 242580 ---延迟也在不停增大

初步分析：sql线程执行速度赶不上io线程拉去日志的速度，随着时间的推移slave延迟越来越大

按照常规优化手段优化

参考文章：
http://blog.itpub.net/29096438/viewspace-2057127/
http://blog.itpub.net/29096438/viewspace-2055014/

排除：因update语句缺少主键导致slave延迟，主库进行大事务导致的salve延迟这两个原因

查看磁盘io状况

如下：
[root@Yun-MySQL02 ~]# iostat -dtxNm 2 10
Linux 2.6.32-431.el6.x86_64 (Yun-MySQL02) 07/22/2016 _x86_64_ (4 CPU)

07/22/2016 05:41:23 PM
Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await svctm %util
sdb 0.01 110.01 3.35 71.07 0.39 0.71 30.17 0.01 14.08 12.73 100%
sda 0.01 2.41 0.13 0.36 0.01 0.01 75.79 0.01 25.07 3.64 0.18
VolGroup0-LogVol01 0.00 0.00 0.13 2.76 0.01 0.01 12.67 0.23 80.89 0.61 0.18
VolGroup0-LogVol00 0.00 0.00 0.00 0.01 0.00 0.00 8.00 0.00 16.45 0.70 0.00
VolGroup1-LogVol00 0.00 0.00 3.36 181.08 0.39 0.71 12.17 0.36 14.94 12.10 100%

07/22/2016 05:41:25 PM
Device: rrqm/s wrqm/s r/s w/s rMB/s wMB/s avgrq-sz avgqu-sz await svctm %util
sdb 0.00 86.00 8.50 126.00 0.16 0.83 15.11 2.71 20.25 17.40 99.50
sda 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
VolGroup0-LogVol01 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
VolGroup0-LogVol00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00 0.00
VolGroup1-LogVol00 0.00 0.00 8.50 211.50 0.16 0.83 9.22 5.01 22.80 14.52 99.50
查看iotop状况：
Total DISK READ: 11.59 K/s | Total DISK WRITE: 877.24 K/s
TID PRIO USER DISK READ DISK WRITE SWAPIN IO> COMMAND
873 be/3 root 0.00 B/s 3.86 K/s 0.00 % 77.79 % [jbd2/dm-2-8]
31764 be/4 mysql 0.00 B/s 104.34 K/s 0.00 % 37.01 % mysqld --defaults-file=/data/mydata/my.cnf --basedir=/home/data/mys~ta/3306/mysql.pid --socket=/data/mydata/3306/mysql.sock --port=3306
31765 be/4 mysql 11.59 K/s 146.85 K/s 0.00 % 28.39 % mysqld --defaults-file=/data/mydata/my.cnf --basedir=/home/data/mys~ta/3306/mysql.pid --socket=/data/mydata/3306/mysql.sock --port=3306
2714 be/4 root 0.00 B/s 0.00 B/s 0.00 % 1.18 % [nfsd]
可以看到io相当繁忙，iowait也很高，并且[jbd2/dm-2-8]占用了io很大的资源

优化sql

iowait随机io那么高,那么我们优化sql，结果发现没效果

其它方法

iotop [jbd2/dm-2-8]过高，搜索了一下，还真发现一篇文章，是ext4文件系统的一个bug，修复过后 slave延迟果然开始降低了付参考链接： http://www.bubuko.com/infodetail-971804.html

后续：

修复上诉bug后情况仍不见好转，用dstat命令看下io前几名的进程
[root@Yun-MySQL02 fiodir]# dstat -r -l -t --top-io read writ| 1m 5m 15m | date/time | block i/o process
1.00 134 |2.10 2.19 2.21|26-07 15:42:23|mysqld 4096B 176k
1.00 142 |2.10 2.19 2.21|26-07 15:42:24|mysqld 4096B 128k
1.00 118 |2.17 2.20 2.21|26-07 15:42:25|mysqld 4096B 176k
0 133 |2.17 2.20 2.21|26-07 15:42:26|mysqld 0 192k
0 119 |2.17 2.20 2.21|26-07 15:42:27|mysqld 0 172k
1.00 116 |2.17 2.20 2.21|26-07 15:42:28|mysqld 4096B 124k
1.00 132 |2.17 2.20 2.21|26-07 15:42:29|nfsd 4096B 2000k
1.00 77.0 |2.16 2.20 2.21|26-07 15:42:30|mysqld 4096B 188k
0 135 |2.16 2.20 2.21|26-07 15:42:31|nfsd 0 2000k
nfs文件系统也占用了大量的io，不知道是不是这个的原因，换到另一块盘问题解决！

过了一段时间发现情况再次出现

查看iostat状态

sdb 0.00 1.98 0.00 8.91 0.00 51.49 11.56 0.40 44.56 0.00 44.56 17.44      15.54
sdb 0.00 2.02 0.00 3.03 0.00 32.32 21.33 0.06 18.33 0.00 18.33 18.33      5.56
sdb 0.00 0.00 2.00 0.00 32.00 0.00 32.00 0.09 9.00 9.00 0.00 43.00         8.60
sdb 0.00 2.00 1.00 3.00 16.00 32.00 24.00 0.07 35.25 11.00 43.33 18.25     7.30
sdb 0.00 2.00 7.00 3.00 176.00 36.00 42.40 0.14 14.40 10.71 23.00 10.80      10.80
sdb 0.00 2.02 2.02 3.03 32.32 28.28 24.00 0.19 37.80 25.50 46.00 37.80      19.09
sdb 0.00 1.98 0.00 2.97 0.00 19.80 13.33 0.07 24.33 0.00 24.33 24.33      7.23
sdb 0.00 2.00 6.00 3.00 368.00 28.00 88.00 0.14 15.11 12.33 20.67 13.56      12.20
sdb 0.00 1.98 0.99 2.97 15.84 35.64 26.00 0.07 18.25 8.00 21.67 18.25      7.23
sdb 0.00 2.02 1.01 3.03 16.16 28.28 22.00 0.05 12.25 17.00 10.67 12.75      5.15
sdb 0.00 8.00 3.00 5.00 48.00 456.00 126.00 0.27 33.62 14.00 45.40 22.38     17.90
sdb 0.00 2.00 6.00 3.00 208.00 28.00 52.44 0.13 14.89 17.00 10.67 5.33      4.80
sdb 0.00 2.02 1.01 3.03 16.16 24.24 20.00 0.08 20.25 9.00 24.00 20.25      8.18
sdb 0.00 2.00 2.00 3.00 32.00 28.00 24.00 0.07 14.60 13.50 15.33 14.60     7.30
sdb 0.00 2.00 4.00 3.00 64.00 52.00 33.14 0.09 13.00 11.50 15.00 13.00     9.10
sdb 0.00 0.00 2.02 0.00 32.32 0.00 32.00 0.03 13.00 13.00 0.00 17.00           3.43
sdb 0.00 2.00 10.00 3.00 3728.00 32.00 578.46 0.22 17.46 15.40 24.33 7.08     9.20
sdb 0.00 1.98 3.96 2.97 63.37 31.68 27.43 0.13 18.29 16.00 21.33 18.71      12.97
util基本1秒一波动，很符合log_buffer写数据到log_file的规律（每隔1秒写入）

查看innodb状态(oradba 或者 dodba 或者脚本)

-------- ---innodb bp pages status-- -----innodb data status---- --innodb log-- his --log(byte)-- read ---query---
time | data free dirty flush| reads writes read written|fsyncs written| list uflush uckpt view inside que|
15:52:27| 596582 8168 11939 797| 31 1034 496k 27.9m| 219 3.0m| 2430 998 70.9m 0 0 0|
15:52:29| 596575 8172 11553 910| 48 1090 768k 30.7m| 162 9.2m| 2467 25k 73.0m 1 0 0|
15:52:30| 596578 8167 11283 824| 43 1018 688k 28.2m| 179 2.4m| 2619 1k 54.7m 1 0 0|
15:52:31| 596557 8179 10976 831| 44 1017 704k 28.3m| 168 10 m| 2612 4k 57.0m 3 0 0|
15:52:32| 596546 8187 10840 743| 25 945 400k 25.7m| 186 9.0m| 2720 1k 59.4m 1 0 0|
15:52:33| 596662 8066 10400 1168| 158 1398 2.5m 39.4m| 206 5.0m| 2768 1k 62.2m 2 0 0|

可以看到Innodb_data_written每秒的写入量很稳定，没什么大的波动，但是Innodb_os_log_written的波动比较频繁

结合上iostat中 wsec/s 较大的数值，基本可以确定IO高负载的元凶是redo log的flush，而不是data page的flush

查看innodb log buffer状态

加大log_buffer_pool与innodb_log_file_size的值，重启数据库，发现iowait降低，slave开始下降！

总结：优化io过高的几种原因：
1.是否是buffer pool过小导致的参考文章：叶金荣--是什么导致磁盘io过高 http://mp.weixin.qq.com/s/sAGFo-h1GCBhad1r1cEWTg
2.是否是sql导致的
3.innodb_io_captiy对io稳定性的影响 http://blog.itpub.net/29096438/viewspace-2134208/
4.其它系统原因

来自 “ ITPUB博客 ” ，链接：http://blog.itpub.net/29096438/viewspace-2122409/，如需转载，请注明出处，否则将追究法律责任。

转载于:http://blog.itpub.net/29096438/viewspace-2122409/

cml2016

关注

0
点赞
踩
2

收藏

觉得还不错? 一键收藏
0
评论
【Mysql】JDB2导致磁盘io使用率高导致mysql延迟过高

参考连接：http://www.bubuko.com/infodetail-971804.html 背景：某项目slave数据库的延迟非常大 mysql> show slave s...
复制链接

扫一扫