一次服务器IO占用率高的定位分析

背景:请假在外中,听平台组同事反馈了一个问题,在往生产数据库中导入部分数据时会造成客户端的访问超时,初步定位是因为服务器磁盘占用IO过高,导数据时IO会飙升到100%,因此引起了不少数据库的慢查询操作导致客户端响应超时,无奈只好暂时停止了导入数据的脚本,同时也延误了针对这部分数据的生产测试工作。于是我第二天回到公司就投入了对这个问题的跟踪定位工作。


环境描述:

  • 操作系统

    wKioL1PzHbih3dckAABqlzu8NXs262.jpg

  • 文件系统

    wKiom1PzHLOyItieAADf6Fm1BEg633.jpg

  • 数据库

    wKiom1PzHMOg31Y7AADJcKOXs80235.jpg

首先我们数据库某最大表的数据也不过300w多条,对于MySQL来说还是能够正常处理的。而且客户端并发量也不过1K多,数据库的TPS也未过百,我先后使用了top,iostat监测到的IO利用率确实都已经达到极限了。最后使用iotop这个工具发现了一个吃IO的罪犯jbd2

wKioL1PzHf2g6lTuAADhxOHRieM865.jpg

Overview
The Journaling Block Device (JBD) provides a filesystem-independent interface for filesystem journaling. ext3, ext4 and OCFS2 are known to use JBD. OCFS2 starting from linux 2.6.28 and ext4 use a fork of JBD called JBD2.

可以知晓它的主要功能是向文件系统写日志。那么肯定是由于对文件系统的操作太频繁导致的IO压力过大,问题这是个系统进程,是系统问题还是?

目前我这台服务器上只有一个应用需要大量操作IO,那就是MySQL数据库,会不会由他导致的?怀着这个疑问我用google将mysql和jbd2联合作为关键字进行搜索,得到了这么一个线索sync_binlog,innodb_flush_log_at_trx_commit这两个mysql的配置项。顿时我仿佛想起了什么,于是翻到《高性能MySQL》这本书的第10章——复制的章节(从上面的环境描述中可以看到我使用了MySQL的主主复制)找到了对sync_binlog的说明

wKioL1PzHhLDWouAAAJT10pjdMs726.jpg

那么innodb_flush_log_at_trx_commit呢?

  • 如果innodb_flush_log_at_trx_commit设置为0,log buffer将每秒一次地写入log file中,并且log file的flush(刷到磁盘)操作同时进行.该模式下,在事务提交的时候,不会主动触发写入磁盘的操作。

  • 如果innodb_flush_log_at_trx_commit设置为1,每次事务提交时MySQL都会把log buffer的数据写入log file,并且flush(刷到磁盘)中去.

  • 如果innodb_flush_log_at_trx_commit设置为2,每次事务提交时MySQL都会把log buffer的数据写入log file.但是flush(刷到磁盘)操作并不会同时进行。该模式下,MySQL会每秒执行一次 flush(刷到磁盘)操作。

由于我们的业务数据的特点,对数据可靠性并不如金融、订单系统那么高于是在权衡下就把sync_binlog设置为每500次刷新一次磁盘,而将innodb_flush_log_at_trx_commit设置为2,再用iotop等工具查看系统IO情况,大大降了下来。好吧,这个借刀杀IO的罪犯终于找到并被处理了。

后记:在这次处理问题的过程中有两个小插曲。

  1. 某领导找来几个人对此问题进行会诊,有猜测服务器资源不够的,有猜测脚本问题的,有猜测数据库本身效率底下的…我个人非常非常反感在没有经过性能监控和数据的分析而凭空猜测问题的做法。我希望给所有靠凭空想象定位问题的人提个醒,请不要随意对自己不了解的问题定性,因为别人不会把你看做高手,只会对你视而不见。

  2. 在找出jbd2的问题之后,看到一些论坛解决方案说是由于linux内核的bug可以选择升级系统内核或者修改内核配置项来解决,也许是对的,但是即使能解决这个问题对我来说成本也很大。我希望大家遇到问题时在利用网络资源的同时结合自己的情况进行进一步分析再选择采用什么解决方案,适合自己的才是最好的

参考资料:
http://unix.stackexchange.com/questions/86875/determining-specific-file-responsible-for-high-i-o
http://serverfault.com/questions/363355/io-wait-causing-so-much-slowdown-ext4-jdb2-at-99-io-during-mysql-commit
http://blog.itpub.net/22664653/viewspace-1063134/

服务器CPU,内存占用率

06-27

5:01pm up 6:04, 1 user, load average: 9.99, 9.73, 9.80rn209 processes: 190 sleeping, 19 running, 0 zombie, 0 stoppedrnCPU0 states: 96.1% user, 3.3% system, 0.0% nice, 0.0% idlernCPU1 states: 94.3% user, 5.2% system, 0.0% nice, 0.0% idlernMem: 3089788K av, 3084688K used, 5100K free, 299000K shrd, 58312K buffrnSwap: 2096440K av, 0K used, 2096440K free 2466988K cachedrnrnPID USER PRI NI SIZE RSS SHARE STAT %CPU %MEM TIME COMMAND rn 1300 oracle 17 0 122M 121M 120M S 25.4 4.0 3:23 oraclern 1141 root 39 0 130M 130M 30328 S 22.1 4.3 3:17 javarn 1288 oracle 23 0 122M 122M 120M S 20.3 4.0 3:10 oraclern 1246 oracle 18 0 121M 120M 119M S 19.8 3.9 3:10 oraclern 1298 oracle 18 0 121M 121M 119M S 15.4 4.0 3:10 oraclern 1296 oracle 16 0 122M 121M 120M S 9.6 4.0 3:14 oraclern 1292 oracle 15 0 120M 120M 118M S 8.1 3.9 3:06 oraclern 1311 oracle 15 0 121M 120M 119M S 7.9 3.9 3:06 oraclern 1303 oracle 15 0 122M 121M 120M S 7.8 4.0 3:10 oraclern 1307 oracle 17 0 122M 121M 120M S 7.1 4.0 3:15 oraclern 1217 oracle 16 0 38976 37M 37340 S 3.4 1.2 0:09 oraclern 1286 oracle 15 0 120M 120M 118M S 3.3 3.9 3:26 oraclern 1761 root 15 0 130M 130M 30328 S 2.8 4.3 0:05 javarn 1795 root 15 0 130M 130M 30328 S 2.4 4.3 0:04 javarn 1857 root 15 0 130M 130M 30328 S 2.4 4.3 0:04 javarn 2012 root 15 0 130M 130M 30328 S 2.3 4.3 0:00 javarn 1770 root 15 0 130M 130M 30328 S 2.1 4.3 0:07 javarn 1901 root 15 0 130M 130M 30328 S 1.9 4.3 0:05 javarn 1700 root 15 0 130M 130M 30328 S 1.8 4.3 0:05 javarn 1735 root 15 0 130M 130M 30328 S 1.6 4.3 0:05 javarn 1783 root 15 0 130M 130M 30328 S 1.6 4.3 0:06 javarn 1356 oracle 16 0 49280 47M 47700 S 1.4 1.5 0:10 oraclern 1791 root 15 0 130M 130M 30328 S 1.4 4.3 0:07 javarn 1883 root 16 0 130M 130M 30328 R 1.4 4.3 0:04 javarn 1680 root 15 0 130M 130M 30328 S 1.3 4.3 0:06 javarn 1632 root 15 0 130M 130M 30328 S 1.1 4.3 0:06 javarn 1841 root 15 0 130M 130M 30328 S 1.1 4.3 0:04 javarn 1768 root 15 0 130M 130M 30328 S 0.9 4.3 0:06 javarn 1875 root 15 0 130M 130M 30328 S 0.9 4.3 0:05 javarn 1895 root 15 0 130M 130M 30328 S 0.9 4.3 0:04 javarn 1927 root 15 0 130M 130M 30328 S 0.9 4.3 0:04 javarn 2032 root 15 0 130M 130M 30328 S 0.9 4.3 0:00 javarn 1881 root 15 0 130M 130M 30328 S 0.8 4.3 0:05 javarn........rnORACLErnTotal System Global Area 1074862160 bytesrnFixed Size 452688 bytesrnVariable Size 939524096 bytesrnDatabase Buffers 134217728 bytesrnRedo Buffers 667648 bytesrnrnrn打开服务的页面很快,但查询结果很慢,过了比较长的时间后,JAVA占用了大部分CPU,页面其本打不开.rn请高手帮我分析一下,这到底是怎么回事(用户数比较多)rn

没有更多推荐了,返回首页

私密
私密原因:
请选择设置私密原因
  • 广告
  • 抄袭
  • 版权
  • 政治
  • 色情
  • 无意义
  • 其他
其他原因:
120
出错啦
系统繁忙,请稍后再试