从应用到内核查接口超时（中）

应用复现

---

接着上文 从应用到内核查接口超时（上） 继续排查致使接口超时的缘由。

转载随意，文章会持续修订，请注明来源地址：https://zhenbianshu.github.io 。

Jdk 的 native 方法固然不是终点，虽然发现 Jdk、docker、操做系统 Bug 的可能性极小，但再往底层查却极可能发现一些常见的配置错误。

为了便于复现，我用 JMH 写了一个简单的 demo，控制速度不断地经过 log4j2 写入日志。将项目打包成 jar 包，就能够很方便地在各处运行了。

@BenchmarkMode(Mode.AverageTime) @OutputTimeUnit(TimeUnit.MICROSECONDS) @State(Scope.Benchmark) @Threads(5) public class LoggerRunner { public static void main(String[] args) throws RunnerException { Options options = new OptionsBuilder() .include(LoggerRunner.class.getName()) .warmupIterations(2) .forks(1) .measurementIterations(1000) .build(); new Runner(options).run(); } } 

我比较怀疑是 docker 的缘由。可是在 docker 内外运行了 jar 包却发现都能很简单地复现日志停顿问题。而 jdk 版本众多，我准备首先排查操做系统配置问题。

系统调用

---

strace 命令很早就使用过，不久前还用它分析过 shell 脚本执行慢的问题( 解决问题，别扩展问题)，但我仍是不太习惯把 Java 和它联系起来，幸亏有部门的老司机指点，因而就使用 strace 分析了一波 Java 应用。

命令跟分析普通脚本同样， strace -T -ttt -f -o strace.log java -jar log.jar， -T 选项能够将每个系统调用的耗时打印到系统调用的结尾。固然排查时使用 -p pid 附加到 tomcat 上也是能够的，虽然会有不少容易混淆的系统调用。

对比 jmh 压测用例输出的 log4j2.info() 方法耗时，发现了下图中的情况。

一次 write 系统调用居然消耗了 147ms，很明显地，问题出在 write 系统调用上。

文件系统

---

结构

这时候就要好好回想一下操做系统的知识了。

在 linux 系统中，万物皆文件，而为了给不一样的介质提供一种抽象的接口，在应用层和系统层之间，抽象了一个虚拟文件系统层（virtual file system, VFS）。上层的应用程序经过 系统调用 system call 操做虚拟文件系统，进而反馈到下层的硬件层。

因为硬盘等介质操做速度与内存不在同一个数量级上，为了平衡二者之间的速度，linux 便把文件映射到内存中，将硬盘单位块(block)对应到内存中的一个 页(page)上。这样，当须要操做文件时，直接操做内存就能够了。当缓冲区操做达到必定量或到达必定的时间后，再将变动统一刷到磁盘上。这样便有效地减小了磁盘操做，应用也没必要等待硬盘操做结束，响应速度获得了提高。

而 write 系统调用会将数据写到内存中的 page cache，将 page 标记为 脏页(dirty) 后返回。

linux 的 writeback 机制

对于将内存缓冲区的内容刷到磁盘上，则有两种方式：

首先，应用程序在调用 write 系统调用写入数据时，若是发现 page cache 的使用量大于了设定的大小，便会主动将内存中的脏页刷到硬盘上。在此期间，全部的 write 系统调用都会被阻塞。

系统固然不会容忍不定时的 write 阻塞，linux 还会定时启动 pdflush 线程，判断内存页达到必定的比例或脏页存活时间达到设定的时间，将这些脏页刷回到磁盘上，以免被动刷缓冲区，这种机制就是 linux 的 writeback 机制。

猜想

了解了以上基础知识，那么对于 write 系统调用为何会被阻塞，提出了两种可能：

• page cache 可用空间不足，致使触发了主动的 flush，此时会阻塞全部对此 device 的 write。
• 写入过程被其余事务阻塞。

首先对于第一种可能： 查看系统配置 dirty_ratio 的大小： 20。此值是 page cache 占用系统可用内存(real mem + swap)的最大百分比， 咱们的内存为 32G，没有启用 swap，则实际可用的 page cache 大小约为 6G。

另外，与 pdflush 相关的系统配置：系统会每 vm.dirty_writeback_centisecs (5s) 唤醒一次 pdflush 线程， 发现脏页比例超过 vm.dirty_background_ratio (10%) 或 脏页存活时间超过 vm.dirty_expire_centisecs(30s) 时，会将脏页刷回硬盘。

查看 /proc/meminfo 内 Dirty/Writeback 项的变化，并对比服务的文件写入速度，结论是数据会被 pdflush 刷回到硬盘，不会触发被动 flush 以阻塞 write 系统调用。

ext4 的 journal 特性

---

write 被阻塞的缘由

继续搜索资料，在一篇文章(Why buffered writes are sometimes stalled )中看到 write 系统调用被阻塞有如下可能：

• 要写入的数据依赖读取的结果时。但记录日志不依赖读文件；
• wirte page 时有别的线程在调用 fsync() 等主动 flush 脏页的方法。但因为锁的存在，log 在写入时不会有其余的线程操做；
• 格式为 ext3/4 的文件系统在记录 journal log 时会阻塞 write。而咱们的系统文件格式为 ext4。维基百科上的一个条目（ https://en.wikipedia.org/wiki/Journaling_block_device ） 也描述了这种可能。

journal

journal 是 文件系统保证数据一致性的一种手段，在写入数据前，将即将进行的各个操做步骤记录下来，一旦系统掉电，恢复时读取这些日志继续操做就能够了。但批量的 journal commit 是一个事务，flush 时会阻塞 write 的提交。

咱们可使用 dumpe2fs /dev/disk | grep features 查看磁盘支持的特性，其中有 has_journal 表明文件系统支持 journal 特性。

ext4 格式的文件系统在挂载时能够选择 (jouranling、ordered、writeback) 三种之一的 journal 记录模式。

三种模式分别有如下特性：

• journal： 在将数据写入文件系统前，必须等待 metadata 和 journal 已经落盘了。
• ordered： 不记录数据的 journal，只记录 metadata 的 journal 日志，且须要保证全部数据在其 metadata journal 被 commit 以前落盘。 ext4 在不添加挂载参数时使用此模式。
• writeback: 数据可能在 metadata journal 被提交以后落盘，可能致使旧数据在系统掉电后恢复到磁盘中。

固然，咱们也能够选择直接禁用 journal，使用 tune2fs -O ^has_journal /dev/disk，只能操做未被挂载的磁盘。

猜想由于 journal 触发了脏页落盘，而脏页落盘致使 write 被阻塞，因此解决 journal 问题就能够解决接口超时问题。

解决方案与压测结果

---

如下是我总结的几个接口超时问题的解决方案：

1. log4j2 日志模式改异步。但有可能会在系统重启时丢失日志，另外在异步队列 ringbuffer 被填满未消费后，新日志会自动使用同步模式。
2. 调整系统刷脏页的配置，将检查脏页和脏页过时时间设置得更短(1s 之内)。但理论上会略微提高系统负载（未明显观察到）。
3. 挂载硬盘时使用 data=writeback 选项修改 journal 模式。 但可能致使系统重启后文件包含已删除的内容。
4. 禁用 ext4 的 journal 特性。但可能会致使系统文件的不一致。
5. 把 ext4 的 journal 日志迁移到更快的磁盘上，如 ssd、闪存等。操做复杂，不易维护。
6. 使用 xfs、fat 等 文件系统格式。特性不了解，影响不可知。

固然，对于这几种方案，我也作了压测，如下是压测的结果。

 

	文件系统特性	接口超时比例
	ext4（同线上）	0.202%
	xfs文件系统	0.06%
	page过时时间和pdflush启动时间都设置为 0.8s	0.017%
	ext4 挂载时 journal 模式为 writeback	0%
	禁用 ext4 的 journal 特性	0%
	log4j2 使用异步日志	0%

小结

---

接口超时问题总算是告一段落，查了好久，不过解决它以后也很是有成就感。遗憾的是没有在 linux 内核代码中找到证据，160M 的代码，分层也不熟悉，实在是无从查起，但愿之后有机会能慢慢接触吧。

程序员仍是要懂些操做系统知识的，不只帮咱们在应对这种诡异的问题时不至于一筹莫展，也能够在作一些业务设计时能有所参考。

又熟悉了一些系统工具和命令，脚手架上又丰富了。

关于本文有什么疑问能够在下面留言交流，若是您以为本文对您有帮助，欢迎关注个人 微博 或 GitHub 。您也能够在个人 博客REPO 右上角点击 Watch 并选择 Releases only 项来 订阅 个人博客，有新文章发布会第一时间通知您。