jstack配合top命令分析CPU飆高、程序死鎖問(wèn)題
jstack：Java堆棧跟蹤工具
jstack（Stack Trace for Java)命令用于生成虛擬機(jī)當(dāng)前時(shí)刻的線(xiàn)程快照（一般稱(chēng)為threaddump或者javacore文件）。線(xiàn)程快照就是當(dāng)前虛擬機(jī)內(nèi)每一條線(xiàn)程正在執(zhí)行的方法堆棧的集合，生成線(xiàn)程快照的主要目的是定位線(xiàn)程出現(xiàn)長(zhǎng)時(shí)間停頓的原因，如線(xiàn)程間死鎖、死循環(huán)、請(qǐng)求外部資源導(dǎo)致的長(zhǎng)時(shí)間等待等都是導(dǎo)致線(xiàn)程長(zhǎng)時(shí)間停頓的常見(jiàn)原因。線(xiàn)程出現(xiàn)停頓的時(shí)候通過(guò)jstack來(lái)查看各個(gè)線(xiàn)程的調(diào)用堆棧，就可以知道沒(méi)有響應(yīng)的線(xiàn)程到底在后臺(tái)做什么事情，或者等待什么資源。jstack的官方文檔地址為：https://docs.oracle.com/javase/8/docs/technotes/tools/unix/jstack.html。
jstack命令格式：jstack [option] vmid
jstack的主要option選項(xiàng)如下：
- -F：當(dāng)正常輸出的請(qǐng)求不被響應(yīng)時(shí)，強(qiáng)制輸出線(xiàn)程堆棧。
- -l：除堆棧外，顯示關(guān)于鎖的附加信息。
- -m：除打印java線(xiàn)程堆棧外，還會(huì)輸出native方法線(xiàn)程堆棧。
Java線(xiàn)程狀態(tài)轉(zhuǎn)化
官網(wǎng)線(xiàn)程狀態(tài)介紹：https://docs.oracle.com/javase/8/docs/technotes/guides/troubleshoot/tooldescr034.html，如下所示
- NEW：創(chuàng)建了線(xiàn)程但是還沒(méi)有調(diào)用start方法
- RUNABLE：線(xiàn)程正在JVM中執(zhí)行，有可能在等待CPU時(shí)間片輪轉(zhuǎn)
- TIMED_WAITING：線(xiàn)程等待指定的時(shí)間，一般則是處于sleep方法，wait方法，join等操作，正在等待時(shí)間
- WAITING：線(xiàn)程無(wú)限期的等待，一般是wait，join等方法沒(méi)有指定時(shí)間
- BLOCKED：線(xiàn)程等待獲取監(jiān)視器鎖而處于阻塞狀態(tài)
- TERMINATED：線(xiàn)程退出
關(guān)于線(xiàn)程各個(gè)狀態(tài)的轉(zhuǎn)化，從網(wǎng)上找了一張圖，畫(huà)的挺詳細(xì)的。
jstack配合top命令分析CPU飆高問(wèn)題
一般分析CPU飆高的步驟如下：
- 先用top 命令在機(jī)器上分析出當(dāng)前占用cpu的進(jìn)程，
- 通過(guò)top -H -p <pid> 查看進(jìn)程內(nèi)各個(gè)線(xiàn)程的資源占用
- top -H -p <pid>命令輸出的是這些線(xiàn)程的pid，然后通過(guò)jstack命令導(dǎo)出線(xiàn)程dump信息。把線(xiàn)程pid（對(duì)應(yīng)線(xiàn)程dump內(nèi)容中的nid，nid是16進(jìn)制表示的）轉(zhuǎn)換成十六進(jìn)制，然后在線(xiàn)程dump文件中搜索即可找到對(duì)應(yīng)的線(xiàn)程。
創(chuàng)建一個(gè)springboot工程，controller程序如下，然后通過(guò)package -Dmaven.test.skip=true打包之后放到Linux上運(yùn)行：
package com.wkp.jvm.chapter2;
import java.util.List;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RestController;
@RestController
public class CpuController {
Logger log=LoggerFactory.getLogger(CpuController.class);
/**
* 演示死循環(huán)
*/
@RequestMapping("/loop")
public List<Long> loop(){
log.info("演示死循環(huán)============");
while(true){
}
}
private Object lock1 = new Object();
private Object lock2 = new Object();
/**
* 演示死鎖
*/
@RequestMapping("/deadlock")
public String deadlock() {
log.info("演示死鎖============");
new Thread(()->{
synchronized(lock1) {
try {Thread.sleep(1000);} catch(Exception e) {}
synchronized(lock2){
System.out.println("Thread 1 over");
}
}
}).start();
new Thread(()->{
synchronized(lock2) {
try {Thread.sleep(1000);} catch(Exception e) {}
synchronized(lock1){
System.out.println("Thread 2 over");
}
}
}).start();
return "deadlock";
}
}
通過(guò)http://ip:port/loop訪(fǎng)問(wèn)觸發(fā)程序死循環(huán)，多訪(fǎng)問(wèn)幾次之后，在Linux上通過(guò)top命令可以看到我們的Java應(yīng)用程序CPU占用越來(lái)越高，系統(tǒng)負(fù)載也逐漸升高。
[root@wkp ~]# top top - 18:13:31 up 321 days, 3:37, 4 users, load average: 13.14, 9.15, 4.72 Tasks: 128 total, 1 running, 108 sleeping, 19 stopped, 0 zombie Cpu(s): 99.8%us, 0.2%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 8193352k total, 7702892k used, 490460k free, 9204k buffers Swap: 0k total, 0k used, 0k free, 75428k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 26295 root 20 0 4524m 378m 13m S 184.8 4.7 13:51.51 java
通過(guò)top命令，我們觀(guān)察到j(luò)ava進(jìn)程26295占用CPU很高，系統(tǒng)負(fù)載也越來(lái)越高.然后我們通過(guò)top -Hp 26295查看進(jìn)程的線(xiàn)程占用情況。
top -Hp pid 可以查看某個(gè)進(jìn)程的線(xiàn)程信息，其中-H 顯示線(xiàn)程信息，-p指定pid
[root@wkp~]# top -Hp 26295 top - 18:16:39 up 321 days, 3:40, 4 users, load average: 13.24, 11.14, 6.33 Tasks: 31 total, 12 running, 19 sleeping, 0 stopped, 0 zombie Cpu(s): 99.8%us, 0.2%sy, 0.0%ni, 0.0%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st Mem: 8193352k total, 7673852k used, 519500k free, 9752k buffers Swap: 0k total, 0k used, 0k free, 75508k cached PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 26379 root 20 0 4524m 378m 13m R 15.6 4.7 2:36.42 java 26384 root 20 0 4524m 378m 13m R 15.6 4.7 1:41.46 java 26388 root 20 0 4524m 378m 13m R 15.6 4.7 1:10.34 java 5673 root 20 0 4524m 378m 13m R 15.6 4.7 1:07.09 java 26386 root 20 0 4524m 378m 13m R 15.3 4.7 1:17.68 java 26380 root 20 0 4524m 378m 13m R 15.0 4.7 2:18.31 java 26381 root 20 0 4524m 378m 13m R 15.0 4.7 2:05.06 java 26382 root 20 0 4524m 378m 13m R 15.0 4.7 1:45.69 java 26385 root 20 0 4524m 378m 13m R 15.0 4.7 1:20.29 java 26387 root 20 0 4524m 378m 13m R 15.0 4.7 1:13.59 java 5801 root 20 0 4524m 378m 13m R 15.0 4.7 0:51.41 java 26383 root 20 0 4524m 378m 13m R 14.6 4.7 1:55.11 java 26295 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.00 java 26305 root 20 0 4524m 378m 13m S 0.0 4.7 0:02.63 java 26306 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.21 java 26307 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.20 java 26311 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.36 java 26312 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.00 java 26314 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.01 java 26327 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.00 java 26328 root 20 0 4524m 378m 13m S 0.0 4.7 0:03.67 java 26329 root 20 0 4524m 378m 13m S 0.0 4.7 0:01.33 java 26330 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.00 java 26331 root 20 0 4524m 378m 13m S 0.0 4.7 0:01.79 java 26376 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.06 java 26377 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.00 java 26378 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.13 java 26389 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.13 java 26390 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.11 java 26391 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.00 java 26392 root 20 0 4524m 378m 13m S 0.0 4.7 0:00.16 java
然后我們執(zhí)行 jstack 26295 > threadstack.txt 命令，將線(xiàn)程dump信息輸出到txt文件中，然后下載下來(lái)。因?yàn)閖stack打印出的線(xiàn)程堆棧中線(xiàn)程號(hào)是16進(jìn)制的，所以我們從上面top -Hp命令打印出的線(xiàn)程中選取第一個(gè)26379，通過(guò) printf "%x\n" 26379轉(zhuǎn)為16進(jìn)制得到670b。
[wkp@wkp4 Desktop]$ printf "%x\n" 26379 670b
然后我們通過(guò)16進(jìn)制的線(xiàn)程號(hào)670b，在threadstack.txt文件中搜索，可以搜到對(duì)應(yīng)的線(xiàn)程（內(nèi)容太多了，只貼了一小部分）：可以看到 at com.wkp.jvm.chapter2.CpuController.loop(CpuController.java:21)，第21行就對(duì)應(yīng)我們的while（true）死循環(huán)，這樣就找到了CPU飆高的原因了。
2019-09-24 18:17:55 Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.162-b12 mixed mode): //=========省略=============================================== "http-nio-9999-exec-1" #16 daemon prio=5 os_prio=0 tid=0x00007fa06943c800 nid=0x670b runnable [0x00007fa01b3e9000] java.lang.Thread.State: RUNNABLE at com.wkp.jvm.chapter2.CpuController.loop(CpuController.java:21) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) //=========省略=============================================== "C1 CompilerThread1" #6 daemon prio=9 os_prio=0 tid=0x00007fa06813e000 nid=0x66d9 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "C2 CompilerThread0" #5 daemon prio=9 os_prio=0 tid=0x00007fa06813b000 nid=0x66d8 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE "Finalizer" #3 daemon prio=8 os_prio=0 tid=0x00007fa068106800 nid=0x66ca in Object.wait() [0x00007fa054267000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x0000000082ebc820> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:143) - locked <0x0000000082ebc820> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:164) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:212) "VM Thread" os_prio=0 tid=0x00007fa0680fa000 nid=0x66c7 runnable "GC task thread#0 (ParallelGC)" os_prio=0 tid=0x00007fa06801e000 nid=0x66c2 runnable "GC task thread#1 (ParallelGC)" os_prio=0 tid=0x00007fa068020000 nid=0x66c3 runnable "VM Periodic Task Thread" os_prio=0 tid=0x00007fa068146000 nid=0x66db waiting on condition JNI global references: 913
下面我們對(duì)線(xiàn)程dump日志的格式做個(gè)介紹，以 "http-nio-9999-exec-1" #16 daemon prio=5 os_prio=0 tid=0x00007fa06943c800 nid=0x670b runnable [0x00007fa01b3e9000]為例：
- http-nio-9999-exec-1：線(xiàn)程名稱(chēng)
- daemon線(xiàn)程類(lèi)型：線(xiàn)程分為守護(hù)線(xiàn)程 (daemon) 和非守護(hù)線(xiàn)程 (non-daemon) 兩種，通常都是守護(hù)線(xiàn)程
- prio=5：線(xiàn)程優(yōu)先級(jí)：默認(rèn)為5，數(shù)字越大優(yōu)先級(jí)越高
- tid=0x00007fa06943c800JVM線(xiàn)程的id：JVM內(nèi)部線(xiàn)程的唯一標(biāo)識(shí)，通過(guò) java.lang.Thread.getId()獲取，通常用自增的方式實(shí)現(xiàn)；
- nid=0x670b系統(tǒng)線(xiàn)程id：對(duì)應(yīng)的系統(tǒng)線(xiàn)程id（Native Thread ID)，可以通過(guò) top -Hp 命令進(jìn)行查看，線(xiàn)程id是十六進(jìn)制的形式
- runnable：系統(tǒng)線(xiàn)程的狀態(tài)
- [0x00007fa01b3e9000]起始棧地址：線(xiàn)程堆棧調(diào)用的起始內(nèi)存地址
其他的線(xiàn)程名含義：
- "C1 CompilerThread1"和"C1 CompilerThread0"是Java的編譯線(xiàn)程
- "Finalizer"是垃圾回收時(shí)，被標(biāo)記的對(duì)象被放到F-Queue隊(duì)列中，F(xiàn)inalizer線(xiàn)程取出隊(duì)列中的對(duì)象進(jìn)行處理
- "GC task thread#0 (ParallelGC)" 和"GC task thread#1 (ParallelGC)" 是ParallelGC垃圾收集器的工作線(xiàn)程
jstack配合top命令查找死鎖
我們演示一下死鎖問(wèn)題的查找：同樣是啟動(dòng)上面的示例springboot程序，然后訪(fǎng)問(wèn) http://ip:port/deadlock觸發(fā)程序死鎖。然后通過(guò)jstack導(dǎo)出線(xiàn)程dump文件，在文件末尾可以看到如下內(nèi)容：
Found one Java-level deadlock: ============================= "Thread-5": waiting to lock monitor 0x00007fc978003778 (object 0x00000000833d0c20, a java.lang.Object), which is held by "Thread-4" "Thread-4": waiting to lock monitor 0x00007fc978003568 (object 0x00000000833d0c30, a java.lang.Object), which is held by "Thread-5" Java stack information for the threads listed above: =================================================== "Thread-5": at com.wkp.jvm.chapter2.CpuController.lambda$deadlock$1(CpuController.java:46) - waiting to lock <0x00000000833d0c20> (a java.lang.Object) - locked <0x00000000833d0c30> (a java.lang.Object) at com.wkp.jvm.chapter2.CpuController$$Lambda$343/408916933.run(Unknown Source) at java.lang.Thread.run(Thread.java:748) "Thread-4": at com.wkp.jvm.chapter2.CpuController.lambda$deadlock$0(CpuController.java:38) - waiting to lock <0x00000000833d0c30> (a java.lang.Object) - locked <0x00000000833d0c20> (a java.lang.Object) at com.wkp.jvm.chapter2.CpuController$$Lambda$342/620117450.run(Unknown Source) at java.lang.Thread.run(Thread.java:748) Found 1 deadlock.
可以看到線(xiàn)程dump中已經(jīng)把出現(xiàn)死鎖的線(xiàn)程打印出來(lái)了，Thread-4和Thread-5互相等待對(duì)方持有的鎖。
其實(shí)關(guān)于線(xiàn)程的dump和死鎖檢查等，JDK提供的有可視化的工具，比如 jconsole和jvisualvm 也是可以做到的。
另外，我們還可以通過(guò)如下 Thread.getAllStackTraces() 打印線(xiàn)程信息
@RequestMapping("/getAllThreadStack")
public void getAllThreadStack() {
for (Entry<Thread, StackTraceElement[]> stackTrace : Thread
.getAllStackTraces().entrySet()) {
Thread thread = (Thread) stackTrace.getKey();
StackTraceElement[] stack = (StackTraceElement[]) stackTrace
.getValue();
if (thread.equals(Thread.currentThread())) {
continue;
}
System.out.println("線(xiàn)程：" + thread.getName());
for (StackTraceElement stackTraceElement : stack) {
System.out.println(stackTraceElement);
}
}
}
到此這篇關(guān)于jstack配合top命令分析CPU飆高、程序死鎖問(wèn)題的文章就介紹到這了,更多相關(guān)Java 程序死鎖內(nèi)容請(qǐng)搜索腳本之家以前的文章或繼續(xù)瀏覽下面的相關(guān)文章希望大家以后多多支持腳本之家！
相關(guān)文章
java之左旋轉(zhuǎn)字符串介紹，需要的朋友可以參考一下2013-02-02
這篇文章主要給大家介紹了關(guān)于java高級(jí)用法之注解和反射講義的相關(guān)資料，文中通過(guò)示例代碼介紹的非常詳細(xì)，對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值，需要的朋友們下面隨著小編來(lái)一起學(xué)習(xí)學(xué)習(xí)吧2021-05-05
Java基于MySQL實(shí)現(xiàn)學(xué)生管理系統(tǒng)
這篇文章主要為大家詳細(xì)介紹了Java基于MySQL實(shí)現(xiàn)學(xué)生管理系統(tǒng)，具有一定的參考價(jià)值，感興趣的小伙伴們可以參考一下2018-01-01
SpringBoot實(shí)現(xiàn)接口返回?cái)?shù)據(jù)脫敏的代碼示例
在當(dāng)今的信息化時(shí)代,數(shù)據(jù)安全尤為重要,接口返回?cái)?shù)據(jù)脫敏是一種重要的數(shù)據(jù)保護(hù)手段,可以防止敏感信息通過(guò)接口返回給客戶(hù)端,本文旨在探討如何在SpringBoot應(yīng)用程序中實(shí)現(xiàn)接口返回?cái)?shù)據(jù)脫敏,需要的朋友可以參考下2024-07-07
SpringBoot生產(chǎn)環(huán)境和測(cè)試環(huán)境配置分離的教程詳解
這篇文章主要介紹了SpringBoot生產(chǎn)環(huán)境和測(cè)試環(huán)境配置分離的教程詳解,需要的朋友可以參考下2020-08-08
mybatis in foreach 雙層嵌套問(wèn)題
這篇文章主要介紹了mybatis in foreach 雙層嵌套問(wèn)題，具有很好的參考價(jià)值，希望對(duì)大家有所幫助。如有錯(cuò)誤或未考慮完全的地方，望不吝賜教2023-03-03
這篇文章主要介紹了Java中的幾種讀取properties配置文件的方式，小編覺(jué)得挺不錯(cuò)的，現(xiàn)在分享給大家，也給大家做個(gè)參考。一起跟隨小編過(guò)來(lái)看看吧2017-05-05
這篇文章主要為大家詳細(xì)介紹了Java中的static關(guān)鍵字，文中示例代碼介紹的非常詳細(xì)，具有一定的參考價(jià)值，感興趣的小伙伴們可以參考一下，希望能夠給你帶來(lái)幫助2022-02-02
淺談DetachedCriteria和Criteria的使用方法(必看)
下面小編就為大家?guī)?lái)一篇淺談DetachedCriteria和Criteria的使用方法(必看)。小編覺(jué)得挺不錯(cuò)的，現(xiàn)在就分享給大家，也給大家做個(gè)參考。一起跟隨小編過(guò)來(lái)看看吧2017-05-05
idea開(kāi)啟mybatis控制臺(tái)SQL日志打印的代碼示例
本文主要介紹了idea開(kāi)啟mybatis控制臺(tái)SQL日志打印的方法,文中通過(guò)示例代碼介紹的非常詳細(xì),對(duì)大家的學(xué)習(xí)或者工作具有一定的參考學(xué)習(xí)價(jià)值,需要的朋友們下面隨著小編來(lái)一起學(xué)習(xí)學(xué)習(xí)吧2023-12-12