一次線上系統(tǒng)每天數(shù)十次Full GC導致頻繁卡死的優(yōu)化實戰(zhàn)!

1局嘁、案例開始前的說明

今天的這個案例也是我們之前線上系統(tǒng)經(jīng)歷過的一個真實的生產(chǎn)JVM優(yōu)化案例,這個優(yōu)化的過程比較復雜晦墙,經(jīng)過了多次優(yōu)化悦昵,當然核心

原理和知識其實還是之前給大家講解過的那些東西。

只不過這個真實生產(chǎn)系統(tǒng)優(yōu)化的過程大家如果能理解透徹晌畅,那么對于大家利用學過的知識和掌握的工具自己去進行JVM優(yōu)化的時候但指,肯

定是大有好處的。

這個線上系統(tǒng)是一個團隊開發(fā)的抗楔,那個團隊開發(fā)完一個新系統(tǒng)上線之后發(fā)現(xiàn)一天的Full GC次數(shù)多大數(shù)十次棋凳,甚至有的時候會上百次,

大家可想而知這是什么概念连躏!

通常來說剩岳,我們建議的一個比較良好的JVM性能,應該是Full GC在幾天才發(fā)生一次入热,或者是最多一天發(fā)生幾次而已拍棕。

所以當時這個新系統(tǒng)在線上的表現(xiàn)非常不好,明顯是有經(jīng)常性的卡頓的勺良,因此針對這個系統(tǒng)莫湘,我們進行了一連串的排查、定位郑气、分析和

優(yōu)化

下面就給大家分析一下整個優(yōu)化的過程幅垮。

2、未優(yōu)化前的JVM性能分析

大家還記得之前帶著大家動手實操過的jstat工具吧尾组?那個工具是非常好用忙芒,非常實用,也是非常常用的一個工具讳侨。

因為很多中小型公司都沒上那種可視化的監(jiān)控平臺呵萨,沒法直接可視化的看到JVM各個區(qū)域的內(nèi)存變化,GC次數(shù)和GC耗時跨跨。

當然潮峦,如果有辦法的話,我建議大家可以給自己所在公司推薦一下類似Zabbix勇婴、Ganglia忱嘹、Open-Falcon、Prometheus之類的可視化

監(jiān)控平臺耕渴,其實接入都非常簡單拘悦,如果把線上系統(tǒng)接入了這些平臺,可以直接圖形化看到JVM的表現(xiàn)橱脸。

但是哪怕你有了可視化監(jiān)控平臺础米,有時候直接對線上系統(tǒng)進行分析的時候分苇,還是jstat更加好用和直接。

所以當時我們通過監(jiān)控平臺+jstat工具分析屁桑,直接得出當時沒優(yōu)化過的系統(tǒng)的JVM性能表現(xiàn)大致如下:

機器配置:2核4G

JVM堆內(nèi)存大幸绞佟:2G

系統(tǒng)運行時間:6天

系統(tǒng)運行6天內(nèi)發(fā)生的Full GC次數(shù)和耗時:250次,70多秒

系統(tǒng)運行6天內(nèi)發(fā)生的Young GC次數(shù)和耗時:2.6萬次蘑斧,1400秒

綜合分析一下糟红,就可以知道,大致來說每天會發(fā)生40多次Full GC乌叶,平均每小時2次盆偿,每次Full GC在300毫秒左右;

每天會發(fā)生4000多次Young GC准浴,每分鐘會發(fā)生3次事扭,每次Young GC在50毫秒左右。

上述數(shù)據(jù)對任何一個線上系統(tǒng)乐横,用jstat可以輕松看出來求橄,因為jstat顯示出來的Full GC和Young GC的次數(shù)都是系統(tǒng)啟動以來的總次數(shù),

耗時都是所有GC加起來的總耗時葡公,所以直接可以拿到上述數(shù)據(jù)罐农,略微分析一下就知道具體情況了。

基本看起來催什,這個系統(tǒng)的性能是相當差了涵亏,每分鐘3次Young GC,每小時2次Full GC蒲凶,這種系統(tǒng)是必須得進行優(yōu)化的气筋。

3、未優(yōu)化前的線上JVM參數(shù)

下面是未優(yōu)化前的線上JVM參數(shù)旋圆,大致如下:

-Xms1536M -Xmx1536M -Xmn512M -Xss256K -XX:SurvivorRatio=5 -XX:+UseParNewGC -XX:+UseConcMarkSweepGC -

XX:CMSInitiatingOccupancyFraction=68 -XX:+CMSParallelRemarkEnabled -XX:+UseCMSInitiatingOccupancyOnly -

XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC

其實基本上跟我們之前看到的參數(shù)沒多大的不同宠默,一個4G的機器上,給JVM的堆內(nèi)存是設(shè)置了1.5G的大小灵巧,其中新生代是給了512M搀矫,

老年代是1G。

比較關(guān)鍵的是“-XX:SurvivorRatio”設(shè)置為了5刻肄,也就是說瓤球,Eden:Survivor1:Survivor2的比例是5:1:1,所以此時Eden區(qū)域大致為365M肄方,每個Survivor區(qū)域大致為70MB冰垄。

而且這里有一個非常關(guān)鍵的參數(shù),那就是“-XX:CMSInitiatingOccupancyFraction”參數(shù)設(shè)置為了68权她,所以一旦老年代內(nèi)存占用達到68%虹茶,也就是大概有680MB左右的對象時,就會觸發(fā)一次Full GC隅要。

4蝴罪、根據(jù)線上系統(tǒng)的GC情況倒推運行內(nèi)存模型

接著我們可以根據(jù)系統(tǒng)的內(nèi)存模型以及GC情況,直接根據(jù)學習過的知識推導出系統(tǒng)運行時的內(nèi)存模型了步清。

首先我們知道每分鐘會發(fā)生3次Young GC要门,說明系統(tǒng)運行20秒就會讓Eden區(qū)滿,也就是產(chǎn)生300多MB的對象廓啊,平均下來系統(tǒng)每秒鐘

會產(chǎn)生15~20MB的對象欢搜。所以20秒左右就會導致Eden區(qū)滿,然后觸發(fā)一次Young GC谴轮。

接著我們根據(jù)每小時2次Full GC推斷出炒瘟,30分鐘會觸發(fā)一次Full GC

根據(jù)“-XX:CMSInitiatingOccupancyFraction=68”參數(shù)的設(shè)置,應該是在老年代有600多MB左右的對象時大概就會觸發(fā)一次Full

GC第步,因為1GB的老年代有68%空間占滿了就會觸發(fā)CMS的GC了疮装。

所以系統(tǒng)運行30分鐘就會導致老年代里有600多MB的對象,進而觸發(fā)CMS垃圾回收器對老年代進行GC粘都。

所以基本上我們就能根據(jù)推導出的運行內(nèi)存模型得出一個結(jié)論:

每隔20秒會讓300多MB的Eden區(qū)滿觸發(fā)一次Young GC廓推,一次Young GC耗時50毫秒左右。

每隔30分鐘會讓老年代里600多MB空間占滿翩隧,進而觸發(fā)一次CMS的GC樊展,一次Full GC耗時300毫秒左右。

但是到這里大家先暫停一下堆生,有的朋友可能立馬會推斷了滚局,他會說,是不是因為Survivor區(qū)域太小了顽频,導致Young GC后的存活對象太

多放不下藤肢,就一直有對象流入老年代,進而導致30分鐘后觸發(fā)Full GC糯景?

實際上僅僅只是分析到這里嘁圈,絕對不能草率下這個判斷的。

因為老年代里為什么有那么多的對象蟀淮?有可能是每次Young GC后的存活對象較多最住,Survivor區(qū)域太小,放不下了

也有可能是有很多長時間存活的對象太多了怠惶,都積累在老年代里涨缚,始終回收不掉,進而導致老年代很容易就達到68%的占比觸發(fā)GC策治。

所以僅僅分析到這里脓魏,絕對不能輕易下結(jié)論兰吟。

5、老年代里到底為什么會有那么多的對象茂翔?

分析到這里混蔼,說句實話,僅僅根據(jù)可視化監(jiān)控和推論是絕對沒法往下分析了珊燎,因為我們并不知道老年代里到底為什么會有那么多的對象

此時就完全可以用jstat在高峰期觀察一下JVM實際運行的情況惭嚣。

通過jstat的觀察,我們當時可以明確看到悔政,每次Young GC過后升入老年代里的對象很少

一般來說晚吞,每次Young GC過后大概就存活幾十MB而已,那么Survivor區(qū)域因為就70MB谋国,所以經(jīng)常會觸發(fā)動態(tài)年齡判斷規(guī)則槽地,導致偶

爾一次Young GC過后有幾十MB對象進入老年代。

因此分析到這里很奇怪烹卒,因為通過jstat追蹤觀察闷盔,并不是每次Young GC后都有幾十MB對象進入老年代的,而是偶爾一次Young GC才

會有幾十MB對象進入老年代旅急,記住逢勾,是偶爾一次!

所以正常來說藐吮,應該不至于30分鐘就導致老年代占用空間達到68%溺拱。

那么老年代里到底為什么有那么多對象呢?

這個時候我們通過jstat運行的時候就觀察到一個現(xiàn)象谣辞,就是老年代里的內(nèi)存占用在系統(tǒng)運行的時候迫摔,不知道為什么系統(tǒng)運行著運行著,

就會突然有幾百MB的對象占據(jù)在里面泥从,大概有五六百MB的對象句占,一直占據(jù)在老年代中。

正是因為系統(tǒng)運行的時候躯嫉,不知道為什么突然有有幾百MB對象進入老年代中纱烘,所以才導致Young GC偶爾一次讓幾十MB對象升入老年

代,平均30分鐘左右就會觸發(fā)一次Full GCF聿汀@奚丁!

那么我們就很奇怪了帆阳,為什么系統(tǒng)運行著會突然有幾百MB的對象進入老年代哺壶?

答案已經(jīng)呼之欲出了,大對象!

一定是系統(tǒng)運行的時候山宾,每隔一段時間就會突然產(chǎn)生幾百MB的大對象至扰,直接進入老年代,不會走年輕代的Eden區(qū)域塌碌。

然后再配合上年輕代還偶爾會有Young GC后幾十MB對象進入老年代渊胸,所以才會30分鐘觸發(fā)一次Full GC旬盯!

6台妆、定位系統(tǒng)的大對象

分析到這里,就很簡單了胖翰,我們只需要采用之前給大家介紹的jmap工具接剩,通過后臺jstat工具觀察系統(tǒng),什么時候發(fā)現(xiàn)老年代里突然進

入了幾百MB的大對象萨咳,就立馬用jmap工具導出一份dump內(nèi)存快照懊缺。

接著可以采用之前說過的jhat,或者是Visual VM之類的可視化工具來分析dump內(nèi)存快照

關(guān)于Visual VM之類的工具培他,大家自行百度即可鹃两,非常簡單易用,其實本質(zhì)就是讓你分析導出的內(nèi)存快照舀凛。

通過內(nèi)存快照的分析俊扳,直接定位出來那個幾百MB的大對象,就是幾個Map之類的數(shù)據(jù)結(jié)構(gòu)猛遍,這是什么東西馋记?直接讓負責寫那個系統(tǒng)代

碼的幾個同學分析了一下,明顯是從數(shù)據(jù)庫里查出來的懊烤!

因為那個系統(tǒng)僅僅就是操作數(shù)據(jù)庫而已梯醒,不存在別的什么特殊操作。

然后這個時候也沒太好的辦法了腌紧,直接笨辦法茸习,幾個人地毯式排查這個系統(tǒng)的所有SQL語句,結(jié)果還真的有一個人發(fā)現(xiàn)壁肋,自己的一個

SQL居然在某種特殊的場景下号胚,會類似如下所示:

select * from tbl。

這是啥意思墩划?就是沒有where條件涕刚!

沒有where條件,就代表這個SQL可能會把表中幾十萬條數(shù)據(jù)直接全部查出來乙帮!

正是因為這個代碼層面的bug杜漠,導致了每隔一段時間系統(tǒng)會搞出幾個上百MB的大對象,這些對象是會全部直接進入老年代的!

然后過一會兒隨著偶爾幾次Young GC有幾十MB對象進入老年代驾茴,所以平均幾十分鐘就會觸發(fā)一次Full GCE握痢!锈至!

7晨缴、針對本案例的JVM和代碼優(yōu)化

其實分析到這里,這個案例如何優(yōu)化已經(jīng)呼之欲出了峡捡!

非常簡單击碗,分成兩步走

第一步,讓開發(fā)同學解決代碼中的bug们拙,避免一些極端情況下SQL語句里不拼接where條件稍途,務必要拼接上where條件,不允許查詢表

中全部數(shù)據(jù)砚婆。徹底解決那個時不時有幾百MB對象進入老年代的問題械拍。

第二步,年輕代明顯過小装盯,Survivor區(qū)域空間不夠坷虑,因為每次Young GC后存活對象在幾十MB左右,如果Survivor就70MB很容易觸發(fā)

動態(tài)年齡判定埂奈,讓對象進入老年代中迄损。所以直接調(diào)整JVM參數(shù)如下:

-Xms1536M -Xmx1536M -Xmn1024M -Xss256K -XX:SurvivorRatio=5 -XX:PermSize=256M -XX:MaxPermSize=256M -

XX:+UseParNewGC -XX:+UseConcMarkSweepGC -XX:CMSInitiatingOccupancyFraction=92 -

XX:+CMSParallelRemarkEnabled -XX:+UseCMSInitiatingOccupancyOnly -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -

XX:+PrintHeapAtGC

直接把年輕代空間調(diào)整為700MB左右,每個Surivor是150MB左右挥转,此時Young GC過后就幾十MG存活對象海蔽,一般不會進入老年代。

反之老年代就留500MB左右就足夠了绑谣,因為一般不會有對象進入老年代党窜。

而且調(diào)整了參數(shù)“-XX:CMSInitiatingOccupancyFraction=92”,避免老年代僅僅占用68%就觸發(fā)GC借宵,現(xiàn)在必須要占用到92%才會觸

發(fā)GC幌衣。

最后,就是主動設(shè)置了永久代大小為256MB壤玫,因為如果不主動設(shè)置會導致默認永久代就在幾十MB的樣子豁护,很容易導致萬一系統(tǒng)運行時

候采用了反射之類的機制,可能一旦動態(tài)加載的類過多欲间,就會頻繁觸發(fā)Full GC楚里。

這幾個步驟優(yōu)化完畢之后,線上系統(tǒng)基本上表現(xiàn)就非常好了猎贴,基本上每分鐘大概發(fā)生一次Young GC班缎,一次在幾十毫秒蝴光;

Full GC幾乎就很少,大概可能要運行至少10天才會發(fā)生一次达址,一次就耗時幾百毫秒而已蔑祟,頻率很低。

?著作權(quán)歸作者所有,轉(zhuǎn)載或內(nèi)容合作請聯(lián)系作者
  • 序言:七十年代末沉唠,一起剝皮案震驚了整個濱河市疆虚,隨后出現(xiàn)的幾起案子,更是在濱河造成了極大的恐慌满葛,老刑警劉巖径簿,帶你破解...
    沈念sama閱讀 218,122評論 6 505
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件,死亡現(xiàn)場離奇詭異纱扭,居然都是意外死亡牍帚,警方通過查閱死者的電腦和手機儡遮,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 93,070評論 3 395
  • 文/潘曉璐 我一進店門乳蛾,熙熙樓的掌柜王于貴愁眉苦臉地迎上來,“玉大人鄙币,你說我怎么就攤上這事肃叶。” “怎么了十嘿?”我有些...
    開封第一講書人閱讀 164,491評論 0 354
  • 文/不壞的土叔 我叫張陵因惭,是天一觀的道長。 經(jīng)常有香客問我绩衷,道長蹦魔,這世上最難降的妖魔是什么? 我笑而不...
    開封第一講書人閱讀 58,636評論 1 293
  • 正文 為了忘掉前任咳燕,我火速辦了婚禮勿决,結(jié)果婚禮上,老公的妹妹穿的比我還像新娘招盲。我一直安慰自己低缩,他們只是感情好,可當我...
    茶點故事閱讀 67,676評論 6 392
  • 文/花漫 我一把揭開白布曹货。 她就那樣靜靜地躺著咆繁,像睡著了一般。 火紅的嫁衣襯著肌膚如雪顶籽。 梳的紋絲不亂的頭發(fā)上玩般,一...
    開封第一講書人閱讀 51,541評論 1 305
  • 那天,我揣著相機與錄音礼饱,去河邊找鬼坏为。 笑死设拟,一個胖子當著我的面吹牛,可吹牛的內(nèi)容都是我干的久脯。 我是一名探鬼主播纳胧,決...
    沈念sama閱讀 40,292評論 3 418
  • 文/蒼蘭香墨 我猛地睜開眼,長吁一口氣:“原來是場噩夢啊……” “哼帘撰!你這毒婦竟也來了跑慕?” 一聲冷哼從身側(cè)響起,我...
    開封第一講書人閱讀 39,211評論 0 276
  • 序言:老撾萬榮一對情侶失蹤摧找,失蹤者是張志新(化名)和其女友劉穎核行,沒想到半個月后,有當?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體蹬耘,經(jīng)...
    沈念sama閱讀 45,655評論 1 314
  • 正文 獨居荒郊野嶺守林人離奇死亡芝雪,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內(nèi)容為張勛視角 年9月15日...
    茶點故事閱讀 37,846評論 3 336
  • 正文 我和宋清朗相戀三年,在試婚紗的時候發(fā)現(xiàn)自己被綠了综苔。 大學時的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片惩系。...
    茶點故事閱讀 39,965評論 1 348
  • 序言:一個原本活蹦亂跳的男人離奇死亡,死狀恐怖如筛,靈堂內(nèi)的尸體忽然破棺而出堡牡,到底是詐尸還是另有隱情,我是刑警寧澤杨刨,帶...
    沈念sama閱讀 35,684評論 5 347
  • 正文 年R本政府宣布晤柄,位于F島的核電站,受9級特大地震影響妖胀,放射性物質(zhì)發(fā)生泄漏芥颈。R本人自食惡果不足惜,卻給世界環(huán)境...
    茶點故事閱讀 41,295評論 3 329
  • 文/蒙蒙 一赚抡、第九天 我趴在偏房一處隱蔽的房頂上張望爬坑。 院中可真熱鬧,春花似錦怕品、人聲如沸妇垢。這莊子的主人今日做“春日...
    開封第一講書人閱讀 31,894評論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽闯估。三九已至,卻和暖如春吼和,著一層夾襖步出監(jiān)牢的瞬間涨薪,已是汗流浹背。 一陣腳步聲響...
    開封第一講書人閱讀 33,012評論 1 269
  • 我被黑心中介騙來泰國打工炫乓, 沒想到剛下飛機就差點兒被人妖公主榨干…… 1. 我叫王不留刚夺,地道東北人献丑。 一個月前我還...
    沈念sama閱讀 48,126評論 3 370
  • 正文 我出身青樓,卻偏偏與公主長得像侠姑,于是被迫代替她去往敵國和親创橄。 傳聞我的和親對象是個殘疾皇子,可洞房花燭夜當晚...
    茶點故事閱讀 44,914評論 2 355

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