一次 jbd2进程导致磁盘 io 高的分析解决过程
故障现象
在3节点组成的大数据集群中，混部了 ES，kafka，zk，pg，mysql，spark，yarn，hdfs，以及业务的 etl 程序等组件。起初发现业务进程处理数据速度很慢，排查后发现数据盘 /data01 的 util 接近100%
但是磁盘吞吐量并不高，IO 流量只有2MB 左右，主要是由 w/s 导致，也就是写入的 iops 高，这种情况一般就是进程的 sync 操作密集。
分析过程
通过 iotop 来查看是哪个进程，显示为 jbd2
查阅一些资料后，了解到 jbd2进程负责 ext4这种日志文件系统的日志提交操作，关于jbd2引起磁盘 io 高，网上也有很多类似案例，总结起来有几方面原因：
- 系统 bug
- ext4文件系统的相关配置问题
- 其他进程的 fsync，sync 操作过于频繁
首先排除系统 bug因素，网络上反馈的问题在很低的版本，我们生产环境为 Centos 7.4，其次，查阅了 /proc/mounts 等信息，发现文件系统配置参数与其他环境差异不大，按照网上提供的关闭某些特性，降低 commit 频率等理论来说会有效果，但需要重新 mount 磁盘，相关组件都要重启，并且这看起来并非根本原因。
尝试分析 sync 调用，使用 sysdig 最方便，但现场环境安装很麻烦，因此开启几个内核 trace查看：
在 jbd2执行 flush 时输出日志
| 1 2 3 |
echo 1 > /sys/kernel/debug/tracing/events/jbd2/jbd2_commit_flushing/enable
|
在任意进程执行 sync 时输出日志
| 1 2 3 |
echo 1 > /sys/kernel/debug/tracing/events/ext4/ext4_sync_file_enter/enable
|
然后观察日志输出：
| 1 2 3 |
cat /sys/kernel/debug/tracing/trace_pipe
|
输出信息如下：
可以看到 jbd2和 java-17417进程有大量的 sync，瞬间刷出大量日志，因此基本确定 java-17417进程。17417为 java 进程的 tid，ps 看一下是哪个任务导致的：
| 1 2 3 |
ps -efL |grep 17417
|
-L 或-T 参数显示线程 id，ps 获取到 pid 和程序路径后，发现是 zk 进程，很让人疑惑，zk 怎么会大量 sync 呢，trace 一下他在做什么：
| 1 2 3 |
strace -f -p 17417
|
输出信息如下：
根据 fd 号去看看这是什么文件：
| 1 2 3 |
ll /proc/{zk_pid}/fd/74
|
发现是 log.xxx，是 zk 的事务日志，zk 频繁写事务日志，是由于对 zk 执行了大量写操作导致的。为了确认是 zk 引起的问题，将 zk 的数据路径修改到其他盘，重启 zk 节点，发现变成其他盘的 util 跑满了，到此为止确认是 zk 引起的。
解决方式
经过与业务沟通后，确认是业务进程设计不合理，对 zk 执行大量写操作，暂时采取临时措施，将 zk 的数据路径调整到系统盘，系统盘为 ssd
没有相关文章.
（转载请注明作者和出处 easyice.cn ，请勿用于任何商业用途）