java - 为什么 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)

这似乎是基于一个繁忙的民意调查，这对我来说听起来很不对。

当我看到这么高的数字时，我应该担心吗？这是什么原因造成的？它是我需要优化的东西，还是更类似于 sleep 或空闲程序？如果它更像是一个 sleep 例程，它是否以某种方式被安排为低于其他 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 的文档:

Thread state for a runnable thread. A thread in the runnable state is executing in the Java virtual machine but it may be waiting for other resources from the operating system such as processor.

这正是正在发生的事情。实际上，线程在操作系统 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() 调用中。

pidstat线程

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

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

使用 ps 轮询线程状态

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

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

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