我目前正在运行一些 JMeter 测试来测试 Web 服务的性能。它使用了大量的 CPU。对于一个 JMeter 请求线程,其使用率为 10-30%(取决于请求的类型)。当我将其增加到仅 15 个线程时,CPU 利用率约为 95%。自然,我想弄清楚到底是怎么回事。我做了一个 Hprof CPU 示例(我尝试了 times 选项,但花了一个半小时才启动我的服务,并且没有消息通过)。以下是该采样的结果片段(超过 15 分钟)。
CPU SAMPLES BEGIN (total = 220846) Fri Aug 22 13:38:54 2014
rank self accum count trace method
1 14.96% 14.96% 33038 300514 java.net.PlainSocketImpl.socketAccept
2 14.84% 29.80% 32776 301258 sun.nio.ch.EPollArrayWrapper.epollWait
3 12.45% 42.26% 27505 313002 sun.nio.ch.EPollArrayWrapper.epollWait
4 7.48% 49.73% 16517 300604 java.net.PlainSocketImpl.socketAccept
5 7.18% 56.91% 15856 303203 sun.nio.ch.EPollArrayWrapper.epollWait
6 6.18% 63.09% 13639 313001 sun.nio.ch.ServerSocketChannelImpl.accept0
7 6.04% 69.13% 13329 304259 sun.nio.ch.EPoll.epollWait
8 5.11% 74.23% 11275 307102 sun.nio.ch.EPollArrayWrapper.epollWait
以及那些顶级样本的相应堆栈:
TRACE 300514:
java.net.PlainSocketImpl.socketAccept(:Unknown line)
java.net.AbstractPlainSocketImpl.accept(:Unknown line)
java.net.ServerSocket.implAccept(:Unknown line)
java.net.ServerSocket.accept(:Unknown line)
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(:Unknown line)
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(:Unknown line)
java.lang.Thread.run(:Unknown line)
TRACE 301258:
sun.nio.ch.EPollArrayWrapper.epollWait(:Unknown line)
sun.nio.ch.EPollArrayWrapper.poll(:Unknown line)
sun.nio.ch.EPollSelectorImpl.doSelect(:Unknown line)
sun.nio.ch.SelectorImpl.lockAndDoSelect(:Unknown line)
sun.nio.ch.SelectorImpl.select(:Unknown line)
org.apache.tomcat.util.net.NioBlockingSelector$BlockPoller.run(NioBlockingSelector.java:327)
TRACE 313002:
sun.nio.ch.EPollArrayWrapper.epollWait(:Unknown line)
sun.nio.ch.EPollArrayWrapper.poll(:Unknown line)
sun.nio.ch.EPollSelectorImpl.doSelect(:Unknown line)
sun.nio.ch.SelectorImpl.lockAndDoSelect(:Unknown line)
sun.nio.ch.SelectorImpl.select(:Unknown line)
org.apache.tomcat.util.net.NioEndpoint$Poller.run(NioEndpoint.java:1163)
java.lang.Thread.run(:Unknown line)
TRACE 300604:
java.net.PlainSocketImpl.socketAccept(:Unknown line)
java.net.AbstractPlainSocketImpl.accept(:Unknown line)
java.net.ServerSocket.implAccept(:Unknown line)
java.net.ServerSocket.accept(:Unknown line)
sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(:Unknown line)
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(:Unknown line)
sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(:Unknown line)
java.lang.Thread.run(:Unknown line)
TRACE 303203:
sun.nio.ch.EPollArrayWrapper.epollWait(:Unknown line)
sun.nio.ch.EPollArrayWrapper.poll(:Unknown line)
sun.nio.ch.EPollSelectorImpl.doSelect(:Unknown line)
sun.nio.ch.SelectorImpl.lockAndDoSelect(:Unknown line)
sun.nio.ch.SelectorImpl.select(:Unknown line)
net.spy.memcached.MemcachedConnection.handleIO(MemcachedConnection.java:217)
net.spy.memcached.MemcachedConnection.run(MemcachedConnection.java:836)
TRACE 313001:
sun.nio.ch.ServerSocketChannelImpl.accept0(:Unknown line)
sun.nio.ch.ServerSocketChannelImpl.accept(:Unknown line)
org.apache.tomcat.util.net.NioEndpoint$Acceptor.run(NioEndpoint.java:793)
java.lang.Thread.run(:Unknown line)
TRACE 304259:
sun.nio.ch.EPoll.epollWait(:Unknown line)
sun.nio.ch.EPollPort$EventHandlerTask.poll(:Unknown line)
sun.nio.ch.EPollPort$EventHandlerTask.run(:Unknown line)
java.lang.Thread.run(:Unknown line)
TRACE 307102:
sun.nio.ch.EPollArrayWrapper.epollWait(:Unknown line)
sun.nio.ch.EPollArrayWrapper.poll(:Unknown line)
sun.nio.ch.EPollSelectorImpl.doSelect(:Unknown line)
sun.nio.ch.SelectorImpl.lockAndDoSelect(:Unknown line)
sun.nio.ch.SelectorImpl.select(:Unknown line)
net.spy.memcached.MemcachedConnection.handleIO(MemcachedConnection.java:217)
net.spy.memcached.MemcachedConnection.run(MemcachedConnection.java:836)
正如您所看到的,超过一半的 CPU 使用率似乎来自应该等待的线程。这不应该占用CPU时间吗?
我看到了这个话题http://www.brendangregg.com/blog/2014-06-09/java-cpu-sampling-using-hprof.html这可能会让我认为这个结果具有误导性,但我的“top -H”结果显示了最大的 CPU 使用率,Zabbix 监控也是如此。所以,看起来它实际上正在消耗CPU。然而,有一个链接指向 hprof 作者的引用,其中指出:
When you have Java threads that are somehow not using the CPU, but managing to stay active, then it will appear as if those stack traces are consuming large amounts of CPU time when they aren't.
有人可以解释为什么会出现这种情况以及我可以采取哪些措施来减少这些情况下的 CPU 使用率?或者所有的CPU使用率指标实际上都是误导性的吗?如果是这样,了解我的服务中真实 CPU 利用率的更好方法是什么?
正如 Brendan Gregg 指出的您链接的博客文章,hprof 从 JVM 认为可运行的所有线程中采样。正如您在 Thread.state 的 Javadoc 中看到的,JVM 区分以下线程状态:
- NEW:尚未启动的线程处于此状态。
- RUNNABLE:在Java虚拟机中执行的线程处于这种状态。
- BLOCKED:被阻塞等待监视器锁的线程处于此状态。
- WAITING:无限期等待另一个线程执行特定操作的线程处于此状态。
- TIMED_WAITING:等待另一个线程执行操作达指定等待时间的线程处于此状态。
- TERMINATED:已退出的线程处于此状态。
正如我们所看到的,JVM 没有为等待 I/O 的线程提供专用状态。那是因为这样的线程实际上是被操作系统而不是JVM阻塞的。也就是说,就JVM而言,等待网络适配器的线程是可运行的。事实上,关于 RUNNABLE 状态的详细 Javadoc 写道:
可运行线程的线程状态。处于可运行状态的线程正在Java虚拟机中执行,但它可能正在等待来自操作系统的其他资源,例如处理器。
因此,hprof“cpu”采样中存在 I/O 方法并不意味着这些方法消耗了 CPU,因为它们的等待时间也被计算在内。
您可以:
- 假设 I/O 方法不负责 CPU 消耗,并关注其他方法
- 使用更好的分析器,考虑等待操作系统级资源
本文内容由网友自发贡献,版权归原作者所有,本站不承担相应法律责任。如您发现有涉嫌抄袭侵权的内容,请联系:hwhale#tublm.com(使用前将#替换为@)