当前位置: 首页 > 知识库问答 >
问题:

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

金伟
2023-03-14

我不是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

顺便说一句:使用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暂停(年轻)]的年轻一代区域来完成。或者记录为[GC暂停(混合)]的年轻一代和老一代区域。

共有2个答案

张茂勋
2023-03-14

请注意,GC工作线程的数量是10。如果系统CPU的数量很小,就会发生严重的资源争用,导致内存拷贝的时间消耗显著增加。

田权
2023-03-14

为什么GCG1还在为此做“停止世界”?

因为G1不是无暂停收集器,所以它只是一个低暂停收集器。

我还认为-XX:MaxGCPauseMillis的默认值是200毫秒,为什么这个值会被29甚至50倍的因子所违反(见下文)?

是的,但这只是一个目标,不是保证。很多事情都可能导致它无法实现这一目标。你有一个相当大的堆,这使得事情更加困难,也就是说,失败更容易引发。

无论如何,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] 

这意味着它在执行主要由内存访问而不是系统调用组成的事情时花费了大部分时间在内核中。因此交换活动或透明的大页面可能是可疑的。

 类似资料:
  • 问题内容: 我不是Java的新手,但是我对垃圾收集只了解一点点。现在,我想通过一些实践经验来改变这种状况。我的目标是在0.3秒以下的延迟,或者在极端情况下0.5也可以。 我有一个带有-Xmx50gb(-Xms50gb)的应用程序,并设置了以下其他GC选项: 但是现在由于垃圾回收,尽管偶尔有足够的可用内存,但我偶尔会在5秒内停顿很长时间。我发现的原因之一: 为什么GCG1仍为此做一个“停止世界”?(

  • 在我们的kafka broker设置中,GC平均需要20毫秒,但随机增加到1-2秒。极端情况持续9秒。这种情况的发生频率相当随机。平均每天发生15次。我尝试过使用GCEasy,但没有给出任何见解。我的内存使用率为20%,但进程仍然使用交换,尽管内存可用。感谢您对如何将其最小化的任何意见 JVM选择: GC日志:

  • 有人能给我解释一下原因吗?

  • 我注意到,与java 6相比,使用java 7的每个年轻垃圾收集平均需要10毫秒以上。我使用的是1.6.0_31和1.7.0_21。配置没有改变,硬件也没有改变,JVM参数是: Java 7: 爪哇6 我还查看了每个单独的时间,对于java 6,每个YGC大约需要10ms,而java 7是20ms。第6版和第7版之间有什么变化可以解释这种行为吗? 编辑:我注意到java 7在64位模式下运行,而j

  • [GC(分配失败)[defnew:10931K->472K(12288K),0.0053905秒]10931K->10712K(39616K),0.0054285秒][times:user=0.00 sys=0.00,real=0.01秒] [GC(分配失败)[defnew:10712k->472k(12288k),0.0057686秒]20952k->20952k(39616k),0.00580

  • 由于ElasticSearch是基于Java语言的应用,所以它必须运行在Java虚拟机上。任何Java程序都被编译成字节码,然后才能运行在JVM上。用最常规的方式思考,可以想象JVM只是执行其它的程序,并且控制程序的行为。但是除非你是在为ElasticSearch开发新的插件(这部分的内容将在第9章 开发ElasticSearch插件中论述),否则这不是你关注的重点。你需要关注的重点是垃圾收集器,