rmi full gc问题_RMI强制Full GC每小时运行一次

rmi full gc问题

在我职业生涯中进行的所有故障排除练习中，我都感觉到，随着时间的推移，我所追寻的错误在不断演变，变得越来越卑鄙和丑陋。也许仅仅是我的年龄开始了。这个特别的Heisenbug –看起来像这篇帖子一样，再次让我清醒了很多，而不是我想要的。

与其他特别令人讨厌的错误一样，我现在遇到的那个错误的症状是“有时系统运行缓慢”。太好了，我已经感到脊椎发麻。当我发现系统在生产中设置了一个简单的监视解决方案来监视系统时，情况变得更好了。从本质上讲，它只不过是Pingdom ，它每秒测量一次响应时间，但是延迟图立即引起了我的注意。

JVM峰值负载

在图中绘制的响应时间似乎是随机的尖峰–每次在蓝月亮中，响应开始花费的时间将近10倍。不久之后，一切又恢复了正常。

最初的犯罪嫌疑人–看不见常规的cron工作或昂贵的报告流程。存储监视也没有暴露任何特别丑陋的查询击中数据库。但是在打电话之前，我在应用程序配置中添加了更多日志记录选项，重新启动了整个程序，并迷惑了自己的行为。

第二天早上，我还有其他事情要看，GC日志等。十分钟之内，我发现自己盯着下面的东西：

11.408: [Full GC [PSYoungGen: 192K->0K(48640K)] [ParOldGen: 16324K->14750K(114688K)] 16516K->14750K(163328K) [PSPermGen: 31995K->31637K(64000K)], 0.1543430 secs] [Times: user=0.58 sys=0.00, real=0.16 secs]
...
3613.362: [Full GC [PSYoungGen: 256K->0K(47104K)] [ParOldGen: 15142K->13497K(114688K)] 15398K->13497K(161792K) [PSPermGen: 32429K->32369K(72192K)], 0.1129070 secs] [Times: user=0.51 sys=0.00, real=0.11 secs]
...
7215.278: [Full GC [PSYoungGen: 224K->0K(44544K)] [ParOldGen: 13665K->13439K(114688K)] 13889K->13439K(159232K) [PSPermGen: 32426K->32423K(70144K)], 0.0881450 secs] [Times: user=0.44 sys=0.00, real=0.09 secs]
...

现在，我可以将看似随机的性能下降与每次经过大约3600秒时运行的Full GC关联起来。将VisualVM附加到JVM令我感到困惑–没有证据表明高内存使用率会导致整个垃圾收集器运行。与开发人员核对后，我确定他们没有通过cron作业运行显式GC。所以我站在那儿，对GC的常规性感到困惑。

工程师对问题感到困惑时会怎么做？他谷歌。就在那里，凝视着我的脸。与担心每小时进行一次完整GC的人员进行的逐页讨论，没有任何明显的原因。

罪魁祸首-RMI。显然，当您的应用程序通过RMI公开其服务或通过RMI使用任何服务时，您必然会有一个额外的垃圾回收周期。正如RMI文档所述：

“当需要确保不导出不可达的远程对象并及时进行垃圾收集时，此属性的值表示Java RMI运行时允许在本地堆的垃圾收集之间允许的最大间隔（以毫秒为单位）。默认值为3600000毫秒（一小时）。”

暂时的解决方案是将sun.rmi.dgc.server.gcInterval长度从默认的3,600秒增加。我想知道，当RMI过去每分钟强制一次完整的GC时，在JDK 6中引入更改之前，情况看起来如何。考虑到当时所有的EJB狂潮，我猜没有一个应用程序在性能方面有机会。如果您有远古时代的回忆，也许您可以了解一下这些应用程序如何能够度过这种疯狂。

参考： RMI强制Full GC每小时从JCG合作伙伴 Nikita Salnikov Tarnovski （在Plumbr Blog博客上）运行一次。