4.8 verbosegc

使用-verbosegc參數，可以查看垃圾收集的一些信息

4.8.1 System.gc()的verbosegc輸出

<GC(3): GC cycle started Tue Mar 19 08:24:34 2002

<GC(3): freed 58808 bytes, 27% free (1163016/4192768), in 14 ms>

<GC(3): mark: 13 ms, sweep: 1 ms, compact: 0 ms>

<GC(3): refs: soft 0 (age >= 32), weak 0, final 0, phantom 0>

圖表 13 System.gc的verbosegc輸出

圖表13是System.gc()的verbosegc輸出示例。開始的GC(3)表示這是第3次進行垃圾收集，第1行顯示垃圾收集開始的時間，第2行表示釋放了58808字節的空間，最終堆有27%的空閑空間，耗時14ms，圓括弧中為空閑的字節數以及堆的總大小。第3行是標識、清理以及壓縮階段分別的耗時。在本例中，由于未發生壓縮動作，所以壓縮階段的耗時為0ms。最后一行表示本次垃圾收集找到的被引用對象數量，在本例中，未找到引用對象。

4.8.2 分配失敗的verbosegc輸出

<AF[5]: Allocation Failure. need 32 bytes, 286 ms since last AF>

<AF[5]: managing allocation failure, action=1 (0/6172496) (247968/248496)>

<GC(6): GC cycle started Tue Mar 19 08:24:46 2002

<GC(6): freed 1770544 bytes, 31% free (2018512/6420992), in 25 ms>

<GC(6): mark: 23 ms, sweep: 2 ms, compact: 0 ms>

<GC(6): refs: soft 1 (age >= 4), weak 0, final 0, phantom 0>

<AF[5]: completed in 26 ms>

圖表 14 分配失敗的verbosegc輸出

圖表14是分配失敗（AF）導致的垃圾收集的verbosegc輸出。分配失敗并不是說在代碼中發生了錯誤，只是在無法獲取足夠的空閑空間時的一個觸發事件。其中包含了和System.gc()相同的幾行輸出。AF[5]表示是第5次分配失敗觸發的垃圾收集。第1行表示發生分配失敗時實際需要的空間，以及距離上一次分配失敗發生的時間間隔。第2行表示針對分配失敗，垃圾收集器采取的動作，以及堆中空閑空間和荒地的大小。可能的分配失敗對應動作為：

· 0 - 垃圾收集器試圖從固化空閑鏈表中進行分配，但是失敗了

· 1 - 垃圾收集器避免使用荒地，為了避免壓縮動作，荒地留作大對象分配使用

· 2 - 垃圾收集器試圖在荒地之外進行分配，但是失敗了

· 3 - 垃圾收集器嘗試擴展堆

· 4 - 垃圾收集器準備清理SoftReference。僅會在進行了完全的擴展之后，堆空閑還低于12%的情況下發生

· 5 - 僅在resettable 虛擬機發生。表示垃圾收集器試圖從臨時堆申請空間

· 6 - 不是一個動作，只是表示堆內空閑空間太少了

最后一行表示分配失敗的耗時，包括停止以及重新啟動應用線程的時間在內。

4.8.3 堆擴展的verbosegc輸出

<AF[11]: Allocation Failure. need 24 bytes, 182 ms since last AF>

<AF[11]: managing allocation failure, action=1 (0/6382368) (10296/38624)>

<GC(12): GC cycle started Tue Mar 19 08:24:49 2002

<GC(12): freed 1877560 bytes, 29% free (1887856/6420992), in 21 ms>

<GC(12): mark: 19 ms, sweep: 2 ms, compact: 0 ms>

<GC(12): refs: soft 0 (age >= 32), weak 0, final 0, phantom 0>

<AF[11]: managing allocation failure, action=3 (1887856/6420992)>

<GC(12): need to expand mark bits for 7600640-byte heap>

<GC(12): expanded mark bits by 16384 to 118784 bytes>

<GC(12): need to expand alloc bits for 7600640-byte heap>

<GC(12): expanded alloc bits by 16384 to 118784 bytes>

<GC(12): expanded heap by 1179648 to 7600640 bytes, 40% free>

<AF[11]: completed in 31 ms>

圖表 15 堆擴展的verbosegc輸出

圖表15是包含分配失敗以及堆擴展在內的verbosegc輸出示例。包含了標識集合、分配集合以及堆分別擴展的大小，還有堆的空閑率。在本例中，堆擴展了1179648字節，空閑率是40%。

4.8.4 堆收縮的verbosegc輸出

<AF[9]: Allocation Failure. need 32 bytes, 92 ms since last AF>

<AF[9]: managing allocation failure, action=1 (0/22100560) (1163184/1163184)>

<GC(9): may need to shrink mark bits for 22149632-byte heap>

<GC(9): shrank mark bits to 348160>

<GC(9): may need to shrink alloc bits for 22149632-byte heap>

<GC(9): shrank alloc bits to 348160>

<GC(9): shrank heap by 1114112 to 22149632 bytes, 79% free>

<GC(9): GC cycle started Tue Mar 19 11:08:18 2002

<GC(9): freed 17460600 bytes, 79% free (17509672/22149632), in 7 ms>

<GC(9): mark: 4 ms, sweep: 3 ms, compact: 0 ms>

<GC(9): refs: soft 0 (age >= 6), weak 0, final 0, phantom 0>

<AF[9]: completed in 8 ms>

圖表 16 堆收縮的verbosegc輸出

圖表16是堆收縮的verbosegc輸出，和堆擴展的輸出非常類似。包含了標識集合、分配集合以及堆分別收縮的大小，還有堆的空閑率。在本例中，堆收縮了1114112字節，空閑率為79%。堆擴展和堆收縮的verbosegc輸出的不同在于堆擴展是在所有的線程恢復運行之后進行，而堆收縮是在所有的線程恢復運行之前進行的。

4.8.5 壓縮動作的verbosegc輸出

<AF[2]: Allocation Failure. need 88 bytes, 5248 ms since last AF>

<AF[2]: managing allocation failure, action=1 (0/4032592) (160176/160176)>

<GC(2): GC cycle started Tue Mar 19 11:32:28 2002

<GC(2): freed 1165360 bytes, 31% free (1325536/4192768), in 63 ms>

<GC(2): mark: 13 ms, sweep: 1 ms, compact: 49 ms>

<GC(2): refs: soft 0 (age >= 32), weak 0, final 3, phantom 0>

<GC(2): moved 32752 objects, 2511088 bytes, reason=2, used 8 more bytes>

<AF[2]: completed in 64 ms>

圖表 17壓縮動作的verbosegc輸出

圖表17是壓縮動作的verbosegc輸出，和普通的分配失敗輸出的主要不同是包含了移動的對象的數量，移動的字節的數量，引發壓縮的原因以及額外使用了多少字節。對于已經產生哈希值的對象，垃圾收集器移動他的時候需要額外的空間，因為重新生成哈希值可能會導致對象的大小增加。如果是增量壓縮，“reason”字段就是“IC reason”。可能的原因如下：

· 1 - 標識和清理之后，尚未獲得滿足分配需求的空間

· 2 - 堆內產生碎片，需要進行壓縮

· 3 - 空閑空間小于-Xminf的一半，空閑空間加上“暗物質”的大小小于-Xminf

· 4 - System.gc()

· 5 - 空閑空間低于5%

· 6 - 空閑空間低于128KB

· 7 - 設置了-Xcompactgc參數

· 8 - 臨時堆的空閑空間低于5%

· 11 - 堆收縮之前的壓縮動作

· 12 - 過多的暗物質導致增量壓縮

· 13 - 設置了-Xpartialcompactgc參數

· 14 - 由于荒地的擴展導致增量壓縮發生

· 15 - 由于荒地空間不足導致增量壓縮發生

4.8.6 并發標識開始的verbosegc輸出

<CONCURRENT GC Free= 379544 Expected free space= 378884 Kickoff=379406>

< Initial Trace rate is 8.01>

圖表 18 并發標識開始的verbosegc輸出

圖表18中的verbosegc輸出顯示了并發標識的開始。第1行表示堆空閑字節數，以及在本次鎖堆分配之后，會有多少的可用空間。Kickoff表示并發標識開始的級別。在本例中，期望的堆大小是378884字節，小于Kickoff的值379406字節。第2行表示初始的追蹤率。在本例中是8.01，其含義是在本次鎖堆分配中，每分配1個字節，垃圾收集器需要追蹤8.01字節的活動對象。

4.8.7 System.gc()并發標識的verbosegc輸出

<GC(23): Bytes Traced =0 (Foreground: 0+ Background: 0) State = 3 >

<GC(23): GC cycle started Fri Oct 11 08:45:34 2002

<GC(23): freed 12847376 bytes, 94% free (127145208/134216192), in 975 ms>

<GC(23): mark: 408 ms, sweep: 70 ms, compact: 497 ms>

<GC(23): refs: soft 0 (age >= 32), weak 0, final 0, phantom 0>

<GC(23): moved 95811 objects, 6316896 bytes, reason=4>

圖表 19 System.gc()的并發標識verbosegc輸出

圖表19為System.gc()的并發標識verbosegc輸出。第1行含有一個數字表示的狀態。可能的值為：

· HALTED (0)

· EXHAUSTED (1)

· EXHAUSTED_BK_HELPER (2)

· ABORTED (3)

在本例中，State為3，說明并發標識未完成初始化階段的工作，所以被終止。還有在并發標識階段已經追蹤的字節數，前臺和后臺分別計數。

4.8.8 分配失敗的并發標識verbosegc輸出

<AF[7]: Allocation Failure. need 528 bytes, 493 ms since last AF or CON>

<AF[7]: managing allocation failure, action=1 (0/3983128) (209640/209640)>

<GC(8): Bytes Traced =670940 (Foreground: 73725+ Background: 597215) State = 0

<GC(8): GC cycle started Tue Oct 08 13:43:14 2002

<GC(8): freed 2926496 bytes, 74% free (3136136/4192768), in 8 ms>

<GC(8): mark: 7 ms, sweep: 1 ms, compact: 0 ms>

<GC(8): refs: soft 0 (age >= 32), weak 0, final 0, phantom 0>

<AF[7]: completed in 10 ms>

圖表 20 分配失敗的并發標識verbosegc輸出

圖表20是分配失敗觸發的帶有并發標識的垃圾收集的verbosegc輸出。

Traced值表示應用線程追蹤的字節數和后臺線程追蹤的字節數的總和，括弧中是應用線程和后臺線程分別追蹤的字節數。State為0，表示并發標識的狀態為HALTED。

4.8.9 帶有:Xgccon參數的分配失敗的并發標識verbosegc輸出

<AF[19]: Allocation Failure. need 65552 bytes, 106 ms since last AF or CON>

<AF[19]: managing allocation failure, action=1 (83624/16684008) (878104/878104)>

<GC(20): Bytes Traced =1882061 (Foreground: 1292013+ Background: 590048) State = 0 >

<GC(20): Card Cleaning Done. Cleaned:27 (0 skipped). Estimation 593 (Factor 0.017)>

<GC(20): GC cycle started Fri Oct 11 10:23:49 2002

<GC(20): freed 8465280 bytes, 53% free (9427008/17562112), in 9 ms>

<GC(20): mark: 7 ms, sweep: 2 ms, compact: 0 ms>

<GC(20): In mark: Final dirty Cards scan: 41 cards

<GC(20): refs: soft 0 (age >= 6), weak 0, final 0, phantom 0>

圖表 21帶有:Xgccon參數的分配失敗的并發標識verbosegc輸出

圖表12是帶有:Xgccon參數的分配失敗的并發標識verbosegc輸出。第3行的State為0，表示并發標識的狀態為HALTED。第4行表示清理了多少卡片。

4.8.10 并發標識的verbosegc輸出

<CON[41]: Concurrent collection, (284528/8238832) (17560/17168), 874 ms since last CON or AF>

<GC(45): Bytes Traced =5098693 (Foreground: 555297+ Background: 4543396) State = 2 >

<GC(45): GC cycle started Tue Oct 08 12:31:14 2002

<GC(45): freed 2185000 bytes, 30% free (2487088/8256000), in 7 ms>

<GC(45): mark: 5 ms, sweep: 2 ms, compact: 0 ms>

<GC(45): refs: soft 0 (age >= 32), weak 0, final 0, phantom 0>

<CON[41]: completed in 9 ms>

圖表 22 并發標識的verbosegc輸出

圖表12是由并發標識開始的一個垃圾收集周期的verbosegc輸出，和分配失敗并發標識的verbosegc輸出非常相似，只是在最后一行中由“CON”取代了原來的“AF”。在本例中，State為2，表示后臺線程已經沒有更多的工作需要處理了。

4.8.11 帶有:Xgccon參數的并發標識的verbosegc輸出

<CON[20]: Concurrent collection, (397808/131070464) (3145728/3145728), 5933 ms since last CON or AF>

<GC(26): Bytes Traced =11845976 (Foreground: 4203037+ Background: 7642939) State = 1 >

<GC(26): Card Cleaning Done. Cleaned:4127 (0 skipped). Estimation 3896 (Factor 0.015)>

<GC(26): GC cycle started Fri Oct 11 09:45:32 2002

<GC(26): wait for concurrent tracers: 1 ms>

<GC(26): freed 117639824 bytes, 90% free (121183360/134216192), in 20 ms>

<GC(26): mark: 10 ms, sweep: 10 ms, compact: 0 ms>

<GC(26): In mark: Final dirty Cards scan: 838 cards

<GC(26): refs: soft 0 (age >= 32), weak 0, final 0, phantom 0>

<CON[20]: completed in 21 ms>

圖表 23帶有:Xgccon參數的并發標識的verbosegc輸出

圖表23是帶有:Xgccon參數的并發標識的verbosegc輸出，類似分配失敗的垃圾收集，帶有追蹤字節數以及清理的卡片數量信息。第5行顯示等待并發追蹤完成的時間。

4.8.12 verbosegc和Resettable

<TH_AF[8]: Transient heap Allocation Failure. need 64 bytes, 9716 ms since last TH_AF>

<TH_AF[8]: managing TH allocation failure, action=3 (0/4389888)>

<GC(25): need to expand transient mark bits for 4586496-byte heap>

<GC(25): expanded transient mark bits by 3072 to 71672 bytes>

<GC(25): need to expand transient alloc bits for 4586496-byte heap>

<GC(25): expanded transient alloc bits by 3072 to 71672 bytes>

<GC(25): expanded transient heap fully by 196608 to 4586496 bytes>

<TH_AF[8]: completed in 1 ms>

圖表 24 臨時堆空間分配失敗的verbosegc輸出

對于Resettable的虛擬機，有一個中間件堆（middleware heap）和一個臨時堆（transient heap）。在臨時堆的verbosegc稍有不同，圖表24就是一個示例輸出。注意，在這里，TH_AF取代了AF標識。resettable虛擬機中發生分配失敗時，會擴展臨時堆空間，而不是進行垃圾收集。圖表24是臨時堆擴展成功的輸出示例。

<TH_AF[11]: Transient heap Allocation Failure. need 32 bytes, 16570 ms since last TH_AF>

<TH_AF[11]: managing TH allocation failure, action=3 (0/4586496)>

<TH_AF[11]: managing TH allocation failure, action=2 (0/4586496)>

<GC(29): GC cycle started Tue Mar 19 14:47:42 2002

<GC(29): freed 402552 bytes from Transient Heap 8% free (402552/4586496) and...>

<GC(29): freed 1456 bytes, 38% free (623304/1636864), in 1285 ms>

<GC(29): mark: 1263 ms, sweep: 22 ms, compact: 0 ms>

<GC(29): refs: soft 0 (age >= 6), weak 0, final 0, phantom 0>

<TH_AF[11]: completed in 1287 ms>

圖表 25 臨時堆擴展失敗的verbosegc輸出

圖表25是臨時堆擴展失敗的verbosegc輸出，此時必須進行垃圾收集。在輸出中包含了中間件堆中和臨時堆中分別釋放的空間。

5 消息

本章是IBM JVM錯誤信息描述，請參考原文。

6 命令行參數

下面是虛擬機內存儲分配以及垃圾收集相關的命令行參數

-verbosegc

-verbose:gc

顯示垃圾收集的信息。在不同的版本，不同的平臺的具體輸出格式不同。

-verbose:Xgccon

顯示垃圾收集信息。除了-verbosegc參數的輸出之外，還包含卡片清理的信息。只有在-Xgcpolicy參數為optavgpause時才可以使用本參數。

-Xverbosegclog:<path to file><file name>

將verbosegc的輸出重定向到一個文件。如果找不到所指定的路徑，則輸出到stderr中。

-Xverbosegclog:<path to file><file name, X, Y>

文件名中必須包含一個“#”，從1開始，在實際輸出時會用數字替代“#”

X和Y是一個整數數值。表示verbosegc的輸出保存到Y個文件中，每個文件包含X次垃圾收集周期。

注：從1.4.1開始，環境變量IBM_JVMST_VERBOSEGC_LOG不再被使用。

-Xcompactgc

每次垃圾收集都進行壓縮。默認是false

-Xdisableexplicitgc

禁用由Sytem.gc()調用引起的垃圾收集。很多應用代碼中都存在調用System.gc()的情況。這樣會由于不合時宜的垃圾收集導致應用性能下降。如果從應用中刪除這些代碼不方便的話，可以使用本參數來通知虛擬機，對于應用調用System.gc()不進行真正的垃圾收集。

如果測試發現-Xdisableexplicitgc對于應用性能有所改善，建議使用在生產環境中。在以下場景，不要設置本參數：

· 帶有CICS參數的zSeries虛擬機，運行在resettable模式，或者是運行DB/2存過過程的

· 某些性能分析工具通過顯式的垃圾收集分析釋放的對象或者檢測內存泄漏問題的

· 性能基準測試中，需要在兩輪測試場景之間進行顯式垃圾收集的

-Xgcpolicy:<optthruput|optavgpause>

設置-Xgcpolicy為optthruput，就會禁用并發標識能力。此為默認設置。對于垃圾收集暫停時間可以接受的應用，optthruput可以帶來最好的吞吐量。

設置-Xgcpolicy為optavgpause啟用并發標識。對于垃圾收集導致的響應慢的應用可以使用optavgpause。

-Xgcthreads

設置用來進行垃圾收集的全部線程的數量。在一個有N個處理器的平臺上，如果虛擬機運行于resettable模式，本參數默認為1；如果不是resettable模式，則為N。

-Xinitacsh<size>

設置存放應用類的系統堆初始大小。只適用于resettable虛擬機。

-Xinitsh<size>

設置系統堆的初始大小。只適用于resettable虛擬機。

-Xjvmset<size>

創建主虛擬機（Master JVM）。設置共享內存的大小，單位為MB。默認是1MB。當JNI_CreateJavaVM()函數返回成功之后，JavaVMOption的”extrainfo”字段會傳傳遞工作虛擬機。

當啟動主虛擬機時，必須將-Xresettable參數和本參數一起使用。

-Xjvmset

創建工作虛擬機（Worker JVM）。JavaVMOption的”extrainfo”字段中包含了創建主虛擬機時的-Xjvmset參數。

-Xmaxe<size>

設置堆的最大擴展量，默認值為0。在resettable模式下，對于中間件堆和臨時堆，實際的最大擴展量為<size>/2。

-Xmaxf<number>

0到1之間的一個浮點數，用來設置堆的最大空閑率，默認值是0.6，即60%。如果本參數設置為0，堆會保持收縮；如果設置為1，堆永不收縮。在resettable模式下，本參數僅用于中間件堆。

-Xmine<size>

設置堆的最小擴展量。默認值為1MB。在resettable模式下，對于中間件堆和臨時堆，實際的最小擴展量為<size>/2。

-Xminf<number>

0到1之間的一個浮點數，用來設置堆的最小空閑率，默認值是0.3，即30%。如果堆內空閑率小于本參數設置，則堆會進行擴展。在resettable模式下，本參數用于中間件堆和臨時堆。

-Xms<size>

堆的初始大小。默認值為：

· Windows, AIX, Linux：4MB

· OS/390：1MB

-Xmx<size>

堆的最大大小。在resettable模式下，本參數決定了中間件堆和臨時堆總共的大小，中間件堆從底開始增長，臨時堆從頂開始增長。如果未明確指定，默認值為：

· Windows：物理內存的一半，最小16MB，最大2GB-1

· OS/390, AIX：64MB

· Linux：物理內存的一半，最小16MB，最大512MB-1

-Xnocompactgc

禁用堆壓縮。默認值為false。

-Xnopartialcompactgc

禁用增量壓縮。默認值為false。

-Xpartialcompactgc

每次垃圾收集都運行增量壓縮。默認值為false。

-Xresettable

設置支持resettable模式。

原文 翻譯

reachable 可到達的

heap lock 堆鎖

JVM 虛擬機

heap 堆

stack 棧

bit 比特位

byte 字節

word 字

thread local heap 線程本地堆

garbage collector 垃圾收集器

garbage collection 垃圾收集

frame 幀

storage component 存儲組件

pinned cluster 固化簇

critical lock 臨界鎖

allocbits 分配集合

markbits 標識集合

compact 壓縮

system heap 系統堆

dark matter 暗物質

bitwise sweep 按位清理

wilderness 荒地

transient heap 臨時堆