记一次隐藏很深的 JVM 线上惨案的分析、排查、解决
副标题[/!--empirenews.page--]
1、本文背景 本文会给大家讲解一个比较特殊的JVM优化案例,这个优化案例本身是因为新手工程师对JVM优化可能了解了一个半吊子,然后不知道从哪里找来了一个非常特殊的JVM参数错误的设置了一下,就导致线上系统频繁的出现Full GC的问题。 但是我们后续大量的优化案例其实都是各种各样奇形怪状的场景,因为正是各种奇怪场景才能让大家逐步积累出来较为丰富的JVM优化实战经验 了解的场景越多,自己未来在处理JVM性能问题的时候才能更是得心应手。 2、问题的产生 这个场景的发生大致如下过程:某天团队里一个新手工程师大概是心血来潮,觉得自己网上看到了某个JVM参数,以为学会了绝世武功秘籍,于是就在当天上线一个系统的时候,自作主张设置了一个JVM参数 这个参数是什么呢? 不用急,跟着看下面的案例分析即可,现在只要知道他设置了一个奇怪的参数,接着事故就发生了。 因为一般中大型公司都是接入类似Zabbix、OpenFalcon或者公司自研的一些监控系统的,监控系统一般都做的很好,可以让你的系统直接接入进去,然后在上面可以看到每台机器的CPU、磁盘、内存、网络的一些负载。 而且可以看到你的JVM的内存使用波动折线图,还有你的JVM GC发生的频率折线图。包括如果你自己上报某个业务指标,也可以在监控系统里看到。 而且一般都会针对线上运行的机器和系统设置一些报警,比如说,你可以设置如果10分钟内发现一个系统的JVM发生了超过3次Full GC,就必须发送报警给你,可以发送给你的短信、邮箱或者是钉钉之类的IM工具。 类似这样的监控系统不在我们的专栏范畴内,建议大家自己可以去查阅资料,其实基于我们讲解的命令行工具,比如jstat,你可以通过linux上的一些命令,让jstat自动对jvm进行监控,把监控结果可以输出到机器的某个文件里去。 然后第二天你就可以去查阅那个文件,也可以看到那台机器的jvm的一些gc统计。 所以说,没有可视化工具,用最简单的命令行工具,其实同样可以起到类似的效果。 所以那天那个工程师设置了一个JVM参数之后,直接导致线上频繁接到JVM的Full GC的报警,大家就很奇怪了,于是就开始排查那个系统了。 3、查看GC日志 之前已经给大家讲解过如何在启动系统的时候让他输出GC日志,所以一旦发现报警,直接登录到线上机器,然后就看到对应的GC日志了。 此时我们看到在GC日志中有大量的Full GC的记录。 那么是为什么导致的Full GC呢? 在日志里,看到了一个“Metadata GC Threshold”的字样,类似于如下日志: 【Full GC(Metadata GC Threshold)xxxxx, xxxxx】 从这里就知道,这频繁的Full GC,实际上是JDK 1.8以后的Metadata元数据区导致的,也就是类似我们之前说的永久代。 这个Metadata区域一般是放一些加载到JVM里去的类的。 所以此时就很奇怪了,为什么会因为Metadata区域频繁的被塞满,进而触发Full GC?而且Full GC大家都知道,会带动CMS回收老年代,还会回收Metadata区域本身。 我们先看看下图: ![]() 4、查看Metaspace内存占用情况 接着我们当然是想看一看Metaspace区域的内存占用情况了,简单点你可以通过jstat来观察,如果有监控系统,他会给你展示出来一个Metaspace内存区域占用的波动曲线图,类似下面这种。 ![]() 看起来Metaspace区域的内存呈现一个波动的状态,他总是会先不断增加,达到一个顶点之后,就会把Metaspace区域给占满,然后自然就会触发一次Full GC,Full GC会带着Metaspace区域的垃圾回收,所以接下来Metaspace区域的内存占用又变得很小了。 5、一个综合性的分析思路 看到这里,相信大家肯定有一点感觉了,这个很明显是系统在运行过程中,不停的有新的类产生被加载到Metaspace区域里去,然后不停的把Metaspace区域占满,接着触发一次Full GC回收掉Metaspace区域中的部分类。 然后这个过程反复的不断的循环,进而造成Metaspace区域反复被占满,然后反复导致Full GC的发生,如下图所示。 ![]() 6、到底是什么类不停的被加载? 接着我们就有点奇怪了,到底是什么类不停的被加载到JVM的Metaspace区域里去? 这个时候就需要在JVM启动参数中加入如下两个参数了:
这两个参数,顾名思义,就是追踪类加载和类卸载的情况,他会通过日志打印出来JVM中加载了哪些类,卸载了哪些类。 加入这两个参数之后,我们就可以看到在Tomcat的catalina.out日志文件中,输出了一堆日志,里面显示类似如下的内容: 【Loaded sun.reflect.GeneratedSerializationConstructorAccessor from __JVM_Defined_Class】 明显可以看到,JVM在运行期间不停的加载了大量的所谓“GeneratedSerializationConstructorAccessor”类到了Metaspace区域里去 如下图所示 ![]() 相信就是因为JVM运行期间不停的加载这种奇怪的类,然后不停的把Metaspace区域占满,才会引发不停的执行Full GC的。 这是一个非常实用的技巧,各位同学一定要掌握,频繁Full GC不光是老年代触发的,有时候也会因为Metaspace区域的类太多而触发。 到此为止,已经慢慢接近真相了。 7、为什么会频繁加载奇怪的类? (编辑:东莞站长网) 【声明】本站内容均来自网络,其相关言论仅代表作者个人观点,不代表本站立场。若无意侵犯到您的权利,请及时与联系站长删除相关内容! |