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

2022-06-15 16:04:13

筆者在發表這篇文章時，發現Spring Boot的最新版本（2.0.5.RELEASE）已經做了修改，在ZipInflaterInputStream主動釋放了堆外內存不再依賴GC；所以Spring Boot升級到最新版本，這個問題也可以得到解決。

背景?

為了更好地實現對項目的管理，我們將組內一個項目遷移到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=detail??JVM參數重啟項目，使用命令??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：??https://github.com/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 endAddress??dump內存，其中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：??https://github.com/spring-projects/spring-boot/tree/master/spring-boot-project/spring-boot-tools/spring-boot-loader/src/main/java/org/springframework/boot/loader??那一塊的源碼。發現Spring Boot對Java JDK的InflaterInputStream進行了包裝并且使用了Inflater，而Inflater本身用于解壓JAR包的需要用到堆外內存。而包裝之后的類ZipInflaterInputStream沒有釋放Inflater持有的堆外內存。于是筆者以為找到了原因，立馬向Spring Boot社區反饋了這個bug：??https://github.com/spring-projects/spring-boot/issues/13935??。但是反饋之后，筆者就發現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升級到最新版本，這個問題也可以得到解決。

責任編輯：龐桂玉來源： Hollis

Java 編程語言