4.8 verbosegc

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

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字節(jié)的空間，最終堆有27%的空閑空間，耗時14ms，圓括弧中為空閑的字節(jié)數(shù)以及堆的總大小。第3行是標識、清理以及壓縮階段分別的耗時。在本例中，由于未發(fā)生壓縮動作，所以壓縮階段的耗時為0ms。最后一行表示本次垃圾收集找到的被引用對象數(shù)量，在本例中，未找到引用對象。

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是分配失?。ˋF）導致的垃圾收集的verbosegc輸出。分配失敗并不是說在代碼中發(fā)生了錯誤，只是在無法獲取足夠的空閑空間時的一個觸發(fā)事件。其中包含了和System.gc()相同的幾行輸出。AF[5]表示是第5次分配失敗觸發(fā)的垃圾收集。第1行表示發(fā)生分配失敗時實際需要的空間，以及距離上一次分配失敗發(fā)生的時間間隔。第2行表示針對分配失敗，垃圾收集器采取的動作，以及堆中空閑空間和荒地的大小?？赡艿姆峙涫?yīng)動作為：

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

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

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

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

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

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

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

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

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是包含分配失敗以及堆擴展在內(nèi)的verbosegc輸出示例。包含了標識集合、分配集合以及堆分別擴展的大小，還有堆的空閑率。在本例中，堆擴展了1179648字節(jié)，空閑率是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字節(jié)，空閑率為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輸出，和普通的分配失敗輸出的主要不同是包含了移動的對象的數(shù)量，移動的字節(jié)的數(shù)量，引發(fā)壓縮的原因以及額外使用了多少字節(jié)。對于已經(jīng)產(chǎn)生哈希值的對象，垃圾收集器移動他的時候需要額外的空間，因為重新生成哈希值可能會導致對象的大小增加。如果是增量壓縮，“reason”字段就是“IC reason”?？赡艿脑蛉缦拢?

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

· 2 - 堆內(nèi)產(chǎn)生碎片，需要進行壓縮

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

· 4 - System.gc()

· 5 - 空閑空間低于5%

· 6 - 空閑空間低于128KB

· 7 - 設(shè)置了-Xcompactgc參數(shù)

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

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

· 12 - 過多的暗物質(zhì)導致增量壓縮

· 13 - 設(shè)置了-Xpartialcompactgc參數(shù)

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

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

4.8.6 并發(fā)標識開始的verbosegc輸出

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

< Initial Trace rate is 8.01>

圖表 18 并發(fā)標識開始的verbosegc輸出

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

4.8.7 System.gc()并發(fā)標識的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()的并發(fā)標識verbosegc輸出

圖表19為System.gc()的并發(fā)標識verbosegc輸出。第1行含有一個數(shù)字表示的狀態(tài)?？赡艿闹禐椋?

· HALTED (0)

· EXHAUSTED (1)

· EXHAUSTED_BK_HELPER (2)

· ABORTED (3)

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

4.8.8 分配失敗的并發(fā)標識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 分配失敗的并發(fā)標識verbosegc輸出

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

Traced值表示應(yīng)用線程追蹤的字節(jié)數(shù)和后臺線程追蹤的字節(jié)數(shù)的總和，括弧中是應(yīng)用線程和后臺線程分別追蹤的字節(jié)數(shù)。State為0，表示并發(fā)標識的狀態(tài)為HALTED。

4.8.9 帶有:Xgccon參數(shù)的分配失敗的并發(fā)標識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參數(shù)的分配失敗的并發(fā)標識verbosegc輸出

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

4.8.10 并發(fā)標識的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 并發(fā)標識的verbosegc輸出

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

4.8.11 帶有:Xgccon參數(shù)的并發(fā)標識的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參數(shù)的并發(fā)標識的verbosegc輸出

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

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虛擬機中發(fā)生分配失敗時，會擴展臨時堆空間，而不是進行垃圾收集。圖表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 命令行參數(shù)

下面是虛擬機內(nèi)存儲分配以及垃圾收集相關(guān)的命令行參數(shù)

-verbosegc

-verbose:gc

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

-verbose:Xgccon

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

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

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

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

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

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

注：從1.4.1開始，環(huán)境變量IBM_JVMST_VERBOSEGC_LOG不再被使用。

-Xcompactgc

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

-Xdisableexplicitgc

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

如果測試發(fā)現(xiàn)-Xdisableexplicitgc對于應(yīng)用性能有所改善，建議使用在生產(chǎn)環(huán)境中。在以下場景，不要設(shè)置本參數(shù)：

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

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

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

-Xgcpolicy:<optthruput|optavgpause>

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

設(shè)置-Xgcpolicy為optavgpause啟用并發(fā)標識。對于垃圾收集導致的響應(yīng)慢的應(yīng)用可以使用optavgpause。

-Xgcthreads

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

-Xinitacsh<size>

設(shè)置存放應(yīng)用類的系統(tǒng)堆初始大小。只適用于resettable虛擬機。

-Xinitsh<size>

設(shè)置系統(tǒng)堆的初始大小。只適用于resettable虛擬機。

-Xjvmset<size>

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

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

-Xjvmset

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

-Xmaxe<size>

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

-Xmaxf<number>

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

-Xmine<size>

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

-Xminf<number>

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

-Xms<size>

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

· Windows, AIX, Linux：4MB

· OS/390：1MB

-Xmx<size>

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

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

· OS/390, AIX：64MB

· Linux：物理內(nèi)存的一半，最小16MB，最大512MB-1

-Xnocompactgc

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

-Xnopartialcompactgc

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

-Xpartialcompactgc

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

-Xresettable

設(shè)置支持resettable模式。

原文 翻譯

reachable 可到達的

heap lock 堆鎖

JVM 虛擬機

heap 堆

stack 棧

bit 比特位

byte 字節(jié)

word 字

thread local heap 線程本地堆

garbage collector 垃圾收集器

garbage collection 垃圾收集

frame 幀

storage component 存儲組件

pinned cluster 固化簇

critical lock 臨界鎖

allocbits 分配集合

markbits 標識集合

compact 壓縮

system heap 系統(tǒng)堆

dark matter 暗物質(zhì)

bitwise sweep 按位清理

wilderness 荒地

transient heap 臨時堆