【问题标题】:What would cause Tomcat (v8) to CPU spike with periodic regularity什么会导致 Tomcat (v8) 周期性地出现 CPU 峰值
【发布时间】:2015-12-07 16:49:53
【问题描述】:

在 Windows 2012 RT (x64) TEST 服务器上,我们正在运行 Tomcat 8 安装,CPU 使用率在其达到峰值使用率的规律性方面令人不安。

该行为发生在安装我们的应用程序之后,但任何人访问它之前。我已经访问了几个页面并测试了一些功能,但没有任何东西可以创建我所知道的这种行为。

服务器上有 2 个虚拟处理器,每隔约 20 秒,CPU 使用率(在运行 Tomcat 的一个处理器上)会飙升至 100%,持续 10 秒(给予或接受)。见下文:

模式的规律性向我表明 Tomcat 8 的安装或设置有问题。

我已经安装了 YourKit Java Profiler(通过 SO 推荐),我希望它可以阐明导致这些峰值的原因,但无法看到线程启动的原因 - 至少是部分原因我对 YourKit 的新鲜感。我确实将它附加到 Tomcat 启动文件中,它似乎正在跟踪行为。

catalina 日志在尖峰事件发生期间是静默的(就像我的应用程序日志一样),但是当我停止 Tomcat 时,有一些关于 ThreadLocals 启动但无法删除的消息,然后:“......线程将被更新随着时间的推移,尽量避免可能的内存泄漏。”

我让服务器在周末运行,这种模式一直持续到今天,所以我认为我的症状不会消失。现在,无论启动什么,都每 20 秒启动一次这些线程(和/或 YourKit)就消耗了系统上所有可用的 RAM。

有什么可能的方法来隔离这个异常的 Tomcat 活动并希望停止或纠正它?

YourKit 中有很多图表和标签,所以我不愿列出所有可能有用的东西。感谢您帮助我缩小 YourKit(或其他工具)可以提供给我的问题。

来自 catalina 日志的关于启动的信息:

Apache Tomcat/8.0.23
Architecture: amd64
Java Home: C:\Program Files\Java\jre1.8.0_65
CATALINA_BASE: C:\Program Files\Apache Software Foundation\Tomcat 8.0

2015-12-08 更新

应 Gergely 的要求,该应用程序是 DSpace 的本地安装。这是一个带有 Postgres SQL 数据库后端的 Java 应用程序。我们正在从这里定制它的开源版本:http://www.dspace.org/introducing。我不确定还有什么有用的,我认为堆栈跟踪更能说明什么正在运行(和没有运行)——见下文。

通过在 YourKit 中打开堆栈遥测,“CPU 估计”可通过在一段时间的分析器历史记录中拖动光标来实现。对我来说,看起来所有 CPU 都在空转。 Tomcat 例程 下图所示的 Java 文件是什么?它们并没有因为与 DSpace 相关(尽管我不是专家)而让我印象深刻,而且在 CPU 达到峰值时看起来也没有任何工作正在完成。

注意:堆栈跟踪在安静期间是相同的——唯一的区别是 CPU 时间(毫秒)是数百毫秒而不是数千毫秒。为了比下面更直接的比较,驼峰在 Thread.run() 中表示约 8,000 毫秒,而安静期消耗约 125 毫秒的 cpu 时间(尽管涵盖的时间量大致相同)。

最后,当请求应用程序的页面时,调用树中会出现一个后续的代码分支。如果它发生在峰值期间,加载整个页面可能只需要 400 毫秒的 CPU 时间。出现的代码分支是 ApplicationFilterChain.java 作为一个单独的分支,与 PooledExecutor$Worker.run() 并排 - 都位于层次结构中的 java.lang.Thread.run() 之下。

当试图解释堆栈跟踪时:EDU.oswego.cs.dl.util.concurrent.PooledExecutor$Worker.run() 负责吗?

没有已知相关活动的处理器峰值

2015-12-08 更新 #2

YourKit 已预先配置为隐藏某些 java 类名模式,这些模式掩盖了对 java.lang.Thread 的深入了解。清除过滤器启用了以下屏幕截图,显示峰值事件期间的绝大多数处理时间是通过调用以下 3 个方法:

  • java.io.WinNTFileSystem.canonicalize0
  • java.io.WinNTFileSystem.getBooleanAttributes (inFile.exists())
  • StardardRoot.java

抱歉,我对 Tomcat 或 DSpace 的了解还不够,无法知道是谁在启动这些任务。 (如果重要的话,第一行正上方的行是java.lang.Thread.run(),然后是<All threads>

【问题讨论】:

  • 在 CPU 使用率较高时进行一些线程转储。
  • 这不太可能是 Tomcat 出了问题。您能告诉我们有关您在服务器上部署的应用程序的任何信息吗?
  • 您是否正在运行任何正在更改/重新索引 DSpace 项目的 cron 作业?那些会击中 Solr,然后会导致额外的活动。
  • @schweerelos,谢谢你的想法——我已经考虑过并寻找过这个想法。有计划的任务,但我不相信它们正在运行。这种断断续续的模式如此反复地扩展自身,并且具有这样的规律性,这在重新索引启动时不会发生。资源使用外观完全不同且“不规则”——不是周期性的。还有一些日志是在真正的索引发生时生成的,在这些峰值期间我没有看到。
  • @GergelyBacso,我的帖子中的更新是否提供了有关 Tomcat 或我的应用程序是否导致这些峰值的任何见解?谢谢

标签: performance tomcat dspace windows2012 yourkit


【解决方案1】:

感谢查看并回复此询问的人。正如许多人推测的那样,问题与我们对 Tomcat 的设置和使用有关——而不是 Tomcat 本身的问题(很可能)。

这是在没有完全了解安装 DSpace 应用程序和 Tomcat 的情况下尝试回答问题,但我认为我知道的足够危险,并且可能对后续用户有所帮助。

在安装应用程序DSpace 时,Tomcat 的配置目录中有一些安装属性决定是否允许在不重新启动 Tomcat 的情况下立即反映编码文件的更改。我们的这些设置之前位于[tomcat]/conf/Catalina/localhost/ 目录中,三个文件中的每一个都包含一个小的、无关紧要的 XML 文件,例如(例如 oai.xml):

<?xml version='1.0'?>
<Context docBase="E:/dspace/webapps/oai"
    reloadable="false"
    cachingAllowed="true"/>

您可以在以下链接中找到有关这些属性的文档: https://wiki.duraspace.org/display/DSDOC5x/Installing+DSpace

该文档中有关于reloadablecachingAllowed 属性的建议。搜索“生产环境中的 Tomcat 上下文设置”。这是一段摘录(重点是我的):

当您第一次开始使用 DSpace 时,这些设置非常有用,因为它们可以让您调整 DSpace XMLUI(XSLT 或 CSS)或 JSPUI(JSP)并看到您的更改被 Tomcat 自动重新加载(无需重新启动Tomcat)。然而,值得注意的是,Apache Tomcat 文档建议生产站点保留默认值(reloadable="false" cachingAllowed="true"),因为允许 Tomcat 自动重新加载所有更改可能会导致“显着的运行时开销”。

是否保留这些 Tomcat 设置完全取决于您。我们只是建议从它们开始,这样您就可以更轻松地自定义您的站点,而无需重新启动 Tomcat。较小的 DSpace 站点可能不会注意到将这些设置保留在生产环境中的任何性能问题。 较大的 DSpace 站点可能希望确保 Tomcat 的性能更加精简。

当我将这些布尔标志切换为 reloadable="false"cachingAllowed="true" CPU 峰值体验立即停止。我不知道关于“大型站点”的警告是否适用于我们,或者是否“简化的性能”可能指的是我观察到的负面活动。

我认为我们的安装可能存在其他问题,导致了这种特殊表现;一个不祥的线索是我们的生产服务器似乎在reloadable="true" 配置中使用这些标志运行。 Java、Tomcat、Windows、AND DSpace 都在同时获得新版本,因此很难确定为什么类似的 Tomcat &lt;context&gt; 设置会产生如此不同的结果。

我现在至少满足于有新的行为并且系统已经平静下来。如果我了解更多信息,我会发布更多信息,但接下来会关注其他难题。

更新

FWIW,属性是直接控制 Tomcat 的设置,它们在版本之间有所不同。例如,cachingAllowed 在版本 8 中被删除,这意味着它可以从 Context 元素中删除。比较:

https://tomcat.apache.org/tomcat-8.0-doc/config/context.html#Attributes https://tomcat.apache.org/tomcat-7.0-doc/config/context.html#Attributes

为了更好地衡量,这里是 Tomcat 8 文档中reloadable 的帮助文本:

如果您希望 Catalina 监视 /WEB-INF/classes/ 和 /WEB-INF/lib 中的类的更改,则设置为 true,并在检测到更改时自动重新加载 Web 应用程序。此功能在应用程序开发期间非常有用,但它需要大量运行时开销,因此不建议在已部署的生产应用程序中使用。这就是该属性的默认设置为 false 的原因。但是,您可以使用 Manager Web 应用程序来按需触发重新加载已部署的应用程序。

所以似乎最终的答案是 Windows 2012-R2 上的 Tomcat 8 带有 reloadable='true' 标志的轮询对 WEB-INF/lib 和 WEB-INF/classes 的更改.要仔细阅读的文件夹和文件的数量很可能是这些激烈的、尖峰 CPU 事件的原因。现在我将依赖 reloadable='false' ,这肯定会为我们消除症状。

【讨论】:

  • 呜呜呜!我应该抓住这个! Tomcat context reload-check 真的配置了10秒!呃。我猜它对你的性能图有很大的影响,因为你的项目有大量的数据。不错的收获。恭喜。
  • 感谢@GergelyBacso——希望这对未来的 CPU 分析问题来说是一个很好的问题。是的,项目的某些部分非常大,修剪掉可能不必要的东西在某些时候可能会很好!很高兴我们都能学到一些东西
  • 我在自定义 context.xml 中只有这一行 。我不确定它指的是什么。有什么想法吗?谢谢,
【解决方案2】:

不是一个明确的答案,但评论太长了

在查看了有关此问题的更新并阅读了一些内容后,我怀疑此反复出现的问题是由 CuratorTask 引起的。原因是:

  • 您获得的堆栈跟踪清楚地表明,由 DSpace 库管理的 WorkerThread(因此不应责怪 Tomcat)当时正在使用处理器。

    李>
  • 在阅读了一些关于DSpace本身的信息后,看起来它有一个功能允许用户定义curator tasks应该是定期执行

  • 除此之外至少有一个任务 - 根据文档 - 它默认激活,所以理论上可以有任何默认激活的任务数。

  • 此外,this 对话显示至少 1 个管理任务,每 10 秒激活一次

所有这些共同指向同一个方向。我建议使用 DSpace 的 UI(可能处于管理员模式)环顾四周并找到活动的策展任务并验证它们的调度是否与您观察到的相符。

【讨论】:

  • Gergely,感谢您的分析和建议。我还没有想到策划的任务,也没有反驳它,所以会继续学习这些。不过,我上传了一个新的屏幕截图,它显示了哪些 java 步骤是 active 并达到了 CPU 峰值,但可能不是启动它们的原因。既然这些线程来自org.apache... 这不意味着Tomcat 有责任吗?或者我们可以安全地假设java.lang.Thread.run() 下的工作是由 DSpace 启动的(屏幕截图中第一行正上方的那一行)?
  • 上面那些突出显示的函数正在处理文件资源。是的,Apache 肯定会加载它们,但我认为它会加载它们,因为它是那些策展人任务所要求的。我的意思是如果我的假设是正确的,那么那些策展人任务需要对一些数据进行操作。当然,仍然不确定这些。以前没见过这个系统。
  • 在我忘记之前我想提一下,我从管理方面运行了我自己的管理任务,它生成了一些在周期性 CPU 峰值期间不会发生的日志注释。这可能不足以证明负面的证据,只是更多的信息。不过,在您从未见过的系统中进行了很好的研究!
  • 非常感谢您的帮助和建议。真正的答案已经被发现并发布。
猜你喜欢
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 1970-01-01
  • 2016-05-01
  • 1970-01-01
  • 2017-07-22
相关资源
最近更新 更多