小编典典

Java ConcurrentMarkSweep垃圾收集器不会删除所有垃圾

java

简短形式:CMS垃圾收集器似乎无法收集数量不断增加的垃圾;最终,我们的JVM填满,应用程序变得无响应。通过外部工具(JConsole或jmap -histo:live)强制GC 清理一次。

更新:该问题似乎与JConsole的JTop插件有关。如果我们不运行JConsole,或者在没有JTop插件的情况下运行它,则该行为消失。

(技术说明:我们正在Linux 2.6.9机器上运行32位Sun JDK
1.6.0_07。除非有不可避免的主要原因,否则升级JDK版本并不是真正的选择。此外,我们的系统也不是连接到可访问Internet的计算机,因此无法选择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中的内存图,有一个完整的GC,它在应用程序生命周期的头几个小时内大约每15分钟运行一次。每个完整的GC之后,仍在使用越来越多的内存。几个小时后,系统达到稳定状态,其中CMS老一代中大约有2GB的已用内存。

这听起来像是经典的内存泄漏,不同之处在于,如果我们使用任何强制执行完整GC的工具(在JConsole中点击“收集垃圾”按钮,或运行jmap -histo:live,等等),则旧版本的内存突然降至约500MB,并且我们的应用在接下来的几个小时内再次变得敏感(在此期间,相同的模式继续发生-
在每个完整的GC之后,越来越多的旧一代已满。)

需要注意的一件事:在JConsole中,报告的ConcurrentMarkSweep GC计数将保持为0,直到我们使用jconsole / jmap /
etc强制进行GC。

通过使用jmap -histojmap -histo:live,我可以确定看似未收集的对象包括:

  • 几百万HashMap秒和数组HashMap$Entry(以1:1的比例)
  • 数百万个Vector和对象数组(比例为1:1,与HashMap的数量大致相同)
  • 数百万个HashSetHashtablecom.sun.jmx.remote.util.OrderClassLoader,以及的数组Hashtable$Entry(每个数组的数目大约相同;大约是HashMaps和Vector的一半)

以下是GC输出的一些摘录;我对它们的解释似乎是CMS GC正在中止而没有故障转移到Stop-the-world
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]

提前致谢!


阅读 407

收藏
2020-11-16

共1个答案

小编典典

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

如果在这种情况下这些实例的存在是您使用JConsole检查JVM中运行情况的直接结果,我不会感到惊讶。看起来它们只是作为常规操作的一部分被GC清理了。

我猜想JMX实现中可能有一个错误(在相对最新的JVM中似乎不太可能),或者您有一些自定义MBean或正在使用导致问题的自定义JMX工具。但是最终,我怀疑OrderClassLoader可能是一个红鲱鱼,问题出在其他地方(GC损坏或其他泄漏)。

2020-11-16