OpenJDK 64-Bit Server VM (25.111-b14) for linux-amd64 JRE (1.8.0_111-8u111-b14-3~14.04.1-b14), built on Nov 5 2016 13:21:07 by "buildd" with gcc 4.8.4 Memory: 4k page, physical 16433116k(3729044k free), swap 0k(0k free) CommandLine flags: -XX:+AlwaysPreTouch -XX:+ExplicitGCInvokesConcurrent -XX:G1SummarizeRSetStatsPeriod=1 -XX:GCLogFileSize=104857600 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/var/log/jenkins/heapdump.log -XX:InitialHeapSize=1073741824 -XX:MaxHeapSize=2147483648 -XX:MaxMetaspaceExpansion=67108864 -XX:NumberOfGCLogFiles=2 -XX:+ParallelRefProcEnabled -XX:+PrintAdaptiveSizePolicy -XX:+PrintGC -XX:+PrintGCCause -XX:+PrintGCDateStamps -XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -XX:+PrintReferenceGC -XX:+PrintTenuringDistribution -XX:+UnlockDiagnosticVMOptions -XX:+UseCompressedClassPointers -XX:+UseCompressedOops -XX:+UseG1GC -XX:+UseGCLogFileRotation -XX:+UseStringDeduplication 0.011: [G1Ergonomics (Heap Sizing) expand the heap, requested expansion amount: 1073741824 bytes, attempted expansion amount: 1073741824 bytes] {Heap before GC invocations=0 (full 0): garbage-first heap total 1048576K, used 52224K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 51 young (52224K), 0 survivors (0K) Metaspace used 8891K, capacity 9008K, committed 9216K, reserved 1056768K class space used 937K, capacity 979K, committed 1024K, reserved 1048576K 2017-04-02T19:01:31.365+0000: 1.930: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 3670016 bytes, new threshold 15 (max 15) 1.930: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 0, predicted base time: 10.00 ms, remaining time: 190.00 ms, target pause time: 200.00 ms] 1.930: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 51 regions, survivors: 0 regions, predicted young region time: 1298.76 ms] 1.930: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 51 regions, survivors: 0 regions, old: 0 regions, predicted pause time: 1308.76 ms, target pause time: 200.00 ms] 2017-04-02T19:01:31.371+0000: 1.936: [SoftReference, 0 refs, 0.0003793 secs]2017-04-02T19:01:31.371+0000: 1.936: [WeakReference, 102 refs, 0.0002557 secs]2017-04-02T19:01:31.372+0000: 1.937: [FinalReference, 4649 refs, 0.0042604 secs]2017-04-02T19:01:31.376+0000: 1.941: [PhantomReference, 0 refs, 0 refs, 0.0004672 secs]2017-04-02T19:01:31.376+0000: 1.941: [JNI Weak Reference, 0.0000095 secs], 0.0121380 secs] [Parallel Time: 5.5 ms, GC Workers: 4] [GC Worker Start (ms): Min: 1930.2, Avg: 1930.2, Max: 1930.2, Diff: 0.1] [Ext Root Scanning (ms): Min: 0.3, Avg: 0.6, Max: 0.8, Diff: 0.5, Sum: 2.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.0, Max: 0, Diff: 0, Sum: 0] [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [Code Root Scanning (ms): Min: 0.1, Avg: 0.6, Max: 1.4, Diff: 1.3, Sum: 2.2] [Object Copy (ms): Min: 3.5, Avg: 4.1, Max: 4.7, Diff: 1.2, Sum: 16.5] [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.4] [Termination Attempts: Min: 1, Avg: 1.2, Max: 2, Diff: 1, Sum: 5] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [GC Worker Total (ms): Min: 5.3, Avg: 5.4, Max: 5.4, Diff: 0.1, Sum: 21.5] [GC Worker End (ms): Min: 1935.6, Avg: 1935.6, Max: 1935.6, Diff: 0.0] [Code Root Fixup: 0.2 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 0.3 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Table Fixup (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.2] [Clear CT: 0.1 ms] [Other: 6.0 ms] [Choose CSet: 0.0 ms] [Ref Proc: 5.5 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.1 ms] [Eden: 51.0M(51.0M)->0.0B(44.0M) Survivors: 0.0B->7168.0K Heap: 51.0M(1024.0M)->13.8M(1024.0M)] Heap after GC invocations=1 (full 0): garbage-first heap total 1048576K, used 14089K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 7 young (7168K), 7 survivors (7168K) Metaspace used 8891K, capacity 9008K, committed 9216K, reserved 1056768K class space used 937K, capacity 979K, committed 1024K, reserved 1048576K } [Times: user=0.03 sys=0.00, real=0.01 secs] 2017-04-02T19:01:31.378+0000: 1.943: [GC concurrent-string-deduplication, 157.9K->157.5K(456.0B), avg 0.3%, 0.0003057 secs] {Heap before GC invocations=1 (full 0): garbage-first heap total 1048576K, used 59145K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 51 young (52224K), 7 survivors (7168K) Metaspace used 8982K, capacity 9136K, committed 9216K, reserved 1056768K class space used 937K, capacity 979K, committed 1024K, reserved 1048576K 2017-04-02T19:01:31.462+0000: 2.027: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 3670016 bytes, new threshold 1 (max 15) - age 1: 3854576 bytes, 3854576 total 2.027: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 1024, predicted base time: 16.36 ms, remaining time: 183.64 ms, target pause time: 200.00 ms] 2.027: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 44 regions, survivors: 7 regions, predicted young region time: 605.22 ms] 2.027: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 44 regions, survivors: 7 regions, old: 0 regions, predicted pause time: 621.58 ms, target pause time: 200.00 ms] 2017-04-02T19:01:31.468+0000: 2.033: [SoftReference, 0 refs, 0.0013301 secs]2017-04-02T19:01:31.469+0000: 2.034: [WeakReference, 87 refs, 0.0002326 secs]2017-04-02T19:01:31.470+0000: 2.034: [FinalReference, 788 refs, 0.0010104 secs]2017-04-02T19:01:31.471+0000: 2.036: [PhantomReference, 0 refs, 0 refs, 0.0005491 secs]2017-04-02T19:01:31.471+0000: 2.036: [JNI Weak Reference, 0.0000082 secs], 0.0095089 secs] [Parallel Time: 5.1 ms, GC Workers: 4] [GC Worker Start (ms): Min: 2027.5, Avg: 2027.5, Max: 2027.5, Diff: 0.1] [Ext Root Scanning (ms): Min: 0.2, Avg: 0.3, Max: 0.7, Diff: 0.5, Sum: 1.3] [Update RS (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, Sum: 0.6] [Processed Buffers: Min: 0, Avg: 1.0, Max: 2, Diff: 2, Sum: 4] [Scan RS (ms): Min: 0.2, Avg: 0.2, Max: 0.2, Diff: 0.1, Sum: 0.8] [Code Root Scanning (ms): Min: 0.0, Avg: 0.3, Max: 1.0, Diff: 1.0, Sum: 1.1] [Object Copy (ms): Min: 3.1, Avg: 4.0, Max: 4.3, Diff: 1.2, Sum: 15.9] [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: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [GC Worker Total (ms): Min: 4.9, Avg: 4.9, Max: 5.0, Diff: 0.1, Sum: 19.8] [GC Worker End (ms): Min: 2032.4, Avg: 2032.4, Max: 2032.4, Diff: 0.0] [Code Root Fixup: 0.2 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 0.3 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.3] [Table Fixup (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.3] [Clear CT: 0.1 ms] [Other: 3.8 ms] [Choose CSet: 0.0 ms] [Ref Proc: 3.4 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.1 ms] [Eden: 44.0M(44.0M)->0.0B(70.0M) Survivors: 7168.0K->4096.0K Heap: 57.8M(1024.0M)->18.7M(1024.0M)] Heap after GC invocations=2 (full 0): garbage-first heap total 1048576K, used 19186K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 4 young (4096K), 4 survivors (4096K) Metaspace used 8982K, capacity 9136K, committed 9216K, reserved 1056768K class space used 937K, capacity 979K, committed 1024K, reserved 1048576K } [Times: user=0.02 sys=0.01, real=0.01 secs] 2017-04-02T19:01:31.478+0000: 2.043: [GC concurrent-string-deduplication, 1547.1K->409.7K(1137.4K), avg 66.7%, 0.0057287 secs] {Heap before GC invocations=2 (full 0): garbage-first heap total 1048576K, used 90866K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 74 young (75776K), 4 survivors (4096K) Metaspace used 8984K, capacity 9136K, committed 9216K, reserved 1056768K class space used 937K, capacity 979K, committed 1024K, reserved 1048576K 2017-04-02T19:01:31.631+0000: 2.196: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 5242880 bytes, new threshold 15 (max 15) - age 1: 105744 bytes, 105744 total 2.196: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 1032, predicted base time: 18.87 ms, remaining time: 181.13 ms, target pause time: 200.00 ms] 2.196: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 70 regions, survivors: 4 regions, predicted young region time: 329.42 ms] 2.196: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 70 regions, survivors: 4 regions, old: 0 regions, predicted pause time: 348.29 ms, target pause time: 200.00 ms] 2017-04-02T19:01:31.639+0000: 2.204: [SoftReference, 0 refs, 0.0006906 secs]2017-04-02T19:01:31.640+0000: 2.205: [WeakReference, 0 refs, 0.0003675 secs]2017-04-02T19:01:31.640+0000: 2.205: [FinalReference, 205 refs, 0.0021561 secs]2017-04-02T19:01:31.642+0000: 2.207: [PhantomReference, 0 refs, 0 refs, 0.0005309 secs]2017-04-02T19:01:31.643+0000: 2.208: [JNI Weak Reference, 0.0000090 secs], 0.0128468 secs] [Parallel Time: 7.7 ms, GC Workers: 4] [GC Worker Start (ms): Min: 2196.1, Avg: 2197.8, Max: 2202.8, Diff: 6.8] [Ext Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, Sum: 0.8] [Update RS (ms): Min: 0.0, Avg: 0.4, Max: 0.7, Diff: 0.7, Sum: 1.6] [Processed Buffers: Min: 0, Avg: 2.0, Max: 5, Diff: 5, Sum: 8] [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1] [Code Root Scanning (ms): Min: 0.0, Avg: 1.5, Max: 6.2, Diff: 6.2, Sum: 6.2] [Object Copy (ms): Min: 0.0, Avg: 0.1, Max: 0.3, Diff: 0.3, Sum: 0.5] [Termination (ms): Min: 0.0, Avg: 3.1, Max: 6.5, Diff: 6.5, Sum: 12.5] [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4] [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.2, Avg: 5.4, Max: 7.7, Diff: 7.5, Sum: 21.7] [GC Worker End (ms): Min: 2203.0, Avg: 2203.2, Max: 2203.7, Diff: 0.7] [Code Root Fixup: 0.0 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 0.4 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Table Fixup (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, Sum: 0.6] [Clear CT: 0.1 ms] [Other: 4.6 ms] [Choose CSet: 0.0 ms] [Ref Proc: 4.1 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.1 ms] [Eden: 70.0M(70.0M)->0.0B(611.0M) Survivors: 4096.0K->3072.0K Heap: 88.7M(1024.0M)->17.6M(1024.0M)] Heap after GC invocations=3 (full 0): garbage-first heap total 1048576K, used 18067K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 3 young (3072K), 3 survivors (3072K) Metaspace used 8984K, capacity 9136K, committed 9216K, reserved 1056768K class space used 937K, capacity 979K, committed 1024K, reserved 1048576K } [Times: user=0.04 sys=0.01, real=0.01 secs] 4.491: [G1Ergonomics (Concurrent Cycles) request concurrent cycle initiation, reason: requested by GC cause, GC cause: Metadata GC Threshold] {Heap before GC invocations=3 (full 0): garbage-first heap total 1048576K, used 280211K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 260 young (266240K), 3 survivors (3072K) Metaspace used 20883K, capacity 21134K, committed 21296K, reserved 1069056K class space used 2363K, capacity 2417K, committed 2432K, reserved 1048576K 4.491: [G1Ergonomics (Concurrent Cycles) initiate concurrent cycle, reason: concurrent cycle initiation requested] 2017-04-02T19:01:33.926+0000: 4.491: [GC pause (Metadata GC Threshold) (young) (initial-mark) Desired survivor size 40370176 bytes, new threshold 15 (max 15) - age 1: 46880 bytes, 46880 total - age 2: 78432 bytes, 125312 total 4.491: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 1101, predicted base time: 13.86 ms, remaining time: 186.14 ms, target pause time: 200.00 ms] 4.491: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 257 regions, survivors: 3 regions, predicted young region time: 77.19 ms] 4.491: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 257 regions, survivors: 3 regions, old: 0 regions, predicted pause time: 91.05 ms, target pause time: 200.00 ms] 2017-04-02T19:01:33.935+0000: 4.500: [SoftReference, 0 refs, 0.0003376 secs]2017-04-02T19:01:33.935+0000: 4.500: [WeakReference, 359 refs, 0.0003314 secs]2017-04-02T19:01:33.936+0000: 4.501: [FinalReference, 6963 refs, 0.0070528 secs]2017-04-02T19:01:33.943+0000: 4.508: [PhantomReference, 0 refs, 8 refs, 0.0005538 secs]2017-04-02T19:01:33.943+0000: 4.508: [JNI Weak Reference, 0.0000249 secs], 0.0188525 secs] [Parallel Time: 8.8 ms, GC Workers: 4] [GC Worker Start (ms): Min: 4490.8, Avg: 4490.9, Max: 4490.9, Diff: 0.1] [Ext Root Scanning (ms): Min: 1.0, Avg: 1.2, Max: 1.5, Diff: 0.4, Sum: 4.7] [Update RS (ms): Min: 0.0, Avg: 0.2, Max: 0.5, Diff: 0.5, Sum: 0.9] [Processed Buffers: Min: 1, Avg: 3.5, Max: 9, Diff: 8, Sum: 14] [Scan RS (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.3] [Code Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.4, Diff: 0.4, Sum: 0.8] [Object Copy (ms): Min: 6.7, Avg: 7.0, Max: 7.2, Diff: 0.4, Sum: 28.0] [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: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [GC Worker Total (ms): Min: 8.7, Avg: 8.7, Max: 8.7, Diff: 0.0, Sum: 34.9] [GC Worker End (ms): Min: 4499.6, Avg: 4499.6, Max: 4499.6, Diff: 0.0] [Code Root Fixup: 0.1 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 0.5 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Table Fixup (ms): Min: 0.0, Avg: 0.3, Max: 0.4, Diff: 0.4, Sum: 1.1] [Clear CT: 0.1 ms] [Other: 9.2 ms] [Choose CSet: 0.0 ms] [Ref Proc: 8.5 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.2 ms] [Eden: 257.0M(611.0M)->0.0B(538.0M) Survivors: 3072.0K->25.0M Heap: 274.1M(1024.0M)->39.1M(1024.0M)] Heap after GC invocations=4 (full 0): garbage-first heap total 1048576K, used 40063K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 25 young (25600K), 25 survivors (25600K) Metaspace used 20883K, capacity 21134K, committed 21296K, reserved 1069056K class space used 2363K, capacity 2417K, committed 2432K, reserved 1048576K } [Times: user=0.06 sys=0.01, real=0.02 secs] 2017-04-02T19:01:33.945+0000: 4.510: [GC concurrent-root-region-scan-start] 2017-04-02T19:01:33.947+0000: 4.512: [GC concurrent-string-deduplication, 21.6K->10.6K(11.0K), avg 66.5%, 0.0001167 secs] 2017-04-02T19:01:33.963+0000: 4.528: [GC concurrent-root-region-scan-end, 0.0187762 secs] 2017-04-02T19:01:33.963+0000: 4.528: [GC concurrent-mark-start] 2017-04-02T19:01:33.984+0000: 4.548: [GC concurrent-mark-end, 0.0200941 secs] 2017-04-02T19:01:33.987+0000: 4.552: [GC remark 2017-04-02T19:01:33.987+0000: 4.552: [Finalize Marking, 0.0001494 secs] 2017-04-02T19:01:33.987+0000: 4.552: [GC ref-proc2017-04-02T19:01:33.987+0000: 4.552: [SoftReference, 0 refs, 0.0003803 secs]2017-04-02T19:01:33.987+0000: 4.552: [WeakReference, 50 refs, 0.0003205 secs]2017-04-02T19:01:33.988+0000: 4.553: [FinalReference, 165 refs, 0.0002585 secs]2017-04-02T19:01:33.988+0000: 4.553: [PhantomReference, 0 refs, 0 refs, 0.0029956 secs]2017-04-02T19:01:33.991+0000: 4.556: [JNI Weak Reference, 0.0000425 secs], 0.0041375 secs] 2017-04-02T19:01:33.991+0000: 4.556: [Unloading, 0.0039555 secs], 0.0085159 secs] [Times: user=0.02 sys=0.00, real=0.01 secs] 2017-04-02T19:01:33.996+0000: 4.561: [GC cleanup 50M->50M(1024M), 0.0010376 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] 7.599: [G1Ergonomics (Concurrent Cycles) request concurrent cycle initiation, reason: requested by GC cause, GC cause: Metadata GC Threshold] {Heap before GC invocations=5 (full 0): garbage-first heap total 1048576K, used 537727K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 512 young (524288K), 25 survivors (25600K) Metaspace used 32488K, capacity 35886K, committed 35920K, reserved 1079296K class space used 4235K, capacity 5229K, committed 5248K, reserved 1048576K 7.599: [G1Ergonomics (Concurrent Cycles) initiate concurrent cycle, reason: concurrent cycle initiation requested] 2017-04-02T19:01:37.034+0000: 7.599: [GC pause (Metadata GC Threshold) (young) (initial-mark) Desired survivor size 37224448 bytes, new threshold 15 (max 15) - age 1: 6186200 bytes, 6186200 total - age 2: 18664 bytes, 6204864 total - age 3: 78392 bytes, 6283256 total 7.599: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 1189, predicted base time: 13.44 ms, remaining time: 186.56 ms, target pause time: 200.00 ms] 7.599: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 487 regions, survivors: 25 regions, predicted young region time: 259.11 ms] 7.599: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 487 regions, survivors: 25 regions, old: 0 regions, predicted pause time: 272.55 ms, target pause time: 200.00 ms] 2017-04-02T19:01:37.069+0000: 7.634: [SoftReference, 0 refs, 0.0005745 secs]2017-04-02T19:01:37.070+0000: 7.635: [WeakReference, 744 refs, 0.0003309 secs]2017-04-02T19:01:37.070+0000: 7.635: [FinalReference, 6000 refs, 0.0025816 secs]2017-04-02T19:01:37.073+0000: 7.638: [PhantomReference, 0 refs, 7 refs, 0.0007175 secs]2017-04-02T19:01:37.073+0000: 7.638: [JNI Weak Reference, 0.0000308 secs] 7.640: [G1Ergonomics (Mixed GCs) do not start mixed GCs, reason: concurrent cycle is about to start] , 0.0409887 secs] [Parallel Time: 33.9 ms, GC Workers: 4] [GC Worker Start (ms): Min: 7599.6, Avg: 7599.7, Max: 7600.1, Diff: 0.6] [Ext Root Scanning (ms): Min: 2.4, Avg: 2.9, Max: 3.4, Diff: 0.9, Sum: 11.8] [Update RS (ms): Min: 0.0, Avg: 0.3, Max: 0.6, Diff: 0.6, Sum: 1.3] [Processed Buffers: Min: 0, Avg: 3.5, Max: 8, Diff: 8, Sum: 14] [Scan RS (ms): Min: 0.1, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.5] [Code Root Scanning (ms): Min: 0.2, Avg: 3.4, Max: 12.1, Diff: 11.9, Sum: 13.5] [Object Copy (ms): Min: 17.6, Avg: 26.8, Max: 30.2, Diff: 12.6, Sum: 107.1] [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.3] [Termination Attempts: Min: 1, Avg: 1.5, Max: 2, Diff: 1, Sum: 6] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.1] [GC Worker Total (ms): Min: 33.2, Avg: 33.7, Max: 33.8, Diff: 0.6, Sum: 134.6] [GC Worker End (ms): Min: 7633.4, Avg: 7633.4, Max: 7633.4, Diff: 0.0] [Code Root Fixup: 0.4 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 0.9 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Table Fixup (ms): Min: 0.0, Avg: 0.5, Max: 0.7, Diff: 0.7, Sum: 2.0] [Clear CT: 0.2 ms] [Other: 5.5 ms] [Choose CSet: 0.0 ms] [Ref Proc: 4.4 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.4 ms] [Eden: 487.0M(538.0M)->0.0B(411.0M) Survivors: 25.0M->40.0M Heap: 526.0M(1024.0M)->54.2M(1024.0M)] Heap after GC invocations=6 (full 0): garbage-first heap total 1048576K, used 55538K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 40 young (40960K), 40 survivors (40960K) Metaspace used 32488K, capacity 35886K, committed 35920K, reserved 1079296K class space used 4235K, capacity 5229K, committed 5248K, reserved 1048576K } [Times: user=0.15 sys=0.00, real=0.04 secs] 2017-04-02T19:01:37.075+0000: 7.640: [GC concurrent-root-region-scan-start] 2017-04-02T19:01:37.080+0000: 7.645: [GC concurrent-string-deduplication, 5320.0B->2568.0B(2752.0B), avg 66.5%, 0.0000315 secs] 2017-04-02T19:01:37.111+0000: 7.676: [GC concurrent-root-region-scan-end, 0.0355510 secs] 2017-04-02T19:01:37.111+0000: 7.676: [GC concurrent-mark-start] 2017-04-02T19:01:37.123+0000: 7.688: [GC concurrent-mark-end, 0.0122776 secs] 2017-04-02T19:01:37.123+0000: 7.688: [GC remark 2017-04-02T19:01:37.123+0000: 7.688: [Finalize Marking, 0.0002549 secs] 2017-04-02T19:01:37.124+0000: 7.689: [GC ref-proc2017-04-02T19:01:37.124+0000: 7.689: [SoftReference, 0 refs, 0.0005850 secs]2017-04-02T19:01:37.124+0000: 7.689: [WeakReference, 66 refs, 0.0003790 secs]2017-04-02T19:01:37.125+0000: 7.690: [FinalReference, 155 refs, 0.0004323 secs]2017-04-02T19:01:37.125+0000: 7.690: [PhantomReference, 0 refs, 0 refs, 0.0008588 secs]2017-04-02T19:01:37.126+0000: 7.691: [JNI Weak Reference, 0.0000220 secs], 0.0024387 secs] 2017-04-02T19:01:37.126+0000: 7.691: [Unloading, 0.0075145 secs], 0.0105306 secs] [Times: user=0.04 sys=0.00, real=0.01 secs] 2017-04-02T19:01:37.134+0000: 7.699: [GC cleanup 59M->59M(1024M), 0.0013311 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] {Heap before GC invocations=7 (full 0): garbage-first heap total 1048576K, used 476402K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 451 young (461824K), 40 survivors (40960K) Metaspace used 37505K, capacity 42030K, committed 42192K, reserved 1085440K class space used 5044K, capacity 6385K, committed 6400K, reserved 1048576K 2017-04-02T19:01:38.477+0000: 9.042: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 29884416 bytes, new threshold 2 (max 15) - age 1: 24135928 bytes, 24135928 total - age 2: 5826408 bytes, 29962336 total - age 3: 18224 bytes, 29980560 total - age 4: 64344 bytes, 30044904 total 9.042: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 1294, predicted base time: 14.51 ms, remaining time: 185.49 ms, target pause time: 200.00 ms] 9.042: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 411 regions, survivors: 40 regions, predicted young region time: 137.70 ms] 9.042: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 411 regions, survivors: 40 regions, old: 0 regions, predicted pause time: 152.21 ms, target pause time: 200.00 ms] 2017-04-02T19:01:38.515+0000: 9.080: [SoftReference, 0 refs, 0.0005437 secs]2017-04-02T19:01:38.516+0000: 9.080: [WeakReference, 680 refs, 0.0001662 secs]2017-04-02T19:01:38.516+0000: 9.081: [FinalReference, 3593 refs, 0.0009691 secs]2017-04-02T19:01:38.517+0000: 9.082: [PhantomReference, 0 refs, 8 refs, 0.0005235 secs]2017-04-02T19:01:38.517+0000: 9.082: [JNI Weak Reference, 0.0000185 secs] 9.084: [G1Ergonomics (Mixed GCs) do not start mixed GCs, reason: reclaimable percentage not over threshold, candidate old regions: 14 regions, reclaimable: 11730256 bytes (1.09 %), threshold: 5.00 %] , 0.0417236 secs] [Parallel Time: 37.2 ms, GC Workers: 4] [GC Worker Start (ms): Min: 9042.2, Avg: 9043.6, Max: 9046.4, Diff: 4.2] [Ext Root Scanning (ms): Min: 0.0, Avg: 1.5, Max: 3.6, Diff: 3.6, Sum: 6.0] [Update RS (ms): Min: 0.0, Avg: 0.3, Max: 0.6, Diff: 0.6, Sum: 1.2] [Processed Buffers: Min: 0, Avg: 2.0, Max: 5, Diff: 5, Sum: 8] [Scan RS (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.5] [Code Root Scanning (ms): Min: 0.0, Avg: 2.8, Max: 9.9, Diff: 9.9, Sum: 11.2] [Object Copy (ms): Min: 23.0, Avg: 30.8, Max: 34.2, Diff: 11.2, Sum: 123.4] [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: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.2] [GC Worker Total (ms): Min: 32.8, Avg: 35.6, Max: 37.1, Diff: 4.2, Sum: 142.5] [GC Worker End (ms): Min: 9079.2, Avg: 9079.3, Max: 9079.3, Diff: 0.1] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 0.8 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.0, Sum: 0.2] [Table Fixup (ms): Min: 0.7, Avg: 0.7, Max: 0.7, Diff: 0.0, Sum: 2.7] [Clear CT: 0.1 ms] [Other: 3.2 ms] [Choose CSet: 0.0 ms] [Ref Proc: 2.5 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.4 ms] [Eden: 411.0M(411.0M)->0.0B(407.0M) Survivors: 40.0M->36.0M Heap: 465.2M(1024.0M)->56.4M(1024.0M)] Heap after GC invocations=8 (full 0): garbage-first heap total 1048576K, used 57803K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 36 young (36864K), 36 survivors (36864K) Metaspace used 37505K, capacity 42030K, committed 42192K, reserved 1085440K class space used 5044K, capacity 6385K, committed 6400K, reserved 1048576K } [Times: user=0.15 sys=0.00, real=0.05 secs] 2017-04-02T19:01:38.523+0000: 9.087: [GC concurrent-string-deduplication, 1088.4K->809.0K(279.4K), avg 50.7%, 0.0035482 secs] {Heap before GC invocations=8 (full 0): garbage-first heap total 1048576K, used 456139K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 425 young (435200K), 36 survivors (36864K) Metaspace used 48405K, capacity 55072K, committed 55248K, reserved 1097728K class space used 5829K, capacity 7584K, committed 7680K, reserved 1048576K 2017-04-02T19:01:40.846+0000: 11.410: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 28311552 bytes, new threshold 2 (max 15) - age 1: 7230328 bytes, 7230328 total - age 2: 23699768 bytes, 30930096 total 11.410: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 2238, predicted base time: 14.79 ms, remaining time: 185.21 ms, target pause time: 200.00 ms] 11.410: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 389 regions, survivors: 36 regions, predicted young region time: 174.19 ms] 11.410: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 389 regions, survivors: 36 regions, old: 0 regions, predicted pause time: 188.97 ms, target pause time: 200.00 ms] 2017-04-02T19:01:40.879+0000: 11.444: [SoftReference, 0 refs, 0.0004029 secs]2017-04-02T19:01:40.880+0000: 11.445: [WeakReference, 552 refs, 0.0002268 secs]2017-04-02T19:01:40.880+0000: 11.445: [FinalReference, 1552 refs, 0.0007621 secs]2017-04-02T19:01:40.881+0000: 11.446: [PhantomReference, 0 refs, 0 refs, 0.0005051 secs]2017-04-02T19:01:40.881+0000: 11.446: [JNI Weak Reference, 0.0000107 secs], 0.0379459 secs] [Parallel Time: 33.0 ms, GC Workers: 4] [GC Worker Start (ms): Min: 11410.6, Avg: 11412.0, Max: 11415.8, Diff: 5.3] [Ext Root Scanning (ms): Min: 0.0, Avg: 1.4, Max: 3.4, Diff: 3.4, Sum: 5.7] [Update RS (ms): Min: 0.0, Avg: 0.8, Max: 1.4, Diff: 1.4, Sum: 3.1] [Processed Buffers: Min: 0, Avg: 3.2, Max: 6, Diff: 6, Sum: 13] [Scan RS (ms): Min: 0.0, Avg: 0.8, Max: 1.1, Diff: 1.1, Sum: 3.1] [Code Root Scanning (ms): Min: 0.0, Avg: 1.3, Max: 4.3, Diff: 4.3, Sum: 5.2] [Object Copy (ms): Min: 24.7, Avg: 27.1, Max: 28.6, Diff: 3.9, Sum: 108.3] [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: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.2] [GC Worker Total (ms): Min: 27.6, Avg: 31.4, Max: 32.9, Diff: 5.3, Sum: 125.7] [GC Worker End (ms): Min: 11443.4, Avg: 11443.5, Max: 11443.5, Diff: 0.0] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 1.4 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, Sum: 0.7] [Table Fixup (ms): Min: 0.0, Avg: 0.7, Max: 1.0, Diff: 1.0, Sum: 2.7] [Clear CT: 0.1 ms] [Other: 3.2 ms] [Choose CSet: 0.0 ms] [Ref Proc: 2.4 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.3 ms] [Eden: 389.0M(389.0M)->0.0B(596.0M) Survivors: 36.0M->18.0M Heap: 445.4M(1024.0M)->63.0M(1024.0M)] Heap after GC invocations=9 (full 0): garbage-first heap total 1048576K, used 64511K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 18 young (18432K), 18 survivors (18432K) Metaspace used 48405K, capacity 55072K, committed 55248K, reserved 1097728K class space used 5829K, capacity 7584K, committed 7680K, reserved 1048576K } [Times: user=0.13 sys=0.00, real=0.04 secs] 2017-04-02T19:01:40.960+0000: 11.525: [GC concurrent-string-deduplication, 11.3M->9647.3K(1929.8K), avg 23.3%, 0.0734806 secs] 12.030: [G1Ergonomics (Concurrent Cycles) request concurrent cycle initiation, reason: requested by GC cause, GC cause: Metadata GC Threshold] {Heap before GC invocations=9 (full 0): garbage-first heap total 1048576K, used 185343K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 137 young (140288K), 18 survivors (18432K) Metaspace used 52257K, capacity 60200K, committed 60296K, reserved 1101824K class space used 6084K, capacity 8156K, committed 8192K, reserved 1048576K 12.030: [G1Ergonomics (Concurrent Cycles) initiate concurrent cycle, reason: concurrent cycle initiation requested] 2017-04-02T19:01:41.465+0000: 12.030: [GC pause (Metadata GC Threshold) (young) (initial-mark) Desired survivor size 32505856 bytes, new threshold 15 (max 15) - age 1: 5738368 bytes, 5738368 total - age 2: 7058296 bytes, 12796664 total 12.030: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 3203, predicted base time: 14.17 ms, remaining time: 185.83 ms, target pause time: 200.00 ms] 12.030: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 119 regions, survivors: 18 regions, predicted young region time: 99.51 ms] 12.030: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 119 regions, survivors: 18 regions, old: 0 regions, predicted pause time: 113.68 ms, target pause time: 200.00 ms] 2017-04-02T19:01:41.489+0000: 12.054: [SoftReference, 0 refs, 0.0004629 secs]2017-04-02T19:01:41.489+0000: 12.054: [WeakReference, 74 refs, 0.0003009 secs]2017-04-02T19:01:41.490+0000: 12.055: [FinalReference, 63 refs, 0.0003354 secs]2017-04-02T19:01:41.490+0000: 12.055: [PhantomReference, 0 refs, 0 refs, 0.0006202 secs]2017-04-02T19:01:41.491+0000: 12.055: [JNI Weak Reference, 0.0000153 secs], 0.0298828 secs] [Parallel Time: 17.0 ms, GC Workers: 4] [GC Worker Start (ms): Min: 12030.1, Avg: 12030.1, Max: 12030.1, Diff: 0.0] [Ext Root Scanning (ms): Min: 1.1, Avg: 1.3, Max: 1.5, Diff: 0.4, Sum: 5.4] [Update RS (ms): Min: 1.1, Avg: 2.3, Max: 3.8, Diff: 2.8, Sum: 9.3] [Processed Buffers: Min: 3, Avg: 4.0, Max: 6, Diff: 3, Sum: 16] [Scan RS (ms): Min: 0.0, Avg: 1.1, Max: 2.1, Diff: 2.1, Sum: 4.2] [Code Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.5, Diff: 0.5, Sum: 0.8] [Object Copy (ms): Min: 11.8, Avg: 12.0, Max: 12.2, Diff: 0.4, Sum: 48.0] [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: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [GC Worker Total (ms): Min: 16.9, Avg: 16.9, Max: 17.0, Diff: 0.0, Sum: 67.7] [GC Worker End (ms): Min: 12047.0, Avg: 12047.0, Max: 12047.0, Diff: 0.0] [Code Root Fixup: 0.2 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 3.5 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1] [Table Fixup (ms): Min: 0.0, Avg: 1.5, Max: 3.0, Diff: 3.0, Sum: 5.9] [Clear CT: 0.2 ms] [Other: 9.0 ms] [Choose CSet: 0.0 ms] [Ref Proc: 8.2 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.2 ms] [Eden: 119.0M(474.0M)->0.0B(597.0M) Survivors: 18.0M->17.0M Heap: 181.5M(1024.0M)->62.0M(1024.0M)] Heap after GC invocations=10 (full 0): garbage-first heap total 1048576K, used 63487K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 17 young (17408K), 17 survivors (17408K) Metaspace used 52257K, capacity 60200K, committed 60296K, reserved 1101824K class space used 6084K, capacity 8156K, committed 8192K, reserved 1048576K } [Times: user=0.10 sys=0.00, real=0.03 secs] 2017-04-02T19:01:41.495+0000: 12.060: [GC concurrent-root-region-scan-start] 2017-04-02T19:01:41.504+0000: 12.069: [GC concurrent-string-deduplication, 869.4K->145.0K(724.4K), avg 26.8%, 0.0048172 secs] 2017-04-02T19:01:41.517+0000: 12.082: [GC concurrent-root-region-scan-end, 0.0216403 secs] 2017-04-02T19:01:41.517+0000: 12.082: [GC concurrent-mark-start] 12.127: [G1Ergonomics (Concurrent Cycles) do not request concurrent cycle initiation, reason: concurrent cycle already in progress, GC cause: Metadata GC Threshold] 12.179: [G1Ergonomics (Concurrent Cycles) do not request concurrent cycle initiation, reason: concurrent cycle already in progress, GC cause: Metadata GC Threshold] 2017-04-02T19:01:41.621+0000: 12.186: [GC concurrent-mark-end, 0.1042042 secs] 2017-04-02T19:01:41.621+0000: 12.186: [GC remark 2017-04-02T19:01:41.621+0000: 12.186: [Finalize Marking, 0.0003022 secs] 2017-04-02T19:01:41.621+0000: 12.186: [GC ref-proc2017-04-02T19:01:41.621+0000: 12.186: [SoftReference, 0 refs, 0.0005079 secs]2017-04-02T19:01:41.622+0000: 12.187: [WeakReference, 547 refs, 0.0005428 secs]2017-04-02T19:01:41.622+0000: 12.187: [FinalReference, 526 refs, 0.0004271 secs]2017-04-02T19:01:41.623+0000: 12.188: [PhantomReference, 0 refs, 8 refs, 0.0007477 secs]2017-04-02T19:01:41.624+0000: 12.189: [JNI Weak Reference, 0.0000341 secs], 0.0024030 secs] 2017-04-02T19:01:41.624+0000: 12.189: [Unloading, 0.0158667 secs], 0.0191253 secs] [Times: user=0.07 sys=0.00, real=0.02 secs] 2017-04-02T19:01:41.640+0000: 12.205: [GC cleanup 82M->82M(1024M), 0.0016454 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] {Heap before GC invocations=11 (full 0): garbage-first heap total 1048576K, used 676906K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 614 young (628736K), 17 survivors (17408K) Metaspace used 71576K, capacity 81334K, committed 81436K, reserved 1120256K class space used 8189K, capacity 10794K, committed 10828K, reserved 1048576K 16.292: [G1Ergonomics (Concurrent Cycles) initiate concurrent cycle, reason: concurrent cycle initiation requested] 2017-04-02T19:01:45.727+0000: 16.292: [GC pause (G1 Evacuation Pause) (young) (initial-mark) Desired survivor size 40370176 bytes, new threshold 15 (max 15) - age 1: 1065208 bytes, 1065208 total - age 2: 5641888 bytes, 6707096 total - age 3: 7056952 bytes, 13764048 total 16.292: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 3083, predicted base time: 15.37 ms, remaining time: 184.63 ms, target pause time: 200.00 ms] 16.293: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 597 regions, survivors: 17 regions, predicted young region time: 125.07 ms] 16.293: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 597 regions, survivors: 17 regions, old: 0 regions, predicted pause time: 140.44 ms, target pause time: 200.00 ms] 2017-04-02T19:01:45.785+0000: 16.350: [SoftReference, 0 refs, 0.0004206 secs]2017-04-02T19:01:45.785+0000: 16.350: [WeakReference, 2478 refs, 0.0003325 secs]2017-04-02T19:01:45.785+0000: 16.350: [FinalReference, 5925 refs, 0.0020861 secs]2017-04-02T19:01:45.788+0000: 16.352: [PhantomReference, 0 refs, 2 refs, 0.0004656 secs]2017-04-02T19:01:45.788+0000: 16.353: [JNI Weak Reference, 0.0000211 secs] 16.356: [G1Ergonomics (Mixed GCs) do not start mixed GCs, reason: concurrent cycle is about to start] , 0.0640093 secs] [Parallel Time: 56.5 ms, GC Workers: 4] [GC Worker Start (ms): Min: 16292.7, Avg: 16293.4, Max: 16294.1, Diff: 1.5] [Ext Root Scanning (ms): Min: 12.6, Avg: 16.6, Max: 23.1, Diff: 10.5, Sum: 66.2] [Update RS (ms): Min: 0.0, Avg: 4.4, Max: 15.1, Diff: 15.1, Sum: 17.8] [Processed Buffers: Min: 0, Avg: 8.8, Max: 23, Diff: 23, Sum: 35] [Scan RS (ms): Min: 0.0, Avg: 1.1, Max: 2.3, Diff: 2.2, Sum: 4.4] [Code Root Scanning (ms): Min: 0.0, Avg: 0.3, Max: 0.9, Diff: 0.9, Sum: 1.4] [Object Copy (ms): Min: 27.1, Avg: 33.1, Max: 37.5, Diff: 10.4, Sum: 132.3] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Termination Attempts: Min: 1, Avg: 1.8, Max: 3, Diff: 2, Sum: 7] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.2] [GC Worker Total (ms): Min: 54.8, Avg: 55.6, Max: 56.3, Diff: 1.5, Sum: 222.3] [GC Worker End (ms): Min: 16348.9, Avg: 16349.0, Max: 16349.0, Diff: 0.0] [Code Root Fixup: 0.2 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 2.3 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [Table Fixup (ms): Min: 0.0, Avg: 1.6, Max: 2.2, Diff: 2.2, Sum: 6.5] [Clear CT: 0.2 ms] [Other: 4.8 ms] [Choose CSet: 0.0 ms] [Ref Proc: 3.6 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.5 ms] [Eden: 597.0M(597.0M)->0.0B(569.0M) Survivors: 17.0M->45.0M Heap: 661.0M(1024.0M)->90.0M(1024.0M)] Heap after GC invocations=12 (full 0): garbage-first heap total 1048576K, used 92159K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 45 young (46080K), 45 survivors (46080K) Metaspace used 71576K, capacity 81334K, committed 81436K, reserved 1120256K class space used 8189K, capacity 10794K, committed 10828K, reserved 1048576K } [Times: user=0.21 sys=0.00, real=0.07 secs] 2017-04-02T19:01:45.792+0000: 16.356: [GC concurrent-root-region-scan-start] 2017-04-02T19:01:45.798+0000: 16.363: [GC concurrent-string-deduplication, 563.5K->236.1K(327.4K), avg 27.9%, 0.0030252 secs] 2017-04-02T19:01:45.841+0000: 16.406: [GC concurrent-root-region-scan-end, 0.0491290 secs] 2017-04-02T19:01:45.841+0000: 16.406: [GC concurrent-mark-start] 2017-04-02T19:01:46.295+0000: 16.859: [GC concurrent-mark-end, 0.4539000 secs] 2017-04-02T19:01:46.302+0000: 16.867: [GC remark 2017-04-02T19:01:46.302+0000: 16.867: [Finalize Marking, 0.0002570 secs] 2017-04-02T19:01:46.302+0000: 16.867: [GC ref-proc2017-04-02T19:01:46.302+0000: 16.867: [SoftReference, 0 refs, 0.0007255 secs]2017-04-02T19:01:46.303+0000: 16.868: [WeakReference, 591 refs, 0.0005397 secs]2017-04-02T19:01:46.303+0000: 16.868: [FinalReference, 372 refs, 0.0005101 secs]2017-04-02T19:01:46.304+0000: 16.869: [PhantomReference, 0 refs, 8 refs, 0.0028356 secs]2017-04-02T19:01:46.307+0000: 16.872: [JNI Weak Reference, 0.0000459 secs], 0.0048254 secs] 2017-04-02T19:01:46.307+0000: 16.872: [Unloading, 0.0137965 secs], 0.0193168 secs] [Times: user=0.07 sys=0.00, real=0.02 secs] 2017-04-02T19:01:46.353+0000: 16.917: [GC cleanup 149M->149M(1024M), 0.0013125 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] {Heap before GC invocations=13 (full 0): garbage-first heap total 1048576K, used 703962K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 614 young (628736K), 45 survivors (46080K) Metaspace used 79466K, capacity 89500K, committed 89756K, reserved 1126400K class space used 9176K, capacity 11861K, committed 11980K, reserved 1048576K 2017-04-02T19:01:51.926+0000: 22.491: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 40370176 bytes, new threshold 15 (max 15) - age 1: 17893016 bytes, 17893016 total - age 2: 1043976 bytes, 18936992 total - age 3: 5534176 bytes, 24471168 total - age 4: 6299920 bytes, 30771088 total 22.491: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 4258, predicted base time: 23.11 ms, remaining time: 176.89 ms, target pause time: 200.00 ms] 22.491: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 569 regions, survivors: 45 regions, predicted young region time: 135.97 ms] 22.491: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 569 regions, survivors: 45 regions, old: 0 regions, predicted pause time: 159.08 ms, target pause time: 200.00 ms] 2017-04-02T19:01:51.981+0000: 22.546: [SoftReference, 0 refs, 0.0005173 secs]2017-04-02T19:01:51.981+0000: 22.546: [WeakReference, 4582 refs, 0.0004361 secs]2017-04-02T19:01:51.982+0000: 22.547: [FinalReference, 6444 refs, 0.0025076 secs]2017-04-02T19:01:51.984+0000: 22.549: [PhantomReference, 0 refs, 14 refs, 0.0006071 secs]2017-04-02T19:01:51.985+0000: 22.550: [JNI Weak Reference, 0.0000173 secs] 22.554: [G1Ergonomics (Mixed GCs) do not start mixed GCs, reason: reclaimable percentage not over threshold, candidate old regions: 24 regions, reclaimable: 16067512 bytes (1.50 %), threshold: 5.00 %] , 0.0637661 secs] [Parallel Time: 54.2 ms, GC Workers: 4] [GC Worker Start (ms): Min: 22491.0, Avg: 22491.2, Max: 22491.5, Diff: 0.5] [Ext Root Scanning (ms): Min: 7.4, Avg: 8.5, Max: 9.7, Diff: 2.3, Sum: 34.1] [Update RS (ms): Min: 1.6, Avg: 1.7, Max: 1.8, Diff: 0.1, Sum: 6.7] [Processed Buffers: Min: 8, Avg: 11.8, Max: 18, Diff: 10, Sum: 47] [Scan RS (ms): Min: 1.8, Avg: 1.9, Max: 2.2, Diff: 0.4, Sum: 7.7] [Code Root Scanning (ms): Min: 0.1, Avg: 0.5, Max: 0.7, Diff: 0.5, Sum: 1.8] [Object Copy (ms): Min: 40.3, Avg: 41.2, Max: 42.0, Diff: 1.7, Sum: 165.0] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Termination Attempts: Min: 1, Avg: 7.8, Max: 12, Diff: 11, Sum: 31] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.2] [GC Worker Total (ms): Min: 53.6, Avg: 53.9, Max: 54.1, Diff: 0.5, Sum: 215.6] [GC Worker End (ms): Min: 22545.1, Avg: 22545.1, Max: 22545.1, Diff: 0.0] [Code Root Fixup: 0.4 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 3.3 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Table Fixup (ms): Min: 2.3, Avg: 2.8, Max: 3.3, Diff: 0.9, Sum: 11.4] [Clear CT: 0.3 ms] [Other: 5.5 ms] [Choose CSet: 0.0 ms] [Ref Proc: 4.3 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.1 ms] [Free CSet: 0.5 ms] [Eden: 569.0M(569.0M)->0.0B(558.0M) Survivors: 45.0M->56.0M Heap: 687.5M(1024.0M)->114.2M(1024.0M)] Heap after GC invocations=14 (full 0): garbage-first heap total 1048576K, used 116960K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 56 young (57344K), 56 survivors (57344K) Metaspace used 79466K, capacity 89500K, committed 89756K, reserved 1126400K class space used 9176K, capacity 11861K, committed 11980K, reserved 1048576K } [Times: user=0.21 sys=0.02, real=0.06 secs] 2017-04-02T19:01:51.996+0000: 22.560: [GC concurrent-string-deduplication, 181.6K->105.0K(76.7K), avg 28.0%, 0.0006814 secs] {Heap before GC invocations=14 (full 0): garbage-first heap total 1048576K, used 743861K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 614 young (628736K), 56 survivors (57344K) Metaspace used 82869K, capacity 94356K, committed 94620K, reserved 1130496K class space used 9594K, capacity 12726K, committed 12748K, reserved 1048576K 2017-04-02T19:01:55.660+0000: 26.225: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 40370176 bytes, new threshold 4 (max 15) - age 1: 19463744 bytes, 19463744 total - age 2: 16057056 bytes, 35520800 total - age 3: 1043768 bytes, 36564568 total - age 4: 5194888 bytes, 41759456 total - age 5: 6293768 bytes, 48053224 total 26.225: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 3617, predicted base time: 22.20 ms, remaining time: 177.80 ms, target pause time: 200.00 ms] 26.225: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 558 regions, survivors: 56 regions, predicted young region time: 124.95 ms] 26.225: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 558 regions, survivors: 56 regions, old: 0 regions, predicted pause time: 147.15 ms, target pause time: 200.00 ms] 2017-04-02T19:01:55.730+0000: 26.295: [SoftReference, 0 refs, 0.0004842 secs]2017-04-02T19:01:55.731+0000: 26.295: [WeakReference, 7693 refs, 0.0010393 secs]2017-04-02T19:01:55.732+0000: 26.296: [FinalReference, 3880 refs, 0.0010351 secs]2017-04-02T19:01:55.733+0000: 26.298: [PhantomReference, 53 refs, 32 refs, 0.0004863 secs]2017-04-02T19:01:55.733+0000: 26.298: [JNI Weak Reference, 0.0000225 secs], 0.0771692 secs] [Parallel Time: 69.4 ms, GC Workers: 4] [GC Worker Start (ms): Min: 26224.8, Avg: 26224.8, Max: 26224.8, Diff: 0.1] [Ext Root Scanning (ms): Min: 4.1, Avg: 4.9, Max: 5.5, Diff: 1.4, Sum: 19.4] [Update RS (ms): Min: 1.5, Avg: 1.7, Max: 1.9, Diff: 0.3, Sum: 7.0] [Processed Buffers: Min: 7, Avg: 10.2, Max: 13, Diff: 6, Sum: 41] [Scan RS (ms): Min: 1.5, Avg: 1.7, Max: 2.0, Diff: 0.5, Sum: 6.8] [Code Root Scanning (ms): Min: 0.2, Avg: 0.7, Max: 1.1, Diff: 1.0, Sum: 2.7] [Object Copy (ms): Min: 59.7, Avg: 60.3, Max: 61.3, Diff: 1.5, Sum: 241.3] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Termination Attempts: Min: 1, Avg: 5.2, Max: 8, Diff: 7, Sum: 21] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.2] [GC Worker Total (ms): Min: 69.3, Avg: 69.4, Max: 69.4, Diff: 0.1, Sum: 277.4] [GC Worker End (ms): Min: 26294.1, Avg: 26294.2, Max: 26294.2, Diff: 0.1] [Code Root Fixup: 0.5 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 2.5 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.3] [Table Fixup (ms): Min: 2.2, Avg: 2.3, Max: 2.4, Diff: 0.1, Sum: 9.2] [Clear CT: 0.2 ms] [Other: 4.5 ms] [Choose CSet: 0.0 ms] [Ref Proc: 3.3 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.1 ms] [Free CSet: 0.5 ms] [Eden: 558.0M(558.0M)->0.0B(550.0M) Survivors: 56.0M->64.0M Heap: 726.4M(1024.0M)->153.1M(1024.0M)] Heap after GC invocations=15 (full 0): garbage-first heap total 1048576K, used 156802K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 64 young (65536K), 64 survivors (65536K) Metaspace used 82869K, capacity 94356K, committed 94620K, reserved 1130496K class space used 9594K, capacity 12726K, committed 12748K, reserved 1048576K } [Times: user=0.30 sys=0.00, real=0.07 secs] 2017-04-02T19:01:55.745+0000: 26.310: [GC concurrent-string-deduplication, 2056.9K->1090.4K(966.5K), avg 30.2%, 0.0079895 secs] {Heap before GC invocations=15 (full 0): garbage-first heap total 1048576K, used 718042K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 597 young (611328K), 64 survivors (65536K) Metaspace used 84601K, capacity 96542K, committed 96796K, reserved 1132544K class space used 9793K, capacity 13031K, committed 13132K, reserved 1048576K 2017-04-02T19:01:58.367+0000: 28.932: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 39321600 bytes, new threshold 2 (max 15) - age 1: 24431992 bytes, 24431992 total - age 2: 17065168 bytes, 41497160 total - age 3: 16020656 bytes, 57517816 total - age 4: 964960 bytes, 58482776 total 28.932: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 4982, predicted base time: 21.68 ms, remaining time: 178.32 ms, target pause time: 200.00 ms] 28.932: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 533 regions, survivors: 64 regions, predicted young region time: 159.67 ms] 28.932: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 533 regions, survivors: 64 regions, old: 0 regions, predicted pause time: 181.35 ms, target pause time: 200.00 ms] 2017-04-02T19:01:58.441+0000: 29.006: [SoftReference, 0 refs, 0.0007001 secs]2017-04-02T19:01:58.442+0000: 29.007: [WeakReference, 8045 refs, 0.0010612 secs]2017-04-02T19:01:58.443+0000: 29.008: [FinalReference, 2150 refs, 0.0007128 secs]2017-04-02T19:01:58.444+0000: 29.009: [PhantomReference, 46 refs, 40 refs, 0.0005474 secs]2017-04-02T19:01:58.444+0000: 29.009: [JNI Weak Reference, 0.0000152 secs], 0.0820512 secs] [Parallel Time: 73.5 ms, GC Workers: 4] [GC Worker Start (ms): Min: 28931.8, Avg: 28931.9, Max: 28932.0, Diff: 0.2] [Ext Root Scanning (ms): Min: 2.0, Avg: 3.9, Max: 5.3, Diff: 3.4, Sum: 15.5] [Update RS (ms): Min: 1.0, Avg: 2.6, Max: 3.1, Diff: 2.2, Sum: 10.3] [Processed Buffers: Min: 6, Avg: 11.0, Max: 16, Diff: 10, Sum: 44] [Scan RS (ms): Min: 4.3, Avg: 4.8, Max: 5.2, Diff: 0.9, Sum: 19.0] [Code Root Scanning (ms): Min: 0.1, Avg: 0.5, Max: 0.8, Diff: 0.6, Sum: 2.0] [Object Copy (ms): Min: 59.7, Avg: 61.6, Max: 63.1, Diff: 3.4, Sum: 246.4] [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: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [GC Worker Total (ms): Min: 73.2, Avg: 73.3, Max: 73.4, Diff: 0.2, Sum: 293.4] [GC Worker End (ms): Min: 29005.2, Avg: 29005.2, Max: 29005.3, Diff: 0.0] [Code Root Fixup: 0.4 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 3.2 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.4] [Table Fixup (ms): Min: 0.4, Avg: 2.3, Max: 3.0, Diff: 2.6, Sum: 9.0] [Clear CT: 0.2 ms] [Other: 4.7 ms] [Choose CSet: 0.0 ms] [Ref Proc: 3.3 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.2 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.1 ms] [Free CSet: 0.6 ms] [Eden: 533.0M(533.0M)->0.0B(576.0M) Survivors: 64.0M->38.0M Heap: 701.2M(1024.0M)->164.3M(1024.0M)] Heap after GC invocations=16 (full 0): garbage-first heap total 1048576K, used 168214K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 38 young (38912K), 38 survivors (38912K) Metaspace used 84601K, capacity 96542K, committed 96796K, reserved 1132544K class space used 9793K, capacity 13031K, committed 13132K, reserved 1048576K } [Times: user=0.27 sys=0.01, real=0.08 secs] 2017-04-02T19:01:58.574+0000: 29.139: [GC concurrent-string-deduplication, 3326.8K->2219.6K(1107.2K), avg 30.7%, 0.0615172 secs] {Heap before GC invocations=16 (full 0): garbage-first heap total 1048576K, used 765206K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 614 young (628736K), 38 survivors (38912K) Metaspace used 85312K, capacity 97388K, committed 97692K, reserved 1134592K class space used 9864K, capacity 13136K, committed 13260K, reserved 1048576K 2017-04-02T19:02:00.848+0000: 31.413: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 40370176 bytes, new threshold 15 (max 15) - age 1: 9990368 bytes, 9990368 total - age 2: 22710464 bytes, 32700832 total 31.413: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 26089, predicted base time: 37.27 ms, remaining time: 162.73 ms, target pause time: 200.00 ms] 31.413: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 576 regions, survivors: 38 regions, predicted young region time: 122.19 ms] 31.413: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 576 regions, survivors: 38 regions, old: 0 regions, predicted pause time: 159.46 ms, target pause time: 200.00 ms] 2017-04-02T19:02:00.903+0000: 31.468: [SoftReference, 0 refs, 0.0006117 secs]2017-04-02T19:02:00.904+0000: 31.469: [WeakReference, 3236 refs, 0.0005832 secs]2017-04-02T19:02:00.904+0000: 31.469: [FinalReference, 1216 refs, 0.0005681 secs]2017-04-02T19:02:00.905+0000: 31.470: [PhantomReference, 120 refs, 36 refs, 0.0006855 secs]2017-04-02T19:02:00.906+0000: 31.471: [JNI Weak Reference, 0.0000439 secs], 0.0620160 secs] [Parallel Time: 54.6 ms, GC Workers: 4] [GC Worker Start (ms): Min: 31413.0, Avg: 31413.1, Max: 31413.2, Diff: 0.1] [Ext Root Scanning (ms): Min: 3.0, Avg: 4.4, Max: 7.5, Diff: 4.5, Sum: 17.5] [Update RS (ms): Min: 15.2, Avg: 17.8, Max: 19.1, Diff: 3.9, Sum: 71.2] [Processed Buffers: Min: 16, Avg: 43.0, Max: 63, Diff: 47, Sum: 172] [Scan RS (ms): Min: 1.0, Avg: 1.3, Max: 1.8, Diff: 0.8, Sum: 5.1] [Code Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.5, Diff: 0.5, Sum: 0.8] [Object Copy (ms): Min: 30.5, Avg: 30.7, Max: 31.2, Diff: 0.7, Sum: 122.7] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Termination Attempts: Min: 1, Avg: 1.2, Max: 2, Diff: 1, Sum: 5] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.3] [GC Worker Total (ms): Min: 54.3, Avg: 54.4, Max: 54.5, Diff: 0.2, Sum: 217.7] [GC Worker End (ms): Min: 31467.5, Avg: 31467.5, Max: 31467.5, Diff: 0.1] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 3.1 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 0.3] [Table Fixup (ms): Min: 1.8, Avg: 2.5, Max: 2.8, Diff: 1.0, Sum: 9.9] [Clear CT: 0.2 ms] [Other: 3.9 ms] [Choose CSet: 0.0 ms] [Ref Proc: 2.8 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.5 ms] [Eden: 576.0M(576.0M)->0.0B(573.0M) Survivors: 38.0M->41.0M Heap: 747.3M(1024.0M)->174.3M(1024.0M)] Heap after GC invocations=17 (full 0): garbage-first heap total 1048576K, used 178454K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 41 young (41984K), 41 survivors (41984K) Metaspace used 85312K, capacity 97388K, committed 97692K, reserved 1134592K class space used 9864K, capacity 13136K, committed 13260K, reserved 1048576K } [Times: user=0.20 sys=0.01, real=0.06 secs] 2017-04-02T19:02:00.923+0000: 31.488: [GC concurrent-string-deduplication, 3406.3K->1937.5K(1468.8K), avg 32.4%, 0.0127664 secs] {Heap before GC invocations=17 (full 0): garbage-first heap total 1048576K, used 766230K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 614 young (628736K), 41 survivors (41984K) Metaspace used 86946K, capacity 99272K, committed 99484K, reserved 1134592K class space used 10062K, capacity 13409K, committed 13516K, reserved 1048576K 2017-04-02T19:02:03.052+0000: 33.617: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 40370176 bytes, new threshold 15 (max 15) - age 1: 6750576 bytes, 6750576 total - age 2: 7427344 bytes, 14177920 total - age 3: 22679480 bytes, 36857400 total 33.617: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 3411, predicted base time: 17.83 ms, remaining time: 182.17 ms, target pause time: 200.00 ms] 33.617: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 573 regions, survivors: 41 regions, predicted young region time: 102.88 ms] 33.617: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 573 regions, survivors: 41 regions, old: 0 regions, predicted pause time: 120.71 ms, target pause time: 200.00 ms] 2017-04-02T19:02:03.094+0000: 33.659: [SoftReference, 0 refs, 0.0005278 secs]2017-04-02T19:02:03.095+0000: 33.660: [WeakReference, 2687 refs, 0.0004299 secs]2017-04-02T19:02:03.095+0000: 33.660: [FinalReference, 1198 refs, 0.0006320 secs]2017-04-02T19:02:03.096+0000: 33.661: [PhantomReference, 98 refs, 40 refs, 0.0005845 secs]2017-04-02T19:02:03.097+0000: 33.662: [JNI Weak Reference, 0.0000169 secs], 0.0492595 secs] [Parallel Time: 41.8 ms, GC Workers: 4] [GC Worker Start (ms): Min: 33617.2, Avg: 33617.3, Max: 33617.3, Diff: 0.1] [Ext Root Scanning (ms): Min: 3.4, Avg: 4.4, Max: 6.5, Diff: 3.2, Sum: 17.8] [Update RS (ms): Min: 0.1, Avg: 3.5, Max: 9.1, Diff: 9.1, Sum: 14.0] [Processed Buffers: Min: 2, Avg: 9.2, Max: 16, Diff: 14, Sum: 37] [Scan RS (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.2, Sum: 0.7] [Code Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, Sum: 0.7] [Object Copy (ms): Min: 28.3, Avg: 33.3, Max: 35.5, Diff: 7.2, Sum: 133.2] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Termination Attempts: Min: 1, Avg: 1.8, Max: 3, Diff: 2, Sum: 7] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.2] [GC Worker Total (ms): Min: 41.6, Avg: 41.7, Max: 41.7, Diff: 0.0, Sum: 166.6] [GC Worker End (ms): Min: 33658.9, Avg: 33658.9, Max: 33659.0, Diff: 0.1] [Code Root Fixup: 0.2 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 3.5 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [Table Fixup (ms): Min: 3.0, Avg: 3.1, Max: 3.4, Diff: 0.4, Sum: 12.5] [Clear CT: 0.3 ms] [Other: 3.4 ms] [Choose CSet: 0.0 ms] [Ref Proc: 2.3 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.4 ms] [Eden: 573.0M(573.0M)->0.0B(572.0M) Survivors: 41.0M->42.0M Heap: 748.3M(1024.0M)->175.6M(1024.0M)] Heap after GC invocations=18 (full 0): garbage-first heap total 1048576K, used 179800K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 42 young (43008K), 42 survivors (43008K) Metaspace used 86946K, capacity 99272K, committed 99484K, reserved 1134592K class space used 10062K, capacity 13409K, committed 13516K, reserved 1048576K } [Times: user=0.15 sys=0.00, real=0.05 secs] 2017-04-02T19:02:03.105+0000: 33.670: [GC concurrent-string-deduplication, 1310.7K->859.5K(451.2K), avg 32.5%, 0.0032700 secs] {Heap before GC invocations=18 (full 0): garbage-first heap total 1048576K, used 765528K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 614 young (628736K), 42 survivors (43008K) Metaspace used 88301K, capacity 100894K, committed 101020K, reserved 1136640K class space used 10228K, capacity 13668K, committed 13772K, reserved 1048576K 2017-04-02T19:02:05.089+0000: 35.653: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 40370176 bytes, new threshold 15 (max 15) - age 1: 6404424 bytes, 6404424 total - age 2: 4278280 bytes, 10682704 total - age 3: 7403928 bytes, 18086632 total - age 4: 21108256 bytes, 39194888 total 35.654: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 3450, predicted base time: 17.47 ms, remaining time: 182.53 ms, target pause time: 200.00 ms] 35.654: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 572 regions, survivors: 42 regions, predicted young region time: 86.94 ms] 35.654: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 572 regions, survivors: 42 regions, old: 0 regions, predicted pause time: 104.41 ms, target pause time: 200.00 ms] 2017-04-02T19:02:05.159+0000: 35.724: [SoftReference, 0 refs, 0.0005375 secs]2017-04-02T19:02:05.160+0000: 35.724: [WeakReference, 2250 refs, 0.0006854 secs]2017-04-02T19:02:05.160+0000: 35.725: [FinalReference, 1599 refs, 0.0020698 secs]2017-04-02T19:02:05.162+0000: 35.727: [PhantomReference, 155 refs, 45 refs, 0.0021212 secs]2017-04-02T19:02:05.164+0000: 35.729: [JNI Weak Reference, 0.0000190 secs], 0.0837528 secs] [Parallel Time: 69.6 ms, GC Workers: 4] [GC Worker Start (ms): Min: 35653.7, Avg: 35654.8, Max: 35657.9, Diff: 4.2] [Ext Root Scanning (ms): Min: 0.6, Avg: 5.6, Max: 11.7, Diff: 11.1, Sum: 22.5] [Update RS (ms): Min: 0.0, Avg: 2.5, Max: 3.6, Diff: 3.6, Sum: 9.8] [Processed Buffers: Min: 0, Avg: 11.0, Max: 19, Diff: 19, Sum: 44] [Scan RS (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, Sum: 0.7] [Code Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.5, Diff: 0.5, Sum: 0.9] [Object Copy (ms): Min: 57.4, Avg: 59.7, Max: 60.9, Diff: 3.4, Sum: 238.9] [Termination (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, Sum: 0.8] [Termination Attempts: Min: 1, Avg: 2.2, Max: 4, Diff: 3, Sum: 9] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.2] [GC Worker Total (ms): Min: 65.3, Avg: 68.4, Max: 69.5, Diff: 4.2, Sum: 273.8] [GC Worker End (ms): Min: 35723.2, Avg: 35723.2, Max: 35723.3, Diff: 0.0] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 6.4 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1] [Table Fixup (ms): Min: 0.0, Avg: 2.5, Max: 6.3, Diff: 6.3, Sum: 10.2] [Clear CT: 0.4 ms] [Other: 7.0 ms] [Choose CSet: 0.0 ms] [Ref Proc: 5.7 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.2 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.6 ms] [Eden: 572.0M(572.0M)->0.0B(565.0M) Survivors: 42.0M->49.0M Heap: 747.6M(1024.0M)->182.1M(1024.0M)] Heap after GC invocations=19 (full 0): garbage-first heap total 1048576K, used 186456K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 49 young (50176K), 49 survivors (50176K) Metaspace used 88301K, capacity 100894K, committed 101020K, reserved 1136640K class space used 10228K, capacity 13668K, committed 13772K, reserved 1048576K } [Times: user=0.28 sys=0.01, real=0.09 secs] 2017-04-02T19:02:05.175+0000: 35.740: [GC concurrent-string-deduplication, 388.6K->182.2K(206.4K), avg 32.8%, 0.0016909 secs] {Heap before GC invocations=19 (full 0): garbage-first heap total 1048576K, used 765016K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 614 young (628736K), 49 survivors (50176K) Metaspace used 89870K, capacity 103394K, committed 103452K, reserved 1138688K class space used 10412K, capacity 14100K, committed 14156K, reserved 1048576K 2017-04-02T19:02:07.048+0000: 37.613: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 40370176 bytes, new threshold 5 (max 15) - age 1: 8081576 bytes, 8081576 total - age 2: 4395272 bytes, 12476848 total - age 3: 4221456 bytes, 16698304 total - age 4: 6795064 bytes, 23493368 total - age 5: 21051344 bytes, 44544712 total 37.613: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 3780, predicted base time: 20.32 ms, remaining time: 179.68 ms, target pause time: 200.00 ms] 37.613: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 565 regions, survivors: 49 regions, predicted young region time: 96.21 ms] 37.613: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 565 regions, survivors: 49 regions, old: 0 regions, predicted pause time: 116.53 ms, target pause time: 200.00 ms] 2017-04-02T19:02:07.109+0000: 37.674: [SoftReference, 0 refs, 0.0006989 secs]2017-04-02T19:02:07.109+0000: 37.674: [WeakReference, 7088 refs, 0.0009714 secs]2017-04-02T19:02:07.110+0000: 37.675: [FinalReference, 3367 refs, 0.0013048 secs]2017-04-02T19:02:07.112+0000: 37.677: [PhantomReference, 91 refs, 46 refs, 0.0006796 secs]2017-04-02T19:02:07.112+0000: 37.677: [JNI Weak Reference, 0.0000136 secs], 0.0687583 secs] [Parallel Time: 60.3 ms, GC Workers: 4] [GC Worker Start (ms): Min: 37612.8, Avg: 37613.2, Max: 37614.3, Diff: 1.4] [Ext Root Scanning (ms): Min: 2.3, Avg: 4.8, Max: 7.7, Diff: 5.4, Sum: 19.4] [Update RS (ms): Min: 0.0, Avg: 2.3, Max: 4.2, Diff: 4.2, Sum: 9.3] [Processed Buffers: Min: 0, Avg: 11.0, Max: 32, Diff: 32, Sum: 44] [Scan RS (ms): Min: 0.0, Avg: 0.2, Max: 0.3, Diff: 0.3, Sum: 0.6] [Code Root Scanning (ms): Min: 0.0, Avg: 0.3, Max: 0.5, Diff: 0.5, Sum: 1.1] [Object Copy (ms): Min: 51.9, Avg: 52.1, Max: 52.3, Diff: 0.4, Sum: 208.4] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Termination Attempts: Min: 1, Avg: 5.0, Max: 8, Diff: 7, Sum: 20] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.0, Sum: 0.3] [GC Worker Total (ms): Min: 58.8, Avg: 59.8, Max: 60.2, Diff: 1.4, Sum: 239.1] [GC Worker End (ms): Min: 37673.0, Avg: 37673.0, Max: 37673.0, Diff: 0.0] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 3.0 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [Table Fixup (ms): Min: 2.8, Avg: 2.8, Max: 2.9, Diff: 0.1, Sum: 11.3] [Clear CT: 0.2 ms] [Other: 5.0 ms] [Choose CSet: 0.0 ms] [Ref Proc: 3.9 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.2 ms] [Humongous Register: 0.0 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.5 ms] [Eden: 565.0M(565.0M)->0.0B(571.0M) Survivors: 49.0M->43.0M Heap: 747.1M(1024.0M)->197.7M(1024.0M)] Heap after GC invocations=20 (full 0): garbage-first heap total 1048576K, used 202402K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 43 young (44032K), 43 survivors (44032K) Metaspace used 89870K, capacity 103394K, committed 103452K, reserved 1138688K class space used 10412K, capacity 14100K, committed 14156K, reserved 1048576K } [Times: user=0.23 sys=0.00, real=0.07 secs] 2017-04-02T19:02:07.119+0000: 37.684: [GC concurrent-string-deduplication, 602.9K->286.1K(316.8K), avg 33.2%, 0.0018959 secs] {Heap before GC invocations=20 (full 0): garbage-first heap total 1048576K, used 787106K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 614 young (628736K), 43 survivors (44032K) Metaspace used 91205K, capacity 105466K, committed 105628K, reserved 1140736K class space used 10557K, capacity 14476K, committed 14540K, reserved 1048576K 2017-04-02T19:02:08.895+0000: 39.459: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 40370176 bytes, new threshold 15 (max 15) - age 1: 15723752 bytes, 15723752 total - age 2: 6280664 bytes, 22004416 total - age 3: 4330400 bytes, 26334816 total - age 4: 3976352 bytes, 30311168 total - age 5: 6668368 bytes, 36979536 total 39.460: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 5510, predicted base time: 20.75 ms, remaining time: 179.25 ms, target pause time: 200.00 ms] 39.460: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 571 regions, survivors: 43 regions, predicted young region time: 89.88 ms] 39.460: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 571 regions, survivors: 43 regions, old: 0 regions, predicted pause time: 110.63 ms, target pause time: 200.00 ms] 2017-04-02T19:02:08.947+0000: 39.512: [SoftReference, 0 refs, 0.0007318 secs]2017-04-02T19:02:08.947+0000: 39.512: [WeakReference, 8363 refs, 0.0007661 secs]2017-04-02T19:02:08.948+0000: 39.513: [FinalReference, 3995 refs, 0.0010797 secs]2017-04-02T19:02:08.949+0000: 39.514: [PhantomReference, 199 refs, 25 refs, 0.0006610 secs]2017-04-02T19:02:08.950+0000: 39.515: [JNI Weak Reference, 0.0000193 secs], 0.0596562 secs] [Parallel Time: 51.5 ms, GC Workers: 4] [GC Worker Start (ms): Min: 39459.7, Avg: 39461.9, Max: 39462.6, Diff: 2.9] [Ext Root Scanning (ms): Min: 1.6, Avg: 2.9, Max: 4.2, Diff: 2.6, Sum: 11.7] [Update RS (ms): Min: 1.8, Avg: 3.6, Max: 4.4, Diff: 2.5, Sum: 14.5] [Processed Buffers: Min: 8, Avg: 38.0, Max: 58, Diff: 50, Sum: 152] [Scan RS (ms): Min: 1.1, Avg: 1.1, Max: 1.1, Diff: 0.1, Sum: 4.4] [Code Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.4, Diff: 0.4, Sum: 0.8] [Object Copy (ms): Min: 40.8, Avg: 41.0, Max: 41.2, Diff: 0.3, Sum: 163.9] [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: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.2, Max: 0.4, Diff: 0.4, Sum: 0.9] [GC Worker Total (ms): Min: 48.1, Avg: 49.1, Max: 51.4, Diff: 3.2, Sum: 196.2] [GC Worker End (ms): Min: 39510.8, Avg: 39510.9, Max: 39511.1, Diff: 0.4] [Code Root Fixup: 0.2 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 3.1 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1] [Table Fixup (ms): Min: 2.1, Avg: 2.7, Max: 2.9, Diff: 0.8, Sum: 10.9] [Clear CT: 0.3 ms] [Other: 4.6 ms] [Choose CSet: 0.0 ms] [Ref Proc: 3.4 ms] [Ref Enq: 0.2 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.5 ms] [Eden: 571.0M(571.0M)->0.0B(558.0M) Survivors: 43.0M->56.0M Heap: 768.7M(1024.0M)->211.2M(1024.0M)] Heap after GC invocations=21 (full 0): garbage-first heap total 1048576K, used 216226K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 56 young (57344K), 56 survivors (57344K) Metaspace used 91205K, capacity 105466K, committed 105628K, reserved 1140736K class space used 10557K, capacity 14476K, committed 14540K, reserved 1048576K } [Times: user=0.20 sys=0.00, real=0.06 secs] 2017-04-02T19:02:08.959+0000: 39.524: [GC concurrent-string-deduplication, 833.2K->454.6K(378.6K), avg 33.6%, 0.0039030 secs] {Heap before GC invocations=21 (full 0): garbage-first heap total 1048576K, used 787618K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 614 young (628736K), 56 survivors (57344K) Metaspace used 92471K, capacity 107246K, committed 107420K, reserved 1142784K class space used 10664K, capacity 14767K, committed 14796K, reserved 1048576K 2017-04-02T19:02:10.823+0000: 41.388: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 40370176 bytes, new threshold 4 (max 15) - age 1: 17055944 bytes, 17055944 total - age 2: 13731680 bytes, 30787624 total - age 3: 6245208 bytes, 37032832 total - age 4: 3944456 bytes, 40977288 total - age 5: 3972608 bytes, 44949896 total - age 6: 6661600 bytes, 51611496 total 41.388: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 3543, predicted base time: 18.40 ms, remaining time: 181.60 ms, target pause time: 200.00 ms] 41.388: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 558 regions, survivors: 56 regions, predicted young region time: 75.41 ms] 41.388: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 558 regions, survivors: 56 regions, old: 0 regions, predicted pause time: 93.81 ms, target pause time: 200.00 ms] 2017-04-02T19:02:10.969+0000: 41.534: [SoftReference, 0 refs, 0.0007639 secs]2017-04-02T19:02:10.970+0000: 41.534: [WeakReference, 10038 refs, 0.0018707 secs]2017-04-02T19:02:10.971+0000: 41.536: [FinalReference, 2682 refs, 0.0020983 secs]2017-04-02T19:02:10.974+0000: 41.538: [PhantomReference, 130 refs, 25 refs, 0.0017242 secs]2017-04-02T19:02:10.975+0000: 41.540: [JNI Weak Reference, 0.0001551 secs], 0.1618043 secs] [Parallel Time: 131.9 ms, GC Workers: 4] [GC Worker Start (ms): Min: 41387.9, Avg: 41393.5, Max: 41396.6, Diff: 8.7] [Ext Root Scanning (ms): Min: 3.4, Avg: 4.1, Max: 5.3, Diff: 1.9, Sum: 16.5] [Update RS (ms): Min: 0.0, Avg: 4.4, Max: 6.6, Diff: 6.6, Sum: 17.5] [Processed Buffers: Min: 0, Avg: 17.2, Max: 64, Diff: 64, Sum: 69] [Scan RS (ms): Min: 0.0, Avg: 0.2, Max: 0.5, Diff: 0.5, Sum: 0.7] [Code Root Scanning (ms): Min: 0.0, Avg: 0.4, Max: 0.9, Diff: 0.9, Sum: 1.5] [Object Copy (ms): Min: 96.5, Avg: 102.9, Max: 109.1, Diff: 12.6, Sum: 411.4] [Termination (ms): Min: 0.0, Avg: 10.3, Max: 13.8, Diff: 13.8, Sum: 41.1] [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [GC Worker Total (ms): Min: 119.1, Avg: 122.2, Max: 127.9, Diff: 8.7, Sum: 488.9] [GC Worker End (ms): Min: 41515.7, Avg: 41515.8, Max: 41515.8, Diff: 0.1] [Code Root Fixup: 0.4 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 7.0 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.2] [Table Fixup (ms): Min: 3.1, Avg: 5.5, Max: 6.6, Diff: 3.5, Sum: 21.8] [Clear CT: 0.4 ms] [Other: 22.1 ms] [Choose CSet: 0.0 ms] [Ref Proc: 20.1 ms] [Ref Enq: 0.3 ms] [Redirty Cards: 0.6 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.6 ms] [Eden: 558.0M(558.0M)->0.0B(562.0M) Survivors: 56.0M->52.0M Heap: 769.2M(1024.0M)->223.6M(1024.0M)] Heap after GC invocations=22 (full 0): garbage-first heap total 1048576K, used 228952K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 52 young (53248K), 52 survivors (53248K) Metaspace used 92471K, capacity 107246K, committed 107420K, reserved 1142784K class space used 10664K, capacity 14767K, committed 14796K, reserved 1048576K } [Times: user=0.42 sys=0.01, real=0.16 secs] 2017-04-02T19:02:11.022+0000: 41.586: [GC concurrent-string-deduplication, 1018.8K->424.4K(594.4K), avg 34.5%, 0.0163194 secs] {Heap before GC invocations=22 (full 0): garbage-first heap total 1048576K, used 804440K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 614 young (628736K), 52 survivors (53248K) Metaspace used 93573K, capacity 108854K, committed 108956K, reserved 1142784K class space used 10776K, capacity 15009K, committed 15052K, reserved 1048576K 2017-04-02T19:02:13.058+0000: 43.623: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 40370176 bytes, new threshold 3 (max 15) - age 1: 13366816 bytes, 13366816 total - age 2: 14343112 bytes, 27709928 total - age 3: 13559064 bytes, 41268992 total - age 4: 5595208 bytes, 46864200 total 43.623: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 6716, predicted base time: 35.28 ms, remaining time: 164.72 ms, target pause time: 200.00 ms] 43.623: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 562 regions, survivors: 52 regions, predicted young region time: 92.51 ms] 43.623: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 562 regions, survivors: 52 regions, old: 0 regions, predicted pause time: 127.78 ms, target pause time: 200.00 ms] 2017-04-02T19:02:13.128+0000: 43.693: [SoftReference, 0 refs, 0.0007270 secs]2017-04-02T19:02:13.129+0000: 43.694: [WeakReference, 8951 refs, 0.0013045 secs]2017-04-02T19:02:13.130+0000: 43.695: [FinalReference, 1943 refs, 0.0012622 secs]2017-04-02T19:02:13.132+0000: 43.697: [PhantomReference, 209 refs, 6 refs, 0.0008397 secs]2017-04-02T19:02:13.132+0000: 43.697: [JNI Weak Reference, 0.0000169 secs], 0.0807488 secs] [Parallel Time: 69.3 ms, GC Workers: 4] [GC Worker Start (ms): Min: 43623.4, Avg: 43623.5, Max: 43623.7, Diff: 0.3] [Ext Root Scanning (ms): Min: 1.9, Avg: 3.1, Max: 4.1, Diff: 2.2, Sum: 12.2] [Update RS (ms): Min: 3.1, Avg: 4.0, Max: 4.6, Diff: 1.5, Sum: 15.9] [Processed Buffers: Min: 36, Avg: 48.5, Max: 68, Diff: 32, Sum: 194] [Scan RS (ms): Min: 0.9, Avg: 1.1, Max: 1.3, Diff: 0.4, Sum: 4.4] [Code Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.5, Diff: 0.5, Sum: 0.8] [Object Copy (ms): Min: 55.3, Avg: 57.1, Max: 61.7, Diff: 6.4, Sum: 228.3] [Termination (ms): Min: 0.0, Avg: 3.7, Max: 4.9, Diff: 4.9, Sum: 14.7] [Termination Attempts: Min: 1, Avg: 1.2, Max: 2, Diff: 1, Sum: 5] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [GC Worker Total (ms): Min: 68.9, Avg: 69.1, Max: 69.2, Diff: 0.3, Sum: 276.5] [GC Worker End (ms): Min: 43692.6, Avg: 43692.7, Max: 43692.7, Diff: 0.0] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 5.1 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.2] [Table Fixup (ms): Min: 0.0, Avg: 2.5, Max: 4.9, Diff: 4.9, Sum: 9.9] [Clear CT: 0.3 ms] [Other: 5.8 ms] [Choose CSet: 0.0 ms] [Ref Proc: 4.5 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.2 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.4 ms] [Eden: 562.0M(562.0M)->0.0B(574.0M) Survivors: 52.0M->40.0M Heap: 785.6M(1024.0M)->230.1M(1024.0M)] Heap after GC invocations=23 (full 0): garbage-first heap total 1048576K, used 235608K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 40 young (40960K), 40 survivors (40960K) Metaspace used 93573K, capacity 108854K, committed 108956K, reserved 1142784K class space used 10776K, capacity 15009K, committed 15052K, reserved 1048576K } [Times: user=0.26 sys=0.00, real=0.09 secs] 2017-04-02T19:02:13.144+0000: 43.709: [GC concurrent-string-deduplication, 1298.4K->504.8K(793.6K), avg 35.6%, 0.0053657 secs] {Heap before GC invocations=23 (full 0): garbage-first heap total 1048576K, used 823384K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 614 young (628736K), 40 survivors (40960K) Metaspace used 95459K, capacity 111430K, committed 111772K, reserved 1144832K class space used 10992K, capacity 15459K, committed 15564K, reserved 1048576K 2017-04-02T19:02:15.089+0000: 45.654: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 40370176 bytes, new threshold 15 (max 15) - age 1: 9957680 bytes, 9957680 total - age 2: 10933248 bytes, 20890928 total - age 3: 14289288 bytes, 35180216 total 45.654: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 9279, predicted base time: 33.72 ms, remaining time: 166.28 ms, target pause time: 200.00 ms] 45.654: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 574 regions, survivors: 40 regions, predicted young region time: 78.92 ms] 45.654: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 574 regions, survivors: 40 regions, old: 0 regions, predicted pause time: 112.64 ms, target pause time: 200.00 ms] 2017-04-02T19:02:15.173+0000: 45.738: [SoftReference, 0 refs, 0.0043955 secs]2017-04-02T19:02:15.177+0000: 45.742: [WeakReference, 6067 refs, 0.0013511 secs]2017-04-02T19:02:15.179+0000: 45.743: [FinalReference, 2833 refs, 0.0042743 secs]2017-04-02T19:02:15.183+0000: 45.748: [PhantomReference, 168 refs, 1 refs, 0.0008615 secs]2017-04-02T19:02:15.184+0000: 45.749: [JNI Weak Reference, 0.0000191 secs], 0.1043386 secs] [Parallel Time: 73.6 ms, GC Workers: 4] [GC Worker Start (ms): Min: 45654.2, Avg: 45658.0, Max: 45663.7, Diff: 9.6] [Ext Root Scanning (ms): Min: 0.0, Avg: 2.5, Max: 5.3, Diff: 5.3, Sum: 10.1] [Update RS (ms): Min: 0.0, Avg: 4.5, Max: 7.5, Diff: 7.5, Sum: 18.1] [Processed Buffers: Min: 0, Avg: 54.8, Max: 99, Diff: 99, Sum: 219] [Scan RS (ms): Min: 0.0, Avg: 1.2, Max: 1.6, Diff: 1.6, Sum: 4.7] [Code Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.6, Diff: 0.6, Sum: 0.7] [Object Copy (ms): Min: 57.6, Avg: 60.5, Max: 67.2, Diff: 9.6, Sum: 241.8] [Termination (ms): Min: 0.0, Avg: 0.3, Max: 1.0, Diff: 1.0, Sum: 1.4] [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [GC Worker Total (ms): Min: 63.2, Avg: 69.2, Max: 72.8, Diff: 9.6, Sum: 276.8] [GC Worker End (ms): Min: 45727.0, Avg: 45727.2, Max: 45727.7, Diff: 0.8] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 8.1 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1] [Table Fixup (ms): Min: 2.9, Avg: 5.2, Max: 7.9, Diff: 5.0, Sum: 20.9] [Clear CT: 0.3 ms] [Other: 22.0 ms] [Choose CSet: 0.0 ms] [Ref Proc: 20.6 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.6 ms] [Eden: 574.0M(574.0M)->0.0B(563.0M) Survivors: 40.0M->51.0M Heap: 804.1M(1024.0M)->241.1M(1024.0M)] Heap after GC invocations=24 (full 0): garbage-first heap total 1048576K, used 246872K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 51 young (52224K), 51 survivors (52224K) Metaspace used 95459K, capacity 111430K, committed 111772K, reserved 1144832K class space used 10992K, capacity 15459K, committed 15564K, reserved 1048576K } [Times: user=0.35 sys=0.00, real=0.11 secs] 2017-04-02T19:02:15.196+0000: 45.761: [GC concurrent-string-deduplication, 621.9K->197.1K(424.8K), avg 36.3%, 0.0029258 secs] {Heap before GC invocations=24 (full 0): garbage-first heap total 1048576K, used 823384K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 614 young (628736K), 51 survivors (52224K) Metaspace used 97710K, capacity 114952K, committed 115228K, reserved 1148928K class space used 11236K, capacity 16098K, committed 16204K, reserved 1048576K 2017-04-02T19:02:17.408+0000: 47.973: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 40370176 bytes, new threshold 4 (max 15) - age 1: 14372144 bytes, 14372144 total - age 2: 7032080 bytes, 21404224 total - age 3: 10879672 bytes, 32283896 total - age 4: 13460792 bytes, 45744688 total 47.973: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 4650, predicted base time: 34.42 ms, remaining time: 165.58 ms, target pause time: 200.00 ms] 47.973: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 563 regions, survivors: 51 regions, predicted young region time: 78.07 ms] 47.973: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 563 regions, survivors: 51 regions, old: 0 regions, predicted pause time: 112.49 ms, target pause time: 200.00 ms] 2017-04-02T19:02:17.467+0000: 48.032: [SoftReference, 0 refs, 0.0005068 secs]2017-04-02T19:02:17.468+0000: 48.033: [WeakReference, 5626 refs, 0.0008882 secs]2017-04-02T19:02:17.469+0000: 48.034: [FinalReference, 2865 refs, 0.0012425 secs]2017-04-02T19:02:17.470+0000: 48.035: [PhantomReference, 76 refs, 1 refs, 0.0004543 secs]2017-04-02T19:02:17.470+0000: 48.035: [JNI Weak Reference, 0.0000141 secs], 0.0671663 secs] [Parallel Time: 58.3 ms, GC Workers: 4] [GC Worker Start (ms): Min: 47973.2, Avg: 47973.9, Max: 47975.7, Diff: 2.5] [Ext Root Scanning (ms): Min: 0.6, Avg: 2.8, Max: 4.5, Diff: 3.9, Sum: 11.2] [Update RS (ms): Min: 1.2, Avg: 2.5, Max: 3.0, Diff: 1.8, Sum: 9.9] [Processed Buffers: Min: 7, Avg: 29.2, Max: 54, Diff: 47, Sum: 117] [Scan RS (ms): Min: 0.2, Avg: 0.2, Max: 0.2, Diff: 0.1, Sum: 0.8] [Code Root Scanning (ms): Min: 0.1, Avg: 0.2, Max: 0.7, Diff: 0.6, Sum: 1.0] [Object Copy (ms): Min: 51.6, Avg: 51.8, Max: 52.2, Diff: 0.6, Sum: 207.1] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Termination Attempts: Min: 1, Avg: 1.8, Max: 4, Diff: 3, Sum: 7] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.2] [GC Worker Total (ms): Min: 55.7, Avg: 57.6, Max: 58.2, Diff: 2.5, Sum: 230.2] [GC Worker End (ms): Min: 48031.4, Avg: 48031.4, Max: 48031.5, Diff: 0.1] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 3.6 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Table Fixup (ms): Min: 0.0, Avg: 2.6, Max: 3.5, Diff: 3.5, Sum: 10.3] [Clear CT: 0.2 ms] [Other: 4.8 ms] [Choose CSet: 0.0 ms] [Ref Proc: 3.6 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.4 ms] [Eden: 563.0M(563.0M)->0.0B(557.0M) Survivors: 51.0M->57.0M Heap: 804.1M(1024.0M)->261.1M(1024.0M)] Heap after GC invocations=25 (full 0): garbage-first heap total 1048576K, used 267352K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 57 young (58368K), 57 survivors (58368K) Metaspace used 97710K, capacity 114952K, committed 115228K, reserved 1148928K class space used 11236K, capacity 16098K, committed 16204K, reserved 1048576K } [Times: user=0.23 sys=0.01, real=0.07 secs] 2017-04-02T19:02:17.477+0000: 48.042: [GC concurrent-string-deduplication, 277.2K->24.8K(252.3K), avg 36.8%, 0.0013668 secs] {Heap before GC invocations=25 (full 0): garbage-first heap total 1048576K, used 837720K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 614 young (628736K), 57 survivors (58368K) Metaspace used 102172K, capacity 119968K, committed 120348K, reserved 1153024K class space used 11822K, capacity 16851K, committed 16972K, reserved 1048576K 2017-04-02T19:02:20.174+0000: 50.739: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 40370176 bytes, new threshold 3 (max 15) - age 1: 23182320 bytes, 23182320 total - age 2: 10737072 bytes, 33919392 total - age 3: 6932896 bytes, 40852288 total - age 4: 10413632 bytes, 51265920 total 50.739: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 9839, predicted base time: 33.81 ms, remaining time: 166.19 ms, target pause time: 200.00 ms] 50.739: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 557 regions, survivors: 57 regions, predicted young region time: 84.14 ms] 50.739: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 557 regions, survivors: 57 regions, old: 0 regions, predicted pause time: 117.95 ms, target pause time: 200.00 ms] 2017-04-02T19:02:20.271+0000: 50.836: [SoftReference, 0 refs, 0.0049143 secs]2017-04-02T19:02:20.276+0000: 50.841: [WeakReference, 1318 refs, 0.0003413 secs]2017-04-02T19:02:20.276+0000: 50.841: [FinalReference, 3490 refs, 0.0018146 secs]2017-04-02T19:02:20.278+0000: 50.843: [PhantomReference, 105 refs, 6 refs, 0.0007714 secs]2017-04-02T19:02:20.279+0000: 50.844: [JNI Weak Reference, 0.0000147 secs], 0.1118008 secs] [Parallel Time: 90.3 ms, GC Workers: 4] [GC Worker Start (ms): Min: 50739.4, Avg: 50739.6, Max: 50739.7, Diff: 0.3] [Ext Root Scanning (ms): Min: 2.8, Avg: 4.9, Max: 9.0, Diff: 6.2, Sum: 19.7] [Update RS (ms): Min: 1.5, Avg: 4.4, Max: 6.0, Diff: 4.5, Sum: 17.6] [Processed Buffers: Min: 38, Avg: 44.0, Max: 49, Diff: 11, Sum: 176] [Scan RS (ms): Min: 0.7, Avg: 1.6, Max: 1.9, Diff: 1.2, Sum: 6.4] [Code Root Scanning (ms): Min: 0.0, Avg: 0.3, Max: 1.1, Diff: 1.0, Sum: 1.3] [Object Copy (ms): Min: 77.0, Avg: 77.3, Max: 77.7, Diff: 0.7, Sum: 309.1] [Termination (ms): Min: 0.0, Avg: 1.4, Max: 1.9, Diff: 1.9, Sum: 5.6] [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [GC Worker Total (ms): Min: 89.8, Avg: 89.9, Max: 90.1, Diff: 0.3, Sum: 359.7] [GC Worker End (ms): Min: 50829.5, Avg: 50829.5, Max: 50829.6, Diff: 0.1] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 5.2 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [Table Fixup (ms): Min: 0.0, Avg: 2.5, Max: 5.1, Diff: 5.1, Sum: 10.1] [Clear CT: 0.4 ms] [Other: 15.5 ms] [Choose CSet: 0.0 ms] [Ref Proc: 13.6 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.4 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.7 ms] [Eden: 557.0M(557.0M)->0.0B(550.0M) Survivors: 57.0M->53.0M Heap: 818.1M(1024.0M)->274.6M(1024.0M)] Heap after GC invocations=26 (full 0): garbage-first heap total 1048576K, used 281176K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 53 young (54272K), 53 survivors (54272K) Metaspace used 102172K, capacity 119968K, committed 120348K, reserved 1153024K class space used 11822K, capacity 16851K, committed 16972K, reserved 1048576K } [Times: user=0.36 sys=0.00, real=0.11 secs] 2017-04-02T19:02:20.302+0000: 50.867: [GC concurrent-string-deduplication, 417.7K->14.1K(403.6K), avg 37.5%, 0.0046531 secs] {Heap before GC invocations=26 (full 0): garbage-first heap total 1048576K, used 844376K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 603 young (617472K), 53 survivors (54272K) Metaspace used 107650K, capacity 125476K, committed 125852K, reserved 1157120K class space used 12497K, capacity 17518K, committed 17612K, reserved 1048576K 2017-04-02T19:02:23.598+0000: 54.162: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 39845888 bytes, new threshold 3 (max 15) - age 1: 14389672 bytes, 14389672 total - age 2: 21128040 bytes, 35517712 total - age 3: 10700808 bytes, 46218520 total 54.163: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 10438, predicted base time: 34.26 ms, remaining time: 165.74 ms, target pause time: 200.00 ms] 54.163: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 550 regions, survivors: 53 regions, predicted young region time: 92.79 ms] 54.163: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 550 regions, survivors: 53 regions, old: 0 regions, predicted pause time: 127.05 ms, target pause time: 200.00 ms] 2017-04-02T19:02:23.664+0000: 54.229: [SoftReference, 0 refs, 0.0007800 secs]2017-04-02T19:02:23.665+0000: 54.230: [WeakReference, 1107 refs, 0.0015481 secs]2017-04-02T19:02:23.667+0000: 54.231: [FinalReference, 3302 refs, 0.0043773 secs]2017-04-02T19:02:23.671+0000: 54.236: [PhantomReference, 133 refs, 5 refs, 0.0007905 secs]2017-04-02T19:02:23.672+0000: 54.237: [JNI Weak Reference, 0.0000204 secs], 0.0796914 secs] [Parallel Time: 65.8 ms, GC Workers: 4] [GC Worker Start (ms): Min: 54162.8, Avg: 54165.8, Max: 54166.9, Diff: 4.1] [Ext Root Scanning (ms): Min: 4.1, Avg: 10.2, Max: 18.4, Diff: 14.3, Sum: 40.7] [Update RS (ms): Min: 0.0, Avg: 9.0, Max: 13.3, Diff: 13.3, Sum: 36.0] [Processed Buffers: Min: 0, Avg: 36.5, Max: 88, Diff: 88, Sum: 146] [Scan RS (ms): Min: 1.8, Avg: 2.3, Max: 2.6, Diff: 0.8, Sum: 9.0] [Code Root Scanning (ms): Min: 0.0, Avg: 0.2, Max: 0.7, Diff: 0.7, Sum: 0.9] [Object Copy (ms): Min: 39.3, Avg: 39.8, Max: 40.3, Diff: 1.0, Sum: 159.1] [Termination (ms): Min: 0.0, Avg: 0.2, Max: 0.4, Diff: 0.4, Sum: 1.0] [Termination Attempts: Min: 1, Avg: 1.2, Max: 2, Diff: 1, Sum: 5] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [GC Worker Total (ms): Min: 60.5, Avg: 61.7, Max: 64.8, Diff: 4.2, Sum: 246.8] [GC Worker End (ms): Min: 54227.4, Avg: 54227.5, Max: 54227.7, Diff: 0.2] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 4.3 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [Table Fixup (ms): Min: 1.2, Avg: 3.4, Max: 4.2, Diff: 2.9, Sum: 13.7] [Clear CT: 0.2 ms] [Other: 9.0 ms] [Choose CSet: 0.0 ms] [Ref Proc: 7.7 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.2 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.5 ms] [Eden: 550.0M(550.0M)->0.0B(549.0M) Survivors: 53.0M->48.0M Heap: 824.6M(1024.0M)->280.6M(1024.0M)] Heap after GC invocations=27 (full 0): garbage-first heap total 1048576K, used 287320K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 48 young (49152K), 48 survivors (49152K) Metaspace used 107650K, capacity 125476K, committed 125852K, reserved 1157120K class space used 12497K, capacity 17518K, committed 17612K, reserved 1048576K } [Times: user=0.23 sys=0.00, real=0.08 secs] 2017-04-02T19:02:23.680+0000: 54.245: [GC concurrent-string-deduplication, 515.5K->47.1K(468.4K), avg 38.4%, 0.0023560 secs] {Heap before GC invocations=27 (full 0): garbage-first heap total 1048576K, used 851925K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 597 young (611328K), 48 survivors (49152K) Metaspace used 112668K, capacity 130562K, committed 130716K, reserved 1161216K class space used 13053K, capacity 18083K, committed 18124K, reserved 1048576K 2017-04-02T19:02:26.382+0000: 56.947: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 39321600 bytes, new threshold 15 (max 15) - age 1: 5465616 bytes, 5465616 total - age 2: 12347376 bytes, 17812992 total - age 3: 21099456 bytes, 38912448 total 56.947: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 9124, predicted base time: 35.03 ms, remaining time: 164.97 ms, target pause time: 200.00 ms] 56.947: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 549 regions, survivors: 48 regions, predicted young region time: 79.12 ms] 56.947: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 549 regions, survivors: 48 regions, old: 0 regions, predicted pause time: 114.15 ms, target pause time: 200.00 ms] 2017-04-02T19:02:26.439+0000: 57.004: [SoftReference, 0 refs, 0.0005348 secs]2017-04-02T19:02:26.440+0000: 57.004: [WeakReference, 1259 refs, 0.0003986 secs]2017-04-02T19:02:26.440+0000: 57.005: [FinalReference, 3657 refs, 0.0024431 secs]2017-04-02T19:02:26.442+0000: 57.007: [PhantomReference, 226 refs, 7 refs, 0.0010864 secs]2017-04-02T19:02:26.443+0000: 57.008: [JNI Weak Reference, 0.0000403 secs], 0.0689553 secs] [Parallel Time: 55.9 ms, GC Workers: 4] [GC Worker Start (ms): Min: 56947.6, Avg: 56947.6, Max: 56947.6, Diff: 0.1] [Ext Root Scanning (ms): Min: 2.4, Avg: 3.7, Max: 6.2, Diff: 3.8, Sum: 15.0] [Update RS (ms): Min: 2.6, Avg: 5.9, Max: 7.6, Diff: 5.0, Sum: 23.4] [Processed Buffers: Min: 25, Avg: 35.0, Max: 43, Diff: 18, Sum: 140] [Scan RS (ms): Min: 0.4, Avg: 3.6, Max: 5.6, Diff: 5.2, Sum: 14.4] [Code Root Scanning (ms): Min: 0.0, Avg: 2.7, Max: 9.7, Diff: 9.7, Sum: 10.7] [Object Copy (ms): Min: 36.3, Avg: 39.8, Max: 41.2, Diff: 4.9, Sum: 159.2] [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.4] [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [GC Worker Total (ms): Min: 55.8, Avg: 55.8, Max: 55.8, Diff: 0.0, Sum: 223.2] [GC Worker End (ms): Min: 57003.4, Avg: 57003.4, Max: 57003.4, Diff: 0.0] [Code Root Fixup: 0.2 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 6.1 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1] [Table Fixup (ms): Min: 1.8, Avg: 4.2, Max: 5.2, Diff: 3.4, Sum: 16.8] [Clear CT: 0.4 ms] [Other: 6.3 ms] [Choose CSet: 0.0 ms] [Ref Proc: 4.8 ms] [Ref Enq: 0.2 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.6 ms] [Eden: 549.0M(549.0M)->0.0B(535.0M) Survivors: 48.0M->54.0M Heap: 832.0M(1024.0M)->288.5M(1024.0M)] Heap after GC invocations=28 (full 0): garbage-first heap total 1048576K, used 295381K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 54 young (55296K), 54 survivors (55296K) Metaspace used 112668K, capacity 130562K, committed 130716K, reserved 1161216K class space used 13053K, capacity 18083K, committed 18124K, reserved 1048576K } [Times: user=0.25 sys=0.00, real=0.07 secs] 2017-04-02T19:02:26.461+0000: 57.026: [GC concurrent-string-deduplication, 741.0K->191.1K(549.9K), avg 39.2%, 0.0037039 secs] {Heap before GC invocations=28 (full 0): garbage-first heap total 1048576K, used 844757K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 589 young (603136K), 54 survivors (55296K) Metaspace used 116285K, capacity 134244K, committed 134428K, reserved 1165312K class space used 13415K, capacity 18448K, committed 18508K, reserved 1048576K 2017-04-02T19:02:29.008+0000: 59.573: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 38797312 bytes, new threshold 4 (max 15) - age 1: 10051016 bytes, 10051016 total - age 2: 3126376 bytes, 13177392 total - age 3: 11712880 bytes, 24890272 total - age 4: 18918592 bytes, 43808864 total 59.573: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 12207, predicted base time: 35.00 ms, remaining time: 165.00 ms, target pause time: 200.00 ms] 59.573: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 535 regions, survivors: 54 regions, predicted young region time: 64.28 ms] 59.573: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 535 regions, survivors: 54 regions, old: 0 regions, predicted pause time: 99.28 ms, target pause time: 200.00 ms] 2017-04-02T19:02:29.061+0000: 59.626: [SoftReference, 0 refs, 0.0004800 secs]2017-04-02T19:02:29.062+0000: 59.627: [WeakReference, 1214 refs, 0.0003699 secs]2017-04-02T19:02:29.062+0000: 59.627: [FinalReference, 3059 refs, 0.0009469 secs]2017-04-02T19:02:29.063+0000: 59.628: [PhantomReference, 189 refs, 5 refs, 0.0005510 secs]2017-04-02T19:02:29.064+0000: 59.629: [JNI Weak Reference, 0.0000158 secs], 0.0612047 secs] [Parallel Time: 52.7 ms, GC Workers: 4] [GC Worker Start (ms): Min: 59572.9, Avg: 59572.9, Max: 59573.0, Diff: 0.1] [Ext Root Scanning (ms): Min: 1.8, Avg: 3.5, Max: 5.9, Diff: 4.1, Sum: 14.1] [Update RS (ms): Min: 4.2, Avg: 6.0, Max: 7.4, Diff: 3.1, Sum: 23.9] [Processed Buffers: Min: 8, Avg: 34.0, Max: 56, Diff: 48, Sum: 136] [Scan RS (ms): Min: 0.5, Avg: 0.8, Max: 0.9, Diff: 0.4, Sum: 3.0] [Code Root Scanning (ms): Min: 0.2, Avg: 0.4, Max: 1.1, Diff: 0.9, Sum: 1.7] [Object Copy (ms): Min: 41.0, Avg: 41.5, Max: 41.7, Diff: 0.7, Sum: 165.8] [Termination (ms): Min: 0.0, Avg: 0.4, Max: 0.6, Diff: 0.6, Sum: 1.8] [Termination Attempts: Min: 1, Avg: 3.2, Max: 6, Diff: 5, Sum: 13] [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.5, Avg: 52.6, Max: 52.6, Diff: 0.1, Sum: 210.4] [GC Worker End (ms): Min: 59625.5, Avg: 59625.5, Max: 59625.6, Diff: 0.0] [Code Root Fixup: 0.4 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 4.0 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [Table Fixup (ms): Min: 0.9, Avg: 3.1, Max: 3.9, Diff: 3.0, Sum: 12.4] [Clear CT: 0.2 ms] [Other: 3.8 ms] [Choose CSet: 0.0 ms] [Ref Proc: 2.6 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.5 ms] [Eden: 535.0M(535.0M)->0.0B(516.0M) Survivors: 54.0M->54.0M Heap: 825.0M(1024.0M)->307.1M(1024.0M)] Heap after GC invocations=29 (full 0): garbage-first heap total 1048576K, used 314456K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 54 young (55296K), 54 survivors (55296K) Metaspace used 116285K, capacity 134244K, committed 134428K, reserved 1165312K class space used 13415K, capacity 18448K, committed 18508K, reserved 1048576K } [Times: user=0.21 sys=0.00, real=0.06 secs] 2017-04-02T19:02:29.074+0000: 59.639: [GC concurrent-string-deduplication, 771.9K->182.5K(589.4K), avg 40.1%, 0.0035680 secs] {Heap before GC invocations=29 (full 0): garbage-first heap total 1048576K, used 843864K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 570 young (583680K), 54 survivors (55296K) Metaspace used 118516K, capacity 136470K, committed 136732K, reserved 1167360K class space used 13686K, capacity 18714K, committed 18764K, reserved 1048576K 2017-04-02T19:02:33.515+0000: 64.080: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 37748736 bytes, new threshold 4 (max 15) - age 1: 25031664 bytes, 25031664 total - age 2: 7304840 bytes, 32336504 total - age 3: 3076072 bytes, 35412576 total - age 4: 11138168 bytes, 46550744 total 64.080: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 13596, predicted base time: 32.17 ms, remaining time: 167.83 ms, target pause time: 200.00 ms] 64.080: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 516 regions, survivors: 54 regions, predicted young region time: 66.98 ms] 64.080: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 516 regions, survivors: 54 regions, old: 0 regions, predicted pause time: 99.15 ms, target pause time: 200.00 ms] 2017-04-02T19:02:33.556+0000: 64.121: [SoftReference, 0 refs, 0.0004649 secs]2017-04-02T19:02:33.557+0000: 64.121: [WeakReference, 1597 refs, 0.0002916 secs]2017-04-02T19:02:33.557+0000: 64.122: [FinalReference, 3655 refs, 0.0011960 secs]2017-04-02T19:02:33.558+0000: 64.123: [PhantomReference, 281 refs, 7 refs, 0.0004972 secs]2017-04-02T19:02:33.559+0000: 64.124: [JNI Weak Reference, 0.0000149 secs], 0.0486496 secs] [Parallel Time: 40.6 ms, GC Workers: 4] [GC Worker Start (ms): Min: 64080.0, Avg: 64080.0, Max: 64080.0, Diff: 0.0] [Ext Root Scanning (ms): Min: 1.8, Avg: 3.1, Max: 4.4, Diff: 2.6, Sum: 12.3] [Update RS (ms): Min: 5.2, Avg: 6.8, Max: 7.7, Diff: 2.5, Sum: 27.2] [Processed Buffers: Min: 22, Avg: 41.2, Max: 69, Diff: 47, Sum: 165] [Scan RS (ms): Min: 3.2, Avg: 3.5, Max: 3.7, Diff: 0.6, Sum: 14.1] [Code Root Scanning (ms): Min: 0.0, Avg: 0.4, Max: 0.9, Diff: 0.9, Sum: 1.6] [Object Copy (ms): Min: 25.6, Avg: 26.6, Max: 27.2, Diff: 1.6, Sum: 106.5] [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: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.2] [GC Worker Total (ms): Min: 40.4, Avg: 40.5, Max: 40.5, Diff: 0.1, Sum: 162.0] [GC Worker End (ms): Min: 64120.4, Avg: 64120.5, Max: 64120.5, Diff: 0.1] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 3.6 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.2] [Table Fixup (ms): Min: 3.3, Avg: 3.4, Max: 3.4, Diff: 0.2, Sum: 13.5] [Clear CT: 0.2 ms] [Other: 3.9 ms] [Choose CSet: 0.0 ms] [Ref Proc: 2.7 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.5 ms] [Eden: 516.0M(516.0M)->0.0B(511.0M) Survivors: 54.0M->50.0M Heap: 824.1M(1024.0M)->315.1M(1024.0M)] Heap after GC invocations=30 (full 0): garbage-first heap total 1048576K, used 322648K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 50 young (51200K), 50 survivors (51200K) Metaspace used 118516K, capacity 136470K, committed 136732K, reserved 1167360K class space used 13686K, capacity 18714K, committed 18764K, reserved 1048576K } [Times: user=0.17 sys=0.01, real=0.05 secs] 2017-04-02T19:02:33.569+0000: 64.134: [GC concurrent-string-deduplication, 1459.2K->209.2K(1250.1K), avg 42.0%, 0.0058331 secs] 67.211: [G1Ergonomics (Concurrent Cycles) request concurrent cycle initiation, reason: requested by GC cause, GC cause: Metadata GC Threshold] {Heap before GC invocations=30 (full 0): garbage-first heap total 1048576K, used 548952K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 271 young (277504K), 50 survivors (51200K) Metaspace used 119529K, capacity 137506K, committed 137628K, reserved 1167360K class space used 13773K, capacity 18816K, committed 18892K, reserved 1048576K 67.211: [G1Ergonomics (Concurrent Cycles) initiate concurrent cycle, reason: concurrent cycle initiation requested] 2017-04-02T19:02:36.647+0000: 67.211: [GC pause (Metadata GC Threshold) (young) (initial-mark) Desired survivor size 37224448 bytes, new threshold 3 (max 15) - age 1: 10803216 bytes, 10803216 total - age 2: 22180424 bytes, 32983640 total - age 3: 4752312 bytes, 37735952 total - age 4: 2382016 bytes, 40117968 total 67.212: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 10703, predicted base time: 27.09 ms, remaining time: 172.91 ms, target pause time: 200.00 ms] 67.212: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 221 regions, survivors: 50 regions, predicted young region time: 47.09 ms] 67.212: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 221 regions, survivors: 50 regions, old: 0 regions, predicted pause time: 74.18 ms, target pause time: 200.00 ms] 2017-04-02T19:02:36.679+0000: 67.244: [SoftReference, 0 refs, 0.0004743 secs]2017-04-02T19:02:36.680+0000: 67.245: [WeakReference, 883 refs, 0.0002149 secs]2017-04-02T19:02:36.680+0000: 67.245: [FinalReference, 1669 refs, 0.0008177 secs]2017-04-02T19:02:36.681+0000: 67.246: [PhantomReference, 93 refs, 6 refs, 0.0006239 secs]2017-04-02T19:02:36.681+0000: 67.246: [JNI Weak Reference, 0.0000190 secs], 0.0389940 secs] [Parallel Time: 31.7 ms, GC Workers: 4] [GC Worker Start (ms): Min: 67212.2, Avg: 67212.4, Max: 67212.9, Diff: 0.6] [Ext Root Scanning (ms): Min: 2.6, Avg: 3.4, Max: 5.2, Diff: 2.6, Sum: 13.7] [Update RS (ms): Min: 4.9, Avg: 6.4, Max: 7.2, Diff: 2.4, Sum: 25.7] [Processed Buffers: Min: 17, Avg: 29.0, Max: 42, Diff: 25, Sum: 116] [Scan RS (ms): Min: 2.3, Avg: 2.6, Max: 2.9, Diff: 0.6, Sum: 10.3] [Code Root Scanning (ms): Min: 0.0, Avg: 0.4, Max: 1.0, Diff: 1.0, Sum: 1.4] [Object Copy (ms): Min: 18.0, Avg: 18.3, Max: 18.6, Diff: 0.6, Sum: 73.3] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0] [Termination Attempts: Min: 1, Avg: 1.8, Max: 4, Diff: 3, Sum: 7] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.2] [GC Worker Total (ms): Min: 30.7, Avg: 31.1, Max: 31.3, Diff: 0.6, Sum: 124.6] [GC Worker End (ms): Min: 67243.5, Avg: 67243.5, Max: 67243.6, Diff: 0.0] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 3.2 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1] [Table Fixup (ms): Min: 3.0, Avg: 3.1, Max: 3.1, Diff: 0.0, Sum: 12.2] [Clear CT: 0.2 ms] [Other: 3.6 ms] [Choose CSet: 0.0 ms] [Ref Proc: 2.4 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.3 ms] [Eden: 221.0M(511.0M)->0.0B(522.0M) Survivors: 50.0M->40.0M Heap: 536.2M(1024.0M)->313.1M(1024.0M)] Heap after GC invocations=31 (full 0): garbage-first heap total 1048576K, used 320600K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 40 young (40960K), 40 survivors (40960K) Metaspace used 119529K, capacity 137506K, committed 137628K, reserved 1167360K class space used 13773K, capacity 18816K, committed 18892K, reserved 1048576K } [Times: user=0.14 sys=0.01, real=0.04 secs] 2017-04-02T19:02:36.686+0000: 67.251: [GC concurrent-root-region-scan-start] 2017-04-02T19:02:36.690+0000: 67.255: [GC concurrent-string-deduplication, 660.1K->155.5K(504.5K), avg 42.6%, 0.0036262 secs] 2017-04-02T19:02:36.707+0000: 67.271: [GC concurrent-root-region-scan-end, 0.0207870 secs] 2017-04-02T19:02:36.707+0000: 67.271: [GC concurrent-mark-start] 67.290: [G1Ergonomics (Concurrent Cycles) do not request concurrent cycle initiation, reason: concurrent cycle already in progress, GC cause: Metadata GC Threshold] 67.311: [G1Ergonomics (Concurrent Cycles) do not request concurrent cycle initiation, reason: concurrent cycle already in progress, GC cause: Metadata GC Threshold] 67.335: [G1Ergonomics (Concurrent Cycles) do not request concurrent cycle initiation, reason: concurrent cycle already in progress, GC cause: Metadata GC Threshold] 67.349: [G1Ergonomics (Concurrent Cycles) do not request concurrent cycle initiation, reason: concurrent cycle already in progress, GC cause: Metadata GC Threshold] 67.383: [G1Ergonomics (Concurrent Cycles) do not request concurrent cycle initiation, reason: concurrent cycle already in progress, GC cause: Metadata GC Threshold] 67.404: [G1Ergonomics (Concurrent Cycles) do not request concurrent cycle initiation, reason: concurrent cycle already in progress, GC cause: Metadata GC Threshold] 67.443: [G1Ergonomics (Concurrent Cycles) do not request concurrent cycle initiation, reason: concurrent cycle already in progress, GC cause: Metadata GC Threshold] 2017-04-02T19:02:37.185+0000: 67.750: [GC concurrent-mark-end, 0.4786975 secs] 2017-04-02T19:02:37.186+0000: 67.751: [GC remark 2017-04-02T19:02:37.186+0000: 67.751: [Finalize Marking, 0.0004909 secs] 2017-04-02T19:02:37.187+0000: 67.751: [GC ref-proc2017-04-02T19:02:37.187+0000: 67.751: [SoftReference, 0 refs, 0.0004035 secs]2017-04-02T19:02:37.187+0000: 67.752: [WeakReference, 14018 refs, 0.0017316 secs]2017-04-02T19:02:37.189+0000: 67.754: [FinalReference, 153 refs, 0.0003667 secs]2017-04-02T19:02:37.189+0000: 67.754: [PhantomReference, 32 refs, 62 refs, 0.0005807 secs]2017-04-02T19:02:37.190+0000: 67.755: [JNI Weak Reference, 0.0000424 secs], 0.0032883 secs] 2017-04-02T19:02:37.190+0000: 67.755: [Unloading, 0.0297027 secs], 0.0346749 secs] [Times: user=0.11 sys=0.00, real=0.04 secs] 2017-04-02T19:02:37.225+0000: 67.790: [GC cleanup 342M->340M(1024M), 0.0022476 secs] [Times: user=0.01 sys=0.00, real=0.00 secs] 2017-04-02T19:02:37.228+0000: 67.793: [GC concurrent-cleanup-start] 2017-04-02T19:02:37.228+0000: 67.793: [GC concurrent-cleanup-end, 0.0000173 secs] {Heap before GC invocations=32 (full 0): garbage-first heap total 1048576K, used 863140K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 562 young (575488K), 40 survivors (40960K) Metaspace used 122184K, capacity 140174K, committed 140612K, reserved 1171456K class space used 14073K, capacity 19126K, committed 19248K, reserved 1048576K 73.017: [G1Ergonomics (Concurrent Cycles) initiate concurrent cycle, reason: concurrent cycle initiation requested] 2017-04-02T19:02:42.452+0000: 73.017: [GC pause (G1 Evacuation Pause) (young) (initial-mark) Desired survivor size 37224448 bytes, new threshold 15 (max 15) - age 1: 6480008 bytes, 6480008 total - age 2: 4535824 bytes, 11015832 total - age 3: 22139848 bytes, 33155680 total 73.017: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 13098, predicted base time: 26.56 ms, remaining time: 173.44 ms, target pause time: 200.00 ms] 73.017: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 522 regions, survivors: 40 regions, predicted young region time: 42.25 ms] 73.017: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 522 regions, survivors: 40 regions, old: 0 regions, predicted pause time: 68.80 ms, target pause time: 200.00 ms] 2017-04-02T19:02:42.484+0000: 73.049: [SoftReference, 0 refs, 0.0005515 secs]2017-04-02T19:02:42.485+0000: 73.049: [WeakReference, 1261 refs, 0.0005610 secs]2017-04-02T19:02:42.485+0000: 73.050: [FinalReference, 2648 refs, 0.0009019 secs]2017-04-02T19:02:42.486+0000: 73.051: [PhantomReference, 152 refs, 5 refs, 0.0007678 secs]2017-04-02T19:02:42.487+0000: 73.052: [JNI Weak Reference, 0.0000206 secs] 73.056: [G1Ergonomics (Mixed GCs) do not start mixed GCs, reason: concurrent cycle is about to start] , 0.0393394 secs] [Parallel Time: 31.0 ms, GC Workers: 4] [GC Worker Start (ms): Min: 73017.7, Avg: 73017.7, Max: 73017.7, Diff: 0.1] [Ext Root Scanning (ms): Min: 2.7, Avg: 3.5, Max: 5.2, Diff: 2.4, Sum: 14.2] [Update RS (ms): Min: 7.8, Avg: 9.1, Max: 9.7, Diff: 2.0, Sum: 36.3] [Processed Buffers: Min: 32, Avg: 36.5, Max: 40, Diff: 8, Sum: 146] [Scan RS (ms): Min: 1.6, Avg: 1.7, Max: 1.8, Diff: 0.2, Sum: 6.7] [Code Root Scanning (ms): Min: 0.0, Avg: 0.3, Max: 0.6, Diff: 0.6, Sum: 1.2] [Object Copy (ms): Min: 15.6, Avg: 15.9, Max: 16.2, Diff: 0.6, Sum: 63.6] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1] [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.0, Sum: 0.1] [GC Worker Total (ms): Min: 30.5, Avg: 30.6, Max: 30.6, Diff: 0.1, Sum: 122.2] [GC Worker End (ms): Min: 73048.3, Avg: 73048.3, Max: 73048.3, Diff: 0.0] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 3.6 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 0.2] [Table Fixup (ms): Min: 0.0, Avg: 2.5, Max: 3.4, Diff: 3.4, Sum: 10.1] [Clear CT: 0.2 ms] [Other: 4.3 ms] [Choose CSet: 0.0 ms] [Ref Proc: 3.1 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.4 ms] [Eden: 522.0M(522.0M)->0.0B(501.0M) Survivors: 40.0M->43.0M Heap: 842.9M(1024.0M)->323.9M(1024.0M)] Heap after GC invocations=33 (full 0): garbage-first heap total 1048576K, used 331685K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 43 young (44032K), 43 survivors (44032K) Metaspace used 122184K, capacity 140174K, committed 140612K, reserved 1171456K class space used 14073K, capacity 19126K, committed 19248K, reserved 1048576K } [Times: user=0.14 sys=0.00, real=0.04 secs] 2017-04-02T19:02:42.492+0000: 73.057: [GC concurrent-root-region-scan-start] 2017-04-02T19:02:42.507+0000: 73.071: [GC concurrent-string-deduplication, 1925.0K->499.0K(1425.9K), avg 44.2%, 0.0137423 secs] 2017-04-02T19:02:42.522+0000: 73.087: [GC concurrent-root-region-scan-end, 0.0304172 secs] 2017-04-02T19:02:42.522+0000: 73.087: [GC concurrent-mark-start] 2017-04-02T19:02:42.915+0000: 73.479: [GC concurrent-mark-end, 0.3924914 secs] 2017-04-02T19:02:42.915+0000: 73.480: [GC remark 2017-04-02T19:02:42.915+0000: 73.480: [Finalize Marking, 0.0003592 secs] 2017-04-02T19:02:42.916+0000: 73.481: [GC ref-proc2017-04-02T19:02:42.916+0000: 73.481: [SoftReference, 0 refs, 0.0005638 secs]2017-04-02T19:02:42.916+0000: 73.481: [WeakReference, 14320 refs, 0.0016386 secs]2017-04-02T19:02:42.918+0000: 73.483: [FinalReference, 11 refs, 0.0002372 secs]2017-04-02T19:02:42.918+0000: 73.483: [PhantomReference, 9 refs, 53 refs, 0.0005024 secs]2017-04-02T19:02:42.919+0000: 73.484: [JNI Weak Reference, 0.0000334 secs], 0.0031303 secs] 2017-04-02T19:02:42.919+0000: 73.484: [Unloading, 0.0290866 secs], 0.0338539 secs] [Times: user=0.10 sys=0.00, real=0.03 secs] 2017-04-02T19:02:42.952+0000: 73.517: [GC cleanup 343M->343M(1024M), 0.0024935 secs] [Times: user=0.00 sys=0.00, real=0.00 secs] {Heap before GC invocations=34 (full 0): garbage-first heap total 1048576K, used 844709K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 544 young (557056K), 43 survivors (44032K) Metaspace used 122576K, capacity 140612K, committed 140868K, reserved 1171456K class space used 14104K, capacity 19193K, committed 19248K, reserved 1048576K 2017-04-02T19:02:53.540+0000: 84.105: [GC pause (G1 Evacuation Pause) (young) Desired survivor size 35651584 bytes, new threshold 4 (max 15) - age 1: 6573096 bytes, 6573096 total - age 2: 4888136 bytes, 11461232 total - age 3: 4365864 bytes, 15827096 total - age 4: 21503256 bytes, 37330352 total 84.105: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 13814, predicted base time: 26.06 ms, remaining time: 173.94 ms, target pause time: 200.00 ms] 84.105: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 501 regions, survivors: 43 regions, predicted young region time: 34.39 ms] 84.105: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 501 regions, survivors: 43 regions, old: 0 regions, predicted pause time: 60.45 ms, target pause time: 200.00 ms] 2017-04-02T19:02:53.564+0000: 84.129: [SoftReference, 0 refs, 0.0005067 secs]2017-04-02T19:02:53.564+0000: 84.129: [WeakReference, 576 refs, 0.0001675 secs]2017-04-02T19:02:53.564+0000: 84.129: [FinalReference, 1392 refs, 0.0017633 secs]2017-04-02T19:02:53.566+0000: 84.131: [PhantomReference, 24 refs, 4 refs, 0.0003690 secs]2017-04-02T19:02:53.567+0000: 84.132: [JNI Weak Reference, 0.0000176 secs] 84.136: [G1Ergonomics (Mixed GCs) do not start mixed GCs, reason: reclaimable percentage not over threshold, candidate old regions: 64 regions, reclaimable: 33708632 bytes (3.14 %), threshold: 5.00 %] , 0.0315837 secs] [Parallel Time: 23.3 ms, GC Workers: 4] [GC Worker Start (ms): Min: 84105.0, Avg: 84105.1, Max: 84105.1, Diff: 0.1] [Ext Root Scanning (ms): Min: 2.0, Avg: 2.9, Max: 4.5, Diff: 2.5, Sum: 11.7] [Update RS (ms): Min: 4.0, Avg: 5.4, Max: 6.0, Diff: 2.0, Sum: 21.5] [Processed Buffers: Min: 20, Avg: 35.2, Max: 53, Diff: 33, Sum: 141] [Scan RS (ms): Min: 0.1, Avg: 0.2, Max: 0.2, Diff: 0.1, Sum: 0.7] [Code Root Scanning (ms): Min: 0.0, Avg: 0.3, Max: 0.6, Diff: 0.6, Sum: 1.2] [Object Copy (ms): Min: 14.0, Avg: 14.4, Max: 14.9, Diff: 0.9, Sum: 57.5] [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.1, Diff: 0.1, Sum: 0.1] [Termination Attempts: Min: 1, Avg: 1.0, Max: 1, Diff: 0, Sum: 4] [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [GC Worker Total (ms): Min: 23.1, Avg: 23.2, Max: 23.2, Diff: 0.1, Sum: 92.7] [GC Worker End (ms): Min: 84128.2, Avg: 84128.2, Max: 84128.3, Diff: 0.0] [Code Root Fixup: 0.3 ms] [Code Root Purge: 0.0 ms] [String Dedup Fixup: 3.6 ms, GC Workers: 4] [Queue Fixup (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1] [Table Fixup (ms): Min: 0.0, Avg: 2.7, Max: 3.6, Diff: 3.6, Sum: 10.6] [Clear CT: 0.2 ms] [Other: 4.2 ms] [Choose CSet: 0.0 ms] [Ref Proc: 3.0 ms] [Ref Enq: 0.1 ms] [Redirty Cards: 0.1 ms] [Humongous Register: 0.1 ms] [Humongous Reclaim: 0.0 ms] [Free CSet: 0.4 ms] [Eden: 501.0M(501.0M)->0.0B(530.0M) Survivors: 43.0M->19.0M Heap: 824.9M(1024.0M)->318.8M(1024.0M)] Heap after GC invocations=35 (full 0): garbage-first heap total 1048576K, used 326488K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 19 young (19456K), 19 survivors (19456K) Metaspace used 122576K, capacity 140612K, committed 140868K, reserved 1171456K class space used 14104K, capacity 19193K, committed 19248K, reserved 1048576K } [Times: user=0.11 sys=0.00, real=0.03 secs] 2017-04-02T19:02:53.573+0000: 84.138: [GC concurrent-string-deduplication, 365.0K->63.0K(302.0K), avg 44.6%, 0.0018821 secs] Heap garbage-first heap total 1048576K, used 830296K [0x0000000080000000, 0x0000000080102000, 0x0000000100000000) region size 1024K, 512 young (524288K), 19 survivors (19456K) Metaspace used 125710K, capacity 143962K, committed 144248K, reserved 1173504K class space used 14510K, capacity 19592K, committed 19632K, reserved 1048576K