純干貨:內(nèi)存溢出通過Jprofile排查思路以及實(shí)踐總結(jié)

嘀嘀嘀~
新鮮出爐的線上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源碼他是怎么做的:

  1. 首先實(shí)現(xiàn)了ClientHttpRequestInterceptor類泥技,在Spring層層處理下,每次使用RestTemplate發(fā)起調(diào)用都會(huì)被該標(biāo)識(shí)的接口實(shí)現(xiàn)攔截磕仅。
  2. 攔截之后珊豹,根據(jù)請(qǐng)求的參數(shù)進(jìn)行打標(biāo)記來標(biāo)識(shí)這一組請(qǐng)求類型,其實(shí)就是Map<標(biāo)記榕订,值>店茶,因?yàn)樗獙⒄?qǐng)求歸類分組!
  3. 所有數(shù)據(jù)歸類完之后保存到ServoMonitorCache中去劫恒,這個(gè)類負(fù)責(zé)統(tǒng)計(jì)該URL相關(guān)的【最大值贩幻、最小值、請(qǐng)求總數(shù)】
  4. 既然是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)注一下~

?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請(qǐng)聯(lián)系作者
  • 序言:七十年代末玷犹,一起剝皮案震驚了整個(gè)濱河市混滔,隨后出現(xiàn)的幾起案子,更是在濱河造成了極大的恐慌歹颓,老刑警劉巖坯屿,帶你破解...
    沈念sama閱讀 222,590評(píng)論 6 517
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件,死亡現(xiàn)場(chǎng)離奇詭異巍扛,居然都是意外死亡领跛,警方通過查閱死者的電腦和手機(jī),發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 95,157評(píng)論 3 399
  • 文/潘曉璐 我一進(jìn)店門电湘,熙熙樓的掌柜王于貴愁眉苦臉地迎上來隔节,“玉大人,你說我怎么就攤上這事寂呛≡踅耄” “怎么了?”我有些...
    開封第一講書人閱讀 169,301評(píng)論 0 362
  • 文/不壞的土叔 我叫張陵贷痪,是天一觀的道長(zhǎng)幻妓。 經(jīng)常有香客問我,道長(zhǎng)劫拢,這世上最難降的妖魔是什么肉津? 我笑而不...
    開封第一講書人閱讀 60,078評(píng)論 1 300
  • 正文 為了忘掉前任,我火速辦了婚禮舱沧,結(jié)果婚禮上妹沙,老公的妹妹穿的比我還像新娘。我一直安慰自己熟吏,他們只是感情好距糖,可當(dāng)我...
    茶點(diǎn)故事閱讀 69,082評(píng)論 6 398
  • 文/花漫 我一把揭開白布。 她就那樣靜靜地躺著牵寺,像睡著了一般悍引。 火紅的嫁衣襯著肌膚如雪。 梳的紋絲不亂的頭發(fā)上帽氓,一...
    開封第一講書人閱讀 52,682評(píng)論 1 312
  • 那天趣斤,我揣著相機(jī)與錄音,去河邊找鬼黎休。 笑死浓领,一個(gè)胖子當(dāng)著我的面吹牛玉凯,可吹牛的內(nèi)容都是我干的。 我是一名探鬼主播镊逝,決...
    沈念sama閱讀 41,155評(píng)論 3 422
  • 文/蒼蘭香墨 我猛地睜開眼壮啊,長(zhǎng)吁一口氣:“原來是場(chǎng)噩夢(mèng)啊……” “哼嫉鲸!你這毒婦竟也來了撑蒜?” 一聲冷哼從身側(cè)響起,我...
    開封第一講書人閱讀 40,098評(píng)論 0 277
  • 序言:老撾萬(wàn)榮一對(duì)情侶失蹤玄渗,失蹤者是張志新(化名)和其女友劉穎座菠,沒想到半個(gè)月后,有當(dāng)?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體藤树,經(jīng)...
    沈念sama閱讀 46,638評(píng)論 1 319
  • 正文 獨(dú)居荒郊野嶺守林人離奇死亡浴滴,尸身上長(zhǎng)有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點(diǎn)故事閱讀 38,701評(píng)論 3 342
  • 正文 我和宋清朗相戀三年,在試婚紗的時(shí)候發(fā)現(xiàn)自己被綠了岁钓。 大學(xué)時(shí)的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片升略。...
    茶點(diǎn)故事閱讀 40,852評(píng)論 1 353
  • 序言:一個(gè)原本活蹦亂跳的男人離奇死亡,死狀恐怖屡限,靈堂內(nèi)的尸體忽然破棺而出品嚣,到底是詐尸還是另有隱情,我是刑警寧澤钧大,帶...
    沈念sama閱讀 36,520評(píng)論 5 351
  • 正文 年R本政府宣布翰撑,位于F島的核電站,受9級(jí)特大地震影響啊央,放射性物質(zhì)發(fā)生泄漏眶诈。R本人自食惡果不足惜,卻給世界環(huán)境...
    茶點(diǎn)故事閱讀 42,181評(píng)論 3 335
  • 文/蒙蒙 一瓜饥、第九天 我趴在偏房一處隱蔽的房頂上張望逝撬。 院中可真熱鬧,春花似錦乓土、人聲如沸宪潮。這莊子的主人今日做“春日...
    開封第一講書人閱讀 32,674評(píng)論 0 25
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽(yáng)坎炼。三九已至,卻和暖如春拦键,著一層夾襖步出監(jiān)牢的瞬間谣光,已是汗流浹背。 一陣腳步聲響...
    開封第一講書人閱讀 33,788評(píng)論 1 274
  • 我被黑心中介騙來泰國(guó)打工芬为, 沒想到剛下飛機(jī)就差點(diǎn)兒被人妖公主榨干…… 1. 我叫王不留萄金,地道東北人蟀悦。 一個(gè)月前我還...
    沈念sama閱讀 49,279評(píng)論 3 379
  • 正文 我出身青樓,卻偏偏與公主長(zhǎng)得像氧敢,于是被迫代替她去往敵國(guó)和親日戈。 傳聞我的和親對(duì)象是個(gè)殘疾皇子,可洞房花燭夜當(dāng)晚...
    茶點(diǎn)故事閱讀 45,851評(píng)論 2 361

推薦閱讀更多精彩內(nèi)容