我有一个带有-Xmx50gb(-Xms50gb)的应用程序,并设置了另一个GC选项：
-XX:+UseG1GC -Xloggc:somewhere.gc.log -XX:+PrintGCDateStamps
但是现在我偶尔因为垃圾收集而长时间停顿超过5秒,尽管似乎有足够的可用内存.我找到的一个原因：
[GC pause (G1 Evacuation Pause) (young) 42G->40G(48G),5.9409662 secs]
为什么GCG1仍然为此做“停止世界”？ (或者至少我看到它正好在这个时候停止我的应用程序)为什么它会做这样的负面清理,如果它不是真的有必要,因为有超过12％的可用RAM空闲.另外我认为-XX：MaxGCPauseMillis的默认值是200毫秒,为什么这个值被违反了29或甚至50(见下文)？
延迟的另一个原因是：
[GC pause (Metadata GC Threshold) (young) (initial-mark) 40G->39G(48G),10.4667233 secs]
这可能会解决via this answer例如只是增加元数据空间-XX：MetaspaceSize = 100M
顺便说一句：使用JSE 1.8.0_91-b14
更新：此类事件的详细GC日志
2016-08-12T09:20:31.589+0200: 1178.312: [GC pause (G1 Evacuation Pause) (young) 1178.312: [G1Ergonomics (CSet Construction) start choosing CSet,_pending_cards: 3159,predicted base time: 1.52 ms,remaining time: 198.48 ms,target pause time: 200.00 ms]
1178.312: [G1Ergonomics (CSet Construction) add young regions to CSet,eden: 136 regions,survivors: 20 regions,predicted young region time: 1924.75 ms]
1178.312: [G1Ergonomics (CSet Construction) finish choosing CSet,old: 0 regions,predicted pause time: 1926.27 ms,target pause time: 200.00 ms]
1185.330: [G1Ergonomics (Heap Sizing) attempt heap expansion,reason: recent GC overhead higher than threshold after GC,recent GC overhead: 21.83 %,threshold: 10.00 %,uncommitted: 0 bytes,calculated expansion amount: 0 bytes (20.00 %)]
1185.330: [G1Ergonomics (Concurrent Cycles) do not request concurrent cycle initiation,reason: still doing mixed collections,occupancy: 42580574208 bytes,allocation request: 0 bytes,threshold: 23592960000 bytes (45.00 %),source: end of GC]
1185.330: [G1Ergonomics (Mixed GCs) do not start mixed GCs,reason: reclaimable percentage not over threshold,candidate old regions: 1 regions,reclaimable: 3381416 bytes (0.01 %),threshold: 5.00 %],7.0181903 secs]
[Parallel Time: 6991.8 ms,GC Workers: 10]
[GC Worker Start (ms): Min: 1178312.6,Avg: 1178312.8,Max: 1178312.9,Diff: 0.2]
[Ext Root Scanning (ms): Min: 1.1,Avg: 1.5,Max: 2.3,Diff: 1.2,Sum: 15.0]
[Update RS (ms): Min: 0.0,Avg: 0.3,Max: 1.3,Diff: 1.3,Sum: 3.4]
[Processed Buffers: Min: 0,Avg: 2.1,Max: 5,Diff: 5,Sum: 21]
[Scan RS (ms): Min: 0.0,Avg: 0.0,Max: 0.1,Diff: 0.1,Sum: 0.4]
[Code Root Scanning (ms): Min: 0.0,Avg: 0.2,Max: 0.4,Diff: 0.4,Sum: 1.7]
[Object Copy (ms): Min: 6964.1,Avg: 6973.0,Max: 6989.5,Diff: 25.3,Sum: 69730.4]
[Termination (ms): Min: 0.0,Avg: 16.4,Max: 25.3,Sum: 164.4]
[Termination Attempts: Min: 1,Avg: 3.2,Max: 13,Diff: 12,Sum: 32]
[GC Worker Other (ms): Min: 0.0,Max: 0.0,Diff: 0.0,Sum: 0.2]
[GC Worker Total (ms): Min: 6991.5,Avg: 6991.6,Max: 6991.7,Diff: 0.2,Sum: 69915.5]
[GC Worker End (ms): Min: 1185304.3,Avg: 1185304.3,Max: 1185304.3,Diff: 0.0]
[Code Root Fixup: 0.1 ms]
[Code Root Purge: 0.0 ms]
[Clear CT: 0.3 ms]
[Other: 26.0 ms]
[Choose CSet: 0.0 ms]
[Ref Proc: 25.3 ms]
[Ref Enq: 0.1 ms]
[Redirty Cards: 0.1 ms]
[Humongous Register: 0.2 ms]
[Humongous Reclaim: 0.0 ms]
[Free CSet: 0.2 ms]
[Eden: 2176.0M(2176.0M)->0.0B(2176.0M) Survivors: 320.0M->320.0M Heap: 40.6G(48.8G)->40.0G(48.8G)]
[Times: user=0.55 sys=46.58,real=7.02 secs]
阅读here关于它：复制(停止世界事件) – 这些是世界暂停撤离或将活动对象复制到新的未使用区域的停止.这可以通过记录为[GC暂停(年轻)]的年轻代区域来完成.或者记录为[GC暂停(混合)]的年轻和老一代区域.
解决方法
Why is GCG1 still doing a “stop the world” for this?
因为G1不是一个无暂停的收集器,它只是一个低暂停收集器.
@H_403_30@Also I thought that the default value for -XX:MaxGCPauseMillis is 200 milliseconds,why is this value violated by a factor of 29 or even 50 (see below)?
它是,但它只是一个目标,而不是保证.许多事情都可能导致它无法实现这一目标.你有一个相当大的堆,这使事情变得更加困难,即失败更容易引发.
无论如何,GC调整之旅始于启用详细的GC日志记录
-Xloggc:<path to gc log file> -XX:+PrintAdaptiveSizePolicy -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+PrintGCDetails
然后通过GCViewer运行生成的日志以获得一般概述,然后返回到reading individual log entries(关于此主题有很多答案/博客帖子),以找出可能导致最糟糕行为的原因.根据原因,可以尝试各种补救措施.
对于追踪垃圾收集器如何工作以及G1的一般性理解将是必要的,以避免货物结果.
@H_403_30@My application has many allocations which could be easily called “humongous allocations”.
如果这确实是原因,那么当前的VM有一些experimental options可以更快地回收它们.
@H_403_30@06001
这意味着在执行主要由内存访问而非系统调用组成的内容时,它大部分时间都花在内核中.交换活动或transparent huge pages可能是嫌疑人.
