什么可能导致全球Tomcat / JVM放缓？

我在Tomcat 7 / Java 7上遇到了一个奇怪而严重的问题，运行了几个（大约15个）Java EE-ish Web应用程序（Hibernate 4 + Spring + Quartz + JSF + Facelets + Richfaces）。

系统运行良好，但经过大量时间后，所有应用程序实例同时突然遭受响应时间的增加。 基本上应用程序仍然有效，但响应时间大约高出三倍。

这是两个图，分别显示了两个示例实例的两个特定工作stream程/操作（login，研讨会访问列表，ajax刷新此列表，注销;下面一行仅仅是ajax刷新的请求时间）的响应时间的申请：

正如你可以看到应用程序的两个实例在同一时间“爆炸”，并保持缓慢。 重新启动服务器后，一切恢复正常。 应用程序的所有实例都“同时爆炸”。

我们将会话数据存储到数据库并将其用于集群。 我们检查了会话的大小和数量，都比较低（这意味着在其他应用程序的服务器上，我们有时会有更多的会话）。 集群中的另一个Tomcat通常会在更长时间内保持快速状态，在这个随机的时间量之后，它也会“死亡”。 我们用jconsole检查了堆的大小，主堆保持在2.5到1 GB的大小，db连接池基本上是充满了空闲的连接，以及线程池。 最大堆大小是5 GB，还有大量的可用的perm gen空间。 负荷不是特别高， 主CPU只有5％的负载。 服务器不交换。 这也没有硬件问题，因为我们另外部署应用程序的问题保持不变的虚拟机。

我不知道该往哪里看，我已经没有想法了。 有人有一个想法在哪里看？

2013-02-21更新：新数据！

我添加了两个更多的时间跟踪到应用程序。 至于测量：监控系统调用执行两个任务的servlet，测量服务器上每个任务的执行时间并将所花费的时间写入响应。 这些值由监控系统logging。

我有几个有趣的新事实：应用程序的热重新部署导致当前Tomcat上的这个单一实例发疯。 这也似乎影响原始的CPU计算性能（见下文）。 这种个人情境爆炸与随机发生的整体情境爆炸是不同的。

现在有一些数据：

首先个人行：

1. 浅蓝色是一个小型工作stream程的总执行时间（细节见上），在客户端测量
2. 红色是淡蓝色的“一部分”，是在客户端测量的执行该工作stream程特殊步骤所需的时间
3. 深蓝在应用程序中进行测量，包括通过Hibernate读取数据库中的实体列表，并遍历该列表，获取懒惰集合和惰性实体。
4. Green是一个使用浮点和整数运算的小型CPU基准。 据我看到没有对象分配，所以没有垃圾。

现在对于个别的爆炸阶段：我用三个黑点标记每个图像。 第一个是或多或less只有一个应用程序实例的“小”爆发 – 在Inst1中跳转（特别是在红线中可见），而Inst2或多或less保持冷静。

在这个小爆炸之后，发生了“大爆炸”，并且该Tomcat上的所有应用程序实例爆炸（第2个点）。 请注意，这种爆炸会影响所有高级操作（请求处理，数据库访问），但不会影响 CPU基准。 它在这两个系统中保持低水平。

之后，我通过触摸context.xml文件来热重新部署Inst1。 正如我刚才所说的那样，这个例子从爆炸到现在完全消失（淡蓝色的线条已经不在图表之内了 – 大约是18秒）。 注意：a）这个重新部署完全不会影响Inst2，b）Inst1的原始数据库访问如何也不受影响 – 但CPU突然变慢了！ 。 我说，这太疯狂了。

更新的更新 Tomcat的防泄漏监听器在应用程序解除部署时不会怀疑过时的ThreadLocals或Threads。 显然，似乎有一些清理问题（我认为这与Big Bang没有直接关系），但Tomcat对我没有任何提示。

2013-02-25更新：应用程序环境和Quartz Schedule

应用程序环境不是很复杂。 除了networking组件（我对这些还不是很了解），基本上有一个应用程序服务器（Linux）和两个数据库服务器（MySQL 5和MSSQL 2008）。 主要负载在MSSQL服务器上，另一个只是作为存储会话的地方。

应用程序服务器运行Apache作为两个Tomcat之间的负载平衡器。 所以我们有两个运行在相同硬件上的JVM（两个Tomcat 实例 ）。 我们使用这种configuration不是为了实际平衡负载，因为应用程序服务器能够运行应用程序（很多年来已经这样做了），而是在无需停机的情况下启用小型应用程序更新。 有问题的Web应用程序被部署为不同客户的独立上下文 ，每个Tomcat大约有15个上下文。 （在我的post里，我看到混合了“实例”和“背景” – 在办公室里，他们经常被用作同义词，我们通常神奇地知道同事在说什么，我不好意思，我真的很抱歉。

用更好的措辞来说明情况 ：我公布的图表显示同一个JVM上同一个应用程序的两个不同上下文的响应时间。 大爆炸影响一个JVM上的所有上下文，但不会发生在另一个上（Tomcats爆炸的顺序是随机的）。 热重新部署后，一个Tomcat实例的上下文变得疯狂（带有所有有趣的副作用，比如看起来比较慢的CPU）。

系统的整体负载相当低。 这是一个内部核心业务相关的软件，约30个活跃用户同时。 应用程序特定的请求（服务器触摸）目前约为每分钟130次。 单个请求的数量很less，但是请求本身通常需要数百个数据库select，所以它们相当昂贵。 但通常一切都完全可以接受。 该应用程序也不会创build大型的无限caching – 有些查找数据会被caching，但只会在很短的时间内完成。

上面我写道，能够运行应用程序的服务器已经好几年了。 我知道find问题的最好方法是首先确切地知道什么时候出现问题，看看在这个时间框架中（在应用程序本身，相关的库或基础结构中）有什么变化，然而问题是我们不知道问题什么时候发生。 让我们称之为次优的（在缺席的意义上）应用程序监视…： – /

我们排除了一些方面，但在过去的几个月中，应用程序已经被更新了几次，因此我们不能简单地部署一个老版本。 不是function更改的最大更新是从JSP切换到Facelets。 但是，“东西”一定是所有问题的原因，但我不知道为什么Facelets会影响纯数据库查询时间。

石英

至于石英时间表：总共有8个工作。 他们大多数每天只运行一次，而且与大数据量同步有关（绝对不像“大数据量”那样“大”，只比日常用户在日常工作中看到的多）。 但是，这些工作当然是在晚上进行的，白天也是有问题的。 我省略了详细的工作列表（如果有帮助，我可以提供更多的课程信息）。 工作的源代码在过去的几个月里并没有改变。 我已经检查过爆炸与工作是否一致，但结果还是没有定论。 我实际上说他们不alignment，但是由于每分钟都有几个工作，我还不能排除。 在我看来，每分钟运行的实际工作都是相当低的重量，他们通常会检查数据是否可用（在不同的数据源，数据库，外部系统，电子邮件帐户），如果是这样写入数据库或推送到另一个系统。

不过，我目前正在启用个人作业执行logging，以便我可以准确地看到每个作业执行的开始和结束时间戳。 也许这提供了更多的见解。

2013-02-28更新：JSF阶段和时间

我手动添加一个JSF phae监听器到应用程序。 我执行了一个示例调用（ajax刷新），这是我得到的（左：正常运行的Tomcat实例，右：大爆炸后的Tomcat实例 – 这两个数字几乎同时来自两个Tomcats，并且以毫秒为单位）：

1. RESTORE_VIEW：17 vs 46
2. APPLY_REQUEST_VALUES：170和486
3. PROCESS_VALIDATIONS：78 vs 321
4. UPDATE_MODEL_VALUES：75 vs 307
5. RENDER_RESPONSE：1059 vs 4162

Ajax刷新本身属于search表单及其search结果。 应用程序的最外层请求filter和Web Flow开始工作之间还有另一个延迟：有一个FlowExecutionListenerAdapter ，用于测量Webstream程某些阶段所花费的时间。 这个监听器在一个未分解的Tomcat上为完整的请求总共1632毫秒报告1405毫秒的“请求已提交”（就我所知，第一个webstream事件），因此我估计大约200毫秒开销。
但是在爆炸的Tomcat上，在7105ms的总请求持续时间内，它报告了5332毫秒的请求提交（意味着所有JSF阶段发生在这5秒钟内），因此我们高达将近2秒的开销， 。
在我的测量filter下面，过滤链包含一个org.ajax4jsf.webapp.BaseFilter ，然后调用Spring servlet。

2013-06-05更新：最近几周发生的一切

一个小而迟的更新…应用程序的性能仍然吸收一段时间后，行为仍然不稳定。 剖析没有太多帮助，它只是产生了大量难以parsing的数据。 （尝试在性能数据上或在生产系统上进行分析……感叹）我们进行了多个testing（剥离软件的某些部分，取消部署其他应用程序等），并且实际上有一些改进会影响整个应用程序。 我们的EntityManager默认的刷新模式是AUTO ，在视图渲染过程中会发出大量的抓取和select，总是包括检查刷新是否是必要的。
所以我们构build了一个JSF阶段侦听器，在RENDER_RESPONSE期间将flush模式设置为COMMIT 。 这大大提高了整体性能，似乎有些缓解了这个问题。

然而，我们的应用程序监视在某些tomcat实例的某些上下文中仍然会产生完全不正常的结果和性能。 就像应该在一秒之内完成的一个动作（而且实际上在部署之后），现在需要四秒钟以上。 （这些数字由浏览器中的手动计时支持，所以不是导致问题的监视）。

例如看下面的图片：

该图显示了两个运行相同上下文的tomcat实例（表示相同的db，相同的configuration，相同的jar）。 蓝线是纯数据库读取操作（获取实体列表，迭代它们，延迟获取集合和相关数据）所花费的时间。 绿松石和红线分别通过渲染几个视图和进行ajax刷新来测量。 绿松石和红色两个请求所呈现的数据大部分与查询蓝线的数据相同。

现在在实例1（右）的0700年左右，纯DB时间有了大幅增加，似乎也影响了实际的渲染响应时间，但是仅在tomcat 1上.Tomcat 0在很大程度上不受此影响，因此不能由DB引起服务器或networking，两个tomcat都在相同的物理硬件上运行。 它必须是Java领域的一个软件问题。

在我的最后一次testing中，我发现了一些有趣的东西：所有的响应都包含头文件“X-Powered-By：JSF / 1.2，JSF / 1.2”。 有些（由WebFlow产生的redirect响应）甚至在那里有三次“JSF / 1.2”。
我追溯了设置这些头文件的代码部分，第一次设置这个头文件是由这个堆栈引起的：

 ... at org.ajax4jsf.webapp.FilterServletResponseWrapper.addHeader(FilterServletResponseWrapper.java:384) at com.sun.faces.context.ExternalContextImpl.<init>(ExternalContextImpl.java:131) at com.sun.faces.context.FacesContextFactoryImpl.getFacesContext(FacesContextFactoryImpl.java:108) at org.springframework.faces.webflow.FlowFacesContext.newInstance(FlowFacesContext.java:81) at org.springframework.faces.webflow.FlowFacesContextLifecycleListener.requestSubmitted(FlowFacesContextLifecycleListener.java:37) at org.springframework.webflow.engine.impl.FlowExecutionListeners.fireRequestSubmitted(FlowExecutionListeners.java:89) at org.springframework.webflow.engine.impl.FlowExecutionImpl.resume(FlowExecutionImpl.java:255) at org.springframework.webflow.executor.FlowExecutorImpl.resumeExecution(FlowExecutorImpl.java:169) at org.springframework.webflow.mvc.servlet.FlowHandlerAdapter.handle(FlowHandlerAdapter.java:183) at org.springframework.webflow.mvc.servlet.FlowController.handleRequest(FlowController.java:174) at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:920) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:827) at javax.servlet.http.HttpServlet.service(HttpServlet.java:641) ... several thousands ;) more 

第二次这个头被设置

 at org.ajax4jsf.webapp.FilterServletResponseWrapper.addHeader(FilterServletResponseWrapper.java:384) at com.sun.faces.context.ExternalContextImpl.<init>(ExternalContextImpl.java:131) at com.sun.faces.context.FacesContextFactoryImpl.getFacesContext(FacesContextFactoryImpl.java:108) at org.springframework.faces.webflow.FacesContextHelper.getFacesContext(FacesContextHelper.java:46) at org.springframework.faces.richfaces.RichFacesAjaxHandler.isAjaxRequestInternal(RichFacesAjaxHandler.java:55) at org.springframework.js.ajax.AbstractAjaxHandler.isAjaxRequest(AbstractAjaxHandler.java:19) at org.springframework.webflow.mvc.servlet.FlowHandlerAdapter.createServletExternalContext(FlowHandlerAdapter.java:216) at org.springframework.webflow.mvc.servlet.FlowHandlerAdapter.handle(FlowHandlerAdapter.java:182) at org.springframework.webflow.mvc.servlet.FlowController.handleRequest(FlowController.java:174) at org.springframework.web.servlet.mvc.SimpleControllerHandlerAdapter.handle(SimpleControllerHandlerAdapter.java:48) at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:925) at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:856) at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:920) at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:827) at javax.servlet.http.HttpServlet.service(HttpServlet.java:641) 

我不知道这是否表明有问题，但是我没有注意到在我们的任何服务器上运行的其他应用程序，所以这也提供了一些提示。 我真的不知道框架代码在做什么（当然，我还没有深入），也许有人有一个想法？ 还是我陷入死胡同？

附录

我的CPU基准testing代码由一个计算Math.tan的循环组成，并使用结果值修改servlet实例上的一些字段（在那里不是volatile / synchronized），然后执行几个原始整数计算。 我知道，这并不是严重的复杂问题，但好吧…似乎在图表中显示了一些东西，但是我不确定它显示了什么。 我做了现场更新，以防止HotSpot优化掉我所有的宝贵代码;）

  long time2 = System.nanoTime(); for (int i = 0; i < 5000000; i++) { double tan = Math.tan(i); if (tan < 0) { this.l1++; } else { this.l2++; } } for (int i = 1; i < 7500; i++) { int n = i; while (n != 1) { this.steps++; if (n % 2 == 0) { n /= 2; } else { n = n * 3 + 1; } } } // This execution time is written to the client. time2 = System.nanoTime() - time2; 

Answer 1

解

增加代码caching的最大大小：

 -XX:ReservedCodeCacheSize=256m 

背景

我们正在使用运行在Tomcat 7和Java 1.7.0_15上的ColdFusion 10。 我们的症状与您的症状相似。 有时服务器上的响应时间和CPU使用率会上升很多，没有明显的原因。 看起来好像CPU变慢了。 唯一的解决办法是重新启动ColdFusion（和Tomcat）。

初步分析

我开始通过查看内存使用情况和垃圾收集器日志。 没有什么可以解释我们的问题。

我的下一步是每小时安排一次堆转储，并定期使用VisualVM进行采样。 目标是从放缓之前和之后获得数据，以便进行比较。 我设法取得了成就。

抽样中有一个function突出：get（）in coldfusion.runtime.ConcurrentReferenceHashMap。 在经济放缓之后，花了很多时间，而之前很less。 我花了一些时间理解这个函数是如何工作的，并且发展了一个理论，说明散列函数可能会导致一些巨大的桶。 使用堆转储，我能够看到最大的桶只包含6个元素，所以我就抛弃了这个理论。

代码caching

当我阅读“Java性能：权威指南”时，我终于走上了正轨。 它有关于JIT编译器的一章，讲述了我之前没有听说过的代码caching。

编译器禁用

当监视执行的编译数量（使用jstat进行监视）和代码caching的大小（使用VisualVM的内存池插件进行监视）时，我看到大小增加到最大值（在我们的环境中默认为48 MB – – 默认值取决于Java版本和Java编译器）。 当Code Cache变满时，JIT编译器被closures。 我读过“CodeCache已满，编译器已被禁用”。 应该打印出来，但是我没有看到这个消息。 也许我们使用的版本没有这个消息。 我知道编译器被closures，因为编译的数量停止增加。

继续优化

JIT编译器可以对先前编译的函数进行去优化，这些函数将提醒解释器再次执行的函数（除非函数被改进的编译所取代）。 去优化的函数可以被垃圾回收来释放代码caching中的空间。

由于某些原因，即使没有编写任何代替它们的函数，函数仍然被优化。 代码caching中会有越来越多的内存可用，但JIT编译器没有重新启动。

当我们遇到一个放缓的时候，我从来没有使用过-XX：+ PrintCompilation，但是我相当肯定，当我看到ConcurrentReferenceHashMap.get（）或者它所依赖的一个函数的时候，会被去最优化。

结果

我们没有看到任何放缓，因为我们将代码caching的最大规模增加到了256 MB，并且我们也看到了一般性能的改善。 我们的代码caching目前有110 MB。

Answer 2

首先，让我说，你已经做了一个很好的工作，抓住关于这个问题的详细事实 ; 我真的很喜欢你如何清楚你所知道的和你在猜测的东西 – 这真的有帮助。

编辑1上下文与实例更新后大规模编辑

我们可以排除：

• GC（这将影响CPU基准服务线程并刺激主CPU）
• Quartz作业（既可以影响Tomcats也可以影响CPU基准）
• 数据库（这将影响两个雄猫）
• networking包风暴和类似（这将影响两个雄猫）

我相信你正在遭受的是在你的JVM的某个地方增加了延迟 。 延迟是线程等待（同步）来自某个地方的响应的地方 – 它增加了您的servlet响应时间，但不会对CPU造成任何损失。 典型的延迟是由以下原因造成的：

• networking电话，包括
  • JDBC
  • EJB或RMI
  • JNDI
  • DNS
  • 文件共享
• 磁盘读取和写入
• 穿线
  • 读取（有时写入）队列
  • synchronized方法或块
  • futures
  • Thread.join()
  • Object.wait()
  • Thread.sleep()

确认问题是延迟

我build议使用商业分析工具。 我喜欢[JProfiler]（ http://www.ej-technologies.com/products/jprofiler/overview.html，15天的试用版），但是YourKit也是由StackOverflow社区推荐的。; 在这个讨论中，我将使用JProfiler术语。

附加到Tomcat进程，同时performance良好，并感觉它在正常情况下的外观。 尤其是，使用高级JDBC，JPA，JNDI，JMS，servlet，套接字和文件探测器来查看JDBC，JMS等操作需要多长时间（ screencast） 。当服务器出现问题并进行比较时，再次运行此操作。您将会看到究竟是什么放缓了在下面的产品屏幕截图中，您可以使用JPA探针查看SQL计时：

JPA热点http://static-aws.ej-technologies.com/SanJPN2pU9HB3g30N03BZsAwd77YzUtpXAsZoe9VUCi.png

但是，探测器可能并没有将这个问题隔离出来，例如可能是一些线程问题。 转到应用程序的“线程”视图; 这将显示一个正在运行的每个线程的状态图，以及它是否正在CPU上执行，在Object.wait() ，正在等待进入synchronized块还是正在等待networkingI / O。 当你知道哪个或哪些线程出现问题时，进入CPU视图，select线程并使用线程状态select器立即深入查看昂贵的方法及其调用堆栈。 [Screencast]（（ screencast ））。您将能够深入到您的应用程序代码。

这是可运行时间的调用堆栈：

这是一样的，但显示networking延迟：

当你知道什么是阻塞的时候，希望解决的道路会更加清晰。

Answer 3

有人有一个想法在哪里看？

1. 问题可能是Tomcat / JVM的问题 – 你是否有一些批处理作业，像共同的数据库一样强调共享资源？

2. 当应用程序响应时间爆炸时，请进行线程转储并查看java进程正在执行的操作？

3. 如果您使用Linux，请使用strace这样的工具，并检查java进程正在做什么。

Answer 4

您是否检查过JVM GC时间？ 某些GCalgorithm可能会“暂停”应用程序线程并增加响应时间。

您可以使用jstat实用程序来监视垃圾回收统计信息：

 jstat -gcutil <pid of tomcat> 1000 100 

以上命令将每100秒打印一次GC统计信息。 查看FGC / YGC列，如果数字不断上升，GC选项有问题。

如果您想缩短响应时间，您可能需要切换到CMS GC：

 -XX:+UseConcMarkSweepGC 

您可以在这里查看更多的GC选项。

Answer 5

在您的应用程序执行缓慢一段时间后会发生什么情况，是否会恢复正常运行？ 如果是这样，那么我会检查是否有任何活动与您的应用程序在这个时间没有关系。 类似于防病毒扫描或系统/数据库备份。

如果没有，那么我会build议使用一个分析器（JProfiler，yourkit等）运行它，这个工具可以很容易地指向你的热点。

Answer 6

我们遇到了同样的问题，运行在Java垃圾回收器上运行的Java 1.7.0_u101（Oracle支持的版本之一，因为最新的公共JDK / JRE 7版本是1.7.0_u79）。 我无法确定问题是否出现在其他Java 7版本或其他GC中。

我们的过程是运行Liferay Portal的Tomcat（我相信Liferay的确切版本在这里是没有意义的）。

这是我们观察到的行为：使用5GB的-Xmx，启动后的初始代码caching池大小约为40MB。 一段时间后，它下降到大约30MB（这是正常的，因为有很多代码在启动时运行，将永远不会再执行，所以它可能会在一段时间后从caching中被驱逐出去）。 我们观察到有一些JIT活动，所以JIT实际上填充了caching（与我后面提到的大小相比，似乎相对于整个堆大小的小caching大小对JIT提出了严格的要求，并且这使得后者相当不安地驱逐caching）。 但是，过了一段时间，没有更多的编译，JVM得到了痛苦的缓慢。 我们不得不时刻杀死我们的雄猫，以获得足够的性能，而当我们向门户添加更多代码时，问题变得越来越糟（因为我认为Code Cache快速饱和）。

看来在JDK 7 JVM中有几个错误导致它不能重新启动JIT（请看这篇博文： https : //blogs.oracle.com/poonam/entry/why_do_i_get_message ），即使在JDK 7中，紧急刷新（博客提到Java错误8006952,8012547,8020151和8029091）。

这就是为什么手动将代码caching增加到紧急刷新不太可能发生的级别“修复”问题（我想JDK 7就是这种情况）。

在我们的例子中，我们不是试图调整代码caching池大小，而是select升级到Java 8.这似乎解决了这个问题。 另外，Code Cache现在看起来也相当大（启动大小约为200MB，巡航大小约为160MB）。 正如所料，在空闲时间过后，如果某个用户（或机器人，或其他）浏览我们的站点，caching池大小会下降，从而导致更多的代码被执行。

我希望你find上面的数据有帮助。

忘了说：我发现博客，支持数据，推断逻辑和这篇文章的结论非常有帮助。 谢谢，真的！

Answer 7

你正在使用Quartz来pipe理定时进程，这似乎是在特定的时间发生的。

发布您的Quartz时间表，让我们知道是否一致，如果是的话，您可以确定哪些内部应用程序可能会开始消耗您的资源。

或者，可能有一部分应用程序代码最终被激活，并决定将数据加载到内存caching中。 你正在使用Hibernate; 检查对你的数据库的调用，看看是否有任何重合。