为什么select()会在程序中消耗这么多CPU时间？

Question

我有几个使用MINA的Java应用程序,它们都使用20个MINA线程.一个应用程序提供大约10,000个并发连接,这些连接通常是空闲的但有时会接收输 对于该应用程序来说,20可能是一个合理的线程数,虽然我没有完全描述它(这个问题正在进行中).另一个应用程序一次只能提供大约15个连接但启动IO工作,因此它们非常繁忙,无论如何都有20个MINA线程,这显然太多了.

对我来说很奇怪的是,两个应用程序总是把他们的CPU时间的30%,有时高达60%用于MINA的select()方法,在VisualVM中进行了分析.调用堆栈如下所示:

java.lang.Thread.State: RUNNABLE
at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:228)
at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:81)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
- locked <40ca5d54> (a sun.nio.ch.Util$2)
- locked <24649fe8> (a java.util.Collections$UnmodifiableSet)
- locked <3fae9662> (a sun.nio.ch.EPollSelectorImpl)
at sun.nio.ch.SelectorImpl.select(SelectorImpl.java:98)
at org.apache.mina.transport.socket.nio.NioProcessor.select(NioProcessor.java:72)
at org.apache.mina.core.polling.AbstractPollingIoProcessor$Processor.run(AbstractPollingIoProcessor.java:1093)
at org.apache.mina.util.NamePreservingRunnable.run(NamePreservingRunnable.java:64)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
at java.lang.Thread.run(Thread.java:722)

它似乎是基于一个繁忙的民意调查,这对我来说听起来真的不对.

当我看到数字那么高时,我应该担心吗？是什么导致这个？这是我需要优化的东西还是更类似于睡眠或闲置程序？如果它更像是一个睡眠例程,它会以某种方式被安排为比其他CPU工作更低的优先级？

更新: 这个线程似乎是同一个问题.我遵循了它的建议,现在正在运行Java 1.7.0_45,但我仍然看到select在具有10k连接的应用程序中占用高达90%的CPU时间.

我们正在使用MINA 2.0.4,这意味着修复了相关的错误.

Answer 1

不幸的是,这是对数字的错误解释.

我已多次面对这种情况(并在stackoverflow上问一个问题).

主要原因是VisualVM没有显示正确的CPU时间.它显示了RUNNING状态中线程时间的百分比.但是从以下文档Thread.State:

可运行线程的线程状态.处于可运行状态的线程正在Java虚拟机中执行,但它可能正在等待来自操作系统的其他资源, 例如处理器.

这正是正在发生的事情.实际上,在OS epoll_wait()调用中阻塞了线程.在Linux框中,有几种方法可以确认是这种情况.

strace'线程

$ strace -tttT -f -p [thread-id]

线程id可以从jstack输出中获得:

$ jstack [java-pid]
[...]
"Netty Builtin Server 1" #17 prio=5 os_prio=31 tid=0x00000001013dd800 nid=0xe12f runnable [0x0000700001fe4000]
  java.lang.Thread.State: RUNNABLE
  at sun.nio.ch.KQueueArrayWrapper.kevent0(Native Method)
  at sun.nio.ch.KQueueArrayWrapper.poll(KQueueArrayWrapper.java:198)
[...]

在这种情况下,线程id是0xe12f(应该转换为十进制).您将看到大部分时间线程将在epoll_wait()通话中.

pidstat线程

$ pidstat -tu -p [java-pid] | grep [thread pid]

你会看到这个线程的低系统和用户CPU时间,这意味着它不消耗CPU.

轮询线程状态使用 ps

$ ps -eL -o pid,tid,state | grep [thread-id]

您将看到大部分时间线程处于状态S或Sl(可中断睡眠)而不是R(可运行).

如果服务没有运营问题,最后你不应该担心.