背景
最近開始看gc日志，感覺頗有了解。但苦于手上沒有例子來練手，結果昨天下午，受到joy-merchant-service的告警，表示有full gc，雖然這個不是我負責的服務，但是好不容易逮到怎麼能不管，于是晚上飯後開始檢視問題。
解決步驟
問題表現
我發現該服務線上共四台機器，每台機器在釋出的時候都會發生full gc，但是
僅限于釋出的時候，而且次數不多1-3次。
曆史記錄
想起以前阿菜改過一次joy-merchant的full-gc的問題，然後找到大象的記錄：
第一次假想
看到上面之前的問題後，我第一個想法是，會不會還是同樣的問題，jvm參數被改了。
然後一頓操作：
whereis tomcat
tomcat: /usr/local/tomcat
cat /usr/local/tomcat/bin/catalina.sh
找到啟動參數配置如下：
然後其他幾台機器的配置都是一樣的。然後我知道我們這邊機器都是java8的。
這個時候如果是老司機，就已經能發現問題了。
但是我還在看參數有什麼不對，繼續研究。
通過配置發現，線上機器老年代用的CMS垃圾回收器
然後需要了解一下配置參數的意義：
| 參數 | 意義 |
|---|---|
| -XX:SurvivorRatio=8 | 兩個Survivor和eden的比，8表示eden：survivor1:survivor2=8:1:1 |
| -XX:MaxTenuringThreshold=9 | 年齡門檻值 |
| -XX:+UseConcMarkSweepGC | 設定老年代為CMS收集器 |
| -XX:+UseCMSInitiatingOccupancyOnly | 使用手動定義初始化定義開始CMS收集；不進行自動平衡 |
| -XX:+CMSScavengeBeforeRemark | 開啟在CMS重新标記階段之前的清除嘗試 |
| -XX:+ScavengeBeforeFullGC | Full GC前調用YGC |
| -XX:+UseCMSCompactAtFullCollection | 使用并發收集器時，開啟對老年代的壓縮 |
| -XX:+CMSParallelRemarkEnabled | 降低标記停頓 |
| -XX:CMSFullGCsBeforeCompaction=9 | 設定多少次Full GC後，對老年代進行壓縮 |
| -XX:CMSInitiatingOccupancyFraction=80 | 使用cms作為垃圾回收使用70%後開始CMS收集（老年代） |
| -XX:+CMSClassUnloadingEnabled | 相對于并行收集器，CMS收集器預設不會對永久代進行垃圾回收。如果希望對永久代進行垃圾回收，可用設定标志 |
| -XX:SoftRefLRUPolicyMSPerMB=0 | 每兆堆空閑空間中SoftReference的存活時間 |
| -XX:-ReduceInitialCardMarks | 這個是為了解決 jdk 6u18 放入大對象導緻 jvm crash bug 的一個配置參數 |
| -XX:+CMSPermGenSweepingEnabled | 允許對持久代進行清理 |
| -XX:CMSInitiatingPermOccupancyFraction=80 | 設定Perm Gen（永久代）使用到達多少比率時觸發CMS GC |
| -XX:+ExplicitGCInvokesConcurrent | HeapDumpOnOutOfMemoryError |
| -XX:+PrintGCDetails | 開啟了詳細GC日志模式 |
| -XX:+PrintGCDateStamps | GC發生的時間資訊 |
| -XX:+PrintGCApplicationConcurrentTime | 列印每次垃圾回收前,程式未中斷的執行時間 |
| -XX:+PrintGCApplicationStoppedTime | 列印垃圾回收期間程式暫停的時間 |
| -XX:+PrintHeapAtGC | 列印GC前後的詳細堆棧資訊 |
| -Xloggc:/data/applogs/heap_trace.txt | 把相關日志資訊記錄到檔案以便分析 |
| -XX:-HeapDumpOnOutOfMemoryError | 讓JVM在出現記憶體溢出時候Dump出目前的記憶體轉儲快照 |
| -XX:HeapDumpPath=/data/applogs/HeapDumpOnOutOfMemoryError | 指定導出堆的存放路徑 |
| 待續 |
瘋狂操作之後，發現更清晰了，然後發現關鍵配置 -Xloggc:/data/applogs/heap_trace.txt ，馬上找到這個位置，檢視fullGC相關日志。
fullGC日志
指令：
cat -n heap_trace.txt | grep -15 'CMS'
得到如下日志：
2018-10-10T17:22:02.983+0800: 15.371: Total time for which application threads were stopped: 0.0004046 seconds, Stopping threads took: 0.0001968 seconds
716 CMS: abort preclean due to time 2018-10-10T17:22:03.005+0800: 15.394: [CMS-concurrent-abortable-preclean: 3.996/5.201 secs] [Times: user=14.58 sys=0.54, real=5.21 secs]
717 2018-10-10T17:22:03.010+0800: 15.398: Application time: 0.0267885 seconds
718 2018-10-10T17:22:03.010+0800: 15.399: [GC (CMS Final Remark) [YG occupancy: 466879 K (1812800 K)]{Heap before GC invocations=3 (full 1):
719 par new generation total 1812800K, used 466879K [0x0000000680600000, 0x00000006fb500000, 0x00000006fb500000)
720 eden space 1611392K, 24% used [0x0000000680600000, 0x0000000698e95660, 0x00000006e2ba0000)
721 from space 201408K, 32% used [0x00000006ef050000, 0x00000006f2faa998, 0x00000006fb500000)
722 to space 201408K, 0% used [0x00000006e2ba0000, 0x00000006e2ba0000, 0x00000006ef050000)
723 concurrent mark-sweep generation total 3222528K, used 80301K [0x00000006fb500000, 0x00000007c0000000, 0x00000007c0000000)
724 Metaspace used 44821K, capacity 45488K, committed 45788K, reserved 1089536K
725 class space used 5365K, capacity 5541K, committed 5552K, reserved 1048576K
726 2018-10-10T17:22:03.011+0800: 15.399: [GC (CMS Final Remark) 15.399: [ParNew: 466879K->89071K(1812800K), 0.0922275 secs] 547181K->169373K(5035328K), 0.0923299 secs] [Times: user=0.23 sys=0.01, real=0.09 secs]
727 Heap after GC invocations=4 (full 1):
728 par new generation total 1812800K, used 89071K [0x0000000680600000, 0x00000006fb500000, 0x00000006fb500000)
729 eden space 1611392K, 0% used [0x0000000680600000, 0x0000000680600000, 0x00000006e2ba0000)
730 from space 201408K, 44% used [0x00000006e2ba0000, 0x00000006e829bf10, 0x00000006ef050000)
731 to space 201408K, 0% used [0x00000006ef050000, 0x00000006ef050000, 0x00000006fb500000)
732 concurrent mark-sweep generation total 3222528K, used 80301K [0x00000006fb500000, 0x00000007c0000000, 0x00000007c0000000)
733 Metaspace used 44821K, capacity 45488K, committed 45788K, reserved 1089536K
734 class space used 5365K, capacity 5541K, committed 5552K, reserved 1048576K
735 }
736 15.491: [Rescan (parallel) , 0.0329930 secs]15.524: [weak refs processing, 0.0008164 secs]15.525: [class unloading, 0.0109658 secs]15.536: [scrub symbol table, 0.0069518 secs]15.543: [scrub string table, 0.0012339 secs][1 CMS-remark: 80301K(3222528K)] 169373K(5035328K), 0.1479142 secs] [Times: user=0.36 sys=0.01, real=0.15 secs]
737 2018-10-10T17:22:03.158+0800: 15.547: Total time for which application threads were stopped: 0.1482674 seconds, Stopping threads took: 0.0000994 seconds
738 2018-10-10T17:22:03.159+0800: 15.547: [CMS-concurrent-sweep-start]
739 2018-10-10T17:22:03.172+0800: 15.560: Application time: 0.0133639 seconds
740 2018-10-10T17:22:03.172+0800: 15.561: Total time for which application threads were stopped: 0.0006498 seconds, Stopping threads took: 0.0000686 seconds
741 2018-10-10T17:22:03.178+0800: 15.566: [CMS-concurrent-sweep: 0.019/0.019 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]
742 2018-10-10T17:22:03.178+0800: 15.566: [CMS-concurrent-reset-start]
743 2018-10-10T17:22:03.188+0800: 15.576: [CMS-concurrent-reset: 0.010/0.010 secs] [Times: user=0.03 sys=0.00, real=0.01 secs]
744 2018-10-10T17:22:04.173+0800: 16.561: Application time: 1.0000975 seconds
其中關鍵資訊：
Metaspace used 44821K, capacity 45488K, committed 45788K, reserved 1089536K
這個說明metaspace使用空間達到44m的時候，就發生了full gc，然後擴容之後，第二次full gc時，情況是這樣的：
Metaspace used 91845K, capacity 92995K, committed 93504K, reserved 1132544K
找到原因
上面可以發現是因為metaspace空間滿了導緻full gc。那麼問題來了，我們metaspaceSize設定的多大呢？從上面的參數列印來看，并沒有配置
好吧，這就是原因。線上的配置是-XX:PermSize=350m -XX:MaxPermSize=350m ，這都是永久代的配置，但我們線上已更新到java8，并沒有永久代。java8取而代之的是metaspace，是以，最終原因是，更新了java8，但是啟動參數沒有修改。
網上說如果沒有配置metaspaceSize，預設大小時20.8M，我在本地測試确實發現是這樣，但是這裡，為什麼是45m？這個問題需要閱讀的您幫我解決！！！
還有就是，我們更新了很多機器，為什麼就這一個服務啟動是會發生full gc？
這個也很簡單，metaspace存放類和方法的中繼資料以及常量池，joy-merchant項目很老了，東西太多。
再次更新，事實證明我太大意了，其他服務啟動的時候也發生了full gc，隻不過沒有配置告警而已。20.8m還是太小了
然後就是CMS的日志解析，有興趣可以閱讀文章：CMS收集過程和日志分析
解決辦法
修改參數：-XX:MetaspaceSize=128m -XX:MaxMetaspaceSize=256m
知識補充
關于metaspaceSize這裡有幾個要點需要明确：
- 無論-XX:MetaspaceSize配置什麼值，Metaspace的初始容量一定是21807104（約20.8m）；
- Metaspace由于使用不斷擴容到-XX:MetaspaceSize參數指定的量，就會發生FGC；且之後每次Metaspace擴容都會發生FGC；
- 如果Old區配置CMS垃圾回收，那麼第2點的FGC也會使用CMS算法進行回收；
- Meta區容量範圍為[20.8m, MaxMetaspaceSize)；
- 如果MaxMetaspaceSize設定太小，可能會導緻頻繁FGC，甚至OOM；
總結
多背 多記 多實踐 形成沉澱