记一次线上频繁GC的排查过程

最新推荐文章于 2024-07-24 08:47:28 发布

岚灵

最新推荐文章于 2024-07-24 08:47:28 发布

阅读量5.3k

点赞数 7

分类专栏： JVM 文章标签： JVM GC 线上问题排查

本文链接：https://blog.csdn.net/weixin_42392874/article/details/89483496

版权

JVM 专栏收录该内容

1 篇文章 0 订阅

订阅专栏

背景

公司有个给服务商使用的直营系统，用户不算多，但是服务器经常出现报警，CPU过高，但是很快CPU又恢复了下来。运维的同事看不下去了，叫我看看，虽然不会影响使用，但是看着频繁的报警实在太烦了。

排查过程

了解现状

系统是用法java做的开发，运行环境是jdk8，应用的JVM配置参数具体信息见下图。

第一时间就想到了是GC导致的CPU突然变高。为了验证想法，去服务器上看了一下。

本想通过TOP命令获取到占用CPU较高的线程，再去看看对应线程的堆栈信息。但是CPU基本都是不到 1%，看了也找不到重点相关线程。还是直接打印GC的信息出来吧，不看不知道，一看吓一跳！

可以看到metaspace（元数据空间，专门用来存元数据的，它是jdk8里特有的数据结构用来替代perm）的使用比例是95%，YGC 6103 次，FGC 1506 次。可怕的是FGC占用的时间高达1314.421s，因为这21分钟java应用进程是STW（stop the world，类似暂停，不可用）。

看了一下内存的分配。

配合之前jvm配置信息，跟内存分配，我以为是没主动给应用分配的内存，自动分配的内存太小了，才导致的频繁GC。问了一下运维的同学，运维的同学回答说，“因为zhiying 长期吃掉主机资源. 我不得不对他进行限制.保护其他资源”，具体的做法就是对docker的资源进行限制。

寻找问题代码

好了，那不管配置多少资源，最后都是会被吃掉，那就是代码的问题了。我就dump了堆内存信息，并下载到本机用eclipse打开看看究竟是哪些对象占用了较多的内存。

jmap -dump:live,format=b,file=heap.hprof  16671

看了很久，不过一些java的原始数据跟对象，没有涉及到业务对象。那就看一下gc的原因吧

jstat -gccause 16671 1000

OMG，该不会是代码里面有人直接调用System.gc()吧？

// help gc
            if (list.size() > 10000) {
                list = null;
                System.gc();
            }

help gc ? help me please! 我们知道：

System.gc其实是做一次full gc
System.gc会暂停整个进程
System.gc一般情况下我们要禁掉，使用-XX:+DisableExplicitGC

分析与解决

问题代码已经找到了，那就下来就是分析修改了。我们来看看为什么会有这样的代码出现

List<Object[]> list = (List<Object[]>) jpaQuery.list(em);

// 统计数量
list.parallelStream().forEach(colums -> {
TaskType taskType = (TaskType) colums[1];
TaskStatus taskStatus = (TaskStatus) colums[2];
Boolean trunkEndFlag = (Boolean) colums[3];

......

好家伙，原来是为了要统计数据，先把数据全部查出来，然后遍历数据分类统计。又意识到这样会有生成很多大对象（多的话会有几十万数据放在这个List对象），所以就手动做垃圾回收。好吧，既然能有垃圾回收的概念，为什么就不能转变一下思路了，sql直接统计出来数据，那样就不会生成大对象了。对，解决方案就是修改业务统计的逻辑。

总结

默认情况下，System.gc()会显式直接触发Full GC，同时对老年代和新生代进行回收。而一般情况下我们认为，垃圾回收应该是自动进行的，无需手工触发。如果过于频繁地触发垃圾回收对系统性能是没有好处的。因此虚拟机提供了一个参数DisableExplicitGC来控制是否手工触发GC。应该从根源解决对象生成的问题，而不是要生成之后再去回收，这样很耗CPU。