G1 collector stays on small young-generation size longer than expected after concurrent cycle

[Wolfgang Pedot]

Thanks for the reply, I have that exact log with AdaptiveSizePolicy 
enabled. I have also added an attachment for convenience.

Here is the log, beginning with initial-mark and ending with the 
decision to grow young-generation. I have noticed that this does not 
allways happen, sometimes young-gen is grown immediately after mixed 
collects are done (see second attachment "good.txt").

regards
Wolfgang



2013-10-28T15:58:33.923+0100: 21430.811: [GC pause (young) (initial-mark)
Desired survivor size 276824064 bytes, new threshold 7 (max 15)
- age   1:   55460056 bytes,   55460056 total
- age   2:   79721520 bytes,  135181576 total
- age   3:   53921760 bytes,  189103336 total
- age   4:   24968016 bytes,  214071352 total
- age   5:   42768296 bytes,  256839648 total
- age   6:   15861352 bytes,  272701000 total
- age   7:   28221288 bytes,  300922288 total
  21430.811: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 200850, predicted base time: 103.40 ms, remaining time: 
196.60 ms, target pause time: 300.00 ms]
  21430.811: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 473 regions, survivors: 51 regions, predicted young region 
time: 76.73 ms]
  21430.811: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 473 regions, survivors: 51 regions, old: 0 regions, predicted 
pause time: 180.13 ms, target pause time: 300.00 ms]
, 0.2397300 secs]
    [Parallel Time: 232.7 ms, GC Workers: 12]
       [GC Worker Start (ms):  21430811.5  21430811.6  21430811.7 
21430811.8  21430811.8  21430811.8  21430811.9  21430811.9  21430811.9 
21430812.0  21430812.0  21430812.0
        Min: 21430811.5, Avg: 21430811.8, Max: 21430812.0, Diff: 0.4]
       [Ext Root Scanning (ms):  45.3  46.2  103.6  46.3  46.8  45.7 
46.4  63.9  66.3  45.9  47.4  59.8
        Min: 45.3, Avg: 55.3, Max: 103.6, Diff: 58.3, Sum: 663.5]
       [Update RS (ms):  46.4  46.2  0.0  46.5  46.0  46.8  46.7  25.2 
26.1  46.5  45.8  29.8
        Min: 0.0, Avg: 37.7, Max: 46.8, Diff: 46.8, Sum: 451.9]
          [Processed Buffers:  109  107  0  99  114  95  109  92  74 
108  107  112
           Min: 0, Avg: 93.8, Max: 114, Diff: 114, Sum: 1126]
       [Scan RS (ms):  0.3  0.3  0.1  0.1  0.2  0.3  0.0  0.3  0.2  0.5 
  0.4  0.2
        Min: 0.0, Avg: 0.2, Max: 0.5, Diff: 0.4, Sum: 2.9]
       [Object Copy (ms):  102.4  101.8  128.5  101.3  101.3  101.4 
101.0  104.7  101.5  101.2  100.4  104.2
        Min: 100.4, Avg: 104.1, Max: 128.5, Diff: 28.1, Sum: 1249.6]
       [Termination (ms):  37.9  37.9  0.0  37.9  37.9  37.9  37.9  37.9 
  37.9  37.9  37.9  37.9
        Min: 0.0, Avg: 34.7, Max: 37.9, Diff: 37.9, Sum: 416.5]
          [Termination Attempts:  36  45  1  37  33  43  1  35  33  32 
36  23
           Min: 1, Avg: 29.6, Max: 45, Diff: 44, Sum: 355]
       [GC Worker Other (ms):  0.1  0.1  0.0  0.0  0.1  0.1  0.1  0.0 
0.0  0.1  0.1  0.1
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.6]
       [GC Worker Total (ms):  232.4  232.3  232.2  232.1  232.1  232.1 
  232.1  232.0  232.0  232.0  231.9  231.9
        Min: 231.9, Avg: 232.1, Max: 232.4, Diff: 0.5, Sum: 2785.1]
       [GC Worker End (ms):  21431043.9  21431043.9  21431043.9 
21431043.9  21431043.9  21431043.9  21431043.9  21431043.9  21431043.9 
21431043.9  21431043.9  21431043.9
        Min: 21431043.9, Avg: 21431043.9, Max: 21431043.9, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.7 ms]
    [Other: 6.3 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 3.4 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.6 ms]
    [Eden: 3784.0M(3784.0M)->0.0B(3728.0M) Survivors: 408.0M->408.0M 
Heap: 13.5G(14.6G)->10096.0M(14.6G)]
  [Times: user=2.66 sys=0.02, real=0.24 secs]
2013-10-28T15:58:34.163+0100: 21431.051: [GC 
concurrent-root-region-scan-start]
2013-10-28T15:58:34.214+0100: 21431.101: [GC 
concurrent-root-region-scan-end, 0.0506100 secs]
2013-10-28T15:58:34.214+0100: 21431.101: [GC concurrent-mark-start]
2013-10-28T15:58:35.986+0100: 21432.874: [GC concurrent-mark-end, 
1.7727150 secs]
2013-10-28T15:58:35.994+0100: 21432.881: [GC remark 
2013-10-28T15:58:36.008+0100: 21432.896: [GC ref-proc, 0.1192260 secs], 
0.2022820 secs]
  [Times: user=1.47 sys=0.00, real=0.20 secs]
2013-10-28T15:58:36.198+0100: 21433.086: [GC cleanup 10G->9836M(14G), 
0.0347900 secs]
  [Times: user=0.28 sys=0.00, real=0.03 secs]
2013-10-28T15:58:36.234+0100: 21433.121: [GC concurrent-cleanup-start]
2013-10-28T15:58:36.234+0100: 21433.122: [GC concurrent-cleanup-end, 
0.0004450 secs]
2013-10-28T15:59:19.111+0100: 21475.998: [GC pause (young)
Desired survivor size 272629760 bytes, new threshold 6 (max 15)
- age   1:   63592160 bytes,   63592160 total
- age   2:   38460008 bytes,  102052168 total
- age   3:   63355736 bytes,  165407904 total
- age   4:   44680008 bytes,  210087912 total
- age   5:   22742184 bytes,  232830096 total
- age   6:   42023016 bytes,  274853112 total
- age   7:   15800936 bytes,  290654048 total
  21475.999: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 180993, predicted base time: 98.72 ms, remaining time: 
201.28 ms, target pause time: 300.00 ms]
  21475.999: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 466 regions, survivors: 51 regions, predicted young region 
time: 80.67 ms]
  21475.999: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 466 regions, survivors: 51 regions, old: 0 regions, predicted 
pause time: 179.39 ms, target pause time: 300.00 ms]
  21476.176: [G1Ergonomics (Mixed GCs) start mixed GCs, reason: 
candidate old regions available, candidate old regions: 635 regions, 
reclaimable: 3505373264 bytes (22.29 %), threshold: 5.00 %]
, 0.1775420 secs]
    [Parallel Time: 171.9 ms, GC Workers: 12]
       [GC Worker Start (ms):  21475999.2  21475999.3  21475999.3 
21475999.3  21475999.4  21475999.4  21475999.4  21475999.5  21475999.5 
21475999.5  21475999.5  21475999.5
        Min: 21475999.2, Avg: 21475999.4, Max: 21475999.5, Diff: 0.3]
       [Ext Root Scanning (ms):  100.6  45.5  64.1  45.1  45.4  44.9 
59.1  46.0  45.5  44.7  44.8  63.3
        Min: 44.7, Avg: 54.1, Max: 100.6, Diff: 55.9, Sum: 649.0]
       [Update RS (ms):  0.0  44.5  24.5  44.8  44.6  45.0  29.6  45.0 
44.5  44.8  44.9  25.2
        Min: 0.0, Avg: 36.5, Max: 45.0, Diff: 45.0, Sum: 437.4]
          [Processed Buffers:  0  125  71  113  123  117  89  97  100 
118  100  54
           Min: 0, Avg: 92.2, Max: 125, Diff: 125, Sum: 1107]
       [Scan RS (ms):  0.1  0.1  0.3  0.2  0.1  0.2  0.4  0.2  0.3  0.5 
  0.4  0.1
        Min: 0.1, Avg: 0.2, Max: 0.5, Diff: 0.4, Sum: 2.8]
       [Object Copy (ms):  70.7  81.3  82.4  81.2  81.0  81.2  82.1 
79.9  80.9  81.1  81.0  82.5
        Min: 70.7, Avg: 80.4, Max: 82.5, Diff: 11.8, Sum: 965.4]
       [Termination (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0 
0.0  0.0  0.0
        Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [Termination Attempts:  3  1  4  5  5  3  4  3  4  5  2  2
           Min: 1, Avg: 3.4, Max: 5, Diff: 4, Sum: 41]
       [GC Worker Other (ms):  0.3  0.1  0.1  0.1  0.2  0.1  0.2  0.0 
0.0  0.1  0.2  0.1
        Min: 0.0, Avg: 0.1, Max: 0.3, Diff: 0.2, Sum: 1.5]
       [GC Worker Total (ms):  171.7  171.4  171.4  171.4  171.5  171.4 
  171.4  171.2  171.2  171.2  171.3  171.2
        Min: 171.2, Avg: 171.3, Max: 171.7, Diff: 0.5, Sum: 2056.2]
       [GC Worker End (ms):  21476170.9  21476170.7  21476170.7 
21476170.7  21476170.8  21476170.8  21476170.9  21476170.7  21476170.7 
21476170.7  21476170.8  21476170.8
        Min: 21476170.7, Avg: 21476170.8, Max: 21476170.9, Diff: 0.2]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.8 ms]
    [Other: 4.8 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 2.0 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.6 ms]
    [Eden: 3728.0M(3728.0M)->0.0B(360.0M) Survivors: 408.0M->384.0M 
Heap: 12.9G(14.6G)->9559.3M(14.6G)]
  [Times: user=2.07 sys=0.00, real=0.18 secs]
2013-10-28T15:59:22.778+0100: 21479.666: [GC pause (mixed)
Desired survivor size 50331648 bytes, new threshold 1 (max 15)
- age   1:   95113344 bytes,   95113344 total
- age   2:   33760400 bytes,  128873744 total
- age   3:   33282608 bytes,  162156352 total
- age   4:   45404280 bytes,  207560632 total
- age   5:   36638688 bytes,  244199320 total
- age   6:   21839560 bytes,  266038880 total
  21479.666: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 127727, predicted base time: 87.54 ms, remaining time: 
212.46 ms, target pause time: 300.00 ms]
  21479.666: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 45 regions, survivors: 48 regions, predicted young region 
time: 56.91 ms]
  21479.667: [G1Ergonomics (CSet Construction) finish adding old regions 
to CSet, reason: old CSet region num reached max, old: 188 regions, max: 
188 regions]
  21479.667: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 45 regions, survivors: 48 regions, old: 188 regions, predicted 
pause time: 217.53 ms, target pause time: 300.00 ms]
  21479.921: [G1Ergonomics (Mixed GCs) continue mixed GCs, reason: 
candidate old regions available, candidate old regions: 447 regions, 
reclaimable: 2132693056 bytes (13.56 %), threshold: 5.00 %]
, 0.2550780 secs]
    [Parallel Time: 243.3 ms, GC Workers: 12]
       [GC Worker Start (ms):  21479667.1  21479667.1  21479667.1 
21479667.2  21479667.2  21479667.2  21479667.3  21479667.3  21479667.3 
21479667.3  21479667.4  21479667.4
        Min: 21479667.1, Avg: 21479667.3, Max: 21479667.4, Diff: 0.3]
       [Ext Root Scanning (ms):  45.6  63.8  59.3  45.9  46.0  46.9 
46.5  46.0  45.6  45.2  89.0  63.4
        Min: 45.2, Avg: 53.6, Max: 89.0, Diff: 43.8, Sum: 643.3]
       [Update RS (ms):  29.6  10.2  14.7  29.4  28.9  29.5  28.3  28.9 
  29.3  29.9  0.0  10.1
        Min: 0.0, Avg: 22.4, Max: 29.9, Diff: 29.9, Sum: 268.8]
          [Processed Buffers:  69  32  57  76  54  67  86  69  74  75  0  26
           Min: 0, Avg: 57.1, Max: 86, Diff: 86, Sum: 685]
       [Scan RS (ms):  39.4  39.5  39.7  40.1  39.6  39.8  39.7  39.5 
40.2  39.5  5.5  39.6
        Min: 5.5, Avg: 36.8, Max: 40.2, Diff: 34.7, Sum: 442.0]
       [Object Copy (ms):  128.6  129.5  129.3  127.7  128.4  126.8 
128.4  128.4  127.8  128.3  148.3  129.7
        Min: 126.8, Avg: 130.1, Max: 148.3, Diff: 21.5, Sum: 1561.3]
       [Termination (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0 
0.0  0.0  0.0
        Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [Termination Attempts:  1  4  13  12  7  8  8  7  2  8  7  8
           Min: 1, Avg: 7.1, Max: 13, Diff: 12, Sum: 85]
       [GC Worker Other (ms):  0.1  0.1  0.1  0.0  0.1  0.1  0.1  0.1 
0.1  0.1  0.1  0.1
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 1.0]
       [GC Worker Total (ms):  243.2  243.2  243.2  243.1  243.1  243.0 
  243.0  243.0  243.0  243.0  242.9  242.9
        Min: 242.9, Avg: 243.0, Max: 243.2, Diff: 0.4, Sum: 2916.6]
       [GC Worker End (ms):  21479910.3  21479910.3  21479910.3 
21479910.3  21479910.3  21479910.3  21479910.3  21479910.3  21479910.3 
21479910.3  21479910.2  21479910.3
        Min: 21479910.2, Avg: 21479910.3, Max: 21479910.3, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 2.0 ms]
    [Other: 9.8 ms]
       [Choose CSet: 0.5 ms]
       [Ref Proc: 2.9 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 1.6 ms]
    [Eden: 360.0M(360.0M)->0.0B(648.0M) Survivors: 384.0M->96.0M Heap: 
9919.3M(14.6G)->8419.4M(14.6G)]
  [Times: user=2.77 sys=0.00, real=0.25 secs]
2013-10-28T15:59:30.652+0100: 21487.540: [GC pause (mixed)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:    7901552 bytes,    7901552 total
  21487.540: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 218925, predicted base time: 105.38 ms, remaining time: 
194.62 ms, target pause time: 300.00 ms]
  21487.540: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 23.27 ms]
  21487.541: [G1Ergonomics (CSet Construction) finish adding old regions 
to CSet, reason: predicted time is too high, predicted time: 1.33 ms, 
remaining time: 1.08 ms, old: 182 regions, min: 80 regions]
  21487.541: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 182 regions, predicted 
pause time: 298.92 ms, target pause time: 300.00 ms]
  21487.843: [G1Ergonomics (Mixed GCs) continue mixed GCs, reason: 
candidate old regions available, candidate old regions: 265 regions, 
reclaimable: 1054790352 bytes (6.71 %), threshold: 5.00 %]
, 0.3030120 secs]
    [Parallel Time: 290.2 ms, GC Workers: 12]
       [GC Worker Start (ms):  21487541.6  21487541.6  21487541.6 
21487541.8  21487541.8  21487541.8  21487541.8  21487541.9  21487541.9 
21487541.9  21487541.9  21487541.9
        Min: 21487541.6, Avg: 21487541.8, Max: 21487541.9, Diff: 0.4]
       [Ext Root Scanning (ms):  46.3  45.6  47.1  65.1  46.3  46.1 
59.6  46.6  45.4  64.4  97.2  45.8
        Min: 45.4, Avg: 54.6, Max: 97.2, Diff: 51.8, Sum: 655.6]
       [Update RS (ms):  55.1  55.4  55.7  35.0  54.8  54.8  40.6  54.1 
  55.5  35.2  0.0  54.9
        Min: 0.0, Avg: 45.9, Max: 55.7, Diff: 55.7, Sum: 551.1]
          [Processed Buffers:  95  87  102  72  102  107  104  81  105 
93  0  116
           Min: 0, Avg: 88.7, Max: 116, Diff: 116, Sum: 1064]
       [Scan RS (ms):  36.6  36.8  36.3  36.4  36.6  36.6  36.4  36.6 
36.7  36.6  16.9  36.9
        Min: 16.9, Avg: 35.0, Max: 36.9, Diff: 20.0, Sum: 419.4]
       [Object Copy (ms):  151.9  151.9  150.7  153.0  151.8  152.2 
153.0  152.3  151.9  153.3  175.4  151.9
        Min: 150.7, Avg: 154.1, Max: 175.4, Diff: 24.7, Sum: 1849.2]
       [Termination (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0 
0.0  0.0  0.0
        Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [Termination Attempts:  1  1  2  2  1  2  1  2  2  1  1  1
           Min: 1, Avg: 1.4, Max: 2, Diff: 1, Sum: 17]
       [GC Worker Other (ms):  0.1  0.1  0.1  0.0  0.0  0.0  0.1  0.0 
0.1  0.1  0.1  0.1
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
       [GC Worker Total (ms):  290.0  289.9  289.8  289.7  289.7  289.6 
  289.7  289.6  289.6  289.5  289.6  289.5
        Min: 289.5, Avg: 289.7, Max: 290.0, Diff: 0.5, Sum: 3476.2]
       [GC Worker End (ms):  21487831.6  21487831.5  21487831.5 
21487831.4  21487831.5  21487831.4  21487831.5  21487831.4  21487831.5 
21487831.5  21487831.5  21487831.5
        Min: 21487831.4, Avg: 21487831.5, Max: 21487831.6, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 2.4 ms]
    [Other: 10.4 ms]
       [Choose CSet: 0.9 ms]
       [Ref Proc: 1.8 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 2.1 ms]
    [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 
9067.4M(14.6G)->7480.0M(14.6G)]
  [Times: user=3.51 sys=0.00, real=0.30 secs]
2013-10-28T15:59:38.671+0100: 21495.559: [GC pause (mixed)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:   24399800 bytes,   24399800 total
- age   2:    4322520 bytes,   28722320 total
  21495.559: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 199259, predicted base time: 103.72 ms, remaining time: 
196.28 ms, target pause time: 300.00 ms]
  21495.559: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 24.30 ms]
  21495.560: [G1Ergonomics (CSet Construction) finish adding old regions 
to CSet, reason: reclaimable percentage not over threshold, old: 62 
regions, max: 188 regions, reclaimable: 784279232 bytes (4.99 %), 
threshold: 5.00 %]
  21495.560: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 62 regions, predicted 
pause time: 222.80 ms, target pause time: 300.00 ms]
  21495.811: [G1Ergonomics (Mixed GCs) do not continue mixed GCs, 
reason: reclaimable percentage not over threshold, candidate old 
regions: 203 regions, reclaimable: 784279232 bytes (4.99 %), threshold: 
5.00 %]
, 0.2522200 secs]
    [Parallel Time: 241.2 ms, GC Workers: 12]
       [GC Worker Start (ms):  21495560.3  21495560.4  21495560.4 
21495560.4  21495560.4  21495560.5  21495560.5  21495560.5  21495560.5 
21495560.5  21495560.6  21495560.6
        Min: 21495560.3, Avg: 21495560.5, Max: 21495560.6, Diff: 0.3]
       [Ext Root Scanning (ms):  64.9  45.7  64.9  45.9  45.6  47.1 
99.2  59.5  45.4  45.5  45.2  46.0
        Min: 45.2, Avg: 54.6, Max: 99.2, Diff: 54.0, Sum: 654.8]
       [Update RS (ms):  42.9  63.9  43.1  63.8  63.8  63.6  0.0  48.9 
63.8  63.6  64.1  63.0
        Min: 0.0, Avg: 53.7, Max: 64.1, Diff: 64.1, Sum: 644.4]
          [Processed Buffers:  70  97  93  92  108  97  0  97  102  100 
  104  96
           Min: 0, Avg: 88.0, Max: 108, Diff: 108, Sum: 1056]
       [Scan RS (ms):  34.9  35.0  34.9  34.6  34.8  34.9  16.6  34.8 
34.8  34.8  34.8  35.0
        Min: 16.6, Avg: 33.3, Max: 35.0, Diff: 18.5, Sum: 400.0]
       [Object Copy (ms):  98.3  96.2  97.9  96.6  96.6  95.2  125.0 
97.5  96.8  96.7  96.6  96.7
        Min: 95.2, Avg: 99.2, Max: 125.0, Diff: 29.8, Sum: 1190.1]
       [Termination (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0 
0.0  0.0  0.0
        Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
          [Termination Attempts:  11  1  10  8  4  6  9  7  5  1  6  12
           Min: 1, Avg: 6.7, Max: 12, Diff: 11, Sum: 80]
       [GC Worker Other (ms):  0.1  0.1  0.1  0.1  0.0  0.1  0.0  0.1 
0.1  0.0  0.1  0.1
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
       [GC Worker Total (ms):  241.0  241.0  241.0  240.9  240.8  240.9 
  240.7  240.8  240.8  240.7  240.7  240.7
        Min: 240.7, Avg: 240.8, Max: 241.0, Diff: 0.3, Sum: 2890.2]
       [GC Worker End (ms):  21495801.3  21495801.3  21495801.3 
21495801.3  21495801.3  21495801.3  21495801.3  21495801.3  21495801.3 
21495801.3  21495801.3  21495801.3
        Min: 21495801.3, Avg: 21495801.3, Max: 21495801.3, Diff: 0.1]
    [Code Root Fixup: 0.3 ms]
    [Clear CT: 2.6 ms]
    [Other: 8.1 ms]
       [Choose CSet: 0.6 ms]
       [Ref Proc: 2.0 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 1.2 ms]
    [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 
8128.0M(14.6G)->7263.3M(14.6G)]
  [Times: user=2.93 sys=0.00, real=0.25 secs]
2013-10-28T15:59:44.685+0100: 21501.573: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:   26676824 bytes,   26676824 total
- age   2:   17917840 bytes,   44594664 total
- age   3:    3599704 bytes,   48194368 total
  21501.574: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 160602, predicted base time: 101.20 ms, remaining time: 
198.80 ms, target pause time: 300.00 ms]
  21501.574: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 60.87 ms]
  21501.574: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause 
time: 162.08 ms, target pause time: 300.00 ms]
, 0.1277600 secs]
    [Parallel Time: 123.2 ms, GC Workers: 12]
       [GC Worker Start (ms):  21501573.9  21501574.0  21501574.1 
21501574.1  21501574.1  21501574.1  21501574.2  21501574.3  21501574.3 
21501574.3  21501574.3  21501574.3
        Min: 21501573.9, Avg: 21501574.2, Max: 21501574.3, Diff: 0.4]
       [Ext Root Scanning (ms):  46.0  45.5  58.9  100.0  63.9  64.1 
45.7  45.2  45.4  45.2  45.3  44.8
        Min: 44.8, Avg: 54.2, Max: 100.0, Diff: 55.2, Sum: 650.1]
       [Update RS (ms):  51.6  52.3  38.6  0.0  32.2  31.9  51.4  52.0 
52.1  51.9  51.7  52.0
        Min: 0.0, Avg: 43.1, Max: 52.3, Diff: 52.3, Sum: 517.8]
          [Processed Buffers:  77  72  73  0  69  56  79  88  78  73  88  80
           Min: 0, Avg: 69.4, Max: 88, Diff: 88, Sum: 833]
       [Scan RS (ms):  0.6  0.6  0.8  0.0  0.7  0.8  0.9  0.6  0.4  0.8 
  0.8  0.8
        Min: 0.0, Avg: 0.6, Max: 0.9, Diff: 0.9, Sum: 7.6]
       [Object Copy (ms):  20.1  19.9  19.9  22.9  21.2  21.3  20.0 
20.2  20.0  20.2  20.2  20.3
        Min: 19.9, Avg: 20.5, Max: 22.9, Diff: 3.0, Sum: 246.2]
       [Termination (ms):  4.8  4.8  4.8  0.0  4.8  4.8  4.8  4.8  4.8 
4.7  4.8  4.8
        Min: 0.0, Avg: 4.4, Max: 4.8, Diff: 4.8, Sum: 52.6]
          [Termination Attempts:  148  161  127  1  142  147  162  139 
163  1  154  155
           Min: 1, Avg: 125.0, Max: 163, Diff: 162, Sum: 1500]
       [GC Worker Other (ms):  0.1  0.1  0.1  0.0  0.0  0.1  0.1  0.1 
0.1  0.1  0.1  0.1
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.8]
       [GC Worker Total (ms):  123.2  123.1  123.0  123.0  122.9  122.9 
  122.9  122.8  122.8  122.8  122.8  122.8
        Min: 122.8, Avg: 122.9, Max: 123.2, Diff: 0.4, Sum: 1475.1]
       [GC Worker End (ms):  21501697.1  21501697.1  21501697.1 
21501697.0  21501697.1  21501697.1  21501697.1  21501697.1  21501697.1 
21501697.1  21501697.1  21501697.1
        Min: 21501697.0, Avg: 21501697.1, Max: 21501697.1, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.8 ms]
    [Other: 3.7 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 1.9 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.2 ms]
    [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 
7911.3M(14.6G)->7293.7M(14.6G)]
  [Times: user=1.50 sys=0.00, real=0.13 secs]
2013-10-28T15:59:51.136+0100: 21508.024: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 3 (max 15)
- age   1:   22020176 bytes,   22020176 total
- age   2:   20834232 bytes,   42854408 total
- age   3:   16616152 bytes,   59470560 total
- age   4:    3427912 bytes,   62898472 total
  21508.025: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 61972, predicted base time: 78.13 ms, remaining time: 
221.87 ms, target pause time: 300.00 ms]
  21508.025: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 20.76 ms]
  21508.025: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause 
time: 98.89 ms, target pause time: 300.00 ms]
, 0.1165410 secs]
    [Parallel Time: 112.6 ms, GC Workers: 12]
       [GC Worker Start (ms):  21508025.1  21508025.1  21508025.2 
21508025.2  21508025.3  21508025.3  21508025.4  21508025.4  21508025.4 
21508025.4  21508025.5  21508025.5
        Min: 21508025.1, Avg: 21508025.3, Max: 21508025.5, Diff: 0.4]
       [Ext Root Scanning (ms):  46.1  45.4  45.6  64.0  44.9  47.0 
45.8  58.7  91.3  64.7  45.6  45.2
        Min: 44.9, Avg: 53.7, Max: 91.3, Diff: 46.4, Sum: 644.3]
       [Update RS (ms):  16.0  16.6  16.6  0.0  16.8  15.1  16.2  2.2 
0.0  0.0  16.1  16.7
        Min: 0.0, Avg: 11.0, Max: 16.8, Diff: 16.8, Sum: 132.3]
          [Processed Buffers:  41  67  65  0  49  68  51  28  0  0  58  61
           Min: 0, Avg: 40.7, Max: 68, Diff: 68, Sum: 488]
       [Scan RS (ms):  0.0  0.1  0.0  0.0  0.1  0.0  0.0  0.1  0.0  0.0 
  0.1  0.0
        Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
       [Object Copy (ms):  23.7  23.7  23.6  21.7  23.8  23.6  23.6 
24.5  20.8  20.8  23.7  23.5
        Min: 20.8, Avg: 23.1, Max: 24.5, Diff: 3.8, Sum: 277.1]
       [Termination (ms):  26.6  26.6  26.6  26.6  26.6  26.6  26.6 
26.6  0.0  26.6  26.6  26.6
        Min: 0.0, Avg: 24.4, Max: 26.6, Diff: 26.6, Sum: 292.4]
          [Termination Attempts:  42  1  48  47  49  44  49  49  1  51 
47  50
           Min: 1, Avg: 39.8, Max: 51, Diff: 50, Sum: 478]
       [GC Worker Other (ms):  0.1  0.1  0.1  0.1  0.1  0.1  0.1  0.1 
0.0  0.1  0.1  0.0
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.8]
       [GC Worker Total (ms):  112.5  112.5  112.4  112.4  112.3  112.3 
  112.2  112.2  112.1  112.1  112.1  112.1
        Min: 112.1, Avg: 112.3, Max: 112.5, Diff: 0.4, Sum: 1347.3]
       [GC Worker End (ms):  21508137.6  21508137.6  21508137.6 
21508137.6  21508137.6  21508137.6  21508137.6  21508137.6  21508137.5 
21508137.6  21508137.6  21508137.6
        Min: 21508137.5, Avg: 21508137.6, Max: 21508137.6, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.2 ms]
    [Other: 3.7 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 2.0 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.2 ms]
    [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 
7941.7M(14.6G)->7391.1M(14.6G)]
  [Times: user=1.35 sys=0.01, real=0.11 secs]
2013-10-28T15:59:58.723+0100: 21515.610: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 3 (max 15)
- age   1:   20444800 bytes,   20444800 total
- age   2:   14599736 bytes,   35044536 total
- age   3:   17794192 bytes,   52838728 total
  21515.611: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 90998, predicted base time: 82.82 ms, remaining time: 
217.18 ms, target pause time: 300.00 ms]
  21515.611: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 19.51 ms]
  21515.611: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause 
time: 102.33 ms, target pause time: 300.00 ms]
, 0.1198280 secs]
    [Parallel Time: 116.2 ms, GC Workers: 12]
       [GC Worker Start (ms):  21515611.0  21515611.0  21515611.1 
21515611.1  21515611.1  21515611.2  21515611.2  21515611.3  21515611.3 
21515611.3  21515611.3  21515611.3
        Min: 21515611.0, Avg: 21515611.2, Max: 21515611.3, Diff: 0.4]
       [Ext Root Scanning (ms):  45.7  45.9  45.8  64.0  45.6  64.2 
45.5  94.2  46.6  59.6  45.7  45.8
        Min: 45.5, Avg: 54.0, Max: 94.2, Diff: 48.7, Sum: 648.5]
       [Update RS (ms):  24.9  24.4  24.7  5.3  25.0  5.5  25.2  0.0 
25.4  9.8  24.5  24.6
        Min: 0.0, Avg: 18.3, Max: 25.4, Diff: 25.4, Sum: 219.5]
          [Processed Buffers:  66  54  63  34  45  33  54  0  58  57  65  56
           Min: 0, Avg: 48.8, Max: 66, Diff: 66, Sum: 585]
       [Scan RS (ms):  0.0  0.2  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.1 
  0.0  0.0
        Min: 0.0, Avg: 0.0, Max: 0.2, Diff: 0.2, Sum: 0.4]
       [Object Copy (ms):  20.9  20.9  20.9  22.1  20.8  21.7  20.6 
21.5  19.2  21.7  21.0  20.8
        Min: 19.2, Avg: 21.0, Max: 22.1, Diff: 2.9, Sum: 252.2]
       [Termination (ms):  24.5  24.5  24.5  24.5  24.5  24.5  24.5  0.0 
  24.5  24.5  24.5  24.5
        Min: 0.0, Avg: 22.5, Max: 24.5, Diff: 24.5, Sum: 269.8]
          [Termination Attempts:  1  1  1  1  1  1  1  1  1  1  1  1
           Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 12]
       [GC Worker Other (ms):  0.0  0.1  0.1  0.1  0.1  0.1  0.1  0.0 
0.0  0.1  0.1  0.0
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
       [GC Worker Total (ms):  116.1  116.1  116.1  116.1  116.0  116.0 
  115.9  115.8  115.8  115.8  115.8  115.8
        Min: 115.8, Avg: 115.9, Max: 116.1, Diff: 0.4, Sum: 1391.3]
       [GC Worker End (ms):  21515727.1  21515727.1  21515727.1 
21515727.1  21515727.1  21515727.1  21515727.1  21515727.0  21515727.1 
21515727.1  21515727.1  21515727.1
        Min: 21515727.0, Avg: 21515727.1, Max: 21515727.1, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.1 ms]
    [Other: 3.5 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 1.8 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.2 ms]
    [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 
8039.1M(14.6G)->7477.8M(14.6G)]
  [Times: user=1.39 sys=0.00, real=0.12 secs]
2013-10-28T16:00:01.284+0100: 21518.172: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 3 (max 15)
- age   1:   22178080 bytes,   22178080 total
- age   2:   15771712 bytes,   37949792 total
- age   3:   12924848 bytes,   50874640 total
  21518.172: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 74257, predicted base time: 77.45 ms, remaining time: 
222.55 ms, target pause time: 300.00 ms]
  21518.172: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 16.66 ms]
  21518.172: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause 
time: 94.12 ms, target pause time: 300.00 ms]
, 0.1202740 secs]
    [Parallel Time: 114.7 ms, GC Workers: 12]
       [GC Worker Start (ms):  21518172.6  21518172.7  21518172.7 
21518172.7  21518172.8  21518172.8  21518172.8  21518172.9  21518173.0 
21518173.0  21518173.0  21518173.0
        Min: 21518172.6, Avg: 21518172.8, Max: 21518173.0, Diff: 0.4]
       [Ext Root Scanning (ms):  61.8  46.5  46.0  45.1  45.3  45.2 
45.4  45.9  59.6  47.8  92.0  64.5
        Min: 45.1, Avg: 53.8, Max: 92.0, Diff: 46.9, Sum: 645.1]
       [Update RS (ms):  2.4  18.7  20.2  20.8  19.9  19.9  34.4  19.4 
4.5  16.9  0.0  0.6
        Min: 0.0, Avg: 14.8, Max: 34.4, Diff: 34.4, Sum: 177.8]
          [Processed Buffers:  32  53  43  51  70  47  19  46  33  46  0  1
           Min: 0, Avg: 36.8, Max: 70, Diff: 70, Sum: 441]
       [Scan RS (ms):  0.1  0.1  0.0  0.0  0.0  0.1  0.0  0.0  0.1  0.1 
  0.0  0.0
        Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
       [Object Copy (ms):  22.1  21.0  20.1  20.4  20.9  20.9  6.3  39.3 
  21.8  21.2  21.1  20.9
        Min: 6.3, Avg: 21.3, Max: 39.3, Diff: 33.0, Sum: 256.0]
       [Termination (ms):  27.1  27.1  27.1  27.1  27.1  27.1  27.1  8.6 
  28.2  27.1  0.0  27.1
        Min: 0.0, Avg: 23.4, Max: 28.2, Diff: 28.2, Sum: 280.6]
          [Termination Attempts:  23  17  15  16  18  17  14  1  17  14 
  1  14
           Min: 1, Avg: 13.9, Max: 23, Diff: 22, Sum: 167]
       [GC Worker Other (ms):  0.1  0.1  0.1  0.1  0.1  0.1  0.1  0.1 
0.0  0.1  0.0  0.1
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
       [GC Worker Total (ms):  113.6  113.5  113.5  113.4  113.3  113.3 
  113.3  113.3  114.2  113.2  113.1  113.2
        Min: 113.1, Avg: 113.4, Max: 114.2, Diff: 1.1, Sum: 1360.9]
       [GC Worker End (ms):  21518286.2  21518286.1  21518286.2 
21518286.2  21518286.2  21518286.2  21518286.2  21518286.2  21518287.1 
21518286.2  21518286.1  21518286.2
        Min: 21518286.1, Avg: 21518286.2, Max: 21518287.1, Diff: 1.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.2 ms]
    [Other: 5.4 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 3.8 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.2 ms]
    [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 
8125.8M(14.6G)->7548.1M(14.6G)]
  [Times: user=1.31 sys=0.00, real=0.12 secs]
2013-10-28T16:00:05.597+0100: 21522.485: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:   16592056 bytes,   16592056 total
- age   2:   17463768 bytes,   34055824 total
- age   3:   15349624 bytes,   49405448 total
  21522.486: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 76409, predicted base time: 77.52 ms, remaining time: 
222.48 ms, target pause time: 300.00 ms]
  21522.486: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 18.97 ms]
  21522.486: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause 
time: 96.49 ms, target pause time: 300.00 ms]
, 0.1174670 secs]
    [Parallel Time: 113.2 ms, GC Workers: 12]
       [GC Worker Start (ms):  21522485.8  21522485.9  21522485.9 
21522486.0  21522486.1  21522486.2  21522486.2  21522486.2  21522486.2 
21522486.2  21522486.3  21522486.3
        Min: 21522485.8, Avg: 21522486.1, Max: 21522486.3, Diff: 0.4]
       [Ext Root Scanning (ms):  45.3  91.8  46.0  46.9  63.4  58.7 
45.1  63.1  45.3  46.3  45.7  48.3
        Min: 45.1, Avg: 53.8, Max: 91.8, Diff: 46.7, Sum: 645.9]
       [Update RS (ms):  20.4  0.0  19.4  19.7  0.8  6.0  19.9  0.8 
19.9  18.8  19.6  17.1
        Min: 0.0, Avg: 13.5, Max: 20.4, Diff: 20.4, Sum: 162.4]
          [Processed Buffers:  57  0  68  73  8  33  55  2  48  62  61  52
           Min: 0, Avg: 43.2, Max: 73, Diff: 73, Sum: 519]
       [Scan RS (ms):  0.0  0.0  0.1  0.1  0.0  0.0  0.1  0.0  0.1  0.1 
  0.1  0.0
        Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
       [Object Copy (ms):  21.5  21.0  21.6  20.2  22.6  22.1  21.7 
22.9  21.5  21.5  21.4  21.3
        Min: 20.2, Avg: 21.6, Max: 22.9, Diff: 2.7, Sum: 259.2]
       [Termination (ms):  25.7  0.0  25.7  25.7  25.7  25.7  25.7  25.7 
  25.7  25.7  25.7  25.7
        Min: 0.0, Avg: 23.6, Max: 25.7, Diff: 25.7, Sum: 283.0]
          [Termination Attempts:  19  1  13  16  14  9  17  18  15  20 
1  16
           Min: 1, Avg: 13.2, Max: 20, Diff: 19, Sum: 159]
       [GC Worker Other (ms):  0.1  0.0  0.1  0.0  0.1  0.1  0.1  0.1 
0.1  0.1  0.1  0.1
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 1.0]
       [GC Worker Total (ms):  112.9  112.8  112.8  112.7  112.6  112.6 
  112.6  112.6  112.6  112.6  112.5  112.5
        Min: 112.5, Avg: 112.7, Max: 112.9, Diff: 0.4, Sum: 1351.9]
       [GC Worker End (ms):  21522598.7  21522598.7  21522598.8 
21522598.7  21522598.8  21522598.8  21522598.8  21522598.8  21522598.8 
21522598.8  21522598.8  21522598.8
        Min: 21522598.7, Avg: 21522598.8, Max: 21522598.8, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.2 ms]
    [Other: 4.1 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 2.5 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.2 ms]
    [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 
8196.1M(14.6G)->7582.0M(14.6G)]
  [Times: user=1.36 sys=0.00, real=0.11 secs]
2013-10-28T16:00:06.595+0100: 21523.483: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 3 (max 15)
- age   1:   26815464 bytes,   26815464 total
- age   2:   12126232 bytes,   38941696 total
- age   3:   15333080 bytes,   54274776 total
- age   4:   13133256 bytes,   67408032 total
  21523.484: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 40586, predicted base time: 68.66 ms, remaining time: 
231.34 ms, target pause time: 300.00 ms]
  21523.484: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 28.52 ms]
  21523.484: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause 
time: 97.18 ms, target pause time: 300.00 ms]
, 0.1269940 secs]
    [Parallel Time: 118.4 ms, GC Workers: 12]
       [GC Worker Start (ms):  21523483.8  21523483.8  21523483.9 
21523483.9  21523483.9  21523483.9  21523483.9  21523483.9  21523483.9 
21523484.0  21523484.1  21523484.0
        Min: 21523483.8, Avg: 21523483.9, Max: 21523484.1, Diff: 0.2]
       [Ext Root Scanning (ms):  87.3  52.5  69.8  96.8  69.7  60.8 
53.7  72.7  70.6  54.0  54.1  86.7
        Min: 52.5, Avg: 69.1, Max: 96.8, Diff: 44.3, Sum: 828.6]
       [Update RS (ms):  0.0  20.6  2.1  0.0  2.0  12.0  20.6  1.2  2.4 
  19.4  46.9  0.0
        Min: 0.0, Avg: 10.6, Max: 46.9, Diff: 46.9, Sum: 127.2]
          [Processed Buffers:  0  62  18  0  12  35  53  4  22  42  23  0
           Min: 0, Avg: 22.6, Max: 62, Diff: 62, Sum: 271]
       [Scan RS (ms):  0.0  0.0  0.1  0.0  0.0  0.0  0.0  0.0  0.0  0.2 
  0.0  0.0
        Min: 0.0, Avg: 0.0, Max: 0.2, Diff: 0.2, Sum: 0.4]
       [Object Copy (ms):  15.0  29.2  30.5  21.3  30.5  29.5  27.9 
36.0  29.2  28.6  1.7  15.4
        Min: 1.7, Avg: 24.6, Max: 36.0, Diff: 34.4, Sum: 294.8]
       [Termination (ms):  15.9  15.9  15.8  0.0  15.8  15.8  15.8  8.1 
  15.8  15.8  15.3  16.0
        Min: 0.0, Avg: 13.8, Max: 16.0, Diff: 16.0, Sum: 166.0]
          [Termination Attempts:  36  66  109  1  76  66  71  1  66  71 
  1  35
           Min: 1, Avg: 49.9, Max: 109, Diff: 108, Sum: 599]
       [GC Worker Other (ms):  0.1  0.1  0.1  0.0  0.1  0.1  0.0  0.1 
0.1  0.1  0.1  0.1
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 1.0]
       [GC Worker Total (ms):  118.3  118.3  118.2  118.2  118.2  118.2 
  118.1  118.2  118.2  118.1  118.0  118.1
        Min: 118.0, Avg: 118.2, Max: 118.3, Diff: 0.2, Sum: 1418.1]
       [GC Worker End (ms):  21523602.1  21523602.1  21523602.1 
21523602.0  21523602.1  21523602.1  21523602.1  21523602.1  21523602.1 
21523602.1  21523602.1  21523602.1
        Min: 21523602.0, Avg: 21523602.1, Max: 21523602.1, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.2 ms]
    [Other: 8.4 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 6.6 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.2 ms]
    [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 
8230.0M(14.6G)->7629.0M(14.6G)]
  [Times: user=1.17 sys=0.00, real=0.13 secs]
2013-10-28T16:00:07.417+0100: 21524.305: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:   10249616 bytes,   10249616 total
- age   2:   21417864 bytes,   31667480 total
- age   3:   11865880 bytes,   43533360 total
  21524.305: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 73249, predicted base time: 85.31 ms, remaining time: 
214.69 ms, target pause time: 300.00 ms]
  21524.305: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 17.95 ms]
  21524.305: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause 
time: 103.27 ms, target pause time: 300.00 ms]
, 0.1186000 secs]
    [Parallel Time: 115.5 ms, GC Workers: 12]
       [GC Worker Start (ms):  21524305.2  21524305.2  21524305.2 
21524305.2  21524305.2  21524305.3  21524305.3  21524305.4  21524305.4 
21524305.4  21524305.4  21524305.4
        Min: 21524305.2, Avg: 21524305.3, Max: 21524305.4, Diff: 0.2]
       [Ext Root Scanning (ms):  47.6  63.0  70.1  65.3  48.5  61.7 
64.8  67.3  47.5  60.0  93.6  47.8
        Min: 47.5, Avg: 61.5, Max: 93.6, Diff: 46.1, Sum: 737.4]
       [Update RS (ms):  30.7  14.1  7.9  11.4  30.3  31.4  11.6  8.8 
29.8  16.6  0.0  33.5
        Min: 0.0, Avg: 18.8, Max: 33.5, Diff: 33.5, Sum: 226.0]
          [Processed Buffers:  34  33  30  28  63  21  23  26  63  29  0  34
           Min: 0, Avg: 32.0, Max: 63, Diff: 63, Sum: 384]
       [Scan RS (ms):  0.0  0.1  0.0  0.0  0.1  0.0  0.0  0.0  0.1  0.0 
  0.0  0.0
        Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
       [Object Copy (ms):  15.7  16.7  16.0  17.3  15.1  1.3  17.5  17.8 
  16.5  17.3  21.5  12.6
        Min: 1.3, Avg: 15.5, Max: 21.5, Diff: 20.2, Sum: 185.5]
       [Termination (ms):  21.2  21.3  21.2  21.2  21.2  20.8  21.2 
21.2  21.2  21.2  0.0  21.2
        Min: 0.0, Avg: 19.4, Max: 21.3, Diff: 21.3, Sum: 233.2]
          [Termination Attempts:  37  36  44  34  45  1  37  42  42  36 
  1  32
           Min: 1, Avg: 32.2, Max: 45, Diff: 44, Sum: 387]
       [GC Worker Other (ms):  0.1  0.1  0.1  0.1  0.0  0.1  0.1  0.1 
0.1  0.1  0.0  0.1
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
       [GC Worker Total (ms):  115.4  115.4  115.4  115.4  115.3  115.3 
  115.3  115.2  115.2  115.2  115.1  115.2
        Min: 115.1, Avg: 115.3, Max: 115.4, Diff: 0.3, Sum: 1383.5]
       [GC Worker End (ms):  21524420.6  21524420.6  21524420.6 
21524420.6  21524420.6  21524420.6  21524420.6  21524420.6  21524420.6 
21524420.6  21524420.5  21524420.6
        Min: 21524420.5, Avg: 21524420.6, Max: 21524420.6, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.2 ms]
    [Other: 3.0 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 1.5 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.2 ms]
    [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 
8277.0M(14.6G)->7634.9M(14.6G)]
  [Times: user=1.19 sys=0.01, real=0.11 secs]
2013-10-28T16:00:09.160+0100: 21526.048: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:    6000328 bytes,    6000328 total
- age   2:    9520600 bytes,   15520928 total
- age   3:   20602264 bytes,   36123192 total
- age   4:   11786432 bytes,   47909624 total
  21526.048: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 27950, predicted base time: 74.37 ms, remaining time: 
225.63 ms, target pause time: 300.00 ms]
  21526.048: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 16.51 ms]
  21526.048: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause 
time: 90.88 ms, target pause time: 300.00 ms]
, 0.1238860 secs]
    [Parallel Time: 119.6 ms, GC Workers: 12]
       [GC Worker Start (ms):  21526048.4  21526048.4  21526048.5 
21526048.5  21526048.5  21526048.6  21526048.6  21526048.6  21526048.6 
21526048.7  21526048.7  21526048.8
        Min: 21526048.4, Avg: 21526048.6, Max: 21526048.8, Diff: 0.4]
       [Ext Root Scanning (ms):  64.3  48.7  56.1  59.2  84.8  66.6 
48.1  60.6  98.8  66.3  48.2  61.0
        Min: 48.1, Avg: 63.6, Max: 98.8, Diff: 50.7, Sum: 762.8]
       [Update RS (ms):  1.5  15.9  9.9  7.0  0.0  0.0  16.0  3.5  0.0 
0.0  15.9  3.2
        Min: 0.0, Avg: 6.1, Max: 16.0, Diff: 16.0, Sum: 73.1]
          [Processed Buffers:  2  40  29  21  0  0  38  13  0  0  31  22
           Min: 0, Avg: 16.3, Max: 40, Diff: 40, Sum: 196]
       [Scan RS (ms):  0.0  0.0  0.1  0.0  0.0  0.0  0.1  0.0  0.0  0.0 
  0.1  0.0
        Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
       [Object Copy (ms):  17.9  19.1  17.6  22.1  2.5  17.0  19.3  19.4 
  20.5  17.1  19.2  19.1
        Min: 2.5, Avg: 17.6, Max: 22.1, Diff: 19.5, Sum: 210.9]
       [Termination (ms):  35.7  35.7  35.7  31.1  32.0  35.7  35.7 
35.7  0.0  35.7  35.7  35.7
        Min: 0.0, Avg: 32.1, Max: 35.7, Diff: 35.7, Sum: 384.6]
          [Termination Attempts:  78  1  57  1  1  70  60  59  1  62  71  66
           Min: 1, Avg: 43.9, Max: 78, Diff: 77, Sum: 527]
       [GC Worker Other (ms):  0.0  0.1  0.0  0.0  0.1  0.0  0.1  0.1 
0.0  0.1  0.0  0.1
        Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.6]
       [GC Worker Total (ms):  119.5  119.6  119.5  119.4  119.4  119.4 
  119.4  119.4  119.3  119.3  119.2  119.1
        Min: 119.1, Avg: 119.4, Max: 119.6, Diff: 0.4, Sum: 1432.5]
       [GC Worker End (ms):  21526167.9  21526168.0  21526168.0 
21526167.9  21526168.0  21526167.9  21526168.0  21526168.0  21526167.9 
21526168.0  21526167.9  21526168.0
        Min: 21526167.9, Avg: 21526168.0, Max: 21526168.0, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.2 ms]
    [Other: 4.1 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 2.7 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.2 ms]
    [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 
8282.9M(14.6G)->7659.5M(14.6G)]
  [Times: user=1.24 sys=0.00, real=0.12 secs]
2013-10-28T16:00:10.519+0100: 21527.407: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:    8936336 bytes,    8936336 total
- age   2:    3011208 bytes,   11947544 total
- age   3:    9009224 bytes,   20956768 total
- age   4:   19393152 bytes,   40349920 total
- age   5:    9924104 bytes,   50274024 total
  21527.407: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 35510, predicted base time: 76.50 ms, remaining time: 
223.50 ms, target pause time: 300.00 ms]
  21527.407: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 12.59 ms]
  21527.407: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause 
time: 89.09 ms, target pause time: 300.00 ms]
, 0.1681470 secs]
    [Parallel Time: 154.5 ms, GC Workers: 12]
       [GC Worker Start (ms):  21527407.6  21527407.6  21527407.7 
21527407.7  21527407.7  21527407.7  21527407.7  21527407.8  21527407.8 
21527407.8  21527407.8  21527407.8
        Min: 21527407.6, Avg: 21527407.7, Max: 21527407.8, Diff: 0.2]
       [Ext Root Scanning (ms):  65.0  134.3  48.8  93.4  49.3  55.4 
67.5  48.0  47.8  48.3  67.3  51.3
        Min: 47.8, Avg: 64.7, Max: 134.3, Diff: 86.6, Sum: 776.3]
       [Update RS (ms):  0.0  0.0  12.9  0.0  13.1  6.4  0.0  13.0  13.2 
  12.7  0.0  10.0
        Min: 0.0, Avg: 6.8, Max: 13.2, Diff: 13.2, Sum: 81.4]
          [Processed Buffers:  0  0  31  0  26  28  0  41  39  42  0  54
           Min: 0, Avg: 21.8, Max: 54, Diff: 54, Sum: 261]
       [Scan RS (ms):  0.0  0.0  0.0  0.0  0.1  0.1  0.0  0.1  0.0  0.1 
  0.0  0.0
        Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
       [Object Copy (ms):  16.7  19.9  19.9  2.6  19.1  19.7  14.0  20.5 
  20.5  20.4  14.1  20.2
        Min: 2.6, Avg: 17.3, Max: 20.5, Diff: 18.0, Sum: 207.7]
       [Termination (ms):  72.6  0.0  72.6  58.3  72.6  72.6  72.6  72.6 
  72.6  72.6  72.7  72.6
        Min: 0.0, Avg: 65.4, Max: 72.7, Diff: 72.7, Sum: 784.6]
          [Termination Attempts:  12  1  15  1  12  16  12  13  9  1  12  14
           Min: 1, Avg: 9.8, Max: 16, Diff: 15, Sum: 118]
       [GC Worker Other (ms):  0.1  0.0  0.1  0.1  0.0  0.1  0.1  0.1 
0.1  0.1  0.1  0.1
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 1.0]
       [GC Worker Total (ms):  154.5  154.3  154.4  154.3  154.2  154.3 
  154.3  154.2  154.2  154.2  154.2  154.2
        Min: 154.2, Avg: 154.3, Max: 154.5, Diff: 0.3, Sum: 1851.4]
       [GC Worker End (ms):  21527562.0  21527561.9  21527562.0 
21527562.0  21527561.9  21527562.0  21527562.0  21527562.0  21527562.0 
21527562.0  21527562.0  21527562.0
        Min: 21527561.9, Avg: 21527562.0, Max: 21527562.0, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.2 ms]
    [Other: 13.4 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 11.9 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.2 ms]
    [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 
8307.5M(14.6G)->7675.9M(14.6G)]
  [Times: user=1.66 sys=0.00, real=0.17 secs]
2013-10-28T16:00:11.861+0100: 21528.749: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 6 (max 15)
- age   1:    8421648 bytes,    8421648 total
- age   2:    7620344 bytes,   16041992 total
- age   3:    2522808 bytes,   18564800 total
- age   4:    7182464 bytes,   25747264 total
- age   5:   18835480 bytes,   44582744 total
- age   6:    9228976 bytes,   53811720 total
  21528.749: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 39666, predicted base time: 81.53 ms, remaining time: 
218.47 ms, target pause time: 300.00 ms]
  21528.749: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 17.48 ms]
  21528.749: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause 
time: 99.00 ms, target pause time: 300.00 ms]
, 0.1418840 secs]
    [Parallel Time: 128.3 ms, GC Workers: 12]
       [GC Worker Start (ms):  21528749.7  21528749.7  21528749.7 
21528749.8  21528749.8  21528749.8  21528749.9  21528749.9  21528749.9 
21528749.9  21528749.9  21528750.8
        Min: 21528749.7, Avg: 21528749.9, Max: 21528750.8, Diff: 1.1]
       [Ext Root Scanning (ms):  51.1  52.6  67.6  74.4  70.3  67.6 
67.7  67.8  99.4  62.3  62.7  66.5
        Min: 51.1, Avg: 67.5, Max: 99.4, Diff: 48.2, Sum: 810.0]
       [Update RS (ms):  23.1  20.8  3.2  0.0  3.1  4.2  4.8  4.5  0.0 
10.3  12.5  3.6
        Min: 0.0, Avg: 7.5, Max: 23.1, Diff: 23.1, Sum: 90.1]
          [Processed Buffers:  50  47  32  0  17  21  26  26  0  28  28  18
           Min: 0, Avg: 24.4, Max: 50, Diff: 50, Sum: 293]
       [Scan RS (ms):  0.0  0.1  0.0  0.0  18.8  0.0  0.0  0.1  0.0  0.0 
  0.0  0.1
        Min: 0.0, Avg: 1.6, Max: 18.8, Diff: 18.8, Sum: 19.2]
       [Object Copy (ms):  20.6  21.3  24.0  20.4  2.7  23.0  22.2  22.3 
  28.3  24.6  41.7  23.7
        Min: 2.7, Avg: 22.9, Max: 41.7, Diff: 38.9, Sum: 274.8]
       [Termination (ms):  33.1  33.1  33.1  33.1  33.0  33.1  33.1 
33.1  0.0  30.5  10.8  33.1
        Min: 0.0, Avg: 28.2, Max: 33.1, Diff: 33.1, Sum: 338.8]
          [Termination Attempts:  1  11  8  8  1  5  5  10  1  1  1  6
           Min: 1, Avg: 4.8, Max: 11, Diff: 10, Sum: 58]
       [GC Worker Other (ms):  0.1  0.1  0.1  0.0  0.1  0.1  0.1  0.1 
0.0  0.1  0.0  0.1
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.7]
       [GC Worker Total (ms):  128.0  128.0  128.0  127.9  127.9  127.9 
  127.9  127.8  127.8  127.8  127.7  126.9
        Min: 126.9, Avg: 127.8, Max: 128.0, Diff: 1.1, Sum: 1533.6]
       [GC Worker End (ms):  21528877.7  21528877.7  21528877.7 
21528877.7  21528877.7  21528877.7  21528877.7  21528877.7  21528877.6 
21528877.7  21528877.6  21528877.7
        Min: 21528877.6, Avg: 21528877.7, Max: 21528877.7, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.2 ms]
    [Other: 13.4 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 11.8 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.2 ms]
    [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 
8323.9M(14.6G)->7724.2M(14.6G)]
  [Times: user=1.36 sys=0.00, real=0.14 secs]
2013-10-28T16:00:13.625+0100: 21530.513: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 6 (max 15)
- age   1:   10421320 bytes,   10421320 total
- age   2:    6261944 bytes,   16683264 total
- age   3:    7196032 bytes,   23879296 total
- age   4:    2495936 bytes,   26375232 total
- age   5:    5485976 bytes,   31861208 total
- age   6:   18536368 bytes,   50397576 total
  21530.513: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 52102, predicted base time: 87.75 ms, remaining time: 
212.25 ms, target pause time: 300.00 ms]
  21530.513: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 11.64 ms]
  21530.513: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause 
time: 99.40 ms, target pause time: 300.00 ms]
, 0.1134930 secs]
    [Parallel Time: 110.3 ms, GC Workers: 12]
       [GC Worker Start (ms):  21530513.5  21530513.6  21530513.6 
21530513.6  21530513.6  21530513.6  21530513.7  21530513.7  21530513.7 
21530513.7  21530513.7  21530514.8
        Min: 21530513.5, Avg: 21530513.7, Max: 21530514.8, Diff: 1.2]
       [Ext Root Scanning (ms):  47.1  90.1  65.0  28.2  59.1  56.9 
66.6  47.2  64.7  60.2  87.9  47.1
        Min: 28.2, Avg: 60.0, Max: 90.1, Diff: 61.9, Sum: 720.1]
       [Update RS (ms):  21.5  0.0  3.0  11.2  9.5  13.9  2.1  21.4  2.6 
  9.1  0.0  20.2
        Min: 0.0, Avg: 9.6, Max: 21.5, Diff: 21.5, Sum: 114.6]
          [Processed Buffers:  54  0  22  42  33  36  10  43  26  26  0  40
           Min: 0, Avg: 27.7, Max: 54, Diff: 54, Sum: 332]
       [Scan RS (ms):  0.0  0.0  0.0  0.1  0.0  0.0  0.0  0.1  0.1  0.1 
  0.0  0.0
        Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.4]
       [Object Copy (ms):  18.0  20.0  18.5  55.1  17.9  15.7  17.8 
17.8  19.1  17.0  2.6  18.1
        Min: 2.6, Avg: 19.8, Max: 55.1, Diff: 52.6, Sum: 237.7]
       [Termination (ms):  23.5  0.0  23.6  15.5  23.6  23.5  23.6  23.5 
  23.6  23.5  19.6  23.5
        Min: 0.0, Avg: 20.6, Max: 23.6, Diff: 23.6, Sum: 247.0]
          [Termination Attempts:  6  1  6  1  7  2  2  4  2  1  1  1
           Min: 1, Avg: 2.8, Max: 7, Diff: 6, Sum: 34]
       [GC Worker Other (ms):  0.1  0.0  0.1  0.1  0.1  0.1  0.1  0.1 
0.1  0.1  0.1  0.1
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
       [GC Worker Total (ms):  110.2  110.2  110.2  110.2  110.2  110.1 
  110.1  110.1  110.1  110.1  110.1  109.0
        Min: 109.0, Avg: 110.1, Max: 110.2, Diff: 1.2, Sum: 1320.7]
       [GC Worker End (ms):  21530623.8  21530623.7  21530623.8 
21530623.8  21530623.8  21530623.8  21530623.8  21530623.8  21530623.8 
21530623.8  21530623.8  21530623.8
        Min: 21530623.7, Avg: 21530623.8, Max: 21530623.8, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.1 ms]
    [Other: 3.0 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 1.5 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.2 ms]
    [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 
8372.2M(14.6G)->7774.0M(14.6G)]
  [Times: user=1.15 sys=0.02, real=0.12 secs]
2013-10-28T16:00:19.956+0100: 21536.844: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:    4026408 bytes,    4026408 total
- age   2:    8853712 bytes,   12880120 total
- age   3:    5294968 bytes,   18175088 total
- age   4:    6427000 bytes,   24602088 total
- age   5:    2472488 bytes,   27074576 total
- age   6:    5429760 bytes,   32504336 total
  21536.844: [G1Ergonomics (CSet Construction) start choosing CSet, 
_pending_cards: 76487, predicted base time: 89.50 ms, remaining time: 
210.50 ms, target pause time: 300.00 ms]
  21536.844: [G1Ergonomics (CSet Construction) add young regions to 
CSet, eden: 81 regions, survivors: 12 regions, predicted young region 
time: 10.64 ms]
  21536.844: [G1Ergonomics (CSet Construction) finish choosing CSet, 
eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause 
time: 100.15 ms, target pause time: 300.00 ms]
, 0.1148320 secs]
    [Parallel Time: 111.4 ms, GC Workers: 12]
       [GC Worker Start (ms):  21536844.7  21536844.7  21536844.7 
21536844.8  21536844.8  21536844.9  21536844.9  21536844.9  21536845.0 
21536845.0  21536845.0  21536845.0
        Min: 21536844.7, Avg: 21536844.9, Max: 21536845.0, Diff: 0.3]
       [Ext Root Scanning (ms):  57.9  89.6  48.0  57.9  65.5  58.2 
61.3  58.4  56.6  43.4  61.4  60.8
        Min: 43.4, Avg: 59.9, Max: 89.6, Diff: 46.2, Sum: 719.1]
       [Update RS (ms):  14.0  0.0  24.7  14.0  6.6  13.6  8.8  13.6 
15.1  27.7  9.0  9.2
        Min: 0.0, Avg: 13.0, Max: 27.7, Diff: 27.7, Sum: 156.2]
          [Processed Buffers:  41  0  73  46  38  55  55  48  61  67  33  43
           Min: 0, Avg: 46.7, Max: 73, Diff: 73, Sum: 560]
       [Scan RS (ms):  0.0  0.0  0.0  0.1  0.1  0.0  0.1  0.0  0.0  0.1 
  0.0  0.1
        Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
       [Object Copy (ms):  14.2  21.4  13.4  14.1  13.8  14.1  15.7 
13.9  14.1  14.7  15.5  15.7
        Min: 13.4, Avg: 15.0, Max: 21.4, Diff: 8.0, Sum: 180.3]
       [Termination (ms):  24.9  0.0  24.9  24.9  24.9  24.9  24.9  24.9 
  24.9  24.9  24.9  24.9
        Min: 0.0, Avg: 22.9, Max: 24.9, Diff: 24.9, Sum: 274.2]
          [Termination Attempts:  51  1  51  49  44  50  52  52  53  1 
56  46
           Min: 1, Avg: 42.2, Max: 56, Diff: 55, Sum: 506]
       [GC Worker Other (ms):  0.1  0.0  0.1  0.1  0.1  0.1  0.1  0.1 
0.0  0.1  0.1  0.1
        Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
       [GC Worker Total (ms):  111.1  111.0  111.1  111.0  111.0  110.9 
  110.9  110.9  110.8  110.8  110.8  110.8
        Min: 110.8, Avg: 110.9, Max: 111.1, Diff: 0.3, Sum: 1331.2]
       [GC Worker End (ms):  21536955.8  21536955.7  21536955.8 
21536955.8  21536955.8  21536955.8  21536955.8  21536955.8  21536955.8 
21536955.8  21536955.8  21536955.8
        Min: 21536955.7, Avg: 21536955.8, Max: 21536955.8, Diff: 0.1]
    [Code Root Fixup: 0.0 ms]
    [Clear CT: 0.1 ms]
    [Other: 3.3 ms]
       [Choose CSet: 0.0 ms]
       [Ref Proc: 1.6 ms]
       [Ref Enq: 0.1 ms]
       [Free CSet: 0.2 ms]
    [Eden: 648.0M(648.0M)->0.0B(6368.0M) Survivors: 96.0M->88.0M Heap: 
8422.0M(14.6G)->7768.2M(14.6G)]
  [Times: user=1.20 sys=0.01, real=0.12 secs]


-------------- next part --------------
2013-10-28T15:58:33.923+0100: 21430.811: [GC pause (young) (initial-mark)
Desired survivor size 276824064 bytes, new threshold 7 (max 15)
- age   1:   55460056 bytes,   55460056 total
- age   2:   79721520 bytes,  135181576 total
- age   3:   53921760 bytes,  189103336 total
- age   4:   24968016 bytes,  214071352 total
- age   5:   42768296 bytes,  256839648 total
- age   6:   15861352 bytes,  272701000 total
- age   7:   28221288 bytes,  300922288 total
 21430.811: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 200850, predicted base time: 103.40 ms, remaining time: 196.60 ms, target pause time: 300.00 ms]
 21430.811: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 473 regions, survivors: 51 regions, predicted young region time: 76.73 ms]
 21430.811: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 473 regions, survivors: 51 regions, old: 0 regions, predicted pause time: 180.13 ms, target pause time: 300.00 ms]
, 0.2397300 secs]
   [Parallel Time: 232.7 ms, GC Workers: 12]
      [GC Worker Start (ms):  21430811.5  21430811.6  21430811.7  21430811.8  21430811.8  21430811.8  21430811.9  21430811.9  21430811.9  21430812.0  21430812.0  21430812.0
       Min: 21430811.5, Avg: 21430811.8, Max: 21430812.0, Diff: 0.4]
      [Ext Root Scanning (ms):  45.3  46.2  103.6  46.3  46.8  45.7  46.4  63.9  66.3  45.9  47.4  59.8
       Min: 45.3, Avg: 55.3, Max: 103.6, Diff: 58.3, Sum: 663.5]
      [Update RS (ms):  46.4  46.2  0.0  46.5  46.0  46.8  46.7  25.2  26.1  46.5  45.8  29.8
       Min: 0.0, Avg: 37.7, Max: 46.8, Diff: 46.8, Sum: 451.9]
         [Processed Buffers:  109  107  0  99  114  95  109  92  74  108  107  112
          Min: 0, Avg: 93.8, Max: 114, Diff: 114, Sum: 1126]
      [Scan RS (ms):  0.3  0.3  0.1  0.1  0.2  0.3  0.0  0.3  0.2  0.5  0.4  0.2
       Min: 0.0, Avg: 0.2, Max: 0.5, Diff: 0.4, Sum: 2.9]
      [Object Copy (ms):  102.4  101.8  128.5  101.3  101.3  101.4  101.0  104.7  101.5  101.2  100.4  104.2
       Min: 100.4, Avg: 104.1, Max: 128.5, Diff: 28.1, Sum: 1249.6]
      [Termination (ms):  37.9  37.9  0.0  37.9  37.9  37.9  37.9  37.9  37.9  37.9  37.9  37.9
       Min: 0.0, Avg: 34.7, Max: 37.9, Diff: 37.9, Sum: 416.5]
         [Termination Attempts:  36  45  1  37  33  43  1  35  33  32  36  23
          Min: 1, Avg: 29.6, Max: 45, Diff: 44, Sum: 355]
      [GC Worker Other (ms):  0.1  0.1  0.0  0.0  0.1  0.1  0.1  0.0  0.0  0.1  0.1  0.1
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.6]
      [GC Worker Total (ms):  232.4  232.3  232.2  232.1  232.1  232.1  232.1  232.0  232.0  232.0  231.9  231.9
       Min: 231.9, Avg: 232.1, Max: 232.4, Diff: 0.5, Sum: 2785.1]
      [GC Worker End (ms):  21431043.9  21431043.9  21431043.9  21431043.9  21431043.9  21431043.9  21431043.9  21431043.9  21431043.9  21431043.9  21431043.9  21431043.9
       Min: 21431043.9, Avg: 21431043.9, Max: 21431043.9, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.7 ms]
   [Other: 6.3 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 3.4 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.6 ms]
   [Eden: 3784.0M(3784.0M)->0.0B(3728.0M) Survivors: 408.0M->408.0M Heap: 13.5G(14.6G)->10096.0M(14.6G)]
 [Times: user=2.66 sys=0.02, real=0.24 secs] 
2013-10-28T15:58:34.163+0100: 21431.051: [GC concurrent-root-region-scan-start]
2013-10-28T15:58:34.214+0100: 21431.101: [GC concurrent-root-region-scan-end, 0.0506100 secs]
2013-10-28T15:58:34.214+0100: 21431.101: [GC concurrent-mark-start]
2013-10-28T15:58:35.986+0100: 21432.874: [GC concurrent-mark-end, 1.7727150 secs]
2013-10-28T15:58:35.994+0100: 21432.881: [GC remark 2013-10-28T15:58:36.008+0100: 21432.896: [GC ref-proc, 0.1192260 secs], 0.2022820 secs]
 [Times: user=1.47 sys=0.00, real=0.20 secs] 
2013-10-28T15:58:36.198+0100: 21433.086: [GC cleanup 10G->9836M(14G), 0.0347900 secs]
 [Times: user=0.28 sys=0.00, real=0.03 secs] 
2013-10-28T15:58:36.234+0100: 21433.121: [GC concurrent-cleanup-start]
2013-10-28T15:58:36.234+0100: 21433.122: [GC concurrent-cleanup-end, 0.0004450 secs]
2013-10-28T15:59:19.111+0100: 21475.998: [GC pause (young)
Desired survivor size 272629760 bytes, new threshold 6 (max 15)
- age   1:   63592160 bytes,   63592160 total
- age   2:   38460008 bytes,  102052168 total
- age   3:   63355736 bytes,  165407904 total
- age   4:   44680008 bytes,  210087912 total
- age   5:   22742184 bytes,  232830096 total
- age   6:   42023016 bytes,  274853112 total
- age   7:   15800936 bytes,  290654048 total
 21475.999: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 180993, predicted base time: 98.72 ms, remaining time: 201.28 ms, target pause time: 300.00 ms]
 21475.999: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 466 regions, survivors: 51 regions, predicted young region time: 80.67 ms]
 21475.999: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 466 regions, survivors: 51 regions, old: 0 regions, predicted pause time: 179.39 ms, target pause time: 300.00 ms]
 21476.176: [G1Ergonomics (Mixed GCs) start mixed GCs, reason: candidate old regions available, candidate old regions: 635 regions, reclaimable: 3505373264 bytes (22.29 %), threshold: 5.00 %]
, 0.1775420 secs]
   [Parallel Time: 171.9 ms, GC Workers: 12]
      [GC Worker Start (ms):  21475999.2  21475999.3  21475999.3  21475999.3  21475999.4  21475999.4  21475999.4  21475999.5  21475999.5  21475999.5  21475999.5  21475999.5
       Min: 21475999.2, Avg: 21475999.4, Max: 21475999.5, Diff: 0.3]
      [Ext Root Scanning (ms):  100.6  45.5  64.1  45.1  45.4  44.9  59.1  46.0  45.5  44.7  44.8  63.3
       Min: 44.7, Avg: 54.1, Max: 100.6, Diff: 55.9, Sum: 649.0]
      [Update RS (ms):  0.0  44.5  24.5  44.8  44.6  45.0  29.6  45.0  44.5  44.8  44.9  25.2
       Min: 0.0, Avg: 36.5, Max: 45.0, Diff: 45.0, Sum: 437.4]
         [Processed Buffers:  0  125  71  113  123  117  89  97  100  118  100  54
          Min: 0, Avg: 92.2, Max: 125, Diff: 125, Sum: 1107]
      [Scan RS (ms):  0.1  0.1  0.3  0.2  0.1  0.2  0.4  0.2  0.3  0.5  0.4  0.1
       Min: 0.1, Avg: 0.2, Max: 0.5, Diff: 0.4, Sum: 2.8]
      [Object Copy (ms):  70.7  81.3  82.4  81.2  81.0  81.2  82.1  79.9  80.9  81.1  81.0  82.5
       Min: 70.7, Avg: 80.4, Max: 82.5, Diff: 11.8, Sum: 965.4]
      [Termination (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Termination Attempts:  3  1  4  5  5  3  4  3  4  5  2  2
          Min: 1, Avg: 3.4, Max: 5, Diff: 4, Sum: 41]
      [GC Worker Other (ms):  0.3  0.1  0.1  0.1  0.2  0.1  0.2  0.0  0.0  0.1  0.2  0.1
       Min: 0.0, Avg: 0.1, Max: 0.3, Diff: 0.2, Sum: 1.5]
      [GC Worker Total (ms):  171.7  171.4  171.4  171.4  171.5  171.4  171.4  171.2  171.2  171.2  171.3  171.2
       Min: 171.2, Avg: 171.3, Max: 171.7, Diff: 0.5, Sum: 2056.2]
      [GC Worker End (ms):  21476170.9  21476170.7  21476170.7  21476170.7  21476170.8  21476170.8  21476170.9  21476170.7  21476170.7  21476170.7  21476170.8  21476170.8
       Min: 21476170.7, Avg: 21476170.8, Max: 21476170.9, Diff: 0.2]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.8 ms]
   [Other: 4.8 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 2.0 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.6 ms]
   [Eden: 3728.0M(3728.0M)->0.0B(360.0M) Survivors: 408.0M->384.0M Heap: 12.9G(14.6G)->9559.3M(14.6G)]
 [Times: user=2.07 sys=0.00, real=0.18 secs] 
2013-10-28T15:59:22.778+0100: 21479.666: [GC pause (mixed)
Desired survivor size 50331648 bytes, new threshold 1 (max 15)
- age   1:   95113344 bytes,   95113344 total
- age   2:   33760400 bytes,  128873744 total
- age   3:   33282608 bytes,  162156352 total
- age   4:   45404280 bytes,  207560632 total
- age   5:   36638688 bytes,  244199320 total
- age   6:   21839560 bytes,  266038880 total
 21479.666: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 127727, predicted base time: 87.54 ms, remaining time: 212.46 ms, target pause time: 300.00 ms]
 21479.666: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 45 regions, survivors: 48 regions, predicted young region time: 56.91 ms]
 21479.667: [G1Ergonomics (CSet Construction) finish adding old regions to CSet, reason: old CSet region num reached max, old: 188 regions, max: 188 regions]
 21479.667: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 45 regions, survivors: 48 regions, old: 188 regions, predicted pause time: 217.53 ms, target pause time: 300.00 ms]
 21479.921: [G1Ergonomics (Mixed GCs) continue mixed GCs, reason: candidate old regions available, candidate old regions: 447 regions, reclaimable: 2132693056 bytes (13.56 %), threshold: 5.00 %]
, 0.2550780 secs]
   [Parallel Time: 243.3 ms, GC Workers: 12]
      [GC Worker Start (ms):  21479667.1  21479667.1  21479667.1  21479667.2  21479667.2  21479667.2  21479667.3  21479667.3  21479667.3  21479667.3  21479667.4  21479667.4
       Min: 21479667.1, Avg: 21479667.3, Max: 21479667.4, Diff: 0.3]
      [Ext Root Scanning (ms):  45.6  63.8  59.3  45.9  46.0  46.9  46.5  46.0  45.6  45.2  89.0  63.4
       Min: 45.2, Avg: 53.6, Max: 89.0, Diff: 43.8, Sum: 643.3]
      [Update RS (ms):  29.6  10.2  14.7  29.4  28.9  29.5  28.3  28.9  29.3  29.9  0.0  10.1
       Min: 0.0, Avg: 22.4, Max: 29.9, Diff: 29.9, Sum: 268.8]
         [Processed Buffers:  69  32  57  76  54  67  86  69  74  75  0  26
          Min: 0, Avg: 57.1, Max: 86, Diff: 86, Sum: 685]
      [Scan RS (ms):  39.4  39.5  39.7  40.1  39.6  39.8  39.7  39.5  40.2  39.5  5.5  39.6
       Min: 5.5, Avg: 36.8, Max: 40.2, Diff: 34.7, Sum: 442.0]
      [Object Copy (ms):  128.6  129.5  129.3  127.7  128.4  126.8  128.4  128.4  127.8  128.3  148.3  129.7
       Min: 126.8, Avg: 130.1, Max: 148.3, Diff: 21.5, Sum: 1561.3]
      [Termination (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Termination Attempts:  1  4  13  12  7  8  8  7  2  8  7  8
          Min: 1, Avg: 7.1, Max: 13, Diff: 12, Sum: 85]
      [GC Worker Other (ms):  0.1  0.1  0.1  0.0  0.1  0.1  0.1  0.1  0.1  0.1  0.1  0.1
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 1.0]
      [GC Worker Total (ms):  243.2  243.2  243.2  243.1  243.1  243.0  243.0  243.0  243.0  243.0  242.9  242.9
       Min: 242.9, Avg: 243.0, Max: 243.2, Diff: 0.4, Sum: 2916.6]
      [GC Worker End (ms):  21479910.3  21479910.3  21479910.3  21479910.3  21479910.3  21479910.3  21479910.3  21479910.3  21479910.3  21479910.3  21479910.2  21479910.3
       Min: 21479910.2, Avg: 21479910.3, Max: 21479910.3, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 2.0 ms]
   [Other: 9.8 ms]
      [Choose CSet: 0.5 ms]
      [Ref Proc: 2.9 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 1.6 ms]
   [Eden: 360.0M(360.0M)->0.0B(648.0M) Survivors: 384.0M->96.0M Heap: 9919.3M(14.6G)->8419.4M(14.6G)]
 [Times: user=2.77 sys=0.00, real=0.25 secs] 
2013-10-28T15:59:30.652+0100: 21487.540: [GC pause (mixed)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:    7901552 bytes,    7901552 total
 21487.540: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 218925, predicted base time: 105.38 ms, remaining time: 194.62 ms, target pause time: 300.00 ms]
 21487.540: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 23.27 ms]
 21487.541: [G1Ergonomics (CSet Construction) finish adding old regions to CSet, reason: predicted time is too high, predicted time: 1.33 ms, remaining time: 1.08 ms, old: 182 regions, min: 80 regions]
 21487.541: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 182 regions, predicted pause time: 298.92 ms, target pause time: 300.00 ms]
 21487.843: [G1Ergonomics (Mixed GCs) continue mixed GCs, reason: candidate old regions available, candidate old regions: 265 regions, reclaimable: 1054790352 bytes (6.71 %), threshold: 5.00 %]
, 0.3030120 secs]
   [Parallel Time: 290.2 ms, GC Workers: 12]
      [GC Worker Start (ms):  21487541.6  21487541.6  21487541.6  21487541.8  21487541.8  21487541.8  21487541.8  21487541.9  21487541.9  21487541.9  21487541.9  21487541.9
       Min: 21487541.6, Avg: 21487541.8, Max: 21487541.9, Diff: 0.4]
      [Ext Root Scanning (ms):  46.3  45.6  47.1  65.1  46.3  46.1  59.6  46.6  45.4  64.4  97.2  45.8
       Min: 45.4, Avg: 54.6, Max: 97.2, Diff: 51.8, Sum: 655.6]
      [Update RS (ms):  55.1  55.4  55.7  35.0  54.8  54.8  40.6  54.1  55.5  35.2  0.0  54.9
       Min: 0.0, Avg: 45.9, Max: 55.7, Diff: 55.7, Sum: 551.1]
         [Processed Buffers:  95  87  102  72  102  107  104  81  105  93  0  116
          Min: 0, Avg: 88.7, Max: 116, Diff: 116, Sum: 1064]
      [Scan RS (ms):  36.6  36.8  36.3  36.4  36.6  36.6  36.4  36.6  36.7  36.6  16.9  36.9
       Min: 16.9, Avg: 35.0, Max: 36.9, Diff: 20.0, Sum: 419.4]
      [Object Copy (ms):  151.9  151.9  150.7  153.0  151.8  152.2  153.0  152.3  151.9  153.3  175.4  151.9
       Min: 150.7, Avg: 154.1, Max: 175.4, Diff: 24.7, Sum: 1849.2]
      [Termination (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Termination Attempts:  1  1  2  2  1  2  1  2  2  1  1  1
          Min: 1, Avg: 1.4, Max: 2, Diff: 1, Sum: 17]
      [GC Worker Other (ms):  0.1  0.1  0.1  0.0  0.0  0.0  0.1  0.0  0.1  0.1  0.1  0.1
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
      [GC Worker Total (ms):  290.0  289.9  289.8  289.7  289.7  289.6  289.7  289.6  289.6  289.5  289.6  289.5
       Min: 289.5, Avg: 289.7, Max: 290.0, Diff: 0.5, Sum: 3476.2]
      [GC Worker End (ms):  21487831.6  21487831.5  21487831.5  21487831.4  21487831.5  21487831.4  21487831.5  21487831.4  21487831.5  21487831.5  21487831.5  21487831.5
       Min: 21487831.4, Avg: 21487831.5, Max: 21487831.6, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 2.4 ms]
   [Other: 10.4 ms]
      [Choose CSet: 0.9 ms]
      [Ref Proc: 1.8 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 2.1 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 9067.4M(14.6G)->7480.0M(14.6G)]
 [Times: user=3.51 sys=0.00, real=0.30 secs] 
2013-10-28T15:59:38.671+0100: 21495.559: [GC pause (mixed)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:   24399800 bytes,   24399800 total
- age   2:    4322520 bytes,   28722320 total
 21495.559: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 199259, predicted base time: 103.72 ms, remaining time: 196.28 ms, target pause time: 300.00 ms]
 21495.559: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 24.30 ms]
 21495.560: [G1Ergonomics (CSet Construction) finish adding old regions to CSet, reason: reclaimable percentage not over threshold, old: 62 regions, max: 188 regions, reclaimable: 784279232 bytes (4.99 %), threshold: 5.00 %]
 21495.560: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 62 regions, predicted pause time: 222.80 ms, target pause time: 300.00 ms]
 21495.811: [G1Ergonomics (Mixed GCs) do not continue mixed GCs, reason: reclaimable percentage not over threshold, candidate old regions: 203 regions, reclaimable: 784279232 bytes (4.99 %), threshold: 5.00 %]
, 0.2522200 secs]
   [Parallel Time: 241.2 ms, GC Workers: 12]
      [GC Worker Start (ms):  21495560.3  21495560.4  21495560.4  21495560.4  21495560.4  21495560.5  21495560.5  21495560.5  21495560.5  21495560.5  21495560.6  21495560.6
       Min: 21495560.3, Avg: 21495560.5, Max: 21495560.6, Diff: 0.3]
      [Ext Root Scanning (ms):  64.9  45.7  64.9  45.9  45.6  47.1  99.2  59.5  45.4  45.5  45.2  46.0
       Min: 45.2, Avg: 54.6, Max: 99.2, Diff: 54.0, Sum: 654.8]
      [Update RS (ms):  42.9  63.9  43.1  63.8  63.8  63.6  0.0  48.9  63.8  63.6  64.1  63.0
       Min: 0.0, Avg: 53.7, Max: 64.1, Diff: 64.1, Sum: 644.4]
         [Processed Buffers:  70  97  93  92  108  97  0  97  102  100  104  96
          Min: 0, Avg: 88.0, Max: 108, Diff: 108, Sum: 1056]
      [Scan RS (ms):  34.9  35.0  34.9  34.6  34.8  34.9  16.6  34.8  34.8  34.8  34.8  35.0
       Min: 16.6, Avg: 33.3, Max: 35.0, Diff: 18.5, Sum: 400.0]
      [Object Copy (ms):  98.3  96.2  97.9  96.6  96.6  95.2  125.0  97.5  96.8  96.7  96.6  96.7
       Min: 95.2, Avg: 99.2, Max: 125.0, Diff: 29.8, Sum: 1190.1]
      [Termination (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Termination Attempts:  11  1  10  8  4  6  9  7  5  1  6  12
          Min: 1, Avg: 6.7, Max: 12, Diff: 11, Sum: 80]
      [GC Worker Other (ms):  0.1  0.1  0.1  0.1  0.0  0.1  0.0  0.1  0.1  0.0  0.1  0.1
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
      [GC Worker Total (ms):  241.0  241.0  241.0  240.9  240.8  240.9  240.7  240.8  240.8  240.7  240.7  240.7
       Min: 240.7, Avg: 240.8, Max: 241.0, Diff: 0.3, Sum: 2890.2]
      [GC Worker End (ms):  21495801.3  21495801.3  21495801.3  21495801.3  21495801.3  21495801.3  21495801.3  21495801.3  21495801.3  21495801.3  21495801.3  21495801.3
       Min: 21495801.3, Avg: 21495801.3, Max: 21495801.3, Diff: 0.1]
   [Code Root Fixup: 0.3 ms]
   [Clear CT: 2.6 ms]
   [Other: 8.1 ms]
      [Choose CSet: 0.6 ms]
      [Ref Proc: 2.0 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 1.2 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 8128.0M(14.6G)->7263.3M(14.6G)]
 [Times: user=2.93 sys=0.00, real=0.25 secs] 
2013-10-28T15:59:44.685+0100: 21501.573: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:   26676824 bytes,   26676824 total
- age   2:   17917840 bytes,   44594664 total
- age   3:    3599704 bytes,   48194368 total
 21501.574: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 160602, predicted base time: 101.20 ms, remaining time: 198.80 ms, target pause time: 300.00 ms]
 21501.574: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 60.87 ms]
 21501.574: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause time: 162.08 ms, target pause time: 300.00 ms]
, 0.1277600 secs]
   [Parallel Time: 123.2 ms, GC Workers: 12]
      [GC Worker Start (ms):  21501573.9  21501574.0  21501574.1  21501574.1  21501574.1  21501574.1  21501574.2  21501574.3  21501574.3  21501574.3  21501574.3  21501574.3
       Min: 21501573.9, Avg: 21501574.2, Max: 21501574.3, Diff: 0.4]
      [Ext Root Scanning (ms):  46.0  45.5  58.9  100.0  63.9  64.1  45.7  45.2  45.4  45.2  45.3  44.8
       Min: 44.8, Avg: 54.2, Max: 100.0, Diff: 55.2, Sum: 650.1]
      [Update RS (ms):  51.6  52.3  38.6  0.0  32.2  31.9  51.4  52.0  52.1  51.9  51.7  52.0
       Min: 0.0, Avg: 43.1, Max: 52.3, Diff: 52.3, Sum: 517.8]
         [Processed Buffers:  77  72  73  0  69  56  79  88  78  73  88  80
          Min: 0, Avg: 69.4, Max: 88, Diff: 88, Sum: 833]
      [Scan RS (ms):  0.6  0.6  0.8  0.0  0.7  0.8  0.9  0.6  0.4  0.8  0.8  0.8
       Min: 0.0, Avg: 0.6, Max: 0.9, Diff: 0.9, Sum: 7.6]
      [Object Copy (ms):  20.1  19.9  19.9  22.9  21.2  21.3  20.0  20.2  20.0  20.2  20.2  20.3
       Min: 19.9, Avg: 20.5, Max: 22.9, Diff: 3.0, Sum: 246.2]
      [Termination (ms):  4.8  4.8  4.8  0.0  4.8  4.8  4.8  4.8  4.8  4.7  4.8  4.8
       Min: 0.0, Avg: 4.4, Max: 4.8, Diff: 4.8, Sum: 52.6]
         [Termination Attempts:  148  161  127  1  142  147  162  139  163  1  154  155
          Min: 1, Avg: 125.0, Max: 163, Diff: 162, Sum: 1500]
      [GC Worker Other (ms):  0.1  0.1  0.1  0.0  0.0  0.1  0.1  0.1  0.1  0.1  0.1  0.1
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.8]
      [GC Worker Total (ms):  123.2  123.1  123.0  123.0  122.9  122.9  122.9  122.8  122.8  122.8  122.8  122.8
       Min: 122.8, Avg: 122.9, Max: 123.2, Diff: 0.4, Sum: 1475.1]
      [GC Worker End (ms):  21501697.1  21501697.1  21501697.1  21501697.0  21501697.1  21501697.1  21501697.1  21501697.1  21501697.1  21501697.1  21501697.1  21501697.1
       Min: 21501697.0, Avg: 21501697.1, Max: 21501697.1, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.8 ms]
   [Other: 3.7 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 1.9 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 7911.3M(14.6G)->7293.7M(14.6G)]
 [Times: user=1.50 sys=0.00, real=0.13 secs] 
2013-10-28T15:59:51.136+0100: 21508.024: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 3 (max 15)
- age   1:   22020176 bytes,   22020176 total
- age   2:   20834232 bytes,   42854408 total
- age   3:   16616152 bytes,   59470560 total
- age   4:    3427912 bytes,   62898472 total
 21508.025: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 61972, predicted base time: 78.13 ms, remaining time: 221.87 ms, target pause time: 300.00 ms]
 21508.025: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 20.76 ms]
 21508.025: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause time: 98.89 ms, target pause time: 300.00 ms]
, 0.1165410 secs]
   [Parallel Time: 112.6 ms, GC Workers: 12]
      [GC Worker Start (ms):  21508025.1  21508025.1  21508025.2  21508025.2  21508025.3  21508025.3  21508025.4  21508025.4  21508025.4  21508025.4  21508025.5  21508025.5
       Min: 21508025.1, Avg: 21508025.3, Max: 21508025.5, Diff: 0.4]
      [Ext Root Scanning (ms):  46.1  45.4  45.6  64.0  44.9  47.0  45.8  58.7  91.3  64.7  45.6  45.2
       Min: 44.9, Avg: 53.7, Max: 91.3, Diff: 46.4, Sum: 644.3]
      [Update RS (ms):  16.0  16.6  16.6  0.0  16.8  15.1  16.2  2.2  0.0  0.0  16.1  16.7
       Min: 0.0, Avg: 11.0, Max: 16.8, Diff: 16.8, Sum: 132.3]
         [Processed Buffers:  41  67  65  0  49  68  51  28  0  0  58  61
          Min: 0, Avg: 40.7, Max: 68, Diff: 68, Sum: 488]
      [Scan RS (ms):  0.0  0.1  0.0  0.0  0.1  0.0  0.0  0.1  0.0  0.0  0.1  0.0
       Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
      [Object Copy (ms):  23.7  23.7  23.6  21.7  23.8  23.6  23.6  24.5  20.8  20.8  23.7  23.5
       Min: 20.8, Avg: 23.1, Max: 24.5, Diff: 3.8, Sum: 277.1]
      [Termination (ms):  26.6  26.6  26.6  26.6  26.6  26.6  26.6  26.6  0.0  26.6  26.6  26.6
       Min: 0.0, Avg: 24.4, Max: 26.6, Diff: 26.6, Sum: 292.4]
         [Termination Attempts:  42  1  48  47  49  44  49  49  1  51  47  50
          Min: 1, Avg: 39.8, Max: 51, Diff: 50, Sum: 478]
      [GC Worker Other (ms):  0.1  0.1  0.1  0.1  0.1  0.1  0.1  0.1  0.0  0.1  0.1  0.0
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.8]
      [GC Worker Total (ms):  112.5  112.5  112.4  112.4  112.3  112.3  112.2  112.2  112.1  112.1  112.1  112.1
       Min: 112.1, Avg: 112.3, Max: 112.5, Diff: 0.4, Sum: 1347.3]
      [GC Worker End (ms):  21508137.6  21508137.6  21508137.6  21508137.6  21508137.6  21508137.6  21508137.6  21508137.6  21508137.5  21508137.6  21508137.6  21508137.6
       Min: 21508137.5, Avg: 21508137.6, Max: 21508137.6, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 3.7 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 2.0 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 7941.7M(14.6G)->7391.1M(14.6G)]
 [Times: user=1.35 sys=0.01, real=0.11 secs] 
2013-10-28T15:59:58.723+0100: 21515.610: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 3 (max 15)
- age   1:   20444800 bytes,   20444800 total
- age   2:   14599736 bytes,   35044536 total
- age   3:   17794192 bytes,   52838728 total
 21515.611: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 90998, predicted base time: 82.82 ms, remaining time: 217.18 ms, target pause time: 300.00 ms]
 21515.611: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 19.51 ms]
 21515.611: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause time: 102.33 ms, target pause time: 300.00 ms]
, 0.1198280 secs]
   [Parallel Time: 116.2 ms, GC Workers: 12]
      [GC Worker Start (ms):  21515611.0  21515611.0  21515611.1  21515611.1  21515611.1  21515611.2  21515611.2  21515611.3  21515611.3  21515611.3  21515611.3  21515611.3
       Min: 21515611.0, Avg: 21515611.2, Max: 21515611.3, Diff: 0.4]
      [Ext Root Scanning (ms):  45.7  45.9  45.8  64.0  45.6  64.2  45.5  94.2  46.6  59.6  45.7  45.8
       Min: 45.5, Avg: 54.0, Max: 94.2, Diff: 48.7, Sum: 648.5]
      [Update RS (ms):  24.9  24.4  24.7  5.3  25.0  5.5  25.2  0.0  25.4  9.8  24.5  24.6
       Min: 0.0, Avg: 18.3, Max: 25.4, Diff: 25.4, Sum: 219.5]
         [Processed Buffers:  66  54  63  34  45  33  54  0  58  57  65  56
          Min: 0, Avg: 48.8, Max: 66, Diff: 66, Sum: 585]
      [Scan RS (ms):  0.0  0.2  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.1  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.2, Diff: 0.2, Sum: 0.4]
      [Object Copy (ms):  20.9  20.9  20.9  22.1  20.8  21.7  20.6  21.5  19.2  21.7  21.0  20.8
       Min: 19.2, Avg: 21.0, Max: 22.1, Diff: 2.9, Sum: 252.2]
      [Termination (ms):  24.5  24.5  24.5  24.5  24.5  24.5  24.5  0.0  24.5  24.5  24.5  24.5
       Min: 0.0, Avg: 22.5, Max: 24.5, Diff: 24.5, Sum: 269.8]
         [Termination Attempts:  1  1  1  1  1  1  1  1  1  1  1  1
          Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 12]
      [GC Worker Other (ms):  0.0  0.1  0.1  0.1  0.1  0.1  0.1  0.0  0.0  0.1  0.1  0.0
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
      [GC Worker Total (ms):  116.1  116.1  116.1  116.1  116.0  116.0  115.9  115.8  115.8  115.8  115.8  115.8
       Min: 115.8, Avg: 115.9, Max: 116.1, Diff: 0.4, Sum: 1391.3]
      [GC Worker End (ms):  21515727.1  21515727.1  21515727.1  21515727.1  21515727.1  21515727.1  21515727.1  21515727.0  21515727.1  21515727.1  21515727.1  21515727.1
       Min: 21515727.0, Avg: 21515727.1, Max: 21515727.1, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 3.5 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 1.8 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 8039.1M(14.6G)->7477.8M(14.6G)]
 [Times: user=1.39 sys=0.00, real=0.12 secs] 
2013-10-28T16:00:01.284+0100: 21518.172: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 3 (max 15)
- age   1:   22178080 bytes,   22178080 total
- age   2:   15771712 bytes,   37949792 total
- age   3:   12924848 bytes,   50874640 total
 21518.172: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 74257, predicted base time: 77.45 ms, remaining time: 222.55 ms, target pause time: 300.00 ms]
 21518.172: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 16.66 ms]
 21518.172: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause time: 94.12 ms, target pause time: 300.00 ms]
, 0.1202740 secs]
   [Parallel Time: 114.7 ms, GC Workers: 12]
      [GC Worker Start (ms):  21518172.6  21518172.7  21518172.7  21518172.7  21518172.8  21518172.8  21518172.8  21518172.9  21518173.0  21518173.0  21518173.0  21518173.0
       Min: 21518172.6, Avg: 21518172.8, Max: 21518173.0, Diff: 0.4]
      [Ext Root Scanning (ms):  61.8  46.5  46.0  45.1  45.3  45.2  45.4  45.9  59.6  47.8  92.0  64.5
       Min: 45.1, Avg: 53.8, Max: 92.0, Diff: 46.9, Sum: 645.1]
      [Update RS (ms):  2.4  18.7  20.2  20.8  19.9  19.9  34.4  19.4  4.5  16.9  0.0  0.6
       Min: 0.0, Avg: 14.8, Max: 34.4, Diff: 34.4, Sum: 177.8]
         [Processed Buffers:  32  53  43  51  70  47  19  46  33  46  0  1
          Min: 0, Avg: 36.8, Max: 70, Diff: 70, Sum: 441]
      [Scan RS (ms):  0.1  0.1  0.0  0.0  0.0  0.1  0.0  0.0  0.1  0.1  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
      [Object Copy (ms):  22.1  21.0  20.1  20.4  20.9  20.9  6.3  39.3  21.8  21.2  21.1  20.9
       Min: 6.3, Avg: 21.3, Max: 39.3, Diff: 33.0, Sum: 256.0]
      [Termination (ms):  27.1  27.1  27.1  27.1  27.1  27.1  27.1  8.6  28.2  27.1  0.0  27.1
       Min: 0.0, Avg: 23.4, Max: 28.2, Diff: 28.2, Sum: 280.6]
         [Termination Attempts:  23  17  15  16  18  17  14  1  17  14  1  14
          Min: 1, Avg: 13.9, Max: 23, Diff: 22, Sum: 167]
      [GC Worker Other (ms):  0.1  0.1  0.1  0.1  0.1  0.1  0.1  0.1  0.0  0.1  0.0  0.1
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
      [GC Worker Total (ms):  113.6  113.5  113.5  113.4  113.3  113.3  113.3  113.3  114.2  113.2  113.1  113.2
       Min: 113.1, Avg: 113.4, Max: 114.2, Diff: 1.1, Sum: 1360.9]
      [GC Worker End (ms):  21518286.2  21518286.1  21518286.2  21518286.2  21518286.2  21518286.2  21518286.2  21518286.2  21518287.1  21518286.2  21518286.1  21518286.2
       Min: 21518286.1, Avg: 21518286.2, Max: 21518287.1, Diff: 1.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 5.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 3.8 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 8125.8M(14.6G)->7548.1M(14.6G)]
 [Times: user=1.31 sys=0.00, real=0.12 secs] 
2013-10-28T16:00:05.597+0100: 21522.485: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:   16592056 bytes,   16592056 total
- age   2:   17463768 bytes,   34055824 total
- age   3:   15349624 bytes,   49405448 total
 21522.486: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 76409, predicted base time: 77.52 ms, remaining time: 222.48 ms, target pause time: 300.00 ms]
 21522.486: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 18.97 ms]
 21522.486: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause time: 96.49 ms, target pause time: 300.00 ms]
, 0.1174670 secs]
   [Parallel Time: 113.2 ms, GC Workers: 12]
      [GC Worker Start (ms):  21522485.8  21522485.9  21522485.9  21522486.0  21522486.1  21522486.2  21522486.2  21522486.2  21522486.2  21522486.2  21522486.3  21522486.3
       Min: 21522485.8, Avg: 21522486.1, Max: 21522486.3, Diff: 0.4]
      [Ext Root Scanning (ms):  45.3  91.8  46.0  46.9  63.4  58.7  45.1  63.1  45.3  46.3  45.7  48.3
       Min: 45.1, Avg: 53.8, Max: 91.8, Diff: 46.7, Sum: 645.9]
      [Update RS (ms):  20.4  0.0  19.4  19.7  0.8  6.0  19.9  0.8  19.9  18.8  19.6  17.1
       Min: 0.0, Avg: 13.5, Max: 20.4, Diff: 20.4, Sum: 162.4]
         [Processed Buffers:  57  0  68  73  8  33  55  2  48  62  61  52
          Min: 0, Avg: 43.2, Max: 73, Diff: 73, Sum: 519]
      [Scan RS (ms):  0.0  0.0  0.1  0.1  0.0  0.0  0.1  0.0  0.1  0.1  0.1  0.0
       Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
      [Object Copy (ms):  21.5  21.0  21.6  20.2  22.6  22.1  21.7  22.9  21.5  21.5  21.4  21.3
       Min: 20.2, Avg: 21.6, Max: 22.9, Diff: 2.7, Sum: 259.2]
      [Termination (ms):  25.7  0.0  25.7  25.7  25.7  25.7  25.7  25.7  25.7  25.7  25.7  25.7
       Min: 0.0, Avg: 23.6, Max: 25.7, Diff: 25.7, Sum: 283.0]
         [Termination Attempts:  19  1  13  16  14  9  17  18  15  20  1  16
          Min: 1, Avg: 13.2, Max: 20, Diff: 19, Sum: 159]
      [GC Worker Other (ms):  0.1  0.0  0.1  0.0  0.1  0.1  0.1  0.1  0.1  0.1  0.1  0.1
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 1.0]
      [GC Worker Total (ms):  112.9  112.8  112.8  112.7  112.6  112.6  112.6  112.6  112.6  112.6  112.5  112.5
       Min: 112.5, Avg: 112.7, Max: 112.9, Diff: 0.4, Sum: 1351.9]
      [GC Worker End (ms):  21522598.7  21522598.7  21522598.8  21522598.7  21522598.8  21522598.8  21522598.8  21522598.8  21522598.8  21522598.8  21522598.8  21522598.8
       Min: 21522598.7, Avg: 21522598.8, Max: 21522598.8, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 4.1 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 2.5 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 8196.1M(14.6G)->7582.0M(14.6G)]
 [Times: user=1.36 sys=0.00, real=0.11 secs] 
2013-10-28T16:00:06.595+0100: 21523.483: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 3 (max 15)
- age   1:   26815464 bytes,   26815464 total
- age   2:   12126232 bytes,   38941696 total
- age   3:   15333080 bytes,   54274776 total
- age   4:   13133256 bytes,   67408032 total
 21523.484: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 40586, predicted base time: 68.66 ms, remaining time: 231.34 ms, target pause time: 300.00 ms]
 21523.484: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 28.52 ms]
 21523.484: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause time: 97.18 ms, target pause time: 300.00 ms]
, 0.1269940 secs]
   [Parallel Time: 118.4 ms, GC Workers: 12]
      [GC Worker Start (ms):  21523483.8  21523483.8  21523483.9  21523483.9  21523483.9  21523483.9  21523483.9  21523483.9  21523483.9  21523484.0  21523484.1  21523484.0
       Min: 21523483.8, Avg: 21523483.9, Max: 21523484.1, Diff: 0.2]
      [Ext Root Scanning (ms):  87.3  52.5  69.8  96.8  69.7  60.8  53.7  72.7  70.6  54.0  54.1  86.7
       Min: 52.5, Avg: 69.1, Max: 96.8, Diff: 44.3, Sum: 828.6]
      [Update RS (ms):  0.0  20.6  2.1  0.0  2.0  12.0  20.6  1.2  2.4  19.4  46.9  0.0
       Min: 0.0, Avg: 10.6, Max: 46.9, Diff: 46.9, Sum: 127.2]
         [Processed Buffers:  0  62  18  0  12  35  53  4  22  42  23  0
          Min: 0, Avg: 22.6, Max: 62, Diff: 62, Sum: 271]
      [Scan RS (ms):  0.0  0.0  0.1  0.0  0.0  0.0  0.0  0.0  0.0  0.2  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.2, Diff: 0.2, Sum: 0.4]
      [Object Copy (ms):  15.0  29.2  30.5  21.3  30.5  29.5  27.9  36.0  29.2  28.6  1.7  15.4
       Min: 1.7, Avg: 24.6, Max: 36.0, Diff: 34.4, Sum: 294.8]
      [Termination (ms):  15.9  15.9  15.8  0.0  15.8  15.8  15.8  8.1  15.8  15.8  15.3  16.0
       Min: 0.0, Avg: 13.8, Max: 16.0, Diff: 16.0, Sum: 166.0]
         [Termination Attempts:  36  66  109  1  76  66  71  1  66  71  1  35
          Min: 1, Avg: 49.9, Max: 109, Diff: 108, Sum: 599]
      [GC Worker Other (ms):  0.1  0.1  0.1  0.0  0.1  0.1  0.0  0.1  0.1  0.1  0.1  0.1
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 1.0]
      [GC Worker Total (ms):  118.3  118.3  118.2  118.2  118.2  118.2  118.1  118.2  118.2  118.1  118.0  118.1
       Min: 118.0, Avg: 118.2, Max: 118.3, Diff: 0.2, Sum: 1418.1]
      [GC Worker End (ms):  21523602.1  21523602.1  21523602.1  21523602.0  21523602.1  21523602.1  21523602.1  21523602.1  21523602.1  21523602.1  21523602.1  21523602.1
       Min: 21523602.0, Avg: 21523602.1, Max: 21523602.1, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 8.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 6.6 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 8230.0M(14.6G)->7629.0M(14.6G)]
 [Times: user=1.17 sys=0.00, real=0.13 secs] 
2013-10-28T16:00:07.417+0100: 21524.305: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:   10249616 bytes,   10249616 total
- age   2:   21417864 bytes,   31667480 total
- age   3:   11865880 bytes,   43533360 total
 21524.305: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 73249, predicted base time: 85.31 ms, remaining time: 214.69 ms, target pause time: 300.00 ms]
 21524.305: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 17.95 ms]
 21524.305: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause time: 103.27 ms, target pause time: 300.00 ms]
, 0.1186000 secs]
   [Parallel Time: 115.5 ms, GC Workers: 12]
      [GC Worker Start (ms):  21524305.2  21524305.2  21524305.2  21524305.2  21524305.2  21524305.3  21524305.3  21524305.4  21524305.4  21524305.4  21524305.4  21524305.4
       Min: 21524305.2, Avg: 21524305.3, Max: 21524305.4, Diff: 0.2]
      [Ext Root Scanning (ms):  47.6  63.0  70.1  65.3  48.5  61.7  64.8  67.3  47.5  60.0  93.6  47.8
       Min: 47.5, Avg: 61.5, Max: 93.6, Diff: 46.1, Sum: 737.4]
      [Update RS (ms):  30.7  14.1  7.9  11.4  30.3  31.4  11.6  8.8  29.8  16.6  0.0  33.5
       Min: 0.0, Avg: 18.8, Max: 33.5, Diff: 33.5, Sum: 226.0]
         [Processed Buffers:  34  33  30  28  63  21  23  26  63  29  0  34
          Min: 0, Avg: 32.0, Max: 63, Diff: 63, Sum: 384]
      [Scan RS (ms):  0.0  0.1  0.0  0.0  0.1  0.0  0.0  0.0  0.1  0.0  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
      [Object Copy (ms):  15.7  16.7  16.0  17.3  15.1  1.3  17.5  17.8  16.5  17.3  21.5  12.6
       Min: 1.3, Avg: 15.5, Max: 21.5, Diff: 20.2, Sum: 185.5]
      [Termination (ms):  21.2  21.3  21.2  21.2  21.2  20.8  21.2  21.2  21.2  21.2  0.0  21.2
       Min: 0.0, Avg: 19.4, Max: 21.3, Diff: 21.3, Sum: 233.2]
         [Termination Attempts:  37  36  44  34  45  1  37  42  42  36  1  32
          Min: 1, Avg: 32.2, Max: 45, Diff: 44, Sum: 387]
      [GC Worker Other (ms):  0.1  0.1  0.1  0.1  0.0  0.1  0.1  0.1  0.1  0.1  0.0  0.1
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
      [GC Worker Total (ms):  115.4  115.4  115.4  115.4  115.3  115.3  115.3  115.2  115.2  115.2  115.1  115.2
       Min: 115.1, Avg: 115.3, Max: 115.4, Diff: 0.3, Sum: 1383.5]
      [GC Worker End (ms):  21524420.6  21524420.6  21524420.6  21524420.6  21524420.6  21524420.6  21524420.6  21524420.6  21524420.6  21524420.6  21524420.5  21524420.6
       Min: 21524420.5, Avg: 21524420.6, Max: 21524420.6, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 3.0 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 1.5 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 8277.0M(14.6G)->7634.9M(14.6G)]
 [Times: user=1.19 sys=0.01, real=0.11 secs] 
2013-10-28T16:00:09.160+0100: 21526.048: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:    6000328 bytes,    6000328 total
- age   2:    9520600 bytes,   15520928 total
- age   3:   20602264 bytes,   36123192 total
- age   4:   11786432 bytes,   47909624 total
 21526.048: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 27950, predicted base time: 74.37 ms, remaining time: 225.63 ms, target pause time: 300.00 ms]
 21526.048: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 16.51 ms]
 21526.048: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause time: 90.88 ms, target pause time: 300.00 ms]
, 0.1238860 secs]
   [Parallel Time: 119.6 ms, GC Workers: 12]
      [GC Worker Start (ms):  21526048.4  21526048.4  21526048.5  21526048.5  21526048.5  21526048.6  21526048.6  21526048.6  21526048.6  21526048.7  21526048.7  21526048.8
       Min: 21526048.4, Avg: 21526048.6, Max: 21526048.8, Diff: 0.4]
      [Ext Root Scanning (ms):  64.3  48.7  56.1  59.2  84.8  66.6  48.1  60.6  98.8  66.3  48.2  61.0
       Min: 48.1, Avg: 63.6, Max: 98.8, Diff: 50.7, Sum: 762.8]
      [Update RS (ms):  1.5  15.9  9.9  7.0  0.0  0.0  16.0  3.5  0.0  0.0  15.9  3.2
       Min: 0.0, Avg: 6.1, Max: 16.0, Diff: 16.0, Sum: 73.1]
         [Processed Buffers:  2  40  29  21  0  0  38  13  0  0  31  22
          Min: 0, Avg: 16.3, Max: 40, Diff: 40, Sum: 196]
      [Scan RS (ms):  0.0  0.0  0.1  0.0  0.0  0.0  0.1  0.0  0.0  0.0  0.1  0.0
       Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
      [Object Copy (ms):  17.9  19.1  17.6  22.1  2.5  17.0  19.3  19.4  20.5  17.1  19.2  19.1
       Min: 2.5, Avg: 17.6, Max: 22.1, Diff: 19.5, Sum: 210.9]
      [Termination (ms):  35.7  35.7  35.7  31.1  32.0  35.7  35.7  35.7  0.0  35.7  35.7  35.7
       Min: 0.0, Avg: 32.1, Max: 35.7, Diff: 35.7, Sum: 384.6]
         [Termination Attempts:  78  1  57  1  1  70  60  59  1  62  71  66
          Min: 1, Avg: 43.9, Max: 78, Diff: 77, Sum: 527]
      [GC Worker Other (ms):  0.0  0.1  0.0  0.0  0.1  0.0  0.1  0.1  0.0  0.1  0.0  0.1
       Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.6]
      [GC Worker Total (ms):  119.5  119.6  119.5  119.4  119.4  119.4  119.4  119.4  119.3  119.3  119.2  119.1
       Min: 119.1, Avg: 119.4, Max: 119.6, Diff: 0.4, Sum: 1432.5]
      [GC Worker End (ms):  21526167.9  21526168.0  21526168.0  21526167.9  21526168.0  21526167.9  21526168.0  21526168.0  21526167.9  21526168.0  21526167.9  21526168.0
       Min: 21526167.9, Avg: 21526168.0, Max: 21526168.0, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 4.1 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 2.7 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 8282.9M(14.6G)->7659.5M(14.6G)]
 [Times: user=1.24 sys=0.00, real=0.12 secs] 
2013-10-28T16:00:10.519+0100: 21527.407: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:    8936336 bytes,    8936336 total
- age   2:    3011208 bytes,   11947544 total
- age   3:    9009224 bytes,   20956768 total
- age   4:   19393152 bytes,   40349920 total
- age   5:    9924104 bytes,   50274024 total
 21527.407: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 35510, predicted base time: 76.50 ms, remaining time: 223.50 ms, target pause time: 300.00 ms]
 21527.407: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 12.59 ms]
 21527.407: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause time: 89.09 ms, target pause time: 300.00 ms]
, 0.1681470 secs]
   [Parallel Time: 154.5 ms, GC Workers: 12]
      [GC Worker Start (ms):  21527407.6  21527407.6  21527407.7  21527407.7  21527407.7  21527407.7  21527407.7  21527407.8  21527407.8  21527407.8  21527407.8  21527407.8
       Min: 21527407.6, Avg: 21527407.7, Max: 21527407.8, Diff: 0.2]
      [Ext Root Scanning (ms):  65.0  134.3  48.8  93.4  49.3  55.4  67.5  48.0  47.8  48.3  67.3  51.3
       Min: 47.8, Avg: 64.7, Max: 134.3, Diff: 86.6, Sum: 776.3]
      [Update RS (ms):  0.0  0.0  12.9  0.0  13.1  6.4  0.0  13.0  13.2  12.7  0.0  10.0
       Min: 0.0, Avg: 6.8, Max: 13.2, Diff: 13.2, Sum: 81.4]
         [Processed Buffers:  0  0  31  0  26  28  0  41  39  42  0  54
          Min: 0, Avg: 21.8, Max: 54, Diff: 54, Sum: 261]
      [Scan RS (ms):  0.0  0.0  0.0  0.0  0.1  0.1  0.0  0.1  0.0  0.1  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
      [Object Copy (ms):  16.7  19.9  19.9  2.6  19.1  19.7  14.0  20.5  20.5  20.4  14.1  20.2
       Min: 2.6, Avg: 17.3, Max: 20.5, Diff: 18.0, Sum: 207.7]
      [Termination (ms):  72.6  0.0  72.6  58.3  72.6  72.6  72.6  72.6  72.6  72.6  72.7  72.6
       Min: 0.0, Avg: 65.4, Max: 72.7, Diff: 72.7, Sum: 784.6]
         [Termination Attempts:  12  1  15  1  12  16  12  13  9  1  12  14
          Min: 1, Avg: 9.8, Max: 16, Diff: 15, Sum: 118]
      [GC Worker Other (ms):  0.1  0.0  0.1  0.1  0.0  0.1  0.1  0.1  0.1  0.1  0.1  0.1
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 1.0]
      [GC Worker Total (ms):  154.5  154.3  154.4  154.3  154.2  154.3  154.3  154.2  154.2  154.2  154.2  154.2
       Min: 154.2, Avg: 154.3, Max: 154.5, Diff: 0.3, Sum: 1851.4]
      [GC Worker End (ms):  21527562.0  21527561.9  21527562.0  21527562.0  21527561.9  21527562.0  21527562.0  21527562.0  21527562.0  21527562.0  21527562.0  21527562.0
       Min: 21527561.9, Avg: 21527562.0, Max: 21527562.0, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 13.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 11.9 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 8307.5M(14.6G)->7675.9M(14.6G)]
 [Times: user=1.66 sys=0.00, real=0.17 secs] 
2013-10-28T16:00:11.861+0100: 21528.749: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 6 (max 15)
- age   1:    8421648 bytes,    8421648 total
- age   2:    7620344 bytes,   16041992 total
- age   3:    2522808 bytes,   18564800 total
- age   4:    7182464 bytes,   25747264 total
- age   5:   18835480 bytes,   44582744 total
- age   6:    9228976 bytes,   53811720 total
 21528.749: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 39666, predicted base time: 81.53 ms, remaining time: 218.47 ms, target pause time: 300.00 ms]
 21528.749: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 17.48 ms]
 21528.749: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause time: 99.00 ms, target pause time: 300.00 ms]
, 0.1418840 secs]
   [Parallel Time: 128.3 ms, GC Workers: 12]
      [GC Worker Start (ms):  21528749.7  21528749.7  21528749.7  21528749.8  21528749.8  21528749.8  21528749.9  21528749.9  21528749.9  21528749.9  21528749.9  21528750.8
       Min: 21528749.7, Avg: 21528749.9, Max: 21528750.8, Diff: 1.1]
      [Ext Root Scanning (ms):  51.1  52.6  67.6  74.4  70.3  67.6  67.7  67.8  99.4  62.3  62.7  66.5
       Min: 51.1, Avg: 67.5, Max: 99.4, Diff: 48.2, Sum: 810.0]
      [Update RS (ms):  23.1  20.8  3.2  0.0  3.1  4.2  4.8  4.5  0.0  10.3  12.5  3.6
       Min: 0.0, Avg: 7.5, Max: 23.1, Diff: 23.1, Sum: 90.1]
         [Processed Buffers:  50  47  32  0  17  21  26  26  0  28  28  18
          Min: 0, Avg: 24.4, Max: 50, Diff: 50, Sum: 293]
      [Scan RS (ms):  0.0  0.1  0.0  0.0  18.8  0.0  0.0  0.1  0.0  0.0  0.0  0.1
       Min: 0.0, Avg: 1.6, Max: 18.8, Diff: 18.8, Sum: 19.2]
      [Object Copy (ms):  20.6  21.3  24.0  20.4  2.7  23.0  22.2  22.3  28.3  24.6  41.7  23.7
       Min: 2.7, Avg: 22.9, Max: 41.7, Diff: 38.9, Sum: 274.8]
      [Termination (ms):  33.1  33.1  33.1  33.1  33.0  33.1  33.1  33.1  0.0  30.5  10.8  33.1
       Min: 0.0, Avg: 28.2, Max: 33.1, Diff: 33.1, Sum: 338.8]
         [Termination Attempts:  1  11  8  8  1  5  5  10  1  1  1  6
          Min: 1, Avg: 4.8, Max: 11, Diff: 10, Sum: 58]
      [GC Worker Other (ms):  0.1  0.1  0.1  0.0  0.1  0.1  0.1  0.1  0.0  0.1  0.0  0.1
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.7]
      [GC Worker Total (ms):  128.0  128.0  128.0  127.9  127.9  127.9  127.9  127.8  127.8  127.8  127.7  126.9
       Min: 126.9, Avg: 127.8, Max: 128.0, Diff: 1.1, Sum: 1533.6]
      [GC Worker End (ms):  21528877.7  21528877.7  21528877.7  21528877.7  21528877.7  21528877.7  21528877.7  21528877.7  21528877.6  21528877.7  21528877.6  21528877.7
       Min: 21528877.6, Avg: 21528877.7, Max: 21528877.7, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.2 ms]
   [Other: 13.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 11.8 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 8323.9M(14.6G)->7724.2M(14.6G)]
 [Times: user=1.36 sys=0.00, real=0.14 secs] 
2013-10-28T16:00:13.625+0100: 21530.513: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 6 (max 15)
- age   1:   10421320 bytes,   10421320 total
- age   2:    6261944 bytes,   16683264 total
- age   3:    7196032 bytes,   23879296 total
- age   4:    2495936 bytes,   26375232 total
- age   5:    5485976 bytes,   31861208 total
- age   6:   18536368 bytes,   50397576 total
 21530.513: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 52102, predicted base time: 87.75 ms, remaining time: 212.25 ms, target pause time: 300.00 ms]
 21530.513: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 11.64 ms]
 21530.513: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause time: 99.40 ms, target pause time: 300.00 ms]
, 0.1134930 secs]
   [Parallel Time: 110.3 ms, GC Workers: 12]
      [GC Worker Start (ms):  21530513.5  21530513.6  21530513.6  21530513.6  21530513.6  21530513.6  21530513.7  21530513.7  21530513.7  21530513.7  21530513.7  21530514.8
       Min: 21530513.5, Avg: 21530513.7, Max: 21530514.8, Diff: 1.2]
      [Ext Root Scanning (ms):  47.1  90.1  65.0  28.2  59.1  56.9  66.6  47.2  64.7  60.2  87.9  47.1
       Min: 28.2, Avg: 60.0, Max: 90.1, Diff: 61.9, Sum: 720.1]
      [Update RS (ms):  21.5  0.0  3.0  11.2  9.5  13.9  2.1  21.4  2.6  9.1  0.0  20.2
       Min: 0.0, Avg: 9.6, Max: 21.5, Diff: 21.5, Sum: 114.6]
         [Processed Buffers:  54  0  22  42  33  36  10  43  26  26  0  40
          Min: 0, Avg: 27.7, Max: 54, Diff: 54, Sum: 332]
      [Scan RS (ms):  0.0  0.0  0.0  0.1  0.0  0.0  0.0  0.1  0.1  0.1  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.4]
      [Object Copy (ms):  18.0  20.0  18.5  55.1  17.9  15.7  17.8  17.8  19.1  17.0  2.6  18.1
       Min: 2.6, Avg: 19.8, Max: 55.1, Diff: 52.6, Sum: 237.7]
      [Termination (ms):  23.5  0.0  23.6  15.5  23.6  23.5  23.6  23.5  23.6  23.5  19.6  23.5
       Min: 0.0, Avg: 20.6, Max: 23.6, Diff: 23.6, Sum: 247.0]
         [Termination Attempts:  6  1  6  1  7  2  2  4  2  1  1  1
          Min: 1, Avg: 2.8, Max: 7, Diff: 6, Sum: 34]
      [GC Worker Other (ms):  0.1  0.0  0.1  0.1  0.1  0.1  0.1  0.1  0.1  0.1  0.1  0.1
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
      [GC Worker Total (ms):  110.2  110.2  110.2  110.2  110.2  110.1  110.1  110.1  110.1  110.1  110.1  109.0
       Min: 109.0, Avg: 110.1, Max: 110.2, Diff: 1.2, Sum: 1320.7]
      [GC Worker End (ms):  21530623.8  21530623.7  21530623.8  21530623.8  21530623.8  21530623.8  21530623.8  21530623.8  21530623.8  21530623.8  21530623.8  21530623.8
       Min: 21530623.7, Avg: 21530623.8, Max: 21530623.8, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 3.0 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 1.5 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 8372.2M(14.6G)->7774.0M(14.6G)]
 [Times: user=1.15 sys=0.02, real=0.12 secs] 
2013-10-28T16:00:19.956+0100: 21536.844: [GC pause (young)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:    4026408 bytes,    4026408 total
- age   2:    8853712 bytes,   12880120 total
- age   3:    5294968 bytes,   18175088 total
- age   4:    6427000 bytes,   24602088 total
- age   5:    2472488 bytes,   27074576 total
- age   6:    5429760 bytes,   32504336 total
 21536.844: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 76487, predicted base time: 89.50 ms, remaining time: 210.50 ms, target pause time: 300.00 ms]
 21536.844: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 10.64 ms]
 21536.844: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 0 regions, predicted pause time: 100.15 ms, target pause time: 300.00 ms]
, 0.1148320 secs]
   [Parallel Time: 111.4 ms, GC Workers: 12]
      [GC Worker Start (ms):  21536844.7  21536844.7  21536844.7  21536844.8  21536844.8  21536844.9  21536844.9  21536844.9  21536845.0  21536845.0  21536845.0  21536845.0
       Min: 21536844.7, Avg: 21536844.9, Max: 21536845.0, Diff: 0.3]
      [Ext Root Scanning (ms):  57.9  89.6  48.0  57.9  65.5  58.2  61.3  58.4  56.6  43.4  61.4  60.8
       Min: 43.4, Avg: 59.9, Max: 89.6, Diff: 46.2, Sum: 719.1]
      [Update RS (ms):  14.0  0.0  24.7  14.0  6.6  13.6  8.8  13.6  15.1  27.7  9.0  9.2
       Min: 0.0, Avg: 13.0, Max: 27.7, Diff: 27.7, Sum: 156.2]
         [Processed Buffers:  41  0  73  46  38  55  55  48  61  67  33  43
          Min: 0, Avg: 46.7, Max: 73, Diff: 73, Sum: 560]
      [Scan RS (ms):  0.0  0.0  0.0  0.1  0.1  0.0  0.1  0.0  0.0  0.1  0.0  0.1
       Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
      [Object Copy (ms):  14.2  21.4  13.4  14.1  13.8  14.1  15.7  13.9  14.1  14.7  15.5  15.7
       Min: 13.4, Avg: 15.0, Max: 21.4, Diff: 8.0, Sum: 180.3]
      [Termination (ms):  24.9  0.0  24.9  24.9  24.9  24.9  24.9  24.9  24.9  24.9  24.9  24.9
       Min: 0.0, Avg: 22.9, Max: 24.9, Diff: 24.9, Sum: 274.2]
         [Termination Attempts:  51  1  51  49  44  50  52  52  53  1  56  46
          Min: 1, Avg: 42.2, Max: 56, Diff: 55, Sum: 506]
      [GC Worker Other (ms):  0.1  0.0  0.1  0.1  0.1  0.1  0.1  0.1  0.0  0.1  0.1  0.1
       Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.9]
      [GC Worker Total (ms):  111.1  111.0  111.1  111.0  111.0  110.9  110.9  110.9  110.8  110.8  110.8  110.8
       Min: 110.8, Avg: 110.9, Max: 111.1, Diff: 0.3, Sum: 1331.2]
      [GC Worker End (ms):  21536955.8  21536955.7  21536955.8  21536955.8  21536955.8  21536955.8  21536955.8  21536955.8  21536955.8  21536955.8  21536955.8  21536955.8
       Min: 21536955.7, Avg: 21536955.8, Max: 21536955.8, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 3.3 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 1.6 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.2 ms]
   [Eden: 648.0M(648.0M)->0.0B(6368.0M) Survivors: 96.0M->88.0M Heap: 8422.0M(14.6G)->7768.2M(14.6G)]
 [Times: user=1.20 sys=0.01, real=0.12 secs] 
-------------- next part --------------
2013-10-30T01:29:30.664+0100: 27690.612: [GC pause (young) (initial-mark)
Desired survivor size 255852544 bytes, new threshold 15 (max 15)
- age   1:   54112176 bytes,   54112176 total
- age   2:   25195152 bytes,   79307328 total
- age   3:   45793088 bytes,  125100416 total
- age   4:    9753864 bytes,  134854280 total
- age   5:    4775680 bytes,  139629960 total
- age   6:    7555296 bytes,  147185256 total
- age   7:    3015480 bytes,  150200736 total
- age   8:    2843864 bytes,  153044600 total
- age   9:    2650656 bytes,  155695256 total
- age  10:     126168 bytes,  155821424 total
- age  11:    2832664 bytes,  158654088 total
- age  12:    3099000 bytes,  161753088 total
- age  13:    9933720 bytes,  171686808 total
- age  14:    9524488 bytes,  181211296 total
- age  15:   17084240 bytes,  198295536 total
 27690.612: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 59857, predicted base time: 48.38 ms, remaining time: 251.62 ms, target pause time: 300.00 ms]
 27690.612: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 445 regions, survivors: 39 regions, predicted young region time: 40.15 ms]
 27690.612: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 445 regions, survivors: 39 regions, old: 0 regions, predicted pause time: 88.53 ms, target pause time: 300.00 ms]
, 0.1458620 secs]
   [Parallel Time: 141.1 ms, GC Workers: 12]
      [GC Worker Start (ms):  27690612.0  27690612.1  27690612.1  27690612.2  27690612.2  27690612.3  27690612.3  27690612.3  27690612.4  27690612.4  27690612.4  27690612.5
       Min: 27690612.0, Avg: 27690612.3, Max: 27690612.5, Diff: 0.5]
      [Ext Root Scanning (ms):  20.5  28.3  30.4  21.7  20.8  21.0  18.7  18.2  43.1  35.2  21.3  26.6
       Min: 18.2, Avg: 25.5, Max: 43.1, Diff: 24.9, Sum: 305.7]
      [Update RS (ms):  20.1  12.3  9.7  19.5  19.6  19.7  15.0  34.1  0.8  0.0  19.7  13.5
       Min: 0.0, Avg: 15.3, Max: 34.1, Diff: 34.1, Sum: 184.1]
         [Processed Buffers:  43  30  17  51  35  41  25  6  1  0  35  24
          Min: 0, Avg: 25.7, Max: 51, Diff: 51, Sum: 308]
      [Scan RS (ms):  0.1  0.4  0.0  0.4  0.4  0.1  0.0  0.1  0.3  0.1  0.0  0.3
       Min: 0.0, Avg: 0.2, Max: 0.4, Diff: 0.4, Sum: 2.2]
      [Object Copy (ms):  99.9  99.6  100.4  98.9  99.6  99.5  106.5  87.9  96.0  104.9  99.2  99.7
       Min: 87.9, Avg: 99.3, Max: 106.5, Diff: 18.6, Sum: 1192.2]
      [Termination (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
         [Termination Attempts:  47  52  39  49  1  41  42  59  47  51  58  57
          Min: 1, Avg: 45.2, Max: 59, Diff: 58, Sum: 543]
      [GC Worker Other (ms):  0.1  0.2  0.0  0.0  0.0  0.0  0.1  0.1  0.1  0.1  0.0  0.1
       Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 0.9]
      [GC Worker Total (ms):  140.8  140.7  140.5  140.4  140.4  140.4  140.5  140.5  140.3  140.3  140.2  140.3
       Min: 140.2, Avg: 140.4, Max: 140.8, Diff: 0.5, Sum: 1685.3]
      [GC Worker End (ms):  27690752.8  27690752.8  27690752.7  27690752.7  27690752.7  27690752.7  27690752.8  27690752.8  27690752.7  27690752.7  27690752.7  27690752.7
       Min: 27690752.7, Avg: 27690752.7, Max: 27690752.8, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 0.8 ms]
   [Other: 3.9 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 2.1 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 0.5 ms]
   [Eden: 3560.0M(3560.0M)->0.0B(3544.0M) Survivors: 312.0M->312.0M Heap: 13.1G(14.6G)->9874.5M(14.6G)]
 [Times: user=1.19 sys=0.13, real=0.16 secs] 
2013-10-30T01:29:30.818+0100: 27690.765: [GC concurrent-root-region-scan-start]
2013-10-30T01:29:30.856+0100: 27690.803: [GC concurrent-root-region-scan-end, 0.0382270 secs]
2013-10-30T01:29:30.856+0100: 27690.803: [GC concurrent-mark-start]
2013-10-30T01:29:32.334+0100: 27692.281: [GC concurrent-mark-end, 1.4779140 secs]
2013-10-30T01:29:32.337+0100: 27692.284: [GC remark 2013-10-30T01:29:32.344+0100: 27692.292: [GC ref-proc, 0.3883890 secs], 0.4504230 secs]
 [Times: user=4.26 sys=0.05, real=0.45 secs] 
2013-10-30T01:29:32.788+0100: 27692.736: [GC cleanup 10127M->9532M(14G), 0.0284350 secs]
 [Times: user=0.17 sys=0.00, real=0.03 secs] 
2013-10-30T01:29:32.817+0100: 27692.765: [GC concurrent-cleanup-start]
2013-10-30T01:29:32.817+0100: 27692.765: [GC concurrent-cleanup-end, 0.0003630 secs]
2013-10-30T01:37:26.669+0100: 28166.616: [GC pause (young)
Desired survivor size 255852544 bytes, new threshold 15 (max 15)
- age   1:   40919168 bytes,   40919168 total
- age   2:   30378112 bytes,   71297280 total
- age   3:   23561576 bytes,   94858856 total
- age   4:   42991232 bytes,  137850088 total
- age   5:    9633512 bytes,  147483600 total
- age   6:    4743768 bytes,  152227368 total
- age   7:    7511072 bytes,  159738440 total
- age   8:    3012496 bytes,  162750936 total
- age   9:    2842096 bytes,  165593032 total
- age  10:    2643488 bytes,  168236520 total
- age  11:     124928 bytes,  168361448 total
- age  12:    2832592 bytes,  171194040 total
- age  13:    3099000 bytes,  174293040 total
- age  14:    9906104 bytes,  184199144 total
- age  15:    9524160 bytes,  193723304 total
 28166.616: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 226256, predicted base time: 89.33 ms, remaining time: 210.67 ms, target pause time: 300.00 ms]
 28166.617: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 443 regions, survivors: 39 regions, predicted young region time: 68.73 ms]
 28166.617: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 443 regions, survivors: 39 regions, old: 0 regions, predicted pause time: 158.06 ms, target pause time: 300.00 ms]
 28166.745: [G1Ergonomics (Mixed GCs) start mixed GCs, reason: candidate old regions available, candidate old regions: 697 regions, reclaimable: 4317871456 bytes (27.45 %), threshold: 5.00 %]
, 0.1286010 secs]
   [Parallel Time: 118.0 ms, GC Workers: 12]
      [GC Worker Start (ms):  28166616.7  28166616.7  28166616.7  28166616.8  28166616.8  28166616.9  28166616.9  28166617.0  28166617.0  28166617.0  28166617.0  28166617.0
       Min: 28166616.7, Avg: 28166616.9, Max: 28166617.0, Diff: 0.4]
      [Ext Root Scanning (ms):  22.0  28.7  30.6  21.9  22.1  21.8  22.3  28.6  21.6  21.8  29.7  31.8
       Min: 21.6, Avg: 25.2, Max: 31.8, Diff: 10.2, Sum: 302.9]
      [Update RS (ms):  37.6  30.1  28.6  37.9  37.2  37.6  36.8  31.6  37.5  37.3  28.8  20.9
       Min: 20.9, Avg: 33.5, Max: 37.9, Diff: 17.0, Sum: 402.0]
         [Processed Buffers:  88  60  62  90  88  91  90  82  109  86  75  51
          Min: 51, Avg: 81.0, Max: 109, Diff: 58, Sum: 972]
      [Scan RS (ms):  4.2  4.4  4.1  3.9  4.4  4.1  4.4  4.1  4.2  4.3  4.5  4.4
       Min: 3.9, Avg: 4.3, Max: 4.5, Diff: 0.5, Sum: 51.1]
      [Object Copy (ms):  53.3  53.8  53.8  53.3  53.4  53.4  53.2  52.5  53.5  53.2  53.8  59.6
       Min: 52.5, Avg: 53.9, Max: 59.6, Diff: 7.1, Sum: 646.9]
      [Termination (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.3]
         [Termination Attempts:  1  104  96  113  111  116  102  96  117  103  115  100
          Min: 1, Avg: 97.8, Max: 117, Diff: 116, Sum: 1174]
      [GC Worker Other (ms):  0.2  0.2  0.1  0.1  0.1  0.0  0.0  0.0  0.1  0.3  0.3  0.0
       Min: 0.0, Avg: 0.1, Max: 0.3, Diff: 0.3, Sum: 1.5]
      [GC Worker Total (ms):  117.3  117.3  117.2  117.1  117.1  117.0  116.9  116.9  116.9  117.1  117.1  116.8
       Min: 116.8, Avg: 117.1, Max: 117.3, Diff: 0.5, Sum: 1404.7]
      [GC Worker End (ms):  28166734.0  28166734.1  28166733.9  28166733.9  28166733.9  28166733.9  28166733.9  28166733.8  28166733.9  28166734.1  28166734.1  28166733.8
       Min: 28166733.8, Avg: 28166733.9, Max: 28166734.1, Diff: 0.3]
   [Code Root Fixup: 0.0 ms]
   [Clear CT: 2.5 ms]
   [Other: 8.2 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 6.1 ms]
      [Ref Enq: 0.4 ms]
      [Free CSet: 0.6 ms]
   [Eden: 3544.0M(3544.0M)->0.0B(440.0M) Survivors: 312.0M->304.0M Heap: 12.5G(14.6G)->9294.2M(14.6G)]
 [Times: user=1.43 sys=0.01, real=0.12 secs] 
2013-10-30T01:38:07.937+0100: 28207.885: [GC pause (mixed)
Desired survivor size 50331648 bytes, new threshold 2 (max 15)
- age   1:   34304808 bytes,   34304808 total
- age   2:   18459760 bytes,   52764568 total
- age   3:   28615288 bytes,   81379856 total
- age   4:   19659904 bytes,  101039760 total
- age   5:   42360080 bytes,  143399840 total
- age   6:    9181056 bytes,  152580896 total
- age   7:    4688968 bytes,  157269864 total
- age   8:    7360688 bytes,  164630552 total
- age   9:    2994952 bytes,  167625504 total
- age  10:    2825216 bytes,  170450720 total
- age  11:    2638880 bytes,  173089600 total
- age  12:     123536 bytes,  173213136 total
- age  13:    2827664 bytes,  176040800 total
- age  14:    3097464 bytes,  179138264 total
- age  15:    9902944 bytes,  189041208 total
 28207.885: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 51567, predicted base time: 46.37 ms, remaining time: 253.63 ms, target pause time: 300.00 ms]
 28207.885: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 55 regions, survivors: 38 regions, predicted young region time: 40.63 ms]
 28207.885: [G1Ergonomics (CSet Construction) finish adding old regions to CSet, reason: old CSet region num reached max, old: 188 regions, max: 188 regions]
 28207.885: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 55 regions, survivors: 38 regions, old: 188 regions, predicted pause time: 277.13 ms, target pause time: 300.00 ms]
 28208.038: [G1Ergonomics (Mixed GCs) continue mixed GCs, reason: candidate old regions available, candidate old regions: 509 regions, reclaimable: 2832392416 bytes (18.01 %), threshold: 5.00 %]
, 0.1535180 secs]
   [Parallel Time: 142.9 ms, GC Workers: 12]
      [GC Worker Start (ms):  28207885.6  28207885.6  28207885.7  28207885.7  28207885.8  28207885.8  28207885.8  28207885.8  28207885.8  28207885.9  28207885.9  28207885.9
       Min: 28207885.6, Avg: 28207885.8, Max: 28207885.9, Diff: 0.4]
      [Ext Root Scanning (ms):  22.3  29.9  31.7  28.0  22.6  30.4  21.9  22.3  21.9  21.9  28.8  22.0
       Min: 21.9, Avg: 25.3, Max: 31.7, Diff: 9.9, Sum: 303.7]
      [Update RS (ms):  14.2  5.4  0.0  7.8  13.6  4.8  14.4  13.7  14.0  13.3  8.3  13.9
       Min: 0.0, Avg: 10.3, Max: 14.4, Diff: 14.4, Sum: 123.4]
         [Processed Buffers:  27  12  0  17  24  17  36  37  25  21  18  28
          Min: 0, Avg: 21.8, Max: 37, Diff: 37, Sum: 262]
      [Scan RS (ms):  22.2  23.2  19.2  22.6  22.4  22.4  23.4  22.3  22.3  24.3  22.1  22.3
       Min: 19.2, Avg: 22.4, Max: 24.3, Diff: 5.1, Sum: 268.7]
      [Object Copy (ms):  83.6  83.7  91.2  83.7  83.5  84.4  82.3  83.7  83.8  82.5  82.7  83.6
       Min: 82.3, Avg: 84.1, Max: 91.2, Diff: 8.9, Sum: 1008.8]
      [Termination (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
         [Termination Attempts:  12  17  15  12  17  15  21  12  16  2  24  16
          Min: 2, Avg: 14.9, Max: 24, Diff: 22, Sum: 179]
      [GC Worker Other (ms):  0.0  0.1  0.1  0.0  0.0  0.0  0.1  0.0  0.0  0.2  0.1  0.0
       Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.7]
      [GC Worker Total (ms):  142.3  142.2  142.2  142.2  142.1  142.1  142.1  142.0  142.0  142.1  142.1  141.9
       Min: 141.9, Avg: 142.1, Max: 142.3, Diff: 0.4, Sum: 1705.3]
      [GC Worker End (ms):  28208027.9  28208027.9  28208027.9  28208027.9  28208027.9  28208027.9  28208027.9  28208027.9  28208027.9  28208028.0  28208028.0  28208027.9
       Min: 28208027.9, Avg: 28208027.9, Max: 28208028.0, Diff: 0.1]
   [Code Root Fixup: 0.3 ms]
   [Clear CT: 1.8 ms]
   [Other: 8.6 ms]
      [Choose CSet: 0.3 ms]
      [Ref Proc: 4.0 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 1.5 ms]
   [Eden: 440.0M(440.0M)->0.0B(648.0M) Survivors: 304.0M->96.0M Heap: 9734.2M(14.6G)->7886.8M(14.6G)]
 [Times: user=1.73 sys=0.00, real=0.15 secs] 
2013-10-30T01:39:00.272+0100: 28260.220: [GC pause (mixed)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:    7067616 bytes,    7067616 total
- age   2:   27834904 bytes,   34902520 total
 28260.220: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 180534, predicted base time: 75.39 ms, remaining time: 224.61 ms, target pause time: 300.00 ms]
 28260.220: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 26.33 ms]
 28260.221: [G1Ergonomics (CSet Construction) finish adding old regions to CSet, reason: predicted time is too high, predicted time: 1.49 ms, remaining time: 0.35 ms, old: 148 regions, min: 88 regions]
 28260.221: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 148 regions, predicted pause time: 299.65 ms, target pause time: 300.00 ms]
 28260.407: [G1Ergonomics (Mixed GCs) continue mixed GCs, reason: candidate old regions available, candidate old regions: 361 regions, reclaimable: 1806105664 bytes (11.48 %), threshold: 5.00 %]
, 0.1872570 secs]
   [Parallel Time: 173.4 ms, GC Workers: 12]
      [GC Worker Start (ms):  28260220.8  28260220.8  28260220.9  28260220.9  28260221.0  28260221.0  28260221.0  28260221.0  28260221.1  28260221.1  28260221.1  28260221.1
       Min: 28260220.8, Avg: 28260221.0, Max: 28260221.1, Diff: 0.4]
      [Ext Root Scanning (ms):  22.3  22.9  29.8  28.3  22.4  32.1  30.3  29.4  22.5  13.1  28.0  31.4
       Min: 13.1, Avg: 26.0, Max: 32.1, Diff: 19.0, Sum: 312.5]
      [Update RS (ms):  36.4  36.6  28.2  31.8  36.2  27.6  28.0  30.2  36.4  32.4  30.1  18.8
       Min: 18.8, Avg: 31.1, Max: 36.6, Diff: 17.7, Sum: 372.8]
         [Processed Buffers:  62  69  64  74  66  55  55  63  69  69  68  46
          Min: 46, Avg: 63.3, Max: 74, Diff: 28, Sum: 760]
      [Scan RS (ms):  25.7  25.4  25.8  25.3  26.1  25.7  25.5  25.6  26.4  26.2  25.4  25.7
       Min: 25.3, Avg: 25.7, Max: 26.4, Diff: 1.1, Sum: 308.7]
      [Object Copy (ms):  87.9  87.4  88.4  86.8  87.4  86.7  88.3  87.5  86.7  100.3  88.4  96.0
       Min: 86.7, Avg: 89.3, Max: 100.3, Diff: 13.6, Sum: 1071.9]
      [Termination (ms):  0.7  0.7  0.7  0.7  0.7  0.7  0.7  0.0  0.7  0.7  0.7  0.7
       Min: 0.0, Avg: 0.6, Max: 0.7, Diff: 0.7, Sum: 7.3]
         [Termination Attempts:  114  135  127  118  107  128  129  1  127  136  123  135
          Min: 1, Avg: 115.0, Max: 136, Diff: 135, Sum: 1380]
      [GC Worker Other (ms):  0.0  0.0  0.1  0.0  0.0  0.0  0.2  0.0  0.0  0.0  0.1  0.2
       Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.8]
      [GC Worker Total (ms):  173.0  173.0  172.9  172.8  172.8  172.8  172.9  172.7  172.7  172.7  172.7  172.8
       Min: 172.7, Avg: 172.8, Max: 173.0, Diff: 0.3, Sum: 2074.0]
      [GC Worker End (ms):  28260393.8  28260393.8  28260393.8  28260393.8  28260393.8  28260393.8  28260393.9  28260393.8  28260393.8  28260393.8  28260393.9  28260394.0
       Min: 28260393.8, Avg: 28260393.8, Max: 28260394.0, Diff: 0.2]
   [Code Root Fixup: 0.4 ms]
   [Clear CT: 1.8 ms]
   [Other: 11.6 ms]
      [Choose CSet: 0.4 ms]
      [Ref Proc: 6.8 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 1.4 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 8534.8M(14.6G)->6992.0M(14.6G)]
 [Times: user=2.02 sys=0.01, real=0.19 secs] 
2013-10-30T01:40:32.405+0100: 28352.352: [GC pause (mixed)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:   16158568 bytes,   16158568 total
- age   2:     708616 bytes,   16867184 total
- age   3:   18023256 bytes,   34890440 total
 28352.353: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 166653, predicted base time: 71.94 ms, remaining time: 228.06 ms, target pause time: 300.00 ms]
 28352.353: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 24.66 ms]
 28352.353: [G1Ergonomics (CSet Construction) finish adding old regions to CSet, reason: predicted time is too high, predicted time: 2.09 ms, remaining time: 0.31 ms, old: 114 regions, min: 88 regions]
 28352.353: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 114 regions, predicted pause time: 299.69 ms, target pause time: 300.00 ms]
 28352.552: [G1Ergonomics (Mixed GCs) continue mixed GCs, reason: candidate old regions available, candidate old regions: 247 regions, reclaimable: 1111160680 bytes (7.06 %), threshold: 5.00 %]
, 0.1996140 secs]
   [Parallel Time: 189.6 ms, GC Workers: 12]
      [GC Worker Start (ms):  28352353.3  28352353.4  28352353.5  28352353.6  28352353.6  28352353.6  28352353.6  28352353.6  28352353.7  28352353.7  28352353.7  28352353.8
       Min: 28352353.3, Avg: 28352353.6, Max: 28352353.8, Diff: 0.4]
      [Ext Root Scanning (ms):  21.9  30.3  22.0  21.6  30.6  22.0  33.3  28.2  21.9  29.6  21.4  21.5
       Min: 21.4, Avg: 25.4, Max: 33.3, Diff: 11.9, Sum: 304.4]
      [Update RS (ms):  50.2  41.1  50.2  50.2  40.8  50.0  29.2  43.3  49.7  42.9  50.5  50.7
       Min: 29.2, Avg: 45.7, Max: 50.7, Diff: 21.4, Sum: 548.8]
         [Processed Buffers:  56  52  65  71  54  67  34  68  66  67  62  62
          Min: 34, Avg: 60.3, Max: 71, Diff: 37, Sum: 724]
      [Scan RS (ms):  22.3  21.9  21.9  22.2  21.9  22.0  22.1  22.7  22.2  22.1  21.8  22.0
       Min: 21.8, Avg: 22.1, Max: 22.7, Diff: 0.9, Sum: 265.1]
      [Object Copy (ms):  95.0  96.0  95.1  95.1  95.8  95.1  104.5  94.9  95.3  94.3  95.2  94.8
       Min: 94.3, Avg: 95.9, Max: 104.5, Diff: 10.1, Sum: 1151.2]
      [Termination (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.3]
         [Termination Attempts:  78  78  85  64  81  86  67  1  90  82  91  86
          Min: 1, Avg: 74.1, Max: 91, Diff: 90, Sum: 889]
      [GC Worker Other (ms):  0.0  0.0  0.0  0.2  0.1  0.1  0.0  0.1  0.0  0.1  0.0  0.0
       Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 0.7]
      [GC Worker Total (ms):  189.4  189.4  189.3  189.3  189.2  189.3  189.2  189.2  189.1  189.1  189.0  189.0
       Min: 189.0, Avg: 189.2, Max: 189.4, Diff: 0.4, Sum: 2270.5]
      [GC Worker End (ms):  28352542.8  28352542.8  28352542.8  28352542.9  28352542.8  28352542.9  28352542.8  28352542.8  28352542.8  28352542.8  28352542.8  28352542.8
       Min: 28352542.8, Avg: 28352542.8, Max: 28352542.9, Diff: 0.1]
   [Code Root Fixup: 0.5 ms]
   [Clear CT: 1.9 ms]
   [Other: 7.6 ms]
      [Choose CSet: 0.4 ms]
      [Ref Proc: 2.5 ms]
      [Ref Enq: 0.1 ms]
      [Free CSet: 1.4 ms]
   [Eden: 648.0M(648.0M)->0.0B(648.0M) Survivors: 96.0M->96.0M Heap: 7640.0M(14.6G)->6393.4M(14.6G)]
 [Times: user=2.26 sys=0.00, real=0.20 secs] 
2013-10-30T01:42:22.386+0100: 28462.334: [GC pause (mixed)
Desired survivor size 50331648 bytes, new threshold 15 (max 15)
- age   1:   11777336 bytes,   11777336 total
- age   2:    7846592 bytes,   19623928 total
- age   3:     546648 bytes,   20170576 total
- age   4:   17067728 bytes,   37238304 total
 28462.334: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 152752, predicted base time: 72.54 ms, remaining time: 227.46 ms, target pause time: 300.00 ms]
 28462.334: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 81 regions, survivors: 12 regions, predicted young region time: 21.02 ms]
 28462.335: [G1Ergonomics (CSet Construction) finish adding old regions to CSet, reason: reclaimable percentage not over threshold, old: 59 regions, max: 188 regions, reclaimable: 782535160 bytes (4.98 %), threshold: 5.00 %]
 28462.335: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 81 regions, survivors: 12 regions, old: 59 regions, predicted pause time: 191.14 ms, target pause time: 300.00 ms]
 28462.502: [G1Ergonomics (Mixed GCs) do not continue mixed GCs, reason: reclaimable percentage not over threshold, candidate old regions: 188 regions, reclaimable: 782535160 bytes (4.98 %), threshold: 5.00 %]
, 0.1683460 secs]
   [Parallel Time: 157.3 ms, GC Workers: 12]
      [GC Worker Start (ms):  28462334.7  28462334.8  28462334.8  28462334.9  28462334.9  28462334.9  28462334.9  28462335.0  28462335.0  28462335.0  28462335.0  28462335.3
       Min: 28462334.7, Avg: 28462334.9, Max: 28462335.3, Diff: 0.6]
      [Ext Root Scanning (ms):  35.8  30.5  30.5  31.9  56.7  30.8  30.4  31.6  30.3  30.1  31.6  25.1
       Min: 25.1, Avg: 32.9, Max: 56.7, Diff: 31.6, Sum: 395.4]
      [Update RS (ms):  38.5  45.5  45.7  40.5  17.6  43.1  45.4  41.1  42.6  42.9  41.4  44.2
       Min: 17.6, Avg: 40.7, Max: 45.7, Diff: 28.1, Sum: 488.5]
         [Processed Buffers:  55  58  52  52  36  66  56  68  52  64  46  64
          Min: 36, Avg: 55.8, Max: 68, Diff: 32, Sum: 669]
      [Scan RS (ms):  16.0  16.4  16.2  16.4  15.9  16.2  16.4  16.0  16.3  16.3  15.6  16.4
       Min: 15.6, Avg: 16.2, Max: 16.4, Diff: 0.8, Sum: 194.0]
      [Object Copy (ms):  66.3  64.2  64.2  67.7  66.3  66.4  64.3  67.7  67.1  67.1  67.7  70.4
       Min: 64.2, Avg: 66.6, Max: 70.4, Diff: 6.2, Sum: 799.5]
      [Termination (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0  0.0
       Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
         [Termination Attempts:  20  21  23  35  28  24  1  25  26  33  29  22
          Min: 1, Avg: 23.9, Max: 35, Diff: 34, Sum: 287]
      [GC Worker Other (ms):  0.0  0.0  0.0  0.0  0.0  0.0  0.1  0.1  0.0  0.0  0.2  0.1
       Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.7]
      [GC Worker Total (ms):  156.7  156.6  156.6  156.6  156.6  156.5  156.5  156.5  156.4  156.4  156.6  156.2
       Min: 156.2, Avg: 156.5, Max: 156.7, Diff: 0.5, Sum: 1878.2]
      [GC Worker End (ms):  28462491.4  28462491.4  28462491.4  28462491.4  28462491.4  28462491.4  28462491.4  28462491.5  28462491.4  28462491.4  28462491.6  28462491.5
       Min: 28462491.4, Avg: 28462491.5, Max: 28462491.6, Diff: 0.2]
   [Code Root Fixup: 0.5 ms]
   [Clear CT: 2.1 ms]
   [Other: 8.5 ms]
      [Choose CSet: 0.3 ms]
      [Ref Proc: 4.7 ms]
      [Ref Enq: 0.2 ms]
      [Free CSet: 0.8 ms]
   [Eden: 648.0M(648.0M)->0.0B(7616.0M) Survivors: 96.0M->88.0M Heap: 7041.4M(14.6G)->6091.8M(14.6G)]
 [Times: user=1.77 sys=0.01, real=0.16 secs]