当我增加内存时，为什么会更频繁地发生垃圾回收？

Question

当我增加内存时，为什么会更频繁地发生垃圾回收？

javagarbage-collectiong1gc

7

我有一个关于g1gc的问题。

这些是堆使用的图表。

上面是-Xms4g -Xmx4g。
下面是-Xms8g -Xmx8g。

我不知道为什么使用8g选项会更频繁地发生g1gc。其他选项都是默认值。

服务器规格是40个逻辑处理器。

附加问题

能否通过增加内存大小来加快内存分配速度，因为区域大小会更大?

gc.log

4G gc.log

2019-05-07T21:03:42.093+0900: 10.280: [GC pause (G1 Evacuation Pause) (young), 0.1785373 secs]
   [Parallel Time: 43.4 ms, GC Workers: 28]
      [GC Worker Start (ms): Min: 10280.0, Avg: 10280.1, Max: 10280.6, Diff: 0.6]
      [Ext Root Scanning (ms): Min: 0.0, Avg: 0.4, Max: 0.8, Diff: 0.8, Sum: 12.0]
      [Update RS (ms): Min: 0.8, Avg: 1.1, Max: 1.6, Diff: 0.8, Sum: 31.5]
         [Processed Buffers: Min: 0, Avg: 2.0, Max: 3, Diff: 3, Sum: 56]
      [Scan RS (ms): Min: 0.0, Avg: 0.4, Max: 0.7, Diff: 0.7, Sum: 10.9]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 38.0, Avg: 38.5, Max: 39.9, Diff: 1.9, Sum: 1079.0]
      [Termination (ms): Min: 1.3, Avg: 2.6, Max: 3.2, Diff: 1.9, Sum: 74.1]
         [Termination Attempts: Min: 413, Avg: 769.6, Max: 855, Diff: 442, Sum: 21549]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 2.0]
      [GC Worker Total (ms): Min: 42.7, Avg: 43.2, Max: 43.4, Diff: 0.7, Sum: 1209.5]
      [GC Worker End (ms): Min: 10323.3, Avg: 10323.3, Max: 10323.4, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.4 ms]
   [Other: 134.7 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 132.4 ms]
      [Ref Enq: 0.9 ms]
      [Redirty Cards: 0.3 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.7 ms]
   [Eden: 928.0M(928.0M)->0.0B(828.0M) Survivors: 26.0M->120.0M Heap: 1193.0M(4096.0M)->409.0M(4096.0M)]
Heap after GC invocations=8 (full 0):
 garbage-first heap   total 4194304K, used 418816K [0x00000006c0000000, 0x00000006c0204000, 0x00000007c0000000)
  region size 2048K, 60 young (122880K), 60 survivors (122880K)
 Metaspace       used 28525K, capacity 30824K, committed 31104K, reserved 1077248K
  class space    used 3583K, capacity 4166K, committed 4224K, reserved 1048576K
}
 [Times: user=1.21 sys=0.08, real=0.18 secs]
{Heap before GC invocations=8 (full 0):
 garbage-first heap   total 4194304K, used 744448K [0x00000006c0000000, 0x00000006c0204000, 0x00000007c0000000)
  region size 2048K, 219 young (448512K), 60 survivors (122880K)
 Metaspace       used 28525K, capacity 30824K, committed 31104K, reserved 1077248K
  class space    used 3583K, capacity 4166K, committed 4224K, reserved 1048576K
2019-05-07T21:03:42.895+0900: 11.082: [GC pause (G1 Evacuation Pause) (young), 0.0505563 secs]
   [Parallel Time: 11.6 ms, GC Workers: 28]
      [GC Worker Start (ms): Min: 11082.3, Avg: 11082.6, Max: 11083.6, Diff: 1.3]
      [Ext Root Scanning (ms): Min: 0.0, Avg: 0.4, Max: 0.8, Diff: 0.8, Sum: 9.9]
      [Update RS (ms): Min: 0.4, Avg: 1.0, Max: 1.5, Diff: 1.1, Sum: 29.4]
         [Processed Buffers: Min: 1, Avg: 1.8, Max: 3, Diff: 2, Sum: 50]
      [Scan RS (ms): Min: 0.8, Avg: 1.2, Max: 1.4, Diff: 0.6, Sum: 32.4]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.0]
      [Object Copy (ms): Min: 8.3, Avg: 8.4, Max: 8.6, Diff: 0.2, Sum: 236.3]
      [Termination (ms): Min: 0.0, Avg: 0.1, Max: 0.1, Diff: 0.1, Sum: 2.8]
         [Termination Attempts: Min: 1, Avg: 42.7, Max: 52, Diff: 51, Sum: 1195]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.1, Sum: 2.0]
      [GC Worker Total (ms): Min: 10.2, Avg: 11.2, Max: 11.5, Diff: 1.3, Sum: 312.9]
      [GC Worker End (ms): Min: 11093.7, Avg: 11093.8, Max: 11093.8, Diff: 0.1]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.3 ms]
   [Other: 38.6 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 37.0 ms]
      [Ref Enq: 0.5 ms]
      [Redirty Cards: 0.3 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 0.5 ms]
   [Eden: 318.0M(252.0M)->0.0B(1052.0M) Survivors: 120.0M->48.0M Heap: 727.0M(4096.0M)->397.0M(4096.0M)]
Heap after GC invocations=9 (full 0):
 garbage-first heap   total 4194304K, used 406528K [0x00000006c0000000, 0x00000006c0204000, 0x00000007c0000000)
  region size 2048K, 24 young (49152K), 24 survivors (49152K)
 Metaspace       used 28525K, capacity 30824K, committed 31104K, reserved 1077248K
  class space    used 3583K, capacity 4166K, committed 4224K, reserved 1048576K
}
 [Times: user=0.34 sys=0.02, real=0.05 secs]
{Heap before GC invocations=9 (full 0):
 garbage-first heap   total 4194304K, used 912384K [0x00000006c0000000, 0x00000006c0204000, 0x00000007c0000000)
  region size 2048K, 271 young (555008K), 24 survivors (49152K)
 Metaspace       used 29461K, capacity 31868K, committed 32256K, reserved 1077248K
  class space    used 3681K, capacity 4237K, committed 4352K, reserved 1048576K

8G gc.log

2019-05-05T02:39:16.996+0900: 201016.724: [GC pause (G1 Evacuation Pause) (young), 0.0336675 secs]
   [Parallel Time: 12.9 ms, GC Workers: 28]
      [GC Worker Start (ms): Min: 201016724.7, Avg: 201016724.9, Max: 201016725.0, Diff: 0.2]
      [Ext Root Scanning (ms): Min: 0.8, Avg: 1.2, Max: 5.2, Diff: 4.4, Sum: 32.4]
      [Update RS (ms): Min: 0.0, Avg: 3.1, Max: 3.5, Diff: 3.5, Sum: 87.7]
         [Processed Buffers: Min: 0, Avg: 11.1, Max: 30, Diff: 30, Sum: 310]
      [Scan RS (ms): Min: 0.1, Avg: 0.3, Max: 0.3, Diff: 0.2, Sum: 7.3]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [Object Copy (ms): Min: 6.9, Avg: 7.5, Max: 7.7, Diff: 0.8, Sum: 211.2]
      [Termination (ms): Min: 0.2, Avg: 0.3, Max: 0.4, Diff: 0.2, Sum: 9.0]
         [Termination Attempts: Min: 105, Avg: 124.7, Max: 146, Diff: 41, Sum: 3491]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 3.2]
      [GC Worker Total (ms): Min: 12.4, Avg: 12.5, Max: 12.7, Diff: 0.4, Sum: 350.8]
      [GC Worker End (ms): Min: 201016737.3, Avg: 201016737.4, Max: 201016737.5, Diff: 0.2]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.7 ms]
   [Other: 20.0 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 17.2 ms]
      [Ref Enq: 0.2 ms]
      [Redirty Cards: 0.3 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 1.7 ms]
   [Eden: 4864.0M(4864.0M)->0.0B(4868.0M) Survivors: 48.0M->44.0M Heap: 5968.1M(8192.0M)->1091.2M(8192.0M)]
Heap after GC invocations=19405 (full 0):
 garbage-first heap   total 8388608K, used 1117388K [0x00000005c0000000, 0x00000005c0404000, 0x00000007c0000000)
  region size 4096K, 11 young (45056K), 11 survivors (45056K)
 Metaspace       used 187853K, capacity 205120K, committed 210176K, reserved 1232896K
  class space    used 22574K, capacity 25471K, committed 26368K, reserved 1048576K
}
 [Times: user=0.39 sys=0.00, real=0.04 secs]
{Heap before GC invocations=19405 (full 0):
 garbage-first heap   total 8388608K, used 6106497K [0x00000005c0000000, 0x00000005c0404000, 0x00000007c0000000)
  region size 4096K, 1228 young (5029888K), 11 survivors (45056K)
 Metaspace       used 187853K, capacity 205120K, committed 210176K, reserved 1232896K
  class space    used 22574K, capacity 25471K, committed 26368K, reserved 1048576K
2019-05-05T02:39:33.830+0900: 201033.558: [GC pause (G1 Evacuation Pause) (young), 0.0373282 secs]
2019-05-05T02:39:33.830+0900: 201033.558: [GC pause (G1 Evacuation Pause) (young), 0.0373282 secs]
   [Parallel Time: 13.9 ms, GC Workers: 28]
      [GC Worker Start (ms): Min: 201033558.4, Avg: 201033558.5, Max: 201033558.6, Diff: 0.2]
      [Ext Root Scanning (ms): Min: 0.8, Avg: 1.2, Max: 4.5, Diff: 3.7, Sum: 32.5]
      [Update RS (ms): Min: 0.0, Avg: 2.8, Max: 3.1, Diff: 3.1, Sum: 77.4]
         [Processed Buffers: Min: 0, Avg: 10.3, Max: 31, Diff: 31, Sum: 289]
      [Scan RS (ms): Min: 0.1, Avg: 0.3, Max: 0.3, Diff: 0.3, Sum: 7.1]
      [Code Root Scanning (ms): Min: 0.0, Avg: 0.0, Max: 0.0, Diff: 0.0, Sum: 0.1]
      [Object Copy (ms): Min: 8.5, Avg: 8.8, Max: 8.9, Diff: 0.4, Sum: 246.0]
      [Termination (ms): Min: 0.3, Avg: 0.4, Max: 0.5, Diff: 0.2, Sum: 12.0]
         [Termination Attempts: Min: 135, Avg: 156.5, Max: 175, Diff: 40, Sum: 4382]
      [GC Worker Other (ms): Min: 0.0, Avg: 0.1, Max: 0.2, Diff: 0.2, Sum: 3.3]
      [GC Worker Total (ms): Min: 13.3, Avg: 13.5, Max: 13.7, Diff: 0.3, Sum: 378.4]
      [GC Worker End (ms): Min: 201033571.9, Avg: 201033572.0, Max: 201033572.1, Diff: 0.2]
   [Code Root Fixup: 0.0 ms]
   [Code Root Purge: 0.0 ms]
   [Clear CT: 0.8 ms]
   [Other: 22.6 ms]
      [Choose CSet: 0.0 ms]
      [Ref Proc: 18.5 ms]
      [Ref Enq: 0.3 ms]
      [Redirty Cards: 1.0 ms]
      [Humongous Register: 0.1 ms]
      [Humongous Reclaim: 0.0 ms]
      [Free CSet: 2.1 ms]
   [Eden: 4868.0M(4868.0M)->0.0B(4880.0M) Survivors: 44.0M->32.0M Heap: 5963.4M(8192.0M)->1082.0M(8192.0M)]
Heap after GC invocations=19406 (full 0):
 garbage-first heap   total 8388608K, used 1107927K [0x00000005c0000000, 0x00000005c0404000, 0x00000007c0000000)
  region size 4096K, 8 young (32768K), 8 survivors (32768K)
 Metaspace       used 187853K, capacity 205120K, committed 210176K, reserved 1232896K
  class space    used 22574K, capacity 25471K, committed 26368K, reserved 1048576K
}
 [Times: user=0.41 sys=0.00, real=0.04 secs]
{Heap before GC invocations=19406 (full 0):
 garbage-first heap   total 8388608K, used 6122963K [0x00000005c0000000, 0x00000005c0404000, 0x00000007c0000000)
  region size 4096K, 1228 young (5029888K), 8 survivors (32768K)
 Metaspace       used 187853K, capacity 205120K, committed 210176K, reserved 1232896K
  class space    used 22574K, capacity 25471K, committed 26368K, reserved 1048576K

- Songkey

2

只是提供信息 - 那种链锯式的日志记录方式表明应用程序很健康。 - Eugene

你的应用程序负载是否保持不变？顺便说一下，如果没有太频繁的full-gc，就没有必要降低InitiatingHeapOccupancyPercent。也许你可以从Scott Oaks的书《Java性能权威指南》第6章“调优G1”中获得一些帮助。 - lxyscls

3个回答

1

我在想，更频繁的垃圾回收可能是因为您能够更快地分配内存。

如果您查看图表及其刻度，第一个图表显示应用程序在未运行GC时大约可以在大约12秒内分配约2GB，相比之下，第二个图表显示在未运行GC时大约可以在大约6秒内分配约2.5GB。

如果一个应用程序能够以超过两倍的速率进行分配，那意味着会产生超过两倍的垃圾。

接下来，比较两个锯齿状图形的上升斜率和下降斜率。在第一个图表中，上升斜率不平稳且比下降斜率更浅。在第二个图表中，斜率更加平滑，并且上升斜率比下降斜率更陡峭。

所以这里有一个理论...

在第一种情况（较小的堆）中，在收集器空闲或标记时，某些东西会减慢分配速率...

在第二种情况下（更大的堆），分配速率更快，这使得垃圾回收器需要做更多的工作。更多的工作意味着它需要更频繁地运行。如果我们假设这种更快的分配速率也对应于应用程序线程更多的CPU利用率，并且当GC正在删除对象时，更快的分配速率+应用程序线程活动得以维持，则可能会从GC线程中窃取周期，导致回收速率变慢（参见下降斜率）。

另一个理论（没有任何证据支持！）是你的应用程序正在广泛使用软引用/弱引用来实现缓存。更多的内存可能意味着更大的缓存，这可能会以“有趣”的方式改变应用程序的行为。例如，它可以导致更快的请求处理和与请求相关的短暂对象更快地被替换掉。

这些理论都相当脆弱。实际上，我们需要更多关于您的应用程序和更多指标的信息。

- Stephen C

首先，感谢您的回答！我添加了4g、8g gc.log（young gc的一部分）。4g内存区域大小为2M，8G内存区域大小为4M。因此，我猜测内存将会以双倍速度增长。我需要看看为什么在4g中下降得更快。 - Songkey

0

根据您的两个图表，看起来您的服务器在更短的时间内分配了更多的内存。正如您自己的图片所示，在第一种情况下，当内存使用量达到3G时执行混合集合，在第二种情况下，假设为5G。但这取决于您的应用程序的内存分配模式。 G1 gc试图满足gc max pause（由XX：MaxGCPauseMillis=设置，默认值为500ms），而不会牺牲吞吐量。

- Michal

谢谢你的回答！我明白为了保持MaxGCPauseMills时间，内存正在变得更大和更频繁。是这样吗？但我想知道如果内存更大，那么它是否会占用更慢... - Songkey

G1允许具有8GB内存的应用程序在执行混合GC之前分配更多内存，只要保持MaxGCPauseMills目标即可。为什么在第二种情况（8GB内存）中分配更多内存比第一种情况（4GB）更快，这取决于您的应用程序及其负载。顺便说一下，您可以查看XX：InitiatingHeapOccupancyPercent设置。例如，在此处https://dzone.com/articles/g1gcgarbage-first-garbage-collector-tuning-flags-1 - Michal

谢谢@Michal。我测试了XX:InitiatingHeapOccupancyPercent=40，但是在图表中没有看到任何不同的地方。我也看了GC日志，但它并不是混合GC。图表总时间为5分钟。混合GC每天发生一次。 - Songkey

我只有一个内存变化，但不知道为什么分配速度更快... 我会继续查找。非常感谢您的回答 :-)。 - Songkey

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

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

- Madplay · Accepted Answer

使用G1GC启动的JVM会构建一个名为region的内存块，其中不区分新生代/幸存者区/老年代物理内存。逻辑上有新生代/幸存者区/老年代，但它们在物理上并没有通过地址进行分隔。

对象在任何区域中创建，并且对象的引用信息存储在Remember集合中（在整个堆中使用5%的级别）。Remember集合是一种数据结构，使我们可以轻松地知道哪个区域被分配了带引用的对象。（跟踪引用到区域）

如果要创建大于区域大小的对象，则会在多个区域中创建对象，并将这组区域称为Humongous。该信息也存储在remember集合中。

区域大小可以从1MB到32MB不等，具体取决于堆大小。下表显示了基于最小堆大小选择区域大小时将选择的区域大小。

|---------------------|------------------|
|    Min Heap Size    |   Region Size    |
|---------------------|------------------|
|     heap < 4GB      |       1MB        |
|---------------------|------------------|
|  4GB <= heap < 8GB  |       2MB        |
|---------------------|------------------|
|  8GB <= heap < 16GB |       4MB        |
|---------------------|------------------|
| 16GB <= heap < 32GB |       8MB        |
|---------------------|------------------|
| 32GB <= heap < 64GB |      16MB        |
|---------------------|------------------|
|     64GB < heap     |      32MB        |
|---------------------|------------------|

因此，在您的情况下，该区域的大小将被计算得不同。此外，内存分配模式可以根据您的应用程序而变化。要找到更准确的原因，我们需要垃圾回收日志。

您可以设置InitiatingheapOccupancyPercent来让后台线程开始时间。堆使用率与总堆大小的比率。减小该值可快速启动后台线程。默认值为45。但是，如果该值太小，则垃圾回收会过于频繁。这需要CPU周期，并可能影响应用程序性能本身。

如您所知，链锯图表现出健康的应用程序。因此，即使您不进行其他设置，也没有大问题。

额外内容：Bug报告可帮助您解决问题。在Bug-8151176中的描述涉及计算老年代占用/总堆大小以实际计算IHOP的目的。这意味着年轻代的占用完全被忽略。也就是说，如果年轻代的分数大于IHOP，则并发周期无法启动。

原因是在老年代占用超过当前堆容量固定百分比时，静态IHOP就开始工作。如果用户或人工决定老年代不能大于触发并发标记的堆容量的该分数，标记将永远不会开始。