文章目錄

• 概述
• GC格式
• 實(shí)例
• GC監(jiān)控
• • 安裝GC可視化插件
  • 啟動(dòng)本地進(jìn)程，監(jiān)控和分析GC情況
• GC日志分析工具

概述

每一種收集器的日志形式都是由他們自身的實(shí)現(xiàn)決定的，也就是說(shuō)每個(gè)收集器的日志格式都可能不一樣。

---

GC格式

一般來(lái)說(shuō)，常見(jiàn)的格式如下：

[GC [<collector>: <starting occupancy1> -> <ending occupancy1>, <pause time1> secs] <starting occupancy3> -> <ending occupancy3>, <pause time3> secs]

• <collector> GC為minor收集過(guò)程中使用的垃圾收集器起的內(nèi)部名稱(chēng).
• <starting occupancy1> young generation 在進(jìn)行垃圾收集前被對(duì)象使用的存儲(chǔ)空間.
• <ending occupancy1> young generation 在進(jìn)行垃圾收集后被對(duì)象使用的存儲(chǔ)空間
• <pause time1> minor收集使應(yīng)用暫停的時(shí)間長(zhǎng)短(秒)
• <starting occupancy3> 整個(gè)堆(Heap Size)在進(jìn)行垃圾收集前被對(duì)象使用的存儲(chǔ)空間
• <ending occupancy3> 整個(gè)堆(Heap Size)在進(jìn)行垃圾收集后被對(duì)象使用的存儲(chǔ)空間
• <pause time3> 整個(gè)垃圾收集使應(yīng)用暫停的時(shí)間長(zhǎng)短(秒),包括major收集使應(yīng)用暫停的時(shí)間(如果發(fā)生了major收集).

---

實(shí)例

我們用前面博文中的例子來(lái)打印下GC日志，然后分析解讀下

VM Args :

-XX:+PrintGCDetails -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime

• -XX:+PrintGCDetails 顯示GC的詳細(xì)信息

• -XX:+PrintGCApplicationConcurrentTime 打印應(yīng)用執(zhí)行的時(shí)間

• -XX:+PrintGCApplicationStoppedTime 打印應(yīng)用被暫停的時(shí)間

package com.artisan.gc;/*** * * @ClassName: ReferenceCountingGC* * @Description: VM Args* * @author: Mr.Yang* * @date: 2018年7月29日 上午10:31:32*/ public class ReferenceCountingGC {private Object instance;private static final int _1M = 1024 * 1024;// 設(shè)置個(gè)成員變量，在堆中占點(diǎn)內(nèi)存，以便觀(guān)察GC是否回收相互引用的情況private byte[] bigByte = new byte[2 * _1M];public static void main(String[] args) {ReferenceCountingGC rc = new ReferenceCountingGC();ReferenceCountingGC rc2 = new ReferenceCountingGC();// 設(shè)置相互引用rc.instance = rc2;rc2.instance = rc;// 將對(duì)象置為空rc.instance = null;rc2.instance = null;// 垃圾回收,觀(guān)察rc 和 rc2能否被回收System.gc();}}

設(shè)置完虛擬機(jī)參數(shù)后，執(zhí)行main方法，輸入如下

Application time: 0.0087943 seconds [GC [PSYoungGen: 4906K->4400K(47232K)] 4906K->4400K(155264K), 0.0020510 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] [Full GC (System) [PSYoungGen: 4400K->0K(47232K)] [PSOldGen: 0K->4255K(108032K)] 4400K->4255K(155264K) [PSPermGen: 2977K->2977K(21248K)], 0.0076827 secs] [Times: user=0.01 sys=0.00, real=0.01 secs] Total time for which application threads were stopped: 0.0098759 seconds HeapPSYoungGen total 47232K, used 1620K [0x00000007cb400000, 0x00000007ce8b0000, 0x0000000800000000)eden space 40512K, 4% used [0x00000007cb400000,0x00000007cb5952b8,0x00000007cdb90000)from space 6720K, 0% used [0x00000007cdb90000,0x00000007cdb90000,0x00000007ce220000)to space 6720K, 0% used [0x00000007ce220000,0x00000007ce220000,0x00000007ce8b0000)PSOldGen total 108032K, used 4255K [0x0000000761c00000, 0x0000000768580000, 0x00000007cb400000)object space 108032K, 3% used [0x0000000761c00000,0x0000000762027c80,0x0000000768580000)PSPermGen total 21248K, used 2995K [0x000000075ca00000, 0x000000075dec0000, 0x0000000761c00000)object space 21248K, 14% used [0x000000075ca00000,0x000000075ccecc30,0x000000075dec0000) Application time: 0.0006608 seconds

我們重點(diǎn)來(lái)說(shuō)下 -XX:+PrintGCDetails 虛擬機(jī)參數(shù)輸出的數(shù)據(jù)

GC日志開(kāi)頭的 [GC 和 [Full GC 說(shuō)明了這次垃圾收集器的停頓類(lèi)型，而不是用來(lái)區(qū)分新生代GC還是老年GC的。

如果有 Full ，說(shuō)明了這次GC發(fā)生了Stop-The-World.

如果是調(diào)用了System.gc()方法所觸發(fā)的收集，那么將顯示[Full GC (System)，如上日志所示。

接下來(lái)的“[DefNew” 或者 “[Tenured” 或者“[Perm” 表示GC發(fā)生的區(qū)域，這里顯示的區(qū)域名稱(chēng)和使用的GC收集器密切相關(guān)。

• 如果是用的Serial收集器，新生代名為“Default New Generation”,所以顯示“[DefNew”。
• 如果是用的ParNew收集器，新生代名為“Parallel New Generation”,所以顯示“[ParNew”。
• 如果是用的Parallel Scavenge收集器，新生代名則顯示為“[PSYongGen”,如日志中顯示。

老年代和永久代同理，名稱(chēng)也是由收集器決定的。

后面方括號(hào)內(nèi)部的 4906K->4400K(47232K)含義是 “GC前該內(nèi)存區(qū)域已經(jīng)使用的容量->GC后該內(nèi)存區(qū)域已使用的容量（該內(nèi)存區(qū)域中容量）”

方括號(hào)之外的 4906K->4400K(155264K) 表示“GC前Java堆已使用容量->GC后Java堆已使用容量（Java堆中容量）”

再往后 0.0020510 secs表示該內(nèi)存區(qū)域GC所占用的時(shí)間，單位為秒。

[Times: user=0.00 sys=0.00, real=0.00 secs]

是更具體的時(shí)間數(shù)據(jù)，取決于收集器，有些收集器可能不打印。

這里面的user、sys、real和Linux的time命令輸出的時(shí)間含義是一致的，分別代表用戶(hù)態(tài)消耗的CPU時(shí)間、內(nèi)核態(tài)消耗的CPU時(shí)間和操作從開(kāi)始到結(jié)束鎖經(jīng)理的墻鐘時(shí)間（Wall Clock Time）.

CPU時(shí)間和墻鐘時(shí)間的區(qū)別是： 墻鐘時(shí)間包括各種費(fèi)運(yùn)算的等待耗時(shí)，比如磁盤(pán)I/O、等待線(xiàn)程阻塞。 而CPU時(shí)間則不包含這些耗時(shí)，但當(dāng)系統(tǒng)有多CPU或者多核的話(huà)，多線(xiàn)程操作會(huì)疊加CPU時(shí)間，所以讀者看到user或者sys時(shí)間超過(guò)real時(shí)間是完全正常的。

---

GC監(jiān)控

##打開(kāi) Java VisualVM
市面上有很多GC監(jiān)控和分析工具，這里我們使用JDK自帶的Java VisualVM，位于JDK的bin目錄下

Java VisualVM的作用不止于此：

• 生成和分析堆內(nèi)存轉(zhuǎn)儲(chǔ)
• 查看和操作MBean
• 監(jiān)控垃圾回收
• 內(nèi)存和CPU分析

---

安裝GC可視化插件

工具–插件

---

啟動(dòng)本地進(jìn)程，監(jiān)控和分析GC情況

還有些其他功能，這里不再闡述了，如何分析觀(guān)察，另開(kāi)篇找個(gè)案例介紹。

---

GC日志分析工具

如果GC日志比較多，一般情況我們不直接閱讀，都是通過(guò)GC日志分析工具提供的圖形化頁(yè)面來(lái)查看。

這里省略，后續(xù)開(kāi)篇單獨(dú)介紹

有個(gè)網(wǎng)頁(yè)版的 http://gceasy.io/

總結(jié)

以上是生活随笔為你收集整理的JVM-07垃圾收集Garbage Collection【GC日志分析】的全部?jī)?nèi)容，希望文章能夠幫你解決所遇到的問(wèn)題。

如果覺(jué)得生活随笔網(wǎng)站內(nèi)容還不錯(cuò)，歡迎將生活随笔推薦給好友。