Hi,
I'm having my application running on java8 with g1gc enabled. I've enabled
gc logs, and I can see that gc time is growing ( at least this is what I
think..)
VM flags:
-Xms6g -Xmx6g
-XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintHeapAtGC
-XX:G1HeapRegionSize=32M -XX:+PrintAdaptiveSizePolicy
A snippet from the gc log:
{Heap before GC invocations=342 (full 1):
garbage-first heap total 6291456K, used 5257482K [0x0000000640000000,
0x00000007c0000000, 0x00000007c0000000)
region size 32768K, 104 young (3407872K), 10 survivors (327680K)
Metaspace used 31200K, capacity 31664K, committed 31872K, reserved
1077248K
class space used 3496K, capacity 3596K, committed 3712K, reserved
1048576K
2015-02-02T17:36:48.237+0200: 4067.021: [GC pause (G1 Evacuation Pause)
(young) 4067.021: [G1Ergonomics (CSet Construction) start choosing CSet,
_pending_cards: 23499, predicted base time: 11.30 ms, remaining time:
188.70 ms, target pause time: 200.00 ms]
4067.021: [G1Ergonomics (CSet Construction) add young regions to CSet,
eden: 94 regions, survivors: 10 regions, predicted young region time:
159.99 ms]
4067.021: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 94
regions, survivors: 10 regions, old: 0 regions, predicted pause time:
171.29 ms, target pause time: 200.00 ms]
, 0.2319995 secs]
[Parallel Time: 229.0 ms, GC Workers: 13]
[GC Worker Start (ms): Min: 4067021.3, Avg: 4067024.1, Max:
4067029.4, Diff: 8.0]
[Ext Root Scanning (ms): Min: 0.0, Avg: 0.5, Max: 1.3, Diff: 1.3,
Sum: 6.9]
[Update RS (ms): Min: 0.6, Avg: 5.3, Max: 7.5, Diff: 6.9, Sum: 69.2]
[Processed Buffers: Min: 1, Avg: 10.2, Max: 33, Diff: 32, Sum: 132]
[Scan RS (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 1.0]
[Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0,
Sum: 0.0]
[Object Copy (ms): Min: 219.7, Avg: 219.9, Max: 220.0, Diff: 0.3,
Sum: 2858.1]
[Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
[GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum:
1.2]
[GC Worker Total (ms): Min: 220.7, Avg: 225.9, Max: 228.8, Diff: 8.0,
Sum: 2937.3]
[GC Worker End (ms): Min: 4067250.0, Avg: 4067250.1, Max: 4067250.2,
Diff: 0.2]
[Code Root Fixup: 0.2 ms]
[Code Root Migration: 0.0 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 1.4 ms]
[Other: 1.4 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 0.8 ms]
[Ref Enq: 0.0 ms]
[Redirty Cards: 0.2 ms]
[Free CSet: 0.1 ms]
[Eden: 3008.0M(3008.0M)->0.0B(2976.0M) Survivors: 320.0M->320.0M Heap:
5134.3M(6144.0M)->2168.1M(6144.0M)]
Heap after GC invocations=343 (full 1):
garbage-first heap total 6291456K, used 2220163K [0x0000000640000000,
0x00000007c0000000, 0x00000007c0000000)
region size 32768K, 10 young (327680K), 10 survivors (327680K)
Metaspace used 31200K, capacity 31664K, committed 31872K, reserved
1077248K
class space used 3496K, capacity 3596K, committed 3712K, reserved
1048576K
}
[Times: user=2.94 sys=0.00, real=0.23 secs]
And the "user" part is keep growing... Can you explain what this actually
means? What exact process in the gc in contributing to this? And what can
be done in order to minimize this time?
Thanks.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20150202/56da790d/attachment-0001.html>