设为首页 - 加入收藏 平凉站长网 (http://www.0933zz.com)- 国内知名站长资讯网站,提供最新最全的站长资讯,创业经验,网站建设等!
热搜: 什么 为什么 平台 赚钱
当前位置: 首页 > 综合聚焦 > 资源网站 > 空间 > 正文

记一次隐藏很深的 JVM 线上惨案的分析、排查、解决

发布时间:2019-09-11 05:27 所属栏目:[空间] 来源:Java的小本家
导读:1、本文背景 本文会给大家讲解一个比较特殊的JVM优化案例,这个优化案例本身是因为新手工程师对JVM优化可能了解了一个半吊子,然后不知道从哪里找来了一个非常特殊的JVM参数错误的设置了一下,就导致线上系统频繁的出现Full GC的问题。 但是我们后续大量的

?记一次隐藏很深的 JVM 线上惨案的分析、排查、解决

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区域本身。

我们先看看下图:

记一次隐藏很深的 JVM 线上惨案的分析、排查、解决

4、查看Metaspace内存占用情况

接着我们当然是想看一看Metaspace区域的内存占用情况了,简单点你可以通过jstat来观察,如果有监控系统,他会给你展示出来一个Metaspace内存区域占用的波动曲线图,类似下面这种。

记一次隐藏很深的 JVM 线上惨案的分析、排查、解决

看起来Metaspace区域的内存呈现一个波动的状态,他总是会先不断增加,达到一个顶点之后,就会把Metaspace区域给占满,然后自然就会触发一次Full GC,Full GC会带着Metaspace区域的垃圾回收,所以接下来Metaspace区域的内存占用又变得很小了。

5、一个综合性的分析思路

看到这里,相信大家肯定有一点感觉了,这个很明显是系统在运行过程中,不停的有新的类产生被加载到Metaspace区域里去,然后不停的把Metaspace区域占满,接着触发一次Full GC回收掉Metaspace区域中的部分类。

然后这个过程反复的不断的循环,进而造成Metaspace区域反复被占满,然后反复导致Full GC的发生,如下图所示。

记一次隐藏很深的 JVM 线上惨案的分析、排查、解决

6、到底是什么类不停的被加载?

接着我们就有点奇怪了,到底是什么类不停的被加载到JVM的Metaspace区域里去?

这个时候就需要在JVM启动参数中加入如下两个参数了:

  1. “-XX:TraceClassLoading?-XX:TraceClassUnloading”?

这两个参数,顾名思义,就是追踪类加载和类卸载的情况,他会通过日志打印出来JVM中加载了哪些类,卸载了哪些类。

加入这两个参数之后,我们就可以看到在Tomcat的catalina.out日志文件中,输出了一堆日志,里面显示类似如下的内容:

【Loaded sun.reflect.GeneratedSerializationConstructorAccessor from __JVM_Defined_Class】

明显可以看到,JVM在运行期间不停的加载了大量的所谓“GeneratedSerializationConstructorAccessor”类到了Metaspace区域里去

如下图所示

记一次隐藏很深的 JVM 线上惨案的分析、排查、解决

相信就是因为JVM运行期间不停的加载这种奇怪的类,然后不停的把Metaspace区域占满,才会引发不停的执行Full GC的。

这是一个非常实用的技巧,各位同学一定要掌握,频繁Full GC不光是老年代触发的,有时候也会因为Metaspace区域的类太多而触发。

到此为止,已经慢慢接近真相了。

7、为什么会频繁加载奇怪的类?

【免责声明】本站内容转载自互联网,其相关言论仅代表作者个人观点绝非权威,不代表本站立场。如您发现内容存在版权问题,请提交相关链接至邮箱:bqsm@foxmail.com,我们将及时予以处理。

网友评论
推荐文章