G1GC 奇怪的行为

Question

我决定在我的 Eclipse Mars RC3 上尝试 G1GC 以供 JavaEE 开发人员安装，但我观察到一个非常奇怪的行为：

如您所见，在应用程序的生命周期中，它有运行近 700 次 FULL GC，而只有 30 次次要 GC。我还注意到，次要 GC 是在应用程序处于负载状态时执行的——通常是在它启动并加载大量内容时执行，而在空闲时执行完整的 GC。（这 11 个小时的大部分时间都是空闲的！）我希望当应用程序什么也不做时，就不需要 GC，或者至少是次要 GC。我还监控了 eclipse 的内存消耗——在空闲时间它从未增加到超过 130-140 MB，所以这是这些完整的 GC 看起来很奇怪的另一个原因。

这是我的 eclipse.ini jvm 配置：

-server
-Xverify:none
-XX:+AggressiveOpts
-XX:+UseG1GC
-XX:MaxGCPauseMillis=100
-XX:+UseStringDeduplication
-XX:+UseCompressedOops
-XX:+UseCompressedClassPointers
-XX:MaxMetaspaceSize=256m
-Xloggc:/home/svetlin/software/eclipse/gc.log
-XX:+PrintGCDetails
-XX:+PrintGCTimeStamps
-XX:+PrintGCDateStamps 
-XX:+UseGCLogFileRotation
-XX:NumberOfGCLogFiles=5
-XX:GCLogFileSize=20m
-Xms1g
-Xmx1g

这是 GC 日志：http://pastebin.com/sVBe4w1A

Java 版本：用于 linux-amd64 JRE (1.8.0_45-internal-b14) 的 OpenJDK 64 位服务器 VM (25.45-b02)，构建于 2015 年 5 月 17 日 19:21:01 通过 gcc 4.9.2 的“buildd”

你知道为什么 G1GC 在显然根本不需要 GC 时执行这些完整的 GC 吗？

Answer 1

您正在遭受 System.gc() 电话的困扰，从您的日志中可以看出：

2015-06-14T14:56:23.682+0300: 12790,173: [Full GC (System.gc())  121M->118M(1024M), 0,4524898 secs]
   [Eden: 4096,0K(561,0M)->0,0B(561,0M) Survivors: 0,0B->0,0B Heap: 121,7M(1024,0M)->118,2M(1024,0M)], [Metaspace: 135216K->135216K(1177600K)]
 [Times: user=0,71 sys=0,00, real=0,45 secs]
2015-06-14T14:57:23.682+0300: 12850,174: [Full GC (System.gc())  121M->118M(1024M), 0,4732930 secs]
   [Eden: 3072,0K(561,0M)->0,0B(561,0M) Survivors: 0,0B->0,0B Heap: 121,2M(1024,0M)->118,2M(1024,0M)], [Metaspace: 135216K->135216K(1177600K)]
 [Times: user=0,73 sys=0,00, real=0,47 secs]
2015-06-14T14:58:28.684+0300: 12915,175: [Full GC (System.gc())  169M->118M(1024M), 0,4912699 secs]
   [Eden: 52,0M(561,0M)->0,0B(561,0M) Survivors: 0,0B->0,0B Heap: 169,9M(1024,0M)->118,8M(1024,0M)], [Metaspace: 135601K->135601K(1177600K)]
 [Times: user=0,74 sys=0,00, real=0,49 secs]

System.gc() 调用似乎每分钟发生一次。你运行是否有任何可能导致此问题的奇怪插件？

否则，定期 System.gc() 调用通常是由于 Java RMI 运行调用它们。在较旧的 Java 版本上，我认为这是每分钟完成一次，但现在增加到每小时一次。无论如何，请尝试设置这些属性以确保：

-Dsun.rmi.dgc.server.gcInterval=999999999
-Dsun.rmi.dgc.client.gcInterval=999999999

作为 JVM 选项。

Answer 2

您所有的完整 GC 都是由对 System.gc() 的调用引起的。您的 GC 日志正好显示其中的 698 个。

所以您的 Eclipse 发行版可能包含一个插件，该插件会导致 System.gc() 次调用。如果您无法修复这些调用，您可以考虑使用 VM 选项 -XX:+DisableExplicitGC 来抑制显式 GC。

G1GC 奇怪的行为

G1GC Strange behavior

java

garbage-collection

g1gc