太極限了，JDK的這個(gè)Bug都能被我踩到

作者：小樓MrRoshi 2022-05-10 12:20:04

如果是在這個(gè)BUG的影響下，只要同一秒內(nèi)有2次變更，且讀取文件最后時(shí)間戳位于這2次變更之間的時(shí)間，第2次變更就無法被程序感知了，同1秒這個(gè)概率比同一毫秒大的多的多，所以當(dāng)然就被觸發(fā)了，導(dǎo)致了一次線上故障。

hello，大家好呀，我是小樓。

之前遇到個(gè)文件監(jiān)聽變更的問題，剛好這周末有空研究了一番，整理出來分享給大家。

從一次故障說起

我們還是從故障說起，這樣更加貼近實(shí)際，也能讓大家更快速理解背景。

有一個(gè)下發(fā)配置的服務(wù)，這個(gè)配置服務(wù)的實(shí)現(xiàn)有點(diǎn)特殊，服務(wù)端下發(fā)配置到各個(gè)服務(wù)的本地文件，當(dāng)然中間經(jīng)過了一個(gè)agent，如果沒有agent也就無法寫本地文件，然后由client端的程序監(jiān)聽這個(gè)配置文件，一旦文件有變更，就重新加載配置，畫個(gè)架構(gòu)圖大概是這樣：

今天的重點(diǎn)是文件的變更該如何監(jiān)聽(watch)，我們當(dāng)時(shí)的實(shí)現(xiàn)非常簡單：

單獨(dú)起個(gè)線程，定時(shí)去獲取文件的最后更新時(shí)間戳(毫秒級)。
記錄每個(gè)文件的最后更新時(shí)間戳，根據(jù)這個(gè)時(shí)間戳是否變化來判斷文件是否有變更。

從上述簡單的描述，我們能看出這樣實(shí)現(xiàn)有一些缺點(diǎn)：

無法實(shí)時(shí)感知文件的變更，感知誤差在于輪詢文件最后更新時(shí)間的間隔。
精確到毫秒級，如果同一毫秒內(nèi)發(fā)生2次變更，且輪詢時(shí)剛好落在這2次變更的中間時(shí)，后一次變更將無法感知，但這概率很小。

還好，上述兩個(gè)缺點(diǎn)幾乎沒有什么大的影響。

但后來還是發(fā)生了一次比較嚴(yán)重的線上故障，這是為什么呢?因?yàn)橐粋€(gè)JDK的BUG，這里直接貼出罪魁禍?zhǔn)祝?/p>

BUG詳見：https://bugs.java.com/bugdatabase/view_bug.do?bug_id=8177809。

在某些JDK版本下，獲取文件的最后更新時(shí)間戳?xí)G失毫秒精度，總是返回整秒的時(shí)間戳，為了直觀感受，寫了個(gè)demo分別在jdk1.8.0_261和jdk_11.0.6測試(均為MacOs)：

jdk_1.8.0_261

jdk_11.0.6

這就好比之前是滄海一粟，現(xiàn)在變成了大海里摸到某條魚的概率。這也能被我們碰到，真是有點(diǎn)極限~

WatchService—JDK內(nèi)置的文件變更監(jiān)聽

當(dāng)了解到之前的實(shí)現(xiàn)存在BUG后，我就去搜了一下Java下如何監(jiān)聽文件變更，果然被我找到了WatchService。

說是WatchService可以監(jiān)聽一個(gè)目錄，對目錄下的文件新增、變更、刪除進(jìn)行監(jiān)聽。于是我很快就寫了個(gè)demo進(jìn)行測試：

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目錄進(jìn)行監(jiān)聽，然后每隔5毫秒往文件寫數(shù)據(jù)，理論上來說，應(yīng)該能收到3次事件，但實(shí)際上很奇怪，仔細(xì)看接收到modify事件的時(shí)間大概是第一次文件修改后的9.5s左右，很奇怪，先記著，我們讀一下WatchService源碼：

>>> 1652076266609 - 1652076257097
9512

WatchService原理

WatchService watchService = FileSystems.getDefault().newWatchService()

通過debug發(fā)現(xiàn)，這里的watchService實(shí)際上是PollingWatchService的實(shí)例，直接看PollingWatchService的實(shí)現(xiàn)：

PollingWatchService上來就起了個(gè)線程，這讓我隱隱不安。再找一下這個(gè)scheduledExecutor在哪里用到：

每隔一段時(shí)間(默認(rèn)為10s)去poll下，這個(gè)poll干了什么?代碼太長，我截出關(guān)鍵部分：

果然，和我們的實(shí)現(xiàn)類似，也是去讀文件的最后更新時(shí)間，根據(jù)時(shí)間的變化來發(fā)出變更事件。

換句話說，在某些JDK版本下，他也是有BUG的!

這也就解釋了上文提到的事件監(jiān)聽為什么是在第一個(gè)9.5s之后才發(fā)出，因?yàn)楸O(jiān)聽注冊后，sleep了500ms后修改文件，10s輪詢，剛好9.5s后拿到第一輪事件。

inotify—Linux內(nèi)核提供的文件監(jiān)聽機(jī)制

至此，我想起了linux上的tail命令，tail 是在文件有變更的情況下輸出文件的末尾，理論上也是監(jiān)聽了文件變更，這塊剛好在很久之前聽過一個(gè)技術(shù)大佬分享如何自己實(shí)現(xiàn)tail命令，用到的底層技術(shù)就是inotify。

簡單來說，inotify是linux內(nèi)核提供的一種監(jiān)控文件變更事件的系統(tǒng)調(diào)用。如果基于此來實(shí)現(xiàn)，不就可以規(guī)避JDK的BUG了嗎?

但奇怪的是為什么Java沒有用這個(gè)來實(shí)現(xiàn)呢?于是我又搜了搜，發(fā)現(xiàn)谷歌似乎有一個(gè)庫，但被刪了，看不到代碼:

github上又搜到一個(gè)：https://github.com/sunmingshi/Jinotify。

看起來是一個(gè)native的實(shí)現(xiàn)，需要自己編譯.so文件，這樣就比較蛋疼了。

記得上次這么蛋疼還是在折騰Java的unix domain socket，也是找到了一個(gè)google的庫，測試沒問題，放到線上就崩了~不得不說google還是厲害，JDK提供不了的庫，我們來提供！

于是我?guī)е@個(gè)疑問去問了一個(gè)搞JVM開發(fā)的朋友，結(jié)果他告訴我，Java也可以使用inotify!

瞬間斗志來了，難道是我測試的姿勢不對?

我又去翻了一遍Java文檔，發(fā)現(xiàn)在角落隱藏了這么一段話：

也就是說，不同的平臺(tái)下會(huì)使用不同的實(shí)現(xiàn)，PollingWatchService是在系統(tǒng)不支持inotify的情況下使用的兜底策略。

于是將watchService的類型打印出來，在Mac上打印為：

class sun.nio.fs.PollingWatchService

在Linux上是：

class sun.nio.fs.LinuxWatchService

LinuxWatchService在Mac上是找不到這個(gè)類，我猜測應(yīng)該是Mac版的JDK壓根沒把這塊代碼打包進(jìn)來。

原來我本地測試都走了兜底策略，看來是測了個(gè)寂寞。

于是我寫了個(gè)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上能收到的事件比本地多的多，而且接收事件的時(shí)間明顯實(shí)時(shí)多了。

為了更加準(zhǔn)確的驗(yàn)證是inotify，用strace抓一下系統(tǒng)調(diào)用，由于JVM fork出的子進(jìn)程較多，所以要加-f命令，輸出太多可以存入文件再分析：

strace -f -o s.txt java FileTime

果然是用到了inotify系統(tǒng)調(diào)用的，再次驗(yàn)證了我們的猜想。

故障是如何修復(fù)的?

再次回到開頭的故障，我們是如何修復(fù)的呢?由于下發(fā)的文件和讀取文件的程序都是我們可控的，所以我們繞過了這個(gè)BUG，給每個(gè)文件寫一個(gè)version，可以用文件內(nèi)容md5值作為version，寫入一個(gè)特殊文件，讀取時(shí)先讀version，當(dāng)version變化時(shí)再重新載入文件。

可能你要問了，為什么不用WatchService呢?

我也問了負(fù)責(zé)人，據(jù)說inotify在docker上運(yùn)行的不是很好，經(jīng)常會(huì)丟失事件，不是Java的問題，所有語言都存在這個(gè)問題，所以一直沒有使用。不過這塊找不到相關(guān)的資料，也無法證明，所以暫時(shí)擱置。