找出cpu飙高的线程---通过jstack分析线程状态,定位问题代码

19 篇文章 0 订阅

jstack是java虚拟机自带的一种堆栈跟踪工具,通过它可以定位出一些代码运行中出现的问题。

找出导致cpu飙高的代码位置

使用top命令查看cpu当前状态

top - 09:41:26 up 77 days, 23:17,  4 users,  load average: 0.17, 0.12, 0.07
Tasks: 212 total,   1 running, 211 sleeping,   0 stopped,   0 zombie
%Cpu(s):  0.1 us,  0.2 sy,  0.0 ni, 99.7 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
KiB Mem : 32649012 total,  2005940 free, 16002368 used, 14640704 buff/cache
KiB Swap: 16449532 total, 16307432 free,   142100 used. 14596072 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                                
30207 root      20   0 12.548g 1.097g  13792 S   0.7  3.5   1:18.67 java                                                                                                   
31017 root      20   0 12.596g 1.891g  13600 S   0.7  6.1   2:17.35 java                                                                                                   
   20 root      20   0       0      0      0 S   0.3  0.0  16:06.52 rcuos/4                                                                                                
 4344 root      20   0       0      0      0 S   0.3  0.0   0:00.87 kworker/1:0                                                                                            
 5585 root      20   0 11.727g 460612  13688 S   0.3  1.4   0:15.43 java                                                                                                   
29987 root      20   0 12.550g 734016  13680 S   0.3  2.2   1:05.43 java                                                                                                   
30430 root      20   0 12.744g 1.525g  13760 S   0.3  4.9   1:49.44 java                                                                                                   
31493 root      20   0 12.569g 1.519g  16332 S   0.3  4.9   2:01.62 java        

从以上cpu状态来看,未出现异常
然后,执行下面的代码

public void doLoop(){
	new Thread(()->{
		int i = 1;
		while(i > 0){
			System.out.println("死循环中。。。");
		}
	}) .start();
}

再查看cpu状态

top - 10:20:11 up 77 days, 23:55,  4 users,  load average: 0.56, 0.85, 0.88
Tasks: 211 total,   1 running, 210 sleeping,   0 stopped,   0 zombie
%Cpu(s):  6.1 us, 16.3 sy,  0.0 ni, 77.5 id,  0.0 wa,  0.0 hi,  0.1 si,  0.0 st
KiB Mem : 32649012 total,   242660 free, 15986512 used, 16419840 buff/cache
KiB Swap: 16449532 total, 16028384 free,   421148 used. 14727860 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND                                                                                                                                                                    
 6993 root      20   0 11.729g 436964  13676 S 100.0  1.3   0:39.36 java                                                                                                                                                                       
 5448 root      20   0  143664   5492   3944 S  13.9  0.0   2:08.24 sshd                                                                                                                                                                       
 6184 root      20   0  107932    624    532 S   8.3  0.0   1:12.85 tail                                                                                                                                                                       
 6279 root      20   0       0      0      0 S   2.6  0.0   0:17.30 kworker/0:0                                                                                                                                                                
21202 root      20   0       0      0      0 S   2.6  0.0   0:29.92 kworker/5:2                                                                                                                                                                
30810 root      20   0       0      0      0 S   2.3  0.0   0:22.66 kworker/4:3                                                                                                                                                                
29924 root      20   0       0      0      0 S   2.0  0.0   0:21.74 kworker/3:1                                                                                                                                                                
29975 root      20   0       0      0      0 S   1.7  0.0   0:18.18 kworker/2:1    

可以看到有一个java的进程cpu占用超过了100%,这就是刚才制造的死循环导致的。
使用top -Hp 6993查看进程下每个线程的状态,进一步定位问题

top - 10:20:26 up 77 days, 23:56,  4 users,  load average: 0.66, 0.85, 0.88
Threads:  35 total,   1 running,  34 sleeping,   0 stopped,   0 zombie
%Cpu(s):  5.9 us, 15.1 sy,  0.0 ni, 78.8 id,  0.0 wa,  0.0 hi,  0.1 si,  0.0 st
KiB Mem : 32649012 total,   248888 free, 15987984 used, 16412140 buff/cache
KiB Swap: 16449532 total, 16026224 free,   423308 used. 14728536 avail Mem 

  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND                                                                                                                                                                     
 7042 root      20   0 11.729g 437536  13676 R 99.9  1.3   0:36.36 java                                                                                                                                                                        
 6993 root      20   0 11.729g 437536  13676 S  0.0  1.3   0:00.00 java                                                                                                                                                                        
 6994 root      20   0 11.729g 437536  13676 S  0.0  1.3   0:03.16 java                                                                                                                                                                        
 6995 root      20   0 11.729g 437536  13676 S  0.0  1.3   0:00.07 java                                                                                                                                                                        
 6996 root      20   0 11.729g 437536  13676 S  0.0  1.3   0:00.07 java                                                                                                                                                                        
 6997 root      20   0 11.729g 437536  13676 S  0.0  1.3   0:00.07 java                                                                                                                                                                        
 6998 root      20   0 11.729g 437536  13676 S  0.0  1.3   0:00.07 java                                                                                                                                                                        
 6999 root      20   0 11.729g 437536  13676 S  0.0  1.3   0:00.08 java  

可以看到7042线程占用了99.9%的cpu
获取7042的16进制表示结果:printf "%x" 7042,得到1b82
使用jstack将线程信息下载到本地

jstack 7042> 7042.txt
sz 7042.txt

然后,使用jstack将线程状态信息导出
通过刚取到的线程id的十六进制结果,找到对应的调用栈。可以定位到出现异常的位置,应该是在CpuController.java:28

"Thread-4" #33 daemon prio=5 os_prio=0 tid=0x00007fa4780da000 nid=0x1b82 runnable [0x00007fa4c31c9000]
   java.lang.Thread.State: RUNNABLE
	at java.io.FileOutputStream.writeBytes(Native Method)
	at java.io.FileOutputStream.write(FileOutputStream.java:326)
	at java.io.BufferedOutputStream.flushBuffer(BufferedOutputStream.java:82)
	at java.io.BufferedOutputStream.flush(BufferedOutputStream.java:140)
	- locked <0x00000005cdc3afa8> (a java.io.BufferedOutputStream)
	at java.io.PrintStream.write(PrintStream.java:482)
	- locked <0x00000005cdc3af88> (a java.io.PrintStream)
	at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
	at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
	at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104)
	- locked <0x00000005cdc3b0c8> (a java.io.OutputStreamWriter)
	at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185)
	at java.io.PrintStream.newLine(PrintStream.java:546)
	- locked <0x00000005cdc3af88> (a java.io.PrintStream)
	at java.io.PrintStream.println(PrintStream.java:807)
	- locked <0x00000005cdc3af88> (a java.io.PrintStream)
	at com.yuxin.jstack.demo.CpuController.lambda$doLoop$0(CpuController.java:28)
	at com.yuxin.jstack.demo.CpuController$$Lambda$335/1200917794.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)

找出死锁代码位置

执行以下代码

	public void doDeadlock(){
		new Thread(()->{
			synchronized(lock1) {
				try {Thread.sleep(1000);}catch(Exception e) {}
				synchronized(lock2) {
					System.out.println("线程1结束");
				}
			}
		}) .start();
		new Thread(()->{
			synchronized(lock2) {
				try {Thread.sleep(1000);}catch(Exception e) {}
				synchronized(lock1) {
					System.out.println("线程2结束");
				}
			}
		}) .start();
	}

使用jstack导出线程信息
可以看到有两个线程处于BLOCKED 状态

"Thread-5" #34 daemon prio=5 os_prio=0 tid=0x00007f234c42c800 nid=0x1cce waiting for monitor entry [0x00007f23964aa000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at com.yuxin.jstack.demo.CpuController.lambda$doDeadlock$2(CpuController.java:46)
	- waiting to lock <0x00000005cebda938> (a java.lang.Object)
	- locked <0x00000005cebda948> (a java.lang.Object)
	at com.yuxin.jstack.demo.CpuController$$Lambda$336/1378440605.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)

"Thread-4" #33 daemon prio=5 os_prio=0 tid=0x00007f234c42b800 nid=0x1ccd waiting for monitor entry [0x00007f23973cb000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at com.yuxin.jstack.demo.CpuController.lambda$doDeadlock$1(CpuController.java:38)
	- waiting to lock <0x00000005cebda948> (a java.lang.Object)
	- locked <0x00000005cebda938> (a java.lang.Object)
	at com.yuxin.jstack.demo.CpuController$$Lambda$335/1522210909.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)

信息的最后一部分,报出死锁问题



Found one Java-level deadlock:
=============================
"Thread-5":
  waiting to lock monitor 0x00007f23696236c8 (object 0x00000005cebda938, a java.lang.Object),
  which is held by "Thread-4"
"Thread-4":
  waiting to lock monitor 0x00007f2369621e08 (object 0x00000005cebda948, a java.lang.Object),
  which is held by "Thread-5"

Java stack information for the threads listed above:
===================================================
"Thread-5":
	at com.yuxin.jstack.demo.CpuController.lambda$doDeadlock$2(CpuController.java:46)
	- waiting to lock <0x00000005cebda938> (a java.lang.Object)
	- locked <0x00000005cebda948> (a java.lang.Object)
	at com.yuxin.jstack.demo.CpuController$$Lambda$336/1378440605.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)
"Thread-4":
	at com.yuxin.jstack.demo.CpuController.lambda$doDeadlock$1(CpuController.java:38)
	- waiting to lock <0x00000005cebda948> (a java.lang.Object)
	- locked <0x00000005cebda938> (a java.lang.Object)
	at com.yuxin.jstack.demo.CpuController$$Lambda$335/1522210909.run(Unknown Source)
	at java.lang.Thread.run(Thread.java:748)

Found 1 deadlock.

综上可以找到在代码CpuController.java:38和CpuController.java:46的调用出现死锁问题

以上,即为通过jstack定位死循环、死锁的方式

  • 2
    点赞
  • 3
    收藏
    觉得还不错? 一键收藏
  • 0
    评论
评论
添加红包

请填写红包祝福语或标题

红包个数最小为10个

红包金额最低5元

当前余额3.43前往充值 >
需支付:10.00
成就一亿技术人!
领取后你会自动成为博主和红包主的粉丝 规则
hope_wisdom
发出的红包
实付
使用余额支付
点击重新获取
扫码支付
钱包余额 0

抵扣说明:

1.余额是钱包充值的虚拟货币,按照1:1的比例进行支付金额的抵扣。
2.余额无法直接购买下载,可以购买VIP、付费专栏及课程。

余额充值