Java垃圾收集器G1GC为“对象复制”花费了很长时间(疏散暂停)

Question

我不是Java，但我对垃圾收集只知道一点点。现在我想用一些实际的经验来改变这一点。我的目标是延迟不到0.3秒，或者在极端情况下，0.5也可以。

我有一个使用-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]

这可能会解决通过这个答案问题，例如仅仅增加元数据空间-XX:MetaspaceSize=100M

BTW:使用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, eden: 136 regions, survivors: 20 regions, 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, Diff: 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, Avg: 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] 

阅读这里关于它:复制(停止世界事件)-这些是停止世界暂停疏散或复制活动对象到新的未使用的区域。这可以通过年轻的生成区域来完成，这些区域记录为GC暂停( young )。或者记录为GC暂停(混合)的年轻和老代区域。

Answer 1

为什么GCG1还在为这个做一个“阻止世界”呢？

因为G1不是一个无用的收集器，它只是一个低暂停的收集器。

此外，我还认为-XX:MaxGCPauseMillis的默认值是200毫秒，为什么这个值被违反了29倍，甚至50倍(见下文)？

是的，但这只是一个目标，而不是保证。很多事情都会导致它不能达到这个目标。你有一个相当大的堆，这使得事情变得更加困难，即失败更容易引发。

无论如何，GC调优过程从启用详细的GC日志记录开始

-Xloggc:<path to gc log file>
-XX:+PrintAdaptiveSizePolicy
-XX:+PrintGCDateStamps
-XX:+PrintGCTimeStamps
-XX:+PrintGCDetails

更新:这些选项用于hotspot 8.9，并在以后使用具有不同参数格式的统一测井。

然后在GCViewer中运行生成的日志以获得一个总体概述，然后返回到读取单个日志条目 (关于这个主题有许多答案/博客文章)，以找出可能导致最糟糕行为的原因。根据原因，可以尝试各种补救办法。

对于跟踪垃圾收集器的一般工作方式和G1的一般理解是必要的，以避免货物偷盗。

我的应用程序有很多分配，可以很容易地称为“巨大的分配”。

如果这是真正的原因，那么当前的VM有一些实验选项来更快地收回它们。

对象复制(ms)：Min: 6964.1，Avg: 6973.0，最大值: 6989.5，差: 25.3，和: 69730.4

这意味着它大部分时间都花在内核上，做一些应该主要由内存访问而不是系统调用组成的事情。因此，交换活动或透明大页可能是可疑的。

Answer 2

请注意，GC工作线程的数量为10。如果系统CPU数量较少，则会发生严重的资源争用，导致内存副本的时间消耗显著增加。