Spring Boot引起的“堆外內存泄漏”排查及經驗總結

背景

為了更好地實現(xiàn)對項目的管理栗精,我們將組內一個項目遷移到MDP框架(基于Spring Boot),隨后我們就發(fā)現(xiàn)系統(tǒng)會頻繁報出Swap區(qū)域使用量過高的異常。筆者被叫去幫忙查看原因,發(fā)現(xiàn)配置了4G堆內內存,但是實際使用的物理內存竟然高達7G换吧,確實不正常。JVM參數(shù)配置是“-XX:MetaspaceSize=256M -XX:MaxMetaspaceSize=256M -XX:+AlwaysPreTouch -XX:ReservedCodeCacheSize=128m -XX:InitialCodeCacheSize=128m, -Xss512k -Xmx4g -Xms4g,-XX:+UseG1GC -XX:G1HeapRegionSize=4M”钥星,實際使用的物理內存如下圖所示:

top命令顯示的內存情況

排查過程

1. 使用Java層面的工具定位內存區(qū)域(堆內內存沾瓦、Code區(qū)域或者使用unsafe.allocateMemory和DirectByteBuffer申請的堆外內存)

筆者在項目中添加-XX:NativeMemoryTracking=detailJVM參數(shù)重啟項目,使用命令jcmd pid VM.native_memory detail查看到的內存分布如下:

jcmd顯示的內存情況

發(fā)現(xiàn)命令顯示的committed的內存小于物理內存谦炒,因為jcmd命令顯示的內存包含堆內內存贯莺、Code區(qū)域、通過unsafe.allocateMemory和DirectByteBuffer申請的內存宁改,但是不包含其他Native Code(C代碼)申請的堆外內存缕探。所以猜測是使用Native Code申請內存所導致的問題。

為了防止誤判还蹲,筆者使用了pmap查看內存分布爹耗,發(fā)現(xiàn)大量的64M的地址;而這些地址空間不在jcmd命令所給出的地址空間里面谜喊,基本上就斷定就是這些64M的內存所導致潭兽。

pmap顯示的內存情況

2. 使用系統(tǒng)層面的工具定位堆外內存

因為筆者已經基本上確定是Native Code所引起,而Java層面的工具不便于排查此類問題斗遏,只能使用系統(tǒng)層面的工具去定位問題山卦。

首先,使用了gperftools去定位問題

gperftools的使用方法可以參考gperftools最易,gperftools的監(jiān)控如下:

gperftools監(jiān)控

從上圖可以看出:使用malloc申請的的內存最高到3G之后就釋放了脚牍,之后始終維持在700M-800M肆糕。筆者第一反應是:難道Native Code中沒有使用malloc申請,直接使用mmap/brk申請的癞松?(gperftools原理就使用動態(tài)鏈接的方式替換了操作系統(tǒng)默認的內存分配器(glibc)视译。)

然后嬉荆,使用strace去追蹤系統(tǒng)調用

因為使用gperftools沒有追蹤到這些內存,于是直接使用命令“strace -f -e”brk,mmap,munmap” -p pid”追蹤向OS申請內存請求酷含,但是并沒有發(fā)現(xiàn)有可疑內存申請鄙早。strace監(jiān)控如下圖所示:

strace監(jiān)控

接著汪茧,使用GDB去dump可疑內存

因為使用strace沒有追蹤到可疑內存申請;于是想著看看內存中的情況限番。就是直接使用命令gdp -pid pid進入GDB之后舱污,然后使用命令dump memory mem.bin startAddress endAddressdump內存,其中startAddress和endAddress可以從/proc/pid/smaps中查找弥虐。然后使用strings mem.bin查看dump的內容扩灯,如下:

gperftools監(jiān)控

從內容上來看,像是解壓后的JAR包信息霜瘪。讀取JAR包信息應該是在項目啟動的時候珠插,那么在項目啟動之后使用strace作用就不是很大了。所以應該在項目啟動的時候使用strace颖对,而不是啟動完成之后捻撑。

再次,項目啟動時使用strace去追蹤系統(tǒng)調用

項目啟動使用strace追蹤系統(tǒng)調用缤底,發(fā)現(xiàn)確實申請了很多64M的內存空間顾患,截圖如下:

strace監(jiān)控

使用該mmap申請的地址空間在pmap對應如下:

strace申請內容對應的pmap地址空間

strace申請內容對應的pmap地址空間

最后,使用jstack去查看對應的線程

因為strace命令中已經顯示申請內存的線程ID个唧。直接使用命令jstack pid去查看線程棧描验,找到對應的線程棧(注意10進制和16進制轉換)如下:

strace申請空間的線程棧

這里基本上就可以看出問題來了:MCC(美團統(tǒng)一配置中心)使用了Reflections進行掃包,底層使用了Spring Boot去加載JAR坑鱼。因為解壓JAR使用Inflater類膘流,需要用到堆外內存,然后使用Btrace去追蹤這個類鲁沥,棧如下:

btrace追蹤棧

然后查看使用MCC的地方呼股,發(fā)現(xiàn)沒有配置掃包路徑,默認是掃描所有的包画恰。于是修改代碼彭谁,配置掃包路徑,發(fā)布上線后內存問題解決允扇。

3. 為什么堆外內存沒有釋放掉呢缠局?

雖然問題已經解決了,但是有幾個疑問:

為什么使用舊的框架沒有問題考润?

為什么堆外內存沒有釋放狭园?

為什么內存大小都是64M,JAR大小不可能這么大糊治,而且都是一樣大唱矛?

為什么gperftools最終顯示使用的的內存大小是700M左右,解壓包真的沒有使用malloc申請內存嗎?

帶著疑問绎谦,筆者直接看了一下Spring Boot Loader那一塊的源碼管闷。發(fā)現(xiàn)Spring Boot對Java JDK的InflaterInputStream進行了包裝并且使用了Inflater,而Inflater本身用于解壓JAR包的需要用到堆外內存窃肠。而包裝之后的類ZipInflaterInputStream沒有釋放Inflater持有的堆外內存包个。于是筆者以為找到了原因,立馬向Spring Boot社區(qū)反饋了這個bug冤留。但是反饋之后赃蛛,筆者就發(fā)現(xiàn)Inflater這個對象本身實現(xiàn)了finalize方法,在這個方法中有調用釋放堆外內存的邏輯搀菩。也就是說Spring Boot依賴于GC釋放堆外內存呕臂。

筆者使用jmap查看堆內對象時,發(fā)現(xiàn)已經基本上沒有Inflater這個對象了肪跋。于是就懷疑GC的時候歧蒋,沒有調用finalize。帶著這樣的懷疑州既,筆者把Inflater進行包裝在Spring Boot Loader里面替換成自己包裝的Inflater谜洽,在finalize進行打點監(jiān)控,結果finalize方法確實被調用了吴叶。于是筆者又去看了Inflater對應的C代碼阐虚,發(fā)現(xiàn)初始化的使用了malloc申請內存,end的時候也調用了free去釋放內存蚌卤。

此刻实束,筆者只能懷疑free的時候沒有真正釋放內存,便把Spring Boot包裝的InflaterInputStream替換成Java JDK自帶的逊彭,發(fā)現(xiàn)替換之后咸灿,內存問題也得以解決了。

這時侮叮,再返過來看gperftools的內存分布情況避矢,發(fā)現(xiàn)使用Spring Boot時,內存使用一直在增加囊榜,突然某個點內存使用下降了好多(使用量直接由3G降為700M左右)审胸。這個點應該就是GC引起的,內存應該釋放了卸勺,但是在操作系統(tǒng)層面并沒有看到內存變化砂沛,那是不是沒有釋放到操作系統(tǒng),被內存分配器持有了呢孔庭?

繼續(xù)探究尺上,發(fā)現(xiàn)系統(tǒng)默認的內存分配器(glibc 2.12版本)和使用gperftools內存地址分布差別很明顯,2.5G地址使用smaps發(fā)現(xiàn)它是屬于Native Stack圆到。內存地址分布如下:

gperftools顯示的內存地址分布

到此怎抛,基本上可以確定是內存分配器在搗鬼;搜索了一下glibc 64M芽淡,發(fā)現(xiàn)glibc從2.11開始對每個線程引入內存池(64位機器大小就是64M內存)马绝,原文如下:

glib內存池說明

按照文中所說去修改MALLOC_ARENA_MAX環(huán)境變量,發(fā)現(xiàn)沒什么效果挣菲。查看tcmalloc(gperftools使用的內存分配器)也使用了內存池方式富稻。

為了驗證是內存池搞的鬼,筆者就簡單寫個不帶內存池的內存分配器白胀。使用命令gcc zjbmalloc.c -fPIC -shared -o zjbmalloc.so生成動態(tài)庫椭赋,然后使用export LD_PRELOAD=zjbmalloc.so替換掉glibc的內存分配器。其中代碼Demo如下:

#include<sys/mman.h>#include<stdlib.h>#include<string.h>#include<stdio.h>//作者使用的64位機器或杠,sizeof(size_t)也就是sizeof(long) void*malloc(size_t size){long*ptr=mmap(0,size+sizeof(long),PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANONYMOUS,0,0);if(ptr==MAP_FAILED){returnNULL;}*ptr=size;// First 8 bytes contain length.return(void*)(&ptr[1]);// Memory that is after length variable}void*calloc(size_t n,size_t size){void*ptr=malloc(n*size);if(ptr==NULL){returnNULL;}memset(ptr,0,n*size);returnptr;}void*realloc(void*ptr,size_t size){if(size==0){free(ptr);returnNULL;}if(ptr==NULL){returnmalloc(size);}long*plen=(long*)ptr;plen--;// Reach top of memorylonglen=*plen;if(size<=len){returnptr;}void*rptr=malloc(size);if(rptr==NULL){free(ptr);returnNULL;}rptr=memcpy(rptr,ptr,len);free(ptr);returnrptr;}voidfree(void*ptr){if(ptr==NULL){return;}long*plen=(long*)ptr;plen--;// Reach top of memorylonglen=*plen;// Read lengthmunmap((void*)plen,len+sizeof(long));}

通過在自定義分配器當中埋點可以發(fā)現(xiàn)其實程序啟動之后應用實際申請的堆外內存始終在700M-800M之間哪怔,gperftools監(jiān)控顯示內存使用量也是在700M-800M左右。但是從操作系統(tǒng)角度來看進程占用的內存差別很大(這里只是監(jiān)控堆外內存)向抢。

筆者做了一下測試认境,使用不同分配器進行不同程度的掃包,占用的內存如下:

內存測試對比

為什么自定義的malloc申請800M挟鸠,最終占用的物理內存在1.7G呢叉信?

因為自定義內存分配器采用的是mmap分配內存,mmap分配內存按需向上取整到整數(shù)個頁艘希,所以存在著巨大的空間浪費硼身。通過監(jiān)控發(fā)現(xiàn)最終申請的頁面數(shù)目在536k個左右,那實際上向系統(tǒng)申請的內存等于512k * 4k(pagesize) = 2G覆享。 為什么這個數(shù)據(jù)大于1.7G呢鸠姨?

因為操作系統(tǒng)采取的是延遲分配的方式,通過mmap向系統(tǒng)申請內存的時候淹真,系統(tǒng)僅僅返回內存地址并沒有分配真實的物理內存讶迁。只有在真正使用的時候,系統(tǒng)產生一個缺頁中斷核蘸,然后再分配實際的物理Page巍糯。

總結

流程圖

整個內存分配的流程如上圖所示。MCC掃包的默認配置是掃描所有的JAR包客扎。在掃描包的時候祟峦,Spring Boot不會主動去釋放堆外內存,導致在掃描階段徙鱼,堆外內存占用量一直持續(xù)飆升宅楞。當發(fā)生GC的時候针姿,Spring Boot依賴于finalize機制去釋放了堆外內存;但是glibc為了性能考慮厌衙,并沒有真正把內存歸返到操作系統(tǒng)距淫,而是留下來放入內存池了,導致應用層以為發(fā)生了“內存泄漏”婶希。所以修改MCC的配置路徑為特定的JAR包榕暇,問題解決。筆者在發(fā)表這篇文章時喻杈,發(fā)現(xiàn)Spring Boot的最新版本(2.0.5.RELEASE)已經做了修改彤枢,在ZipInflaterInputStream主動釋放了堆外內存不再依賴GC;所以Spring Boot升級到最新版本筒饰,這個問題也可以得到解決缴啡。

作者:java成功之路

鏈接:http://www.reibang.com/p/2d3730146063

來源:簡書

?著作權歸作者所有,轉載或內容合作請聯(lián)系作者
  • 序言:七十年代末,一起剝皮案震驚了整個濱河市瓷们,隨后出現(xiàn)的幾起案子盟猖,更是在濱河造成了極大的恐慌,老刑警劉巖换棚,帶你破解...
    沈念sama閱讀 212,454評論 6 493
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件式镐,死亡現(xiàn)場離奇詭異,居然都是意外死亡固蚤,警方通過查閱死者的電腦和手機娘汞,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 90,553評論 3 385
  • 文/潘曉璐 我一進店門,熙熙樓的掌柜王于貴愁眉苦臉地迎上來夕玩,“玉大人你弦,你說我怎么就攤上這事×敲希” “怎么了禽作?”我有些...
    開封第一講書人閱讀 157,921評論 0 348
  • 文/不壞的土叔 我叫張陵,是天一觀的道長揩页。 經常有香客問我旷偿,道長,這世上最難降的妖魔是什么爆侣? 我笑而不...
    開封第一講書人閱讀 56,648評論 1 284
  • 正文 為了忘掉前任萍程,我火速辦了婚禮,結果婚禮上兔仰,老公的妹妹穿的比我還像新娘茫负。我一直安慰自己,他們只是感情好乎赴,可當我...
    茶點故事閱讀 65,770評論 6 386
  • 文/花漫 我一把揭開白布忍法。 她就那樣靜靜地躺著潮尝,像睡著了一般。 火紅的嫁衣襯著肌膚如雪饿序。 梳的紋絲不亂的頭發(fā)上勉失,一...
    開封第一講書人閱讀 49,950評論 1 291
  • 那天,我揣著相機與錄音嗤堰,去河邊找鬼戴质。 笑死度宦,一個胖子當著我的面吹牛踢匣,可吹牛的內容都是我干的。 我是一名探鬼主播戈抄,決...
    沈念sama閱讀 39,090評論 3 410
  • 文/蒼蘭香墨 我猛地睜開眼离唬,長吁一口氣:“原來是場噩夢啊……” “哼!你這毒婦竟也來了划鸽?” 一聲冷哼從身側響起输莺,我...
    開封第一講書人閱讀 37,817評論 0 268
  • 序言:老撾萬榮一對情侶失蹤,失蹤者是張志新(化名)和其女友劉穎裸诽,沒想到半個月后嫂用,有當?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體,經...
    沈念sama閱讀 44,275評論 1 303
  • 正文 獨居荒郊野嶺守林人離奇死亡丈冬,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內容為張勛視角 年9月15日...
    茶點故事閱讀 36,592評論 2 327
  • 正文 我和宋清朗相戀三年嘱函,在試婚紗的時候發(fā)現(xiàn)自己被綠了。 大學時的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片埂蕊。...
    茶點故事閱讀 38,724評論 1 341
  • 序言:一個原本活蹦亂跳的男人離奇死亡往弓,死狀恐怖,靈堂內的尸體忽然破棺而出蓄氧,到底是詐尸還是另有隱情函似,我是刑警寧澤,帶...
    沈念sama閱讀 34,409評論 4 333
  • 正文 年R本政府宣布喉童,位于F島的核電站撇寞,受9級特大地震影響,放射性物質發(fā)生泄漏堂氯。R本人自食惡果不足惜重抖,卻給世界環(huán)境...
    茶點故事閱讀 40,052評論 3 316
  • 文/蒙蒙 一、第九天 我趴在偏房一處隱蔽的房頂上張望祖灰。 院中可真熱鬧钟沛,春花似錦、人聲如沸局扶。這莊子的主人今日做“春日...
    開封第一講書人閱讀 30,815評論 0 21
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽。三九已至畜埋,卻和暖如春莫绣,著一層夾襖步出監(jiān)牢的瞬間,已是汗流浹背悠鞍。 一陣腳步聲響...
    開封第一講書人閱讀 32,043評論 1 266
  • 我被黑心中介騙來泰國打工对室, 沒想到剛下飛機就差點兒被人妖公主榨干…… 1. 我叫王不留,地道東北人咖祭。 一個月前我還...
    沈念sama閱讀 46,503評論 2 361
  • 正文 我出身青樓掩宜,卻偏偏與公主長得像,于是被迫代替她去往敵國和親么翰。 傳聞我的和親對象是個殘疾皇子牺汤,可洞房花燭夜當晚...
    茶點故事閱讀 43,627評論 2 350

推薦閱讀更多精彩內容