你们要的线上GC问题案例来啦

1,492 阅读7分钟

先推荐一篇好文

最近写了几篇关于GC的文章,主要是因为线上有一些关于GC的问题,所以想顺便总结一波,梳理一下GC的一些知识点和排查思路。

之前有读者留言说能不能写一篇实战经验方面的,这不就来了吗~

我们项目上用到的主要还是CMS + ParNew的组合。所以重点看的资料也是这方面的。

在学习的过程中,也拜读了美团技术团队的这篇文章《Java中9种常见的CMS GC问题分析与解决》。这篇文章质量非常高,从理论知识,源码分析,到常见的GC问题案例,囊括了分析路径、根因、调优策略等等内容,非常详尽且全面,尤其是最后部分的处理流程SOP和根因鱼骨图,非常nice。墙裂推荐,值得一读!!!

知道大家喜欢现成的,所以我手动copy了这两张图过来,有需要的自取:

排查问题SOP

根因鱼骨图

GC问题案例

我遇到的案例可能没有上面文章作者那么丰富,但也是真实遇到的几个案例,所以借这篇文章分享出来,大家可以参考参考,避免踩类似的坑。

案例1 Young GC频繁

之前有个任务会频繁地重复调用一个接口。所以用guava cache做了一个简单的内存缓存。结果上线后发现经常收到Young GC频繁的告警,时间跟这个任务的启动时间也比较吻合。

通过监控看到的GC图大概是这样:

案例1

可以看到,Young GC的次数会在某一个时间点飙升。同时伴随着Old区域内存快速升高,最后会触发一次Full GC。

根据这个情况,可以肯定的是由于本次代码改动引起的。通过Heap Dump分析后发现,占用内存较大的是一个guava cache的Map对象。

查找代码发现,使用guava cache的时候,没有设置最大缓存数量和弱引用,而是设置了一个几分钟的过期时间。而这个任务的量又比较大,到线上后很快就缓存了大量的对象,导致频繁触发Young GC,但又由于有引用GC不掉(这个从Survivor区的内存大小图像可以推测),所以慢慢代数比较多的对象就晋升到了老年代,后面老年代内存到达一定阈值引发Full GC。

后面通过设置最大缓存数量解决了这个问题。又积累了一个宝贵的经验,完美!

案例2 Young GC和Old GC都频繁

在线上灰度环境中发现收到Young GC和Old GC频繁的告警。监控看到的GC图大概长这样:

案例2

根据GC图大概可以看出来,Young GC和Old GC都非常频繁,且每次都能回收走大量的对象。那可以简单地推测:确实是产生了大量的对象,且极有可能有一部分大对象。小对象引发的Young GC频繁,而大对象引发了Old GC频繁。

排查下来也是一段代码引起的。对于一个查询和排序分页的SQL,同时这个SQL需要join多张表,在分库分表下,直接调用SQL性能很差,甚至超时。于是想了个比较low的办法:查单表,把所有数据查出来,在内存排序分页。用了一个List来保存数据,而有些数据量大,造成了这个现象。用Heap Dump分析,也印证了这个猜测,List类型的对象占用了大量的空间。

案例3 接口线程池满和Full GC

这是一个报接口线程池满的问题。但每次都会在同一时间Full GC。监控图大概长这样:

案例3

从时间上来看,先是Java线程数量飙升,然后触发Full GC。后面重启后,Java线程数量恢复正常水位。

这里涉及到一个冷知识:一个Java线程默认会占用多少内存?

这个参数可以控制: -XX:ThreadStackSize。在64 位的Linux下, 默认是1 MB(这个说法也不全对,还是取决于栈深度)。Java 11对这个有一个优化,可以减少内存占用。详情可以参考这篇文章:dzone.com/articles/ho…

排查下来根因是这个应用还是使用的Log4j 1,而Log4j 1有性能问题,在高并发下,下面这段代码的同步块可能会引起大量线程阻塞:

void callAppenders(LoggingEvent event) {
    int writes = 0;

    for(Category c = this; c != null; c=c.parent) {
        // Protected against simultaneous call to addAppender, removeAppender,...
        synchronized(c) {
            if(c.aai != null) {
                writes += c.aai.appendLoopOnAppenders(event);
            }
            if(!c.additive) {
                break;
            }
        }
    }

    if(writes == 0) {
        repository.emitNoAppenderWarning(this);
    }
}

解决办法就是减少日志打印,升级日志框架到Log4j 2或者Logback。

案例4 应用启动时Full GC频繁

这个是较早的一个案例了,GC图已经找不到了。

但引发Full GC频繁的大概就这几种可能性:

  • 调用System.gc()
  • Old区空间不足
  • 永久代/元空间满

根据代码和GC图排除了前面两种可能性,那就是元空间满了。在Java 8中,XX:MaxMetaspaceSize是没有上限的,最大容量与机器的内存有关;但是XX:MetaspaceSize是有一个默认值的:21M。而如果应用需要进元空间的对象较多(比如有大量代码),就会频繁触发Full GC。解决办法是可以通过JVM参数指定元空间大小:-XX:MetaspaceSize=128M

总结

可以看到上面的大多数案例都是代码改动或者应用框架引起的。一般公司内都会有默认的一套JVM参数,真正需要JVM参数调优解决问题的case其实是比较少的。

而且有时候GC问题可能并不是问题的根源,有可能是其它问题引发的GC问题,在实际排查的时候要根据日志及时间线去判断。

至于怎么去判断是否“频繁”和“耗时长”?虽然有一些公式计算,但我觉得只要不影响现有的业务,那就是可以接受的。而如果某个应用的GC表现明显不同于以往的平均水平,或者其它相似应用的水平,那就有理由怀疑是不是存在GC问题了。

很多时候GC问题不充分的压测是测试不出来的,而压测成本又比较大。经常会在线上灰度发布中观察到,所以需要在灰度发布的时候密切观察系统的监控和告警。如果有条件,可以上红蓝部署,降低风险。

GC问题还是蛮复杂的,需要大量的经验和理论知识。遇到之后可以总结分析一下根因,平时也可以看看其他人的博客,吸取经验,这样就能不断完善自己的知识体系。

求个支持

我是Yasin,一个坚持技术原创的博主,我的微信公众号是:编了个程

都看到这儿了,如果觉得我的文章写得还行,不妨支持一下。

文章会首发到公众号,阅读体验最佳,欢迎大家关注。

你的每一个转发、关注、点赞、评论都是对我最大的支持!

还有学习资源、和一线互联网公司内推哦

求个支持

我是Yasin,一个坚持技术原创的博主,我的微信公众号是:编了个程

都看到这儿了,如果觉得我的文章写得还行,不妨支持一下。

文章会首发到公众号,阅读体验最佳,欢迎大家关注。

你的每一个转发、关注、点赞、评论都是对我最大的支持!

还有学习资源、和一线互联网公司内推哦