简介Java技术栈广泛应用于free fish服务器应用。基于JVM提供的托管堆内存管理，开发人员在创建/回收对象时不需要过多关注内存分配/释放动作。垃圾收集器会在需要时自动清理堆中未使用的对象，确保有足够的空间用于新的对象分配。 　　

　　

　　开发者在享受自动内存管理带来的便利的同时，也不可避免地要承担垃圾收集器在清理死对象方面的一些开销，比如机器资源利用率的增加、应用线程的暂时挂起等。根据JVM使用的垃圾收集算法不同，收集的堆区不同，在GC的过程中，用户线程的暂停时间和完成一次GC所用的时间也不同。 　　

　　

　　其中，Full GC(以下简称FGC)将扫描整个堆空间，清理所有死对象，而FGC(以下简称STW)将停止世界，这意味着所有用户线程都将被挂起，直到GC结束。FGC旅行的暂停时间取决于堆空间和幸存对象的数量，通常从几秒到几十秒不等。在此期间，应用无法向外界提供任何服务，如接口超时、成功率下降、全上游依赖线程池等。极大地影响了用户体验，甚至访问压力可能会转移到其他健康机器上，增加了健康机器对象的分发压力，最终导致FGC和集群雪崩。 　　

　　

　　对于前端业务应用来说，在承接业务流量的正常过程中产生的对象，大部分都是夜间产生和消失的对象。理论上，大部分对象应该由新一代GC(YGC)清理；然而，大多数GC算法仅在老年期的占用空间超过某个阈值时才触发FGC。因此，一旦出现FGC，通常意味着与该应用的对象分配或垃圾收集相关的JVM参数出现了问题，这是业务运行中的重大隐患，需要尽快排查和治理。 　　

　　

　　本文通过前台FGC调优的三个案例，介绍了JVM参数、中间件配置、业务代码级别引起的FGC现象、分析过程以及相应的解决方案。希望能起到抛砖引玉的作用，给有同样疑惑的读者朋友带来一些启发。 　　

　　

　　领域核心应用发布并运行时的FGC现象。当闲鱼商品域的一个核心应用正常接收业务流量时，集群中会不时出现少量FGC，导致接口RT毛刺，成功率略有下降。在应用发布过程中，集群FGC频率明显增加，界面抖动明显，大部分FGC出现在不在发布批次的机器上。 　　

　　

　　这个应用承担了添加、删除、查看闲鱼商品的大部分流量。集群运行时的FGC不仅会影响用户体验，成为未来业务发展的一大隐患，而且发布时的抖动会导致一旦出现问题无法快速回滚到之前的版本，这是安全生产的一大隐患，需要尽快解决。 　　

　　

　　选择带有FGC的机器，检查其JVM信息监控，如下图所示： 　　

　　

　　 　　

　　

　　从图中不难得到很多有用的信息： 　　

　　

　　使用全新CMS组合。 　　

　　

　　当陈年达到1.7G左右时，CMS老Gen GC被触发。[1.7G可能是固定的老一代回收阈值] 　　

　　

　　老职业会随着时间的推移慢慢上升，逐渐达到顶峰。[幸存者空间可能不够] 　　

　　

　　老Gen GC一次回收200MB左右，水位降到1.5G单次回收收益不明显。【老年时期有很多固定职业的大物件】 　　

　　

　　从监测的角度来看，这是一个非常明显的现象，因为保障的分配，使得一些最终会死亡的对象进入老年，老年触及CMS恢复的阈值，导致CMS老Gen GC的出现。但是，在证据充分之前，我们不能盲目下结论，需要继续仔细验证上述假设，以便根据深层次原因制定出能够根治FGC的解决方案。 　　

　　

　　对于假设1和2，检查应用程序JVM参数配置： 　　

　　

　　 　　

　　

　　可以看到，应用确实使用了CMS作为垃圾收集器，堆大小配置为4G，年轻区2G，老区2G，CMS initiatingcoccupancyfraction的参数配置为80%，也就是说当老龄占用超过80%时触发CMS老Gen回收，2G*0.8=1.6G，差不多就是监控中反映的1.7G左右。回收开始，然后老年职业回落。 　　

　　

　　另外，顺便可以得到幸存者比例为10的结论，单个幸存者面积约为2048 */(10 ^ 1 ^ 1)=174762k，可以为后面的分析提供帮助。 　　

　　

　　对于假设3，监控系统上以分钟为单位聚合的折线图无法满足需求。需要通过GC日志分析机器每次GC回收后各个区域的堆空间占用情况，看看YGC一次结束后是否存在幸存者区域占用高的情况。下图显示了一个非常有代表性的GC日志： 　　

　　

　　 　　

　　

　　需要注意的是，ParNew是STW的算法，回收过程中不存在对象分配的可能。全新恢复前后堆空间的变化可以用下图表示： 　　

mg src="https://tupian.lamuhao.com/pic/img.php?k=tr外汇最新状况,tr外汇托管平台最新消息4.jpg">

　　

计算GC日志中各个区域的存活对象占用空间变化：
第一次回收: Young区 40225K存活，全堆1697070K存活，Old区1697070-40225=1656845K
第二次回收: Young区174720K存活，全堆1859440K存活，Old区1859440-174720=1684720K
Old区占用上涨约27875K
而先前通过JVM参数，可以知道单个Survivor区大小约为174762K，第二次回收极有可能出现了担保分配。Survivor区可能在某些回收中，显得不够用。

　　

对于假设4，可以随机找一台线上机器，将流量切走后执行带FGC的Heap dump，目的是拿到FGC过后的堆对象集合。查看支配树，如下图所示：

　　

　　

可以看到排前4的对象已经占用了老年代约 687MB的空间，整体约1.3G的对象常驻老年代空间。且这4个对象对于业务而言都是十分重要的对象，初步来看并没有太大的优化空间。

　　

分析到这里，该应用FGC的根因就呼之欲出了。

　　

　　

根因偶现Survivor不够用的担保分配(可能还有晋升) -> Old Gen占用上涨 -> Old Gen 距离回收阈值仅有约200M的余量 -> 频繁 CMS Old Gen GC。

　　

在应用发布过程中，又因为正在启动的应用，RPC、HTTP服务等没有上线，或者是处于小流量预热阶段，整个集群的流量就会倾斜到不在发布流程中的机器，使得每台机器需要承受的QPS升高，对象分配压力增大，YGC次数增多，通过担保分配晋升老年代的速率加快，导致老年代更快的触顶，出现频繁FGC。

　　

　　

解法虽然该应用的FGC成因并不难分析，但是为其制定一个能根治FGC的解法却还是需要一些考量。

　　

商品业务经过长时间的发展，该应用代码量非常大，业务逻辑错综复杂，且依赖了大量中间件、二方服务，很难去搞清楚这些业务对象的存活周期。要想解决这个应用的FGC现象，最好的办法就是：在不触发FGC的前提下清理掉担保到Old Gen的Young区存活对象。

　　

该应用之前使用CMS回收器，但是通过后续分析发现，很难在CMS上达成上述目标。主要是因为存在以下几点困难：

　　

Survivor 存在不够用现象。然而业务复杂，很难给出一个一定够用的数字。盲目调大，挤占了Young区的空间，导致YGC频繁，可能存在吞吐下降，RT升高的风险。

　　

Old Gen 常驻大对象多？考虑大对象治理。依赖的服务未必有治理方案、升级回归存在成本。

　　

Old Gen固定阈值产生CMS Old Gen GC？
调高阈值？有担保分配失败，回退到全堆STW FGC的风险。
调大Old Gen？全堆大小不变的话挤占Young区，风险同1。
增大全堆大小？应用容器内存吃紧，有容器OOM进程被杀的风险，以及这么做只是减少了Old Gen FGC的次数，没法根治。 且存在Old区变大，CMS Old Gen GC耗时变长的风险。

　　

最终决定更换垃圾回收器为G1GC，因为G1GC默认晋升代数15代，可以使得更少的对象晋升到老年代，且支持Mixed GC增量式回收老年代垃圾。因此通过担保分配、晋升到Old区的垃圾可以通过Mixed GC清理。Mixed GC发生在YGC中，而G1的YGC又是能并发回收的，与ParNew相比具有更好的用户体验。

　　

在G1GC默认的参数基础上，使用 G1NewSizePercent 参数固定Eden下限30%，设置 InitiatingHeapOccupancyPercent 为60%，保证Eden区不会过于小影响吞吐量，留10%的余量给Mixed GC时的并发分配动作；设置 MaxGCPauseMillis 为 120ms，期望稍微牺牲停顿时间换取更大吞吐量，以及Region大小4MB：期望GC能更精细的分配及标记Region，减少空间浪费。

　　

　　

成效最终该应用发布抖动消失，FGC消失，GC耗时相比优化前（CMS）总体下降近一半。业务高峰期对象分配压力极大的时候，仍能控制在一分钟GC总耗时不超过500ms的水平下清理老年区所有死亡对象。FGC现象被彻底根治。

　　

　　

　　

首页应用发布FGC
现象闲鱼首页应用，在发布过程中每次都会存在一小批机器，在应用启动后陷入FGC，必须手动重启才能恢复；每次陷入FGC的机器IP均不重复，通过置换容器也无法解决问题。与上文提及的商品域应用不同的是，首页应用在正常运行时不会出现FGC，正常机器的JVM堆监控及GC日志显示内存分配压力不算太大，且该应用已经在使用G1GC。

　　

　　

分析查看发生FGC机器的JVM监控：

　　

可以看到，从发布开始之后，有问题的机器老年代空间持续上涨，随后出现大量的FGC。从图中的GC耗时来看，一分钟有44.4s在FGC，7.9s在YGC。总计有52.3s处于GC状态。应用基本上没法响应外界请求。

　　

从监控上看，也不难得知这是比较典型的堆内存泄漏。一般有两种情况：无用对象不释放，或者是对象存活周期由于某些原因而显著变长，导致堆里面存在大量存活对象，空间不够用。对于这种情况，通常需要借助Heap dump来观察堆里面究竟是什么对象大量占用空间。

　　

　　

从Heap dump结果中，发现堆里面存在大量的Log4j RingBufferLogEvent，也就是说，堆里有大量的Log4j异步线程没来得及消费的日志请求。而且最大的消息体竟然能到1.4M左右的大小。

　　

通过对消息体内部的字符串分析，发现这是线上某个接口的出入参日志。通过对线上请求的抓包分析，发现该接口返回的内容确实较多，平均在1M以上。而这些接口出入参，又确实需要通过打日志的方式，上报到日志平台保存起来，供排查问题使用。这种出入参记录方式在闲鱼被广泛使用，通过review打日志的代码，发现并没有什么明显的问题。因此，问题基本上与应用的代码没太大相关性。唯一值得注意的点是日志体较大，考虑从日志产生到落盘的整个流程入手分析，看整个过程是否存在性能瓶颈。

　　

闲鱼服务端应用为了提升打日志性能，降低同步调用打日志时出现IO Hang的风险，开启了Log4j的异步日志打印功能。这也是Log4j官网比较推荐的一种性能优化方式。具体原理如下图所示：

　　

　　

在正常情况下，应用代码调用日志输出方法后，传入的日志文本会被封装成一个Event，投递到Log4j内部的一个环形队列中（由 disruptor 提供，这是一种无锁跨线程通信的库，能够提供比队列更高的吞吐和更低的延迟）就立即返回。由Log4j的后台线程不断消费环形队列中的Event，将日志输出到文件上。

　　

根因最终，我们认为导致此现象发生的原因是：冷 JVM 涌入大量大日志打印请求 -> RingBuffer 大量占用堆内存 + 日志消费跟不上速度 -> 触发YGC，甚至是STW FGC -> STW FGC暂停Log4j消费写盘线程 -> 恶性循环，应用雪崩。

　　

在问题排查过程中 ，还发现首页应用使用的新版 AliJDK 在使用新版协程支持来处理线程间切换以及阻塞、唤醒调用时，存在极小概率出现调度器死循环，部分/全部线程失去响应，JVM僵死的情况。不排除协程调度器死循环可能影响Log4j日志消费线程的情况。该场景极难复现，出现时Thread dump工具、JVM Agent等诊断工具均无法连接上JVM，看不到现场，排查难度高。
此外，全协程模型带来的性能提升感知不强。因此，为了保险起见，处理此问题时，顺便也关闭了新版协程，使得JVM回退到传统的线程模型运行代码。

　　

　　

解法对于该应用的FGC问题，采取4步走策略，逐个击破：

　　

RingBuffer大量占用堆内存: 通过限制RingBuffer Slot数为一个合理值，保证应用中最大的LogEvent填满RingBuffer时也不至于把堆撑爆。本应用设置的是2048。

　　

一般情况下，该值不需要调整。因为通常情况下极少有应用会产生超大日志体。如确实需要调整此参数，需要结合应用的日志使用场景，分情况评估。

　　

JVM过冷：延长新启动机器小流量预热时长。

　　

Log4j 队列满时内存占用过大：升级Log4j到2.14.1。使用新版队列满策略，同步等待队列消费出slot。

　　

Log消费过程存在无意义的计算：对于不需要占位符替换的场景关闭占位符替换特性，提高消费速度。

　　

　　

成效应用上述策略后，发布参数调整的修复分支。效果立竿见影，此分支发布过程中无任何FGC发生。回访应用负责人，此后所有的发布均不再出现上文提及的FGC。

　　

　　

　　

玩家业务应用运行时FGC

　　

现象某玩家业务应用，使用G1GC垃圾回收器，平时集群正常承接业务流量，没有FGC，对象分配压力并不大。但是有一天集群突然出现FGC，且随着时间的推移FGC的频率越来越高。机器重启无法解决问题。

　　

　　

分析查看发生FGC机器的JVM监控，可惜监控并没能给到太多有用的信息：

　　

　　

　　

从监控上看，堆使用率、YGC次数等都比较正常，机器运行过程中老年代基本上保持在相对稳定的水位，偶尔出现FGC时，也能迅速清理掉堆中死亡对象，使得占用迅速回落到正常水位。因此基本可以排除内存泄漏、担保分配、晋升等原因而出现的缓慢上升的老年代占用。

　　

从接口QPS、RT、Load等指标看，这些指标也非常平稳，可以排除有瞬时大流量冲击机器导致爆发式业务压力产生的FGC。多次FGC之间间隔并不规律；排查过定时任务调度平台，也可以排除由于某些内存压力较大的定时任务产生的FGC。

　　

分析到这里，没有更好的办法，把目光转向FGC发生时的gc日志、应用日志，期望从日志中得到有价值的信息。

　　

查看gc日志，发现在若干次正常的YGC后，存在一次to-space exhausted：这是一次因为Eden区空间不够而产生的YGC，而在这次YGC中Survivor区也不够用。一般情况下G1GC因为会根据新生代对象存活率自适应调整Survivor区大小，基本上极少出现to-space exhausted。随后日志显示Old区占用上涨了数百MB。显然，这预示着业务中有超大对象分配。

　　

一旦知道有”超大对象”分配，方向就变得明朗了起来。G1认为占用了超过Region大小一半的连续堆空间的对象是大对象。且在大对象分配时，会给出大对象分配的调用栈。

　　

该应用中配置的Region大小为32M，一半则为16M。

　　

　　

　　

根因通过排查上述调用栈的代码，发现是一句日志打印的代码引发的血案。具体现场如下代码段所示：

　　

一个类实例里面封装着一个有非常多的Entry的Map，这个类又因为有@Data注解，lombok会为其隐式实现toString方法。而在打印日志过程中，使用 + 操作符连接字符串和对象，会默认调用对象的toString方法，将对象转化成字符串形式。

　　

该对象在没转换成字符串的时候，虽然里面的Map有非常多的Entry，但是都是分散在堆的各处的，不是连续的内存。体现为MapWrapper的支配堆空间可能很大，但是本体占用十分小。

　　

一旦调用toString方法，将对象转换成字符串形式时，就会把Map里面每个entry都转化成字符串形式保存在一个字符串里；而字符串本体需要一段连续的内存来保存char信息，因此需要一段连续的堆空间来存储这个字符串。如果Map的Entry很多，那么最终出来的字符串就会很大，当超过了一半Region大小时，G1会认为这是一个大对象，直接分配到老年代。

　　

更要命的是，底层在使用StringBuilder来append字符串，当StringBuilder需要扩容时，会创建一个新的char<>数组，并把原来的内容复制到新的char<>数组里面。如果原来的char<>数组已经是分配到老年代的大对象了，那新的char<>数组也会被分配到老年代，最终一次toString可能产生好几个驻留在老年代的大对象，尽管它们已经死亡。

　　

反映到gc日志上，即为老年代激增数百MB。

　　

可能有读者好奇，理论上一个日志对象这么大，应该能在磁盘利用率，磁盘写入IO量等指标上有所反映。而该应用设置的线上环境日志等级为WARN，这个产生了大对象分配的日志打印等级为INFO。所以这个大对象不会打到磁盘上。因此，一条根本不会被打印到磁盘上的日志，就因为一个小小的 +，就多出了大量的计算工作、内存分配，甚至导致了线上FGC的发生。

　　

　　

解法看上去复杂的问题，解法有时候反而非常简单：可以通过修改代码，使用"{}"占位符来拼接对象；也可以直接优化掉这句日志打印。

　　

　　

成效负责此业务的同学优化掉了上述日志、排查了大Map产生的业务场景并做了相关优化。修复上线后，FGC消失。

　　

　　

总结

　　

本文介绍的三则前台应用FGC问题，分别是由JVM参数、中间件配置、业务代码层面引起。三则案例监控表象、分析过程、解决方法不尽相同。但是给开发同学们的启发却是相通的。

　　

从工程层面：开发同学在写每一行代码的时候，都应该清楚这行代码的行为、包括时间、空间复杂度，以及一些极端情况下会产生的后果；开发功能时，应该充分了解业务特点，设计合适的数据结构；使用中间件，框架时，应该熟悉中间件提供的特性，遵循中间件的推荐用法，避免日后埋坑。

　　

从问题分析层面：要培养透过现象看本质的思考方式，熟悉各种监控指标的作用以及监测的对象，在出现问题的时候能够快速通过各项指标定位问题点，为快速止血及后续的修复提供方向。

　　

从技术层面：借用一句Oracle官方文档对G1回收器调优参数介绍时的总结："When you evaluate or tune any garbage collection, there is always a latency versus throughput trade-off"。GC调优的根本难点在于：找到回收吞吐量和停顿时间的平衡点。应用的平均GC吞吐量 = sum(每次GC回收的堆空间) / sum(GC运行时间)。目前市面上有很多“并发式”垃圾回收算法，允许用户线程和垃圾回收线程同时运行，以便获得更短的停顿时间。然而，停顿时间并不等于GC运行时间，如果一个GC算法虽然停顿时间很短，但是总体运行时间较长；在GC完成前，被死亡对象占用的堆空间可能是无法完全释放的，与GC线程并发运行的用户线程在这个时间段仍然会继续分配新对象，如果堆剩余空间不足以坚持到GC执行完成，就有可能因为堆空间不足，回退到STW的FGC，反而得不偿失。因此，在配置垃圾回收器的相关参数时，也需要综合考虑应用的对象分配特点，模拟线上真实业务负载，找到最合适的参数值，从而保证业务运行稳定。

　　

　　

　　

<