回忆录：一次GC引发的产品事故

背景

事故发生在某个工作日下午，初诊症状为页面响应时间巨长，没有任何反应，页面一直处于加载状态中，根据后端监控平台显示，相关服务的所有实例CPU占用率达到100%，为了快速恢复服务，及时止损，果断决定在负载均衡后，依次重启一半的实例，然后再进一步观察是否能处理正常的业务流量，不幸中的万幸，这招管用了，如果不管用，可能就需要通过蓝绿部署进行回滚操作了（但这样会将最新版本的一些功能进行回滚）。但这种管用是临时还是永久的呢？

根因分析

难道万能的重启大法能治百病？当然不是，任何一次产品事故都是难道的学习机会，往往这样的经验还非常的宝贵，于是根因分析必不可少。我们很快在服务暂时恢复正常后，即刻开始了进一步的调查工作？通过分布式追踪平台，很快定位到了调用链上面有问题的服务，针对有问题的服务进行进一步分析，CPU占用率100%往往只是表象，导致它的原因才是我们真正关心的点；如下图，根据可视化的日志，发现频繁的Full GC占用了大量的CPU时间片，并且Stop the world，挂起了应用进程，导致服务可用性的降低：

在GC策略上面，我们的服务默认都是选择的CMS，在可达性分析的时候, 一般会经历下面三个阶段：

初始标记（只标记与GC Root直接相关的节点，单GC线程, 短暂的应用停顿）
并发标记（GC进程和业务进程并发运行，没有停顿应用）
重新标记 （防止并发标记过程中，业务进程的更改，并行重新标记和修复，短暂的应用停顿）

整个过程，对比其他类型的GC回收策略（除G1外，JAVA9的默认策略），CMS减少回收停顿时间，应用停顿时间应该更短，可用性更高。

那是什么导致的Full GC呢？

显示调用system.gc()?
内存不足？
统计得到的Minor GC晋升到老年代的平均大小大于老年代的剩余空间？

诊断结果为内存不足造成的，那么内存不足又分为不同类型的内存，比如JVM 堆内存（GC主要回收的地方），栈内存，Native内存。

更加进一步的分析为metaspace，Java8后引入了metaspace替换掉了持久代，最主要的不同在于metaspace是直接在Native内存里面分配，不在heap上面，默认可以动态伸缩，具有更高的自由度，具体大小与主机内存有关，当然你也可以通过下面参数设置它的大小-XX:MaxMetaspaceSize。

如下图， metaspace的空间随着时间的推移，逐步增加，直到服务器重启后才得到释放。

为什么会造成metaspace leak？

根据上面的我们掌握的信息，我们已经可以断定，同样的问题，随着时间的推移，还会不断重现。由于我们进行了如下的步骤：

问题重现，在产品环境下，将产品日志经过一定清洗之后（保证操作不会产生脏数据或者副作用），下载下来，通过Jmeter模拟多用户并发访问的真实场景，访问Inactive的服务实例，随着访问量的上升，加速事故重现的概率。
内存泄露分析，多次下载heap dump，分析泄露的classes或者classloaders，最后发现了大量的类似class，被重复加载。
二分法排错，在代码级别上面，进行二分法排错，最后锁定了问题。

根本原因：在某次发布时，升级了一个包，那个包里面包含了一个很老版本的JAXB库，由于历史原因没有遵守maven version的规范，它的version类似2.X.X.1，而不是正常的release version格式：major.minor.bugfix，于是maven在处理版本冲突的时候，选择了较老版本的库，最后这个库，在具体的业务场景下，不断的重复创建并加载相关的类信息，不断占用metaspace的空间, 导致Full GC，造成100%CPU。