一次频繁full gc引发的问题排查
一次频繁full gc引发的问题排查
一、背景
刚发布的应用，间隔8小时不到，就开始告警，告警的位置还很特殊，属于调用外组接口的位置，让人费解。
最后查明原因，是大对象造成频繁full gc，这里，记录下排查问题的过程。
如果大家正在寻找一个java的学习环境，或者在开发中遇到困难，可以加入我们的java学习圈，点击即可加入，共同学习，节约学习时间，减少很多在学习中遇到的难题。
二、初排查
2.1 看链路
报错的位置很奇葩，锅彷佛在外组身上，由于公司接入了skywalking，于是去看下skywalking的链路跟踪日志：
全都是几十毫秒，看不出啥，公司的skywalking也忒垃圾。没办法，去diss下外组人员，你家的接口怎么这么稀烂，看把我们应用搞成啥样了。
然而，仔细一看，另外一个外组的接口也这么慢，不正常啊。
再看下其他机器是正常的，只有两台机器是不正常的，那就不太可能是外组的接口问题了，要从自身找原因。
2.2 看性能
看下机器的监控信息
- 机器的信息看起来很正常，内存CPU都没打满，会不会是设置的最大内存小了？
ps -ef | grep java看下jvm的参数，一看也是正常的。 - skywalking的监控信息也看下，发现两台机器在搞事情，gc很频繁。
所以可能是机器有问题？换个机器试试。因为是docker实例，随手可换。
三、找具体原因
docker实例重建无果，剩下的几台实例陆陆续续也告警了，这多半是代码问题了。
先看下内存使用情况：jstat -gcutil 8
full gc这么高，肯定是有内存泄漏。要么是大对象，要么是流没关。
然后坑继续：
- 生成java 堆信息报告：jmap -dump:format=b,file=heap.dump 导出了文件，但实在太大了，5个G，下载三分之一就会断掉，不得不重下。
- 使用jmap -histo:live 查看，最大的[I，int数组，看不出来是什么。
没办法，先猜测一波，是不是流没关呢？用了Okhttp的异步操作，一看异步操作果然没显式去关闭，如获至宝，close调起。发布等待中。
结果，八个小时不到，又开始了。原来，OkHttp的string()方法，finally里调用了Util.closeQuietly(source)，是可以自动关闭流的。
四、问题解决
没办法，肯定是大对象了，只不过大对象在哪儿？只能去看dump文件。
4.1 下载dump文件
先想办法下载dump文件，5个G虽然大，分成10个文件下载还是能接受的。
split -b 700M -a 1 heap.dump heap.dump. 分割之后，出现8个文件，下载之。
4.2 合并文件
下载完成之后，合并文件。在windows上，可以打开git bash窗口(Linux环境即可)。输入命令：
cat heap.dump.* > heap.dump 还原heap.dump文件。
4.3 打开dump文件
分析dump文件，文章好多，当然先找个最简单的，用jdk自带的jvisualvm。
可是它有点不争气，一直在分析，卡在界面不动，不知所谓。
换个eclipse mat试试。先考虑用插件，在eclipse的marketplase里面下载，然而就是下载不了，弃之，直接下载mat：http://www.eclipse.org/mat/ 下载之，解压，双击，提示jdk至少要11，想换个低版本，但是谁知道哪个版本可以兼容jdk1.8的，不如下载jdk11来的快，下载之。
修改MemoryAnalyzer.ini指定jdk11：
-vm
C:/Program Files/Java/jdk-11/bin/javaw.exe启动成功。但是会出现以下错误：
- 内存不够，内存分配要大于文件大小，-vmargs 调整
-Xmx10240m，足够大 - 磁盘要够，index文件也要好几个G。
打开：
4.4 指标分析
全英文，太难了。下面是一些常用的指标的解释：
- Histogram可以列出内存中每个对象的名字、数量以及大小。
- Dominator Tree会将所有内存中的对象按大小进行排序，并且我们可以分析对象之间的引用结构。
- Leak Suspects Report：内存泄露报告，Leak Suspects 是MAT帮我们分析的可能有内存泄露嫌疑的地方，可以体现出哪些对象被保持在内存中，以及为什么它们没有被垃圾回收
- List objects --> with outgoing references 查看当前对象持有的外部对象引用（在对象关系图中为从当前对象指向外的箭头）
- List objects --> with incoming references 查看当前对象被哪些外部对象所引用（在对象关系图中为指向当前对象的箭头）
- Shallow Heap：当前对象自己所占内存的大小，不包含引用关系的
- Retained Heap：对象以及它所持有的其它引用（包括直接和间接）所占的总内存
- 首先打开了Leak Suspects Report。
高端大气看不懂！看这个报告还以为是logback有问题，其实并不是。
- 换个Histogram视图：
高端大气还是看不懂！就认识一个AES。这让我到哪儿说理去。
- 换个Dominator Tree视图：
一下子就看到了可以定位的的AESStack方法。找到它。
4.5 结果分析
class AESStack {
private ConcurrentLinkedQueue<AES> queue = new ConcurrentLinkedQueue<>();
public static final AESStack INSTANCE = new AESStack();
public void init(int num) {
int count = Math.min(Math.max(0, num), 500);
for (int i = 0; i < count; i++) {
queue.offer(new AES(AES.genAesKey()));
}
}在这里，每次init的时候会生成num个AES对象，存入queue中，而调用方是另外一个类的构造函数。是创建thrift客户端的代码。
这段代码逻辑上是没有问题的，但是创建的客户端只能作为全局变量被创建一次，如果作为局部变量被创建多次，就会产生内容泄漏。而我们的代码就是将用写在方法中，因此产生了内存泄漏。
五、结论
没有结论是不完整的，但是这种full gc，其实就是查找内存泄漏的位置，需要借助于工具。而本次内存泄漏的原因，主要在于公司的基础组件太烂，在一个很普通的实体中写了一个不普通的连接池，而文档不健全，导致调用方难以及时发现其实隐藏的风险。