性能问答>700M的堆young gc时用了70秒>
7回复
3年前

700M的堆young gc时用了70秒



环境:
java version “1.8.0_45”
Java HotSpot™ 64-Bit Server VM (build 25.45-b02, mixed mode)
Linux version 3.10.0-862.mt20190308.130.el7.x86_64 (root@gh-hulk-k8s-ep01) (gcc version 4.8.5 20150623 (Red Hat 4.8.5-11) (GCC) ) #1 SMP Fri Mar 8 06:37:16 UTC 2019
CentOS release 6.8 (Final)

GC日志
[Times: user=0.04 sys=0.01, real=0.35 secs]
2019-12-12T16:58:56.080+0800: 624216.197: Total time for which application threads were stopped: 0.4716215 seconds, Stopping threads took: 0.0001637 seconds
{Heap before GC invocations=3861 (full 0):
garbage-first heap total 6291456K, used 699144K [0x0000000640000000, 0x0000000640403000, 0x00000007c0000000)
region size 4096K, 76 young (311296K), 3 survivors (12288K)
Metaspace used 147487K, capacity 151988K, committed 152192K, reserved 1183744K
class space used 16748K, capacity 17703K, committed 17792K, reserved 1048576K
2019-12-12T16:59:12.061+0800: 624232.177: [GC pause (G1 Evacuation Pause) (young)
Desired survivor size 20971520 bytes, new threshold 15 (max 15)

  • age 1: 1886968 bytes, 1886968 total
  • age 2: 239392 bytes, 2126360 total
  • age 3: 102464 bytes, 2228824 total
  • age 4: 276920 bytes, 2505744 total
  • age 5: 22824 bytes, 2528568 total
  • age 6: 319288 bytes, 2847856 total
  • age 7: 340312 bytes, 3188168 total
  • age 8: 322072 bytes, 3510240 total
  • age 9: 501176 bytes, 4011416 total
  • age 10: 451264 bytes, 4462680 total
  • age 11: 701304 bytes, 5163984 total
  • age 12: 497560 bytes, 5661544 total
  • age 13: 494368 bytes, 6155912 total
  • age 14: 404664 bytes, 6560576 total
  • age 15: 348944 bytes, 6909520 total
    624232.712: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 3220, predicted base time: 314.99 ms, remaining time: 0.00 ms, target pause time:200.00 ms]
    624232.712: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 73 regions, survivors: 3 regions, predicted young region time: 18.77 ms]
    624232.712: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 73 regions, survivors: 3 regions, old: 0 regions, predicted pause time: 333.76 ms, target pause time: 200.00 ms], 74.9579940 secs]
    [Parallel Time: 72933.5 ms, GC Workers: 4]
    [GC Worker Start (ms): Min: 624233673.7, Avg: 624233673.8, Max: 624233673.8, Diff: 0.1]
    [Ext Root Scanning (ms): Min: 5611.4, Avg: 6759.2, Max: 7143.2, Diff: 1531.8, Sum: 27037.0]
    [Update RS (ms): Min: 13300.8, Avg: 14061.3, Max: 15541.4, Diff: 2240.5, Sum: 56245.3]
    [Processed Buffers: Min: 2, Avg: 44.2, Max: 93, Diff: 91, Sum: 177]
    [Scan RS (ms): Min: 36455.3, Avg: 36455.3, Max: 36455.3, Diff: 0.0, Sum: 145821.3]
    [Code Root Scanning (ms): Min: 8663.3, Avg: 8663.3, Max: 8663.4, Diff: 0.0, Sum: 34653.4]
    [Object Copy (ms): Min: 4075.5, Avg: 4458.7, Max: 5606.3, Diff: 1530.8, Sum: 17834.6]
    [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
    [GC Worker Other (ms): Min: 1049.4, Avg: 2530.2, Max: 3290.9, Diff: 2241.4, Sum: 10120.6]
    [GC Worker Total (ms): Min: 72928.0, Avg: 72928.0, Max: 72928.1, Diff: 0.2, Sum: 291712.1]
    [GC Worker End (ms): Min: 624306601.8, Avg: 624306601.8, Max: 624306601.8, Diff: 0.1]
    [Code Root Fixup: 0.4 ms]
    [Code Root Purge: 0.0 ms]
    [Clear CT: 0.2 ms]
    [Other: 2023.9 ms]
    [Choose CSet: 0.0 ms]
    [Ref Proc: 25.1 ms]
    [Ref Enq: 0.0 ms]
    [Redirty Cards: 0.0 ms]
    [Humongous Reclaim: 0.0 ms]
    [Free CSet: 0.3 ms]
    [Eden: 292.0M(292.0M)->0.0B(288.0M) Survivors: 12.0M->16.0M Heap: 682.8M(6144.0M)->393.3M(6144.0M)]
    Heap after GC invocations=3862 (full 0):
    garbage-first heap total 6291456K, used 402775K [0x0000000640000000, 0x0000000640403000, 0x00000007c0000000)
    region size 4096K, 4 young (16384K), 4 survivors (16384K)
    Metaspace used 147487K, capacity 151988K, committed 152192K, reserved 1183744K
    class space used 16748K, capacity 17703K, committed 17792K, reserved 1048576K
    }
    [Times: user=0.05 sys=0.03, real=75.00 secs]
    2019-12-12T17:00:26.513+0800: 624306.629: Total time for which application threads were stopped: 76.8287768 seconds, Stopping threads took: 0.9801482 seconds
    2019-12-12T17:00:28.950+0800: 624309.066: Total time for which application threads were stopped: 1.4367328 seconds, Stopping threads took: 1.4328138 seconds
    2019-12-12T17:00:29.470+0800: 624309.586: Total time for which application threads were stopped: 0.4734412 seconds, Stopping threads took: 0.4705677 seconds
    {Heap before GC invocations=3862 (full 0):
    garbage-first heap total 6291456K, used 697687K [0x0000000640000000, 0x0000000640403000, 0x00000007c0000000)
    region size 4096K, 76 young (311296K), 4 survivors (16384K)
    Metaspace used 147489K, capacity 151988K, committed 152192K, reserved 1183744K
    class space used 16748K, capacity 17703K, committed 17792K, reserved 1048576K
    2019-12-12T17:00:29.575+0800: 624309.692: [GC pause (G1 Evacuation Pause) (young)
    Desired survivor size 20971520 bytes, new threshold 15 (max 15)
  • age 1: 2243136 bytes, 2243136 total
  • age 2: 250616 bytes, 2493752 total
  • age 3: 170696 bytes, 2664448 total
  • age 4: 93728 bytes, 2758176 total
  • age 5: 272336 bytes, 3030512 total
  • age 6: 22288 bytes, 3052800 total
  • age 7: 246392 bytes, 3299192 total
  • age 8: 338904 bytes, 3638096 total
  • age 9: 321736 bytes, 3959832 total
  • age 10: 500352 bytes, 4460184 total
  • age 11: 450928 bytes, 4911112 total
  • age 12: 701304 bytes, 5612416 total
  • age 13: 497560 bytes, 6109976 total
  • age 14: 494328 bytes, 6604304 total
  • age 15: 404664 bytes, 7008968 total
    624309.692: [G1Ergonomics (CSet Construction) start choosing CSet, _pending_cards: 7877, predicted base time: 26338.13 ms, remaining time: 0.00 ms, target pause time: 200.00 ms]
    624309.692: [G1Ergonomics (CSet Construction) add young regions to CSet, eden: 72 regions, survivors: 4 regions, predicted young region time: 2333.72 ms]
    624309.692: [G1Ergonomics (CSet Construction) finish choosing CSet, eden: 72 regions, survivors: 4 regions, old: 0 regions, predicted pause time: 28671.85 ms, target pause time: 200.00 ms]
    624309.708: [G1Ergonomics (Heap Sizing) attempt heap expansion, reason: recent GC overhead higher than threshold after GC, recent GC overhead: 11.91 %, threshold: 10.00 %, uncommitted: 0 bytes, calculated expansion amount: 0 bytes (20.
    00 %)]
    , 0.0162867 secs]
    [Parallel Time: 14.3 ms, GC Workers: 4]
    [GC Worker Start (ms): Min: 624309692.3, Avg: 624309692.3, Max: 624309692.3, Diff: 0.0]
    [Ext Root Scanning (ms): Min: 4.0, Avg: 4.2, Max: 4.4, Diff: 0.3, Sum: 16.8]
    [Update RS (ms): Min: 2.0, Avg: 2.1, Max: 2.2, Diff: 0.2, Sum: 8.5]
    [Processed Buffers: Min: 22, Avg: 73.0, Max: 112, Diff: 90, Sum: 292]
    [Scan RS (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
    [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
    [Object Copy (ms): Min: 7.8, Avg: 7.9, Max: 8.1, Diff: 0.3, Sum: 31.7]
    [Termination (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
    [GC Worker Other (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
    [GC Worker Total (ms): Min: 14.3, Avg: 14.3, Max: 14.3, Diff: 0.0, Sum: 57.2]
    [GC Worker End (ms): Min: 624309706.6, Avg: 624309706.6, Max: 624309706.6, Diff: 0.0]
    [Code Root Fixup: 0.4 ms]
    [Code Root Purge: 0.0 ms]
    [Clear CT: 0.1 ms]
    [Other: 1.5 ms]
    [Choose CSet: 0.0 ms]
    [Ref Proc: 0.2 ms]
    [Ref Enq: 0.0 ms]
    [Redirty Cards: 0.0 ms]
    [Humongous Reclaim: 0.0 ms]
    [Free CSet: 0.2 ms]
    [Eden: 288.0M(288.0M)->0.0B(280.0M) Survivors: 16.0M->24.0M Heap: 681.3M(6144.0M)->402.1M(6144.0M)]
    Heap after GC invocations=3863 (full 0):
    garbage-first heap total 6291456K, used 411706K [0x0000000640000000, 0x0000000640403000, 0x00000007c0000000)
    region size 4096K, 6 young (24576K), 6 survivors (24576K)
    Metaspace used 147489K, capacity 151988K, committed 152192K, reserved 1183744K
    class space used 16748K, capacity 17703K, committed 17792K, reserved 1048576K
    }
    [Times: user=0.05 sys=0.01, real=0.02 secs]
4912 阅读
请先登录,查看7条精彩评论吧
快去登录吧,你将获得
  • 浏览更多精彩评论
  • 和开发者讨论交流,共同进步