logo标签列表

Java并发标记清除垃圾收集器未能清除所有垃圾

javagarbage-collectionconcurrent-mark-sweep
10

简述：CMS垃圾收集器似乎未能收集越来越多的垃圾；最终，我们的JVM填满了，并且应用程序变得无响应。通过外部工具（JConsole或jmap -histo:live）强制进行GC一次可以清理它。

更新：该问题似乎与JConsole的JTop插件有关；如果我们不运行JConsole或以没有JTop插件的方式运行它，则该问题消失。

（技术说明：我们在Linux 2.6.9盒子上运行Sun JDK 1.6.0_07，32位。除非有不可避免的重大原因，否则升级JDK版本并不是一个真正的选择。此外，我们的系统未连接到可访问互联网的计算机，因此无法提供JConsole等的截图。）

我们目前正在使用以下标志运行JVM：

-server -Xms3072m -Xmx3072m -XX:NewSize=512m -XX:MaxNewSize=512m 
-XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+CMSParallelRemarkEnabled 
-XX:CMSInitiatingOccupancyFraction=70 
-verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps 
-XX:+DisableExplicitGC

在JConsole中观察内存图形，我们的应用程序在前几个小时内会每15分钟左右运行一次full GC；在每次full GC之后，仍有越来越多的内存被使用。几个小时后，系统达到稳定状态，CMS old gen中大约使用了2GB的内存。

这听起来像是一个经典的内存泄漏，但如果我们使用任何强制进行full GC的工具（在JConsole中点击“收集垃圾”按钮或运行jmap -histo:live等），旧代突然降至使用约500MB，并且我们的应用程序在接下来的几个小时内重新变得响应（在此期间相同的模式继续- 每次full GC之后，越来越多的old gen已满。）

值得注意的一件事是，在JConsole中，报告的ConcurrentMarkSweep GC计数将保持为0，直到我们使用jconsole/jmap等强制进行GC。

通过连续使用jmap -histo和jmap -histo:live，我能够确定明显未被收集的对象包括：

  • 几百万个HashMap和HashMap$Entry数组（1：1比例）
  • 几百万个Vector和Object数组（1：1比例，与HashMap数量大约相同）
  • 几百万个HashSet、Hashtable和com.sun.jmx.remote.util.OrderClassLoader，以及Hashtable$Entry数组（每种类型数量大约相同；大约是HashMap和Vector的一半）

以下是GC输出的一些摘录；我对它们的解释似乎是CMS GC被中止而没有转移到停机GC。我是否会误解这个输出？有什么会导致这种情况发生吗？

在正常运行时，CMS GC输出块看起来像这样：

36301.827: [GC [1 CMS-initial-mark: 1856321K(2621330K)] 1879456K(3093312K), 1.7634200 secs] [Times: user=0.17 sys=0.00, real=0.18 secs]
36303.638: [CMS-concurrent-mark-start]
36314.903: [CMS-concurrent-mark: 7.804/11.264 secs] [Times: user=2.13 sys=0.06, real=1.13 secs]
36314.903: [CMS-concurrent-preclean-start]
36314.963: [CMS-concurrent-preclean: 0.037/0.060 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]
36314.963: [CMS-concurrent-abortable-preclean-start]
36315.195: [GC 36315.195: [ParNew: 428092K->40832K(471872K), 1.1705760 secs] 2284414K->1897153K(3093312K), 1.1710560 secs] [Times: user=0.13 sys=0.02, real=0.12 secs]
CMS: abort preclean due to time 36320.059: [CMS-concurrent-abortable-preclean: 0.844/5.095 secs] [Times: user=0.74 sys=0.05, real=0.51 secs]
36320.062: [GC[YG occupancy: 146166 K (471872 K)]36320.062: [Rescan (parallel), 1.54078550 secs]36321.603: [weak refs processing, 0.0042640 secs] [1 CMS-remark: 1856321K(2621440K)] 2002488K(3093312K), 1.5456150 secs] [Times: user=0.18 sys=0.03, real=0.15 secs]
36321.608: [CMS-concurrent-sweep-start]
36324.650: [CMS-concurrent-sweep: 2.686/3.042 secs] [Times: uesr=0.66 sys=0.02, real=0.30 secs]
36324.651: [CMS-concurrent-reset-start]
36324.700: [CMS-concurrent-reset: 0.050/0.050 secs] [Times: user=0.01 sys=0.00, real=0.01 secs]

就是这样，下一行将是下一个ParNew GC。

当我们使用jmap -histo:live命令强制进行GC时，我们会得到：

48004.088: [CMS-concurrent-mark: 8.012/8.647 secs] [Times: user=1.15 sys=0.02, real=0.87 secs]
(concurrent mode interrupted)

接下来大约有125行以下形式的代码：（一些GeneratedMethodAccessor，一些GeneratedSerializationConstructorAccessor，一些GeneratedConstructorAccessor等）

[Unloading class sun.reflect.GeneratedMethodAccessor3]

其后跟随：

: 1911295K->562232K(2621440K), 15.6886180 secs] 2366440K->562232K(3093312K), [CMS Perm: 52729K->51864K(65536K)], 15.6892270 secs] [Times: user=1.55 sys=0.01, real=1.57 secs]

提前感谢！

你是否尝试过最新的JVM以查看问题是否已解决？这可能是一个很好的数据点。 - NG.
我对CMS收集器不太了解，无法提供良好的建议，但有一件事情让我感到困惑，那就是新生代似乎并没有缩小的迹象。通常情况下，我会期望一次完整的收集将对象从新生代移动到老年代。 - Anon
@SB 我会尝试一个更新的JVM - 就像你说的，这是一个好的数据点。@Anon - 这不是相反吗？我认为新->终身发生在年轻GC上。 - Sbodd
在Sun的白皮书(http://www.oracle.com/technetwork/java/javase/tech/memorymanagement-whitepaper-1-150020.pdf)中有一些措辞似乎表明在进行完整收集时会发生晋升: "经过一定数量的年轻代收集后仍存活的对象最终会被提升或保留到老年代。" 但无论如何，我期望任何垃圾回收器都会收集年轻代，特别是当它几乎满时。 - Anon
不要使用jmap来请求JVM的直方图，请求堆转储可能会更少干扰。有一些很棒的离线hprof分析工具（如eclipse mat和yourkit），可以提供更多信息。这种方法的另一个好处是您不会污染正在研究的堆（我不知道-histo是否会这样做，但我只是在说）。 - Ron
4个回答
7

com.sun.jmx.remote.util.OrderClassLoader在JMX的远程层中使用，代码的快速审查表明它们是作为JVM内部远程请求的取消编组过程的一部分而创建的。这些类加载器的生命周期将直接与取消编组的事物的生命周期相关联，因此一旦不再引用该事物，类加载器就可以被释放。

如果您使用JConsole来检查JVM的情况，则不会感到惊讶，在这种情况下，这些实例的存在可能是直接结果。看起来它们将作为正常操作的一部分被GC清理。

我猜JMX实现中可能有Bug（在相对最新的JVM中似乎不太可能），或者您可能有一些自定义MBeans或正在使用一些自定义的JMX工具导致了问题。但最终，我怀疑OrderClassLoader可能是一个误导，并且问题在其他地方（如损坏的GC或其他泄漏）。

你似乎是对的 - 如果我们不使用JConsole，或者不使用JConsole的JTop插件，那么涉及到的对象和行为将完全消失。我仍然不知道它们为什么没有被正确清理，但至少系统又可以正常工作了。 - Sbodd
1.7.0_05 仍然存在相同的错误。 - Ralf H
5
技术说明：我们在Linux 2.6.9上运行Sun JDK 1.6.0_07，32位。除非有无法避免的重大原因，否则升级JDK版本并不是一个真正的选项。
几个更新的Java版本已经更新了CMS垃圾回收器，特别是6u12、6u14和6u18。
我不是GC方面的专家，但我猜测6u14的预清理修复 可能 可以解决您所看到的问题。当然，我也可以说6u18的类卸载错误同样适用。就像我所说的，我不是GC方面的专家。
这里有一些解决方案：
  • 6u10：（影响6u4+）CMS在-XX:+ParallelRefProcEnabled时永远不会清除引用
  • 6u12：CMS：并发预清理期间溢出对象数组的编码不正确
  • 6u12：CMS：使用并行并发标记时处理溢出不正确
  • 6u14：CMS：断言失败“is_cms_thread == Thread::current()->is_ConcurrentGC_thread()”
  • 6u14：CMS：需要CMSInitiatingPermOccupancyFraction来进行perm，与CMSInitiatingOccupancyFraction分离
  • 6u14：CMS断言：_concurrent_iteration_safe_limit更新丢失
  • 6u14：CMS：参考列表预清理期间处理溢出不正确
  • 6u14：使用CMS和COOPs运行时发生SIGSEGV或(!is_null(v),"oop value can never be zero")断言
  • 6u14：CMS：CompactibleFreeListSpace::block_size()中的活锁。
  • 6u14：使CMS与压缩oops一起工作
  • 6u18：CMS：使用-XX:+UseCompressedOops会导致核心转储
  • 6u18：CMS：与类卸载相关的错误
  • 6u18：CMS：在cms预清理存在时，ReduceInitialCardMarks不安全
  • 6u18：[回归]-XX:NewRatio与-XX:+UseConcMarkSweepGC一起使用会导致致命错误
  • 6u20：卡标记可能延迟太久
除了以上所有内容，6u14还引入了 G1垃圾收集器，尽管它仍在测试中。G1旨在取代Java 7中的CMS。
可以使用以下命令行开关在Java 6u14及更高版本中使用G1： -XX:+UnlockExperimentalVMOptions -XX:+UseG1GC
-1
我会建议从更简单的项目开始，例如：
-server -Xms3072m -Xmx3072m -XX:+UseParallelOldGC -verbose:gc -XX:+PrintGCDetails -XX:+PrintGCTimeStamps

看看这是否符合你的需求。

-2

看起来你正在构建指向它们的所有者的对象（A指向B指向A）。这会导致引用计数仍然大于零，因此垃圾收集器无法清理它们。释放它们时需要打破循环。在A或B中将引用置空将解决问题。即使在更大的引用链中也可以使用向量和对象数组（例如A->B->C->D->A）。您的HashMaps可能会使用它们。

远程加载程序的存在可能表明未能清理和关闭通过JNDI或其他远程访问方法加载的对象的引用。

编辑：我再次查看了您的最后一行。您可能需要增加perm分配。

1
你知道Java垃圾收集器不使用引用计数吗？ - Anon
作为对Anon笔记的补充，并发标记和清除的简单解释是“标记所有从根可达的对象”作为活动对象，并收集它认为已死亡的对象。当然，这仅适用于老年代；Java垃圾回收有两个代：年轻代和老年代。 - Powerlord
网页内容由stack overflow 提供, 点击上面的
可以查看英文原文，
原文链接