
現象
最近接手了一個同事的專案,某一天介面的回應耗時突然增加了很多,由幾十ms 增加到了幾十秒,
首先查看機器上的日志,有呼叫第三方介面超時,查詢資料庫超時,立馬查看第三方介面監控和資料庫監控,一切正常,可能由于 GC 停頓造成統計的超時,這個時候我們通過 jstat -gcutil pid 查看 gc 情況,資料如下:
S0 S1 E O M CCS YGC YGCT FGC FGCT GCT
0.00 0.00 3.88 12.86 76.39 45.62 211 8.574 892 626.192 634.767
0.00 0.00 4.10 12.86 76.39 45.62 211 8.574 893 626.192 634.767
0.00 0.00 0.00 12.88 76.39 45.62 211 8.574 894 626.915 635.489
0.00 0.00 0.11 12.88 76.39 45.62 211 8.574 896 627.678 636.253
0.00 0.00 0.00 12.87 76.39 45.62 211 8.574 897 628.926 637.500
0.00 0.00 0.00 12.87 76.39 45.62 211 8.574 899 630.381 638.956
0.00 0.00 1.92 12.87 76.39 45.62 211 8.574 901 631.155 639.729
0.00 0.00 0.00 12.87 76.39 45.62 211 8.574 902 632.379 640.954
0.00 0.00 2.14 12.87 76.39 45.62 211 8.574 903 633.094 641.668
0.00 0.00 0.00 12.88 76.39 45.62 211 8.574 904 633.859 642.433
復制代碼
這里我們可以看到年輕代(E) 使用率很小,老年代(O)使用率 12% 也不多,M(Metaspace) 使用率 76.39% 也沒占滿,Yong GC 沒有變化,Full GC 一直在進行,每次耗時800多ms,結合前面 E、O 和 M 使用率都沒有變化,說明記憶體一直回收不掉,
JVM 記憶體大小相關配置如下:
-Xms3g -Xmx3g -Xmn1g -XX:MetaspaceSize=256m -XX:MaxMetaspaceSize=256m
復制代碼
接下來我們看下 GC 日志:
2020-08-13T23:11:00.352+0800: 214929.371: [GC (CMS Initial Mark) 276144K(3040896K), 0.0405942 secs]
2020-08-13T23:11:00.886+0800: 214929.905: [Full GC (Metadata GC Threshold) 290482K->275966K(3040896K), 0.7939954 secs]
2020-08-13T23:11:01.693+0800: 214930.712: [Full GC (Last ditch collection) 275966K->275964K(3040896K), 0.8086755 secs]
2020-08-13T23:11:02.520+0800: 214931.539: [Full GC (Metadata GC Threshold) 295199K->273816K(3040896K), 0.8332017 secs]
2020-08-13T23:11:03.366+0800: 214932.385: [Full GC (Last ditch collection) 273816K->273799K(3040896K), 0.7748226 secs]
復制代碼
GC 日志中有 Metadata GC Threshold ,結合前面 Metaspace 使用率最高我們猜測可能是 Metaspace 溢位了,然后我們在日志中 grep OutOfMemory 關鍵字,有如下報錯:
java.lang.OutOfMemoryError: Metaspace
復制代碼
至此可以確認是 Metaspace 出問題了,但是為什么 jstat 輸出的使用率只有 76.39% 呢?大家如果經常使用 jstat 看一下正常的程式就會很多正常情況 Metaspace 都占用 90% 以上,
Metaspace
Metaspace 元資料空間,專門用來存盤類的元資料,它是 JDK8 中用來替代 Perm 的特殊資料結構,
Metaspace 空間被分配在本地記憶體中(非堆上),默認不限制記憶體使用,可以使用 MaxMetaspaceSize 指定最大值,MetaspaceSize 指定最小值,默認 21 M,通過 mmap 來從作業系統申請記憶體,申請的記憶體會分成一個一個 Metachunk,以 Metachunk 為單位將記憶體分配給類加載器,每個 Metachunk 對應唯一一個類加載器,一個類加載器可以有多個 Metachunk ,
可以用 java -XX:+PrintFlagsFinal -version 來查看 JVM 的默認引數值
在 Java 虛擬機中,每個類加載器都有一個 ClassLoaderData 的資料結構,ClassloaderData 內部有管理記憶體的 Metaspace,Metaspace 在 initialize 的時候會呼叫 get_initialization_chunk 分配第一塊 Metachunk,類加載器在類的時候是以 Metablock 為單位來使用 Metachunk,
//classLoaderData.hpp
class ClassLoaderData : public CHeapObj<mtClass> {
...
Metaspace * _metaspace; // Meta-space where meta-data defined by the
// classes in the class loader are allocated.
Mutex* _metaspace_lock; // Locks the metaspace for allocations and setup.
...
}
// metaspace.hpp
class Metaspace : public CHeapObj<mtClass> {
...
private:
void initialize(Mutex* lock, MetaspaceType type);
Metachunk* get_initialization_chunk(MetadataType mdtype,
size_t chunk_word_size,
size_t chunk_bunch);
...
}
// metachunk.hpp
class Metachunk : public Metabase<Metachunk>
class Metablock : public Metabase<Metablock>
// Metablock 和 Metachunk 的父類
template <class T>
class Metabase VALUE_OBJ_CLASS_SPEC {
size_t _word_size;
T* _next;
T* _prev;
...
}
復制代碼
下圖所示是每個類加載器分配記憶體結構,
接下來我們講下什么時候會觸發 FullGC,有個引數 MinMetaspaceFreeRatio(默認40) ,當滿足如下條件就會進行 GC,如果當前需要申請的記憶體比剩余可以 commit 的空間還要大,如果還沒有達到 MaxMetaspaceSize 的話,會觸發擴容,
剩余可以 commit 的空間大小 < (commited 大小 * MinMetaspaceFreeRatio)
上面說到 commited 的記憶體,這里還有幾個概念 :used、capacity、reserved,如下圖所示
-
used: chunk 中已經使用的 block 記憶體,這些 block 中都加載了類的資料,
-
capacity:在使用的 chunk 記憶體,
-
commited:所有分配的 chunk 記憶體,這里包含空閑可以再次被利用的,
-
reserved:是可以使用的內存大小,
如下所示,是列印出來的記憶體資訊,最后一行是開啟壓縮指標(64位壓縮為32位)后,Metaspace 中專門存放 kclass 的資訊,
Heap
par new generation total 30720K, used 1519K [0x00000007f8600000, 0x00000007fa750000, 0x00000007fa750000)
eden space 27328K, 5% used [0x00000007f8600000, 0x00000007f877bcc8, 0x00000007fa0b0000)
from space 3392K, 0% used [0x00000007fa400000, 0x00000007fa400000, 0x00000007fa750000)
to space 3392K, 0% used [0x00000007fa0b0000, 0x00000007fa0b0000, 0x00000007fa400000)
concurrent mark-sweep generation total 68288K, used 21614K [0x00000007fa750000, 0x00000007fea00000, 0x00000007fea00000)
Metaspace used 23505K, capacity 30704K, committed 30720K, reserved 1073152K
class space used 3341K, capacity 7550K, committed 7552K, reserved 1048576K
復制代碼
基礎知識講完了,現在我們回到開頭,我們通過 jstat 列印出的 M 是怎么計算的呢?這里使用率并不是我們理解的整個 Metaspace 記憶體的使用率,
M = used / commited
復制代碼
所以 Metaspace 記憶體溢位了,使用率也才 76%,有兩種可能:
-
這次分配的記憶體達到了 61M( 256M*24% ) 以上?
-
給類加載器分配的 chunk 使用率很低?
第一種顯然不太可能,一個類不可能需要這么大的記憶體,第二種有種情況,當創建很多類加載器,而每個類加載器又加載了很少的類,
上面我們說了剩余空閑記憶體小于metaspaceGC的閾值就會執行FullGC,但是我們開頭說有些正常場景我們通過 jstat 列印的使用率都達到了 90% 多都沒有觸發 FullGC,這是為什么呢?歡迎留言分享你的答案
排查程式
首先,我們看下 Metaspace 加載的到底是哪些類
jcmd pid GC.class_stats |awk '{print $13}'| sort | uniq -c |sort -r| head
復制代碼
通過 jcmd 查看加載的類,然后統計數量,我們看到,Script1 被加載了兩萬多次,按 JVM 類加載的雙親委派方式,一個類最多被加載一次,這里出現了多次,可能是不同的類加載器加載的,
27348 Script1
3
2 ClassName
1 sun.util.spi.CalendarProvider
1 sun.util.resources.en.TimeZoneNames_en
1 sun.util.resources.en.CurrencyNames_en_US
1 sun.util.resources.en.CalendarData_en
1 sun.util.resources.TimeZoneNamesBundle
1 sun.util.resources.TimeZoneNames
1 sun.util.resources.ParallelListResourceBundle$KeySet
復制代碼
通過 jcmd 查看,需要在啟動是加上引數:-XX:+UnlockDiagnosticVMOptions
然后我們再看下 JVM 類加載器的資料
jmap -clstats pid
這里 classes 是加載類的數量,從輸出中可以看到有大量 GroovyClassLoader 類加載器,
class_loader classes bytes parent_loader alive? type
<bootstrap> 2850 4913169 null live <internal>
0x000000077bc27bc0 1 1394 0x000000077bc64418 dead groovy/lang/GroovyClassLoader$InnerLoader@0x00000007f0dcf828
0x000000077d9e7d98 0 0 0x0000000770800000 dead groovy/lang/GroovyClassLoader@0x00000007f0af9890
0x00000007805e8050 0 0 0x0000000770800000 dead groovy/lang/GroovyClassLoader@0x00000007f0af9890
0x000000077df07de0 0 0 0x0000000770800000 dead groovy/lang/GroovyClassLoader@0x00000007f0af9890
0x0000000780028010 1 1394 0x000000078005a6c8 dead groovy/lang/GroovyClassLoader$InnerLoader@0x00000007f0dcf828
0x0000000776467650 1 1394 0x000000077646b190 dead groovy/lang/GroovyClassLoader$InnerLoader@0x00000007f0dcf828
0x000000077a167a00 1 1394 0x000000077a16b380 dead groovy/lang/GroovyClassLoader$InnerLoader@0x00000007f0dcf828
復制代碼
通過統計,每個 GroovyClassLoader$InnerLoader 都只加載一個類,然后他的數量一共有 27348,跟上面的 Script1 類數量剛好對的上,說明就是這個類加載器加載的,
接下來怎么定位哪里生產的類加載器加載的類呢?
首先看 groovy 是哪里引入的,然后本地除錯,加上JVM 引數:-XX:+UnlockDiagnosticVMOptions,加載類的時候控制臺就會列印,就可以一步一步定位到哪里加載的,
我們專案中用 sharding 做的分表,sharding 引入的 groovy 版本如下
<dependency>
<groupId>io.shardingsphere</groupId>
<artifactId>sharding-jdbc-spring-boot-starter</artifactId>
<version>3.0.0.M1</version>
</dependency>
<dependency>
<groupId>org.codehaus.groovy</groupId>
<artifactId>groovy</artifactId>
<classifier>indy</classifier>
<version>2.4.5</version>
</dependency>
復制代碼
最終定位到出現問題的代碼如下,當你配置分表的運算式后,每次執行查詢操作,都會創建一個 GroovyShell 來執行配置的運算式,在 GroovyShell 中,每次都會生成一個類加載器,來加載類 Script1,加載完后又無法被 GC 掉,導致記憶體泄露,
public InlineShardingStrategy(final InlineShardingStrategyConfiguration inlineShardingStrategyConfig) {
Preconditions.checkNotNull(inlineShardingStrategyConfig.getShardingColumn(), "Sharding column cannot be null.");
Preconditions.checkNotNull(inlineShardingStrategyConfig.getAlgorithmExpression(), "Sharding algorithm expression cannot be null.");
shardingColumn = inlineShardingStrategyConfig.getShardingColumn();
String algorithmExpression = InlineExpressionParser.handlePlaceHolder(inlineShardingStrategyConfig.getAlgorithmExpression().trim());
closure = (Closure) new GroovyShell().evaluate(Joiner.on("").join("{it -> \"", algorithmExpression, "\"}"));
}
復制代碼
這里升級 sharding 新版本即可,新版本中 GroovyShell 是static 的,
public final class InlineExpressionParser {
...
private static final GroovyShell SHELL = new GroovyShell();
...
}
復制代碼
這里還有個疑問,類加載器加載用完了并且狀態是 dead 為什么不回收掉呢?
本地復現
復現的代碼很簡單,引入上述 groovy 版本,在運行時加上 JVM 引數
// -Xmx100M -Xms100M -verbose:class -XX:+PrintGCDetails -XX:MaxMetaspaceSize=30M -XX:MetaspaceSize=30M -XX:+UseConcMarkSweepGC -XX:+CMSClassUnloadingEnabled -XX:+UnlockDiagnosticVMOptions -XX:+HeapDumpOnOutOfMemoryError
public static void main(String[] args) {
for (int i = 0; i < 4000; i++) {
new GroovyShell().parse("");
}
}
復制代碼
接下來主要講下,怎么用 mat 來排查這個類加載為什么沒有被回收,用 mat 加載上示例程式 dump 出來的堆,選擇 Histogram ,然后在正則中輸入 GroovyClassLoader ,Objects 是表示創建物件數量,這里有 3255 個,說明上面的 for 回圈執行了 3255 次之后 Metaspace 就溢位了,
接下來選擇 Dominator Tree,然后輸入 Script1 正則過濾,右鍵選擇:Path To Gc Roots,這里我們只關心強參考,所以 execlude 其他型別參考,
如果類加載器被回收,它所加載的類也會被回收,如果類有被參考,肯定不能被回收,所以,我們從 Script1 的物件開始,如下圖所有,Script1 類有被參考,最終到達 GC root (AppClassLoader),所以 Full GC 也沒法回收掉,
看完三件事??
如果你覺得這篇內容對你還蠻有幫助,我想邀請你幫我三個小忙:
-
點贊,轉發,有你們的 『點贊和評論』,才是我創造的動力,
-
關注公眾號 『 java爛豬皮 』,不定期分享原創知識,
-
同時可以期待后續文章ing??
-
歡迎關注作者gitee,希望共同學習

轉載請註明出處,本文鏈接:https://www.uj5u.com/houduan/182750.html
標籤:其他
