JVM 參數:跟蹤垃圾回收
1. 前言
本節內容主要是學習 JVM 跟蹤垃圾回收的常用參數配置,這是工作中跟蹤垃圾回收情況時 JVM 中最常用的參數配置,需要重點對本節內容進行學習。本節主要知識點如下:
- 掌握 IntelliJ IDEA 如何配置 JVM 參數,這是我們學習 JVM 參數配置的前提。對于有部分同學使用 Eclipse 作為開發工具的,可以自行搜索配置方式,此處只針對目前使用廣泛的 IntelliJ IDEA 工具進行介紹;
- 理解并掌握跟蹤垃圾回收的參數 -XX:+PrintGC,為本節重點內容;
- 理解并掌握跟蹤垃圾回收的參數 -XX:+PrintGCDetails,為本節重點內容;
- 理解并掌握跟蹤垃圾回收的參數 -XX:+PrintHeapAtGC,為本節重點內容;
- 理解并掌握跟蹤垃圾回收的參數 -XX:+PrintGCTimeStamps,為本節重點內容。
JVM 跟蹤垃圾回收的常用參數配置是使用 JVM 所必須的知識點,通篇皆為重點掌握內容,需要在理解的基礎上并掌握參數的使用方法。
2. IntelliJ IDEA 配置 JVM參數
通過開發工具 IntelliJ IDEA 配置 JVM參數,需要打開 “Run->Edit Configurations” 菜單,然后在 VM Options 中添加相應的 JVM 參數。
如上圖為添加 JVM 參數 -XX:+PrintGC 的圖片說明示例,掌握添加參數的方式,是學習具體參數配置的前提。
3. 示例代碼準備
為了能夠更好的體會,垃圾回收參數的執行效果,我們需要準備一段簡易的代碼,供我們執行使用,并在代碼中手動執行垃圾回收操作,觸發垃圾回收機制,使我們的參數能夠追蹤垃圾回收的動作,并打印相應的日志。
實例:準備測試代碼,創建一個 String 類型的 ArrayList,并在 list 中添加三個元素,分別是 “Hello”,“World”,“?。?!”。然后直接手動執行垃圾回收操作。
public class PrintGCParamsDemo {
public static void main(String[] args) {
ArrayList<String> list = new ArrayList<String>();
list.add("Hello");
list.add("World");
list.add("!!!");
System.gc(); //手動執行 gc 垃圾回收
}
}
Tips: 之所以要手動執行 gc 垃圾回收,是因為 JVM 自動的執行垃圾回收是需要一定的條件的,簡單的 main 函數是不能夠達到觸發垃圾回收的臨界值的。所以這里手動進行 gc 方法的調用,是為了展示我們的參數鎖帶來的作用。
4. -XX:+PrintGC 參數
參數作用:-XX:+PrintGC 參數是垃圾回收跟蹤中十分常用的參數。使用這個參數啟動 Java 虛擬機后,只要遇到 GC,就會打印日志。
為了更好的理解并掌握 -XX:+PrintGC 參數,我們通過如下步驟進行操作。
- 步驟 1:在 VM Options 中配置參數 -XX:+PrintGC 并保存;
- 步驟 2:運行示例代碼,觀察執行結果。
結果驗證:
[GC (System.gc()) 3933K->792K(251392K), 0.0054898 secs]
[Full GC (System.gc()) 792K->730K(251392K), 0.0290579 secs]
結果分析:由于這是第一次接觸 JVM 打印日志,我們按照字段逐一進行分析。
- GC 與 Full GC:代表了垃圾回收的類型,后續會有詳細的講解,這里了解日志意義即可;
- System.gc():代表了引發方式,是通過調用 gc 方法進行的垃圾回收;
- 3933K->792K(251392K):代表了之前使用了 3933k 的空間,回收之后使用 792k 空間,言外之意這次垃圾回收節省了 3933k - 792k = 3141k 的容量。251392K 代表總容量;
- 792K->730K(251392K):分析同上;
- 0.0054898 secs:代表了垃圾回收的執行時間,以秒為單位。
那么我們通過上邊的結果分析,可以非常順利的解讀這兩行日志。
5. -XX:+PrintGCDetails 參數
參數作用:-XX:+PrintGCDetails 參數是垃圾回收跟蹤中十分常用的參數,而且日志更加詳細。獲取比 -XX:+PrintGC 參數更詳細的 GC 信息。
為了更好的理解并掌握 -XX:+PrintGCDetails 參數,我們通過如下步驟進行操作。
- 步驟 1:在 VM Options 中配置參數 -XX:+PrintGCDetails 并保存;
- 步驟 2:運行示例代碼,觀察執行結果。
結果驗證:
[GC (System.gc()) [PSYoungGen: 3933K->792K(76288K)] 3933K->800K(251392K), 0.0034601 secs] [Times: user=0.00 sys=0.00, real=0.00 secs]
[Full GC (System.gc()) [PSYoungGen: 792K->0K(76288K)] [ParOldGen: 8K->730K(175104K)] 800K->730K(251392K), [Metaspace: 3435K->3435K(1056768K)], 0.0217628 secs] [Times: user=0.03 sys=0.00, real=0.02 secs]
結果分析: 這里只做新增部分的解釋。
- PSYoungGen:代表了「年輕代」的回收,在這里只需要了解即可,因為后續講解 JVM 堆內存以及垃圾回收原理時才會涉及到年輕代;
- ParOldGen:「老年代」這里只需要了解即可,因為后續講解 JVM 堆內存以及垃圾回收原理時才會涉及到老年代;
- Metaspace:「元空間」,JDK 的低版本也稱之為永久代,依然,此處了解即可。
我們看到 -XX:+PrintGCDetails 參數打印了更加詳細的日志內容,把空間清理的部分也表達的更加詳細了。
6. -XX:+PrintHeapAtGC 參數
參數作用:-XX:+PrintHeapAtGC 參數是垃圾回收跟蹤中,對堆空間進行跟蹤時十分常用的參數,可以在每次 GC 前后分別打印堆的信息。注意,是 GC 前后均打印,打印兩次。
為了更好的理解并掌握 -XX:+PrintHeapAtGC 參數,我們通過如下步驟進行操作。
- 步驟 1:在 VM Options 中配置參數 -XX:+PrintHeapAtGC 并保存;
- 步驟 2:運行示例代碼,觀察執行結果。
結果驗證:
{Heap before GC invocations=1 (full 0):
PSYoungGen total 76288K, used 3933K [0x000000076b400000, 0x0000000770900000, 0x00000007c0000000)
eden space 65536K, 6% used [0x000000076b400000,0x000000076b7d7480,0x000000076f400000)
from space 10752K, 0% used [0x000000076fe80000,0x000000076fe80000,0x0000000770900000)
to space 10752K, 0% used [0x000000076f400000,0x000000076f400000,0x000000076fe80000)
ParOldGen total 175104K, used 0K [0x00000006c1c00000, 0x00000006cc700000, 0x000000076b400000)
object space 175104K, 0% used [0x00000006c1c00000,0x00000006c1c00000,0x00000006cc700000)
Metaspace used 3420K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 371K, capacity 388K, committed 512K, reserved 1048576K
Heap after GC invocations=1 (full 0):
PSYoungGen total 76288K, used 792K [0x000000076b400000, 0x0000000770900000, 0x00000007c0000000)
eden space 65536K, 0% used [0x000000076b400000,0x000000076b400000,0x000000076f400000)
from space 10752K, 7% used [0x000000076f400000,0x000000076f4c6030,0x000000076fe80000)
to space 10752K, 0% used [0x000000076fe80000,0x000000076fe80000,0x0000000770900000)
ParOldGen total 175104K, used 0K [0x00000006c1c00000, 0x00000006cc700000, 0x000000076b400000)
object space 175104K, 0% used [0x00000006c1c00000,0x00000006c1c00000,0x00000006cc700000)
Metaspace used 3420K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 371K, capacity 388K, committed 512K, reserved 1048576K
}
{Heap before GC invocations=2 (full 1):
PSYoungGen total 76288K, used 792K [0x000000076b400000, 0x0000000770900000, 0x00000007c0000000)
eden space 65536K, 0% used [0x000000076b400000,0x000000076b400000,0x000000076f400000)
from space 10752K, 7% used [0x000000076f400000,0x000000076f4c6030,0x000000076fe80000)
to space 10752K, 0% used [0x000000076fe80000,0x000000076fe80000,0x0000000770900000)
ParOldGen total 175104K, used 0K [0x00000006c1c00000, 0x00000006cc700000, 0x000000076b400000)
object space 175104K, 0% used [0x00000006c1c00000,0x00000006c1c00000,0x00000006cc700000)
Metaspace used 3420K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 371K, capacity 388K, committed 512K, reserved 1048576K
Heap after GC invocations=2 (full 1):
PSYoungGen total 76288K, used 0K [0x000000076b400000, 0x0000000770900000, 0x00000007c0000000)
eden space 65536K, 0% used [0x000000076b400000,0x000000076b400000,0x000000076f400000)
from space 10752K, 0% used [0x000000076f400000,0x000000076f400000,0x000000076fe80000)
to space 10752K, 0% used [0x000000076fe80000,0x000000076fe80000,0x0000000770900000)
ParOldGen total 175104K, used 705K [0x00000006c1c00000, 0x00000006cc700000, 0x000000076b400000)
object space 175104K, 0% used [0x00000006c1c00000,0x00000006c1cb07a0,0x00000006cc700000)
Metaspace used 3420K, capacity 4496K, committed 4864K, reserved 1056768K
class space used 371K, capacity 388K, committed 512K, reserved 1048576K
}
結果分析: 由于這是對「堆空間」的日志打印,在學習完 JVM 堆空間之前,了解即可。對于堆空間的參數跟蹤,這里進行了更加細致的打印。從結果來看,在 GC 前后,打印了兩次堆空間信息,并且將 PSYoungGen 以及 ParOldGen 進行了更加詳細的日志打印。
后續學習完 JVM堆空間之后,回望這部分知識,會非常的簡單,此處也必須要先了解,為后續對堆的學習打下良好的基礎。
7. -XX:+PrintGCTimeStamps 參數
參數作用:會在每次 GC 發生時,額外輸出 GC 發生的時間,該輸出時間為虛擬機啟動后的時間偏移量。需要與 -XX:+PrintGC 或 -XX:+PrintGCDetails 配合使用,單獨使用 -XX:+PrintGCTimeStamps 參數是沒有效果的。
為了更好的理解并掌握 -XX:+PrintGCTimeStamps 參數,我們通過如下步驟進行操作。
- 步驟 1:在 VM Options 中配置參數 -XX:+PrintGC -XX:+PrintGCTimeStamps 并保存;
- 步驟 2:運行示例代碼,觀察執行結果。
結果驗證:
0.247: [GC (System.gc()) 3933K->760K(251392K), 0.0114098 secs]
0.259: [Full GC (System.gc()) 760K->685K(251392K), 0.0079185 secs]
結果分析:我們看到了,與 -XX:+PrintGC 參數打印的結果,唯一的區別就是日志開頭的 0.247 與 0.259。此處 0.247 與 0.259 表示, JVM開始運行 0.247 秒后發生了 GC,開始運行 0.259 秒后,發生了 Full GC。
8. 小結
本小節的重點內容,即我們所講述的四個常見的跟蹤垃圾回收的參數,學習者,需要對這四個常用參數的意義,以及使用方式進行掌握。由于日志輸出中部分內容,涉及到的知識點還沒有講到,但是本節對于這些內容的初步接觸,能夠有利于學習者,在后續的學習中提升學習的效率,以及理解效率。