Java - GC 正在运行，但未回收任何内容

heap-memory java heap-dump coldfusion coldfusion-9

2022-09-04 23:03:31

在过去的几天里，我们看到我们服务器上的JVM进入了一种状态，它们在OldGen的GC中花费了100%的CPU时间，当：

一个。它们不需要这样做，因为堆上还剩下足够的空间，并且

B.他们没有收回任何东西。

我知道它们在GC中，方法是查看堆栈跟踪并将ProcessExplorer中的ThreadID与堆栈转储中的线程ID相关联。每个 GC 线程占用大约 4% 的 CPU。

服务器运行 16 千兆堆（32gig 物理 RAM），有 8 个内核。正常运行时间通常在30天左右，由于MS修补要求，只需要重新启动，但目前它们在20天标记处崩溃。

这是持续时间的图表，时间尺度 = 19 天。http://i45.tinypic.com/257qalu.png

这是该图尾部的缩放 http://i48.tinypic.com/2duiccw.png

如您所见，持续时间急剧增加。

下面是 GC 之后的堆使用情况图。http://i48.tinypic.com/znna4h.png

如果这是典型的内存泄漏，我希望看到橙色峰值越来越高，直到它们不能再达到峰值，但正如这张图所示，还剩下足够的堆空间。

我为每个服务器都有堆转储，没有什么是有问题的。有几个ehCache商店，我可以看到我们的应用程序代码，即只是“正常的东西”

我们在大约20天前所做的最大更改是实现一个供应商补丁，该补丁将内部缓存从使用硬引用的无限哈希映射（以及明显的内存泄漏）更改为由软引用组成的哈希映射，我想知道这是否是原因，即，不知何故，在一点之后管理这些软引用会产生巨大的开销？

有没有人对下一步该看哪里有任何想法，或者有人可以证实我的软参考理论吗？

这是我的jvm.args：

java.args=-server -Xms16000m -Xmx16000m -Dsun.io.useCanonCaches=false -XX：MaxPermSize=350m -Xloggc：e：/gcLogs/eRGCLogs.txt -verbose：gc -XX：+PrintGCDetails -XX：+PrintGCTimeStamps -XX：+PrintGCDateStamps -XX：+UseParallelGC -XX：+UseParallelOldGC -Dnet.sf.ehcache.sizeof.filter=D：/jo3/java_ehCacheOpenSource/sizeOfExclusions.config -Xbatch -Dcoldfusion.rootDir={application.home}/../ -Dcoldfusion.libPath={application.home}/../lib -Dcoldfusion.classPath={application.home}/../lib/updates，{application.home}/../lib，{application.home}/../gateway/lib/，{application.home}/../wwwroot/WEB-INF/flex/jars，{application.home}/../wwwroot/WEB-INF/cfform/jars，d：/jo3/java，d：/JO3/java_ehCacheOpenSource/，D：/jo3/java_ehCacheMonitorProbe

我们使用的是Coldfusion，它有点像一个位于Java之上的庞大框架。

JVM 版本： 1.6.0_29

根据要求，“正常”GC 日志如下所示：

2013-03-19T22：11：36.670+1100： 1288665.702： [GC [PSYoungGen： 4695800K->471119K（4722112K）] 9301727K->5077046K（15644800K）， 0.3584434 secs] [次数： user=5.01 sys=0.00， real=0.36 秒] 2013-03-19T22：14：55.078+1100： 1288864.099： [GC [PSYoungGen： 4722063K->498009K（4783104K）] 9327990K->5103936K（15705792K）， 0.3766889 秒] [次数： user=5.37 sys=0.00， real=0.38 秒] 2013-03-19T22：17：46.749+1100： 1289035.760： [GC [PSYoungGen： 4654489K->517299K（4673792K）] 9260416K->5123227K（15596480K）， 0.4130828 secs] [次数： user=5.80 sys=0.00， real=0.41 secs] 2013-03-19T22：21：08.762+1100： 1289237.763： [GC [PSYoungGen： 4673779K->522660K（4738880K）] 9279707K->5143831K（15661568K）， 0.4005516 秒] [次数： user=5.97 sys=0.00， real=0.40 secs] 2013-03-19T22：23：42.683+1100： 1289391.675： [GC [PSYoungGen： 4582628K->530998K（4590976K）] 9203799K->5186242K（15513664K）， 0.4317352 秒] [次数： user=6.24 sys=0.00， real=0.43 秒] 2013-03-19T22：26：11.096+1100： 1289540.080： [GC [PSYoungGen： 4590966K->518331K（4724096K）] 9246210K->5206959K（15646784K）， 0.3914401 秒] [次数： user=5.99 sys=0.00， real=0.39 秒] 2013-03-19T22：27：44.076+1100： 1289633.055： [GC [PSYoungGen： 2602730K->447527K（4732864K）] 7291358K->5208743K（15655552K）， 0.3725317 秒] [次数： user=5.80 sys=0.00， real=0.37 secs] 2013-03-19T22：27：44.448+1100： 1289633.428： [完整 GC （系统） [PSYoungGen： 447527K->0K（4732864K）] [ParOldGen： 4761215K->4628296K（10922688K）] 5208743K->4628296K（15655552K） [PSPermGen： 352378K->352287K（352832K）]， 4.2955639 秒] [次： user=57.70 sys=0.06， real=4.30 secs] 2013-03-19T22：30：37.950+1100： 1289806.920： [GC [PSYoungGen： 4004416K->70948K（4690432K）] 8632712K->4699245K（15613120K）， 0.1062227 秒] [次数： user=0.76 sys=0.00， real=0.11 secs] 2013-03-19T22：33：27.154+1100： 1289976.115： [GC [PSYoungGen： 4054116K->109175K（4092352K）] 8682413K->4737472K（15015040K）， 0.1347919 秒][时间： user=1.03 sys=0.00， real=0.13 secs] 2013-03-19T22：36：32.120+1100： 1290161.070： [GC [PSYoungGen： 4092343K->147318K（4712320K）] 8720640K->4775615K（15635008K）， 0.1593523 秒] [次数： user=1.58 sys=0.00， real=0.16 secs] 2

当我们处于故障模式时，GC 日志如下所示：

2013-03-22T10：03：47.619+1100： 1504185.901： [GC [PSYoungGen： 0K->0K（5452736K）] 4413907K->4413907K（16375424K）， 0.0114248 secs] [次数： user=0.16 sys=0.00， real=0.01 secs] 2013-03-22T10：03：47.631+1100： 1504185.912： [Full GC [PSYoungGen： 0K->0K（5452736K）] [ParOldGen： 4413907K->4412613K（10922688K）] 4413907K->4412613K（16375424K） [PSPermGen： 358399K->358278K（358400K）]， 5.4435442 秒] [时间： user=73.74 sys=0.14， real=5.44 秒] 2013-03-22T10：03：53.145+1100： 1504191.426： [GC [PSYoungGen： 269219K->7734K（5449088K）] 4681833K->4422114K（16371776K）， 0.0298728 秒] [次数： user=0.34 sys=0.00， real=0.03 secs] 2013-03-22T10：03：53.175+1100： 1504191.456： [Full GC [PSYoungGen： 7734K->0K（5449088K）] [ParOldGen： 4414379K->4415189K（10922688K）] 4422114K->4415189K（16371776K） [PSPermGen： 358399K->358371K（358400K）]， 2.6033684 秒] [时间： user=36.33 sys=0.00， real=2.60 secs] 2013-03-22T10：03：55.788+1100： 1504194.069： [GC [PSYoungGen： 94969K->826K（5451328K）] 4510158K->4416015K（16374016K）， 0.0133588 秒] [倍数： user=0.16 sys=0.00， real=0.01 secs] 2013-03-22T10：03：55.802+1100： 1504194.082： [Full GC [PSYoungGen： 826K->0K（5451328K）] [ParOldGen： 4415189K->4415348K（10922688K）] 4416015K->4415348K（16374016K） [PSPermGen： 358399K->358389K（358400K）]， 2.7156884 秒] [时间： user=38.11 sys=0.00，实数=2.71秒] 2

答案 1

正如许多人在评论中提到的那样，PermGen中的空间不足很可能是您的原因。这可能是由于在整个代码中过多地插入字符串引起的，这可能导致PermGen“爆炸” - 也加载了很多类（通常通过后台为您执行此操作的框架）也可能导致这种情况。

此外，正如提到的评论之一 - 使用CMS集合（并发标记和扫描）可以减少您的停止世界GC，假设问题出在旧一代的容量上。它还可以通过减少延迟来提高性能，无论当前问题如何，延迟都很好。

此外，如果您发布GC日志的片段，则有助于为您指出正确的方向。

关于 jstat 工具，您可以通过以下方式使用它来获取有用的信息：

jstat -gcutil <pid> <interval>

我通常使用1000ms的间隔。为您提供GC利用率（以%）为单位 - 因此您可以看到是否有任何生成接近100%。-gcutil

您还可以使用并获得旧一代的确切容量。jstat -gc <pid> ...

编辑：查看GC日志后

根据您的GC日志，它确认了您的PermGen正在填满的原始前提。在 10：03：47 和 10：03：55 之间的时间范围内，我可以看到 PermGen 不断达到其最大值，并且 GC 以某种方式删除了大约 10-100 KB 的数据：

请参阅以下内容：

2013-03-22T10:03:47.631+1100: 1504185.912: [Full GC [... [PSPermGen: 358399K->358278K(358400K)]...
2013-03-22T10:03:53.175+1100: 1504191.456: [Full GC [... [PSPermGen: 358399K->358371K(358400K)]...
2013-03-22T10:03:55.802+1100: 1504194.082: [Full GC [... [PSPermGen: 358399K->358389K(358400K)]...

如果你看看老一代和年轻一代，你可以看到他们都没有达到他们的最大值，OldGen消耗了10GB中的4GB - 所以这不是原因。

从您收集的数据中，我无法判断PermGen的填充速度是否与该过程的正常运行时间一致 - 这意味着看起来PermGen应该在一天内填充，而不是20天。因此，很难说什么是明确的解决方案，但这里有一些建议：

检查你的代码，以确保你没有滥用的方法 - 如果你在代码中无缘无故地使用它太广泛，这可能是你的根本原因。Stringintern()
检查您正在使用的框架是否动态生成类 - 这也将消耗PermGen空间，但在某种程度上。
如果可以，请每周重新启动一次进程，以防止出现停机
考虑增加PermGen空间，但要对其进行监视，因为增加它可能会延长20天的持续时间，但不能解决问题。在该过程存在足够长的时间之后，PermGen应该保持相当静态。
使用Coldfusion PermGen字符串在Google上运行搜索会产生许多报告问题的命中 - 尝试遵循这些点击以专注于您的调查。

答案 2