你一定不能错过，Java视频全套

• 从一次YGC耗时过长的案例说起

• YGC的相关知识点总结

01 从一次YGC耗时过长的案例说起

今年4月份，我们的广告服务在新版本上线后，收到了大量的服务超时告警，通过下面的监控图可以看到：超时量突然大面积增加，1分钟内甚至达到了上千次接口超时。下面详细介绍下该问题的排查过程。

1. 检查监控

收到告警后，我们第一时间查看了监控系统，立马发现了YoungGC耗时过长的异常。 我们的 程序大概在 21 点50 左右上线，通过下图可以看出： 在上线之前，YGC基本几十毫秒内完成，而上线后YGC耗时明显变长，最长甚至达到了3秒多。

由于 YGC期间程序会 Stop The World ，而我们上游系统设置的服务超时时间都在几百毫秒，因此推断：是因为YGC耗时过长引发了服务大面积超时。

按照GC问题的常规排查流程，我们立刻摘掉了一个节点，然后通过以下命令dump了堆内存文件用来保留现场。

jmap -dump:format=b,file=heap pid

最后对线上服务做了回滚处理，回滚后服务立马恢复了正常，接下来就是长达1天的问题排查和修复过程。

2. 确认JVM配置

用下面的命令，我们再次检查了JVM的参数

ps aux | grep “applicationName=adsearch”

-Xms4g -Xmx4g -Xmn2g -Xss1024K

-XX:ParallelGCThreads=5

-XX:+UseConcMarkSweepGC

-XX:+UseParNewGC

-XX:+UseCMSCompactAtFullCollection

-XX:CMSInitiatingOccupancyFraction=80

可以看到堆内存为4G，新生代和老年代均为2G，新生代采用ParNew收集器。

再通过命令 jmap -heap pid 查到：新生代的Eden区为1.6G，S0和S1区均为0.2G。

本次上线并未修改JVM相关的任何参数，同时我们服务的请求量基本和往常持平。因此猜测：此问题大概率和上线的代码相关。

3. 检查代码

再回到YGC的原理来思考这个问题，一次YGC的过程主要包括以下两个步骤：

1、从GC Root扫描对象，对存活对象进行标注

2、将存活对象复制到S1区或者晋升到Old区

根据下面的监控图可以看出：正常情况下，Survivor区的使用率一直维持在很低的水平（大概30M左右），但是上线后，Survivor区的使用率开始波动，最多的时候快占满0.2G了。而且，YGC耗时和Survivor区的使用率基本成正相关。因此，我们推测：应该是长生命周期的对象越来越多，导致标注和复制过程的耗时增加。

再回到服务的整体表现：上游流量并没有出现明显变化，正常情况下，核心接口的响应时间也基本在200ms以内，YGC的频率大概每8秒进行1次。

很显然，对于局部变量来说，在每次YGC后就能够马上被回收了。那为什么还会有如此多的对象在YGC后存活下来呢？

我们进一步将怀疑对象锁定在：程序的全局变量或者类静态变量上。但是diff了本次上线的代码，我们并未发现代码中有引入此类变量。

4. 对dump的堆内存文件进行分析

代码排查没有进展后，我们开始从堆内存文件中寻找线索，使用MAT工具导入了第1步dump出来的堆文件后，然后通过Dominator Tree视图查看到了当前堆中的所有大对象。

立马发现NewOldMappingService这个类所占的空间很大，通过代码定位到：这个类位于第三方的client包中，由我们公司的商品团队提供，用于实现新旧类目转换（最近商品团队在对类目体系进行改造，为了兼容旧业务，需要进行新旧类目映射）。

进一步查看代码，发现这个类中存在大量的静态HashMap，用于缓存新旧类目转换时需要用到的各种数据，以减少RPC调用，提高转换性能。

原本以为，非常接近问题的真相了，但是深入排查发现：这个类的所有静态变量全部在类加载时就初始化完数据了，虽然会占到100多M的内存，但是之后基本不会再新增数据。并且，这个类早在3月份就上线使用了，client包的版本也一直没变过。

经过上面种种分析，这个类的静态HashMap会一直存活，经过多轮YGC后，最终晋升到老年代中，它不应该是YGC持续耗时过长的原因。因此，我们暂时排除了这个可疑点。

5. 分析YGC处理Reference的耗时

团队对于YGC问题的排查经验很少，不知道再往下该如何分析了。基本扫光了网上可查到的所有案例，发现原因集中在这两类上：

1、对存活对象标注时间过长：比如重载了Object类的Finalize方法，导致标注Final Reference耗时过长；或者String.intern方法使用不当，导致YGC扫描StringTable时间过长。

2、长周期对象积累过多：比如本地缓存使用不当，积累了太多存活对象；或者锁竞争严重导致线程阻塞，局部变量的生命周期变长。

针对第1类问题，可以通过以下参数显示GC处理Reference的耗时-XX:+PrintReferenceGC。 添加此参数后，可以看到不同类型的 reference 处理耗时都很短，因此又排除了此项因素。

6. 再回到长周期对象进行分析

再往后，我们添加了各种GC参数试图寻找线索都没有结果，似乎要黔驴技穷，没有思路了。综合监控和种种分析来看：应该只有长周期对象才会引发我们这个问题。

折腾了好几个小时，最终峰回路转，一个小伙伴重新从MAT堆内存中找到了第二个怀疑点。

从上面的截图可以看到：大对象中排在第3位的ConfigService类进入了我们的视野，该类的一个ArrayList变量中竟然包含了270W个对象，而且大部分都是相同的元素。

ConfigService这个类在第三方Apollo的包中，不过源代码被公司架构部进行了二次改造，通过代码可以看出：问题出在了第11行，每次调用getConfig方法时都会往List中添加元素，并且未做去重处理。

我们的广告服务在apollo中存储了大量的广告策略配置，而且大部分请求都会调用ConfigService的getConfig方法来获取配置，因此会不断地往静态变量namespaces中添加新对象，从而引发此问题。

至此，整个问题终于水落石出了。这个BUG是因为架构部在对apollo client包进行定制化开发时不小心引入的，很显然没有经过仔细测试，并且刚好在我们上线前一天发布到了中央仓库中，而公司基础组件库的版本是通过super-pom方式统一维护的，业务无感知。

7. 解决方案

为了快速验证YGC耗时过长是因为此问题导致的，我们在一台服务器上直接用旧版本的apollo client 包进行了替换，然后重启了服务，观察了将近20分钟，YGC恢复正常。

最后，我们 通知架构部修复BUG，重新发布了super-pom ，彻底解决了这个问题。

02 YGC的相关知识点总结

通过上面这个案例，可以看到YGC问题其实比较难排查。相比FGC或者OOM，YGC的日志很简单，只知道新生代内存的变化和耗时，同时dump出来的堆内存必须要仔细排查才行。

另外，如果不清楚YGC的流程，排查起来会更加困难。这里，我对YGC相关的知识点再做下梳理，方便大家更全面的理解YGC。

1. 5个问题重新认识新生代

YGC 在新生代中进行，首先要清楚新生代的堆结构划分。新生代分为Eden区和两个Survivor区，其中Eden:from:to = 8:1:1 (比例可以通过参数 –XX:SurvivorRatio 来设定 )，这是最基本的认识。

为什么会有新生代？

如果不分代，所有对象全部在一个区域，每次GC都需要对全堆进行扫描，存在效率问题。分代后，可分别控制回收频率，并采用不同的回收算法，确保GC性能全局最优。

为什么新生代会采用复制算法？

新生代的对象朝生夕死，大约90%的新建对象可以被很快回收，复制算法成本低，同时还能保证空间没有碎片。虽然标记整理算法也可以保证没有碎片，但是由于新生代要清理的对象数量很大，将存活的对象整理到待清理对象之前，需要大量的移动操作，时间复杂度比复制算法高。

为什么新生代需要两个Survivor区？

为了节省空间考虑，如果采用传统的复制算法，只有一个Survivor区，则Survivor区大小需要等于Eden区大小，此时空间消耗是8 * 2，而两块Survivor可以保持新对象始终在Eden区创建，存活对象在Survivor之间转移即可，空间消耗是8+1+1，明显后者的空间利用率更高。

新生代的实际可用空间是多少？

YGC后，总有一块Survivor区是空闲的，因此新生代的可用内存空间是90%。在YGC的log中或者通过 jmap -heap pid 命令查看新生代的空间时，如果发现capacity只有90%，不要觉得奇怪。

Eden区是如何加速内存分配的？

HotSpot虚拟机使用了两种技术来加快内存分配。分别是bump-the-pointer和TLAB（Thread Local Allocation Buffers）。

由于Eden区是连续的，因此bump-the-pointer在对象创建时，只需要检查最后一个对象后面是否有足够的内存即可，从而加快内存分配速度。

总结

总的来说，面试是有套路的，一面基础，二面架构，三面个人。

最后，小编这里收集整理了一些资料，其中包括面试题（含答案）、书籍、视频等。希望也能帮助想进大厂的朋友，点击这里即可免费获取

//gitee.com/vip204888/java-p7)**

[外链图片转存中…(img-JJ8dihhw-1628434437917)]

[外链图片转存中…(img-zq2jHU6e-1628434437918)]

[外链图片转存中…(img-Xw6Qy6uO-1628434437919)]