纯干货:内存溢出通过Jprofile排查思路以及实践总结

系统管理员 2021-09-12 01:14 679阅读 0赞

> 嘀嘀嘀~  
> 新鲜出炉的线上bug已到账，请注意查收!!!!

最近忙的头都抬不起来，都没有机会和bug好好说说话；这不线上的bug已经及时赶到，还是内存溢出的。

头疼的一批，业务都还没搞完，线上的调用第三方的服务惨遭毒手。

从服务的log日志上来看是出现了内存溢出，首先分析该服务上一次发布的内容，**嗯！和自己有关**(MMP~~)。但是没有引入什么大组件,仅仅只是新接入了几个访问第三方的接口，按照常理来说应该不会出问题。

好了，既然是内存溢出，那肯定是有大对象出现，这时候看看服务器CPU，**1000%** 好家伙~  
通过线程ID定位到具体的线程发现是GC出了问题，那么这次CPU飙高和内存溢出都是因为服务中出现大对象导致的。

按照之前的处理经验:

*  [纯干货:线上出现fullGC次数很多的排查思路以及实践总结][fullGC]
 *  [纯干货:大对象导致FullGC频繁的原因及实践思路][FullGC]

先分析GC次数:

![6370985-464a30c04792c4c8][]

在这里插入图片描述

**好家伙，Full GC的真勤快~**

**老年代几乎被占满了。**

### 通过jmap定位内存实例占用排名 ###

jmap -histo [pid] | sort -n -r -k 2 | head -10

> 不好意思，这里没有保留事故现场，里面列举出来第一名是AtomicLong。

单单根据这个实例排名没有发现特别有效的信息，因为都不是业务里面类，而是SpringCloud里面相关的。  
这个方法如果发现不是自定义的业务类引起的，就得想办法生成dump文件去做具体的分析实例相关的引用。

### 通过dump进行分析 ###

jmap -dump:format=b,file=dump.hprof 15889 // [pid]    // 生成hprof 文件

这里通过MAT分析该hprof文件的时候出现了问题

> mat分析的过程可以参考文中的纯干货大对象链接

java.lang.OutOfMemoryError: GC overhead limit exceeded
        at org.eclipse.mat.hprof.HprofParserHandlerImpl.resolveClassHierarchy(HprofParserHandlerImpl.java:654)
        at org.eclipse.mat.hprof.Pass2Parser.readInstanceDump(Pass2Parser.java:207)
        at org.eclipse.mat.hprof.Pass2Parser.readDumpSegments(Pass2Parser.java:161)
        at org.eclipse.mat.hprof.Pass2Parser.read(Pass2Parser.java:91)
        at org.eclipse.mat.hprof.HprofIndexBuilder.fill(HprofIndexBuilder.java:94)
        at org.eclipse.mat.parser.internal.SnapshotFactoryImpl.parse(SnapshotFactoryImpl.java:222)
        at org.eclipse.mat.parser.internal.SnapshotFactoryImpl.openSnapshot(SnapshotFactoryImpl.java:126)
        at org.eclipse.mat.snapshot.SnapshotFactory.openSnapshot(SnapshotFactory.java:145)
        at org.eclipse.mat.internal.apps.ParseSnapshotApp.parse(ParseSnapshotApp.java:134)
        at org.eclipse.mat.internal.apps.ParseSnapshotApp.start(ParseSnapshotApp.java:106)
        at org.eclipse.equinox.internal.app.EclipseAppHandle.run(EclipseAppHandle.java:196)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.runApplication(EclipseAppLauncher.java:134)
        at org.eclipse.core.runtime.internal.adaptor.EclipseAppLauncher.start(EclipseAppLauncher.java:104)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:388)
        at org.eclipse.core.runtime.adaptor.EclipseStarter.run(EclipseStarter.java:243)
        at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
        at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
        at java.lang.reflect.Method.invoke(Method.java:498)
        at org.eclipse.equinox.launcher.Main.invokeFramework(Main.java:656)
        at org.eclipse.equinox.launcher.Main.basicRun(Main.java:592)
        at org.eclipse.equinox.launcher.Main.run(Main.java:1498)
        at org.eclipse.equinox.launcher.Main.main(Main.java:1471)

完了，分析不出来！！！！  
这个时候我还以为是linux的mat工具不行了，然后通过压缩hprof文件，下载到本地然后再进行分析，然而。。。也还是不行！！！

但是!!!!! **由于本人平常喜欢捣鼓一些性能工具，意外在电脑上发现`jprofile`可以分析该文件。**

有了分析的工具那么其他就好说了,至少有线索，（**尽管我对这个工具用的不是很熟~~**）

> 关于Jprofile相关的文章资料，有需要可以百度先了解一下大概，还是不清楚可以留言交流

不说了老表上图!

![6370985-4c61a9c992aad70d][]

在这里插入图片描述

这个就是工具分析出来的，这里先定位关键信息 ：

*  AtomicLong这个实例占用的总数最多达到了1500W。
 *  其次需要关注的就是MonitorConfig（**一开始我也没注意到这，因为这些压根我都没有咋了解过,但是这个类是关键**）

仅仅知道这俩个类是不够的,因为还不知道这俩货是用来干啥的~ 头疼.

**这个时候只能一步步分析它的引用，由于AtomicLong占用的最多，那么需要定位引用它的实例是谁！**

选中最大的对象，右键选择**Use Retained Objects**

![6370985-4bffb3fd20d05e8d][]

在这里插入图片描述

选择References，查看引用，点击OK。

![6370985-9b497444692173a1][]

在这里插入图片描述

过程可能需要一些等待 **稍安勿躁**

分析结果:

![6370985-110fefe182a862ab][]

在这里插入图片描述

这里面已经列出来的大部分对象， **我们只关注他是怎么产生的、被谁引用的。**  
选择第一个对象一直往下找:

![6370985-81fa55616964c4ae][]

在这里插入图片描述

请注意这两个类，从名字上看就是两个拦截器；  
这两个类都是属于Cloud体系里面的用来做监控指标相关的。

然后大概看了下两个类的代码:  
都是出自:`MetricsInterceptorConfiguration`配置类加载。  
两个类都是负责拦截请求，根据请求时间、返回状态码做汇总。  
这里被开启的条件是应用中使用了`RestTemplate`，联想到溢出的服务上个应用就是对接第三方加入了`RestTemplate`类,但是问题来了,RestTemplate在我们服务中已经大规模应用都没有出现过问题，为什么会出现内存溢出的情况呢？

看看`MetricsClientHttpRequestInterceptor`源码他是怎么做的:

1.  首先实现了ClientHttpRequestInterceptor类，在Spring层层处理下，每次使用RestTemplate发起调用都会被该标识的接口实现拦截。
2.  拦截之后，根据请求的参数进行打标记来标识这一组请求类型，**其实就是Map<标记，值>，因为他要将请求归类分组！**
3.  所有数据归类完之后保存到`ServoMonitorCache`中去，这个类负责统计该URL相关的【最大值、最小值、请求总数】
4.  既然是Map结构，那么Key的命中率非常重要，如果命中率非常差，那么就会命中不了，命中不了就添加，然后值就越来越多！！！

这里简单贴一段代码:

public synchronized BasicTimer getTimer(MonitorConfig config) {
            // 根据外面传递进来的config配置，里面的tags属性存储了参数
            BasicTimer t = this.timerCache.get(config);
            if (t != null)
                return t;
            
            t = new BasicTimer(config);
            // 查找不到则进行缓存..
            this.timerCache.put(config, t);
    
            if (this.timerCache.size() > this.config.getCacheWarningThreshold()) {
                log.warn("timerCache is above the warning threshold of " + this.config.getCacheWarningThreshold() + " with size " + this.timerCache.size() + ".");
            }
    
            this.monitorRegistry.register(t);
            return t;
        }

看完这个功能之后联想到之前上线的功能，大概了解了溢出的原因：

*  我们上一次发版的内容就是新加了一个对接第三方的接口，该第三方给到我们的API都是GET请求类型的参数.
 *  然后**GET请求URL**上面的参数可能是**动态**的(**每次请求参数里面都带了时间戳**)，导致每次拦截器汇总的时候，命中不了，所以一直添加，由于是Map结构又是Spring的单例模式，GC压根就回收不了这玩意，导致了内存溢出！

其他应用的RestTemplate都没有出问题的原因是我们都用到是post请求，URL是固定的。不会缓存参数。即便是GET请求参数变化的概率不大！

后面经过本地模拟这种情况证实了想法，诶~ 要了命了。  
我也不知道这算不算Bug~

解决的方案也很简单，通过`MetricsInterceptorConfiguration` 我们知道它默认是开启的，但是也可以在配置文件中进行关闭：

spring:
        cloud:
            netflix:
                metrics:
                    enabled: false

由于我们压根都不需要这个类，直接就给关了。后续再继续关注一下~

[fullGC]: https://links.jianshu.com/go?to=https%3A%2F%2Feditor.csdn.net%2Fmd%2F%3FarticleId%3D104906673
[FullGC]: https://links.jianshu.com/go?to=https%3A%2F%2Feditor.csdn.net%2Fmd%2F%3FarticleId%3D105009840
[6370985-464a30c04792c4c8]: /images/20210811/a4296920faa948a2b606a76573410cb9.png
[6370985-4c61a9c992aad70d]: /images/20210811/dfa086030e984d0eb67b3cc2d4122eaf.png
[6370985-4bffb3fd20d05e8d]: /images/20210811/126b702392394f6d98a3e28d801f7a5d.png
[6370985-9b497444692173a1]: /images/20210811/66dbde58b1d345c9a7b29083f3d7d109.png
[6370985-110fefe182a862ab]: /images/20210811/fb17b8378401447fa8d7b7ab95a4c10f.png
[6370985-81fa55616964c4ae]: /images/20210811/b02958eddba7478b921aa5b58fdfae88.png