为了进行测试,我们将使用以下简单程序:
public class Main {
public static void main(String[] args) {
new Thread(new Idle(), 'Idle').start();
new Thread(new Busy(), 'Busy').start();
}
}
class Idle implements Runnable {
@Override
public void run() {
try {
TimeUnit.HOURS.sleep(1);
} catch (InterruptedException e) {
}
}
}
class Busy implements Runnable {
@Override
public void run() {
while(true) {
'Foo'.matches('F.*');
}
}
}
如您所见,它启动了两个线程。 Idle
不消耗任何CPU(请记住,睡眠线程消耗内存,但不消耗CPU),而Busy
占用整个内核,因为正则表达式的解析和执行是一个令人惊讶的复杂过程。 让我们运行该程序,然后将其忽略。 我们如何快速发现Busy
是我们软件中有问题的部分? 首先,我们使用top来找出消耗大部分CPU的java
进程的进程ID( PID
)。 这很简单:
$ top -n1 | grep -m1 java
这将显示包含“ java
”语句的top
输出的第一行:
22614 tomek 20 0 1360m 734m 31m S 6 24.3 7:36.59 java
第一列是PID,让我们提取它。 不幸的是,事实证明top
使用ANSI转义码表示颜色 –看不见的字符破坏了grep
和cut
类的工具。 幸运的是,我找到了一个Perl脚本来删除这些字符 ,并最终能够提取用尽CPU的java
进程的PID:
$ top -n1 | grep -m1 java | perl -pe 's/\e\[?.*?[\@-~] ?//g' | cut -f1 -d' '
cut -f1 -d' '
调用只是将第一个值从以空格分隔的列中取出:
22614
现在,当我们遇到有问题的JVM PID时,我们可以使用top -H
查找有问题的Linux线程。 -H
选项显示与进程相对的所有线程的列表,PID列现在表示内部Linux线程ID:
$ top -n1 -H | grep -m1 java
$ top -n1 -H | grep -m1 java | perl -pe 's/\e\[?.*?[\@-~] ?//g' | cut -f1 -d' '
输出令人惊讶地相似,但是第一个值现在是线程ID:
25938 tomek 20 0 1360m 748m 31m S 2 24.8 0:15.15 java
25938
因此,我们有一个繁忙的JVM的进程ID和Linux线程ID(很可能来自该进程)消耗了我们的CPU。 这是最好的部分:如果查看jstack输出(在JDK中可用),则每个线程的名称旁边都会印有一些神秘的ID:
'Busy' prio=10 tid=0x7f3bf800 nid=0x6552 runnable [0x7f25c000]
java.lang.Thread.State: RUNNABLE
at java.util.regex.Pattern$Node.study(Pattern.java:3010)
没错, nid=0x645a
参数与top -H
打印的线程ID相同。 当然,不要太简单,在jstack
以十六进制打印时, top
使用十进制表示法。 再次有一个简单的解决方案, printf'%x' :
$ printf '%x' 25938
6552
让我们将我们现在拥有的所有内容包装到一个脚本中并合并结果:
#!/bin/bash
PID=$(top -n1 | grep -m1 java | perl -pe 's/\e\[?.*?[\@-~] ?//g' | cut -f1 -d' ')
NID=$(printf '%x' $(top -n1 -H | grep -m1 java | perl -pe 's/\e\[?.*?[\@-~] ?//g' | cut -f1 -d' '))
jstack $PID | grep -A500 $NID | grep -m1 '^$' -B 500
PID
持有java
PID, NID
持有线程ID,很可能来自该JVM。 最后一行只是转储给定PID的JVM堆栈跟踪,并过滤(使用grep
)具有相匹配的nid
的线程。 猜猜它有什么用:
$ ./profile.sh
'Busy' prio=10 tid=0x7f3bf800 nid=0x6552 runnable [0x7f25c000]
java.lang.Thread.State: RUNNABLE
at java.util.regex.Pattern$Node.study(Pattern.java:3010)
at java.util.regex.Pattern$Curly.study(Pattern.java:3854)
at java.util.regex.Pattern$CharProperty.study(Pattern.java:3355)
at java.util.regex.Pattern$Start.<init>(Pattern.java:3044)
at java.util.regex.Pattern.compile(Pattern.java:1480)
at java.util.regex.Pattern.<init>(Pattern.java:1133)
at java.util.regex.Pattern.compile(Pattern.java:823)
at java.util.regex.Pattern.matches(Pattern.java:928)
at java.lang.String.matches(String.java:2090)
at com.blogspot.nurkiewicz.Busy.run(Main.java:27)
at java.lang.Thread.run(Thread.java:662)
多次运行脚本(或使用watch
,请参见下文)将在不同位置捕获Busy
线程,但是几乎总是在正则表达式解析中进行–这是我们有问题的部分!
多线程
如果您的应用程序具有多个需要CPU的线程,则可以使用watch -n1 ./profile.sh
命令watch -n1 ./profile.sh
运行一次脚本并获取半实时堆栈转储,这很可能来自不同的线程。 使用以下程序进行测试:
new Thread(new Idle(), 'Idle').start();
new Thread(new Busy(), 'Busy-1').start();
new Thread(new Busy(), 'Busy-2').start();
您将看到Busy-1
或Busy-2
线程的堆栈跟踪(在Pattern
类中的不同位置),但是从不Idle
。
参考: 哪个Java线程消耗了我的CPU? 来自我们的JCG合作伙伴 Tomasz Nurkiewicz,来自Java和邻里博客。
翻译自: https://www.javacodegeeks.com/2012/08/which-java-thread-consumes-my-cpu.html