本文采用的JDK版本：
java version "1.8.0_144"
Java(TM) SE Runtime Environment (build 1.8.0_144-b01)
Java HotSpot(TM) 64-Bit Server VM (build 25.144-b01, mixed mode)
一沦泌、GC 日志參數(shù)
設(shè)置JVM GC格式日志的主要參數(shù)包括如下8個：
-XX:+PrintGC 輸出簡要GC日志
-XX:+PrintGCDetails 輸出詳細(xì)GC日志
-Xloggc:gc.log 輸出GC日志到文件
-XX:+PrintGCTimeStamps 輸出GC的時(shí)間戳（以JVM啟動到當(dāng)期的總時(shí)長的時(shí)間戳形式）
-XX:+PrintGCDateStamps 輸出GC的時(shí)間戳（以日期的形式魄衅，如 2013-05-04T21:53:59.234+0800）
-XX:+PrintHeapAtGC 在進(jìn)行GC的前后打印出堆的信息
-verbose:gc
-XX:+PrintReferenceGC 打印年輕代各個引用的數(shù)量以及時(shí)長
本文假設(shè)讀者已經(jīng)熟悉JVM 內(nèi)存結(jié)構(gòu)钉跷。
1.1 -XX:+PrintGC與-verbose:gc
如果想開啟GC日志的信息，可以通過設(shè)置如下的參數(shù)任一參數(shù)：
-XX:+PrintGC
-XX:+PrintGCDetails
-Xloggc:gc.log
如果只設(shè)置-XX:+PrintGC那么打印的日志如下所示：
[GC (Allocation Failure) 61805K->9849K(256000K), 0.0041139 secs]
1崎逃、GC 表示是一次YGC（Young GC）
2失尖、Allocation Failure 表示是失敗的類型
3、68896K->5080K 表示年輕代從68896K降為5080K
4纬朝、256000K表示整個堆的大小
5收叶、0.0041139 secs表示這次GC總計(jì)所用的時(shí)間
在JDK 8中，-verbose:gc是-XX:+PrintGC一個別稱共苛，日志格式等價(jià)與：-XX:+PrintGC判没，。
不過在JDK 9中 -XX:+PrintGC被標(biāo)記為deprecated隅茎。
-verbose:gc是一個標(biāo)準(zhǔn)的選項(xiàng)澄峰， -XX:+PrintGC是一個實(shí)驗(yàn)的選項(xiàng)，建議使用-verbose:gc替代-XX:+PrintGC
參考：Difference between -XX:+PrintGC and -verbose:gc
1.2 -XX:+PrintGCDetails
[GC (Allocation Failure) [PSYoungGen: 53248K->2176K(59392K)] 58161K->7161K(256000K), 0.0039189 secs] [Times: user=0.02 sys=0.01, real=0.00 secs]
1辟犀、GC 表示是一次YGC（Young GC）
2俏竞、Allocation Failure 表示是失敗的類型
3、PSYoungGen 表示年輕代大小
4、53248K->2176K 表示年輕代占用從53248K降為2176K
5魂毁、59392K表示年輕帶的大小
6玻佩、58161K->7161K 表示整個堆占用從53248K降為2176K
7、256000K表示整個堆的大小
8席楚、 0.0039189 secs 表示這次GC總計(jì)所用的時(shí)間
9咬崔、[Times: user=0.02 sys=0.01, real=0.00 secs] 分別表示，用戶態(tài)占用時(shí)長烦秩，內(nèi)核用時(shí)垮斯，真實(shí)用時(shí)。
時(shí)間保留兩位小數(shù)闻镶，四舍五入甚脉。
1.3 -XX:+PrintGCTimeStamps
1.963: [GC (Allocation Failure) 61805K->9849K(256000K), 0.0041139 secs]
如果加上-XX:+PrintGCTimeStamps那么日志僅僅比1.1介紹的最前面多了一個時(shí)間戳： 1.963， 表示從JVM啟動到打印GC時(shí)刻用了1.963秒铆农。
1.4 -XX:+PrintGCDateStamps
2019-03-05T16:56:15.108+0800: [GC (Allocation Failure) 61805K->9849K(256000K), 0.0041139 secs]
如果加上-XX:+PrintGCDateStamps那么日志僅僅比1.1介紹的最前面多了一個日期時(shí)間： 2019-03-05T16:56:15.108+0800牺氨， 表示打印GC的時(shí)刻的時(shí)間是2019-03-05T16:56:15.108+0800。+0800表示是東8區(qū)墩剖。
1.5 -XX:+PrintHeapAtGC
這個參數(shù)開啟后猴凹，
使用如下參數(shù)-verbose:gc -XX:+PrintHeapAtGC -Xmn64M -Xms256M -Xmx256M
打印日志如下：
{Heap before GC invocations=1 (full 0):
PSYoungGen total 57344K, used 49152K [0x00000000fc000000, 0x0000000100000000, 0x0000000100000000)
eden space 49152K, 100% used [0x00000000fc000000,0x00000000ff000000,0x00000000ff000000)
from space 8192K, 0% used [0x00000000ff800000,0x00000000ff800000,0x0000000100000000)
to space 8192K, 0% used [0x00000000ff000000,0x00000000ff000000,0x00000000ff800000)
ParOldGen total 196608K, used 0K [0x00000000f0000000, 0x00000000fc000000, 0x00000000fc000000)
object space 196608K, 0% used [0x00000000f0000000,0x00000000f0000000,0x00000000fc000000)
Metaspace used 7901K, capacity 8264K, committed 8448K, reserved 1056768K
class space used 888K, capacity 986K, committed 1024K, reserved 1048576K
[GC (Allocation Failure) 49152K->2416K(253952K), 0.0030218 secs]
Heap after GC invocations=1 (full 0):
PSYoungGen total 57344K, used 2400K [0x00000000fc000000, 0x0000000100000000, 0x0000000100000000)
eden space 49152K, 0% used [0x00000000fc000000,0x00000000fc000000,0x00000000ff000000)
from space 8192K, 29% used [0x00000000ff000000,0x00000000ff258020,0x00000000ff800000)
to space 8192K, 0% used [0x00000000ff800000,0x00000000ff800000,0x0000000100000000)
ParOldGen total 196608K, used 16K [0x00000000f0000000, 0x00000000fc000000, 0x00000000fc000000)
object space 196608K, 0% used [0x00000000f0000000,0x00000000f0004000,0x00000000fc000000)
Metaspace used 7901K, capacity 8264K, committed 8448K, reserved 1056768K
class space used 888K, capacity 986K, committed 1024K, reserved 1048576K
}
由此可以看出在，打印如下日志前后
[GC (Allocation Failure) 49152K->2416K(253952K), 0.0030218 secs]
詳細(xì)打印出了日志信息
invocations 表示GC的次數(shù)岭皂，每次GC增加一次郊霎，每次GC前后的invocations相等
1、Heap before GC invocations=1 表示是第1次GC調(diào)用之前的堆內(nèi)存狀況
2爷绘、{Heap before GC invocations=1 (full 0): 表示是第1次GC調(diào)用之后的堆內(nèi)存狀況
1.6 -Xloggc:gc.log
如果使用該參數(shù)-Xloggc則默認(rèn)開啟如下兩個參數(shù)
-XX:+PrintGC -XX:+PrintGCTimeStamps
如果啟動參數(shù)如下：-Xloggc:gc.log -Xmn64M -Xms256M -Xmx256M則日志格式如下所示
0.318: [GC (Allocation Failure) 49152K->2384K(253952K), 0.0038675 secs]
gc.log也可以指定絕對的路徑书劝。
在gc.log最前面還會默認(rèn)打印系統(tǒng)的JDK版本與啟動的參數(shù)
Java HotSpot(TM) 64-Bit Server VM (25.144-b01) for linux-amd64 JRE (1.8.0_144-b01), built on Jul 21 2017 21:57:33 by "java_re" with gcc 4.3.0 20080428 (Red Hat 4.3.0-8)
Memory: 4k page, physical 16287104k(1657700k free), swap 16636924k(15826632k free)
CommandLine flags: -XX:InitialHeapSize=268435456 -XX:MaxHeapSize=268435456 -XX:MaxNewSize=67108864 -XX:NewSize=67108864 -XX:+PrintGC -XX:+PrintGCTimeStamps -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseParallelGC
1.7 -XX:+PrintReferenceGC
此設(shè)置 -XX:+PrintReferenceGC可以打印出SoftReference，WeakReference土至，F(xiàn)inalReference购对，PhantomReference，JNI Weak Reference幾種引用的數(shù)量陶因，以及清理所用的時(shí)長骡苞，該參數(shù)在進(jìn)行YGC調(diào)優(yōu)時(shí)可以排上用場。
[GC (Allocation Failure) [SoftReference, 0 refs, 0.0000119 secs][WeakReference, 499 refs, 0.0000370 secs][FinalReference, 1045 refs, 0.0002313 secs][PhantomReference, 0 refs, 0 refs, 0.0000039 secs][JNI Weak Reference, 0.0000290 secs][PSYoungGen: 53456K->4880K(57344K)] 53496K->4928K(253952K), 0.0037199 secs] [Times: user=0.02 sys=0.01, real=0.01 secs]
具體可以參考占小狼的一篇實(shí)戰(zhàn)：一次 Young GC 的優(yōu)化實(shí)踐（FinalReference 相關(guān)）
三楷扬、CMS GC日志詳細(xì)分析
[GC (CMS Initial Mark) [1 CMS-initial-mark: 19498K(32768K)] 36184K(62272K), 0.0018083 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
[CMS-concurrent-mark-start]
[CMS-concurrent-mark: 0.011/0.011 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
[CMS-concurrent-preclean-start]
[CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
[CMS-concurrent-abortable-preclean-start]
CMS: abort preclean due to time [CMS-concurrent-abortable-preclean: 0.558/5.093 secs] [Times: user=0.57 sys=0.00, real=5.09 secs]
[GC (CMS Final Remark) [YG occupancy: 16817 K (29504 K)][Rescan (parallel) , 0.0021918 secs][weak refs processing, 0.0000245 secs][class unloading, 0.0044098 secs][scrub symbol table, 0.0029752 secs][scrub string table, 0.0006820 secs][1 CMS-remark: 19498K(32768K)] 36316K(62272K), 0.0104997 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
[CMS-concurrent-sweep-start]
[CMS-concurrent-sweep: 0.007/0.007 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
[CMS-concurrent-reset-start]
[CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
CMS日志分為兩個STW(stop the world)
分別是init remark（1） 與 remark（7）兩個階段解幽。一般耗時(shí)比YGC長約10倍（個人經(jīng)驗(yàn)）。
（1）烘苹、[GC (CMS Initial Mark) [1 CMS-initial-mark: 19498K(32768K)] 36184K(62272K), 0.0018083 secs][Times: user=0.01 sys=0.00, real=0.01 secs]
會STO(Stop The World)躲株，這時(shí)候的老年代容量為 32768K， 在使用到 19498K 時(shí)開始初始化標(biāo)記镣衡。耗時(shí)短徘溢。
（2）吞琐、[CMS-concurrent-mark-start]
并發(fā)標(biāo)記階段開始
（3）、[CMS-concurrent-mark: 0.011/0.011 secs] [Times: user=0.02 sys=0.00, real=0.00 secs]
并發(fā)標(biāo)記階段花費(fèi)時(shí)間然爆。
（4）、[CMS-concurrent-preclean-start]
并發(fā)預(yù)清理階段黍图，也是與用戶線程并發(fā)執(zhí)行曾雕。虛擬機(jī)查找在執(zhí)行并發(fā)標(biāo)記階段新進(jìn)入老年代的對象(可能會有一些對象從新生代晉升到老年代， 或者有一些對象被分配到老年代)助被。通過重新掃描剖张，減少下一個階段”重新標(biāo)記”的工作，因?yàn)橄乱粋€階段會Stop The World揩环。
（5）搔弄、[CMS-concurrent-preclean: 0.001/0.001 secs] [Times: user=0.00 sys=0.00, real=0.01 secs]
并發(fā)預(yù)清理階段花費(fèi)時(shí)間。
（6）丰滑、[CMS-concurrent-abortable-preclean-start] CMS: abort preclean due to time [CMS-concurrent-abortable-preclean: 0.558/5.093 secs][Times: user=0.57 sys=0.00, real=5.09 secs]
并發(fā)可中止預(yù)清理階段顾犹，運(yùn)行在并行預(yù)清理和重新標(biāo)記之間，直到獲得所期望的eden空間占用率褒墨。增加這個階段是為了避免在重新標(biāo)記階段后緊跟著發(fā)生一次垃圾清除
（7）炫刷、[GC (CMS Final Remark) [YG occupancy: 16817 K (29504 K)][Rescan (parallel) , 0.0021918 secs][weak refs processing, 0.0000245 secs][class unloading, 0.0044098 secs][scrub symbol table, 0.0029752 secs][scrub string table, 0.0006820 secs][1 CMS-remark: 19498K(32768K)] 36316K(62272K), 0.0104997 secs] [Times: user=0.02 sys=0.00, real=0.01 secs]
會STW(Stop The World)，收集階段郁妈，這個階段會標(biāo)記老年代全部的存活對象浑玛，包括那些在并發(fā)標(biāo)記階段更改的或者新創(chuàng)建的引用對象
（8）、[CMS-concurrent-sweep-start]
并發(fā)清理階段開始噩咪，與用戶線程并發(fā)執(zhí)行顾彰。
（9）、[CMS-concurrent-sweep: 0.007/0.007 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
并發(fā)清理階段結(jié)束胃碾，所用的時(shí)間涨享。
（10）、[CMS-concurrent-reset-start]
開始并發(fā)重置书在。在這個階段灰伟，與CMS相關(guān)數(shù)據(jù)結(jié)構(gòu)被重新初始化，這樣下一個周期可以正常進(jìn)行儒旬。
（11）栏账、[CMS-concurrent-reset: 0.000/0.000 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
并發(fā)重置所用結(jié)束，所用的時(shí)間栈源。
參考：
Geek-Yan: JVM 學(xué)習(xí)筆記(四) CMS GC日志詳解
四挡爵、GC調(diào)優(yōu)
設(shè)置JVM GC 性能的有如下參數(shù)
4.1 -Xmn
新生代大小官網(wǎng)推薦的大小是3/8, 如果設(shè)置太小，比如1/10會導(dǎo)致Minor GC 與Major GC次數(shù)增多甚垦。
4.2 -XX:MaxTenuringThreshold=n
其中n的大小為區(qū)間為[0,15],如果高于15茶鹃，JDK7 會默認(rèn)15涣雕，JDK 8會啟動報(bào)錯
五、常見問題
1 .并發(fā)模式失敱蒸妗（concurrent mode failure）
發(fā)生在CMS GC運(yùn)行期間挣郭，詳情參考：
JVM 調(diào)優(yōu) —— GC 長時(shí)間停頓問題及解決方法
2. 提升失敗（promotion failed）
發(fā)生在Minor GC期間
