大量类加载器创建导致诡异FullGC

大量类加载器创建导致诡异FullGC用 mat 加载上示例程序 dump 出来的堆 选择 Histogram 然后在正则中输入 GroovyClassL Objects 是表示创建对象数量 这里有 3255 个 说明上面的 for 循环执行了 3255 次之后

欢迎大家来到IT世界,在知识的湖畔探索吧!

由 GC 问题带你全面了解 JDK8 Metaspace

01

现象

最近接手了一个同事的项目,某一天接口的响应耗时突然增加了很多,由几十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 

欢迎大家来到IT世界,在知识的湖畔探索吧!

这里我们可以看到年轻代(E) 使用率很小,老年代(O)使用率 12% 也不多,M(Metaspace) 使用率 76.39% 也没占满,Yong GC 没有变化,Full GC 一直在进行,每次耗时800多ms。结合前面 E、O 和 M 使用率都没有变化,说明内存一直回收不掉

JVM 内存大小相关配置如下:

欢迎大家来到IT世界,在知识的湖畔探索吧! -Xms3g -Xmx3g -Xmn1g -XX:MetaspaceSize=256m -XX:MaxMetaspaceSize=256m 

接下来我们看下 GC 日志:

2020-08-13T23:11:00.352+0800: .371: [GC (CMS Initial Mark) K(K), 0.0 secs] 2020-08-13T23:11:00.886+0800: .905: [Full GC (Metadata GC Threshold) K->K(K), 0. secs] 2020-08-13T23:11:01.693+0800: .712: [Full GC (Last ditch collection) K->K(K), 0. secs] 2020-08-13T23:11:02.520+0800: .539: [Full GC (Metadata GC Threshold) K->K(K), 0. secs] 2020-08-13T23:11:03.366+0800: .385: [Full GC (Last ditch collection) K->K(K), 0. secs] 

GC 日志中有 Metadata GC Threshold ,结合前面 Metaspace 使用率最高我们猜测可能是 Metaspace 溢出了,然后我们在日志中 grep OutOfMemory 关键字,有如下报错:

欢迎大家来到IT世界,在知识的湖畔探索吧!java.lang.OutOfMemoryError: Metaspace 

至此可以确认是 Metaspace 出问题了,但是为什么 jstat 输出的使用率只有 76.39% 呢?大家如果经常使用 jstat 看一下正常的程序就会很多正常情况 Metaspace 都占用 90% 以上。

02

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 { ... 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 { ... 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 class Metablock : public Metabase // Metablock 和 Metachunk 的父类 template class Metabase VALUE_OBJ_CLASS_SPEC { size_t _word_size; T* _next; T* _prev; ... } 

下图所示是每个类加载器分配内存结构(这里 virtual space node 就不展开讲了,感兴趣的同学可以参考第2篇参考文档)

大量类加载器创建导致诡异FullGC

接下来我们讲下什么时候会触发 FullGC,有个参数 MinMetaspaceFreeRatio(默认40) ,当满足如下条件就会进行 GC,如果当前需要申请的内存比剩余可以 commit 的空间还要大,如果还没有达到 MaxMetaspaceSize 的话,会触发扩容。

剩余可以 commit 的空间大小 < (commited 大小 * MinMetaspaceFreeRatio) 

上面说到 commited 的内存,这里还有几个概念 :usedcapacityreserved,如下图所示

  • used: chunk 中已经使用的 block 内存,这些 block 中都加载了类的数据。
  • capacity:在使用的 chunk 内存。
  • commited:所有分配的 chunk 内存,这里包含空闲可以再次被利用的。
  • reserved:是可以使用的内存大小。
大量类加载器创建导致诡异FullGC

如下所示,是打印出来的内存信息,最后一行是开启压缩指针(64位压缩为32位)后,Metaspace 中专门存放 kclass 的信息。(这里的内容不延伸了,具体可以参考第 3、7 篇参考文章)

Heap par new generation total 30720K, used 1519K [0x00000007f, 0x00000007fa, 0x00000007fa) eden space 27328K, 5% used [0x00000007f, 0x00000007f877bcc8, 0x00000007fa0b0000) from space 3392K, 0% used [0x00000007fa, 0x00000007fa, 0x00000007fa) to space 3392K, 0% used [0x00000007fa0b0000, 0x00000007fa0b0000, 0x00000007fa) concurrent mark-sweep generation total 68288K, used 21614K [0x00000007fa, 0x00000007fea00000, 0x00000007fea00000) Metaspace used 23505K, capacity 30704K, committed 30720K, reserved K class space used 3341K, capacity 7550K, committed 7552K, reserved K 

基础知识讲完了,现在我们回到开头,我们通过 jstat 打印出的 M 是怎么计算的呢?这里使用率并不是我们理解的整个 Metaspace 内存的使用率。

M = used / commited 

所以 Metaspace 内存溢出了,使用率也才 76%,有两种可能:

  1. 这次分配的内存达到了 61M( 256M*24% ) 以上?
  2. 给类加载器分配的 chunk 使用率很低

第一种显然不太可能,一个类不可能需要这么大的内存。第二种有种情况,当创建很多类加载器,而每个类加载器又加载了很少的类。

上面我们说了剩余空闲内存小于metaspaceGC的阈值就会执行FullGC,但是我们开头说有些正常场景我们通过 jstat 打印的使用率都达到了 90% 多都没有触发 FullGC,这是为什么呢?欢迎留言分享你的答案

03

排查程序

首先,我们看下 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 2850  null live 0x000000077bc27bc0 1 1394 0x000000077bc64418 dead groovy/lang/GroovyClassLoader$InnerLoader@0x00000007f0dcf828 0x000000077d9e7d98 0 0 0x0000000 dead groovy/lang/GroovyClassLoader@0x00000007f0af9890 0x00000007805e8050 0 0 0x0000000 dead groovy/lang/GroovyClassLoader@0x00000007f0af9890 0x000000077df07de0 0 0 0x0000000 dead groovy/lang/GroovyClassLoader@0x00000007f0af9890 0x0000000 1 1394 0x000000078005a6c8 dead groovy/lang/GroovyClassLoader$InnerLoader@0x00000007f0dcf828 0x0000000 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 为什么不回收掉呢?

04

本地复现

复现的代码很简单,引入上述 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 就溢出了。

大量类加载器创建导致诡异FullGC

接下来选择 Dominator Tree,然后输入 Script1 正则过滤,右键选择:Path To Gc Roots,这里我们只关心强引用,所以 execlude 其他类型引用。

大量类加载器创建导致诡异FullGC

如果类加载器被回收,它所加载的类也会被回收,如果类有被引用,肯定不能被回收,所以,我们从 Script1 的对象开始。如下图所有,Script1 类有被引用,最终到达 GC root (AppClassLoader),所以 Full GC 也没法回收掉。

大量类加载器创建导致诡异FullGC

参考文档

  1. https://github.com/codefollower/OpenJDK-Research,OpenJDK(HotSpot JVM、Javac)源代码。
  2. https://stuefe.de/posts/metaspace/what-is-metaspace/,这篇文章讲 Metaspace 源码相关概念。
  3. http://java-latte.blogspot.com/2014/03/metaspace-in-java-8.html,这篇也是讲 Metaspace 可以结合第二篇文章看。
  4. https://docs.oracle.com/javase/8/docs/technotes/guides/vm/gctuning/considerations.html,Oracle 的文档,可以看下 Metaspace 什么时候 GC。
  5. https://stackoverflow.com/questions//understanding-metaspace-line-in-jvm-heap-printout?answertab=votes,used、capacity、committed 和 reserved 相关概念。
  6. https://www.youtube.com/watch?v=jsJtZdYhQuE,Red Hat Java Team 分享的 Metaspace 中存放的数据结构和类型。
  7. https://stuefe.de/posts/metaspace/sizing-metaspace/,这个讲控制 Metaspace 大小的两个参数 MaxMetaspaceSize 和 CompressedClassSpaceSize

微信搜索 CoderMeng 关注获取更多干货文章

免责声明:本站所有文章内容,图片,视频等均是来源于用户投稿和互联网及文摘转载整编而成,不代表本站观点,不承担相关法律责任。其著作权各归其原作者或其出版社所有。如发现本站有涉嫌抄袭侵权/违法违规的内容,侵犯到您的权益,请在线联系站长,一经查实,本站将立刻删除。 本文来自网络,若有侵权,请联系删除,如若转载,请注明出处:https://itzsg.com/94169.html

(0)
上一篇 2024年 12月 3日 下午3:45
下一篇 2024年 12月 3日 下午4:15

相关推荐

发表回复

您的邮箱地址不会被公开。 必填项已用 * 标注

联系我们YX

mu99908888

在线咨询: 微信交谈

邮件:itzsgw@126.com

工作时间:时刻准备着!

关注微信