4回复
4年前
大量Full GC (Allocation Failure)导致程序没响应
摘了一段gc日志,不知道能不能说明问题,我对这方面没接触过。感觉就是full gc很多而且时间很长,大部分都在30秒上下。
1261.237: [GC pause (G1 Evacuation Pause) (young), 0.0338226 secs]
[Parallel Time: 28.0 ms, GC Workers: 8]
[GC Worker Start (ms): Min: 1261237.0, Avg: 1261237.0, Max: 1261237.1, Diff: 0.1]
[Ext Root Scanning (ms): Min: 1.0, Avg: 1.7, Max: 4.9, Diff: 3.9, Sum: 13.8]
[Update RS (ms): Min: 22.2, Avg: 25.4, Max: 26.5, Diff: 4.3, Sum: 202.9]
[Processed Buffers: Min: 74, Avg: 81.4, Max: 88, Diff: 14, Sum: 651]
[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.1, Max: 0.1, Diff: 0.1, Sum: 0.7]
[Termination (ms): Min: 0.0, Avg: 0.6, Max: 0.9, Diff: 0.9, Sum: 5.0]
[Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 8]
[GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
[GC Worker Total (ms): Min: 27.8, Avg: 27.8, Max: 27.9, Diff: 0.1, Sum: 222.7]
[GC Worker End (ms): Min: 1261264.8, Avg: 1261264.8, Max: 1261264.9, Diff: 0.0]
[Code Root Fixup: 0.3 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.3 ms]
[Other: 5.3 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 4.3 ms]
[Ref Enq: 0.3 ms]
[Redirty Cards: 0.3 ms]
[Humongous Register: 0.1 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.1 ms]
[Eden: 0.0B(544.0M)->0.0B(544.0M) Survivors: 0.0B->0.0B Heap: 10.5G(10.6G)->10.5G(10.6G)]
[Times: user=0.23 sys=0.00, real=0.03 secs]
1261.272: [Full GC (Allocation Failure) 10G->9291M(10G), 35.2415783 secs]
[Eden: 0.0B(544.0M)->0.0B(544.0M) Survivors: 0.0B->0.0B Heap: 10.5G(10.6G)->9291.1M(10.6G)], [Metaspace: 135021K->134994K(1187840K)]
[Times: user=51.67 sys=0.01, real=35.25 secs]
1296.514: [GC concurrent-mark-abort]
1296.613: [GC pause (G1 Humongous Allocation) (young) (initial-mark), 0.0655962 secs]
[Parallel Time: 56.8 ms, GC Workers: 8]
[GC Worker Start (ms): Min: 1296615.9, Avg: 1296616.0, Max: 1296616.1, Diff: 0.2]
[Ext Root Scanning (ms): Min: 5.1, Avg: 5.4, Max: 5.5, Diff: 0.4, Sum: 42.8]
[Update RS (ms): Min: 8.3, Avg: 9.0, Max: 10.7, Diff: 2.4, Sum: 71.9]
[Processed Buffers: Min: 18, Avg: 26.5, Max: 32, Diff: 14, Sum: 212]
[Scan RS (ms): Min: 0.0, Avg: 0.2, Max: 0.2, Diff: 0.2, Sum: 1.2]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
[Object Copy (ms): Min: 39.5, Avg: 41.1, Max: 41.7, Diff: 2.2, Sum: 329.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: 8]
[GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 0.8]
[GC Worker Total (ms): Min: 55.6, Avg: 55.7, Max: 55.8, Diff: 0.2, Sum: 445.8]
[GC Worker End (ms): Min: 1296671.7, Avg: 1296671.7, Max: 1296671.8, Diff: 0.1]
[Code Root Fixup: 0.4 ms]
[Code Root Purge: 0.6 ms]
[Clear CT: 0.3 ms]
[Other: 7.5 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 4.1 ms]
[Ref Enq: 0.3 ms]
[Redirty Cards: 0.3 ms]
[Humongous Register: 0.1 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.3 ms]
[Eden: 228.0M(544.0M)->0.0B(476.0M) Survivors: 0.0B->68.0M Heap: 9519.1M(10.6G)->9368.4M(10.6G)]
[Times: user=0.43 sys=0.00, real=0.06 secs]
1296.679: [GC concurrent-root-region-scan-start]
1296.803: [GC concurrent-root-region-scan-end, 0.1232174 secs]
1296.803: [GC concurrent-mark-start]
5579 阅读