作者:京東科技 王長春
事情要回顧到雙11.11備戰前夕,在那個風雨交加的夜晚,一個急促的咚咚報警,驚破了電閃雷鳴的黑夜,將沉浸在夢香,熟睡的我驚醒。
一看手機咚咚報警,不好!有大事發生了!電話馬上打給老闆:
老闆說: 長連線嗎?
我說:是的!
老闆說:該來的還是要來的,最終還是來了,快,趕緊先把服務重啟下!
我說:已經重啟了!
老闆說: 這問題必須給我解決了!
我說:必須的!
線上應用長連線Netty服務出現記憶體漏失了!真讓人頭大
在這風雨交加的夜晚,此時,面對毫無頭緒的問題,以及迫切想攻克問題的心,已經讓我興奮不已,手一把揉揉剛還迷糊的眼,今晚又註定是一個不眠之夜!
說起支付業務的長連線服務,真是說來話長,我們這就長話短說:
隨著業務及系統架構的複雜化,一些場景,使用者操作無法同步得到結果。一般採用的短連線輪訓的策略,使用者端需要不停的發起請求,時效性較差還浪費伺服器資源。
短輪訓痛點:
相比於短連線輪訓策略,長連線服務可做到實時推播資料,並且在一個連結保持期間可進行多次資料推播。服務應用常見場景:PC端掃碼支付,使用者開啟掃碼支付頁面,手機掃碼完成支付,頁面實時展示支付成功資訊,提供良好的使用者體驗。
長連服務優勢:
這個長連線服務使用Netty
框架,Netty
的高效能為這個應用帶來了無上的榮光,承接了眾多長連線使用場景的業務:
回到線上問題,出現記憶體漏失的是長連線前置服務,觀察線上服務,這個應用的記憶體漏失的現象總伴隨著記憶體的增長,這個增長真是非常的緩慢,緩慢,緩慢,2、3個月內從30%慢慢增長到70%,極難發現:
每次發生記憶體漏失,記憶體快耗盡時,總得重啟下,雖說重啟是最快解決的方法,但是程式設計師是天生懶惰的,要數著日子來重啟,那絕對不是一個優秀程式設計師的行為!問題必須徹底解決!
遇到問題,毫無頭緒,首先還是需要去案發第一現場,排查「死者(應用範例)」死亡現場,通過在發生FullGC的時間點,通過Digger查詢ERROR
紀錄檔,沒想到還真找到破案的第一線索:
io.netty.util.ResourceLeakDetector [176] - LEAK: ByteBuf.release() was not called before it's garbage-collected. Enable advanced leak reporting to find out where the leak occurred. To enable advanced leak reporting, specify the JVM option '-Dio.netty.leakDetection.level=advanced' or call ResourceLeakDetector.setLevel() See http://netty.io/wiki/reference-counted-objects.html for more information.
線上紀錄檔竟然有一個明顯的"LEAK"
洩漏字樣,作為技術人的敏銳的技術嗅覺,和找Bug的直覺,可以確認,這就是事故案發第一現場。
我們憑藉下大學四六級英文水平的,繼續翻譯下線索,原來是這吶!
ByteBuf.release() 在垃圾回收之前沒有被呼叫。啟用高階洩漏報告以找出洩漏發生的位置。要啟用高階洩漏報告,請指定 JVM 選項「-Dio.netty.leakDetectionLevel=advanced」或呼叫 ResourceLeakDetector.setLevel()
啊哈!這資訊不就是說了嘛!ByteBuf.release()
在垃圾回收前沒有呼叫,有ByteBuf
物件沒有被釋放,ByteBuf
可是分配在直接記憶體的,沒有被釋放,那就意味著堆外記憶體漏失,所以記憶體一直是非常緩慢的增長,GC都不能夠進行釋放。
提供了這個線索,那到底是我們應用中哪段程式碼出現了ByteBuf
物件的記憶體漏失呢?
專案這麼大,Netty通訊處理那麼多,怎麼找呢?自己從中搜尋,那肯定是不靠譜,找到了又怎麼釋放呢?
面對這一連三問?彆著急,Netty的紀錄檔提示還是非常完善:啟用高階洩漏報告找出洩漏發生位置嘛,生產上不可能啟用,並且生產發生時間極長,時間上來不及,而且未經驗證,不能直接生產釋出,那就原生程式碼復現一下!找到具體程式碼位置。
為了本地復現Netty
洩漏,定位詳細的記憶體漏失程式碼,我們需要做這幾步:
1、設定足夠小的本地JVM記憶體,以便快速模擬堆外記憶體漏失。
如圖,我們設定設定PermSize=30M, MaxPermSize=43M
2、模擬足夠多的長連線請求,我們使用Postman定時批次發請求,以達到服務的堆外記憶體漏失。
啟動專案,通過JProfiler
JVM監控工具,我們觀察到記憶體緩慢的增長,最終觸發了本地Netty
的堆外記憶體漏失,本地復現成功:
_那問題具體出現在程式碼中哪塊呢?_我們最重要的是定位具體程式碼,在開啟了Netty
的高階記憶體漏失級別為高階,來定位下:
3、開啟Netty
的高階記憶體漏失檢測級別,JVM引數如下:
-Dio.netty.leakDetectionLevel=advanced
再啟動專案,模擬請求,達到本地應用JVM記憶體漏失,Netty輸出如下具體紀錄檔資訊,可以看到,具體的紀錄檔資訊比之前的資訊更加完善:
2020-09-24 20:11:59.078 [nioEventLoopGroup-3-1] INFO io.netty.handler.logging.LoggingHandler [101] - [id: 0x2a5e5026, L:/0:0:0:0:0:0:0:0:8883] READ: [id: 0x926e140c, L:/127.0.0.1:8883 - R:/127.0.0.1:58920]
2020-09-24 20:11:59.078 [nioEventLoopGroup-3-1] INFO io.netty.handler.logging.LoggingHandler [101] - [id: 0x2a5e5026, L:/0:0:0:0:0:0:0:0:8883] READ COMPLETE
2020-09-24 20:11:59.079 [nioEventLoopGroup-2-8] ERROR io.netty.util.ResourceLeakDetector [171] - LEAK: ByteBuf.release() was not called before it's garbage-collected. See http://netty.io/wiki/reference-counted-objects.html for more information.
WARNING: 1 leak records were discarded because the leak record count is limited to 4. Use system property io.netty.leakDetection.maxRecords to increase the limit.
Recent access records: 5
#5:
io.netty.buffer.AdvancedLeakAwareCompositeByteBuf.readBytes(AdvancedLeakAwareCompositeByteBuf.java:476)
io.netty.buffer.AdvancedLeakAwareCompositeByteBuf.readBytes(AdvancedLeakAwareCompositeByteBuf.java:36)
com.jd.jr.keeplive.front.service.nettyServer.handler.LongRotationServerHandler.getClientMassageInfo(LongRotationServerHandler.java:169)
com.jd.jr.keeplive.front.service.nettyServer.handler.LongRotationServerHandler.handleHttpFrame(LongRotationServerHandler.java:121)
com.jd.jr.keeplive.front.service.nettyServer.handler.LongRotationServerHandler.channelRead(LongRotationServerHandler.java:80)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:362)
io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:348)
io.netty.channel.AbstractChannelHandlerContext.fireChannelRead(AbstractChannelHandlerContext.java:340)
io.netty.channel.ChannelInboundHandlerAdapter.channelRead(ChannelInboundHandlerAdapter.java:86)
......
#4:
Hint: 'LongRotationServerHandler#0' will handle the message from this point.
io.netty.buffer.AdvancedLeakAwareCompositeByteBuf.touch(AdvancedLeakAwareCompositeByteBuf.java:1028)
io.netty.buffer.AdvancedLeakAwareCompositeByteBuf.touch(AdvancedLeakAwareCompositeByteBuf.java:36)
io.netty.handler.codec.http.HttpObjectAggregator$AggregatedFullHttpMessage.touch(HttpObjectAggregator.java:359)
......
#3:
Hint: 'HttpServerExpectContinueHandler#0' will handle the message from this point.
io.netty.buffer.AdvancedLeakAwareCompositeByteBuf.touch(AdvancedLeakAwareCompositeByteBuf.java:1028)
io.netty.buffer.AdvancedLeakAwareCompositeByteBuf.touch(AdvancedLeakAwareCompositeByteBuf.java:36)
io.netty.handler.codec.http.HttpObjectAggregator$AggregatedFullHttpMessage.touch(HttpObjectAggregator.java:359)
......
#2:
Hint: 'HttpHeartbeatHandler#0' will handle the message from this point.
io.netty.buffer.AdvancedLeakAwareCompositeByteBuf.touch(AdvancedLeakAwareCompositeByteBuf.java:1028)
io.netty.buffer.AdvancedLeakAwareCompositeByteBuf.touch(AdvancedLeakAwareCompositeByteBuf.java:36)
io.netty.handler.codec.http.HttpObjectAggregator$AggregatedFullHttpMessage.touch(HttpObjectAggregator.java:359)
......
#1:
Hint: 'IdleStateHandler#0' will handle the message from this point.
io.netty.buffer.AdvancedLeakAwareCompositeByteBuf.touch(AdvancedLeakAwareCompositeByteBuf.java:1028)
io.netty.buffer.AdvancedLeakAwareCompositeByteBuf.touch(AdvancedLeakAwareCompositeByteBuf.java:36)
io.netty.handler.codec.http.HttpObjectAggregator$AggregatedFullHttpMessage.touch(HttpObjectAggregator.java:359)
......
Created at:
io.netty.util.ResourceLeakDetector.track(ResourceLeakDetector.java:237)
io.netty.buffer.AbstractByteBufAllocator.compositeDirectBuffer(AbstractByteBufAllocator.java:217)
io.netty.buffer.AbstractByteBufAllocator.compositeBuffer(AbstractByteBufAllocator.java:195)
io.netty.handler.codec.MessageAggregator.decode(MessageAggregator.java:255)
......
開啟高階的洩漏檢測級別後,通過上面異常紀錄檔,我們可以看到記憶體漏失的具體地方:com.jd.jr.keeplive.front.service.nettyServer.handler.LongRotationServerHandler.getClientMassageInfo(LongRotationServerHandler.java:169)
不得不說Netty
記憶體漏失排查這點是真香!真香好評!
找到問題了,那我麼就需要解決,如何釋放ByteBuf
記憶體呢?
其實Netty
官方也針對這個問題做了專門的討論,一般的經驗法則是,最後存取參照計數物件的一方負責銷燬該參照計數物件,具體來說:
如果一個[傳送]元件將一個參照計數的物件傳遞給另一個[接收]元件,則傳送元件通常不需要銷燬它,而是由接收元件進行銷燬。
如果一個元件使用了一個參照計數的物件,並且知道沒有其他物件將再存取它(即,不會將參照傳遞給另一個元件),則該元件應該銷燬它。
詳情請看翻譯的Netty官方檔案對參照計數的功能使用:
【翻譯】Netty的物件參照計數
【原文】Reference counted objects
總結起來主要三個方式:
方式一:手動釋放,哪裡使用了,使用完就手動釋放。
方式二:升級ChannelHandler
為SimpleChannelHandler
, 在SimpleChannelHandler
中,Netty
對收到的所有訊息都呼叫了ReferenceCountUtil.release(msg)
。
方式三:如果處理過程中不確定ByteBuf
是否應該被釋放,那交給Netty的ReferenceCountUtil.release(msg)
來釋放,這個方法會判斷上下文是否可以釋放。
考慮到長連線前置應用使用的是ChannelHandler
,如果升級SimpleChannelHandler
對現有API介面變動比較大,同時如果手動釋放,不確定是否應該釋放風險也大,因此使用方式三,如下:
問題修復後,線上服務正常,記憶體使用率也沒有再出現因洩漏而增長,從線上我們增加的紀錄檔中看出,FullHttpRequest
中ByteBuf
記憶體釋放成功。從此長連線前置記憶體漏失的問題徹底解決。
一、Netty的記憶體漏失排查其實並不難,Netty提供了比較完整的排查記憶體漏失工具
JVM 選項-Dio.netty.leakDetection.level
目前有 4 個洩漏檢測級別的:
DISABLED - 完全禁用洩漏檢測。不推薦。
SIMPLE - 抽樣 1% 的緩衝區是否有洩漏。預設。
ADVANCED - 抽樣 1% 的緩衝區是否洩漏,以及能定位到緩衝區洩漏的程式碼位置。
PARANOID - 與 ADVANCED 相同,只是它適用於每個緩衝區,適用於自動化測試階段。如果生成輸出包含「LEAK:」,則可能會使生成失敗。
本次記憶體漏失問題,我們通過本地設定洩漏檢測級別為高階,即:-Dio.netty.leakDetectionLevel=advanced
定位到了具體記憶體漏失的程式碼。
同時Netty也給出了避免洩漏的最佳實踐:
在 PARANOID 洩漏檢測級別以及 SIMPLE 級別執行單元測試和整合測試。
在 SIMPLE 級別向整個叢集推出應用程式之前,請先在相當長的時間內檢視是否存在洩漏。
如果有洩漏,灰度釋出中使用 ADVANCED 級別,以獲得有關洩漏來源的一些提示。
不要將洩漏的應用程式部署到整個群集。
二、解決Netty記憶體漏失,Netty也提供了指導方案,主要有三種方式
方式一:手動釋放,哪裡使用了,使用完就手動釋放,這個對使用方要求比較高了。
方式二:如果處理過程中不確定ByteBuf
是否應該被釋放,那交給Netty
的ReferenceCountUtil.release(msg)
來釋放,這個方法會判斷上下文中是否可以釋放,簡單方便。
方式三:升級ChannelHandler
為SimpleChannelHandler
, 在SimpleChannelHandler中,Netty對收到的所有訊息都呼叫了ReferenceCountUtil.release(msg)
,升級介面,可能對現有API改動會比較大。