大量类加载器建立致使诡异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,但愿共同窗习

相关文章
相关标签/搜索