jstack实战排查线上CPU占用过高的问题
1、通过top命令查看占用CPU过高的进程,信息如下:
shell> top
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
30718 root 20 0 3033296 333488 14084 S 96.7 17.7 8:32.75 java
3451 root 20 0 156164 7016 4184 S 1.7 0.4 0:31.61 sshd
32517 root 20 0 155028 5868 4184 S 1.0 0.3 0:07.26 sshd
9 root 20 0 0 0 0 S 0.7 0.0 231:10.83 rcu_sched
3537 root 20 0 162652 2984 1592 S 0.7 0.2 0:10.66 top
15625 root 20 0 162020 2276 1596 R 0.7 0.1 0:00.36 top
发现占用CPU最高的进程PID是:30718,此时我们知道这个java应用占用CPU最高,但不知道是应用中哪个地方的代码造成的。一个进程中包含若干线程,最想知道的就这个进程的资源占用详情了。此时仍使用top命令继续查看,格式:top -p pid -H。
shell> top -p 30718 -H
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
3427 root 20 0 3033296 335140 14088 R 92.7 17.8 16:49.21 java
30729 root 20 0 3033296 335140 14088 S 0.3 17.8 0:01.24 java
31081 root 20 0 3033296 335140 14088 S 0.3 17.8 0:00.28 java
30718 root 20 0 3033296 335140 14088 S 0.0 17.8 0:00.00 java
30719 root 20 0 3033296 335140 14088 S 0.0 17.8 0:19.10 java
30720 root 20 0 3033296 335140 14088 S 0.0 17.8 0:00.34 java
30721 root 20 0 3033296 335140 14088 S 0.0 17.8 0:00.33 java
30722 root 20 0 3033296 335140 14088 S 0.0 17.8 0:00.41 java
30723 root 20 0 3033296 335140 14088 S 0.0 17.8 0:00.00 java
30724 root 20 0 3033296 335140 14088 S 0.0 17.8 0:00.01 java
30725 root 20 0 3033296 335140 14088 S 0.0 17.8 0:00.00 java
30726 root 20 0 3033296 335140 14088 S 0.0 17.8 0:22.39 java
发现PID=3427的线程占用CPU最高,找到了线程号,就要想办法知道java的线程名称了。这时我们就需要用到jstack命令了,jstack pid,可以连接一个正在运行的进程,试一下看看。
shell> jstack 30718
2020-03-15 15:01:48
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.172-b11 mixed mode):
"http-nio-8080-Acceptor" #45 daemon prio=5 os_prio=0 tid=0x00007fc72c1c3000 nid=0x79b4 runnable [0x00007fc6fc2c2000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.ServerSocketChannelImpl.accept0(Native Method)
at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:422)
at sun.nio.ch.ServerSocketChannelImpl.accept(ServerSocketChannelImpl.java:250)
- locked <0x00000000ff2ffca0> (a java.lang.Object)
at org.apache.tomcat.util.net.NioEndpoint.serverSocketAccept(NioEndpoint.java:461)
at org.apache.tomcat.util.net.NioEndpoint.serverSocketAccept(NioEndpoint.java:73)
at org.apache.tomcat.util.net.Acceptor.run(Acceptor.java:95)
at java.lang.Thread.run(Thread.java:748)
"sendText" #50 daemon prio=5 os_prio=0 tid=0x00007fc6e41b4000 nid=0xd63 runnable [0x00007fc6d7dfe000]
java.lang.Thread.State: RUNNABLE
at cn.fetosoft.rooster.demo.job.JobLiveMonitor$SendTextTask.run(JobLiveMonitor.java:63)
at java.lang.Thread.run(Thread.java:748)
"http-nio-8080-exec-9" #42 daemon prio=5 os_prio=0 tid=0x00007fc72cf06000 nid=0x79b0 waiting on condition [0x00007fc6fc5c5000]
java.lang.Thread.State: WAITING (parking)
at sun.misc.Unsafe.park(Native Method)
- parking to wait for <0x00000000ff3272b0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
.....
dump出了所有的java线程,此处只显示了部分线程信息。还可以通过命令将线程信息dump到文件中,从中可以看到线程的详细信息,其中nid就是线程的ID,是16进制的,把PID=3427转换成16进制。
shell> printf "%x\n" 3427
d63
使用grep过滤一下关键字为d63的线程
shell> jstack 30718 | grep d63
"sendText" #50 daemon prio=5 os_prio=0 tid=0x00007fc6e41b4000 nid=0xd63 runnable [0x00007fc6d7dfe000]
将线程信息dump到文件中
shell> jstack 30718 >> dump.txt
这样就找到了这个线程,根据线程名称“sendText”可以直接定位到java源码:
@OnOpen
public void openSession(Session session, @PathParam("jobCode") String code){
this.session = session;
jobCode = code;
isConn = true;
Thread thread = new Thread(new SendTextTask(session), "sendText");
thread.start();
}
class SendTextTask implements Runnable{
private Session tsession;
public SendTextTask(Session session){
this.tsession = session;
}
@Override
public void run() {
logger.info("Start sending messages >>>>>>>>>>>>>");
try{
while (isConn) {
String data = QUEUE.poll();
if(StringUtils.isNotBlank(data)) {
tsession.getBasicRemote().sendText(data);
}
}
}catch(IOException e){
logger.error("sendText", e);
}
if(!isConn){
logger.info("Stop sending messages >>>>>>>>>>>>>");
}
}
}
从源码中可以看到,这里使用了一个线程从队列中获取信息,使用的while循环,会导致cpu一直空转,造成占用率很高,到此就查到问题点了。
从刚才的实战中也可以看到,创建线程的时候自定义名称很重要,对排查问题是非常的有用。