使用 Jstack 命令

先使用 Top 找出占用 CPU 最高的 Java 进程

企业微信截图_863eccb6-c834-4890-9fc6-3fa497c1ff28.png
通过 top 命令可以清晰的看到占用 CPU 的进程信息,占用最高的 Java 进程的 PID 是 5232

再通过 Top 命令找出占用 Cpu 最高的线程

上一个我们已经查到了占用 CPU 最高的进程信息以及它的 PID,接着我们就可以使用 top -Hp PID 命令从进程中找到占用 CPU 最高的线程是哪个
具体命令:

1
>top -Hp 5232

展示界面与上面差不多,但前面的 ID 是线程的 ID,我们记下占用 CPU 最高的线程 ID 号

使用 Jstack 命令导出线程快照

接着我们使用 Jstack PID将进程的线程栈导出来,命令如:

1
>jstack 5232 > thread_jstack.log

:::info
注意这里的 5232 是我们第一步中查询出来的进程 PID,而不是第二步中的线程 ID,后面的 thread_jstack.log 是导出的文件中,可以指定目录与其它名称
:::

查询线程栈日志

最后我们就可以查询占用 CPU 最高的线程的线程栈日志了。
首先把 top -Hp PID 命令中查询出来的占用 CPU 最高的线程栈 ID 转为十六进制数
然后使用这个十六进制数在 thread_jstack.log日志中搜索即可,会匹配到日志中 nid 这里的值。
日志中会详细的把线程名称、状态以及对应的代码打印出来,这样就能够知道是哪块的代码占用了大量 CPU,从而有针对性的排查问题了
image.png

使用 Arthas 工具

使用 Arthas 工具会比使用 Jstack 命令更加方便快捷,主要是使用 Thread命令,官网有详细的文档
Arthas
下面从官网文档中摘抄最常用的两个命令记录下

一键展示当前最忙的 N 个线程并打印堆栈

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
[arthas@27764]$ thread -n 3
"C2 CompilerThread1" [Internal] cpuUsage=95.87% deltaTime=257ms time=47762ms


"http-nio-8412-exec-7" Id=88 cpuUsage=59.46% deltaTime=159ms time=17460ms TIMED_WAITING
at java.net.SocketInputStream.socketRead0(Native Method)
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116)
at java.net.SocketInputStream.read(SocketInputStream.java:170)
at java.net.SocketInputStream.read(SocketInputStream.java:141)
at com.mysql.jdbc.util.ReadAheadInputStream.fill(ReadAheadInputStream.java:101)
at com.mysql.jdbc.util.ReadAheadInputStream.readFromUnderlyingStreamIfNecessary(ReadAheadInputStream.java:144)
at com.mysql.jdbc.util.ReadAheadInputStream.read(ReadAheadInputStream.java:174)
at com.mysql.jdbc.MysqlIO.readFully(MysqlIO.java:3011)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3472)
at com.mysql.jdbc.MysqlIO.reuseAndReadPacket(MysqlIO.java:3462)
at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:3905)
at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2530)
//省略详细堆栈日志


"C2 CompilerThread6" [Internal] cpuUsage=42.31% deltaTime=113ms time=53087ms


thread -b, 找出当前阻塞其他线程的线程

有时候我们发现应用卡住了, 通常是由于某个线程拿住了某个锁, 并且其他线程都在等待这把锁造成的。 为了排查这类问题, arthas 提供了thread -b, 一键找出那个罪魁祸首。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
$ thread -b
"http-bio-8080-exec-4" Id=27 TIMED_WAITING
at java.lang.Thread.sleep(Native Method)
at test.arthas.TestThreadBlocking.doGet(TestThreadBlocking.java:22)
- locked java.lang.Object@725be470 <---- but blocks 4 other threads!
at javax.servlet.http.HttpServlet.service(HttpServlet.java:624)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:731)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at test.filter.TestDurexFilter.doFilter(TestDurexFilter.java:46)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:505)
at com.taobao.tomcat.valves.ContextLoadFilterValve$FilterChainAdapter.doFilter(ContextLoadFilterValve.java:191)
at com.taobao.eagleeye.EagleEyeFilter.doFilter(EagleEyeFilter.java:81)
at com.taobao.tomcat.valves.ContextLoadFilterValve.invoke(ContextLoadFilterValve.java:150)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:429)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1085)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:625)
at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:318)
- locked org.apache.tomcat.util.net.SocketWrapper@7127ee12
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)

Number of locked synchronizers = 1
- java.util.concurrent.ThreadPoolExecutor$Worker@31a6493e

:::warning
注意:目前只支持找出 synchronized 关键字阻塞住的线程, 如果是java.util.concurrent.Lock, 目前还不支持。
:::