使用堆外內存優化JVM GC問題小記

最近項目中的一個關鍵服務，因爲業務的特殊性引起了一系列GC問題。通過不短期的追蹤和嘗試，最終完美解決。如下記錄一下過程及收穫。

背景簡介

該服務是爲了提供商品排序功能，業務要求以下：

1. 商品是分國家的，每一個國家的商品不一樣.
2. 每一個商品有主鍵字段 goodsId，且有一個一維特徵矩陣，保存爲一個長度128的一維float數組。
3. 排序時，提供查詢條件的特徵矩陣A，和一批備選商品的goodsId（最多5000個），而後拿輸入的矩陣A和全部備選商品的特徵矩陣相乘，獲得每一個商品的匹配度分值，返回。
4. 商品集合須要定時更新，且每一個國家的商品集合單獨更新。

這裏能夠看到此服務的特殊性了吧：每一個請求最大須要查到 5000 個float[128]數組！這個數據怎麼存還真是個問題。

咱們採用的方案是在內存中創建一個大map，結構是一個 Map<String, Map<String, float[128]>。外層保存國家到商品集合的映射，內部的Map則是goodsId到其特徵矩陣的映射。咱們計算了一下數據量，粗略的估計是單個內層Map所佔的內存約 350M，整個外部大Map的內存要佔到約 2GB.

爲確保理解，map的簡單圖示以下：

nation1:
  goodsId1: 特徵矩陣1
  goodsId2: 特徵矩陣2
  ...
nation2:
  goodsId1: 特徵矩陣1
  goodsId2: 特徵矩陣2
  ...
複製代碼

看官到這裏必定會問，爲何咱們不用Redis等集中式緩存，而是直接把數據放到內存中？

嗯，寫這篇文章以前，我作了一輪壓測，發現Redis的性能真的沒那麼強。好比官方一直宣稱的單實例OPS 100000+，確實能達到，但這個數字意味着什麼呢？意味着一個get請求須要0.01ms，那一個1000大小的MGET就須要10ms！這仍是沒有網絡延時的狀況下。我在本地實測（server和client分別在本地物理機和虛擬機）的MGET 5000 個key，延時在40 - 60ms之間 （本場景下value還不是太大，1kB左右，尚未形成性能的顯著降低）。這裏貼一篇文章：Redis 的性能幻想與殘酷現實

還有個思路是使用Redis加上本地緩存。可是本場景中上百萬條數據，又沒有熱點，本地緩存也很難有效。

言歸正傳。有了這個map，服務的主接口就好辦了：

• 輸入：接受一個nation參數，一組goodsId，和一個查詢條件的特徵矩陣A，也是float[128]
• 根據nation和goodsId查到商品特徵矩陣，而後和A相乘，獲得該商品的匹配度分值。

初版效果： 正常QPS下，平均延時10ms之內。

背景已交代完。下面噩夢要開始了~

出現GC問題

上線後一切都很完美。然而運行了一段時間後，上游服務開始不按期地出現超時甚至熔斷，每次持續時間很短。一番調查後咱們注意到問題發生時這個服務的TP99指標會有尖峯，以下圖所示：

響應時間有時會飆升到接近1秒！在日誌沒什麼異常的狀況下只能懷疑是GC在做祟了，因而找來GC日誌一探究竟。

觀察GC日誌

如下爲JVM 參數取 -Xmx4g -Xmx4g 時的一段gc日誌, Java版本：OpenJDK 1.8.0_212

{Heap before GC invocations=393 (full 5):
 PSYoungGen      total 1191936K, used 191168K [0x000000076ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 986112K, 0% used [0x000000076ab00000,0x000000076ab00000,0x00000007a6e00000)
  from space 205824K, 92% used [0x00000007b3700000,0x00000007bf1b0000,0x00000007c0000000)
  to   space 205824K, 0% used [0x00000007a6e00000,0x00000007a6e00000,0x00000007b3700000)
 ParOldGen       total 2796544K, used 2791929K [0x00000006c0000000, 0x000000076ab00000, 0x000000076ab00000)
  object space 2796544K, 99% used [0x00000006c0000000,0x000000076a67e750,0x000000076ab00000)
 Metaspace       used 70873K, capacity 73514K, committed 73600K, reserved 1114112K
  class space    used 8549K, capacity 9083K, committed 9088K, reserved 1048576K
4542.168: [Full GC (Ergonomics) [PSYoungGen: 191168K->167781K(1191936K)] [ParOldGen: 2791929K->2796093K(2796544K)] 2983097K->2963875K(3988480K), [Metaspace: 70873K->70638K(1114112K)], 2.9853595 secs] [Times: user=11.28 sys=0.00, real=2.99 secs]
Heap after GC invocations=393 (full 5):
 PSYoungGen      total 1191936K, used 167781K [0x000000076ab00000, 0x00000007c0000000, 0x00000007c0000000)
  eden space 986112K, 0% used [0x000000076ab00000,0x000000076ab00000,0x00000007a6e00000)
  from space 205824K, 81% used [0x00000007b3700000,0x00000007bdad95e8,0x00000007c0000000)
  to   space 205824K, 0% used [0x00000007a6e00000,0x00000007a6e00000,0x00000007b3700000)
 ParOldGen       total 2796544K, used 2796093K [0x00000006c0000000, 0x000000076ab00000, 0x000000076ab00000)
  object space 2796544K, 99% used [0x00000006c0000000,0x000000076aa8f6d8,0x000000076ab00000)
 Metaspace       used 70638K, capacity 73140K, committed 73600K, reserved 1114112K
  class space    used 8514K, capacity 9016K, committed 9088K, reserved 1048576K
}
複製代碼

從日誌中能夠獲得的一些信息：

• JDK 8 若不指定gc方式，默認採用的是Parallel Scavenge + Parallel Old的組合。居然不是CMS。
• 本次Full GC的緣由是老年代滿了，STW停頓了3秒鐘……

調整gc策略

既然出現了GC問題，那必需要調整一波了。下面是我作過的一些嘗試：

1. 垃圾收集器換成CMS
2. 既然老年代空間不夠，那就多給它空間唄！將整個堆調大，把老年代內存調大。

如下是實驗結果和結論：

1. 換成CMS也沒什麼卵用，反而更差了。猜想緣由是CMS比較依賴CPU內核數量，而咱們在docker環境中，將核數限制的很低，致使CMS的並行處理提升不明顯。甚至有時候因爲老年代內存吃緊，還會出現Concurrent Mode Failure，進入線性Full GC兜底，消耗時間更長。
2. 堆內存增大後，發生普通GC和Full GC的次數減小了，但單次的GC卻更慢了。沒法解決問題。

再附上一塊兒CMS車禍現場：

[GC (CMS Initial Mark) [1 CMS-initial-mark: 4793583K(5472256K)] 4886953K(6209536K), 0.0075637 secs] [Times: user=0.01 sys=0.00, real=0.00 secs]
[CMS-concurrent-mark-start]
03:05:50.594 INFO [XNIO-2 task-8] c.shein.srchvecsort.filter.LogFilter ---- GET /prometheus?null took 3ms and returned 200
{Heap before GC invocations=240 (full 7):
par new generation total 737280K, used 737280K [0x0000000640000000, 0x0000000672000000, 0x0000000672000000)
eden space 655360K, 100% used [0x0000000640000000, 0x0000000668000000, 0x0000000668000000)
from space 81920K, 100% used [0x0000000668000000, 0x000000066d000000, 0x000000066d000000)
to space 81920K, 0% used [0x000000066d000000, 0x000000066d000000, 0x0000000672000000)
concurrent mark-sweep generation total 5472256K, used 4793583K [0x0000000672000000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace used 66901K, capacity 69393K, committed 69556K, reserved 1110016K
class space used 8346K, capacity 8805K, committed 8884K, reserved 1048576K
[GC (Allocation Failure) [ParNew: 737280K->737280K(737280K), 0.0000229 secs][CMS[CMS-concurrent-mark: 1.044/1.045 secs] [Times: user=1.36 sys=0.05, real=1.05 secs]
(concurrent mode failure): 4793583K->3662044K(5472256K), 3.8206326 secs] 5530863K->3662044K(6209536K), [Metaspace: 66901K->66901K(1110016K)], 3.8207144 secs] [Times: user=3.82 sys=0.00, real=3.82 secs]
Heap after GC invocations=241 (full 8):
par new generation total 737280K, used 0K [0x0000000640000000, 0x0000000672000000, 0x0000000672000000)
eden space 655360K, 0% used [0x0000000640000000, 0x0000000640000000, 0x0000000668000000)
from space 81920K, 0% used [0x0000000668000000, 0x0000000668000000, 0x000000066d000000)
to space 81920K, 0% used [0x000000066d000000, 0x000000066d000000, 0x0000000672000000)
concurrent mark-sweep generation total 5472256K, used 3662044K [0x0000000672000000, 0x00000007c0000000, 0x00000007c0000000)
Metaspace used 66901K, capacity 69393K, committed 69556K, reserved 1110016K
class space used 8346K, capacity 8805K, committed 8884K, reserved 1048576K
}
複製代碼

這裏順便提一下過程當中遇到的一些坑，主要是docker/k8s環境的限制，有些還沒有解決。後面有機會再具體講講吧。

• jstat 因爲Java 進程爲0，沒法指定進程。
• OOM crash dump彷佛很差收集。
• VisualVM很差鏈接。

如何避免GC問題

思考：問題在哪裏？

這次的GC問題其實緣由很明顯：因爲業務的特殊性，咱們在內存中持有了幾個很大的map對象，毫無疑問它們會進入老年代。然而這些對象又並不是長生不死！每隔一段時間，因爲數據須要更新，又會有一些新的map對象被建立出來，舊的map對象失去引用，須要被GC回收掉。因爲老年代內存大量增加，不得不進行Major GC，且一次性要釋放掉大量內存，這個時間很難降到特別低。

既然問題出在大map對象，那解決思路天然是：避免使用大map對象，或者更準確地說——不要把這麼大的數據放到堆內存中。

數據不放到堆內存中，那要麼放堆外（進程內直接內存），要麼放進程外。

進程外方案顯然就是各類數據庫了；進程內的方案呢？則有進程內數據庫（如Berkeley DB）和堆外緩存兩種。而數據庫對我來講又過重了，其實我想要的只是一個map的功能。所以便決定進一步研究堆外緩存。

另：關於Java緩存的方案這裏再也不贅述，引用《跟開濤學架構》中的緩存一節：

Java緩存類型

• 堆緩存：使用java堆內存來存儲對象，好處是不須要序列化/反序列化，速度快，缺點是受GC影響。可使用Guava Cache、Ehcache 3.x、MapDB實現。
• 堆外緩存：緩存數據存儲在堆外，突破了JVM的枷鎖，讀取數據時須要序列化/反序列化，比對堆內緩存慢不少。可使用Ehcache 3.x、MapDB實現。
• 磁盤緩存：在JVM重啓時數據還在，而堆緩存/堆外緩存數據會丟失，須要從新加載。可使用Ehcache 3.x、MapDB實現。
• 分佈式緩存：沒啥好說的了，Redis…

堆外緩存

直接貼上兩篇文章吧：

• 你所不知道的堆外緩存
• JAVA堆外內存的簡介和使用

簡單總結一下：

1. 堆內緩存在數據量巨大時會形成GC性能問題。堆外緩存可解。
2. 堆外緩存的實現原理就是Unsafe類直接操做進程內存，那麼就須要本身控制內存回收，以及和Java對象之間的序列化/反序列化，由於到了堆外只認識字節，不認識Java對象。
3. 這麼有用而又不易實現的功能固然最好求諸框架。支持的框架有mapdb，ohc，ehcache3等。ehcache3收費，ohc則最快。

綜上，決定採用ohc。官網地址在此。

代碼設計

思路：

1. 靈活性考慮，採用策略模式。參考上文你所不知道的堆外緩存文末。
2. 既然仍是看成map用，那就讓封裝的工具類繼承Map接口。ohc的一個OHCache對象表明一塊堆外緩存，我將它封裝爲一個map，存放一個國家的數據。天然，程序中會有多個OHCache。
3. 此外，注意到OHCache類自己是繼承Closeable接口的，也就是調用其Close()方法能夠釋放其資源，即回收內存。所以封裝的工具類也須要繼承Closeable，並在更新國家數據的時候，調用被替換的原map對象的Close()方法，釋放內存。經測試可行。
4. 既然是在Spring Boot中使用，又是個緩存框架，天然但願將它適配到Spring的緩存體系中來。目前還沒有實施。

效果

下圖爲改進以前，使用堆內map時，在刷新數據時更新map致使的GC狀況：

能夠看到Young GC的時間已經很長，同時還有Major GC。實際的GC時間比圖表上(actuator指標)的要高出不少，Major GC 1秒以上。

使用堆外內存改進後，我將JVM堆內存改小，爲堆外留夠內存，效果：

• 效果竟然是同樣啊。。。仍然會有Major GC問題！圖我就不貼了。
• 平均延時由原來的10ms變成了40ms……

這不科學！必定是哪裏不對~

更進一步

這裏就不(xie)賣(bu)關(xia)子(qu)了，直接說問題緣由吧。

坑一：讀取大文件

此次升級還作了一項改動：更新map所用的數據源由數據庫改爲了s3上的文件，而這些文件會有大幾百MB。而咱們使用了CommonsIO的readLines()方法。嗯，它會把整個文件內容加載到堆中，不GC纔怪！

改用行枚舉器後，GC問題終於消失了。再也不有Major GC。

下圖中正在發生map替換：

Major GC次數是零哦！

坑二：序列化

ohc須要你提供key和value的序列化方式，傳入一個ByteBuffer。因爲年少無知，我再一次使用了Apache的序列化工具，將對象按JDK序列化方式轉變成堆內字節數組後，再拷貝到ByteBuffer中。

解決方案是直接操做ByteBuffer，自定義序列化方式。修改以後，延時問題也解決了。

最終效果

TP99穩定在了13ms之內哦！拜拜甜甜圈，哦不，拜拜了毛刺~

再附上替換map時進程總內存的變化：

感謝觀看！