线上 FullGC 问题排查实践 —— 手把手教你排查线上问题

一、问题发现与排查

1.1 找到问题原因

问题起因是我们收到了 jdos 的容器 CPU 告警，CPU 使用率已经达到 104%

观察该机器日志发现，此时有很多线程在执行跑批任务。正常来说，跑批任务是低 CPU 高内存型，所以此时考虑是 FullGC 引起的大量 CPU 占用（之前有类似情况，告知用户后重启应用后解决问题）。

通过泰山查看该机器内存使用情况：

可以看到 CPU 确实使用率偏高，** 但是内存使用率并不高，只有 62%，** 属于正常范围内。

到这里其实就有点迷惑了，按道理来说此时内存应该已经打满才对。

后面根据其他指标，例如流量的突然进入也怀疑过是 jsf 接口被突然大量调用导致的 cpu 占满，所以内存使用率不高，不过后面都慢慢排除了。其实在这里就有点一筹莫展了，现象与猜测不符，只有 CPU 增长而没有内存增长，** 那么什么原因会导致单方面 CPU 增长？** 然后又朝这个方向排查了半天也都被否定了。

后面突然意识到，会不会是监控有 “问题”？

换句话说应该是我们看到的监控有问题，这里的监控是机器的监控，而不是 JVM 的监控！

JVM 的使用的 CPU 是在机器上能体现出来的，而 JVM 的堆内存高额使用之后在机器上体现的并不是很明显。

遂去 sgm 查看对应节点的 jvm 相关情况：

可以看到我们的堆内存老年代确实有过被打满然后又清理后的情况，查看此时的 CPU 使用情况也可以与 GC 时间对应上。

那么此时可以确定，是 Full GC 引起的问题。

1.2 找到 FULL GC 的原因

我们首先 dump 出了 gc 前后的堆内存快照，

然后使用 JPofiler 进行内存分析。（JProfiler 是一款堆内存分析工具，可以直接连接线上 jvm 实时查看相关信息，也可以分析 dump 出来的堆内存快照，对某一时刻的堆内存情况进行分析）

首先将我们 dump 出来的文件解压，修改后缀名.bin，然后打开即可。（我们使用行云上自带的 dump 小工具，也可以自己去机器上通过命令手工 dump 文件）

首先选择 Biggest Objects，查看当时堆内存中最大的几个对象。

从图中可以看出，四个 List 对象就占据了近 900MB 的内存，而我们刚刚看到堆内存最大也只有 1.3GB，因此再加上其他的对象，很容易就会把老年代占满引发 full gc 的问题。

选择其中一个最大的对象作为我们要查看的对象

这个时候我们已经可以定位到对应的大内存对象对应的位置：

其实至此我们已经能够大概定位出问题所在，如果还是不确定的话，可以查看具体的对象信息，方法如下：

可以看到我们的大 List 对象，其实内部是很多个 Map 对象，而每个 Map 对象中又有很多键值对。

在这里也可以看到 Map 中的相关属性信息。

也可以在以下界面直接看到相关信息：

然后一路点下去就可以看到对应的属性。

至此，我们理论上已经找到了大对象在代码中的位置。

二、问题解决

2.1 找到大对象在代码中的位置与问题的根本原因

首先我们根据上述过程找到对应位置与逻辑

我们的项目中大概逻辑是这样的：

1. 首先会解析用户上传的 Excel 样本，并将其加载到内存中作为一个 List 变量，即我们上述看到的变量。一个 20w 的样本，此时字段数量有 a 个，大概占用空间 100mb 左右。
2. 然后遍历循环用户样本，根据用户样本中的数据，再增加一些额外的请求数据，根据此数据请求相关结果。此时字段数量有 a+n 个，占用空间已经在 200mb 左右。
3. 循环完成后将此 200mb 的数据存入缓存。
4. 开始生成 excel，将 200mb 数据从缓存中取出，并根据之前记录的 a 个字段，取出初始的样本字段填充至 excel。

用流程图表示为：

结合一些具体排查问题的图片：

其中一个现象是每次 gc 后的最小内存正在逐步变大，对应上述步骤中第二步，内存正在逐步膨胀。

结论：

将用户上传的 excel 样本加载到内存中，并将其作为一个 List<Map<String, String>> 的结构存储起来，首先一个 20mb 的 excel 文件以此方式存储会膨胀占用 120mb 左右堆内存，此步骤会大量占用堆内存，并且因为任务逻辑原因，该大对象内存会在 jvm 中存在长达 4-12 小时之久，导致一但任务过多，jvm 堆内存很容易被打满。

这里列举了为什么使用 HashMap 会导致内存膨胀，其主要原因是存储空间效率比较低：

一个 Long 对象占内存计算：在 HashMap<Long，Long> 结构中，只有 Key 和 Value 所存放的两个长整型数据是有效数据，共 16 字节（2×8 字节）。这两个长整型数据包装成 java.lang.Long 对象之后，就分别具有 8 字节的 MarkWord、8 字节的 Klass 指针，再加 8 字节存储数据的 long 值（一个包装对象占 24 字节）。

然后这 2 个 Long 对象组成 Map.Entry 之后，又多了 16 字节的对象头（8 字节 MarkWord+8 字节 Klass 指针 = 16 字节），然后一个 8 字节的 next 字段和 4 字节的 int 型的 hash 字段（8 字节 next 指针 + 4 字节 hash 字段 + 4 字节填充 = 16 字节），为了对齐，还必须添加 4 字节的空白填充，最后还有 HashMap 中对这个 Entry 的 8 字节的引用，这样增加两个长整型数字，实际耗费的内存为 (Long (24byte)×2)+Entry (32byte)+HashMapRef (8byte)=88byte，空间效率为有效数据除以全部内存空间，即 16 字节 / 88 字节 = 18%。

——《深入理解 Java 虚拟机》5.2.6

以下是刚上传的 excel 中 dump 出的堆内存对象，其占用的内存达到了 128mb，而上传的 excel 实际只有 17.11mb。

空间效率 17.1mb/128mb≈13.4%

2.2 如何解决此问题

暂且不讨论上述流程是否合理，解决办法一般可以分为两类，一类是治本，即不把该对象放入 jvm 内存中，转而存入缓存中，不在内存中则大对象问题自然迎刃而解。另一类是治标，即缩小该大内存对象，在日常使用场景下使其一般不会触发频繁的 full gc 问题。

两种方式各有优劣：

2.2.1 激进治疗：不把他存入内存

解决逻辑也很简单，例如在加载数据时，将其按照样本加载数据一条一条存入 redis 缓存，然后我们只需要知道样本中有多少的数量，按照数量的先后顺序从缓存中取出数据，即可解决该问题。

优点：可以从根本上解决此问题，以后基本上不会存在该问题，数据量再大只需要添加相应的 redis 资源即可。

缺点：首先会增加许多 redis 缓存空间消耗，其次从显示考虑对于我们项目来说，此处代码古老且晦涩难懂，改动需要较大工作量与回归测试。

2.2.2 保守治疗：缩减其数据量

分析 2.1 的上述流程，首先第三步是完全没必要的，先存入缓存再取出，额外占用缓存空间。（猜测系历史问题，此处不再深究）。

其次是在第二步中，多出来的字段 n，在请求结束后该字段就已经无用了，因此可以考虑在请求结束后删除无用字段。

此时也有两种解决方案，一种是只删除无用字段缩减其 map 大小，然后将其作为参数传递给生成 excel 使用；另一种方式是请求完成直接删除该 map，然后在生成 excel 时再重新读取用户上传的 excel 样本。

优点：改动较小，不需要太复杂的回归测试

缺点：在极端大数据量情况下，仍有可能出现 full gc 的情况

具体实现方式就不展开了。

其中一种实现方式

//获取有用的字段
String[] colEnNames = (String[]) colNameMap.get(Constant.BATCH_COL_EN_NAMES);
List<String> colList = Arrays.asList(colEnNames);
//去除无用的字段
param.keySet().removeIf(key -> !colList.contains(key));

三、拓展思考

首先本文中监控图是在复现当时场景时人为制造的 gc 常见。

在 cpu 使用率图中，大家可以观察到 cpu 使用率上升时间确实跟 gc 的时间相吻合，但是并没有出现当时场景中的 104% 的 CPU 使用率。

其实直接原因比较简单，就是因为系统虽然出现了 full gc，但是并没有频繁出现。

小范围低频率的 full gc 不太会引起系统的 cpu 飙升，这也是我们所看到的现象。

那么当时的场景是什么原因呢？

我们上文提到过，我们在堆内存中的大对象是会随着任务的进行逐步膨胀的，那么当我们的任务足够多，时间足够长，就有可能导致每次 full gc 后可用空间变得越来越小，当可用空间小到一定程度之后就，每次 full gc 完成之后发现空间还是不够使用，就会触发下一次的 gc，从而导致最终结果的频繁发生 gc，引起 cpu 频率的飙升不下。

四、问题排查总结

• 当我们遇到线上 cpu 使用率过高的情况时，可以先查看是否是 full gc 引起的问题，注意要看的是 jvm 的监控，或者使用 jstat 相关命令查看。不要被机器内存监控所误导。
• 如果确定是 gc 引起的问题，可以通过 JProfiler 直连线上 jvm 或者使用 dump 保存堆快照后离线分析。
• 首先可以找到最大的对象，一般情况下是大对象引起的 full gc。还有一种情况是，不像这么明显是四个大对象，也可能是比较均衡的十几个 50mb 的对象，具体情况还需要具体分析。
• 通过上述工具找到确定有问题的对象后找到其堆栈对应的代码位置，通过代码分析找到问题的具体原因，通过其他现象推演猜测是否正确，进而找到问题的真正原因。
• 根据问题的原因解决此问题。

当然，上述只是不算很复杂的排查情况，不同的系统肯定有不同的内存情况，我们应当具体问题具体分析，而从此次问题中可以学到的就是如果排查解决问题的思路。

原文：

https://my.oschina.net/u/4090830/blog/8704836