遇到記憶體漏失

2020-08-10 16:28:56

爲了更好地實現對專案的管理,我們將組內一個專案遷移到MDP框架(基於Spring Boot),隨後我們就發現系統會頻繁報出Swap區域使用量過高的異常。

 

筆者被叫去幫忙檢視原因,發現設定了4G堆內記憶體,但是實際使用的實體記憶體竟然高達7G,確實不正常。

 

JVM參數設定是

 

-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層面的工具定位記憶體區域(堆內記憶體、Code區域或者使用unsafe.allocateMemory和DirectByteBuffer申請的堆外記憶體)

 

筆者在專案中新增-XX:NativeMemoryTracking=detailJVM參數重新啓動專案,使用命令jcmd pid VM.native_memory detail檢視到的記憶體分佈如下:

 

jcmd顯示的記憶體情況

 

發現命令顯示的committed的記憶體小於實體記憶體,因爲jcmd命令顯示的記憶體包含堆內記憶體、Code區域、通過unsafe.allocateMemory和DirectByteBuffer申請的記憶體,但是不包含其他Native Code(C程式碼)申請的堆外記憶體。所以猜測是使用Native Code申請記憶體所導致的問題。

 

爲了防止誤判,筆者使用了pmap檢視記憶體分佈,發現大量的64M的地址;而這些地址空間不在jcmd命令所給出的地址空間裏面,基本上就斷定就是這些64M的記憶體所導致。

 

pmap顯示的記憶體情況

 

2. 使用系統層面的工具定位堆外記憶體

 

因爲筆者已經基本上確定是Native Code所引起,而Java層面的工具不便於排查此類問題,只能使用系統層面的工具去定位問題。

 

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

 

gperftools的使用方法可以參考gperftools,gperftools的監控如下:

 

gperftools監控

 

從上圖可以看出:使用malloc申請的的記憶體最高到3G之後就釋放了,之後始終維持在700M-800M。筆者第一反應是:難道Native Code中沒有使用malloc申請,直接使用mmap/brk申請的?(gperftools原理就使用動態鏈接的方式替換了操作系統預設的記憶體分配器(glibc)。)

 

然後,使用strace去追蹤系統呼叫

 

因爲使用gperftools沒有追蹤到這些記憶體,於是直接使用命令「strace -f -e」brk,mmap,munmap」 -p pid」追蹤向OS申請記憶體請求,但是並沒有發現有可疑記憶體申請。strace監控如下圖所示:

 

strace監控

 

接着,使用GDB去dump可疑記憶體

 

因爲使用strace沒有追蹤到可疑記憶體申請;於是想着看看記憶體中的情況。就是直接使用命令gdp -pid pid進入GDB之後,然後使用命令dump memory mem.bin startAddress endAddressdump記憶體,其中startAddress和endAddress可以從/proc/pid/smaps中查詢。然後使用strings mem.bin檢視dump的內容,如下:

 

gperftools監控

 

從內容上來看,像是解壓後的JAR包資訊。讀取JAR包資訊應該是在專案啓動的時候,那麼在專案啓動之後使用strace作用就不是很大了。所以應該在專案啓動的時候使用strace,而不是啓動完成之後。

 

再次,專案啓動時使用strace去追蹤系統呼叫

 

專案啓動使用strace追蹤系統呼叫,發現確實申請了很多64M的記憶體空間,截圖如下:

 

strace監控

 

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

 

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

 

最後,使用jstack去檢視對應的執行緒

 

因爲strace命令中已經顯示申請記憶體的執行緒ID。直接使用命令jstack pid去檢視執行緒棧,找到對應的執行緒棧(注意10進位制和16進位制轉換)如下:

 

strace申請空間的執行緒棧

 

這裏基本上就可以看出問題來了:MCC(美團統一設定中心)使用了Reflections進行掃包,底層使用了Spring Boot去載入JAR。因爲解壓JAR使用Inflater類,需要用到堆外記憶體,然後使用Btrace去追蹤這個類,棧如下:

 

btrace追蹤棧

 

然後檢視使用MCC的地方,發現沒有設定掃包路徑,預設是掃描所有的包。於是修改程式碼,設定掃包路徑,發佈上線後記憶體問題解決。

 

3. 爲什麼堆外記憶體沒有釋放掉呢?

 

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

 

  • 爲什麼使用舊的框架沒有問題?

  • 爲什麼堆外記憶體沒有釋放?

  • 爲什麼記憶體大小都是64M,JAR大小不可能這麼大,而且都是一樣大?

  • 爲什麼gperftools最終顯示使用的的記憶體大小是700M左右,解壓包真的沒有使用malloc申請記憶體嗎?

 

帶着疑問,筆者直接看了一下Spring Boot Loader那一塊的原始碼。發現Spring Boot對Java JDK的InflaterInputStream進行了包裝並且使用了Inflater,而Inflater本身用於解壓JAR包的需要用到堆外記憶體。而包裝之後的類ZipInflaterInputStream沒有釋放Inflater持有的堆外記憶體。於是筆者以爲找到了原因,立馬向Spring Boot社羣反饋了這個bug。但是反饋之後,筆者就發現Inflater這個物件本身實現了finalize方法,在這個方法中有呼叫釋放堆外記憶體的邏輯。也就是說Spring Boot依賴於GC釋放堆外記憶體。

 

筆者使用jmap檢視堆內物件時,發現已經基本上沒有Inflater這個物件了。於是就懷疑GC的時候,沒有呼叫finalize。帶着這樣的懷疑,筆者把Inflater進行包裝在Spring Boot Loader裏面替換成自己包裝的Inflater,在finalize進行打點監控,結果finalize方法確實被呼叫了。於是筆者又去看了Inflater對應的C程式碼,發現初始化的使用了malloc申請記憶體,end的時候也呼叫了free去釋放記憶體。

 

此刻,筆者只能懷疑free的時候沒有真正釋放記憶體,便把Spring Boot包裝的InflaterInputStream替換成Java JDK自帶的,發現替換之後,記憶體問題也得以解決了。

 

這時,再返過來看gperftools的記憶體分佈情況,發現使用Spring Boot時,記憶體使用一直在增加,突然某個點記憶體使用下降了好多(使用量直接由3G降爲700M左右)。這個點應該就是GC引起的,記憶體應該釋放了,但是在操作系統層面並沒有看到記憶體變化,那是不是沒有釋放到操作系統,被記憶體分配器持有了呢?

 

繼續探究,發現系統預設的記憶體分配器(glibc 2.12版本)和使用gperftools記憶體地址分佈差別很明顯,2.5G地址使用smaps發現它是屬於Native Stack。記憶體地址分佈如下:

 

gperftools顯示的記憶體地址分佈

 

到此,基本上可以確定是記憶體分配器在搗鬼;搜尋了一下glibc 64M,發現glibc從2.11開始對每個執行緒引入記憶體池(64位元機器大小就是64M記憶體),原文如下:

 

glib記憶體池說明

 

按照文中所說去修改MALLOC_ARENA_MAX環境變數,發現沒什麼效果。檢視tcmalloc(gperftools使用的記憶體分配器)也使用了記憶體池方式。

 

爲了驗證是記憶體池搞的鬼,筆者就簡單寫個不帶記憶體池的記憶體分配器。使用命令gcc zjbmalloc.c -fPIC -shared -o zjbmalloc.so生成動態庫,然後使用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) {    return NULL;   }   *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) {  return NULL; } memset(ptr, 0, n * size); return ptr;}void *realloc(void *ptr, size_t size){ if (size == 0) {  free(ptr);  return NULL; } if (ptr == NULL) {  return malloc(size); } long *plen = (long*)ptr; plen--;                          // Reach top of memory long len = *plen; if (size <= len) {  return ptr; } void* rptr = malloc(size); if (rptr == NULL) {  free(ptr);  return NULL; } rptr = memcpy(rptr, ptr, len); free(ptr); return rptr;}void free (void* ptr ){   if (ptr == NULL) {   return;   }   long *plen = (long*)ptr;   plen--;                          // Reach top of memory   long len = *plen;               // Read length   munmap((void*)plen, len + sizeof(long));}

 

通過在自定義分配器當中埋點可以發現其實程式啓動之後應用實際申請的堆外記憶體始終在700M-800M之間,gperftools監控顯示記憶體使用量也是在700M-800M左右。但是從操作系統角度來看進程佔用的記憶體差別很大(這裏只是監控堆外記憶體)。

 

筆者做了一下測試,使用不同分配器進行不同程度的掃包,佔用的記憶體如下:

 

記憶體測試對比

 

爲什麼自定義的malloc申請800M,最終佔用的實體記憶體在1.7G呢?

 

因爲自定義記憶體分配器採用的是mmap分配記憶體,mmap分配記憶體按需向上取整到整數個頁,所以存在着巨大的空間浪費。通過監控發現最終申請的頁面數目在536k個左右,那實際上向系統申請的記憶體等於512k * 4k(pagesize) = 2G。爲什麼這個數據大於1.7G呢?

 

因爲操作系統採取的是延遲分配的方式,通過mmap向系統申請記憶體的時候,系統僅僅返回記憶體地址並沒有分配真實的實體記憶體。只有在真正使用的時候,系統產生一個缺頁中斷,然後再分配實際的物理Page。

 

# 總結

 

流程圖

 

整個記憶體分配的流程如上圖所示。MCC掃包的預設設定是掃描所有的JAR包。在掃描包的時候,Spring Boot不會主動去釋放堆外記憶體,導致在掃描階段,堆外記憶體佔用量一直持續飆升。

 

當發生GC的時候,Spring Boot依賴於finalize機制 機製去釋放了堆外記憶體;但是glibc爲了效能考慮,並沒有真正把記憶體歸返到操作系統,而是留下來放入記憶體池了,導致應用層以爲發生了「記憶體漏失」。

 

所以修改MCC的設定路徑爲特定的JAR包,問題解決。筆者在發表這篇文章時,發現Spring Boot的最新版本(2.0.5.RELEASE)已經做了修改,在ZipInflaterInputStream主動釋放了堆外記憶體不再依賴GC;所以Spring Boot升級到最新版本,這個問題也可以得到解決。