大量類加載器建立致使詭異FullGC

現象

最近接手了一個同事的項目,某一天接口的響應耗時忽然增長了不少,由幾十ms 增長到了幾十秒。java

首先查看機器上的日誌,有調用第三方接口超時,查詢數據庫超時。立馬查看第三方接口監控和數據庫監控,一切正常。可能因爲 GC 停頓形成統計的超時,這個時候咱們經過 jstat -gcutil pid 查看 gc 狀況。數據以下:git

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 使用率都沒有變化,說明內存一直回收不掉。web

JVM 內存大小相關配置以下:spring

-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 關鍵字,有以下報錯:express

java.lang.OutOfMemoryError: Metaspace
複製代碼

至此能夠確認是 Metaspace 出問題了,可是爲何 jstat 輸出的使用率只有 76.39% 呢?你們若是常用 jstat 看一下正常的程序就會不少正常狀況 Metaspace 都佔用 90% 以上。bootstrap

Metaspace

Metaspace 元數據空間,專門用來存儲類的元數據,它是 JDK8 中用來替代 Perm 的特殊數據結構。數據結構

Metaspace 空間被分配在本地內存中(非堆上),默認不限制內存使用,可使用 MaxMetaspaceSize 指定最大值。MetaspaceSize 指定最小值,默認 21 M。經過 mmap 來從操做系統申請內存,申請的內存會分紅一個一個 Metachunk,以 Metachunk 爲單位將內存分配給類加載器,每一個 Metachunk 對應惟一一個類加載器,一個類加載器能夠有多個 Metachunk 。ide

能夠用 java -XX:+PrintFlagsFinal -version 來查看 JVM 的默認參數值spring-boot

在 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;
...
}
複製代碼

下圖所示是每一個類加載器分配內存結構。

image.png

接下來咱們講下何時會觸發 FullGC,有個參數 MinMetaspaceFreeRatio(默認40) ,當知足以下條件就會進行 GC,若是當前須要申請的內存比剩餘能夠 commit 的空間還要大,若是尚未達到 MaxMetaspaceSize 的話,會觸發擴容。

剩餘能夠 commit 的空間大小 < (commited 大小 * MinMetaspaceFreeRatio)

上面說到 commited 的內存,這裏還有幾個概念 :used、capacity、reserved,以下圖所示

  • used: chunk 中已經使用的 block 內存,這些 block 中都加載了類的數據。

  • capacity:在使用的 chunk 內存。

  • commited:全部分配的 chunk 內存,這裏包含空閒能夠再次被利用的。

  • reserved:是可使用的內存大小。

image.png

以下所示,是打印出來的內存信息,最後一行是開啓壓縮指針(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%,有兩種可能:

  1. 此次分配的內存達到了 61M( 256M*24% ) 以上?

  2. 給類加載器分配的 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 就溢出了。

image.png

接下來選擇 Dominator Tree,而後輸入 Script1 正則過濾,右鍵選擇:Path To Gc Roots,這裏咱們只關心強引用,因此 execlude 其餘類型引用。

image.png

若是類加載器被回收,它所加載的類也會被回收,若是類有被引用,確定不能被回收,因此,咱們從 Script1 的對象開始。以下圖全部,Script1 類有被引用,最終到達 GC root (AppClassLoader),因此 Full GC 也無法回收掉。

image.png

看完三件事❤️

若是你以爲這篇內容對你還蠻有幫助,我想邀請你幫我三個小忙:

  1. 點贊,轉發,有大家的 『點贊和評論』,纔是我創造的動力。

  2. 關注公衆號 『 java爛豬皮 』,不按期分享原創知識。

  3. 同時能夠期待後續文章ing🚀

  4. 歡迎關注做者gitee,但願共同窗習

相關文章
相關標籤/搜索