Netty堆外記憶體洩露排查盛宴

摘要： 導讀 Netty 是一個非同步事件驅動的網路通訊層框架，用於快速開發高可用高效能的服務端網路框架與客戶端程式，它極大地簡化了 TCP 和 UDP 套接字伺服器等網路程式設計。 Netty 底層基於 JDK 的 NIO，我們為什麼不直接基於 JDK 的 NIO 或者其他NIO框架： ...

導讀

Netty 是一個非同步事件驅動的網路通訊層框架，用於快速開發高可用高效能的服務端網路框架與客戶端程式，它極大地簡化了 TCP 和 UDP 套接字伺服器等網路程式設計。

Netty 底層基於 JDK 的 IO/">NIO，我們為什麼不直接基於 JDK 的 NIO 或者其他NIO框架：

1. 使用 JDK 自帶的 NIO 需要了解太多的概念，程式設計複雜。
2. Netty 底層 IO 模型隨意切換，而這一切只需要做微小的改動。
3. Netty自帶的拆包解包，異常檢測等機制讓我們從 NIO 的繁重細節中脫離出來，只需關心業務邏輯即可。
4. Netty解決了JDK 的很多包括空輪訓在內的 Bug。
5. Netty底層對執行緒，Selector 做了很多細小的優化，精心設計的 Reactor 執行緒做到非常高效的併發處理。
6. 自帶各種協議棧，讓我們處理任何一種通用協議都幾乎不用親自動手。
7. Netty社群活躍，遇到問題隨時郵件列表或者 issue。
8. Netty已經歷各大RPC框架（Dubbo），訊息中介軟體（RocketMQ），大資料通訊（Hadoop）框架的廣泛的線上驗證，健壯性無比強大。

背景

最近在做一個基於 Websocket 的長連中介軟體，服務端使用實現了 Socket.IO 協議（基於WebSocket協議，提供長輪詢降級能力） 的 ofollow,noindex" target="_blank">netty-socketio 框架，該框架為 Netty 實現，鑑於本人對 Netty 比較熟，並且對比同樣實現了 Socket.IO 協議的其他框架，Netty 的口碑都要更好一些，因此選擇這個框架作為底層核心。

誠然，任何開源框架都避免不了 Bug 的存在，我們在使用這個開源框架時，就遇到一個堆外記憶體洩露的 Bug。美團的價值觀一直都是“追求卓越”，所以我們就想挑戰一下，找到那隻臭蟲（Bug），而本文就是遇到的問題以及排查的過程。當然，想看結論的同學可以直接跳到最後，閱讀總結即可。

問題

某天早上，我們突然收到告警，Nginx 服務端出現大量5xx。

我們使用 Nginx 作為服務端 WebSocket 的七層負載，5xx的爆發通常表明服務端不可用。由於目前 Nginx 告警沒有細分具體哪臺機器不可用，接下來，我們就到CAT（美團點評統一監控平臺，目前已經開源）去檢查一下整個叢集的各項指標，就發現如下兩個異常:

某臺機器在同一時間點爆發 GC（垃圾回收），而且在同一時間，JVM 執行緒阻塞。

接下來，我們就就開始了漫長的堆外記憶體洩露“排查之旅”。

排查過程

階段1: 懷疑是log4j2

因為執行緒被大量阻塞，我們首先想到的是定位哪些執行緒被阻塞，最後查出來是 Log4j2 狂打日誌導致 Netty 的 NIO 執行緒阻塞（由於沒有及時保留現場，所以截圖缺失）。NIO 執行緒阻塞之後，因我們的伺服器無法處理客戶端的請求，所以對Nginx來說就是5xx。

接下來，我們查看了 Log4j2 的配置檔案。

我們發現列印到控制檯的這個 appender 忘記註釋掉了，所以初步猜測：因為這個專案列印的日誌過多，而 Log4j2 列印到控制檯是同步阻塞列印的，所以就導致了這個問題。那麼接下來，我們把線上所有機器的這行註釋掉，本以為會“大功告成”，但沒想到僅僅過了幾天，5xx告警又來“敲門”。看來，這個問題並沒我們最初想象的那麼簡單。

階段2：可疑日誌浮現

接下來，我們只能硬著頭皮去查日誌，特別是故障發生點前後的日誌，於是又發現了一處可疑的地方：

可以看到：在極短的時間內，狂打 failed to allocate 64(bytes) of direct memory(...) 日誌（瞬間十幾個日誌檔案，每個日誌檔案幾百M），日誌裡丟擲一個 Netty 自己封裝的 OutOfDirectMemoryError 。說白了，就是堆外記憶體不夠用，Netty 一直在“喊冤”。

堆外記憶體洩露，聽到這個名詞就感到很沮喪。因為這個問題的排查就像 C 語言記憶體洩露一樣難以排查，首先能想到的就是，在 OOM 爆發之前，檢視有無異常。然後查遍了 CAT 上與機器相關的所有指標，查遍了 OOM 日誌之前的所有日誌，均未發現任何異常！這個時候心裡已經“萬馬奔騰”了......

階段3：定位OOM源

沒辦法，只能看著這堆討厭的 OOM 日誌發著呆，希望答案能夠“蹦到”眼前，但是那只是妄想。一籌莫展之際，突然一道光在眼前一閃而過，在 OOM 下方的幾行日誌變得耀眼起來（為啥之前就沒想認真檢視日誌？估計是被堆外記憶體洩露這幾個詞嚇怕了吧 ==！），這幾行字是 ....PlatformDepedeng.incrementMemory()... 。

原來，堆外記憶體是否夠用，是 Netty 這邊自己統計的，那麼是不是可以找到統計程式碼，找到統計程式碼之後我們就可以看到 Netty 裡面的對外記憶體統計邏輯了？於是，接下來翻翻程式碼，找到這段邏輯，就在 PlatformDepedent 這個類裡面。

這個地方，是一個對已使用堆外記憶體計數的操作，計數器為 DIRECT_MEMORY_COUNTER ，如果發現已使用記憶體大於堆外記憶體的上限（使用者自行指定），就丟擲一個自定義 OOM Error，異常裡面的文字內容正是我們在日誌裡面看到的。

接下來，就驗證一下這個方法是否是在堆外記憶體分配的時候被呼叫。

果然，在 Netty 每次分配堆外記憶體之前，都會計數。想到這，思路就開始慢慢清晰，而心情也開始從“秋風瑟瑟”變成“春光明媚”。

階段4：反射進行堆外記憶體監控

CAT 上關於堆外記憶體的監控沒有任何異常（應該是沒有統計準確，一直維持在 1M），而這邊我們又確認堆外記憶體已快超過上限，並且已經知道 Netty 底層是使用的哪個欄位來統計。那麼接下來要做的第一件事情，就是反射拿到這個欄位，然後我們自己統計 Netty 使用堆外記憶體的情況。

堆外記憶體統計欄位是 DIRECT_MEMORY_COUNTER ，我們可以通過反射拿到這個欄位，然後定期 Check 這個值，就可以監控 Netty 堆外記憶體的增長情況。

於是我們通過反射拿到這個欄位，然後每隔一秒列印，為什麼要這樣做？

因為，通過我們前面的分析，在爆發大量 OOM 現象之前，沒有任何可疑的現象。那麼只有兩種情況，一種是突然某個瞬間分配了大量的堆外記憶體導致OOM；一種是堆外記憶體緩慢增長，到達某個點之後，最後一根稻草將機器壓垮。在這段程式碼加上去之後，我們打包上線。

階段5：到底是緩慢增長還是瞬間飆升？

程式碼上線之後，初始記憶體為 16384k（16M），這是因為線上我們使用了池化堆外記憶體，預設一個 chunk 為16M，這裡不必過於糾結。

但是沒過一會，記憶體就開始緩慢飆升，並且沒有釋放的跡象，二十幾分鍾之後，記憶體使用情況如下：

走到這裡，我們猜測可能是前面提到的第二種情況，也就是記憶體緩慢增長造成的 OOM，由於記憶體實在增長太慢，於是調整機器負載權重為其他機器的兩倍，但是仍然是以數K級別在持續增長。那天剛好是週五，索性就過一個週末再開看。

週末之後，我們到公司第一時間就連上了跳板機，登入線上機器，開始 tail -f 繼續檢視日誌。在輸完命令之後，懷著期待的心情重重的敲下了回車鍵：

果然不出所料，記憶體一直在緩慢增長，一個週末的時間，堆外記憶體已經飆到快一個 G 了。這個時候，我竟然想到了一句成語：“只要功夫深，鐵杵磨成針”。雖然堆外記憶體以幾個K的速度在緩慢增長，但是隻要一直持續下去，總有把記憶體打爆的時候（線上堆外記憶體上限設定的是2G）。

此時，我們開始自問自答環節：記憶體為啥會緩慢增長，伴隨著什麼而增長？因為我們的應用是面向使用者端的WebSocket，那麼，會不會是每一次有使用者進來，互動完之後離開，記憶體都會增長一些，然後不釋放呢？帶著這個疑問，我們開始了線下模擬過程。

階段6：線下模擬

本地起好服務，把監控堆外記憶體的單位改為以B為單位（因為本地流量較小，打算一次一個客戶端連線），另外，本地也使用非池化記憶體（記憶體數字較小，容易看出問題），在服務端啟動之後，控制檯列印資訊如下

在沒有客戶端接入的時候，堆外記憶體一直是0，在意料之中。接下來，懷著著無比激動的心情，開啟瀏覽器，然後輸入網址，開始我們的模擬之旅。

我們的模擬流程是：新建一個客戶端連結->斷開連結->再新建一個客戶端連結->再斷開連結。

如上圖所示，一次 Connect 和 Disconnect 為一次連線的建立與關閉，上圖綠色框框的日誌分別是兩次連線的生命週期。我們可以看到，記憶體每次都是在連線被關閉的的時候暴漲 256B，然後也不釋放。走到這裡，問題進一步縮小，肯定是連線被關閉的時候，觸發了框架的一個Bug，而且這個Bug在觸發之前分配了 256B 的記憶體，隨著Bug被觸發，記憶體也沒有釋放。問題縮小之後，接下來開始“擼原始碼”，捉蟲！

階段7：線下排查

接下來，我們將本地服務重啟，開始完整的線下排查過程。同時將目光定位到 netty-socketio 這個框架的 Disconnect 事件（客戶端WebSocket連線關閉時會呼叫到這裡），基本上可以確定，在 Disconnect 事件前後申請的記憶體並沒有釋放。

在使用 idea debug 時，要選擇只掛起當前執行緒，這樣我們在單步跟蹤的時候，控制檯仍然可以看到堆外記憶體統計執行緒在列印日誌。

在客戶端連線上之後然後關閉，斷點進入到 onDisconnect 回撥，我們特意在此多停留了一會，發現控制檯記憶體並沒有飆升（7B這個記憶體暫時沒有去分析，只需要知道，客戶端連線斷開之後，我們斷點hold住，記憶體還未開始漲）。接下來，神奇的一幕出現了，我們將斷點放開，讓程式跑完：

Debug 鬆掉之後，記憶體立馬飆升了！！此時，我們已經知道，這隻“臭蟲”飛不了多遠了。在 Debug 時，掛起的是當前執行緒，那麼肯定是當前執行緒某個地方申請了堆外記憶體，然後沒有釋放，繼續“快馬加鞭“，深入原始碼。

其實，每一次單步除錯，我們都會觀察控制檯的記憶體飆升的情況。很快，我們來到了這個地方：

在這一行沒執行之前，控制檯的記憶體依然是 263B。然後，當執行完該行之後，立刻從 263B漲到519B（漲了256B）。

於是，Bug 範圍進一步縮小。我們將本次程式跑完，釋然後客戶端再來一次連線，斷點打在 client.send() 這行， 然後關閉客戶端連線，之後直接進入到這個方法，隨後的過程有點長，因為與 Netty 的時間傳播機制有關，這裡就省略了。最後，我們跟蹤到了如下程式碼， handleWebsocket ：

在這個地方，我們看到一處非常可疑的地方，在上圖的斷點上一行，呼叫 encoder 分配了一段記憶體，呼叫完之後，我們的控制檯立馬就彪了 256B。所以，我們懷疑肯定是這裡申請的記憶體沒有釋放，它這裡接下來呼叫 encoder.encodePacket() 方法，猜想是把資料包的內容以二進位制的方式寫到這段 256B的記憶體。接下來，我們追蹤到這段 encode 程式碼，單步執行之後，就定位到這行程式碼：

這段程式碼是把 packet 裡面一個欄位的值轉換為一個 char。然而，當我們使用 idea 預執行的時候，卻丟擲類一個憤怒的 NPE！！也就是說，框架申請到一段記憶體之後，在 encoder 的時候，自己 GG 了，還給自己挖了個NPE的深坑，最後導致記憶體無法釋放（最外層有堆外記憶體釋放邏輯，現在無法執行到了）。而且越攢越多，直到被“最後一根稻草”壓垮，堆外記憶體就這樣爆了。這裡的原始碼，有興趣的讀者可以自己去分析一下，限於篇幅原因，這裡就不再展開敘述了。

階段8：Bug解決

既然 Bug 已經找到，接下來就要解決問題了。這裡只需要解決這個NPE異常，就可以 Fix 掉。我們的目標就是，讓這個 subType 欄位不為空。於是我們先通過 idea 的執行緒呼叫棧，定位到這個 packet 是在哪個地方定義的：

我們找到 idea 的 debugger 面板，眼睛盯著 packet 這個物件不放，然後上線移動游標，便光速定位到。原來，定義 packet 物件這個地方在我們前面的程式碼其實已經出現過，我們查看了一下 subType 這個欄位，果然是 null。接下來，解決 Bug 就很容易了。

我們給這個欄位賦值即可，由於這裡是連線關閉事件，所以我們給他指定了一個名為 DISCONNECT 的欄位（可以改天深入去研究 Socket.IO 的協議），反正這個 Bug 是在連線關閉的時候觸發的，就粗暴一點了 ！

解決這個 Bug 的過程是：將這個框架的原始碼下載到本地，然後加上這一行，最後重新 Build一下，pom 裡改了一下名字，推送到我們公司的倉庫。這樣，專案就可以直接進行使用了。

階段9：線下驗證

一切準備就緒之後，我們就來進行本地驗證，在服務起來之後，我們瘋狂地建立連線，瘋狂地斷開連線，並觀察堆外記憶體的情況：

Bingo！不管我們如何斷開連線，堆外記憶體不漲了。至此，Bug 基本 Fix，當然最後一步，我們把程式碼推到線上驗證。

階段10：線上驗證

這次線上驗證，我們避免了比較土的打日誌方法，我們把堆外記憶體的這個指標“噴射”到 CAT 上，然後再來觀察一段時間的堆外記憶體的情況：

過完一段時間，堆外記憶體已經穩定不漲了。此刻，我們的“捉蟲之旅”到此結束。最後，我們還為大家做一個小小的總結，希望對您有所幫助。

總結

1. 遇到堆外記憶體洩露不要怕，仔細耐心分析，總能找到思路，要多看日誌，多分析。

2. 如果使用了 Netty 堆外記憶體，那麼可以自行監控堆外記憶體的使用情況，不需要藉助第三方工具，我們是使用的“反射”拿到的堆外記憶體的情況。

3. 逐漸縮小範圍，直到 Bug 被找到。當我們確認某個執行緒的執行帶來 Bug 時，可單步執行，可二分執行，定位到某行程式碼之後，跟到這段程式碼，然後繼續單步執行或者二分的方式來定位最終出 Bug 的程式碼。這個方法屢試不爽，最後總能找到想要的 Bug。

4. 熟練掌握 idea 的除錯，讓我們的“捉蟲”速度快如閃電（“閃電俠”就是這麼來的）。這裡，最常見的除錯方式是預執行表示式，以及通過執行緒呼叫棧，死盯某個物件，就能夠掌握這個物件的定義、賦值之類。

最後，祝願大家都能找到自己的“心儀已久” Bug！

作者簡介

閃電俠，2014年加入美團點評，主要負責美團點評移動端統一長連工作，歡迎同行進行技術交流。

招聘

目前我們團隊負責美團點評長連基礎設施的建設，支援美團酒旅、外賣、到店、打車、金融等幾乎公司所有業務的快速發展。加入我們，你可以親身體驗到千萬級線上連線、日吞吐百億請求的場景，你會直面網際網路高併發、高可用的挑戰，有機會接觸到 Netty 在長連領域的各個場景。我們誠邀有激情、有想法、有經驗、有能力的同學，和我們一起並肩奮鬥！歡迎感興趣的同學投遞簡歷至 chao.yu#dianping.com 諮詢。

參考文獻

1. Netty 是什麼
2. Netty 原始碼分析之服務端啟動全解析