一次詭異的FGC,原因讓我找了好久平痰!

正擼著代碼汞舱,公司內的聊天工具彈出一條信息:

“狼哥,我這個機器總是頻繁FGC...”

我趕緊打開對話框宗雇,機智的回復一個表情

然后繼續(xù)默默擼碼昂芜。

隨后,小伙伴砸了一段GC日志過來


2019-09-17T20:33:57.889+0800: 4753520.554: [Full GC (Metadata GC Threshold) 4753520.554: [CMS[YG occupancy: 723220 K (1887488 K)]4753520.988: [weak refs process        ing, 0.0042134 secs]4753520.992: [class unloading, 0.0987343 secs]4753521.091: [scrub symbol table, 0.0237609 secs]4753521.115: [scrub string table, 0.0025983 s        ecs]: 145423K->141376K(3354624K), 0.6260023 secs] 868644K->864597K(5242112K), [Metaspace: 128179K->128179K(1234944K)], 0.6264315 secs] [Times: user=1.24 sys=0.0        0, real=0.63 secs]
4159962 Heap after GC invocations=8029 (full 50):
4159963  par new generation   total 1887488K, used 723220K [0x0000000673400000, 0x00000006f3400000, 0x00000006f3400000)
4159964   eden space 1677824K,  42% used [0x0000000673400000, 0x000000069ed59090, 0x00000006d9a80000)
4159965   from space 209664K,   4% used [0x00000006d9a80000, 0x00000006da36c210, 0x00000006e6740000)
4159966   to   space 209664K,   0% used [0x00000006e6740000, 0x00000006e6740000, 0x00000006f3400000)
4159967  concurrent mark-sweep generation total 3354624K, used 141376K [0x00000006f3400000, 0x00000007c0000000, 0x00000007c0000000)
4159968  Metaspace       used 128145K, capacity 136860K, committed 262144K, reserved 1234944K
4159969   class space    used 14443K, capacity 16168K, committed 77312K, reserved 1048576K
4159970 }
4159971 {Heap before GC invocations=8029 (full 50):
4159972  par new generation   total 1887488K, used 723220K [0x0000000673400000, 0x00000006f3400000, 0x00000006f3400000)
4159973   eden space 1677824K,  42% used [0x0000000673400000, 0x000000069ed59090, 0x00000006d9a80000)
4159974   from space 209664K,   4% used [0x00000006d9a80000, 0x00000006da36c210, 0x00000006e6740000)
4159975   to   space 209664K,   0% used [0x00000006e6740000, 0x00000006e6740000, 0x00000006f3400000)
4159976  concurrent mark-sweep generation total 3354624K, used 141376K [0x00000006f3400000, 0x00000007c0000000, 0x00000007c0000000)
4159977  Metaspace       used 128145K, capacity 136860K, committed 262144K, reserved 1234944K
4159978   class space    used 14443K, capacity 16168K, committed 77312K, reserved 1048576K

我這慧眼一瞧逾礁,看到了幾個關鍵單詞Full GCMetadata GC Threshold访惜,然后很隨意的回復了

“是不是metaspace沒有設置嘹履,或者設置太小,導致了FGC” 外加一個得意的表情

然后债热,又砸過來一段JVM參數(shù)配置

CATALINA_OPTS="$CATALINA_OPTS -server -Djava.awt.headless=true -Xms5324m -Xmx5324m -Xss512k -XX:PermSize=350m -XX:MaxPermSize=350m -XX:MetaspaceSize=256m -XX:MaxMet    aspaceSize=256m -XX:NewSize=2048m -XX:MaxNewSize=2048m -XX:SurvivorRatio=8 -XX:MaxTenuringThreshold=9 -XX:+UseConcMarkSweepGC -XX:+UseCMSInitiatingOccupancyOnly -XX    :+CMSScavengeBeforeRemark -XX:+ScavengeBeforeFullGC -XX:+UseCMSCompactAtFullCollection -XX:+CMSParallelRemarkEnabled -XX:CMSFullGCsBeforeCompaction=9 -XX:CMSInitiat    ingOccupancyFraction=80 -XX:+CMSClassUnloadingEnabled -XX:SoftRefLRUPolicyMSPerMB=0 -XX:-ReduceInitialCardMarks -XX:+CMSPermGenSweepingEnabled -XX:CMSInitiatingPerm    OccupancyFraction=80 -XX:+ExplicitGCInvokesConcurrent -Djava.nio.channels.spi.SelectorProvider=[sun.nio.ch](http://sun.nio.ch/).EPollSelectorProvider -Djava.util.logging.manager=org.apac    he.juli.ClassLoaderLogManager -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime -XX:+PrintHeapAtGC     -Xloggc:/data/applogs/heap_trace.txt -XX:+IgnoreUnrecognizedVMOptions -XX:-HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/data/applogs/HeapDumpOnOutOfMemoryError"

“應該不是砾嫉,我們配置了-XX:MaxMetaspaceSize=256m -XX:MetaspaceSize=256m”

看到配置之后,有點懵逼窒篱,好像超出了我的認知范圍焕刮,一下子沒回復,又扔過來一堆數(shù)據(jù)墙杯。

image.png

“看cat監(jiān)控數(shù)據(jù)配并,Metaspace使用率在50%的時候就FGC了,GC 日志上的顯示也只用了142M高镐,可是我們明明設置了初始值是256M溉旋,最大值250M,這還沒達到閾值”

機智如我嫉髓,趕緊回復 “等等观腊,我空的時候再看看”

等空閑下來,我又想起了這個問題算行,決定好好研究下梧油。

既然是Metadata GC Threshold引起的FGC,那么只可能是MetadataSpace使用完了州邢,我又反復的看了下GC日志片段儡陨,盯著下面看了會

[0x00000006f3400000, 0x00000007c0000000, 0x00000007c0000000)
4159977  Metaspace       used 128145K, capacity 136860K, committed 262144K, reserved 1234944K

發(fā)生FGC之前,Metaspace的committed確實達到了256M,
我們需要知道一點:當目前的committed內存+當前需要分配的內存達到Metaspace閾值迄委,就會發(fā)生Metadata GC Threshold的FGC褐筛。

看到這里,我們也能大概猜出了叙身,這次FGC是合理的渔扎。

但是,為什么used指標只有125M信轿,卻還要申請其它內存晃痴?

看來只有一個原因可以解釋了:內存碎片。

之前只聽過老年代因為CMS的標記清理會產生內存碎片導致FGC财忽,為什么Metaspace也會有這樣的問題倘核?

讓同事對有問題的機器dump了下,用mat打開之后即彪,發(fā)現(xiàn)了一個新大陸紧唱,包含了大量的類加載器。

難道這個碎片問題是大量類加載器引起的隶校?

本地驗證

有了這個疑問漏益,那就簡單了,看看能不能在本地復現(xiàn)深胳。
1绰疤、先定義一個自定義的類加載器,破壞雙親委派

public class MyClassLoader extends ClassLoader {

        @Override
        protected Class<?> findClass(String name) throws ClassNotFoundException {
            try{
                String filePath = "/Users/zhanjun/Desktop/" + name.replace('.', File.separatorChar) + ".class";
                //指定讀取磁盤上的某個文件夾下的.class文件:
                File file = new File(filePath);
                FileInputStream fis = new FileInputStream(file);
                byte[] bytes = new byte[fis.available()];
                fis.read(bytes);
                //調用defineClass方法舞终,將字節(jié)數(shù)組轉換成Class對象
                Class<?> clazz = this.defineClass(name, bytes, 0, bytes.length);
                fis.close();
                return clazz;
            }catch (FileNotFoundException e){
                e.printStackTrace();
            } catch (IOException e) {
                e.printStackTrace();
            } finally {

            }
            return super.findClass(name);
        }
    }

2轻庆、然后在while循環(huán)中,不斷的 load 已經編譯好的class文件

public static void main(String[] args) throws Exception {
        while (true) {
            Class clazz0 = new MyClassLoader().loadClass("com.sankuai.discover.memory.OOM");
        }
    }

3敛劝、最后余爆,配置一下jvm啟動參數(shù)

-Xmx2688M -Xms2688M -Xmn960M -XX:MetaspaceSize=50M -XX:MaxMetaspaceSize=100M -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC -XX:+UseConcMarkSweepGC

啟動之后,不一會兒在控制臺果然出現(xiàn)了日志

{Heap before GC invocations=0 (full 0):
 par new generation   total 884736K, used 330302K [0x0000000752400000, 0x000000078e400000, 0x000000078e400000)
  eden space 786432K,  42% used [0x0000000752400000, 0x000000076668fae0, 0x0000000782400000)
  from space 98304K,   0% used [0x0000000782400000, 0x0000000782400000, 0x0000000788400000)
  to   space 98304K,   0% used [0x0000000788400000, 0x0000000788400000, 0x000000078e400000)
 concurrent mark-sweep generation total 1769472K, used 0K [0x000000078e400000, 0x00000007fa400000, 0x00000007fa400000)
 Metaspace       used 22636K, capacity 102360K, committed 102400K, reserved 1118208K
  class space    used 8829K, capacity 33008K, committed 33008K, reserved 1048576K
2019-09-21T16:09:28.562-0800: [Full GC (Metadata GC Threshold) 2019-09-21T16:09:28.562-0800: [CMS: 0K->5029K(1769472K), 0.0987115 secs] 330302K->5029K(2654208K), [Metaspace: 22636K->22636K(1118208K)], 0.1340367 secs] [Times: user=0.11 sys=0.03, real=0.13 secs] 
Heap after GC invocations=1 (full 1):
 par new generation   total 884736K, used 0K [0x0000000752400000, 0x000000078e400000, 0x000000078e400000)
  eden space 786432K,   0% used [0x0000000752400000, 0x0000000752400000, 0x0000000782400000)
  from space 98304K,   0% used [0x0000000782400000, 0x0000000782400000, 0x0000000788400000)
  to   space 98304K,   0% used [0x0000000788400000, 0x0000000788400000, 0x000000078e400000)
 concurrent mark-sweep generation total 1769472K, used 5029K [0x000000078e400000, 0x00000007fa400000, 0x00000007fa400000)
 Metaspace       used 2885K, capacity 4500K, committed 43008K, reserved 1058816K
  class space    used 291K, capacity 388K, committed 33008K, reserved 1048576K
}

從日志可以看出來夸盟,發(fā)生FGC之前龙屉,used大概22M,committed已經達到100M满俗,這時再加載class的時候转捕,需要申請內存,就不夠了唆垃,只能通過FGC對Metaspace的內存進行整理壓縮五芝。

到現(xiàn)在,我們已經驗證了過多的類加載器確實可以引起FGC辕万。

內存碎片是怎么產生的枢步?

其實沉删,JVM內部為了實現(xiàn)高效分配,在類加載器第一次加載類的時候醉途,會在Metaspace分配一個獨立的內存塊矾瑰,隨后該類加載加載的類信息都保存在該內存塊。但如果這個類加載器只加載了一個類或者少數(shù)類隘擎,那這塊內存就被浪費了殴穴,如果類加載器又特別多,那內存碎片就產生了货葬。

最后編輯于
?著作權歸作者所有,轉載或內容合作請聯(lián)系作者
  • 序言:七十年代末采幌,一起剝皮案震驚了整個濱河市,隨后出現(xiàn)的幾起案子震桶,更是在濱河造成了極大的恐慌休傍,老刑警劉巖,帶你破解...
    沈念sama閱讀 219,589評論 6 508
  • 序言:濱河連續(xù)發(fā)生了三起死亡事件蹲姐,死亡現(xiàn)場離奇詭異磨取,居然都是意外死亡,警方通過查閱死者的電腦和手機柴墩,發(fā)現(xiàn)死者居然都...
    沈念sama閱讀 93,615評論 3 396
  • 文/潘曉璐 我一進店門忙厌,熙熙樓的掌柜王于貴愁眉苦臉地迎上來,“玉大人拐邪,你說我怎么就攤上這事慰毅“兀” “怎么了扎阶?”我有些...
    開封第一講書人閱讀 165,933評論 0 356
  • 文/不壞的土叔 我叫張陵,是天一觀的道長婶芭。 經常有香客問我东臀,道長,這世上最難降的妖魔是什么犀农? 我笑而不...
    開封第一講書人閱讀 58,976評論 1 295
  • 正文 為了忘掉前任惰赋,我火速辦了婚禮,結果婚禮上呵哨,老公的妹妹穿的比我還像新娘赁濒。我一直安慰自己,他們只是感情好孟害,可當我...
    茶點故事閱讀 67,999評論 6 393
  • 文/花漫 我一把揭開白布拒炎。 她就那樣靜靜地躺著,像睡著了一般挨务。 火紅的嫁衣襯著肌膚如雪击你。 梳的紋絲不亂的頭發(fā)上玉组,一...
    開封第一講書人閱讀 51,775評論 1 307
  • 那天,我揣著相機與錄音丁侄,去河邊找鬼惯雳。 笑死,一個胖子當著我的面吹牛鸿摇,可吹牛的內容都是我干的石景。 我是一名探鬼主播,決...
    沈念sama閱讀 40,474評論 3 420
  • 文/蒼蘭香墨 我猛地睜開眼户辱,長吁一口氣:“原來是場噩夢啊……” “哼鸵钝!你這毒婦竟也來了?” 一聲冷哼從身側響起庐镐,我...
    開封第一講書人閱讀 39,359評論 0 276
  • 序言:老撾萬榮一對情侶失蹤恩商,失蹤者是張志新(化名)和其女友劉穎,沒想到半個月后必逆,有當?shù)厝嗽跇淞掷锇l(fā)現(xiàn)了一具尸體怠堪,經...
    沈念sama閱讀 45,854評論 1 317
  • 正文 獨居荒郊野嶺守林人離奇死亡,尸身上長有42處帶血的膿包…… 初始之章·張勛 以下內容為張勛視角 年9月15日...
    茶點故事閱讀 38,007評論 3 338
  • 正文 我和宋清朗相戀三年名眉,在試婚紗的時候發(fā)現(xiàn)自己被綠了粟矿。 大學時的朋友給我發(fā)了我未婚夫和他白月光在一起吃飯的照片。...
    茶點故事閱讀 40,146評論 1 351
  • 序言:一個原本活蹦亂跳的男人離奇死亡损拢,死狀恐怖陌粹,靈堂內的尸體忽然破棺而出,到底是詐尸還是另有隱情福压,我是刑警寧澤掏秩,帶...
    沈念sama閱讀 35,826評論 5 346
  • 正文 年R本政府宣布,位于F島的核電站荆姆,受9級特大地震影響蒙幻,放射性物質發(fā)生泄漏。R本人自食惡果不足惜胆筒,卻給世界環(huán)境...
    茶點故事閱讀 41,484評論 3 331
  • 文/蒙蒙 一邮破、第九天 我趴在偏房一處隱蔽的房頂上張望。 院中可真熱鬧仆救,春花似錦抒和、人聲如沸。這莊子的主人今日做“春日...
    開封第一講書人閱讀 32,029評論 0 22
  • 文/蒼蘭香墨 我抬頭看了看天上的太陽组砚。三九已至,卻和暖如春范嘱,著一層夾襖步出監(jiān)牢的瞬間送膳,已是汗流浹背。 一陣腳步聲響...
    開封第一講書人閱讀 33,153評論 1 272
  • 我被黑心中介騙來泰國打工丑蛤, 沒想到剛下飛機就差點兒被人妖公主榨干…… 1. 我叫王不留叠聋,地道東北人。 一個月前我還...
    沈念sama閱讀 48,420評論 3 373
  • 正文 我出身青樓受裹,卻偏偏與公主長得像碌补,于是被迫代替她去往敵國和親。 傳聞我的和親對象是個殘疾皇子棉饶,可洞房花燭夜當晚...
    茶點故事閱讀 45,107評論 2 356

推薦閱讀更多精彩內容