總第323篇
2019年 第001篇
在項目遷移到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
-XX:MaxMetaspaceSize=256M
-XX:+AlwaysPreTouch
-XX:ReservedCodeCacheSize=128m
-XX:InitialCodeCacheSize=128m,
-Xss512k -Xmx4g -Xms4g,-XX:+UseG1GC
-XX:G1HeapRegionSize=4M 實際使用的實體記憶體如下圖所示：
排查過程
1. 使用Java層面的工具定位記憶體區域（堆内記憶體、Code區域或者使用unsafe.allocateMemory和DirectByteBuffer申請的堆外記憶體）
筆者在項目中添加-XX:NativeMemoryTracking=detailJVM參數重新開機項目，使用指令jcmd pid VM.native_memory detail檢視到的記憶體分布如下：
發現指令顯示的committed的記憶體小于實體記憶體，因為jcmd指令顯示的記憶體包含堆内記憶體、Code區域、通過unsafe.allocateMemory和DirectByteBuffer申請的記憶體，但是不包含其他Native Code（C代碼）申請的堆外記憶體。是以猜測是使用Native Code申請記憶體所導緻的問題。
為了防止誤判，筆者使用了pmap檢視記憶體分布，發現大量64M位址；而這些位址空間不在jcmd指令所給出的位址空間裡面，基本上可斷定就是這些64M的記憶體所導緻。
2. 使用系統層面的工具定位堆外記憶體
因為筆者已經基本上确定是Native Code所引起，而Java層面的工具不便于排查此類問題，隻能使用系統層面的工具去定位問題。
首先，使用了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監控如下圖所示：
接着，使用GDB去dump可疑記憶體
因為使用strace沒有追蹤到可疑記憶體申請；于是想着看看記憶體中的情況。就是直接使用指令gdp -pid pid進入GDB之後，然後使用指令dump memory mem.bin startAddress endAddressdump記憶體，其中startAddress和endAddress可以從/proc/pid/smaps中查找。然後使用strings mem.bin檢視dump的内容，如下：
從内容上來看，像是解壓後的JAR包資訊。讀取JAR包資訊應該是在項目啟動的時候，那麼在項目啟動之後使用strace作用就不是很大了。是以應該在項目啟動的時候使用strace，而不是啟動完成之後。
再次，項目啟動時使用strace去追蹤系統調用
項目啟動使用strace追蹤系統調用，發現确實申請了很多64M的記憶體空間，截圖如下：
使用該mmap申請的位址空間在pmap對應如下：
最後，使用jstack去檢視對應的線程
因為strace指令中已經顯示申請記憶體的線程ID。直接使用指令jstack pid去檢視線程棧，找到對應的線程棧（注意10進制和16進制轉換）如下：
這裡基本上就可以看出問題來了：MCC（美團統一配置中心）使用了Reflections進行掃包，底層使用了Spring Boot去加載JAR。因為解壓JAR使用Inflater類，需要用到堆外記憶體，然後使用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。記憶體位址分布如下：
到此，基本上可以确定是記憶體配置設定器在搗鬼；搜尋了一下glibc 64M，發現glibc從2.11開始對每個線程引入記憶體池（64位機器大小就是64M記憶體），原文如下：
按照文中所說去修改MALLOC_ARENA_MAX環境變量，發現沒什麼效果。檢視tcmalloc（gperftools使用的記憶體配置設定器）也使用了記憶體池方式。
為了驗證是記憶體池搞的鬼，筆者就簡單寫個不帶記憶體池的記憶體配置設定器。使用指令gcc zjbmalloc.c -fPIC -shared -o zjbmalloc.so生成動态庫，然後使用export LD_PRELOAD=zjbmalloc.so替換掉glibc的記憶體配置設定器。其中代碼Demo如下：
通過在自定義配置設定器當中埋點可以發現其實程式啟動之後應用實際申請的堆外記憶體始終在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更新到最新版本，這個問題也可以得到解決。
參考資料
- GNU C Library (glibc)
- Native Memory Tracking
- Spring Boot
- gperftools
- Btrace
作者簡介
紀兵，2015年加入美團，目前主要從事酒店C端相關的工作。
歡迎加入美團Java技術交流群，跟項目維護者零距離交流。進群方式：請加美美同學微信（微信号：MTDPtech02），回複：Spring Boot，美美會自動拉你進群。
---------- END ----------
也許你還想看
Spring MVC注解故障追蹤記
這個Spring高危漏洞，你修補了嗎？