GC日志參數(shù)

-verbose:gc

輸出gc日志信息，默認(rèn)輸出到標(biāo)準(zhǔn)輸出

-XX:+PrintGC

輸出GC日志。類似：-verbose:gc

-XX:+PrintGCDetails

在發(fā)生垃圾回收時(shí)打印內(nèi)存回收詳細(xì)的日志，并在進(jìn)程退出時(shí)輸出當(dāng)前內(nèi)存各區(qū)域分配情況

-XX:+PrintGCTimeStamps

輸出GC發(fā)生時(shí)的時(shí)間戳

-XX:+PrintGCDateStamps

輸出GC發(fā)生時(shí)的時(shí)間戳（以日期的形式，如2013-05-04T21:53:59.234+0800)

-XX:+PrintHeapAtGC

每一次GC前和GC后，都打印堆信息

-Xloggc:<file>

表示把GC日志寫(xiě)入到一個(gè)文件中去，而不是打印到標(biāo)準(zhǔn)輸出中

GC日志格式

GC日志分類

MinorGC

????????MinorGC(或young GC或YGC)日志：

[GC (Allocation Failure) [PSYoungGen: 31744K->2192K(36864K)] 31744K->2200K(121856K), 0.0139308 secs] [Times: user=0.05 sys=0.01, real=0.01 secs]?

FullGC

????????Full GC日志介紹：

[Full GC (Metadata GC Threshold) [PSYoungGen: 5104K->0K(132096K)] [ParOldGen: 416K->5453K(50176K)] 5520K->5453K(182272K), [Metaspace: 20637K->20637K(1067008K)], 0.0245883 secs] [Times: user=0.06 sys=0.00, real=0.02 secs]?

GC日志結(jié)構(gòu)剖析

垃圾收集器

• 使用Serial收集器在新生代的名字是Default New Generation，因此顯示的是"[DefNew"
• 使用ParNew收集器在新生代的名字會(huì)變成"[ParNew",意思是"Parallel New Generation"
• 使用Parallel Scavenge收集器在新生代的名字是"[PSYoungGen",這里的JDK1.7使用的就是PSYoungGen
• 使用Parallel Old Generation收集器在老年代的名字是"[ParOldGen"
• 使用G1收集器的話，會(huì)顯示為"garbage-first heap"

Allocation Failure：表明本次引起GC的原因是因?yàn)樵?strong>年輕代中沒(méi)有足夠的空間能夠存儲(chǔ)新的數(shù)據(jù)了。

GC前后情況

????????我們可以發(fā)現(xiàn)GC日志格式的規(guī)律一般都是：GC前內(nèi)存占用—>GC后內(nèi)存占用（該區(qū)域內(nèi)存總大小）

????????[PSYoungGen: 5986K->696K(8704K)] 5986K->704K(9216K)

????????中括號(hào)內(nèi)：GC回收前年輕代堆大小，回收后大小，（年輕代堆總大小）

????????括號(hào)外：GC回收前年輕代和老年代大小，回收后大小，（年輕代和老年代總大小）

GC時(shí)間

GC日志中有三個(gè)時(shí)間：user，sys和real

• user – 進(jìn)程執(zhí)行用戶態(tài)代碼（核心之外）所使用的時(shí)間。這是執(zhí)行此進(jìn)程所使用的實(shí)際 CPU 時(shí)間，其他進(jìn)程和此進(jìn)程阻塞的時(shí)間并不包括在內(nèi)。在垃圾收集的情況下，表示 GC 線程執(zhí)行所使用的 CPU 總時(shí)間。
• sys – 進(jìn)程在內(nèi)核態(tài)消耗的 CPU 時(shí)間，即在內(nèi)核執(zhí)行系統(tǒng)調(diào)用或等待系統(tǒng)事件所使用的 CPU?時(shí)間。
• real – 程序從開(kāi)始到結(jié)束所用的時(shí)鐘時(shí)間。這個(gè)時(shí)間包括其他進(jìn)程使用的時(shí)間片和進(jìn)程阻塞的時(shí)間（比如等待 I/O 完成）。對(duì)于并行g(shù)c，這個(gè)數(shù)字應(yīng)該接近（用戶時(shí)間+系統(tǒng)時(shí)間）除以垃圾收集器使用的線程數(shù)。

????????由于多核的原因，一般的GC事件中，real time是小于sys + user time的，因?yàn)橐话闶嵌鄠€(gè)線程并發(fā)的去做GC，所以real time是要小于sys+user time的。如果real>sys+user的話，則你的應(yīng)用可能存在下列問(wèn)題：IO負(fù)載非常重或者是CPU不夠用。

Minor GC日志解析

2020-11-20T17:19:43.265-0800: 0.822: [GC (ALLOCATION FAILURE) [PSYOUNGGEN: 76800K->8433K(89600K)] 76800K->8449K(294400K), 0.0088371 SECS] [TIMES: USER=0.02 SYS=0.01, REAL=0.01 SECS]?

2020-11-20T17:19:43.265-0800

????????日志打印時(shí)間日期格式如2013-05-04T21:53:59.234+0800

0.822

????????gc發(fā)生時(shí)，Java虛擬機(jī)啟動(dòng)以來(lái)經(jīng)過(guò)的秒數(shù)

[GC (ALLOCATION FAILURE)

????????發(fā)生了一次垃圾回收，這是一次Minor GC。它不區(qū)分新生代GC還是老年代GC，括號(hào)里的內(nèi)容是gc發(fā)生的原因，這里的Allocation Failure的原因是新生代中沒(méi)有足夠區(qū)域能夠存放需要分配的數(shù)層而失敗。

[PSYOUNGGEN: 76800K->8433K(89600K)]

PSYoungGen:表示GC發(fā)生的區(qū)域，區(qū)域名稱與使用的GC收集器是密切相關(guān)的

1. Serial收集器：Default New Generation顯示DefNew
2. ParNew收集器：ParNew
3. Parallel Scanvengel收集器：PSYoung
4. 老年代和新生代同理，也是和收集器名稱相關(guān)

76800K->8433K(89600K：GC前該內(nèi)存區(qū)域已使用容量·>GC后該區(qū)域容量（該區(qū)域總?cè)萘?#xff09;

1. 如果是新生代，總?cè)萘縿t會(huì)顯示整個(gè)新生代內(nèi)存的9/10，即eden+from/to區(qū)
2. 如果是老年代，總?cè)萘縿t是全部?jī)?nèi)存大小，無(wú)變化

76800K->8449K(294400K)

????????在顯示完區(qū)域容量GC的情況之后，會(huì)接著顯示整個(gè)堆內(nèi)存區(qū)域的GC情況：GC前堆內(nèi)存已使用容量·>GC堆內(nèi)存容量（堆內(nèi)存總?cè)萘?#xff09;

????????堆內(nèi)存總?cè)萘?#61;9/10新生代+老年代<初始化的內(nèi)存大小

0.0088371 SECS

????????整個(gè)GC所花費(fèi)的時(shí)間，單位是秒

[TIMES: USER=0.02 SYS=0.01, REAL=0.01 SECS]?

????????user：指的是CPU工作在用戶態(tài)所花費(fèi)的時(shí)間

????????sys：指的是CPU工作在內(nèi)核態(tài)所花費(fèi)的時(shí)間

????????rea：指的是在此次Gc事件中所花費(fèi)的總時(shí)間

Full GC日志解析

2020-11-20T17:19:43.794-0800: 1.351: [FULL GC (METADATA GC THRESHOLD) [PSYOUNGGEN: 10082K->0K(89600K)] [PAROLDGEN: 32K->9638K(204800K)] 10114K->9638K(294400K),[METASPACE: 20158K->20156K(1067008K)], 0.0285388 SECS] [TIMES: USER=0.11 SYS=0.00, REAL=0.03 SECS]?

2020-11-20T17:19:43.794-0800

????????日志打印時(shí)間日期格式如2013-05-04T21:53:59.234+0800

1.351

????????gc發(fā)生時(shí)，Java虛擬機(jī)啟動(dòng)以來(lái)經(jīng)過(guò)的秒數(shù)

FULL GC (METADATA GC THRESHOLD)

????????發(fā)生了一次垃圾回收，這是一次FULL GC。它不區(qū)分新生代GC還是老年代GC。括號(hào)里的內(nèi)容是gc發(fā)生的原因，這里的Metadata GC Threshold的原因是Metaspacel區(qū)不夠用了。

????????Full GC(Ergonomics)：JVM自適應(yīng)調(diào)整導(dǎo)致的GC

????????Full GC(System)：調(diào)用了System.gc()方法

[PSYOUNGGEN: 10082K->0K(89600K)]

????????PSYoungGen:表示GC發(fā)生的區(qū)域，區(qū)域名稱與使用的GC收集器是密切相關(guān)的

1. Seriall收集器：Default New Generation顯示DefNew
2. ParNewl收集器：ParNew
3. Parallel Scanvengel收集器：PSYoung
4. 老年代和新生代同理，也是和收集器名稱相關(guān)

????????10082K->0K(89600K):GC前該內(nèi)存區(qū)域已使用容量 --> GC后該區(qū)域容量（該區(qū)域總?cè)萘?#xff09;

1. 如果是新生代，總?cè)萘縿t會(huì)顯示整個(gè)新生代內(nèi)存的9/10，即eden+from/to區(qū)
2. 如果是老年代，總?cè)萘縿t是全部?jī)?nèi)存大小，無(wú)變化

[PAROLDGEN: 32K->9638K(204800K)]

????????老年代區(qū)域沒(méi)有發(fā)生GC，因?yàn)楸敬蜧C是metaspace起的

10114K->9638K(294400K)

????????在顯示完區(qū)域容量GC的情況之后，會(huì)接著顯示整個(gè)堆內(nèi)存區(qū)域的GC情況：GC前堆內(nèi)存已使用容量 --> GC堆內(nèi)存容量（堆內(nèi)存總?cè)萘?#xff09;堆內(nèi)存總?cè)萘?#61;9/10新生代+老年代<初始化的內(nèi)存大小

[METASPACE: 20158K->20156K(1067008K)]

????????metaspace GC回收2K空間

0.0285388 SECS

????????整個(gè)GC所花費(fèi)的時(shí)間，單位是秒

[TIMES: USER=0.11 SYS=0.00, REAL=0.03 SECS]?

????????user：指的是CPU工作在用戶態(tài)所花費(fèi)的時(shí)間

????????sys：指的是CPU工作在內(nèi)核態(tài)所花費(fèi)的時(shí)間

????????rea：指的是在此次Gc事件中所花費(fèi)的總時(shí)間

案例演示

代碼

/*** 在jdk7 和 jdk8中分別執(zhí)行*  * -verbose:gc -Xms20M -Xmx20M -Xmn10M -XX:+PrintGCDetails -XX:SurvivorRatio=8 -XX:+UseSerialGC*/
public class GCLogTest1 {private static final int _1MB = 1024 * 1024;public static void testAllocation() {byte[] allocation1, allocation2, allocation3, allocation4;allocation1 = new byte[2 * _1MB];allocation2 = new byte[2 * _1MB];allocation3 = new byte[2 * _1MB];allocation4 = new byte[4 * _1MB];}public static void main(String[] agrs) {testAllocation();}
}

圖解

在JDK7中：與jdk8中有所不同

GC日志分析工具

????????上節(jié)介紹了GC日志的打印及含義，但是GC日志看起來(lái)比較麻煩，本節(jié)將會(huì)介紹一下GC日志可視化分析工具GCeasy和GCviewer等。通過(guò)GC日志可視化分析工具，我們可以很方便的看到JVM各個(gè)分代的內(nèi)存使用情況、垃圾回收次數(shù)、垃圾回收的原因、垃圾回收占用的時(shí)間、吞吐量等，這些指標(biāo)在我們進(jìn)行JVM調(diào)優(yōu)的時(shí)候是很有用的。

????????如果想把GC日志存到文件的話， 是下面這個(gè)參數(shù)：-Xloggc:/path/to/gc.log?然后就可以用一些工具去分析這些gc日志。

GCeasy

????????GCeasy——一款超好用的在線分析GC日志的網(wǎng)站

????????官網(wǎng)地址：https://gceasy.io/，GCeasy是一款在線的GC日志分析器，可以通過(guò)GC日志分析進(jìn)行內(nèi)存泄漏檢測(cè)、GC暫停原因分析、JVM配置建議優(yōu)化等功能，而且是可以免費(fèi)使用的（有一些服務(wù)是收費(fèi)的）。

GCViewer

????????GCViewer是一個(gè)免費(fèi)的、開(kāi)源的分析小工具，用于可視化查看由SUN/Oracle,IBM,HP和BEA Java虛擬機(jī)產(chǎn)生的垃圾收集器的日志。

????????GCViewer用于可視化Java VM選項(xiàng)-verbose:gc?和.NET生成的數(shù)據(jù)-Xloggc:<file>。它還計(jì)算與垃圾回收相關(guān)的性能指標(biāo)（吞吐量，累積的暫停，最長(zhǎng)的暫停等）。當(dāng)通過(guò)更改世代大小或設(shè)置初始堆大小來(lái)調(diào)整特定應(yīng)用程序的垃圾回收時(shí)，此功能非常有用。

1.下載GCViewer工具

????????源碼下載：https://github.com/chewiebug/GCViewer

????????運(yùn)行版本下載：https://github.com/chewiebug/GCViewer/wiki/Changelog

2.只需雙擊gcviewer-1.3x.jar或運(yùn)行java -jar gcviewer-1.3x.jar（它需要運(yùn)行java 1.8 vm），即可啟動(dòng)GCViewer（gui）

其他工具

GChisto：GChisto是一款專業(yè)分析gc日志的工具，可以通過(guò)gc日志來(lái)分析：MinorGC、Full GC的次數(shù)、頻率、持續(xù)時(shí)間等，通過(guò)列表、報(bào)表、圖表等不同形式來(lái)反應(yīng)gc的情況。

HPjmeter：工具很強(qiáng)大，但只能打開(kāi)由以下參數(shù)生成的GC log，verbose:gc-XIoggc:gc.log。添加其他參數(shù)生成的gc.log無(wú)法打開(kāi)。HPjmeter集成了以前的HPjtunel功能，可以分析在HP機(jī)器上產(chǎn)生的垃圾回收日志文件