惊！发现了 JDK 的一个 bug
共 4045字，需浏览 9分钟
·
2022-05-19 21:58
hello，大家好呀，我是二哥呀。
之前遇到个文件监听变更的问题，刚好这昨天晚上有空研究了一番，整理出来分享给大家。
从一次故障说起
我们还是从故障说起，这样更加贴近实际，也能让大家更快速理解背景。
有一个下发配置的服务，这个配置服务的实现有点特殊，服务端下发配置到各个服务的本地文件，当然中间经过了一个 agent，如果没有 agent 也就无法写本地文件，然后由 client 端的程序监听这个配置文件，一旦文件有变更，就重新加载配置，画个架构图大概是这样：
今天的重点是文件的变更该如何监听（watch），我们当时的实现非常简单：
单独起个线程，定时去获取文件的最后更新时间戳（毫秒级） 记录每个文件的最后更新时间戳，根据这个时间戳是否变化来判断文件是否有变更
从上述简单的描述，我们能看出这样实现有一些缺点：
无法实时感知文件的变更，感知误差在于轮询文件最后更新时间的间隔 精确到毫秒级，如果同一毫秒内发生 2 次变更，且轮询时刚好落在这 2 次变更的中间时，后一次变更将无法感知，但这概率很小
还好，上述两个缺点几乎没有什么大的影响。
但后来还是发生了一次比较严重的线上故障，这是为什么呢？因为一个 JDK 的 BUG，这里直接贴出罪魁祸首：
BUG 详见：https://bugs.java.com/bugdatabase/view_bug.do?bug_id=8177809
在某些 JDK 版本下，获取文件的最后更新时间戳会丢失毫秒精度，总是返回整秒的时间戳，为了直观感受，写了个 demo 分别在jdk1.8.0_261和jdk_11.0.6测试（均为 MacOs）：
jdk_1.8.0_261 
jdk_11.0.6 
如果是在这个 BUG 的影响下，只要同一秒内有 2 次变更，且读取文件最后时间戳位于这 2 次变更之间的时间，第 2 次变更就无法被程序感知了，同 1 秒这个概率比同一毫秒大的多的多，所以当然就被触发了，导致了一次线上故障。
这就好比之前是沧海一粟，现在变成了大海里摸到某条鱼的概率。这也能被我们碰到，真是有点极限~
WatchService—JDK 内置的文件变更监听
当了解到之前的实现存在 BUG 后，我就去搜了一下 Java 下如何监听文件变更，果然被我找到了WatchService。
说是 WatchService 可以监听一个目录，对目录下的文件新增、变更、删除进行监听。于是我很快就写了个 demo 进行测试：
public static void watchDir(String dir) {
Path path = Paths.get(dir);
try (WatchService watchService = FileSystems.getDefault().newWatchService()) {
path.register(watchService, StandardWatchEventKinds.ENTRY_CREATE, StandardWatchEventKinds.ENTRY_MODIFY, StandardWatchEventKinds.ENTRY_DELETE, StandardWatchEventKinds.OVERFLOW);
while (true) {
WatchKey key = watchService.take();
for (WatchEvent watchEvent : key.pollEvents()) {
if (watchEvent.kind() == StandardWatchEventKinds.ENTRY_CREATE) {
System.out.println("create..." + System.currentTimeMillis());
} else if (watchEvent.kind() == StandardWatchEventKinds.ENTRY_MODIFY) {
System.out.println("modify..." + System.currentTimeMillis());
} else if (watchEvent.kind() == StandardWatchEventKinds.ENTRY_DELETE) {
System.out.println("delete..." + System.currentTimeMillis());
} else if (watchEvent.kind() == StandardWatchEventKinds.OVERFLOW) {
System.out.println("overflow..." + System.currentTimeMillis());
}
}
if (!key.reset()) {
System.out.println("reset false");
return;
}
}
} catch (Exception e) {
e.printStackTrace();
}
}
先对/tmp/file_test目录进行监听，然后每隔 5 毫秒往文件写数据，理论上来说，应该能收到 3 次事件，但实际上很奇怪，仔细看接收到modify事件的时间大概是第一次文件修改后的9.5s左右，很奇怪，先记着，我们读一下 WatchService 源码
>>> 1652076266609 - 1652076257097
9512
WatchService 原理
WatchService watchService = FileSystems.getDefault().newWatchService()
通过 debug 发现，这里的 watchService 实际上是 PollingWatchService 的实例，直接看 PollingWatchService 的实现：
PollingWatchService 上来就起了个线程，这让我隐隐不安。再找一下这个 scheduledExecutor 在哪里用到：
每隔一段时间（默认为 10s）去 poll 下，这个 poll 干了什么？代码太长，我截出关键部分：
果然，和我们的实现类似，也是去读文件的最后更新时间，根据时间的变化来发出变更事件。
换句话说，在某些 JDK 版本下，他也是有 BUG 的！
这也就解释了上文提到的事件监听为什么是在第一个 9.5s 之后才发出，因为监听注册后，sleep 了 500ms 后修改文件，10s 轮询，刚好 9.5s 后拿到第一轮事件。
inotify—Linux 内核提供的文件监听机制
至此，我想起了 linux 上的tail命令，tail 是在文件有变更的情况下输出文件的末尾，理论上也是监听了文件变更，这块刚好在很久之前听过一个技术大佬分享如何自己实现tail命令，用到的底层技术就是inotify
简单来说，inotify 是 linux 内核提供的一种监控文件变更事件的系统调用。如果基于此来实现，不就可以规避 JDK 的 BUG 了吗？
但奇怪的是为什么 Java 没有用这个来实现呢？于是我又搜了搜，发现谷歌似乎有一个库，但被删了，看不到代码:
github 上又搜到一个：https://github.com/sunmingshi/Jinotify
看起来是一个 native 的实现，需要自己编译.so 文件，这样就比较蛋疼了。
记得上次这么蛋疼还是在折腾 Java 的 unix domain socket，也是找到了一个 google 的库，测试没问题，放到线上就崩了~不得不说 google 还是厉害，JDK 提供不了的库，我们来提供~
于是我带着这个疑问去问了一个搞 JVM 开发的朋友，结果他告诉我，Java 也可以使用 inotify！
瞬间斗志来了，难道是我测试的姿势不对？
我又去翻了一遍 Java 文档，发现在角落隐藏了这么一段话：
也就是说，不同的平台下会使用不同的实现，PollingWatchService 是在系统不支持 inotify 的情况下使用的兜底策略。
于是将 watchService 的类型打印出来，在 Mac 上打印为：
class sun.nio.fs.PollingWatchService
在 Linux 上是：
class sun.nio.fs.LinuxWatchService
LinuxWatchService 在 Mac 上是找不到这个类，我猜测应该是 Mac 版的 JDK 压根没把这块代码打包进来。
原来我本地测试都走了兜底策略，看来是测了个寂寞。
于是我写了个 demo 再测试一把：
public static void main(String[] args) throws Exception {
Thread thread = new Thread(() -> watchDir("/tmp/file_test"));
thread.setDaemon(false);
thread.start();
Thread.sleep(500L);
for (int i = 0; i < 3; i++) {
String path = "/tmp/file_test/test";
FileWriter fileWriter = new FileWriter(path);
fileWriter.write(i);
fileWriter.close();
File file = new File(path);
System.out.println(file.lastModified());
Thread.sleep(5);
}
}
本地 Mac
Linux
可以看出，Linux 上能收到的事件比本地多的多，而且接收事件的时间明显实时多了。
为了更加准确的验证是 inotify，用strace抓一下系统调用，由于 JVM fork 出的子进程较多，所以要加-f命令，输出太多可以存入文件再分析：
strace -f -o s.txt java FileTime
果然是用到了 inotify 系统调用的，再次验证了我们的猜想。
故障是如何修复的？
再次回到开头的故障，我们是如何修复的呢？由于下发的文件和读取文件的程序都是我们可控的，所以我们绕过了这个 BUG，给每个文件写一个version，可以用文件内容 md5 值作为 version，写入一个特殊文件，读取时先读 version，当 version 变化时再重新载入文件。
可能你要问了，为什么不用 WatchService 呢？
我也问了负责人，据说 inotify 在 docker 上运行的不是很好，经常会丢失事件，不是 Java 的问题，所有语言都存在这个问题，所以一直没有使用。不过这块找不到相关的资料，也无法证明，所以暂时搁置。
最后说几句
有些 BUG，不踩过就很难避免，代码只要存在 BUG 的可能性，就一定会暴露出来，只是时间问题。
我们要在技术上深入探究，小心求证，但产品上不必执着，可另辟蹊径。
另外解决不了的问题时可以找这个领域的资深人士，所以平时没事认识几个大牛很有必要。我们今天的分析到此结束，我是二哥，下期再见~
最后，如果你感兴趣的话，欢迎加入 二哥的编程知识星球 （点击了解详情），和 160 多名 小伙伴一起交流学习，这是一个 Java 学习指南 + 编程实战的私密圈子，你可以向二哥提问、帮你制定学习计划、跟着二哥一起做实战项目。
没有什么使我停留——除了目的，纵然岸旁有玫瑰、有绿荫、有宁静的港湾，我是不系之舟。
推荐阅读：
