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

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í)間戳（毫秒級(jí)）
• 記錄每個(gè)文件的最后更新時(shí)間戳，根據(jù)這個(gè)時(shí)間戳是否變化來判斷文件是否有變更

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

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

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

但后來還是發(fā)生了一次比較嚴(yán)重的線上故障，這是為什么呢？因?yàn)橐粋€(gè)JDK的BUG，這里直接貼出罪魁禍?zhǔn)祝?img class="rich_pages wxw-img" data-ratio="0.5790987535953979" src="https://filescdn.proginn.com/935cb9640be0364a8fbcaf19a4f33d1f/235f3dd3f0073fef3b6e3320059fb828.webp" data-type="png" data-w="2086" style="border-radius: 6px;display: block;margin: 20px auto;object-fit: contain;box-shadow: rgb(153, 153, 153) 2px 4px 7px;height: auto !important;">

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

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

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

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

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

說是WatchService可以監(jiān)聽一個(gè)目錄，對(duì)目錄下的文件新增、變更、刪除進(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();
????}
}

先對(duì)/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)聽注冊(cè)后，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！

瞬間斗志來了，難道是我測試的姿勢不對(duì)？

我又去翻了一遍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í)擱置。

最后說幾句

有些BUG，不踩過就很難避免，代碼只要存在BUG的可能性，就一定會(huì)暴露出來，只是時(shí)間問題。

我們要在技術(shù)上深入探究，小心求證，但產(chǎn)品上不必執(zhí)著，可另辟蹊徑。

我們今天的分析到此結(jié)束，我是小樓，下期再見~

• 搜索關(guān)注微信公眾號(hào)"捉蟲大師"，后端技術(shù)分享，架構(gòu)設(shè)計(jì)、性能優(yōu)化、源碼閱讀、問題排查、踩坑實(shí)踐。
• 技術(shù)交流群加我微信MrRoshi備注「加群」，拉你進(jìn)群，各領(lǐng)域大佬帶你飛