JVM性能在随机时间之后下降。

Question

简而言之，我遇到了一个“随机”出现在一个JVM中的性能问题，这个问题可能已经运行了几天，但我似乎找不到根本原因。我倾向于某个东西在吞噬线程池，但一直无法找到它。

我已经浏览了所有我能想到的追踪这件事，任何建议都会很棒！

(我有Jprofiler、yourkit和jvisualvm供我使用，我试着使用它们运行，并在JVM中运行比较)

这就是我们的设计。我们在一个大量使用的测试环境中运行40个JVM(每台硬件机器10个)。它们使用一个名为UltraESB(2.3.0)的开源产品，它利用线程池进行异步请求/应答处理，但在我们的示例中，基于无状态头的消息路由。在我们的开发环境中，我们有一个不太严重但仍然常用的设置，而且我们从未见过这个问题。

所以我们经常看到小的GCs(每几分钟一次)，很少看到主要的GCs(一天左右一次)。我们在Centos6.7上使用hotspot Java 1.7_71 (Haswell CPU bug是修补的)

偶尔(在我看来完全是随机的)，JVM中的一个会开始表现不佳(我们有应用程序性能的监视器+度量标准)。在正常情况下，我们用<1ms处理消息。一旦遇到错误场景，我们就开始看到数百毫秒(100-200毫秒)的处理时间。当我们在几个星期内运行这些程序时，我们将看到几个性能不佳的JVM。再循环就能把东西清理干净，它们还能在几天内跑得很好。由于JVM出错，我们开始看到它们的处理时间与其他遇到性能问题的实例(包括其他硬件上的实例)几乎完全相同。这并不奇怪，因为它们是完全相同的代码基和JMS负载平衡循环，因此它们处理几乎相同数量的消息。

我通过打开CPU性能分析触发了这种性能影响。见图：蓝色是一个很好的过程，直到我打开CPU跟踪，它开始表现不佳。

有趣的是，即使在剖析被禁用之后，不良的性能仍在继续。

我试过测量的东西

我试过的任何东西都没有指向任何银弹。

GC监视- GC持续时间和CPU利用率在引用和性能较差的JVM之间似乎是一致的。

GC启动选项：

GC_OPTS="-XX:+PrintGCDetails \
-XX:+UseG1GC \
-XX:MaxGCPauseMillis=100 \
-XX:+ParallelRefProcEnabled \
-XX:+UnlockExperimentalVMOptions \
-XX:-ResizePLAB \
-XX:G1NewSizePercent=50 \
-XX:G1MaxNewSizePercent=50 \
-XX:+PrintAdaptiveSizePolicy \
-Xloggc:/logs/applogs/${instancename}/gc.${DATE}.log"

CPU采样--在内部发生了这么多事情--我觉得没有什么特别之处。打开它会引起问题，但并不总是取决于采样设置。

线程池使用统计数据作为MBean导出，线程池(Spring3.2.4 ThreadPoolTaskExecutor)和正在使用的线程似乎与其他性能良好的实例相同。

Answer 1

你可以试试http://mevss.jku.at/AntTracks。这是一个研究JVM，记录您的内存行为。然后，它能够随着时间的推移显示堆属性，并且能够根据跟踪在离线的任何时间点显示堆。此VM构建时对行为的影响很小，因此不会像配置不当的抽样那样扭曲应用程序的行为。当然，只有当您期望内存/ GC在您的问题中发挥作用时，这才会有所帮助。

Answer 2

当我们从Spring侦听器容器使用的线程池中分离工作线程池时，我们的问题消失了。仍然找不到根本原因，但问题已经解决了。