來源| OSCHINA 社區
作者 | 京東云開發者社區-京東零售 劉鵬
背景:
介紹
天網風控靈璣系統是基于內存計算實現的高吞吐低延遲在線計算服務,提供滑動或滾動窗口內的 count、distinctCout、max、min、avg、sum、std 及區間分布類的在線統計計算服務。客戶端和服務端底層通過 netty 直接進行 tcp 通信,且服務端也是基于 netty 將數據備份到對應的 slave 集群。
低延遲的瓶頸
靈璣第 1 個版本經過大量優化,系統能提供較大的吞吐量。如果對客戶端設置 10ms 超時,服務端 1wqps/core 的流量下,可用率只能保證在 98.9% 左右,高并發情況下主要是 gc 導致可用率降低。如果基于 cms 垃圾回收器。當一臺 8c16g 的機器在經過第二個版本優化后吞吐量超過 20wqps 的時候,那么大概每 4 秒會產生一次 gc。如果按照一次 gc 等于 30ms。那么至少分鐘顆粒度在 gc 時間的占比至少在 (15*30/1000/60)=0.0075。也就意味著分鐘級別的 tp992 至少在 30ms。不滿足相關業務的需求。
jdk17+ZGC
為了解決上述延遲過高的相關問題,JDK 11 開始推出了一種低延遲垃圾回收器 ZGC。ZGC 使用了一些新技術和優化算法,可以將 GC 暫停時間控制在 10 毫秒以內,而在 JDK 17 的加持下,ZGC 的暫停時間甚至可以控制在亞毫秒級別。實測在平均停頓時間在 10us 左右,主要是基于一個染色指針和讀屏障做到大多數 gc 階段可以做到并發的,有興趣的同學可以了解下,并且 jdk17 是一個 lts 版本。
問題:
采用 jdk17+zgc 經過相關的壓測后,一切都在向著好的方向發展,但是在一種特殊場景壓測,需要將數據從北京數據中心同步給宿遷數據中心的時候,發現了一些詭異的事情
服務端容器的內存瘋漲,并且停止壓測后,內存只是非常緩慢的減少。
相關機器 cpu 一直保存在 20%(已經無流量請求)
一直在次數不多的 gc。大概每 10s 一次
排查之旅
內存泄漏排查
第一反應是遇到內存瘋漲和無法釋放該問題時,首先歸納為內存泄漏問題,感覺這題也簡單明了。開始相關內存泄漏檢查:先 dump 堆內存分析發現占用堆內存的是 netty 相關的對象,恰好前段時間也有個同學也分享了 netty 下的不合理使用 netty byteBuf 導致的內存泄漏,進一步增加了對 netty 內存泄露的懷疑。于是開啟 netty 內存泄漏嚴格檢查模式 (加上 jvm 參數 Dio.netty.leakDetection.level=PARANOID),重新試跑并沒有發現相關內存泄漏日志。好吧~!初步判定不是 netty 內存泄漏。
jdk 與 netty 版本 bug 排查
會不會是 netty 與 jdk17 兼容不好導致的 bug? 回滾 jdk8 測試發現的確不存在這個問題,當時使用的是 jdk17.0.7 版本。正好官方發布了 jdk17.0.8 版本,并且看到版本介紹上有若干的 Bug Fixes。所以又升級了 jdk 一個小版本,然而發現問題仍然在。會不會是 netty 的版本過低?正好看見 gitup 上也有類似的 issue# https://github.com/netty/netty/issues/6125WriteBufferWaterMark's 并且在高版本疑似修復了該問題,修改了 netty 幾個版本重新壓測,然而發現問題仍然在。
直接原因定位與解決
經過上述兩次排查,發現問題比想象中復雜,應該深入分析下為什么,重新梳理了下相關線索:
發現回滾至 jdk8 的時候,對應宿遷中心的集群接受到的備份數據量比北京中心發送的數據量低了很多
為什么沒有流量了還一直有 gc,cpu 高應該是 gc 造成的(當時認為是 zgc 的內存的一些特性)
內存分析:為什么 netty 的 MpscUnboundedArrayQueue 引用了大量的 AbstractChannelHandlerContext$WriteTask 對象,。MpscUnboundedArrayQueue 是生產消費 writeAndFlush 任務隊列,WriteTask 是相關的 writeAndFlush 的任務對象,正是因為大量的 WriteTask 對象及其引用導致了內存占用過高。
只有跨數據中心出現該問題,同數據中心數據壓測不會出現該問題。
分析過后已經有了基本的猜想,因為跨數據中心下機房延遲更大,單 channel 信道下已經沒法滿足同步數據能力,導致 netty 的 eventLoop 的消費能不足導致積壓。 解決方案:增加與備份數據節點的 channel 信道連接,采用 connectionPool,每次批量同步數據的時候隨機選擇一個存活的 channel 進行數據通信。經過相關改造后發現問題得到了解決。
根因定位與解決
根因定位
雖然經過上述的改造,表面上看似解決了問題,但是問題的根本原因還是沒有被發現
1. 如果是 eventLoop 消費能力不足,為什么停止壓測后,相關內存只是緩慢減少,按理說應該是瘋狂的內存減少。
2. 為什么一直 cpu 在 23% 左右,按照平時的壓測數據,同步數據是一個流轉批的操作,最多也就消耗 5% cpu 左右,多出來的 cpu 應該是 gc 造成的,但是數據同步應該并不多,不應該造成這么多的 gc 壓力。
3. 為什么 jdk8 下不會存在該問題
推測應該是有個 netty eventLoop 消費耗時阻塞的操作導致消費能力大幅度下降。所以感覺還是 netty 的問題,于是開了 netty 的相關 debug 日志。發現了一行關鍵日志
[2023-08-23 1116.163] DEBUG [] - io.netty.util.internal.PlatformDependent0 - direct buffer constructor: unavailable: Reflective setAccessible(true) disabled順著這條日志找到了本次的問題根因,為什么一個直接內存的構造器不能使用會導致我們系統 WriteTask 消費阻塞, 帶著這個目的去查看相關的源碼。
源碼分析
一) netty 默認會用 PooledByteBufAllocator 來分配直接內存,采用類似 jmelloc 的內存池機制,每次內存不足的時候會通過創建 io.netty.buffer.PoolArena.DirectArena#newChunk 去預占申請內存。
protected PoolChunknewChunk() { // 關鍵代碼 ByteBuffer memory = allocateDirect(chunkSize); } }
二) allocateDirect () 是申請直接內存的邏輯。大致就是如果能采用底層 unsafe 去申請、釋放直接內存和反射創建 ByteBuffer 對象,那么就采用 unsafe。否則就直接調用 java 的 Api ByteBuffer.allocateDirect 來直接分配內存并且采用自帶的 Cleaner 來釋放內存。這里 PlatformDependent.useDirectBufferNoCleaner 是個關鍵點,其實就是 USE_DIRECT_BUFFER_NO_CLEANER 參數配置
PlatformDependent.useDirectBufferNoCleaner() ? PlatformDependent.allocateDirectNoCleaner(capacity) : ByteBuffer.allocateDirect(capacity);
三) USE_DIRECT_BUFFER_NO_CLEANER 參數邏輯配置在 PlatformDependent 類的 static {} 里面。
關鍵邏輯:maxDirectMemory==0 和!hasUnsafe () 在 jdk17 下沒有特殊配置都是不滿足條件的,關鍵是 PlatformDependent0.hasDirectBufferNoCleanerConstructor 的判斷邏輯
if (maxDirectMemory == 0 || !hasUnsafe() || !PlatformDependent0.hasDirectBufferNoCleanerConstructor()) { USE_DIRECT_BUFFER_NO_CLEANER = false; } else { USE_DIRECT_BUFFER_NO_CLEANER = true;
四) PlatformDependent0.hasDirectBufferNoCleanerConstructor () 的判斷是看 PlatformDependent0 的 DIRECT_BUFFER_CONSTRUCTOR 是否 NULL,回到了剛開的 debug 日志,我們是可以看到在默認情況下 DIRECT_BUFFER_CONSTRUCTOR 該構造器是 unavailable 的(unavailable 則為 NULL)。以下代碼具體的邏輯判斷及其偽代碼。
1. 開啟條件一:jdk9 及其以上必須要開啟 jvm 參數 -io.netty.tryReflectionSetAccessible 參數 2. 開啟條件二:能反射獲取到一個 private DirectByteBuffer 構造器,該構造器是通過內存地址和大小來構造 DirectByteBuffer.(備注:如果在 jdk9 以上對 java.nio 有模塊權限限制,需要加上 jvm 啟動參數 --add-opens=java.base/java.nio=ALL-UNNAMED , 否則會報 Unable to make private java.nio.DirectByteBuffer (long,int) accessible: module java.base does not "opens java.nio" to unnamed module) 所以這里我們默認是沒有開啟這兩個 jvm 參數的,那么 DIRECT_BUFFER_CONSTRUCTOR 為空值,對應第二部 PlatformDependent.useDirectBufferNoCleaner () 為 false。
// 偽代碼,實際與這不一致 ByteBuffer direct = ByteBuffer.allocateDirect(1); if(SystemPropertyUtil.getBoolean("io.netty.tryReflectionSetAccessible", javaVersion() < 9 || RUNNING_IN_NATIVE_IMAGE)) { DIRECT_BUFFER_CONSTRUCTOR = direct.getClass().getDeclaredConstructor(long.class, int.class) }
五) 現在回到第 2 步驟,發現 PlatformDependent.useDirectBufferNoCleaner () 在 jdk 高版本下默認值是 false。那么每次申請直接內存都是通過 ByteBuffer.allocateDirect 來創建。那么到這個時候就已經定位到相關根因了,通過 ByteBuffer.allocateDirect 來申請直接內存,如果內存不足的時候會強制系統 System.Gc (),并且會同步等待 DirectByteBuffer 通過 Cleaner 的虛引用回收內存。下面是 ByteBuffer.allocateDirect 預占內存(reserveMemory)的關鍵代碼。大概邏輯是 觸達申請的最大的直接內存 -> 判斷是否有相關的對象在 gc 回收 -> 沒有在回收則主動觸發 System.gc () 來觸發回收 -> 在同步循環最多等待 MAX_SLEEPS 次數看是否有足夠的直接內存。整個同步等待邏輯在親測在 jdk17 版本最多能 1 秒以上。
所以最根本原因:如果這個時候我們的 netty 的消費者 EventLoop 處理消費因為申請直接內存在達到最大內存的場景,那么就會導致有大量的任務消費都會同步去等待申請直接內存上。并且如果沒有足夠的的直接內存,那么就會成為大面積的消費阻塞。
static void reserveMemory(long size, long cap) { if (!MEMORY_LIMIT_SET && VM.initLevel() >= 1) { MAX_MEMORY = VM.maxDirectMemory(); MEMORY_LIMIT_SET = true; } // optimist! if (tryReserveMemory(size, cap)) { return; } final JavaLangRefAccess jlra = SharedSecrets.getJavaLangRefAccess(); boolean interrupted = false; try { do { try { refprocActive = jlra.waitForReferenceProcessing(); } catch (InterruptedException e) { // Defer interrupts and keep trying. interrupted = true; refprocActive = true; } if (tryReserveMemory(size, cap)) { return; } } while (refprocActive); // trigger VM's Reference processing System.gc(); int sleeps = 0; while (true) { if (tryReserveMemory(size, cap)) { return; } if (sleeps >= MAX_SLEEPS) { break; } try { if (!jlra.waitForReferenceProcessing()) { Thread.sleep(sleepTime); sleepTime <<= 1; sleeps++; } } catch (InterruptedException e) { interrupted = true; } } // no luck throw new OutOfMemoryError ("Cannot reserve " + size + " bytes of direct buffer memory (allocated: " + RESERVED_MEMORY.get() + ", limit: " + MAX_MEMORY +")"); } finally { if (interrupted) { // don't swallow interrupts Thread.currentThread().interrupt(); } } }
六) 雖然我們看到了阻塞的原因,但是為什么 jdk8 下為什么就不會阻塞從 4 步驟中看到 java 9 以下是設置了 DIRECT_BUFFER_CONSTRUCTOR 的,因此采用的是 PlatformDependent.allocateDirectNoCleaner 進行內存分配。以下是具體的介紹和關鍵代碼
步驟一:申請內存前:通過全局內存計數器DIRECT_MEMORY_COUNTER,在每次申請內存的時候調用 incrementMemoryCounter 增加相關的 size,如果達到相關 DIRECT_MEMORY_LIMIT (默認是 - XX:MaxDirectMemorySize) 參數則直接拋出異常,而不會去同步 gc 等待導致大量耗時。。
步驟二:分配內存 allocateDirectNoCleaner: 是通過 unsafe 去申請內存,再用構造器DIRECT_BUFFER_CONSTRUCTOR通過內存地址和大小來構造 DirectBuffer。釋放也可以通過 unsafe.freeMemory 根據內存地址來釋放相關內存,而不是通過 java 自帶的 cleaner 來釋放內存。
public static ByteBuffer allocateDirectNoCleaner(int capacity) { assert USE_DIRECT_BUFFER_NO_CLEANER; incrementMemoryCounter(capacity); try { return PlatformDependent0.allocateDirectNoCleaner(capacity); } catch (Throwable e) { decrementMemoryCounter(capacity); throwException(e); return null; } } private static void incrementMemoryCounter(int capacity) { if (DIRECT_MEMORY_COUNTER != null) { long newUsedMemory = DIRECT_MEMORY_COUNTER.addAndGet(capacity); if (newUsedMemory > DIRECT_MEMORY_LIMIT) { DIRECT_MEMORY_COUNTER.addAndGet(-capacity); throw new OutOfDirectMemoryError("failed to allocate " + capacity + " byte(s) of direct memory (used: " + (newUsedMemory - capacity) + ", max: " + DIRECT_MEMORY_LIMIT + ')'); } } } static ByteBuffer allocateDirectNoCleaner(int capacity) { return newDirectBuffer(UNSAFE.allocateMemory(Math.max(1, capacity)), capacity); }
經過上述的源碼分析,已經看到了根本原因,就是 ByteBuffer.allocateDirect gc 同步等待直接內存釋放導致消費能力嚴重不足導致的,并且在最大直接內存不足的情況下,大面積的消費阻塞耗時在申請直接內存,導致消費 WriteTask 能力接近于 0,內存從而無法下降
總結
1. 流程圖: 2. 直接原因:
跨數據中心同步數據單 channel 管道同步數據能力不足,導致 tcp 環阻塞。從而導致 netty eventLoop 的消費 WriteTask 任務 (WriteAndFlush) 中的 write 能力大于 flush 能力,因此申請的大量的直接內存存放在 ChannelOutboundBuffer#unflushedEntry 鏈表中沒法 flush。
3. 根本原因:
netty 在 jdk 高版本需要手動添加 jvm 參數 -add-opens=java.base/java.nio=ALL-UNNAMED 和 - io.netty.tryReflectionSetAccessible 來開啟采用直接調用底層 unsafe 來申請內存,如果不開啟那么 netty 申請內存采用 ByteBuffer.allocateDirect 來申請直接內存,如果 EventLoop 消費任務申請的直接內存達到最大直接內存場景,那么就會導致有大量的任務消費都會同步去等待申請直接內存上。并且如果沒有釋放足夠的直接內存,那么就會成為大面積的消費阻塞,也同時導致大量的對象累積在 netty 的無界隊列 MpscUnboundedArrayQueue 中。
4. 反思與定位問題慢的原因:
默認同步數據這里不會是系統瓶頸,沒有加上 lowWaterMark 和 highWaterMark 水位線的判斷(socketChannel.isWritable ()),如果同步數據達到系統瓶頸應該提前能感知到拋出異常。
同步數據的時候調用 writeAndFlush 應該加上相關的異常監聽器(以下代碼 2),若果能提前感知到異常 OutOfMemoryError 那么更方便排查到相關問題。
(1)ChannelFuture writeAndFlush(Object msg) (2)ChannelFuture writeAndFlush(Object msg, ChannelPromise promise);
jdk17 下監控系統看到的非堆內存監控并未與系統實際使用的直接內存統計一致,導致開始定位問題無法定位到直接內存已經達到最大值,從而并未往這個方案思考。
相關引用的中間件底層通信也是依賴于 netty 通信,如果有類似的數據同步也可能會觸發類似的問題。特別 ump 在高版本和 titan 使用 netty 的時候是進行了 shade 打包的,并且相關的 jvm 參數也被修改,雖然不會觸發該 bug,但是也可能導致觸發系統 gc。
ump高版本:jvm參數修改(低版本直接采用了底層socket通信,未使用netty和創建ByteBuffer) io.netty.tryReflectionSetAccessible->ump.profiler.shade.io.netty.tryReflectionSetAccessible titan:jvm參數修改:io.netty.tryReflectionSetAccessible->titan.profiler.shade.io.netty.tryReflectionSetAccessible
審核編輯:湯梓紅
-
cpu
+關注
關注
68文章
10890瀏覽量
212404 -
數據中心
+關注
關注
16文章
4831瀏覽量
72252 -
TCP
+關注
關注
8文章
1374瀏覽量
79159 -
內存計算
+關注
關注
1文章
15瀏覽量
12188
原文標題:jdk17下netty導致堆內存瘋漲原因排查
文章出處:【微信號:OSC開源社區,微信公眾號:OSC開源社區】歡迎添加關注!文章轉載請注明出處。
發布評論請先 登錄
相關推薦
評論