G1垃圾回收日志分析
生活随笔
收集整理的這篇文章主要介紹了
G1垃圾回收日志分析
小編覺得挺不錯(cuò)的,現(xiàn)在分享給大家,幫大家做個(gè)參考.
標(biāo)準(zhǔn) gc 日志
使用G1垃圾回收器最難的地方是讀懂回收日志。G1回收雖然也是分代的，但是打印出來的日志卻不像其他回收器那樣明顯。所以需要好好配置JVM參數(shù)才行。先看下面一段日志，這段日志是通過配置好的JVM參數(shù)輸出的，分隔明確，很容易分辨出每次回收過程。
# 每次回收以 花括號(hào)開始 # invocations=2302 代表第2302次回收 {Heap before GC invocations=2302 (full 0):garbage-first heap total 32768K, used 30719K [0x00000007be000000, 0x00000007be100100, 0x00000007c0000000)region size 1024K, 18 young (18432K), 0 survivors (0K)Metaspace used 7722K, capacity 7936K, committed 8064K, reserved 1056768Kclass space used 1013K, capacity 1068K, committed 1152K, reserved 1048576K# 代表是一次 yong GC ,原因是: 疏散停頓（Evacuation Pause）是將活著的對(duì)象從一個(gè)區(qū)域（young or young + old）拷貝到另一個(gè)區(qū)域的階段。 2020-10-09T20:13:01.203-0800: 22.971: [GC pause (G1 Evacuation Pause) (young) (to-space exhausted), 0.0062834 secs]# 4 個(gè)線程回收[Parallel Time: 0.9 ms, GC Workers: 4][GC Worker Start (ms): Min: 22970.7, Avg: 22970.8, Max: 22971.0, Diff: 0.3][Ext Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.2, Diff: 0.2, Sum: 0.6][Update RS (ms): Min: 0.5, Avg: 0.6, Max: 0.6, Diff: 0.1, Sum: 2.4][Processed Buffers: Min: 4, Avg: 7.5, Max: 10, Diff: 6, Sum: 30][Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1][Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4][GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][GC Worker Total (ms): Min: 0.6, Avg: 0.8, Max: 0.9, Diff: 0.3, Sum: 3.2][GC Worker End (ms): Min: 22971.6, Avg: 22971.6, Max: 22971.6, Diff: 0.0][Code Root Fixup: 0.0 ms][Code Root Purge: 0.0 ms][Clear CT: 0.0 ms][Other: 5.3 ms][Evacuation Failure: 5.0 ms][Choose CSet: 0.0 ms][Ref Proc: 0.2 ms][Ref Enq: 0.0 ms][Redirty Cards: 0.0 ms][Humongous Register: 0.0 ms][Humongous Reclaim: 0.0 ms][Free CSet: 0.0 ms]# 這一行比較簡(jiǎn)單，不再解釋[Eden: 18.0M(18.0M)->0.0B(16.0M) Survivors: 0.0B->0.0B Heap: 30.0M(32.0M)->10.7M(32.0M)] Heap after GC invocations=2303 (full 0):garbage-first heap total 32768K, used 10994K [0x00000007be000000, 0x00000007be100100, 0x00000007c0000000)region size 1024K, 0 young (0K), 0 survivors (0K)Metaspace used 7722K, capacity 7936K, committed 8064K, reserved 1056768Kclass space used 1013K, capacity 1068K, committed 1152K, reserved 1048576K }# 回收結(jié)束標(biāo)志，各階段耗時(shí)[Times: user=0.01 sys=0.00, real=0.00 secs] # 下面是一段mix gc ，以一個(gè)yong gc 開始，開始的原因是大對(duì)象分配失敗 （G1 Humongous Allocation） {Heap before GC invocations=2303 (full 0):garbage-first heap total 32768K, used 20906K [0x00000007be000000, 0x00000007be100100, 0x00000007c0000000)region size 1024K, 9 young (9216K), 0 survivors (0K)Metaspace used 7722K, capacity 7936K, committed 8064K, reserved 1056768Kclass space used 1013K, capacity 1068K, committed 1152K, reserved 1048576K# 初始標(biāo)記 + yong gc 2020-10-09T20:13:01.212-0800: 22.980: [GC pause (G1 Humongous Allocation) (young) (initial-mark), 0.0008588 secs][Parallel Time: 0.7 ms, GC Workers: 4][GC Worker Start (ms): Min: 22980.2, Avg: 22980.2, Max: 22980.2, Diff: 0.0][Ext Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, Sum: 0.9][Update RS (ms): Min: 0.2, Avg: 0.3, Max: 0.3, Diff: 0.1, Sum: 1.0][Processed Buffers: Min: 3, Avg: 4.5, Max: 5, Diff: 2, Sum: 18][Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.2][Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4][GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.2][GC Worker Total (ms): Min: 0.6, Avg: 0.6, Max: 0.6, Diff: 0.1, Sum: 2.3][GC Worker End (ms): Min: 22980.8, Avg: 22980.8, Max: 22980.8, Diff: 0.0][Code Root Fixup: 0.0 ms][Code Root Purge: 0.0 ms][Clear CT: 0.0 ms][Other: 0.2 ms][Choose CSet: 0.0 ms][Ref Proc: 0.1 ms][Ref Enq: 0.0 ms][Redirty Cards: 0.0 ms][Humongous Register: 0.0 ms][Humongous Reclaim: 0.0 ms][Free CSet: 0.0 ms][Eden: 9216.0K(16.0M)->0.0B(15.0M) Survivors: 0.0B->1024.0K Heap: 21.4M(32.0M)->10.7M(32.0M)] Heap after GC invocations=2304 (full 0):garbage-first heap total 32768K, used 10996K [0x00000007be000000, 0x00000007be100100, 0x00000007c0000000)region size 1024K, 1 young (1024K), 1 survivors (1024K)Metaspace used 7722K, capacity 7936K, committed 8064K, reserved 1056768Kclass space used 1013K, capacity 1068K, committed 1152K, reserved 1048576K }[Times: user=0.00 sys=0.00, real=0.00 secs] # 掃描根節(jié)點(diǎn) 2020-10-09T20:13:01.213-0800: 22.981: [GC concurrent-root-region-scan-start] 2020-10-09T20:13:01.213-0800: 22.981: [GC concurrent-root-region-scan-end, 0.0000529 secs] # 并發(fā)標(biāo)記 2020-10-09T20:13:01.213-0800: 22.981: [GC concurrent-mark-start] 2020-10-09T20:13:01.215-0800: 22.983: [GC concurrent-mark-end, 0.0018968 secs] # 重新標(biāo)記 2020-10-09T20:13:01.215-0800: 22.983: [GC remark 2020-10-09T20:13:01.215-0800: 22.983: [Finalize Marking, 0.0000987 secs] 2020-10-09T20:13:01.215-0800: 22.983: [GC ref-proc, 0.0000624 secs] 2020-10-09T20:13:01.216-0800: 22.983: [Unloading, 0.0018305 secs], 0.0021155 secs][Times: user=0.01 sys=0.00, real=0.00 secs] # 并發(fā)清除 2020-10-09T20:13:01.218-0800: 22.985: [GC cleanup 20M->12M(32M), 0.0003173 secs][Times: user=0.00 sys=0.00, real=0.00 secs] 2020-10-09T20:13:01.218-0800: 22.986: [GC concurrent-cleanup-start] 2020-10-09T20:13:01.218-0800: 22.986: [GC concurrent-cleanup-end, 0.0000095 secs] # 再來一次yong gc {Heap before GC invocations=2305 (full 0):garbage-first heap total 32768K, used 22697K [0x00000007be000000, 0x00000007be100100, 0x00000007c0000000)region size 1024K, 16 young (16384K), 1 survivors (1024K)Metaspace used 7712K, capacity 7918K, committed 8064K, reserved 1056768Kclass space used 1010K, capacity 1061K, committed 1152K, reserved 1048576K 2020-10-09T20:13:01.220-0800: 22.988: [GC pause (G1 Evacuation Pause) (young), 0.0012414 secs][Parallel Time: 1.0 ms, GC Workers: 4][GC Worker Start (ms): Min: 22988.0, Avg: 22988.0, Max: 22988.1, Diff: 0.0][Ext Root Scanning (ms): Min: 0.1, Avg: 0.1, Max: 0.2, Diff: 0.0, Sum: 0.6][Update RS (ms): Min: 0.6, Avg: 0.7, Max: 0.7, Diff: 0.1, Sum: 2.7][Processed Buffers: Min: 8, Avg: 8.8, Max: 9, Diff: 1, Sum: 35][Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.3][Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4][GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][GC Worker Total (ms): Min: 0.9, Avg: 0.9, Max: 0.9, Diff: 0.1, Sum: 3.6][GC Worker End (ms): Min: 22988.9, Avg: 22988.9, Max: 22989.0, Diff: 0.0][Code Root Fixup: 0.0 ms][Code Root Purge: 0.0 ms][Clear CT: 0.1 ms][Other: 0.2 ms][Choose CSet: 0.0 ms][Ref Proc: 0.1 ms][Ref Enq: 0.0 ms][Redirty Cards: 0.0 ms][Humongous Register: 0.0 ms][Humongous Reclaim: 0.0 ms][Free CSet: 0.0 ms][Eden: 15.0M(15.0M)->0.0B(3072.0K) Survivors: 1024.0K->1024.0K Heap: 22.2M(32.0M)->5214.5K(32.0M)] Heap after GC invocations=2306 (full 0):garbage-first heap total 32768K, used 5214K [0x00000007be000000, 0x00000007be100100, 0x00000007c0000000)region size 1024K, 1 young (1024K), 1 survivors (1024K)Metaspace used 7712K, capacity 7918K, committed 8064K, reserved 1056768Kclass space used 1010K, capacity 1061K, committed 1152K, reserved 1048576K }[Times: user=0.00 sys=0.00, real=0.00 secs] # 然后是mix gc {Heap before GC invocations=2306 (full 0):garbage-first heap total 32768K, used 8286K [0x00000007be000000, 0x00000007be100100, 0x00000007c0000000)region size 1024K, 4 young (4096K), 1 survivors (1024K)Metaspace used 7712K, capacity 7918K, committed 8064K, reserved 1056768Kclass space used 1010K, capacity 1061K, committed 1152K, reserved 1048576K 2020-10-09T20:13:01.223-0800: 22.991: [GC pause (G1 Evacuation Pause) (mixed), 0.0009352 secs][Parallel Time: 0.6 ms, GC Workers: 4][GC Worker Start (ms): Min: 22990.7, Avg: 22990.7, Max: 22990.8, Diff: 0.1][Ext Root Scanning (ms): Min: 0.1, Avg: 0.2, Max: 0.3, Diff: 0.1, Sum: 0.8][Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Processed Buffers: Min: 0, Avg: 0.2, Max: 1, Diff: 1, Sum: 1][Scan RS (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.2][Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.2, Diff: 0.2, Sum: 0.2][Object Copy (ms): Min: 0.1, Avg: 0.3, Max: 0.4, Diff: 0.3, Sum: 1.1][Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4][GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][GC Worker Total (ms): Min: 0.5, Avg: 0.6, Max: 0.6, Diff: 0.1, Sum: 2.3][GC Worker End (ms): Min: 22991.3, Avg: 22991.3, Max: 22991.3, Diff: 0.0][Code Root Fixup: 0.0 ms][Code Root Purge: 0.0 ms][Clear CT: 0.0 ms][Other: 0.2 ms][Choose CSet: 0.0 ms][Ref Proc: 0.1 ms][Ref Enq: 0.0 ms][Redirty Cards: 0.0 ms][Humongous Register: 0.0 ms][Humongous Reclaim: 0.0 ms][Free CSet: 0.0 ms][Eden: 3072.0K(3072.0K)->0.0B(18.0M) Survivors: 1024.0K->1024.0K Heap: 8286.5K(32.0M)->4441.5K(32.0M)] Heap after GC invocations=2307 (full 0):garbage-first heap total 32768K, used 4441K [0x00000007be000000, 0x00000007be100100, 0x00000007c0000000)region size 1024K, 1 young (1024K), 1 survivors (1024K)Metaspace used 7712K, capacity 7918K, committed 8064K, reserved 1056768Kclass space used 1010K, capacity 1061K, committed 1152K, reserved 1048576K }[Times: user=0.00 sys=0.00, real=0.00 secs]觀察上面的gc日志可以總結(jié)出以下幾點(diǎn)
4 上面的JVM參數(shù)是
詳細(xì)GC日志
上面的日志基本上已經(jīng)夠用了，如果想更精細(xì)一點(diǎn)可以加上 -XX:+PrintAdaptiveSizePolicy 打印內(nèi)存調(diào)節(jié)的過程。然后日志如下所示
對(duì)于普通的yong gc ，日志如下：
對(duì)于普通的yong gc日志就是上面這樣一個(gè)接一個(gè)。但是mix gc完全不一樣，開始的時(shí)候回打印gc開始的原因，結(jié)束的時(shí)候會(huì)打印gc結(jié)束的原因。
# 觸發(fā)了concurrent cycle。開始concurrent cycle有2個(gè)條件： # 申請(qǐng)H-OBJ（申請(qǐng)的內(nèi)存大于Region的一半） # 堆占用率達(dá)到45%。 # 這里的原因是堆占用率達(dá)到45%24.658: [G1Ergonomics (Concurrent Cycles) request concurrent cycle initiation, reason: occupancy higher than threshold, occupancy: 12582912 bytes, allocation request: 3549488 bytes, threshold: 15099480 bytes (45.00 %), source: concurrent humongous allocation]24.658: [G1Ergonomics (Concurrent Cycles) request concurrent cycle initiation, reason: requested by GC cause, GC cause: G1 Humongous Allocation]# 一個(gè)yong gc開始，標(biāo)志 initial-mark {Heap before GC invocations=824 (full 0):garbage-first heap total 32768K, used 25048K [0x00000007be000000, 0x00000007be100100, 0x00000007c0000000)region size 1024K, 17 young (17408K), 1 survivors (1024K)Metaspace used 11630K, capacity 11998K, committed 12160K, reserved 1060864Kclass space used 1511K, capacity 1588K, committed 1664K, reserved 1048576K24.658: [G1Ergonomics (Concurrent Cycles) initiate concurrent cycle, reason: concurrent cycle initiation requested] 2020-10-09T20:09:58.050-0800: 24.658: [GC pause (G1 Humongous Allocation) (young) (initial-mark) 24.658: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 0, predicted base time: 17.61 ms, remaining time: 182.39 ms, target pause time: 200.00 ms]24.658: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 16 regions, survivors: 1 regions, predicted young region time: 0.03 ms]24.658: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 16 regions, survivors: 1 regions, old: 0 regions, predicted pause time: 17.64 ms, target pause time: 200.00 ms]24.681: [G1Ergonomics (Heap Sizing) attempt heap expansion, reason: recent GC overhead higher than threshold after GC, recent GC overhead: 44.10 %, threshold: 10.00 %, uncommitted: 0 bytes, calculated expansion amount: 0 bytes (20.00 %)] , 0.0231035 secs][Parallel Time: 11.7 ms, GC Workers: 4][GC Worker Start (ms): Min: 24658.3, Avg: 24658.5, Max: 24658.7, Diff: 0.4][Ext Root Scanning (ms): Min: 0.0, Avg: 0.8, Max: 1.4, Diff: 1.3, Sum: 3.1][Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Processed Buffers: Min: 0, Avg: 0.2, Max: 1, Diff: 1, Sum: 1][Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1][Termination (ms): Min: 0.0, Avg: 3.0, Max: 10.9, Diff: 10.9, Sum: 12.0][Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4][GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][GC Worker Total (ms): Min: 1.1, Avg: 3.8, Max: 11.6, Diff: 10.6, Sum: 15.3][GC Worker End (ms): Min: 24659.8, Avg: 24662.4, Max: 24669.9, Diff: 10.1][Code Root Fixup: 0.0 ms][Code Root Purge: 0.0 ms][Clear CT: 0.0 ms][Other: 11.3 ms][Choose CSet: 0.0 ms][Ref Proc: 11.2 ms][Ref Enq: 0.0 ms][Redirty Cards: 0.0 ms][Humongous Register: 0.0 ms][Humongous Reclaim: 0.0 ms][Free CSet: 0.0 ms][Eden: 16.0M(18.0M)->0.0B(18.0M) Survivors: 1024.0K->1024.0K Heap: 25.5M(32.0M)->3625.0K(32.0M)] Heap after GC invocations=825 (full 0):garbage-first heap total 32768K, used 3625K [0x00000007be000000, 0x00000007be100100, 0x00000007c0000000)region size 1024K, 1 young (1024K), 1 survivors (1024K)Metaspace used 11630K, capacity 11998K, committed 12160K, reserved 1060864Kclass space used 1511K, capacity 1588K, committed 1664K, reserved 1048576K }[Times: user=0.01 sys=0.00, real=0.02 secs] 2020-10-09T20:09:58.074-0800: 24.682: [GC concurrent-root-region-scan-start] 2020-10-09T20:09:58.075-0800: 24.683: [GC concurrent-root-region-scan-end, 0.0008813 secs] 2020-10-09T20:09:58.075-0800: 24.683: [GC concurrent-mark-start] 2020-10-09T20:09:58.084-0800: 24.692: [GC concurrent-mark-end, 0.0091770 secs] 2020-10-09T20:09:58.084-0800: 24.692: [GC remark 2020-10-09T20:09:58.084-0800: 24.692: [Finalize Marking, 0.0018289 secs] 2020-10-09T20:09:58.086-0800: 24.694: [GC ref-proc, 0.0001201 secs] 2020-10-09T20:09:58.086-0800: 24.694: [Unloading, 0.0022931 secs], 0.0045892 secs][Times: user=0.01 sys=0.00, real=0.00 secs] 2020-10-09T20:09:58.089-0800: 24.697: [GC cleanup 15M->15M(32M), 0.0002603 secs][Times: user=0.00 sys=0.00, real=0.00 secs] {Heap before GC invocations=826 (full 0):garbage-first heap total 32768K, used 27824K [0x00000007be000000, 0x00000007be100100, 0x00000007c0000000)region size 1024K, 19 young (19456K), 1 survivors (1024K)Metaspace used 11630K, capacity 11998K, committed 12160K, reserved 1060864Kclass space used 1511K, capacity 1588K, committed 1664K, reserved 1048576K# 再來一次yong gc 2020-10-09T20:09:58.095-0800: 24.703: [GC pause (G1 Evacuation Pause) (young) 24.703: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 3, predicted base time: 18.84 ms, remaining time: 181.16 ms, target pause time: 200.00 ms]24.703: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 18 regions, survivors: 1 regions, predicted young region time: 0.03 ms]24.703: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 18 regions, survivors: 1 regions, old: 0 regions, predicted pause time: 18.87 ms, target pause time: 200.00 ms]24.707: [G1Ergonomics (Heap Sizing) attempt heap expansion, reason: recent GC overhead higher than threshold after GC, recent GC overhead: 50.01 %, threshold: 10.00 %, uncommitted: 0 bytes, calculated expansion amount: 0 bytes (20.00 %)]# 正常可回收的對(duì)象不超過5%，停止 mixed 回收。24.707: [G1Ergonomics (Mixed GCs) do not start mixed GCs, reason: reclaimable percentage not over threshold, candidate old regions: 3 regions, reclaimable: 1661096 bytes (4.95 %), threshold: 5.00 %] , 0.0043467 secs][Parallel Time: 1.5 ms, GC Workers: 4][GC Worker Start (ms): Min: 24702.6, Avg: 24703.3, Max: 24704.0, Diff: 1.4][Ext Root Scanning (ms): Min: 0.0, Avg: 0.7, Max: 1.4, Diff: 1.4, Sum: 2.9][Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Processed Buffers: Min: 0, Avg: 0.5, Max: 1, Diff: 1, Sum: 2][Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1][Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.2][Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4][GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0][GC Worker Total (ms): Min: 0.0, Avg: 0.8, Max: 1.5, Diff: 1.5, Sum: 3.2][GC Worker End (ms): Min: 24704.0, Avg: 24704.1, Max: 24704.1, Diff: 0.0][Code Root Fixup: 0.0 ms][Code Root Purge: 0.0 ms][Clear CT: 0.0 ms][Other: 2.8 ms][Choose CSet: 0.0 ms][Ref Proc: 2.7 ms][Ref Enq: 0.0 ms][Redirty Cards: 0.0 ms][Humongous Register: 0.0 ms][Humongous Reclaim: 0.0 ms][Free CSet: 0.0 ms][Eden: 18.0M(18.0M)->0.0B(18.0M) Survivors: 1024.0K->1024.0K Heap: 27.2M(32.0M)->5925.8K(32.0M)] Heap after GC invocations=827 (full 0):garbage-first heap total 32768K, used 5925K [0x00000007be000000, 0x00000007be100100, 0x00000007c0000000)region size 1024K, 1 young (1024K), 1 survivors (1024K)Metaspace used 11630K, capacity 11998K, committed 12160K, reserved 1060864Kclass space used 1511K, capacity 1588K, committed 1664K, reserved 1048576K }[Times: user=0.01 sys=0.00, real=0.00 secs]-XX:G1HeapWastePercent
通過-XX:G1HeapWastePercent指定觸發(fā)Mixed GC的堆垃圾占比，默認(rèn)值5%，也就是在全局標(biāo)記結(jié)束后能夠統(tǒng)計(jì)出所有Cset內(nèi)可被回收的垃圾占整對(duì)的比例值，如果超過5%，那么就會(huì)觸發(fā)之后的多輪Mixed GC，如果不超過，那么會(huì)在之后的某次Young GC中重新執(zhí)行全局并發(fā)標(biāo)記?？梢試L試適當(dāng)?shù)恼{(diào)高此閾值，能夠適當(dāng)?shù)慕档蚆ixed GC的頻率。
由一些參數(shù)控制，另外也控制著哪些老年代Region會(huì)被選入CSet（收集集合）。
G1HeapWastePercent：在global concurrent marking結(jié)束之后，我們可以知道old gen regions中有多少空間要被回收，在每次YGC之后和再次發(fā)生Mixed GC之前，會(huì)檢查垃圾占比是否達(dá)到此參數(shù)，只有達(dá)到了，下次才會(huì)發(fā)生Mixed GC。
G1MixedGCLiveThresholdPercent：old generation region中的存活對(duì)象的占比，只有在此參數(shù)之下，才會(huì)被選入CSet。
G1MixedGCCountTarget：一次global concurrent marking之后，最多執(zhí)行Mixed GC的次數(shù)。
G1OldCSetRegionThresholdPercent：一次Mixed GC中能被選入CSet的最多old generation region數(shù)量。
通過-XX:G1MixedGCLiveThresholdPercent指定被納入Cset的Region的存活空間占比閾值，不同版本默認(rèn)值不同，有65%和85%。在全局并發(fā)標(biāo)記階段，如果一個(gè)Region的存活對(duì)象的空間占比低于此值，則會(huì)被納入Cset。 此值直接影響到Mixed GC選擇回收的區(qū)域，當(dāng)發(fā)現(xiàn)GC時(shí)間較長(zhǎng)時(shí)，可以嘗試調(diào)低此閾值，盡量?jī)?yōu)先選擇回收垃圾占比高的Region，但此舉也可能導(dǎo)致垃圾回收的不夠徹底，最終觸發(fā)Full GC。但是納入的region還是有上限的，由G1MixedGCCountTarget控制，默認(rèn)不超過全部Region的10%。
通過-XX:InitiatingHeapOccupancyPercent指定觸發(fā)全局并發(fā)標(biāo)記的老年代使用占比，默認(rèn)值45%，也就是老年代占堆的比例超過45%。如果Mixed GC周期結(jié)束后老年代使用率還是超過45%,那么會(huì)再次觸發(fā)全局并發(fā)標(biāo)記過程，這樣就會(huì)導(dǎo)致頻繁的老年代GC，影響應(yīng)用吞吐量。同時(shí)老年代空間不大，Mixed GC回收的空間肯定是偏少的。可以適當(dāng)調(diào)高IHOP的值，當(dāng)然如果此值太高，很容易導(dǎo)致年輕代晉升失敗而觸發(fā)Full GC，所以需要多次調(diào)整測(cè)試。
通過-XX:G1MixedGCCountTarget指定一個(gè)周期內(nèi)觸發(fā)Mixed GC最大次數(shù)，默認(rèn)值8。一次全局并發(fā)標(biāo)記后，最多接著8次Mixed GC，把全局并發(fā)標(biāo)記階段生成的Cset里的Region拆分為最多8部分，然后在每輪Mixed GC里收集一部分。這個(gè)值要和上一個(gè)參數(shù)配合使用，8*10%=80%，應(yīng)該來說會(huì)大于每次標(biāo)記階段的Cset集合了。一般此參數(shù)也不需額外調(diào)整。
參考：https://zhuanlan.zhihu.com/p/181305087
總結(jié)
以上是生活随笔為你收集整理的G1垃圾回收日志分析的全部?jī)?nèi)容，希望文章能夠幫你解決所遇到的問題。
- 上一篇： SQL注入产生原理
- 下一篇： 微信公众号java开发沉淀（五）推送群发