JVM-07垃圾收集Garbage Collection【GC日志分析】
文章目錄
- 概述
- GC格式
- 實例
- GC監控
- 安裝GC可視化插件
- 啟動本地進程,監控和分析GC情況
- GC日志分析工具
概述
每一種收集器的日志形式都是由他們自身的實現決定的,也就是說每個收集器的日志格式都可能不一樣。
GC格式
一般來說,常見的格式如下:
[GC [<collector>: <starting occupancy1> -> <ending occupancy1>, <pause time1> secs] <starting occupancy3> -> <ending occupancy3>, <pause time3> secs]- <collector> GC為minor收集過程中使用的垃圾收集器起的內部名稱.
- <starting occupancy1> young generation 在進行垃圾收集前被對象使用的存儲空間.
- <ending occupancy1> young generation 在進行垃圾收集后被對象使用的存儲空間
- <pause time1> minor收集使應用暫停的時間長短(秒)
- <starting occupancy3> 整個堆(Heap Size)在進行垃圾收集前被對象使用的存儲空間
- <ending occupancy3> 整個堆(Heap Size)在進行垃圾收集后被對象使用的存儲空間
- <pause time3> 整個垃圾收集使應用暫停的時間長短(秒),包括major收集使應用暫停的時間(如果發生了major收集).
實例
我們用前面博文中的例子來打印下GC日志,然后分析解讀下
VM Args :
-XX:+PrintGCDetails -XX:+PrintGCApplicationConcurrentTime -XX:+PrintGCApplicationStoppedTime-
-XX:+PrintGCDetails 顯示GC的詳細信息
-
-XX:+PrintGCApplicationConcurrentTime 打印應用執行的時間
-
-XX:+PrintGCApplicationStoppedTime 打印應用被暫停的時間
設置完虛擬機參數后,執行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我們重點來說下 -XX:+PrintGCDetails 虛擬機參數輸出的數據
GC日志開頭的 [GC 和 [Full GC 說明了這次垃圾收集器的停頓類型,而不是用來區分新生代GC還是老年GC的。
如果有 Full ,說明了這次GC發生了Stop-The-World.
如果是調用了System.gc()方法所觸發的收集,那么將顯示[Full GC (System),如上日志所示。
接下來的“[DefNew” 或者 “[Tenured” 或者“[Perm” 表示GC發生的區域,這里顯示的區域名稱和使用的GC收集器密切相關。
- 如果是用的Serial收集器,新生代名為“Default New Generation”,所以顯示“[DefNew”。
- 如果是用的ParNew收集器,新生代名為“Parallel New Generation”,所以顯示“[ParNew”。
- 如果是用的Parallel Scavenge收集器,新生代名則顯示為“[PSYongGen”,如日志中顯示。
老年代和永久代同理,名稱也是由收集器決定的。
后面方括號內部的 4906K->4400K(47232K)含義是 “GC前該內存區域已經使用的容量->GC后該內存區域已使用的容量(該內存區域中容量)”
方括號之外的 4906K->4400K(155264K) 表示“GC前Java堆已使用容量->GC后Java堆已使用容量(Java堆中容量)”
再往后 0.0020510 secs表示該內存區域GC所占用的時間,單位為秒。
[Times: user=0.00 sys=0.00, real=0.00 secs]是更具體的時間數據,取決于收集器,有些收集器可能不打印。
這里面的user、sys、real和Linux的time命令輸出的時間含義是一致的,分別代表用戶態消耗的CPU時間、內核態消耗的CPU時間和操作從開始到結束鎖經理的墻鐘時間(Wall Clock Time).
CPU時間和墻鐘時間的區別是: 墻鐘時間包括各種費運算的等待耗時,比如磁盤I/O、等待線程阻塞。 而CPU時間則不包含這些耗時,但當系統有多CPU或者多核的話,多線程操作會疊加CPU時間,所以讀者看到user或者sys時間超過real時間是完全正常的。
GC監控
##打開 Java VisualVM
市面上有很多GC監控和分析工具,這里我們使用JDK自帶的Java VisualVM,位于JDK的bin目錄下
Java VisualVM的作用不止于此:
- 生成和分析堆內存轉儲
- 查看和操作MBean
- 監控垃圾回收
- 內存和CPU分析
安裝GC可視化插件
工具–插件
啟動本地進程,監控和分析GC情況
還有些其他功能,這里不再闡述了,如何分析觀察,另開篇找個案例介紹。
GC日志分析工具
如果GC日志比較多,一般情況我們不直接閱讀,都是通過GC日志分析工具提供的圖形化頁面來查看。
這里省略,后續開篇單獨介紹
有個網頁版的 http://gceasy.io/
總結
以上是生活随笔為你收集整理的JVM-07垃圾收集Garbage Collection【GC日志分析】的全部內容,希望文章能夠幫你解決所遇到的問題。
- 上一篇: JVM-05垃圾收集Garbage Co
- 下一篇: JVM-08垃圾收集Garbage Co