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

Question

我有几个使用 MINA 的 Java 应用程序，它们都使用 20 个 MINA 线程。一个应用程序服务于大约 10,000 个并发连接，这些连接通常是空闲的，但有时会接收输入。 20 可能是该应用程序的合理线程数，尽管我没有完全分析它（这个问题正在解决）。另一个应用程序一次只提供大约 15 个连接，但会启动 IO 工作，因此它们非常繁忙，并且有 20 个 MINA 线程，这显然太多了。

让我感到奇怪的是，这两个应用程序总是将大约 30%，有时甚至高达 60% 的 CPU 时间投入到 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 工作的优先级？

更新：this thread 似乎是同一个问题。我听从了它的建议，现在正在运行 Java 1.7.0_45，但我仍然看到 select 在具有 10k 连接的应用程序中占用了高达 90% 的 CPU 时间。

我们使用的是 MINA 2.0.4，这意味着 this relevant bug 是固定的。

Answer 1

很遗憾，这是对数字的错误解释。

我已经多次遇到这种情况（也可以在stackoverflow 上提问）。

主要原因是 VisualVM 没有显示正确的 CPU 时间。它显示RUNNING 状态下线程时间的百分比。但是来自Thread.State的文档：

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

这正是正在发生的事情。实际上，线程在 OS epoll_wait() 调用中被阻塞。在 Linux 机器上，有几种方法可以确认是这种情况。

strace'ing 线程

$ 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() 调用中。

pidstating 线程

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

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

使用ps轮询线程状态

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

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

最后，如果服务没有操作问题，您不必担心。

Answer 2

首先，两个应用程序有相同的问题很好；它可能表明问题出在 JVM 或操作系统上，而不是您的应用程序 :-)

正如 jzd 提到的，nio.select() 有问题。 {各种 Java 版本} x {各种平台，内核版本} 的乘积使它看起来像是一个无处不在的问题。我希望其中一项对您有用：

• 如果您使用的是 Linux，请尝试使用 2.6 内核，以防万一您使用的是 2.4

  ，假设该错误类似于：http://bugs.sun.com/view_bug.do?bug_id=6670302

• 使用较旧的版本的 JRE/JDK，而不是最新版本！

  ，即回到 JRE 6 / JDK 6 而不是 7。

试试

• {旧版 JRE (6)，旧版 Linux 内核} 或
• {较新版本的 JRE (7)，较新版本的 Linux 内核}

而不是像 {older, newer} 或 {newer, old} 那样将它们混合在一起。

Answer 3

一个应用轮询 10,000 个连接，每个连接使用的 CPU 非常少，但加起来可能占 CPU 时间的很大一部分。 所有优先级都是让其他工作先排队。

另一个连接较少但每个连接处理较多的应用也可能显示较高的百分比，但它应该显示较低的等待时间和较高的 CPU 占用率。

Answer 4

就像提到的链接问题的答案一样，常见问题是较旧的 JDK 错误。由于您现在使用的是更新版本，我认为这实际上可能是硬件瓶颈。

这是一个 glassfish 问题的链接，描述了他们讨论硬件（网络和服务器）成为问题根源的可能性。

https://www.java.net//forum/topic/glassfish/glassfish/glassfish-31-deadlock-epollarraywrapperepollwait-how-handle

另外，还有一个类似的问题，目前还没有答案： SelectorImpl is BLOCKED