Java垃圾回收器G1GC在“对象复制”（疏散暂停）过程中花费时间较长

Question

Java垃圾回收器G1GC在“对象复制”（疏散暂停）过程中花费时间较长

13

我不是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对此仍然要执行"停止整个世界(stop the world)"操作呢？（或者至少我看到它在这个时候停止了我的应用程序）。如果可用RAM空间超过12％，那么为什么需要进行如此负面的清理呢？另外，我认为-XX:MaxGCPauseMillis的默认值是200毫秒，为什么该值会被违反29倍甚至50倍（请参见下文）？

另一个延迟的原因是：

[GC pause (Metadata GC Threshold) (young) (initial-mark) 40G->39G(48G), 10.4667233 secs]

这可能通过这个答案得到解决，例如只需要增加元数据空间-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, 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 pause (young)]。或同时使用年轻和老一代区域进行操作，这些区域会被标记为[GC Pause (mixed)]。

- Karussell

你有阅读官方文档吗？ - the8472

是的，当然。这些链接是 http://docs.oracle.com/javase/8/docs/technotes/guides/vm/gctuning/g1_gc.html 和 http://docs.oracle.com/javase/8/docs/technotes/guides/vm/gctuning/g1_gc_tuning.html。 - Karussell

你是否在应用程序中明确调用了 System.gc() 方法？ - Mick Mnemonic

不，我不会显式调用gc()。 - Karussell

无论如何，尝试使用“-XX：+DisableExplicitGC”不会有任何损失。 - Mick Mnemonic

我的应用程序有许多分配，可以轻松地称为“巨大的分配”。现在我读到了使用G1GC时应避免这些分配。如果我知道我有约38g的基本RAM使用率和仅有几个GB的活动对象，我应该调整什么？请参考此演示文稿http://presentations2015.s3.amazonaws.com/40_presentation.pdf。 - Karussell

2个回答

0

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

- user12137499

网页内容由stack overflow 提供, 点击上面的

可以查看英文原文，
原文链接

- the8472 · Accepted Answer

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

它是，但这只是一个目标，而不是保证。许多事情会导致它无法达到该目标。你的堆相当大，这使得事情更加困难，即故障更容易引起。

无论如何，GC调优之旅始于通过启用verbose GC日志记录来进行。

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

更新：这些选项适用于热点8.9及更高版本，请使用统一日志记录，该选项具有不同的参数格式。

然后通过GCViewer运行结果日志以获得概述，并返回读取单个日志条目（关于此主题有许多答案/博客文章）以找出可能导致最差行为的原因。根据原因可以尝试各种补救措施。

一些关于追踪垃圾收集器如何工作的基本理解和G1将是必要的，以避免盲目跟从。

我的应用程序有许多可以轻松称为“庞大分配”的分配。

如果实际上是这个原因，则当前的VM有一些实验性选项可以更快地回收它们。

 [Object Copy (ms): Min: 6964.1, Avg: 6973.0, Max: 6989.5, Diff: 25.3, Sum: 69730.4]
 [Times: user=0.55 sys=46.58, real=7.02 secs]

这意味着在执行大部分由内存访问而非系统调用组成的任务时，它会花费大量时间在内核中。因此，交换活动或透明巨大页面很可能是罪魁祸首。