太極限了,JDK的這個(gè)Bug都能被我踩到
hello,大家好呀,我是小樓。
之前遇到個(gè)文件監(jiān)聽(tīng)變更的問(wèn)題,剛好這周末有空研究了一番,整理出來(lái)分享給大家。
從一次故障說(shuō)起
我們還是從故障說(shuō)起,這樣更加貼近實(shí)際,也能讓大家更快速理解背景。
有一個(gè)下發(fā)配置的服務(wù),這個(gè)配置服務(wù)的實(shí)現(xiàn)有點(diǎn)特殊,服務(wù)端下發(fā)配置到各個(gè)服務(wù)的本地文件,當(dāng)然中間經(jīng)過(guò)了一個(gè)agent,如果沒(méi)有agent也就無(wú)法寫(xiě)本地文件,然后由client端的程序監(jiān)聽(tīng)這個(gè)配置文件,一旦文件有變更,就重新加載配置,畫(huà)個(gè)架構(gòu)圖大概是這樣:
今天的重點(diǎn)是文件的變更該如何監(jiān)聽(tīng)(watch),我們當(dāng)時(shí)的實(shí)現(xiàn)非常簡(jiǎn)單:
- 單獨(dú)起個(gè)線程,定時(shí)去獲取文件的最后更新時(shí)間戳(毫秒級(jí))。
- 記錄每個(gè)文件的最后更新時(shí)間戳,根據(jù)這個(gè)時(shí)間戳是否變化來(lái)判斷文件是否有變更。
從上述簡(jiǎn)單的描述,我們能看出這樣實(shí)現(xiàn)有一些缺點(diǎn):
- 無(wú)法實(shí)時(shí)感知文件的變更,感知誤差在于輪詢文件最后更新時(shí)間的間隔。
- 精確到毫秒級(jí),如果同一毫秒內(nèi)發(fā)生2次變更,且輪詢時(shí)剛好落在這2次變更的中間時(shí),后一次變更將無(wú)法感知,但這概率很小。
還好,上述兩個(gè)缺點(diǎn)幾乎沒(méi)有什么大的影響。
但后來(lái)還是發(fā)生了一次比較嚴(yán)重的線上故障,這是為什么呢?因?yàn)橐粋€(gè)JDK的BUG,這里直接貼出罪魁禍?zhǔn)祝?/p>
BUG詳見(jiàn):https://bugs.java.com/bugdatabase/view_bug.do?bug_id=8177809。
在某些JDK版本下,獲取文件的最后更新時(shí)間戳?xí)G失毫秒精度,總是返回整秒的時(shí)間戳,為了直觀感受,寫(xiě)了個(gè)demo分別在jdk1.8.0_261和jdk_11.0.6測(cè)試(均為MacOs):
- jdk_1.8.0_261
- jdk_11.0.6
如果是在這個(gè)BUG的影響下,只要同一秒內(nèi)有2次變更,且讀取文件最后時(shí)間戳位于這2次變更之間的時(shí)間,第2次變更就無(wú)法被程序感知了,同1秒這個(gè)概率比同一毫秒大的多的多,所以當(dāng)然就被觸發(fā)了,導(dǎo)致了一次線上故障。
這就好比之前是滄海一粟,現(xiàn)在變成了大海里摸到某條魚(yú)的概率。這也能被我們碰到,真是有點(diǎn)極限~
WatchService—JDK內(nèi)置的文件變更監(jiān)聽(tīng)
當(dāng)了解到之前的實(shí)現(xiàn)存在BUG后,我就去搜了一下Java下如何監(jiān)聽(tīng)文件變更,果然被我找到了WatchService。
說(shuō)是WatchService可以監(jiān)聽(tīng)一個(gè)目錄,對(duì)目錄下的文件新增、變更、刪除進(jìn)行監(jiān)聽(tīng)。于是我很快就寫(xiě)了個(gè)demo進(jìn)行測(cè)試:
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)聽(tīng),然后每隔5毫秒往文件寫(xiě)數(shù)據(jù),理論上來(lái)說(shuō),應(yīng)該能收到3次事件,但實(shí)際上很奇怪,仔細(xì)看接收到modify事件的時(shí)間大概是第一次文件修改后的9.5s左右,很奇怪,先記著,我們讀一下WatchService源碼:
>>> 1652076266609 - 1652076257097
9512
WatchService原理
WatchService watchService = FileSystems.getDefault().newWatchService()
通過(guò)debug發(fā)現(xiàn),這里的watchService實(shí)際上是PollingWatchService的實(shí)例,直接看PollingWatchService的實(shí)現(xiàn):
PollingWatchService上來(lái)就起了個(gè)線程,這讓我隱隱不安。再找一下這個(gè)scheduledExecutor在哪里用到:
每隔一段時(shí)間(默認(rèn)為10s)去poll下,這個(gè)poll干了什么?代碼太長(zhǎng),我截出關(guān)鍵部分:
果然,和我們的實(shí)現(xiàn)類似,也是去讀文件的最后更新時(shí)間,根據(jù)時(shí)間的變化來(lái)發(fā)出變更事件。
換句話說(shuō),在某些JDK版本下,他也是有BUG的!
這也就解釋了上文提到的事件監(jiān)聽(tīng)為什么是在第一個(gè)9.5s之后才發(fā)出,因?yàn)楸O(jiān)聽(tīng)注冊(cè)后,sleep了500ms后修改文件,10s輪詢,剛好9.5s后拿到第一輪事件。
inotify—Linux內(nèi)核提供的文件監(jiān)聽(tīng)機(jī)制
至此,我想起了linux上的tail命令,tail 是在文件有變更的情況下輸出文件的末尾,理論上也是監(jiān)聽(tīng)了文件變更,這塊剛好在很久之前聽(tīng)過(guò)一個(gè)技術(shù)大佬分享如何自己實(shí)現(xiàn)tail命令,用到的底層技術(shù)就是inotify。
簡(jiǎn)單來(lái)說(shuō),inotify是linux內(nèi)核提供的一種監(jiān)控文件變更事件的系統(tǒng)調(diào)用。如果基于此來(lái)實(shí)現(xiàn),不就可以規(guī)避JDK的BUG了嗎?
但奇怪的是為什么Java沒(méi)有用這個(gè)來(lái)實(shí)現(xiàn)呢?于是我又搜了搜,發(fā)現(xiàn)谷歌似乎有一個(gè)庫(kù),但被刪了,看不到代碼:
github上又搜到一個(gè):https://github.com/sunmingshi/Jinotify。
看起來(lái)是一個(gè)native的實(shí)現(xiàn),需要自己編譯.so文件,這樣就比較蛋疼了。
記得上次這么蛋疼還是在折騰Java的unix domain socket,也是找到了一個(gè)google的庫(kù),測(cè)試沒(méi)問(wèn)題,放到線上就崩了~不得不說(shuō)google還是厲害,JDK提供不了的庫(kù),我們來(lái)提供!
于是我?guī)е@個(gè)疑問(wèn)去問(wèn)了一個(gè)搞JVM開(kāi)發(fā)的朋友,結(jié)果他告訴我,Java也可以使用inotify!
瞬間斗志來(lái)了,難道是我測(cè)試的姿勢(shì)不對(duì)?
我又去翻了一遍Java文檔,發(fā)現(xiàn)在角落隱藏了這么一段話:
也就是說(shuō),不同的平臺(tái)下會(huì)使用不同的實(shí)現(xiàn),PollingWatchService是在系統(tǒng)不支持inotify的情況下使用的兜底策略。
于是將watchService的類型打印出來(lái),在Mac上打印為:
class sun.nio.fs.PollingWatchService
在Linux上是:
class sun.nio.fs.LinuxWatchService
LinuxWatchService在Mac上是找不到這個(gè)類,我猜測(cè)應(yīng)該是Mac版的JDK壓根沒(méi)把這塊代碼打包進(jìn)來(lái)。
原來(lái)我本地測(cè)試都走了兜底策略,看來(lái)是測(cè)了個(gè)寂寞。
于是我寫(xiě)了個(gè)demo再測(cè)試一把:
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ù)的?
再次回到開(kāi)頭的故障,我們是如何修復(fù)的呢?由于下發(fā)的文件和讀取文件的程序都是我們可控的,所以我們繞過(guò)了這個(gè)BUG,給每個(gè)文件寫(xiě)一個(gè)version,可以用文件內(nèi)容md5值作為version,寫(xiě)入一個(gè)特殊文件,讀取時(shí)先讀version,當(dāng)version變化時(shí)再重新載入文件。
可能你要問(wèn)了,為什么不用WatchService呢?
我也問(wèn)了負(fù)責(zé)人,據(jù)說(shuō)inotify在docker上運(yùn)行的不是很好,經(jīng)常會(huì)丟失事件,不是Java的問(wèn)題,所有語(yǔ)言都存在這個(gè)問(wèn)題,所以一直沒(méi)有使用。不過(guò)這塊找不到相關(guān)的資料,也無(wú)法證明,所以暫時(shí)擱置。
最后說(shuō)幾句
有些BUG,不踩過(guò)就很難避免,代碼只要存在BUG的可能性,就一定會(huì)暴露出來(lái),只是時(shí)間問(wèn)題。
我們要在技術(shù)上深入探究,小心求證,但產(chǎn)品上不必執(zhí)著,可另辟蹊徑。