嘀嘀嘀~
新鮮出爐的線上bug已到賬叼耙,請(qǐng)注意查收!!!!
最近忙的頭都抬不起來,都沒有機(jī)會(huì)和bug好好說說話执隧;這不線上的bug已經(jīng)及時(shí)趕到,還是內(nèi)存溢出的户侥。
頭疼的一批殴玛,業(yè)務(wù)都還沒搞完,線上的調(diào)用第三方的服務(wù)慘遭毒手添祸。
從服務(wù)的log日志上來看是出現(xiàn)了內(nèi)存溢出滚粟,首先分析該服務(wù)上一次發(fā)布的內(nèi)容,嗯刃泌!和自己有關(guān)(MMP~~)凡壤。但是沒有引入什么大組件,僅僅只是新接入了幾個(gè)訪問第三方的接口,按照常理來說應(yīng)該不會(huì)出問題耙替。
好了亚侠,既然是內(nèi)存溢出,那肯定是有大對(duì)象出現(xiàn)俗扇,這時(shí)候看看服務(wù)器CPU硝烂,1000% 好家伙~
通過線程ID定位到具體的線程發(fā)現(xiàn)是GC出了問題,那么這次CPU飆高和內(nèi)存溢出都是因?yàn)榉?wù)中出現(xiàn)大對(duì)象導(dǎo)致的铜幽。
按照之前的處理經(jīng)驗(yàn):
先分析GC次數(shù):
好家伙滞谢,F(xiàn)ull GC的真勤快~
老年代幾乎被占滿了。
通過jmap定位內(nèi)存實(shí)例占用排名
jmap -histo [pid] | sort -n -r -k 2 | head -10
不好意思除抛,這里沒有保留事故現(xiàn)場(chǎng)狮杨,里面列舉出來第一名是AtomicLong。
單單根據(jù)這個(gè)實(shí)例排名沒有發(fā)現(xiàn)特別有效的信息到忽,因?yàn)槎疾皇菢I(yè)務(wù)里面類橄教,而是SpringCloud里面相關(guān)的。
這個(gè)方法如果發(fā)現(xiàn)不是自定義的業(yè)務(wù)類引起的,就得想辦法生成dump文件去做具體的分析實(shí)例相關(guān)的引用护蝶。
通過dump進(jìn)行分析
jmap -dump:format=b,file=dump.hprof 15889 // [pid] // 生成hprof 文件
這里通過MAT分析該hprof文件的時(shí)候出現(xiàn)了問題
mat分析的過程可以參考文中的純干貨大對(duì)象鏈接
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)
完了华烟,分析不出來!3只摇?呀!
這個(gè)時(shí)候我還以為是linux的mat工具不行了搅方,然后通過壓縮hprof文件比吭,下載到本地然后再進(jìn)行分析,然而姨涡。衩藤。。也還是不行L纹I捅怼!
但是!!!!! 由于本人平常喜歡搗鼓一些性能工具匈仗,意外在電腦上發(fā)現(xiàn)jprofile
可以分析該文件瓢剿。
有了分析的工具那么其他就好說了,至少有線索,(盡管我對(duì)這個(gè)工具用的不是很熟~~)
關(guān)于Jprofile相關(guān)的文章資料悠轩,有需要可以百度先了解一下大概间狂,還是不清楚可以留言交流
不說了老表上圖!
這個(gè)就是工具分析出來的,這里先定位關(guān)鍵信息 :
- AtomicLong這個(gè)實(shí)例占用的總數(shù)最多達(dá)到了1500W火架。
- 其次需要關(guān)注的就是MonitorConfig(一開始我也沒注意到這鉴象,因?yàn)檫@些壓根我都沒有咋了解過,但是這個(gè)類是關(guān)鍵)
僅僅知道這倆個(gè)類是不夠的,因?yàn)檫€不知道這倆貨是用來干啥的~ 頭疼.
這個(gè)時(shí)候只能一步步分析它的引用,由于AtomicLong占用的最多何鸡,那么需要定位引用它的實(shí)例是誰(shuí)纺弊!
選中最大的對(duì)象,右鍵選擇Use Retained Objects
選擇References骡男,查看引用淆游,點(diǎn)擊OK。
過程可能需要一些等待 稍安勿躁
分析結(jié)果:
這里面已經(jīng)列出來的大部分對(duì)象隔盛,我們只關(guān)注他是怎么產(chǎn)生的犹菱、被誰(shuí)引用的。
選擇第一個(gè)對(duì)象一直往下找:
請(qǐng)注意這兩個(gè)類骚亿,從名字上看就是兩個(gè)攔截器已亥;
這兩個(gè)類都是屬于Cloud體系里面的用來做監(jiān)控指標(biāo)相關(guān)的。
然后大概看了下兩個(gè)類的代碼:
都是出自:MetricsInterceptorConfiguration
配置類加載来屠。
兩個(gè)類都是負(fù)責(zé)攔截請(qǐng)求,根據(jù)請(qǐng)求時(shí)間、返回狀態(tài)碼做匯總俱笛。
這里被開啟的條件是應(yīng)用中使用了RestTemplate
捆姜,聯(lián)想到溢出的服務(wù)上個(gè)應(yīng)用就是對(duì)接第三方加入了RestTemplate
類,但是問題來了,RestTemplate在我們服務(wù)中已經(jīng)大規(guī)模應(yīng)用都沒有出現(xiàn)過問題,為什么會(huì)出現(xiàn)內(nèi)存溢出的情況呢迎膜?
看看MetricsClientHttpRequestInterceptor
源碼他是怎么做的:
- 首先實(shí)現(xiàn)了ClientHttpRequestInterceptor類泥技,在Spring層層處理下,每次使用RestTemplate發(fā)起調(diào)用都會(huì)被該標(biāo)識(shí)的接口實(shí)現(xiàn)攔截磕仅。
- 攔截之后珊豹,根據(jù)請(qǐng)求的參數(shù)進(jìn)行打標(biāo)記來標(biāo)識(shí)這一組請(qǐng)求類型,其實(shí)就是Map<標(biāo)記榕订,值>店茶,因?yàn)樗獙⒄?qǐng)求歸類分組!
- 所有數(shù)據(jù)歸類完之后保存到
ServoMonitorCache
中去劫恒,這個(gè)類負(fù)責(zé)統(tǒng)計(jì)該URL相關(guān)的【最大值贩幻、最小值、請(qǐng)求總數(shù)】 - 既然是Map結(jié)構(gòu)两嘴,那么Key的命中率非常重要丛楚,如果命中率非常差,那么就會(huì)命中不了憔辫,命中不了就添加趣些,然后值就越來越多!7∧喧务!
這里簡(jiǎn)單貼一段代碼:
public synchronized BasicTimer getTimer(MonitorConfig config) {
// 根據(jù)外面?zhèn)鬟f進(jìn)來的config配置,里面的tags屬性存儲(chǔ)了參數(shù)
BasicTimer t = this.timerCache.get(config);
if (t != null)
return t;
t = new BasicTimer(config);
// 查找不到則進(jìn)行緩存..
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;
}
看完這個(gè)功能之后聯(lián)想到之前上線的功能枉圃,大概了解了溢出的原因:
- 我們上一次發(fā)版的內(nèi)容就是新加了一個(gè)對(duì)接第三方的接口功茴,該第三方給到我們的API都是GET請(qǐng)求類型的參數(shù).
- 然后GET請(qǐng)求URL上面的參數(shù)可能是動(dòng)態(tài)的(每次請(qǐng)求參數(shù)里面都帶了時(shí)間戳),導(dǎo)致每次攔截器匯總的時(shí)候孽亲,命中不了坎穿,所以一直添加,由于是Map結(jié)構(gòu)又是Spring的單例模式返劲,GC壓根就回收不了這玩意玲昧,導(dǎo)致了內(nèi)存溢出!
其他應(yīng)用的RestTemplate都沒有出問題的原因是我們都用到是post請(qǐng)求篮绿,URL是固定的孵延。不會(huì)緩存參數(shù)。即便是GET請(qǐng)求參數(shù)變化的概率不大亲配!
后面經(jīng)過本地模擬這種情況證實(shí)了想法尘应,誒~ 要了命了惶凝。
我也不知道這算不算Bug~
解決的方案也很簡(jiǎn)單,通過MetricsInterceptorConfiguration
我們知道它默認(rèn)是開啟的犬钢,但是也可以在配置文件中進(jìn)行關(guān)閉:
spring:
cloud:
netflix:
metrics:
enabled: false
由于我們壓根都不需要這個(gè)類苍鲜,直接就給關(guān)了。后續(xù)再繼續(xù)關(guān)注一下~