嘀嘀嘀~
新鲜出炉的线上bug已到账,请注意查收!!!
最近忙的头都抬不起来,都没有机会和bug好好说说话;这不线上的bug已经及时赶到,还是内存溢出的。
头疼的一批,业务都还没搞完,线上的调用第三方的服务惨遭毒手。
从服务的log日志上来看是出现了内存溢出,首先分析该服务上一次发布的内容,嗯!和自己有关(MMP~~)。但是没有引入什么大组件,仅仅只是新接入了几个访问第三方的接口,按照常理来说应该不会出问题。
好了,既然是内存溢出,那肯定是有大对象出现,这时候看看服务器CPU,1000% 好家伙~
通过线程ID定位到具体的线程发现是GC出了问题,那么这次CPU飙高和内存溢出都是因为服务中出现大对象导致的。
按照之前的处理经验:
先分析GC次数:
好家伙,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相关的文章资料,有需要可以百度先了解一下大概,还是不清楚可以留言交流
不说了老表上图!
这个就是工具分析出来的,这里先定位关键信息 :
- AtomicLong这个实例占用的总数最多达到了1500W。
- 其次需要关注的就是MonitorConfig(一开始我也没注意到这,因为这些压根我都没有咋了解过,但是这个类是关键)
仅仅知道这俩个类是不够的,因为还不知道这俩货是用来干啥的~ 头疼.
这个时候只能一步步分析它的引用,由于AtomicLong占用的最多,那么需要定位引用它的实例是谁!
选中最大的对象,右键选择Use Retained Objects
选择References,查看引用,点击OK。
过程可能需要一些等待 稍安勿躁
分析结果:
这里面已经列出来的大部分对象,我们只关注他是怎么产生的、被谁引用的。
选择第一个对象一直往下找:
请注意这两个类,从名字上看就是两个拦截器;
这两个类都是属于Cloud体系里面的用来做监控指标相关的。
然后大概看了下两个类的代码:
都是出自:MetricsInterceptorConfiguration
配置类加载。
两个类都是负责拦截请求,根据请求时间、返回状态码做汇总。
这里被开启的条件是应用中使用了RestTemplate
,联想到溢出的服务上个应用就是对接第三方加入了RestTemplate
类,但是问题来了,RestTemplate在我们服务中已经大规模应用都没有出现过问题,为什么会出现内存溢出的情况呢?
看看MetricsClientHttpRequestInterceptor
源码他是怎么做的:
- 首先实现了ClientHttpRequestInterceptor类,在Spring层层处理下,每次使用RestTemplate发起调用都会被该标识的接口实现拦截。
- 拦截之后,根据请求的参数进行打标记来标识这一组请求类型,其实就是Map<标记,值>,因为他要将请求归类分组!
- 所有数据归类完之后保存到
ServoMonitorCache
中去,这个类负责统计该URL相关的【最大值、最小值、请求总数】 - 既然是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
由于我们压根都不需要这个类,直接就给关了。后续再继续关注一下~