我的程序跑了 60 多小时，就是为了让你看一眼 JDK 的 BUG 导致的内存泄漏
來源 |?why技術(shù)
荒腔走板
大家好，我是 why，老規(guī)矩，先來一個(gè)簡短的荒腔走板，給冰冷的技術(shù)文注入一絲色彩。
上面圖片中這個(gè)正在奔跑的少年，是正在參加校運(yùn)會(huì)的我，那一年我 18 歲，高三。
參加的項(xiàng)目是 3000 米長跑，那個(gè)時(shí)候長跑一向是大家都不喜歡的運(yùn)動(dòng)，但是我喜歡。
我是從小鄉(xiāng)村出來的，小學(xué)、初中的時(shí)候操場(chǎng)就是用煤渣加泥土鋪成的一圈僅 200 米的跑道。
在那個(gè) 200 米的跑道上，我從小學(xué)跑到初中，跑了不知道多少公里。
初中的時(shí)候參加了學(xué)校長跑隊(duì)的集訓(xùn)。有一天集訓(xùn)完成之后，體育老師給我們說：
你們一定要刻苦訓(xùn)練，將來要到城里面去讀書。你們知道嗎？城里面的跑道一圈是 400 米，還是用塑膠鋪成的跑道，跑上去不知道比這個(gè)煤渣舒服多少倍。我知道長跑很痛苦，但是如果你真的喜歡它，你就得享受這個(gè)痛苦的過程。不要放棄，特別是在最后沖刺階段。因?yàn)?#xff0c;如果你不拼盡全力，等你到終點(diǎn)之后你總是會(huì)覺得自己能再快一點(diǎn)，可惜比賽已經(jīng)結(jié)束了。
后來，我退出了集訓(xùn)隊(duì)，但是老師的話我一直記得。
我也如愿進(jìn)入了城里讀高中，見到了傳說中的“塑膠跑道”。還參加了開在塑膠跑道上的運(yùn)動(dòng)會(huì)。
前段時(shí)間我翻到這張照片的時(shí)候，我就想起了初中集訓(xùn)的一些點(diǎn)滴記憶，也想起了老師的話：享受痛苦，咬牙堅(jiān)持，無愧結(jié)果。
這周，今年的高考也結(jié)束了。
其實(shí)這個(gè)道理放在高考，和高考之后的人生會(huì)面臨的更多更復(fù)雜的挑戰(zhàn)面前都可以。
人生嘛，無非就是：奔跑，跌倒，奔跑。
奔跑吧，驕傲的少年。前面有更多的機(jī)會(huì)和更難的挑戰(zhàn)在等著你。
好了，說回文章。
從一個(gè)BUG說起
前段時(shí)間翻到了一個(gè) JDK 有點(diǎn)意思的 BUG，帶大家一起瞅瞅。
https://bugs.java.com/bugdatabase/view_bug.do?bug_id=8137185
memory leak，內(nèi)存泄漏。
是誰導(dǎo)致的內(nèi)存泄漏呢？
ConcurrentLinkedQueue，這個(gè)隊(duì)列。
這個(gè) BUG 里面說，在 jetty 項(xiàng)目里面也爆出了這個(gè) BUG：
我看了一下，覺得 jetty 的這個(gè)寫的挺有意思的。
我按照 jetty 的這個(gè)講吧，反正都是同一個(gè) JDK BUG 導(dǎo)致的。地址如下：
https://bugs.eclipse.org/bugs/show_bug.cgi?id=477817
我用我八級(jí)半的蹩腳英語給大家翻譯一下這個(gè)叫做 max 的同學(xué)說了些什么。
他說：在 Java 項(xiàng)目里面，錯(cuò)誤的使用 ConcurrentLinkedQueue（文章后面用縮寫 CLQ 代替）會(huì)導(dǎo)致內(nèi)存泄漏的問題。
在 jetty 的 QueuedThreadPool 這個(gè)線程池里面，使用了 CLQ 這個(gè)隊(duì)列，它會(huì)導(dǎo)致內(nèi)存緩慢增長，最終引發(fā)內(nèi)存泄漏。
雖然 QueuedThreadPool 僅僅使用了這個(gè)隊(duì)列的 add 方法和 remove 方法。但不幸的是，remove 方法不會(huì)把隊(duì)列的大小變小，只會(huì)使隊(duì)列里面被刪除的 node 為空。因此，該列表將增長到無窮大。
然后他給了一個(gè)附件，附件里面是一段程序，可以演示這個(gè)問題。
我們先不看他的程序，后面我們統(tǒng)一演示這個(gè)問題。
先給大家看一下 jetty 的 QueuedThreadPool 線程池。
看哪個(gè)版本的 jetty 呢？
可以看到這個(gè) BUG 是在 2015 年 9 月 18 日被爆出來的。所以，我們找一個(gè)這個(gè)日期之前的版本就行。
于是我找了一個(gè) 2015 年 9 月 3 日發(fā)布的? maven 版本：
在這個(gè)版本里面的 QueuedThreadPool 是這樣的：
可以看到，它確實(shí)使用了 CLQ 隊(duì)列。
而從這個(gè)對(duì)象所有被調(diào)用的地方來看，jetty 只使用了這個(gè)隊(duì)列的 size、add、remove(obj) 方法：
和前面 max 同學(xué)描述的一致。
然后這個(gè) max 同學(xué)給了幾張圖片，來佐證他的論點(diǎn)：
主要關(guān)注我框起來的地方，就是說他展示了一張圖片。可以從這圖片中看出內(nèi)存泄漏的問題，而這個(gè)圖片的來源是他們真實(shí)的項(xiàng)目。
這個(gè)項(xiàng)目已經(jīng)運(yùn)行了大約兩天，每五分鐘就會(huì)有一個(gè) web 請(qǐng)求過來。
下面是他給出的圖片：
從他的這個(gè)圖片中，我就只看出了 CLQ 的 node 很多。
但是他說了，他這個(gè)項(xiàng)目請(qǐng)求量并不大，用的 jetty 框架也不應(yīng)該創(chuàng)建這么多的 node 出來。
好了，我們前面分析了 max 同學(xué)說的這個(gè)問題，接下來就是大佬出場(chǎng)，來解惑了：
我們先不看回答，先看看回答問題的人是誰。?
Greg Wilkins，何許人也？
我找到了他的領(lǐng)英地址：
https://www.linkedin.com/in/gregwilkins/?originalSubdomain=au
jetty 項(xiàng)目的領(lǐng)導(dǎo)者，短短的幾個(gè)單詞，就足以讓你直呼牛逼。
高端的食材，往往只需要最簡單的烹飪。高端的人才，往往只需要寥寥數(shù)語的介紹。
大佬的簡歷就是這么樸實(shí)無華，且枯燥。
而且，你看這個(gè)頭像。哎，酸了酸了。果然再次印證了這句話：變禿了，也變強(qiáng)了，并不適用于外國的神仙。
好了，我們看一下這個(gè) jetty 項(xiàng)目的領(lǐng)導(dǎo)者是怎么回答這個(gè)問題的：
首先他用 stupefied 表示了非常的震驚！然后，用到了 Ouch 語氣詞。相當(dāng)于我們常說的：
他說：臥槽，我發(fā)現(xiàn)它不僅導(dǎo)致內(nèi)存泄漏，而且會(huì)隨著時(shí)間的推移，導(dǎo)致隊(duì)列越來越慢。太TM震驚了。
這個(gè)問題一定會(huì)對(duì)使用大量線程的服務(wù)器產(chǎn)生影響......希望不是所有的服務(wù)器都會(huì)有影響。
但不管是不是所有的服務(wù)器都有這個(gè)問題，只要出現(xiàn)了這個(gè)問題，對(duì)于某些服務(wù)器來說，它一定是一個(gè)非常嚴(yán)重的 BUG。
然后他說了一個(gè) Great catch！我理解這是一個(gè)語氣助詞。就類似于：太牛逼了。
這個(gè)不好翻譯，我貼一個(gè)例句，大家自己去體會(huì)一下吧：
我也是沒想到，在技術(shù)文里面還給大家教起了英文。
最后他說：我正在修復(fù)這個(gè)問題。
然后，在 7 分 37 秒之后， Greg 又回復(fù)了一次：
可以看出，過了快 8 分鐘，他還在持續(xù)震驚。我懷疑這 8 分鐘里面他一直在搖頭。
他說：我還在為這個(gè) BUG 搖頭，它怎么這么久都沒被發(fā)現(xiàn)呢！對(duì)于 jetty 來說修復(fù)起來非常的簡單，使用 set 結(jié)構(gòu)代替 queue 隊(duì)列即可實(shí)現(xiàn)一樣的效果。
那我們看一下修復(fù)之后的 jetty 中的 QueuedThreadPool 是怎樣的，這里我用的是 2015 年 10 月 6 日發(fā)布的一個(gè)包，也就是這個(gè) BUG 爆出之后的最近的一個(gè)包：
里面對(duì)應(yīng)的代碼是這樣的：
簡單粗暴的用 CurrentHashSet 代替了 CLQ。
因?yàn)檫@個(gè) BUG 在 JDK 中是已經(jīng)修復(fù)了，出于好奇，我想看看 CLQ 還有沒有機(jī)會(huì)重新站出來。
于是我看了一下今年發(fā)布的最新版本里面的代碼：
既不是用的 CurrentHashSet ，也沒有給 CLQ 機(jī)會(huì)。
而是 JDK 8 的 ConcurrentHashMap 里面的 newKeySet 方法，C 位出道：
這是一個(gè)小小的 jetty 線程池的演變過程。恭喜你，又學(xué)到了一個(gè)基本上不會(huì)用到的知識(shí)點(diǎn)。
回到 Greg 的回復(fù)中，這次的回復(fù)里面，他還給了一個(gè)修復(fù)的演示實(shí)例，下一小節(jié)我會(huì)針對(duì)這個(gè)實(shí)例進(jìn)行解讀。
在 23 分鐘之后，他就提交代碼修復(fù)完成了。
從第一次回復(fù)帖子，到定位問題，再到提交代碼，用了 30 分鐘的時(shí)間。
然后在凌晨 2 點(diǎn) 57 分（這個(gè)時(shí)間點(diǎn)，大佬都是不用睡覺的嗎？還是說剛修完福報(bào)，下班了）， max 回復(fù)到：
我不敢相信 CLQ 使用起來會(huì)有這樣的問題，他們至少應(yīng)該在 API 文檔里面說明一下。
這里的他們，應(yīng)該指的是 JDK 團(tuán)隊(duì)的成員，特指 Doug Lea，畢竟是他老爺子的作品。
為什么沒有在 API 文檔里面說明呢？
因?yàn)樗麄冏约阂膊恢烙羞@個(gè) BUG 啊。
Greg 連著回復(fù)了兩條，并且直接指出了解決方案：
問題的原因是 remove 方法的源碼里面，有上圖中標(biāo)號(hào)為 ① 的這樣一行代碼。
這行代碼會(huì)去取消被移除的這個(gè) node （其值已經(jīng)被替換為 null）和 list 之間的鏈接，然后可以讓 GC 回收這個(gè) node。
但是，當(dāng)集合里面只有一個(gè)元素的時(shí)候， next != null 這個(gè)判斷是不成立的。
所以就會(huì)出現(xiàn)這個(gè)需要移除的節(jié)點(diǎn)已經(jīng)被置為 null 了，但卻沒有取消和隊(duì)列之間的連接，導(dǎo)致 GC 線程不會(huì)回收這個(gè)節(jié)點(diǎn)。
他給出的解決方案也很簡單，就是標(biāo)號(hào)為②、③的地方。總之，只需要讓代碼執(zhí)行 pred.casNext 方法就行。
總之一句話，導(dǎo)致內(nèi)存泄漏的原因是一個(gè)被置為 null 的 node，由于代碼問題，導(dǎo)致該 node 節(jié)點(diǎn)，既不會(huì)被使用，也不會(huì)被 GC 回收掉。
如果你還沒理解到這個(gè) BUG 的原因，說明你對(duì) CLQ 這個(gè)隊(duì)列的結(jié)構(gòu)還不太清晰。
那么我建議你讀一下《Java并發(fā)編程的藝術(shù)》這一本書，里面有一小節(jié)專門講這個(gè)隊(duì)列的，圖文并茂，寫的還是非常清晰。
這個(gè) BUG 在 jetty 里面的來龍去脈算是說清楚了。
然后，我們?cè)倩氐?JDK BUG 的這個(gè)鏈接中去：
他這里寫的原因就是我前面說的原因，沒有 unlink，所以不能被回收。
而且他說到：這個(gè) BUG 在最新的JDK 7、8和9版本中都存在。
他說的最新是指截止這個(gè) BUG 被提出來之前：
Demo跑起來
這一小節(jié)里面，我們跑一下 Greg 給的那個(gè)修復(fù) Demo，親手去摸一下這個(gè) BUG 的樣子。
https://bugs.eclipse.org/bugs/attachment.cgi?id=256704
你可以打開上面那個(gè)鏈接，直接復(fù)制粘貼到你的 IDEA 里面去：
注意第 13 行，因?yàn)?Greg 給的是修復(fù) Demo，所以用的是 ConcurrentHashSet，由于我們要演示這個(gè)bug，所以使用 CLQ。
這個(gè) Demo 就是在死循環(huán)里面調(diào)用 queue 的 add(obj) 和 remove(obj) 方法。每循環(huán) 10000 次，就打印出時(shí)間間隔、隊(duì)列大小、最大內(nèi)存、剩余內(nèi)存、總內(nèi)存的值。
最終運(yùn)行起來的效果是這樣的（JDK 版本是 1.7.0_71）：
可以看到每次打印 duration 這個(gè)時(shí)間間隔是越來越大，隊(duì)列大小始終為 1。
后面三個(gè)內(nèi)存相關(guān)的參數(shù)可以先不關(guān)心，下一小節(jié)我們用圖形化工具來看。
你知道上面這個(gè)程序，到我寫文章寫到這里的時(shí)候，我跑了多久了嗎？
61 小時(shí) 32 分 53 秒。
最新一次循環(huán) 10000 次所需要的時(shí)間間隔是 575615ms，快接近 10?分鐘：
這就是 Greg 說的：不僅僅是內(nèi)存泄漏，而且越來越慢。
但是，同樣的程序，我用 JDK 1.8.0_212 版本跑的時(shí)候情況卻是這樣的：
時(shí)間間隔很穩(wěn)定，不會(huì)隨著時(shí)間的推移而增加。
說明這個(gè)版本是修復(fù)了這個(gè) BUG 的，我?guī)Т蠹铱纯丛创a：
JDK 1.8.0_212 版本的源碼里面，在 CLQ 的 remove(obj) 方法的 502 行末尾注釋了一個(gè) unlink。
官方的修復(fù)方法可以看這里：
http://hg.openjdk.java.net/jdk8u/jdk8u-dev/jdk/rev/8efe549f3c87
改動(dòng)比較多，但是原理還是和之前分析的一樣：
我僅僅在兩個(gè) JDK 版本中跑過示例代碼。
在 JDK 1.8.0_212 沒有發(fā)現(xiàn)內(nèi)存泄漏的問題，我看了對(duì)應(yīng)的 remove(obj)?方法的源碼確實(shí)是修復(fù)了。
在 JDK 1.7.0_71 中可以看到內(nèi)存泄漏的問題。
unlink，一個(gè)簡簡單單的詞，背后原來藏了這么多故事。
jconsole、VisualVM、jmc
既然都說到內(nèi)存泄漏了，那必須得介紹幾個(gè)可視化的故障排除工具。
前面說了，這個(gè)程序跑了 61 個(gè)小時(shí)了，給大家看一下這個(gè)時(shí)間段里面堆內(nèi)存的使用情況：
可以看到整個(gè)堆內(nèi)存的使用量是一個(gè)明顯的、緩慢的上升趨勢(shì)。
上面這個(gè)圖就是來自 jconsole。
結(jié)合程序，通過圖片我們可以分析出，這種情況一定是內(nèi)存泄漏了，這是一個(gè)非常經(jīng)典的內(nèi)存泄漏的走勢(shì)。
接下來，我們?cè)倏匆幌?jmc 的監(jiān)控情況：
上面展示的是已經(jīng)使用的堆內(nèi)存的大小，走勢(shì)和 jconsole 的走勢(shì)一樣。
然后再看看 VisualVM 的圖：
VisualVM 的圖，我不知道怎么看整個(gè)運(yùn)行了 60?多小時(shí)的走勢(shì)圖，但是從上面的圖也是能看出是有上升趨勢(shì)的。
在 VisualVM 里面，我們可以直接 Dump 堆，然后進(jìn)行分析：
可以清楚的看到， CLQ 的 Node 的大小占據(jù)了 94.2%。
但是，從我們的程序來看，我們根本就沒有用到這么多 Node。我們只是用了一個(gè)而已。
你說，這不是內(nèi)存泄漏是什么。
內(nèi)存泄漏最終會(huì)導(dǎo)致 OOM。
所以當(dāng)發(fā)生 OOM 的時(shí)候，我們需要分析是不是有內(nèi)存泄漏。也就是看內(nèi)存里面的對(duì)象到底應(yīng)不應(yīng)該存活，如果都應(yīng)該存活那就不是內(nèi)存泄漏，是內(nèi)存不足了。需要檢查一下 JVM 的參數(shù)配置（-Xmx/-Xms），根據(jù)機(jī)器內(nèi)存情況，判斷是否還能再調(diào)大一點(diǎn)。
同時(shí)，也需要檢查一下代碼，是否存在生命周期過程的對(duì)象，是否有數(shù)據(jù)結(jié)構(gòu)使用不合理的地方，盡量減少程序運(yùn)行期的內(nèi)存消耗。
我們可以通過把堆內(nèi)存設(shè)置的小一點(diǎn)，來模擬一下內(nèi)存泄漏導(dǎo)致的 OOM。
還是用之前的測(cè)試案例，但是我們指定 -Xmx 為 20m，即最大可用的堆大小為 20m。
然后把代碼跑起來，同時(shí)通過 VisualVM 、jconsole、jmc 這三個(gè)工具監(jiān)控起來，為了我們有足夠的時(shí)候準(zhǔn)備好檢測(cè)工具，我在第 8 行加入休眠代碼，其他的代碼和之前的一樣：
加入 -Xmx20m 參數(shù)：
運(yùn)行起來之后，我們同時(shí)通過工具來查看內(nèi)存變化，下面三個(gè)圖從上到下的工具分別是 VisualVM、jconsole、jmc：
從圖片的走勢(shì)來看，和我們之前分析的是一樣的，內(nèi)存一直在增長。
程序運(yùn)行 19 分 06 秒后，發(fā)生 OOM 異常：
那正常的走勢(shì)圖應(yīng)該是怎么樣的呢？
我們?cè)?JDK 1.8.0_121 版本中（已經(jīng)修復(fù)了 remove 方法），用相同的 JVM 參數(shù)（-Xmx20m）再跑一下：
首先從上面的日志中可以看出，時(shí)間間隔并沒有遞增，程序運(yùn)行的非常的快。
然后用 VisualVM 檢測(cè)內(nèi)存，同樣跑 19 分鐘后截圖如下：
可以看到堆內(nèi)存的使用量并沒有隨著時(shí)間的推移而越來越高。但是還是有非常頻繁的 GC 操作。
這個(gè)不難理解，因?yàn)?CLQ 的數(shù)據(jù)結(jié)構(gòu)用的是鏈表。而鏈表又是由不同的 node 節(jié)點(diǎn)組成。
由于調(diào)用 remove 方法后，node 節(jié)點(diǎn)具備被回收的條件，所以頻繁的調(diào)用 remove 方法對(duì)節(jié)點(diǎn)進(jìn)行刪除，會(huì)觸發(fā) JVM 的 min GC。
這種 JDK BUG 導(dǎo)致的內(nèi)存泄漏其實(shí)挺讓人崩潰的。首先你第一次感知到它是因?yàn)槌绦虬l(fā)生了 OOM。
也許你會(huì)先無腦的加大堆內(nèi)存空間，恰好你的程序運(yùn)行了一周之后又要上線了，所以涉及到重啟應(yīng)用。
然后很長一段時(shí)間內(nèi)沒有發(fā)生 OOM 了。你就想這個(gè)問題可能解決了。
但是它還是在繼續(xù)發(fā)生著，很可能由于節(jié)假日前后不能上線，比如國慶七天，加上前后幾天，大概有半個(gè)月的樣子應(yīng)用沒有上線，所以沒有重啟，程序越來越慢，最終導(dǎo)致第二次 OOM 的出現(xiàn)。
這個(gè)時(shí)候，你覺得可能不是內(nèi)存溢出這么簡單了。
會(huì)不會(huì)是內(nèi)存泄漏了？
然后你再次重啟。這次重啟之后，你開始時(shí)不時(shí)的 Dump 一下內(nèi)存，拿出來分析分析。
突然發(fā)現(xiàn)，這個(gè) node 怎么這么多呢？
最終，找到這個(gè)問題的原因。
原來是 JDK 的 BUG。
你就會(huì)發(fā)出和 Greg 一樣的感嘆：臥槽，震驚，這么牛皮！？
我這個(gè)運(yùn)行了 60 多小時(shí)的程序到現(xiàn)在堆內(nèi)存使用了 233m，但是我整個(gè)堆的大小是接近 2G。
通過 jmc 同時(shí)展示堆的整體大小和已經(jīng)使用的堆大小你可以發(fā)現(xiàn)，距離內(nèi)存泄漏可以說是道阻且長了：
我粗略的算了一下，這個(gè)程序大概還得運(yùn)行 475 個(gè)小時(shí)左右，也就是 19 天之后才會(huì)出現(xiàn)由于內(nèi)存泄漏，導(dǎo)致的 OOM。
我會(huì)盡量跑下去，但是聽到我電腦嗡嗡嗡的風(fēng)扇聲，我不知道它還能不能頂?shù)米 ?br />
如果它頂住了，我在后面的文章里面通知大家。
好了，圖形化工具這一小節(jié)就到這里了。
我們只是展示了它們非常小的一個(gè)功能，合理的使用它們常常能達(dá)到事半功倍的作用。
如果你不太了解它們的功能，建議你看看《深入理解JVM虛擬機(jī)（第3版）》，里面有一章節(jié)專門講這幾個(gè)工具的。
最后說一句，
這是我昨天晚上寫文章的時(shí)候拍的 ，女朋友說一眼望去感覺我是一個(gè)盯盤的人，在看股票走勢(shì)圖，這只股票太牛逼了。
要是股市的總體走勢(shì)也像內(nèi)存泄露那么單純而直接就好了。
只要在 OOM 之前落袋為安就行。可惜有的人就是在 OOM 的前一刻滿倉殺入，真是個(gè)悲傷的故事。
推薦閱讀
僅用2年過渡到自研ARM芯片，蘋果的底氣從何而來？
開源巨頭 SUSE 收購 Rancher Labs，云原生時(shí)代來臨
國內(nèi)廠商 Onyx 違反 GPL 協(xié)議，中國開源何去何從？
天上地下，馬斯克和貝佐斯終有一戰(zhàn)？
空間-角度信息交互用于光場(chǎng)圖像超分辨重構(gòu)，性能達(dá)到最新SOTA | ECCV 2020
贈(zèng)書 | DeFi沉思錄：歷史、中國與未來
總結(jié)
以上是生活随笔為你收集整理的我的程序跑了 60 多小时，就是为了让你看一眼 JDK 的 BUG 导致的内存泄漏的全部內(nèi)容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： 开源巨头 SUSE 收购 Rancher
- 下一篇： CSDN鸿蒙社区福利：HarmonyOS