Question about Object Copy times

[D vd Reddy]

Hi,

We are running G1 GC with heap size of around 140 - 150 GB, we are
observing high object copy times during young gc (> 80 % of the total GC
time).
Is this expected or is there anything we are doing wrong.  I am not able to
find any documentation of optimizing high object copy times,
any help would be appreciated


CommandLine flags: -XX:+AggressiveOpts -XX:InitialHeapSize=154618822656
-XX:+ManagementServer
-XX:MaxGCPauseMillis=1000 -XX:MaxHeapSize=154618822656
-XX:MaxMetaspaceSize=268435456
-XX:MetaspaceSize=268435456 -XX:ObjectAlignmentInBytes=16
-XX:+PrintGC -XX:+PrintGCDetails -XX:+PrintGCTimeStamps
-XX:+UnlockExperimentalVMOptions
-XX:-UseCompressedOops -XX:+UseG1GC


Sample young GC snippet




4416.985: [GC pause (G1 Evacuation Pause) (young), 0.3180932 secs]
   [Parallel Time: 291.1 ms, GC Workers: 23]
      [GC Worker Start (ms): Min: 4416985.5, Avg: 4416985.9, Max:
4416986.2, Diff: 0.7]
      [Ext Root Scanning (ms): Min: 1.2, Avg: 1.7, Max: 4.4, Diff: 3.2,
Sum: 38.5]
      [Update RS (ms): Min: 36.3, Avg: 39.4, Max: 40.0, Diff: 3.8, Sum:
906.0]
         [Processed Buffers: Min: 47, Avg: 80.9, Max: 124, Diff: 77, Sum:
1861]
      [Scan RS (ms): Min: 0.5, Avg: 1.0, Max: 1.1, Diff: 0.6, Sum: 22.5]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0,
Sum: 0.6]
      [Object Copy (ms): Min: 247.1, Avg: 247.2, Max: 247.5, Diff: 0.4,
Sum: 5686.4]
      [Termination (ms): Min: 0.0, Avg: 0.3, Max: 0.4, Diff: 0.4, Sum: 7.5]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.3, Max: 0.7, Diff: 0.7, Sum:
7.6]
      [GC Worker Total (ms): Min: 289.4, Avg: 290.0, Max: 290.4, Diff: 1.0,
Sum: 6669.3]
      [GC Worker End (ms): Min: 4417275.5, Avg: 4417275.8, Max: 4417276.2,
Diff: 0.7]
   [Code Root Fixup: 0.4 ms]
   [Code Root Migration: 0.5 ms]
   [Clear CT: 9.3 ms]
   [Other: 16.8 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 3.7 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 6.0 ms]
   [Eden: 80.3G(80.3G)->0.0B(81.7G) Survivors: 2944.0M->2176.0M Heap:
126.4G(144.0G)->45.4G(144.0G)]
 [Times: user=6.84 sys=0.01, real=0.32 secs]

Full GC Log for a period of run :
https://gist.github.com/dvdreddy/5ecf9a58a3f309e8bb60


Thanks in advance
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://mail.openjdk.java.net/pipermail/hotspot-gc-use/attachments/20150820/3f7edf67/attachment.html>