Page MenuHomePhabricator
Create Task
Maniphest T176192

WDQS clone keeps freezing up on GC
Closed, DeclinedPublic
Actions

Description

After IRC conv with @Smalyshev posting it here. @Gehel, could you think of what might be the cause of it?

I observed a 10+ hour freeze of my clone of WDQS, after which it seemed recovered. GC log (below) showed very long 1minute GC pause cycles. The current runtime stats and configuration can be seen at http://88.99.164.208/bigdata/

The service uses default configuration from runBlazegraph.sh, except that HEAP_SIZE was boosted from 16GB to 30GB on a 127GB server. I just lowered it back to 16 just to be certain its not the cause. The database is about twice the size of the wikidata-only store.

2017-09-18T16:29:11.412+0200: 108085.193: Total time for which application threads were stopped: 0.0011448 seconds, Stopping threads took: 0.0000139 seconds
2017-09-18T16:29:11.412+0200: 108085.193: [Full GC (Allocation Failure)  29G->29G(30G), 66.8452146 secs]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.8G(30.0G)], [Metaspace: 38211K->38211K(1085440K)]
 [Times: user=120.84 sys=0.00, real=66.84 secs] 
2017-09-18T16:30:18.257+0200: 108152.039: Total time for which application threads were stopped: 66.8454983 seconds, Stopping threads took: 0.0000152 seconds
2017-09-18T16:30:18.258+0200: 108152.039: [GC concurrent-mark-abort]
2017-09-18T16:30:18.552+0200: 108152.333: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
 (to-space exhausted), 0.7249978 secs]
   [Parallel Time: 656.0 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108152334.3, Avg: 108152334.3, Max: 108152334.4, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.2, Avg: 0.3, Max: 0.6, Diff: 0.4, Sum: 3.0]
      [Update RS (ms): Min: 0.1, Avg: 2.3, Max: 7.6, Diff: 7.5, Sum: 23.5]
         [Processed Buffers: Min: 1, Avg: 6.5, Max: 15, Diff: 14, Sum: 65]
      [Scan RS (ms): Min: 40.0, Avg: 40.8, Max: 41.1, Diff: 1.2, Sum: 408.3]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 607.1, Avg: 612.5, Max: 614.5, Diff: 7.4, Sum: 6124.7]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
         [Termination Attempts: Min: 1, Avg: 23.9, Max: 41, Diff: 40, Sum: 239]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 655.9, Avg: 656.0, Max: 656.0, Diff: 0.1, Sum: 6559.7]
      [GC Worker End (ms): Min: 108152990.3, Avg: 108152990.3, Max: 108152990.3, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.2 ms]
   [Clear CT: 3.3 ms]
   [Other: 65.4 ms]
      [Evacuation Failure: 61.8 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 1.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.7 ms]
   [Eden: 136.0M(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=1.70 sys=0.02, real=0.73 secs] 
2017-09-18T16:30:19.277+0200: 108153.058: Total time for which application threads were stopped: 0.7254731 seconds, Stopping threads took: 0.0000493 seconds
2017-09-18T16:30:19.292+0200: 108153.073: [GC pause (G1 Evacuation Pause) (young) (initial-mark)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.1967381 secs]
   [Parallel Time: 196.0 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108153073.7, Avg: 108153073.7, Max: 108153073.8, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.5, Avg: 0.5, Max: 0.6, Diff: 0.1, Sum: 5.4]
      [Update RS (ms): Min: 193.7, Avg: 194.2, Max: 195.3, Diff: 1.6, Sum: 1942.1]
         [Processed Buffers: Min: 143, Avg: 190.3, Max: 278, Diff: 135, Sum: 1903]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.4]
      [Termination (ms): Min: 0.0, Avg: 1.1, Max: 1.5, Diff: 1.5, Sum: 10.7]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 195.8, Avg: 195.9, Max: 195.9, Diff: 0.1, Sum: 1958.7]
      [GC Worker End (ms): Min: 108153269.6, Avg: 108153269.6, Max: 108153269.6, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.6 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.1 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=1.95 sys=0.00, real=0.19 secs] 
2017-09-18T16:30:19.489+0200: 108153.270: [GC concurrent-root-region-scan-start]
2017-09-18T16:30:19.489+0200: 108153.270: [GC concurrent-root-region-scan-end, 0.0000219 secs]
2017-09-18T16:30:19.489+0200: 108153.270: [GC concurrent-mark-start]
2017-09-18T16:30:19.489+0200: 108153.270: Total time for which application threads were stopped: 0.1971676 seconds, Stopping threads took: 0.0000347 seconds
2017-09-18T16:30:19.490+0200: 108153.271: [Full GC (Allocation Failure)  29G->29G(30G), 67.9231575 secs]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.8G(30.0G)], [Metaspace: 38265K->38265K(1085440K)]
 [Times: user=122.31 sys=0.00, real=67.93 secs] 
2017-09-18T16:31:27.413+0200: 108221.194: Total time for which application threads were stopped: 67.9234908 seconds, Stopping threads took: 0.0000161 seconds
2017-09-18T16:31:27.413+0200: 108221.194: [GC concurrent-mark-abort]
2017-09-18T16:31:27.416+0200: 108221.197: Total time for which application threads were stopped: 0.0013514 seconds, Stopping threads took: 0.0007219 seconds
2017-09-18T16:31:27.417+0200: 108221.198: Total time for which application threads were stopped: 0.0005006 seconds, Stopping threads took: 0.0000418 seconds
2017-09-18T16:31:27.438+0200: 108221.219: Total time for which application threads were stopped: 0.0002974 seconds, Stopping threads took: 0.0000506 seconds
2017-09-18T16:31:27.478+0200: 108221.259: [GC pause (G1 Humongous Allocation) (young) (initial-mark)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.0274237 secs]
   [Parallel Time: 23.0 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108221261.0, Avg: 108221261.0, Max: 108221261.1, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.6, Avg: 0.7, Max: 0.8, Diff: 0.2, Sum: 6.9]
      [Update RS (ms): Min: 5.9, Avg: 6.4, Max: 6.9, Diff: 1.0, Sum: 63.6]
         [Processed Buffers: Min: 3, Avg: 6.3, Max: 13, Diff: 10, Sum: 63]
      [Scan RS (ms): Min: 7.3, Avg: 7.9, Max: 8.3, Diff: 1.0, Sum: 78.5]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 7.8, Avg: 7.9, Max: 8.1, Diff: 0.3, Sum: 78.8]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.3]
         [Termination Attempts: Min: 1, Avg: 114.3, Max: 139, Diff: 138, Sum: 1143]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 22.8, Avg: 22.8, Max: 22.9, Diff: 0.1, Sum: 228.3]
      [GC Worker End (ms): Min: 108221283.9, Avg: 108221283.9, Max: 108221283.9, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.1 ms]
   [Clear CT: 1.7 ms]
   [Other: 2.5 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.3 ms]
   [Eden: 56.0M(1536.0M)->0.0B(1512.0M) Survivors: 0.0B->24.0M Heap: 29.8G(30.0G)->29.8G(30.0G)]
 [Times: user=0.25 sys=0.00, real=0.03 secs] 
2017-09-18T16:31:27.506+0200: 108221.287: [GC concurrent-root-region-scan-start]
2017-09-18T16:31:27.506+0200: 108221.287: Total time for which application threads were stopped: 0.0278431 seconds, Stopping threads took: 0.0000376 seconds
2017-09-18T16:31:27.520+0200: 108221.301: [GC concurrent-root-region-scan-end, 0.0146693 secs]
2017-09-18T16:31:27.520+0200: 108221.301: [GC concurrent-mark-start]
2017-09-18T16:31:27.710+0200: 108221.491: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
- age   1:   20396896 bytes,   20396896 total
 (to-space exhausted), 0.6071921 secs]
   [Parallel Time: 556.6 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108221491.1, Avg: 108221491.1, Max: 108221491.1, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.2, Avg: 0.3, Max: 0.5, Diff: 0.3, Sum: 3.0]
      [Update RS (ms): Min: 0.0, Avg: 35.0, Max: 61.2, Diff: 61.2, Sum: 350.4]
         [Processed Buffers: Min: 0, Avg: 33.9, Max: 80, Diff: 80, Sum: 339]
      [Scan RS (ms): Min: 0.0, Avg: 16.4, Max: 27.6, Diff: 27.6, Sum: 164.5]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 467.3, Avg: 504.6, Max: 556.2, Diff: 88.9, Sum: 5046.3]
      [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.6]
         [Termination Attempts: Min: 1, Avg: 68.2, Max: 90, Diff: 89, Sum: 682]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 556.5, Avg: 556.5, Max: 556.5, Diff: 0.1, Sum: 5564.9]
      [GC Worker End (ms): Min: 108222047.6, Avg: 108222047.6, Max: 108222047.6, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 1.9 ms]
   [Other: 48.5 ms]
      [Evacuation Failure: 46.7 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 1.0 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.2 ms]
      [Free CSet: 0.3 ms]
   [Eden: 80.0M(1512.0M)->0.0B(1536.0M) Survivors: 24.0M->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=1.56 sys=0.00, real=0.61 secs] 
2017-09-18T16:31:28.317+0200: 108222.098: Total time for which application threads were stopped: 0.6075988 seconds, Stopping threads took: 0.0000422 seconds
2017-09-18T16:31:28.387+0200: 108222.168: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
 (to-space exhausted), 0.3057584 secs]
   [Parallel Time: 281.4 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108222167.8, Avg: 108222167.8, Max: 108222167.9, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.3, Avg: 0.4, Max: 0.9, Diff: 0.6, Sum: 4.4]
      [Update RS (ms): Min: 152.0, Avg: 152.8, Max: 153.4, Diff: 1.3, Sum: 1528.1]
         [Processed Buffers: Min: 133, Avg: 163.9, Max: 235, Diff: 102, Sum: 1639]
      [Scan RS (ms): Min: 0.3, Avg: 0.9, Max: 1.3, Diff: 1.0, Sum: 8.9]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 126.9, Avg: 127.0, Max: 127.2, Diff: 0.2, Sum: 1270.2]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
         [Termination Attempts: Min: 1, Avg: 1.1, Max: 2, Diff: 1, Sum: 11]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 281.1, Avg: 281.2, Max: 281.3, Diff: 0.1, Sum: 2812.0]
      [GC Worker End (ms): Min: 108222449.0, Avg: 108222449.1, Max: 108222449.1, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.7 ms]
   [Other: 23.6 ms]
      [Evacuation Failure: 22.6 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.4 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.2 ms]
      [Free CSet: 0.1 ms]
   [Eden: 24.0M(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=1.76 sys=0.00, real=0.31 secs] 
2017-09-18T16:31:28.692+0200: 108222.474: Total time for which application threads were stopped: 0.3061782 seconds, Stopping threads took: 0.0000426 seconds
2017-09-18T16:31:28.693+0200: 108222.474: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.0538663 secs]
   [Parallel Time: 53.1 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108222474.1, Avg: 108222474.1, Max: 108222474.2, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.3, Avg: 0.4, Max: 0.6, Diff: 0.3, Sum: 3.6]
      [Update RS (ms): Min: 52.1, Avg: 52.3, Max: 52.6, Diff: 0.5, Sum: 523.5]
         [Processed Buffers: Min: 43, Avg: 61.9, Max: 103, Diff: 60, Sum: 619]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
      [Termination (ms): Min: 0.0, Avg: 0.3, Max: 0.4, Diff: 0.4, Sum: 2.5]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 52.9, Avg: 53.0, Max: 53.1, Diff: 0.1, Sum: 530.0]
      [GC Worker End (ms): Min: 108222527.1, Avg: 108222527.1, Max: 108222527.2, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.5 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.53 sys=0.00, real=0.05 secs] 
2017-09-18T16:31:28.747+0200: 108222.528: Total time for which application threads were stopped: 0.0543116 seconds, Stopping threads took: 0.0000207 seconds
2017-09-18T16:31:28.747+0200: 108222.528: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.0010285 secs]
   [Parallel Time: 0.5 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108222528.3, Avg: 108222528.4, Max: 108222528.4, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 0.3, Avg: 0.3, Max: 0.5, Diff: 0.2, Sum: 3.1]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Processed Buffers: Min: 0, Avg: 0.2, Max: 1, Diff: 1, Sum: 2]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
      [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 1.4]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [GC Worker Total (ms): Min: 0.5, Avg: 0.5, Max: 0.5, Diff: 0.1, Sum: 4.8]
      [GC Worker End (ms): Min: 108222528.8, Avg: 108222528.8, Max: 108222528.9, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.3 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.00 sys=0.00, real=0.00 secs] 
2017-09-18T16:31:28.748+0200: 108222.529: Total time for which application threads were stopped: 0.0013573 seconds, Stopping threads took: 0.0000179 seconds
2017-09-18T16:31:28.748+0200: 108222.530: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.0007695 secs]
   [Parallel Time: 0.3 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108222529.6, Avg: 108222529.6, Max: 108222529.6, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 0.2, Avg: 0.2, Max: 0.3, Diff: 0.0, Sum: 2.4]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Processed Buffers: Min: 0, Avg: 0.2, Max: 1, Diff: 1, Sum: 2]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [GC Worker Total (ms): Min: 0.3, Avg: 0.3, Max: 0.3, Diff: 0.0, Sum: 2.7]
      [GC Worker End (ms): Min: 108222529.9, Avg: 108222529.9, Max: 108222529.9, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.3 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.01 sys=0.00, real=0.00 secs] 
2017-09-18T16:31:28.749+0200: 108222.530: Total time for which application threads were stopped: 0.0009711 seconds, Stopping threads took: 0.0000122 seconds
2017-09-18T16:31:28.749+0200: 108222.531: [Full GC (Allocation Failure)  29G->29G(30G), 68.1929269 secs]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.8G(30.0G)], [Metaspace: 38287K->38287K(1085440K)]
 [Times: user=122.72 sys=0.00, real=68.19 secs] 
2017-09-18T16:32:36.942+0200: 108290.724: Total time for which application threads were stopped: 68.1931276 seconds, Stopping threads took: 0.0000118 seconds
2017-09-18T16:32:36.942+0200: 108290.724: [GC concurrent-mark-abort]
2017-09-18T16:32:37.037+0200: 108290.818: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
 (to-space exhausted), 0.3366420 secs]
   [Parallel Time: 301.3 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108290820.1, Avg: 108290820.1, Max: 108290820.2, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.3, Avg: 0.3, Max: 0.5, Diff: 0.2, Sum: 3.4]
      [Update RS (ms): Min: 2.1, Avg: 2.4, Max: 3.0, Diff: 0.9, Sum: 23.9]
         [Processed Buffers: Min: 1, Avg: 3.2, Max: 9, Diff: 8, Sum: 32]
      [Scan RS (ms): Min: 11.7, Avg: 12.4, Max: 12.7, Diff: 1.0, Sum: 124.2]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 285.8, Avg: 286.0, Max: 286.1, Diff: 0.3, Sum: 2859.9]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
         [Termination Attempts: Min: 1, Avg: 16.0, Max: 23, Diff: 22, Sum: 160]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 301.1, Avg: 301.2, Max: 301.2, Diff: 0.1, Sum: 3011.7]
      [GC Worker End (ms): Min: 108291121.3, Avg: 108291121.3, Max: 108291121.3, Diff: 0.0]
   [Code Root Fixup: 0.2 ms]
   [Code Root Purge: 0.2 ms]
   [Clear CT: 1.7 ms]
   [Other: 33.2 ms]
      [Evacuation Failure: 30.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.5 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.2 ms]
      [Free CSet: 0.4 ms]
   [Eden: 48.0M(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.63 sys=0.00, real=0.34 secs] 
2017-09-18T16:32:37.374+0200: 108291.155: Total time for which application threads were stopped: 0.3371441 seconds, Stopping threads took: 0.0000372 seconds
2017-09-18T16:32:37.375+0200: 108291.156: [GC pause (G1 Evacuation Pause) (young) (initial-mark)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.0832823 secs]
   [Parallel Time: 81.7 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108291156.1, Avg: 108291156.2, Max: 108291156.3, Diff: 0.2]
      [Ext Root Scanning (ms): Min: 0.6, Avg: 0.7, Max: 0.8, Diff: 0.2, Sum: 7.2]
      [Update RS (ms): Min: 80.4, Avg: 80.5, Max: 80.7, Diff: 0.3, Sum: 805.3]
         [Processed Buffers: Min: 40, Avg: 55.1, Max: 80, Diff: 40, Sum: 551]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.5]
      [Termination (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, Sum: 2.0]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 81.4, Avg: 81.5, Max: 81.6, Diff: 0.2, Sum: 815.1]
      [GC Worker End (ms): Min: 108291237.7, Avg: 108291237.7, Max: 108291237.8, Diff: 0.0]
   [Code Root Fixup: 0.3 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 1.2 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.3 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.81 sys=0.00, real=0.08 secs] 
2017-09-18T16:32:37.458+0200: 108291.239: [GC concurrent-root-region-scan-start]
2017-09-18T16:32:37.458+0200: 108291.239: Total time for which application threads were stopped: 0.0839485 seconds, Stopping threads took: 0.0000536 seconds
2017-09-18T16:32:37.458+0200: 108291.239: [GC concurrent-root-region-scan-end, 0.0000401 secs]
2017-09-18T16:32:37.458+0200: 108291.239: [GC concurrent-mark-start]
2017-09-18T16:32:37.459+0200: 108291.240: [Full GC (Allocation Failure)  29G->29G(30G), 65.2333156 secs]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)], [Metaspace: 38287K->38287K(1085440K)]
 [Times: user=126.70 sys=0.00, real=65.24 secs] 
2017-09-18T16:33:42.692+0200: 108356.473: Total time for which application threads were stopped: 65.2338278 seconds, Stopping threads took: 0.0000250 seconds
2017-09-18T16:33:42.692+0200: 108356.474: [GC concurrent-mark-abort]
2017-09-18T16:33:42.733+0200: 108356.514: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
 (to-space exhausted), 0.1282456 secs]
   [Parallel Time: 105.2 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108356515.3, Avg: 108356515.4, Max: 108356515.4, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.3, Avg: 0.4, Max: 0.9, Diff: 0.7, Sum: 3.8]
      [Update RS (ms): Min: 2.8, Avg: 3.3, Max: 3.9, Diff: 1.0, Sum: 32.5]
         [Processed Buffers: Min: 2, Avg: 3.7, Max: 10, Diff: 8, Sum: 37]
      [Scan RS (ms): Min: 6.3, Avg: 6.8, Max: 7.1, Diff: 0.8, Sum: 67.6]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 94.5, Avg: 94.7, Max: 94.9, Diff: 0.4, Sum: 946.8]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
         [Termination Attempts: Min: 1, Avg: 8.1, Max: 14, Diff: 13, Sum: 81]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 105.1, Avg: 105.1, Max: 105.1, Diff: 0.0, Sum: 1050.8]
      [GC Worker End (ms): Min: 108356620.5, Avg: 108356620.5, Max: 108356620.5, Diff: 0.0]
   [Code Root Fixup: 0.2 ms]
   [Code Root Purge: 0.3 ms]
   [Clear CT: 1.7 ms]
   [Other: 20.9 ms]
      [Evacuation Failure: 18.3 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.3 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.2 ms]
      [Free CSet: 0.3 ms]
   [Eden: 24.0M(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.29 sys=0.00, real=0.12 secs] 
2017-09-18T16:33:42.861+0200: 108356.642: Total time for which application threads were stopped: 0.1287688 seconds, Stopping threads took: 0.0000471 seconds
2017-09-18T16:33:42.862+0200: 108356.643: [GC pause (G1 Evacuation Pause) (young) (initial-mark)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.0434074 secs]
   [Parallel Time: 42.3 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108356643.1, Avg: 108356643.2, Max: 108356643.2, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.7, Avg: 0.8, Max: 0.9, Diff: 0.2, Sum: 8.1]
      [Update RS (ms): Min: 38.9, Avg: 39.6, Max: 41.2, Diff: 2.3, Sum: 395.6]
         [Processed Buffers: Min: 28, Avg: 34.4, Max: 42, Diff: 14, Sum: 344]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.4]
      [Termination (ms): Min: 0.0, Avg: 1.7, Max: 2.4, Diff: 2.4, Sum: 16.9]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 42.1, Avg: 42.1, Max: 42.2, Diff: 0.1, Sum: 421.1]
      [GC Worker End (ms): Min: 108356685.3, Avg: 108356685.3, Max: 108356685.3, Diff: 0.0]
   [Code Root Fixup: 0.2 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.9 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.42 sys=0.00, real=0.05 secs] 
2017-09-18T16:33:42.905+0200: 108356.686: [GC concurrent-root-region-scan-start]
2017-09-18T16:33:42.905+0200: 108356.686: [GC concurrent-root-region-scan-end, 0.0000251 secs]
2017-09-18T16:33:42.905+0200: 108356.686: [GC concurrent-mark-start]
2017-09-18T16:33:42.905+0200: 108356.686: Total time for which application threads were stopped: 0.0439630 seconds, Stopping threads took: 0.0000204 seconds
2017-09-18T16:33:42.906+0200: 108356.687: [Full GC (Allocation Failure)  29G->29G(30G), 65.8253884 secs]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)], [Metaspace: 38287K->38203K(1085440K)]
 [Times: user=121.88 sys=0.00, real=65.82 secs] 
2017-09-18T16:34:48.731+0200: 108422.512: Total time for which application threads were stopped: 65.8257800 seconds, Stopping threads took: 0.0000182 seconds
2017-09-18T16:34:48.731+0200: 108422.512: [GC concurrent-mark-abort]
2017-09-18T16:34:48.732+0200: 108422.513: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
 (to-space exhausted), 0.0028246 secs]
   [Parallel Time: 0.6 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108422514.4, Avg: 108422514.5, Max: 108422514.5, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.2, Avg: 0.3, Max: 0.5, Diff: 0.3, Sum: 3.1]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1]
         [Processed Buffers: Min: 0, Avg: 1.0, Max: 3, Diff: 3, Sum: 10]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.3]
      [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.7]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 0.4, Avg: 0.4, Max: 0.5, Diff: 0.1, Sum: 4.3]
      [GC Worker End (ms): Min: 108422514.9, Avg: 108422514.9, Max: 108422514.9, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.1 ms]
   [Clear CT: 0.1 ms]
   [Other: 2.0 ms]
      [Evacuation Failure: 0.2 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.1 ms]
   [Eden: 8192.0K(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.00 sys=0.00, real=0.00 secs] 
2017-09-18T16:34:48.735+0200: 108422.516: Total time for which application threads were stopped: 0.0032001 seconds, Stopping threads took: 0.0000834 seconds
2017-09-18T16:34:48.735+0200: 108422.516: [GC pause (G1 Evacuation Pause) (young) (initial-mark)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.0011855 secs]
   [Parallel Time: 0.6 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108422516.0, Avg: 108422516.0, Max: 108422516.0, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 0.5, Avg: 0.5, Max: 0.5, Diff: 0.1, Sum: 4.9]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
         [Processed Buffers: Min: 0, Avg: 1.2, Max: 4, Diff: 4, Sum: 12]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.3]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [GC Worker Total (ms): Min: 0.5, Avg: 0.6, Max: 0.6, Diff: 0.0, Sum: 5.5]
      [GC Worker End (ms): Min: 108422516.6, Avg: 108422516.6, Max: 108422516.6, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.01 sys=0.00, real=0.00 secs] 
2017-09-18T16:34:48.736+0200: 108422.517: [GC concurrent-root-region-scan-start]
2017-09-18T16:34:48.736+0200: 108422.517: 2017-09-18T16:34:48.736+0200: Total time for which application threads were stopped: 0.0013626 seconds, Stopping threads took: 0.0000190 seconds
108422.517: [GC concurrent-root-region-scan-end, 0.0000091 secs]
2017-09-18T16:34:48.736+0200: 108422.517: [GC concurrent-mark-start]
2017-09-18T16:34:48.736+0200: 108422.517: [Full GC (Allocation Failure)  29G->29G(30G), 61.4517157 secs]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)], [Metaspace: 38203K->38203K(1085440K)]
 [Times: user=115.79 sys=0.00, real=61.45 secs] 
2017-09-18T16:35:50.188+0200: 108483.969: Total time for which application threads were stopped: 61.4519292 seconds, Stopping threads took: 0.0000128 seconds
2017-09-18T16:35:50.188+0200: 108483.969: [GC concurrent-mark-abort]
2017-09-18T16:35:50.189+0200: 108483.970: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
 (to-space exhausted), 0.0058147 secs]
   [Parallel Time: 2.4 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108483971.8, Avg: 108483971.9, Max: 108483972.0, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.3, Avg: 0.3, Max: 0.5, Diff: 0.2, Sum: 3.2]
      [Update RS (ms): Min: 0.0, Avg: 0.2, Max: 2.0, Diff: 2.0, Sum: 2.2]
         [Processed Buffers: Min: 0, Avg: 1.8, Max: 8, Diff: 8, Sum: 18]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.7, Max: 0.8, Diff: 0.8, Sum: 7.2]
      [Termination (ms): Min: 0.0, Avg: 1.1, Max: 1.2, Diff: 1.2, Sum: 10.5]
         [Termination Attempts: Min: 1, Avg: 3.9, Max: 8, Diff: 7, Sum: 39]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 2.3, Avg: 2.3, Max: 2.4, Diff: 0.1, Sum: 23.2]
      [GC Worker End (ms): Min: 108483974.2, Avg: 108483974.2, Max: 108483974.2, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.2 ms]
   [Clear CT: 0.1 ms]
   [Other: 3.0 ms]
      [Evacuation Failure: 0.5 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 8192.0K(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.02 sys=0.00, real=0.01 secs] 
2017-09-18T16:35:50.195+0200: 108483.976: Total time for which application threads were stopped: 0.0063013 seconds, Stopping threads took: 0.0000870 seconds
2017-09-18T16:35:50.195+0200: 108483.976: [GC pause (G1 Evacuation Pause) (young) (initial-mark)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.0030171 secs]
   [Parallel Time: 2.2 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108483976.2, Avg: 108483976.2, Max: 108483976.3, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.6, Avg: 0.7, Max: 0.7, Diff: 0.2, Sum: 6.6]
      [Update RS (ms): Min: 0.1, Avg: 0.3, Max: 1.3, Diff: 1.2, Sum: 2.6]
         [Processed Buffers: Min: 1, Avg: 1.5, Max: 3, Diff: 2, Sum: 15]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.3]
      [Termination (ms): Min: 0.0, Avg: 1.1, Max: 1.3, Diff: 1.3, Sum: 10.7]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 1.9, Avg: 2.0, Max: 2.1, Diff: 0.1, Sum: 20.2]
      [GC Worker End (ms): Min: 108483978.2, Avg: 108483978.3, Max: 108483978.3, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.7 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.0 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.02 sys=0.00, real=0.00 secs] 
2017-09-18T16:35:50.198+0200: 108483.979: [GC concurrent-root-region-scan-start]
2017-09-18T16:35:50.198+0200: 108483.979: Total time for which application threads were stopped: 0.0033405 seconds, Stopping threads took: 0.0000366 seconds
2017-09-18T16:35:50.198+0200: 108483.979: [GC concurrent-root-region-scan-end, 0.0000151 secs]
2017-09-18T16:35:50.198+0200: 108483.979: [GC concurrent-mark-start]
2017-09-18T16:35:50.198+0200: 108483.979: [Full GC (Allocation Failure)  29G->29G(30G), 63.7496852 secs]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)], [Metaspace: 38203K->38203K(1085440K)]
 [Times: user=118.09 sys=0.00, real=63.75 secs] 
2017-09-18T16:36:53.948+0200: 108547.729: Total time for which application threads were stopped: 63.7499749 seconds, Stopping threads took: 0.0000464 seconds
2017-09-18T16:36:53.948+0200: 108547.729: [GC concurrent-mark-abort]
2017-09-18T16:36:53.952+0200: 108547.733: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
 (to-space exhausted), 0.0420813 secs]
   [Parallel Time: 31.1 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108547735.9, Avg: 108547736.0, Max: 108547736.1, Diff: 0.2]
      [Ext Root Scanning (ms): Min: 0.3, Avg: 0.5, Max: 2.1, Diff: 1.8, Sum: 5.4]
      [Update RS (ms): Min: 0.0, Avg: 8.9, Max: 12.0, Diff: 12.0, Sum: 88.8]
         [Processed Buffers: Min: 0, Avg: 5.7, Max: 13, Diff: 13, Sum: 57]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 18.5, Avg: 21.5, Max: 30.5, Diff: 12.0, Sum: 214.6]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 30.8, Avg: 30.9, Max: 31.0, Diff: 0.2, Sum: 309.2]
      [GC Worker End (ms): Min: 108547766.9, Avg: 108547766.9, Max: 108547766.9, Diff: 0.0]
   [Code Root Fixup: 0.2 ms]
   [Code Root Purge: 0.2 ms]
   [Clear CT: 0.1 ms]
   [Other: 10.6 ms]
      [Evacuation Failure: 7.3 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.2 ms]
      [Humongous Register: 0.2 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 8192.0K(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.15 sys=0.00, real=0.04 secs] 
2017-09-18T16:36:53.994+0200: 108547.775: Total time for which application threads were stopped: 0.0426064 seconds, Stopping threads took: 0.0000499 seconds
2017-09-18T16:36:53.995+0200: 108547.776: [GC pause (G1 Evacuation Pause) (young) (initial-mark)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.0126976 secs]
   [Parallel Time: 11.7 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108547776.3, Avg: 108547776.4, Max: 108547776.4, Diff: 0.2]
      [Ext Root Scanning (ms): Min: 0.6, Avg: 0.7, Max: 0.7, Diff: 0.1, Sum: 6.6]
      [Update RS (ms): Min: 10.6, Avg: 10.7, Max: 10.9, Diff: 0.2, Sum: 107.2]
         [Processed Buffers: Min: 8, Avg: 11.5, Max: 22, Diff: 14, Sum: 115]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.4]
      [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 1.2]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 11.5, Avg: 11.5, Max: 11.6, Diff: 0.2, Sum: 115.5]
      [GC Worker End (ms): Min: 108547787.9, Avg: 108547787.9, Max: 108547787.9, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.8 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.11 sys=0.00, real=0.01 secs] 
2017-09-18T16:36:54.008+0200: 108547.789: [GC concurrent-root-region-scan-start]
2017-09-18T16:36:54.008+02002017-09-18T16:36:54.008+0200: : 108547.789: 108547.789: [GC concurrent-root-region-scan-end, 0.0000251 secs]
Total time for which application threads were stopped: 0.0131616 seconds, Stopping threads took: 0.0000459 seconds
2017-09-18T16:36:54.008+0200: 108547.789: [GC concurrent-mark-start]
2017-09-18T16:36:54.009+0200: 108547.790: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.0011553 secs]
   [Parallel Time: 0.5 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108547789.7, Avg: 108547789.8, Max: 108547789.8, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.3, Avg: 0.3, Max: 0.4, Diff: 0.1, Sum: 3.3]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Processed Buffers: Min: 0, Avg: 0.2, Max: 1, Diff: 1, Sum: 2]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.4]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 0.3, Avg: 0.4, Max: 0.5, Diff: 0.1, Sum: 4.0]
      [GC Worker End (ms): Min: 108547790.2, Avg: 108547790.2, Max: 108547790.2, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.1 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.01 sys=0.00, real=0.00 secs] 
2017-09-18T16:36:54.010+0200: 108547.791: Total time for which application threads were stopped: 0.0015660 seconds, Stopping threads took: 0.0000600 seconds
2017-09-18T16:36:54.010+0200: 108547.791: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.0009802 secs]
   [Parallel Time: 0.4 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108547791.3, Avg: 108547791.3, Max: 108547791.3, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 0.3, Avg: 0.3, Max: 0.3, Diff: 0.1, Sum: 2.8]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Processed Buffers: Min: 0, Avg: 0.2, Max: 1, Diff: 1, Sum: 2]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 0.3, Avg: 0.3, Max: 0.3, Diff: 0.0, Sum: 3.0]
      [GC Worker End (ms): Min: 108547791.6, Avg: 108547791.6, Max: 108547791.6, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.0 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.00 sys=0.00, real=0.00 secs] 
2017-09-18T16:36:54.011+0200: 108547.792: Total time for which application threads were stopped: 0.0012603 seconds, Stopping threads took: 0.0000361 seconds
2017-09-18T16:36:54.011+0200: 108547.792: [Full GC (Allocation Failure)  29G->29G(30G), 61.3606403 secs]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)], [Metaspace: 38203K->38203K(1085440K)]
 [Times: user=116.14 sys=0.00, real=61.37 secs] 
2017-09-18T16:37:55.372+0200: 108609.153: Total time for which application threads were stopped: 61.3609114 seconds, Stopping threads took: 0.0000401 seconds
2017-09-18T16:37:55.372+0200: 108609.153: [GC concurrent-mark-abort]
2017-09-18T16:37:55.372+0200: 108609.154: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
 (to-space exhausted), 0.0029150 secs]
   [Parallel Time: 0.6 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108609155.2, Avg: 108609155.3, Max: 108609155.4, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.3, Avg: 0.3, Max: 0.5, Diff: 0.2, Sum: 3.3]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
         [Processed Buffers: Min: 0, Avg: 1.0, Max: 2, Diff: 2, Sum: 10]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.7]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.3]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 0.4, Avg: 0.5, Max: 0.5, Diff: 0.1, Sum: 4.5]
      [GC Worker End (ms): Min: 108609155.8, Avg: 108609155.8, Max: 108609155.8, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.1 ms]
   [Clear CT: 0.1 ms]
   [Other: 2.1 ms]
      [Evacuation Failure: 0.2 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.1 ms]
   [Eden: 8192.0K(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.01 sys=0.00, real=0.00 secs] 
2017-09-18T16:37:55.375+0200: 108609.157: Total time for which application threads were stopped: 0.0032398 seconds, Stopping threads took: 0.0000424 seconds
2017-09-18T16:37:55.377+0200: 108609.158: [GC pause (G1 Evacuation Pause) (young) (initial-mark)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.0011620 secs]
   [Parallel Time: 0.6 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108609157.9, Avg: 108609157.9, Max: 108609158.0, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.4, Avg: 0.5, Max: 0.5, Diff: 0.1, Sum: 4.7]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1]
         [Processed Buffers: Min: 0, Avg: 1.0, Max: 3, Diff: 3, Sum: 10]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.3]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.4]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [GC Worker Total (ms): Min: 0.5, Avg: 0.6, Max: 0.6, Diff: 0.1, Sum: 5.5]
      [GC Worker End (ms): Min: 108609158.5, Avg: 108609158.5, Max: 108609158.5, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.4 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.0 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.01 sys=0.00, real=0.00 secs] 
2017-09-18T16:37:55.378+0200: 108609.159: [GC concurrent-root-region-scan-start]
2017-09-18T16:37:55.378+0200: 108609.159: 2017-09-18T16:37:55.378+0200: 108609.159: Total time for which application threads were stopped: 0.0016204 seconds, Stopping threads took: 0.0000119 seconds
[GC concurrent-root-region-scan-end, 0.0000102 secs]
2017-09-18T16:37:55.378+0200: 108609.159: [GC concurrent-mark-start]
2017-09-18T16:37:55.395+0200: 108609.176: [Full GC (Allocation Failure)  29G->29G(30G), 61.6614641 secs]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)], [Metaspace: 38203K->38203K(1085440K)]
 [Times: user=116.38 sys=0.00, real=61.66 secs] 
2017-09-18T16:38:57.056+0200: 108670.838: Total time for which application threads were stopped: 61.6618382 seconds, Stopping threads took: 0.0000352 seconds
2017-09-18T16:38:57.057+0200: 108670.838: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
 (to-space exhausted), 0.0030438 secs]
   [Parallel Time: 0.7 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108670839.6, Avg: 108670839.7, Max: 108670839.8, Diff: 0.1]
      [Ext Root Scanning (ms): Min: 0.3, Avg: 0.3, Max: 0.4, Diff: 0.2, Sum: 3.2]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.2]
         [Processed Buffers: Min: 0, Avg: 1.0, Max: 4, Diff: 4, Sum: 10]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.2, Max: 0.2, Diff: 0.2, Sum: 1.5]
      [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.6]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [GC Worker Total (ms): Min: 0.5, Avg: 0.6, Max: 0.6, Diff: 0.1, Sum: 5.6]
      [GC Worker End (ms): Min: 108670840.3, Avg: 108670840.3, Max: 108670840.3, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.1 ms]
   [Clear CT: 0.1 ms]
   [Other: 2.1 ms]
      [Evacuation Failure: 0.2 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.1 ms]
   [Eden: 8192.0K(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.01 sys=0.00, real=0.00 secs] 
2017-09-18T16:38:57.060+0200: 108670.841: Total time for which application threads were stopped: 0.0033704 seconds, Stopping threads took: 0.0000466 seconds
2017-09-18T16:38:57.060+0200: 108670.841: [GC concurrent-mark-abort]
2017-09-18T16:38:57.060+0200: 108670.841: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 100663296 bytes, new threshold 15 (max 15)
, 0.0007894 secs]
   [Parallel Time: 0.4 ms, GC Workers: 10]
      [GC Worker Start (ms): Min: 108670841.3, Avg: 108670841.3, Max: 108670841.3, Diff: 0.0]
      [Ext Root Scanning (ms): Min: 0.2, Avg: 0.2, Max: 0.2, Diff: 0.0, Sum: 2.2]
      [Update RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
         [Processed Buffers: Min: 1, Avg: 1.4, Max: 3, Diff: 2, Sum: 14]
      [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.4]
         [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 10]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [GC Worker Total (ms): Min: 0.3, Avg: 0.3, Max: 0.3, Diff: 0.0, Sum: 3.0]
      [GC Worker End (ms): Min: 108670841.6, Avg: 108670841.6, Max: 108670841.6, Diff: 0.0]
   [Code Root Fixup: 0.1 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.1 ms]
   [Other: 0.3 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 0.1 ms]
      [Ref Enq: 0.0 ms]
      [Redirty Cards: 0.1 ms]
      [Humongous Register: 0.0 ms]
      [Humongous Reclaim: 0.1 ms]
      [Free CSet: 0.0 ms]
   [Eden: 0.0B(1536.0M)->0.0B(1536.0M) Survivors: 0.0B->0.0B Heap: 29.9G(30.0G)->29.9G(30.0G)]
 [Times: user=0.00 sys=0.00, real=0.00 secs] 
2017-09-18T16:38:57.061+0200: 108670.842: Total time for which application threads were stopped: 0.0009832 seconds, Stopping threads took: 0.0000291 seconds

Related Objects

Event Timeline

Yurik created this task.Sep 19 2017, 1:31 AM
Restricted Application added projects: Wikidata, Discovery-ARCHIVED. · View Herald TranscriptSep 19 2017, 1:31 AM
Restricted Application added a subscriber: Aklapper. · View Herald Transcript
Gehel added a comment.Sep 19 2017, 8:17 AM

I had a chat with @Yurik to dig a bit more into this issue. He is seeing a 75% GC overhead, which seems very different than the behaviour we observe on our own wdqs instances. We are doing our own investigation into GC tuning (T175919).

I did gave @Yurik a few idea to try:

  • reduce heap size
  • investigate thread dumps during the crash / freeze
  • disable G1
  • ...

I'm closing this as it does not seem to be related to WDQS itself.

Gehel closed this task as Declined.Sep 19 2017, 8:17 AM
Yurik added a comment.EditedSep 20 2017, 8:58 PM

@Gehel I have been running it for a day with 16GB space, and got this gc report - apparently sys time is usually slow. Thread dump report. Any thoughts?
P.S. I tried running it in a smaller machine (8gb i think), and i got tons of slowdowns in update scripts.

Yurik added a comment.Sep 28 2017, 6:20 PM

I saw the issue again, and filed a bug with the stacktraces - https://jira.blazegraph.com/browse/BLZG-9058

Seems like there is a lock contention of sorts.

Content licensed under Creative Commons Attribution-ShareAlike (CC BY-SA) 4.0 unless otherwise noted; code licensed under GNU General Public License (GPL) 2.0 or later and other open source licenses. By using this site, you agree to the Terms of Use, Privacy Policy, and Code of Conduct. · Wikimedia Foundation · Privacy Policy · Code of Conduct · Terms of Use · Disclaimer · CC-BY-SA · GPL