哪个 Java 线程占用了 CPU？

假设你的 Java 程序占用了100% 的 CPU。它有50根线。你得找出哪条线是有罪的。我还没找到有用的工具。目前，我使用以下非常耗时的例行程序:

  1. 运行 jstack <pid>，其中 pid 是 Java 进程的进程 id。找到它的简单方法是运行 JDK-jps中包含的另一个实用程序。最好将 jstack 的输出重定向到一个文件。
  2. 搜索“可运行”线程。跳过那些在套接字上等待的线程(由于某种原因它们仍然被标记为可运行)。
  3. 重复步骤1和步骤2几次，看看是否能找到一个模式。

或者，您可以附加到 Eclipse 中的 Java 进程，并尝试一个接一个地挂起线程，直到遇到占用 CPU 的线程。在单 CPU 机器上，您可能需要首先降低 Java 进程的优先级，以便能够移动。即便如此，由于超时，Eclipse 通常也不能附加到正在运行的进程。

我希望 Sun 的 visualvm工具可以做到这一点。

有人知道更好的办法吗？

76567 次浏览
小开

这是一种古怪的方式，但似乎你可以在调试器中启动应用程序，然后暂停 所有线程，通过代码查找哪一个没有阻塞锁或在某种循环中的 I/O 调用。还是你已经试过了？

小开

只需运行 JVisualVM，连接到您的应用程序并使用线程视图。持续活跃的那个最有可能是你的罪魁祸首。

小开

如果在 Windows 下运行，请尝试 进程资源管理器。打开进程的属性对话框，然后选择 Threads 选项卡。

小开
最佳答案

尝试查看 可视化虚拟机的热线程检测器插件——它使用 ThreadMXBean API 获取多个 CPU 消耗示例以查找最活跃的线程。它是基于 与 Bruce Chapman 等效的命令行的，这也可能是有用的。

小开

进行一次线程转储。等待10秒钟。进行另一次线程转储。再重复一次。 检查线程转储并查看哪些线程被卡在相同的位置，或者处理相同的请求。 这是一种手工操作的方法，但通常很有用。

小开

您可以考虑的一个选项是从应用程序内部查询线程以获得答案。通过 ThreadMXBean，您可以从 Java 应用程序中查询线程的 CPU 使用情况，并查询有问题的线程的堆栈跟踪。

ThreadMXBean 选项允许在实时应用程序中构建此类监视。它的影响可以忽略不计，而且有一个明显的优势，那就是你可以让它做你想做的事情。

小开

如果你怀疑 VisualVM 是一个很好的工具，试试看(因为它确实是这样做的)找出线程只能帮助你大致了解为什么它会消耗这么多的 CPU。

然而，如果这是显而易见的，我会直接使用分析器来找出为什么你正在消耗这么多的 CPU。

小开

看一下 JConsole 的 热门话题插件。

小开

Jvmtop 可以显示最大的消耗线程:

    TID NAME                                 STATE     CPU    TOTALCPU
25 http-8080-Processor13                RUNNABLE  4.55%     1.60%
128022 RMI TCP Connection(18)-10.101.       RUNNABLE  1.82%     0.02%
36578 http-8080-Processor164               RUNNABLE  0.91%     2.35%
128026 JMX server connection timeout   TIMED_WAITING  0.00%     0.00%
小开

确定哪个 JavaThread 在生产服务器中消耗了最多的 CPU。

大多数(如果不是所有)生产系统做任何重要的事情将使用1个以上的 java 线程。当某些事情变得疯狂，你的 CPU 使用率达到100% 时，很难确定是哪个线程导致了这种情况。至少我是这么想的。直到一个比我聪明的人告诉我怎么做。在这里，我将告诉你如何做到这一点，你也可以惊讶你的家人和朋友与你的极客技能。

测试申请

为了测试这个，我们需要一个测试应用程序。所以我给你一个。它由三个类别组成:

  • 执行 CPU 密集型操作的 HeavyThread类(计算 MD5哈希)
  • 一个 LightThread类，做一些不那么 CPU 密集的事情(计数和睡眠)。
  • 一个 StartThreads类启动1个 CPU 密集型和几个轻线程。

下面是这些类的代码:

import java.security.MessageDigest;
import java.security.NoSuchAlgorithmException;
import java.util.UUID;


/**
* thread that does some heavy lifting
*
* @author srasul
*
*/
public class HeavyThread implements Runnable {


private long length;


public HeavyThread(long length) {
this.length = length;
new Thread(this).start();
}


@Override
public void run() {
while (true) {
String data = "";


// make some stuff up
for (int i = 0; i < length; i++) {
data += UUID.randomUUID().toString();
}


MessageDigest digest;
try {
digest = MessageDigest.getInstance("MD5");
} catch (NoSuchAlgorithmException e) {
throw new RuntimeException(e);
}


// hash the data
digest.update(data.getBytes());
}
}
}




import java.util.Random;


/**
* thread that does little work. just count & sleep
*
* @author srasul
*
*/
public class LightThread implements Runnable {


public LightThread() {
new Thread(this).start();
}


@Override
public void run() {
Long l = 0l;
while(true) {
l++;
try {
Thread.sleep(new Random().nextInt(10));
} catch (InterruptedException e) {
e.printStackTrace();
}
if(l == Long.MAX_VALUE) {
l = 0l;
}
}
}
}




/**
* start it all
*
* @author srasul
*
*/
public class StartThreads {


public static void main(String[] args) {
// lets start 1 heavy ...
new HeavyThread(1000);


// ... and 3 light threads
new LightThread();
new LightThread();
new LightThread();
}
}

假设您从未见过这段代码，并且您有一个失控 Java 进程的 PID，该进程正在运行这些类并且正在消耗100% 的 CPU。

首先让我们开始 StartThreads课程。

$ ls
HeavyThread.java  LightThread.java  StartThreads.java
$ javac *
$ java StartThreads &

在这个阶段，一个运行的 Java 进程需要占用100个 CPU: screenshot of top output

在最上面按 Shift-H 打开 Threads。最上面的手册页说:

   -H : Threads toggle
Starts top with the last remembered 'H' state reversed.  When
this  toggle is On, all individual threads will be displayed.
Otherwise, top displays a  summation  of  all  threads  in  a
process.

而现在在我的顶部与线显示打开我看到: top screenshot with threads displayed

我有一个具有 PID 28294的 java进程。让我们使用 jstack获取这个进程的堆栈转储:

$ jstack 28924
2010-11-18 13:05:41
Full thread dump Java HotSpot(TM) 64-Bit Server VM (17.0-b16 mixed mode):


"Attach Listener" daemon prio=10 tid=0x0000000040ecb000 nid=0x7150 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE


"DestroyJavaVM" prio=10 tid=0x00007f9a98027800 nid=0x70fd waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE


"Thread-3" prio=10 tid=0x00007f9a98025800 nid=0x710d waiting on condition [0x00007f9a9d543000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at LightThread.run(LightThread.java:21)
at java.lang.Thread.run(Thread.java:619)


"Thread-2" prio=10 tid=0x00007f9a98023800 nid=0x710c waiting on condition [0x00007f9a9d644000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at LightThread.run(LightThread.java:21)
at java.lang.Thread.run(Thread.java:619)


"Thread-1" prio=10 tid=0x00007f9a98021800 nid=0x710b waiting on condition [0x00007f9a9d745000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at LightThread.run(LightThread.java:21)
at java.lang.Thread.run(Thread.java:619)


"Thread-0" prio=10 tid=0x00007f9a98020000 nid=0x710a runnable [0x00007f9a9d846000]
java.lang.Thread.State: RUNNABLE
at sun.security.provider.DigestBase.engineReset(DigestBase.java:139)
at sun.security.provider.DigestBase.engineUpdate(DigestBase.java:104)
at java.security.MessageDigest$Delegate.engineUpdate(MessageDigest.java:538)
at java.security.MessageDigest.update(MessageDigest.java:293)
at sun.security.provider.SecureRandom.engineNextBytes(SecureRandom.java:197)
- locked <0x00007f9aa457e400> (a sun.security.provider.SecureRandom)
at sun.security.provider.NativePRNG$RandomIO.implNextBytes(NativePRNG.java:257)
- locked <0x00007f9aa457e708> (a java.lang.Object)
at sun.security.provider.NativePRNG$RandomIO.access$200(NativePRNG.java:108)
at sun.security.provider.NativePRNG.engineNextBytes(NativePRNG.java:97)
at java.security.SecureRandom.nextBytes(SecureRandom.java:433)
- locked <0x00007f9aa4582fc8> (a java.security.SecureRandom)
at java.util.UUID.randomUUID(UUID.java:162)
at HeavyThread.run(HeavyThread.java:27)
at java.lang.Thread.run(Thread.java:619)


"Low Memory Detector" daemon prio=10 tid=0x00007f9a98006800 nid=0x7108 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE


"CompilerThread1" daemon prio=10 tid=0x00007f9a98004000 nid=0x7107 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE


"CompilerThread0" daemon prio=10 tid=0x00007f9a98001000 nid=0x7106 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE


"Signal Dispatcher" daemon prio=10 tid=0x0000000040de4000 nid=0x7105 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE


"Finalizer" daemon prio=10 tid=0x0000000040dc4800 nid=0x7104 in Object.wait() [0x00007f9a97ffe000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00007f9aa45506b0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
- locked <0x00007f9aa45506b0> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)


"Reference Handler" daemon prio=10 tid=0x0000000040dbd000 nid=0x7103 in Object.wait() [0x00007f9a9de92000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00007f9aa4550318> (a java.lang.ref.Reference$Lock)
at java.lang.Object.wait(Object.java:485)
at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)
- locked <0x00007f9aa4550318> (a java.lang.ref.Reference$Lock)


"VM Thread" prio=10 tid=0x0000000040db8800 nid=0x7102 runnable


"GC task thread#0 (ParallelGC)" prio=10 tid=0x0000000040d6e800 nid=0x70fe runnable


"GC task thread#1 (ParallelGC)" prio=10 tid=0x0000000040d70800 nid=0x70ff runnable


"GC task thread#2 (ParallelGC)" prio=10 tid=0x0000000040d72000 nid=0x7100 runnable


"GC task thread#3 (ParallelGC)" prio=10 tid=0x0000000040d74000 nid=0x7101 runnable


"VM Periodic Task Thread" prio=10 tid=0x00007f9a98011800 nid=0x7109 waiting on condition


JNI global references: 910

从我的顶部，我看到的 PID 的顶部线程是 28938。十六进制的 28938是 0x710A。注意，在堆栈转储中，每个线程都有一个以十六进制显示的 nid。正好 0x710A是线程的 id:

"Thread-0" prio=10 tid=0x00007f9a98020000 nid=0x710a runnable [0x00007f9a9d846000]
java.lang.Thread.State: RUNNABLE
at sun.security.provider.DigestBase.engineReset(DigestBase.java:139)
at sun.security.provider.DigestBase.engineUpdate(DigestBase.java:104)
at java.security.MessageDigest$Delegate.engineUpdate(MessageDigest.java:538)
at java.security.MessageDigest.update(MessageDigest.java:293)
at sun.security.provider.SecureRandom.engineNextBytes(SecureRandom.java:197)
- locked <0x00007f9aa457e400> (a sun.security.provider.SecureRandom)
at sun.security.provider.NativePRNG$RandomIO.implNextBytes(NativePRNG.java:257)
- locked <0x00007f9aa457e708> (a java.lang.Object)
at sun.security.provider.NativePRNG$RandomIO.access$200(NativePRNG.java:108)
at sun.security.provider.NativePRNG.engineNextBytes(NativePRNG.java:97)
at java.security.SecureRandom.nextBytes(SecureRandom.java:433)
- locked <0x00007f9aa4582fc8> (a java.security.SecureRandom)
at java.util.UUID.randomUUID(UUID.java:162)
at HeavyThread.run(HeavyThread.java:27)
at java.lang.Thread.run(Thread.java:619)

因此，您可以确认运行 HeavyThread类的线程正在消耗大部分 CPU。

在读取世界的情况下，可能是一堆线程占用一部分 CPU，这些线程放在一起将导致 Java 进程使用100% 的 CPU。

摘要

  • 跑上去
  • 按 Shift-H 启用线程视图
  • 获取具有最高 CPU 的线程的 PID
  • 将 PID 转换为 HEX
  • 获取 Java 进程的堆栈转储
  • 寻找线程与匹配的十六进制 PID。
小开

我建议大家看看阿里巴巴开源的 阿尔塞斯工具。

它包含一组有用的命令，可以帮助您调试生产代码:

  • Dashboard : Java 进程概述
  • SC : 由您的 JVM 加载的搜索类
  • Jad : 将类反编译为源代码
  • Watch : 查看方法调用输入和结果
  • Trace : 查找方法调用的瓶颈
  • Monitor : 查看方法调用统计信息
  • Stack : 查看方法的调用堆栈
  • Tt : 方法调用的时间隧道

仪表板的例子: dashboard

小开

使用 ps -eL或 top -H -p <pid>，或者如果您需要实时查看和监视，运行 top (然后 shift H) ，以获得与 java 进程相关联的轻量级进程(LWP aka 线程)。

root@xxx:/# ps -eL
PID LWP TTY TIME CMD
1 1 ? 00:00:00 java
1 7 ? 00:00:01 java
1 8 ? 00:07:52 java
1 9 ? 00:07:52 java
1 10 ? 00:07:51 java
1 11 ? 00:07:52 java
1 12 ? 00:07:52 java
1 13 ? 00:07:51 java
1 14 ? 00:07:51 java
1 15 ? 00:07:53 java
…
1 164 ? 00:00:02 java
1 166 ? 00:00:02 java
1 169 ? 00:00:02 java

注意: LWP = 轻量级进程; 在 Linux 中，一个线程与一个进程相关联，因此可以在内核中管理它; LWP 与父进程共享文件和其他资源。 现在让我们看看花费大量时间的线程

 1 8 ? 00:07:52 java
1 9 ? 00:07:52 java
1 10 ? 00:07:51 java
1 11 ? 00:07:52 java
1 12 ? 00:07:52 java
1 13 ? 00:07:51 java
1 14 ? 00:07:51 java
1 15 ? 00:07:53 java

Jstack 是一个用于打印 Java Stack 的 JDK 实用程序; 它打印表单的线程。

熟悉其他很酷的 JDK 工具(Jcmd jstat jhat jmap jstack等ー https://docs.oracle.com/javase/8/docs/technotes/tools/unix/)

jstack -l <process id>

堆栈跟踪中的 nid、 Nativethread id 是在 linux (https://gist.github.com/rednaxelafx/843622)中连接到 LWT 的线程 id

“GC task thread#0 (ParallelGC)” os_prio=0 tid=0x00007fc21801f000 nid=0x8 runnable

Nid 是在十六进制中给出的; 因此我们转换线程 id 花费的时间最多 十六进制中的8,9,10,11,12,13,14,15 = 8,9，A，B，C，D，E，F。

(请注意，这个特定的堆栈是从一个 Docker 容器中的 Java 获取的，如果为1，则有一个方便的进程) 让我们看看这个 ID 的线索. 。

“GC task thread#0 (ParallelGC)” os_prio=0 tid=0x00007fc21801f000 nid=0x8 runnable
“GC task thread#1 (ParallelGC)” os_prio=0 tid=0x00007fc218020800 nid=0x9 runnable
“GC task thread#2 (ParallelGC)” os_prio=0 tid=0x00007fc218022800 nid=0xa runnable
“GC task thread#3 (ParallelGC)” os_prio=0 tid=0x00007fc218024000 nid=0xb runnable
“GC task thread#4 (ParallelGC)” os_prio=0 tid=0x00007fc218026000 nid=0xc runnable
“GC task thread#5 (ParallelGC)” os_prio=0 tid=0x00007fc218027800 nid=0xd runnable
“GC task thread#6 (ParallelGC)” os_prio=0 tid=0x00007fc218029800 nid=0xe runnable
“GC task thread#7 (ParallelGC)” os_prio=0 tid=0x00007fc21802b000 nid=0xf runnable

所有与 GC 相关的线程; 难怪它占用了大量的 CPU 时间; 但是 GC 在这里是一个问题。

使用 jstat (而不是 jstack!)实用工具对 GC 进行快速检查。

jstat -gcutil <pid>


提交答案