導(dǎo)讀

本文記錄最近一例Java應(yīng)用OOM問題的排查過程，希望可以給遇到類似問題的同學(xué)提供參考。

前言：此文記錄最近一例Java應(yīng)用OOM問題的排查過程，希望可以給遇到類似問題的同學(xué)提供參考。在本地集團(tuán)，大多數(shù)情況下Java堆的大小會(huì)設(shè)置為容器規(guī)格的50%～70%，但如果你設(shè)置為50%時(shí)還是遇到了OS OOM的問題，會(huì)不會(huì)無法忍受進(jìn)而想要知道這是為什么？沒錯(cuò)，我也有一樣的好奇。

背景

某核心應(yīng)用的負(fù)責(zé)同學(xué)反饋應(yīng)用存在少量機(jī)器OOM被OS kill的問題?？磗unfire監(jiān)控信息，的確如此。

初步收集到的信息：

容器內(nèi)存=8G，Java 11，G1 GC=4G，MaxDirectMemorySize=1G。詳見下圖：

業(yè)務(wù)同學(xué)已經(jīng)做過Java dump，可以看到堆外對(duì)象幾乎沒有，堆內(nèi)的使用量也不大，<3G。上機(jī)器查看Java進(jìn)程的內(nèi)存使用量的確很大：

通過目前掌握到的信息來看，4G（Java堆）+1G（堆外）+512M（元空間）+250M（CodeCache）+其它，離6.8G還是有不少差距，無法簡(jiǎn)單的明確原因，需要深入排查分析了。

問題結(jié)論

省流版

中間件中多個(gè)不同的ClassLoader加載了多個(gè)netty的io.netty.buffer.PooledByteBufAllocator，每一個(gè)都有1G的內(nèi)存配額，所以存在實(shí)際使用的堆外內(nèi)存超出1G限制的問題。

通過Arthas可以看到存在這個(gè)類的7個(gè)不同的實(shí)例：

而其中rocketmq-client的這一個(gè)，已經(jīng)基本用完1G的內(nèi)存（其它幾個(gè)使用量大多在100多M的樣子）：

詳細(xì)版

中間件中多個(gè)不同的ClassLoader加載了多個(gè)netty的io.netty.buffer.PooledByteBufAllocator，每個(gè)Allocator都用自己的計(jì)數(shù)器在限制堆外內(nèi)存的使用量，這個(gè)限制值大多數(shù)情況下取值至MaxDirectMemorySize，所以會(huì)存在無法限制堆外內(nèi)存使用量在1G以內(nèi)的問題。（這個(gè)設(shè)計(jì)是否合理，還請(qǐng)中間件的同學(xué)幫忙補(bǔ)充了）

這個(gè)應(yīng)用是餓了么彈內(nèi)的應(yīng)用，io.netty.buffer.PooledByteBufAllocator，有7個(gè)ClassLoader加載了它，分別是：

sentinel's ModuleClassLoader、rocketmq-client's ModuleClassLoader、tair-plugin's ModuleClassLoader、hsf's ModuleClassLoader、XbootModuleClassLoader、pandora-qos-service's ModuleClassLoader、ele-enhancer's ModuleClassLoader。

相比彈內(nèi)應(yīng)用的4個(gè)（數(shù)據(jù)來自淘天集團(tuán)的核心應(yīng)用ump2，如下圖），多了3個(gè)。

在Java8，以及Java11中（JVM參數(shù)設(shè)置了-Dio.netty.tryReflectionSetAccessible=true過后），netty會(huì)直接使用unsafe的方法申請(qǐng)堆外內(nèi)存，不通過Java的DirectMemory分配API，所以通過監(jiān)控看不到堆外內(nèi)存的占用量，也不受JVM MaxDirectMemorySize的管控。

查看DirectByteBuffer實(shí)現(xiàn)代碼可以發(fā)現(xiàn)，它限制MaxDirectMemorySize的方法是在Java層（代碼標(biāo)記處1），實(shí)際上在JVM底層是沒有任何限制的，netty是直接用了這里代碼標(biāo)記處2的API分配內(nèi)存。

排查過程

1.1.通過NativeMemoryTracking看Native內(nèi)存的占用分布

通過在JVM參數(shù)上加上-XX:NativeMemoryTracking=detail，就可以打印出詳細(xì)的內(nèi)存分類的占用信息了，觀察了一整天，發(fā)現(xiàn)主要的可疑變化是在Other部分，即堆外的部分，如下圖。（ Java NMT的詳細(xì)使用可以參考相應(yīng)的技術(shù)文章）

明明是限制的堆外1G，怎么超過了這么多。再多觀察一會(huì)，發(fā)現(xiàn)它還會(huì)繼續(xù)緩慢上漲的，最高達(dá)到接近1.5GB。這就和最開始查看Java進(jìn)程的RSS占用對(duì)上了。

1.2.native內(nèi)存泄漏了嗎

JVM使用什么native分配器

通過查看機(jī)器上安裝的JDK的信息，可以看到使用的是jemalloc的內(nèi)存分配器。是不是它有泄漏、內(nèi)存碎片、歸還不及時(shí)的問題？

網(wǎng)上搜索，發(fā)現(xiàn)的有一篇文章講的場(chǎng)景和我們這里的有一些類似。（https://blog.csdn.net/liulilittle/article/details/137535634）

嘗試重新下載jemalloc的源碼，并進(jìn)行其參數(shù)的調(diào)整：

export MALLOC_CONF="dirty_decay_ms:0,muzzy_decay_ms:0"

觀察發(fā)現(xiàn)內(nèi)存的占用量有少量的下降，但還是會(huì)超過1個(gè)G，看起來核心問題不在這里。

誰在分配內(nèi)存

同時(shí)還通過perf工具監(jiān)控了下調(diào)用內(nèi)存分配的調(diào)用棧，想看看有什么線索沒有，然而并沒有什么線索。畢竟這個(gè)內(nèi)存的增長(zhǎng)比較緩慢，perf也不可能抓太長(zhǎng)時(shí)間了，遂放棄這個(gè)思路。

sudo perf probe -x /opt/taobao/install/ajdk11_11.0.23.24/lib/libjemalloc.so.2 malloc

sudo perf record -e probe_libjemalloc:malloc -p `pidof java` -g -- sleep 10

內(nèi)存里面裝了什么

通過 sudo pmap -x `pidof java` | sort -k 3 -n 命令查看進(jìn)程的所有內(nèi)存塊信息，如下圖示：

排除最大的4G的這一個(gè)（這是Java堆），以及內(nèi)存標(biāo)志帶x的兩個(gè)（可執(zhí)行代碼標(biāo)志，那是CodeCache），把其它的塊都dump下來，看看里面都放了啥，有沒有什么不平凡的。

使用gdb命令：gdb --batch --pid `pidof java` -ex "dump memory mem1.log 0x7f0109800000 0x7f0109800000+0x200000"

然后將dump下的內(nèi)存以字符串的方式輸出觀察下：cat mem1.log | strings

如圖所示，發(fā)現(xiàn)里面大量的內(nèi)容都和RocketMQ有關(guān)。不過我發(fā)現(xiàn)我早率了，這些dump內(nèi)容我看了快一天，根本沒有發(fā)現(xiàn)什么不太對(duì)的地方，看起來都是正常的占用。（不過明顯能看出來這里面存了一堆消費(fèi)者信息，表達(dá)的比較冗余）

求助JVM專家

還真是從入門到放棄，到這個(gè)時(shí)候已經(jīng)沒啥信心啦。遂求助于JVM的專家毛亮，他給了大的方向，一是這里不太可能有native的內(nèi)存泄漏，二是既然懷疑是堆外，把堆外內(nèi)存減少一點(diǎn)看看情況，明確下是不是native內(nèi)存分配器的回收特性就是這樣。往往native的內(nèi)存分配器都有自己的管理策略，他會(huì)有自己的回收拐點(diǎn)，比應(yīng)用看到的高一點(diǎn)是合理的。

的確，那么接下來的策略就是把MaxDirectMemeorySize調(diào)低到512M觀察下效果吧。

1.3.堆外內(nèi)存調(diào)小影響業(yè)務(wù)了

在堆外內(nèi)存從1G調(diào)小到512M過后，過了個(gè)周末，周一的時(shí)候業(yè)務(wù)同學(xué)就反饋，調(diào)小遇到問題了，存在MQ消息消費(fèi)不及時(shí)而導(dǎo)致消息擠壓的問題。結(jié)合之前看到的native內(nèi)存的信息，突然想到，MQ客戶端一定是占用了超過512M的內(nèi)存，內(nèi)心里出現(xiàn)了兩個(gè)問題：

1.MQ底層依賴netty，那么netty實(shí)際使用的內(nèi)存是多少？以及這個(gè)內(nèi)存占用量和native的堆外占用量是什么關(guān)系？

2.為啥Java的DirectMemory占用這么少，netty的內(nèi)存占用似乎并沒有被看到，這是怎么回事？

帶著這兩個(gè)問題，查看了netty內(nèi)存管理的核心類 io.netty.buffer.PooledByteBufAllocator，以及機(jī)器上啟動(dòng)過程中打印出的信息。

結(jié)合這里面涉及的另一個(gè)核心類io.netty.util.internal.PlatformDependent，大概明白了這里面的邏輯，netty是直接使用（是有前提條件的，但這個(gè)應(yīng)用通過JVM參數(shù)[-Dio.netty.tryReflectionSetAccessible=true]開啟了這個(gè)特性，這也是大多數(shù)應(yīng)用上面的行為）UNSAFE.allocateMemory分配內(nèi)存，完全繞過Java的直接內(nèi)存API。然后它自己實(shí)現(xiàn)了內(nèi)存占用空間的限制，這個(gè)值等于JVM參數(shù)中的MaxDirectMemorySize。到這里，似乎發(fā)現(xiàn)了曙光，莫非就是netty？（netty這么做的原因是為了不依賴JVM機(jī)制而加速內(nèi)存的釋放，同時(shí)也是為了解決在堆外內(nèi)存不足時(shí)JVM的糟糕的回收機(jī)制設(shè)計(jì)。）

1.4.Netty到底占用了多少內(nèi)存

好在netty的類中有一個(gè)靜態(tài)變量是可以很容易的看到這個(gè)信息的：

io.netty.buffer.PooledByteBufAllocator#DEFAULT。

那么這個(gè)時(shí)候就是需要上機(jī)器去執(zhí)行它了。Arthas是個(gè)不錯(cuò)的工具，可以直接在機(jī)器執(zhí)行表達(dá)式看任何靜態(tài)變量的值，并不需要我們改代碼然后去調(diào)用上面的對(duì)象做日志打印。

登錄機(jī)器后，通過命令查找netty Allocator的類定義：

sc -d io.netty.buffer.PooledByteBufAllocator

發(fā)現(xiàn)有不止一個(gè)Allocator，來自于不同的ClassLoader，以及不同的jar包。一共有7個(gè)。

然后一個(gè)一個(gè)的看他們實(shí)際占用的大?。?/p>

getstatic -c d5bc00 io.netty.buffer.PooledByteBufAllocator DEFAULT

然后把他們占用的內(nèi)存逐項(xiàng)加起來，發(fā)現(xiàn)的確超過了1G，同時(shí)和前面通過NMT看到的Other類別的內(nèi)存大小是比較吻合的。到這里大概就明確具體是怎么回事了，內(nèi)存是netty用掉的。

1.5.業(yè)務(wù)應(yīng)該怎么做呢

到目前為此，問題是明確了，但似乎并沒有什么太好的解法。一個(gè)是rocketmq-client的內(nèi)存占用是不是太大了，有沒有什么可以優(yōu)化的地方？（從前面看native內(nèi)存看到的內(nèi)容來看，還是有很大的優(yōu)化空間的，一大堆地址信息都是以字符串的形式寫在內(nèi)存里面），另一個(gè)是中間件的調(diào)整肯定是長(zhǎng)期的，短期業(yè)務(wù)要怎么辦呢？

思考再三，短期來看只能是先讓業(yè)務(wù)把Java堆調(diào)?。ㄍㄟ^Java dump以及JVM監(jiān)控可以看出來堆的使用率并不高），來適應(yīng)當(dāng)前的現(xiàn)狀了。

至于堆外內(nèi)存大小沒有限制住的問題，我感覺并不是中間件同學(xué)的預(yù)期之中的，這塊后面也找相關(guān)同學(xué)聊一聊。

后記

以后排查Java堆外內(nèi)存過大的問題，優(yōu)先看netty的占用。