使用 100% 单 CPU 内核的 Java Web 应用程序

Question

我们有使用 Spring 3.2.5 并在 Tomcat 7 上运行的 Java 应用程序。

由于过去几天的一些未知原因，它在经过一段时间的正确行为后开始使用 100% 的单核(这是一个有 2 个 CPU，每个 8 个核的机器)，并且有一段时间它的整体 CPU 使用率是高但分布在核心。

我们从 GC 点开始调查它 - 运气不好，尝试更多/更少的内存、不同的 GC 类型和配置都没有帮助。

当它使用 100% 的单核时，我们设法用 jstack 模拟线程，有很多这样的线程:

Thread 11260: (state = BLOCKED)
 - sun.nio.ch.EPollArrayWrapper.epollWait(long, int, long, int) @bci=0 (Compiled frame; information may be imprecise)

Thread 11375: (state = BLOCKED)
 - sun.nio.ch.EPollArrayWrapper.epollWait(long, int, long, int) @bci=0 (Compiled frame; information may be imprecise)
 - sun.nio.ch.EPollArrayWrapper.poll(long) @bci=18, line=269 (Compiled frame)

Thread 11421: (state = BLOCKED)
 - com.mysql.jdbc.Field.getStringFromBytes(int, int) @bci=144, line=719 (Compiled frame)

我们开始调查网络流量 - 但事实并非如此。

我们还能调查什么？是什么导致了这种奇怪的 CPU 使用 - 当它消耗所有单核时，应用程序没有响应。

没有RUNNING状态的线程，但是有很多:

Thread 12947: (state = IN_NATIVE)
 - java.net.PlainSocketImpl.$$YJP$$socketAccept(java.net.SocketImpl) @bci=0 (Interpreted frame)
 - java.net.PlainSocketImpl.socketAccept(java.net.SocketImpl) @bci=8 (Interpreted frame)
 - java.net.AbstractPlainSocketImpl.accept(java.net.SocketImpl) @bci=13, line=398 (Interpreted frame)
 - java.net.ServerSocket.implAccept(java.net.Socket) @bci=111, line=530 (Interpreted frame)
 - java.net.ServerSocket.accept() @bci=119, line=498 (Interpreted frame)
 - org.apache.catalina.core.StandardServer.await() @bci=269, line=453 (Interpreted frame)
 - org.apache.catalina.startup.Catalina.await() @bci=10, line=777 (Interpreted frame)
 - org.apache.catalina.startup.Catalina.start() @bci=272, line=723 (Interpreted frame)
 - sun.reflect.NativeMethodAccessorImpl.invoke0(java.lang.reflect.Method, java.lang.Object, java.lang.Object[]) @bci=0 (Interpreted frame)
 - sun.reflect.NativeMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) @bci=118, line=57 (Interpreted frame)
 - sun.reflect.DelegatingMethodAccessorImpl.invoke(java.lang.Object, java.lang.Object[]) @bci=12, line=43 (Interpreted frame)
 - java.lang.reflect.Method.invoke(java.lang.Object, java.lang.Object[]) @bci=63, line=606 (Interpreted frame)
 - org.apache.catalina.startup.Bootstrap.start() @bci=43, line=321 (Interpreted frame)
 - org.apache.catalina.startup.Bootstrap.main(java.lang.String[]) @bci=187, line=455 (Interpreted frame)

$$YJP$$ 来自 YK 分析器。

在其他机器上，遇到同样的问题，我再次在 IN_NATIVE 中找到了 497 个线程中的 345 个:

Thread 4979: (state = IN_NATIVE)
 - sun.nio.ch.EPollArrayWrapper.epollWait(long, int, long, int) @bci=0 (Compiled frame; information may be imprecise)
 - sun.nio.ch.EPollArrayWrapper.poll(long) @bci=18, line=269 (Compiled frame)
 - sun.nio.ch.EPollSelectorImpl.doSelect(long) @bci=28, line=79 (Compiled frame)
 - sun.nio.ch.SelectorImpl.lockAndDoSelect(long) @bci=37, line=87 (Compiled frame)
 - sun.nio.ch.SelectorImpl.select(long) @bci=30, line=98 (Compiled frame)
 - org.jboss.netty.channel.socket.nio.SelectorUtil.select(java.nio.channels.Selector) @bci=4, line=68 (Compiled frame)
 - org.jboss.netty.channel.socket.nio.AbstractNioSelector.select(java.nio.channels.Selector) @bci=1, line=415 (Compiled frame)
 - org.jboss.netty.channel.socket.nio.AbstractNioSelector.run() @bci=56, line=212 (Compiled frame)
 - org.jboss.netty.channel.socket.nio.AbstractNioWorker.run() @bci=1, line=89 (Interpreted frame)
 - org.jboss.netty.channel.socket.nio.NioWorker.run() @bci=1, line=178 (Interpreted frame)
 - org.jboss.netty.util.ThreadRenamingRunnable.run() @bci=55, line=108 (Interpreted frame)
 - org.jboss.netty.util.internal.DeadLockProofWorker$1.run() @bci=14, line=42 (Interpreted frame)
 - java.util.concurrent.ThreadPoolExecutor.runWorker(java.util.concurrent.ThreadPoolExecutor$Worker) @bci=95, line=1145 (Interpreted frame)
 - java.util.concurrent.ThreadPoolExecutor$Worker.run() @bci=5, line=615 (Interpreted frame)
 - java.lang.Thread.run() @bci=11, line=745 (Interpreted frame)

我也找到了一个:

Thread 13591: (state = IN_JAVA)
 - org.hibernate.engine.Cascade.cascadeAssociation(java.lang.Object, org.hibernate.type.Type, org.hibernate.engine.CascadeStyle, java.lang.Object, boolean) @bci=16, line=239 (Compiled frame; information may be imprecise)
 - org.hibernate.engine.Cascade.cascadeProperty(java.lang.Object, org.hibernate.type.Type, org.hibernate.engine.CascadeStyle, java.lang.Object, boolean) @bci=42, line=193 (Compiled frame)
 - org.hibernate.engine.Cascade.cascade(org.hibernate.persister.entity.EntityPersister, java.lang.Object, java.lang.Object) @bci=224, line=154 (Compiled frame)
 - org.hibernate.event.def.AbstractFlushingEventListener.cascadeOnFlush(org.hibernate.event.EventSource, org.hibernate.persister.entity.EntityPersister, java.lang.Object, java.lang.Object) @bci=60, line=154 (Compiled frame)
 - org.hibernate.event.def.AbstractFlushingEventListener.prepareEntityFlushes(org.hibernate.event.EventSource) @bci=106, line=145 (Compiled frame)
 - org.hibernate.event.def.AbstractFlushingEventListener.flushEverythingToExecutions(org.hibernate.event.FlushEvent) @bci=79, line=88 (Compiled frame)
 - org.hibernate.event.def.DefaultAutoFlushEventListener.onAutoFlush(org.hibernate.event.AutoFlushEvent) @bci=31, line=58 (Compiled frame)
 - org.hibernate.impl.SessionImpl.autoFlushIfRequired(java.util.Set) @bci=83, line=997 (Compiled frame)
 - org.hibernate.impl.SessionImpl.list(java.lang.String, org.hibernate.engine.QueryParameters) @bci=55, line=1149 (Compiled frame)
 - org.hibernate.impl.QueryImpl.list() @bci=33, line=102 (Compiled frame)
 - org.hibernate.impl.AbstractQueryImpl.uniqueResult() @bci=7, line=835 (Compiled frame)

我们可能会丢失一些资源，但这种情况在服务器负载高和低以及不同的时间都会发生。

Answer 1

我希望这可能已经解决了，如果没有，我建议按照以下步骤查找 CPU 使用率高的原因

1. 使用操作系统级别的命令查找哪个线程正在占用大量 CPU，例如使用 H 键或 -H 命令行选项 (top -H -p) 的 TOP，对于使用 F5 的 AIX htop，对于 Windows 使用 perfmon 或使用 Process explorer (https://technet.microsoft.com/en-us/sysinternals/bb896653.aspx)

2. 识别导致高 CPU 的线程并记下线程 ID(这可能是十六进制)

3. 获取线程转储并找到指定线程的线程堆栈

4. 尝试了解哪些方法被调用，哪些方法是 CPU 密集型方法。

这可以很容易地在 JVisual VM Sampler 或 JRofiler 中进行监控。