正文

jstack命令及其死锁、CPU飙高问题排查使用

toobug
toobugV管理员/1.49 W阅读/0评论
0422
此篇文章发布距今已超过1454天，您需要注意文章的内容或图片是否可用！

jstack是jdk自带的线程堆栈分析工具，使用该命令可以查看或导出 java 应用程序中线程堆栈信息。jstack用于生成java虚拟机当前时刻的线程快照。线程快照是当前java虚拟机内每一条线程正在执行的方法堆栈的集合，生成线程快照的主要目的是定位线程出现长时间停顿的原因，如线程间死锁、死循环、请求外部资源导致的长时间等待等。 线程出现停顿的时候通过jstack来查看各个线程的调用堆栈，就可以知道没有响应的线程到底在后台做什么事情，或者等待什么资源。 如果java程序崩溃生成core文件，jstack工具可以用来获得core文件的java stack和native stack的信息，从而可以轻松地知道java程序是如何崩溃和在程序何处发生问题。另外，jstack工具还可以附属到正在运行的java程序中，看到当时运行的java程序的java stack和native stack的信息, 如果现在运行的java程序呈现hung的状态，jstack是非常有用的。

一、jstack用法

[root@smdw tang]# jstack
Usage:
    jstack [-l] <pid>
        (to connect to running process)
    jstack -F [-m] [-l] <pid>
        (to connect to a hung process)
    jstack [-m] [-l] <executable> <core>
        (to connect to a core file)
    jstack [-m] [-l] [server_id@]<remote server IP or hostname>
        (to connect to a remote debug server)

Options:
    -F  to force a thread dump. Use when jstack <pid> does not respond (process is hung)
    -m  to print both java and native frames (mixed mode)
    -l  long listing. Prints additional information about locks
    -h or -help to print this help message

二、jstack查看输出

[root@smdw tang]# jps -l
640 sun.tools.jps.Jps
2465 /usr/local/whistle/webapps/EurekaServer/lib/EurekaServer-0.0.1.jar
14417 /usr/local/whistle/webapps/dataAnalysis/lib/dataAnalysis.jar
6753 sun.tools.jstatd.Jstatd
21380 com.weishao.standard.StandardConverterApplication
4696 kafka.Kafka
1882 org.apache.zookeeper.server.quorum.QuorumPeerMain
12830 com.weishao.dbswitch.webapi.WebServiceApplication
[root@smdw tang]# jstack -l 21380
2020-03-07 14:11:25
Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.112-b15 mixed mode):

"Attach Listener" #107 daemon prio=9 os_prio=0 tid=0x00007faf94001000 nid=0x7f7c waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"RMI TCP Connection(59)-172.16.68.35" #106 daemon prio=5 os_prio=0 tid=0x00007faf5800b000 nid=0x7f2c runnable [0x00007faecbffd000]
   java.lang.Thread.State: RUNNABLE
	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 java.io.BufferedInputStream.fill(BufferedInputStream.java:246)
	at java.io.BufferedInputStream.read(BufferedInputStream.java:265)
	- locked <0x0000000758b002a8> (a java.io.BufferedInputStream)
	at java.io.FilterInputStream.read(FilterInputStream.java:83)
	at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:550)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:826)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:683)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler$$Lambda$741/422928510.run(Unknown Source)
	at java.security.AccessController.doPrivileged(Native Method)
	at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
	at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
	- <0x0000000769c643b8> (a java.util.concurrent.ThreadPoolExecutor$Worker)

................

   Locked ownable synchronizers:
	- None

"VM Thread" os_prio=0 tid=0x00007fb0488ac000 nid=0x53a5 runnable 

"Gang worker#0 (Parallel GC Threads)" os_prio=0 tid=0x00007fb048025800 nid=0x5386 runnable

三、jstack统计线程数

[root@smdw tang]# jstack -l 21380 | grep 'java.lang.Thread.State' | wc -l
63

四、jstack检测死锁

（1）死锁代码

public class DeathLock {

    private static Lock lock1 = new ReentrantLock();
    private static Lock lock2 = new ReentrantLock();

    public static void deathLock() {
        Thread t1 = new Thread() {
            @Override
            public void run() {
                try {
                    lock1.lock();
                    TimeUnit.SECONDS.sleep(1);
                    lock2.lock();
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        };
        Thread t2 = new Thread() {
            @Override
            public void run() {
                try {
                    lock2.lock();
                    TimeUnit.SECONDS.sleep(1);
                    lock1.lock();
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
            }
        };

        t1.setName("mythread1");
        t2.setName("mythread2");
        t1.start();
        t2.start();
    }

    public static void main(String[] args) {
        deathLock();
    }
}

（2）jstack分析

"mythread2" #12 prio=5 os_prio=0 tid=0x0000000058ef7800 nid=0x1ab4 waiting on condition [0x0000000059f8f000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000d602d610> (a java.util.concurrent.lock
s.ReentrantLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInt
errupt(AbstractQueuedSynchronizer.java:836)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(A
bstractQueuedSynchronizer.java:870)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(Abstrac
tQueuedSynchronizer.java:1199)
        at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLo
ck.java:209)
        at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)

        at DeathLock$2.run(DeathLock.java:34)

   Locked ownable synchronizers:
        - <0x00000000d602d640> (a java.util.concurrent.locks.ReentrantLock$Nonfa
irSync)

"mythread1" #11 prio=5 os_prio=0 tid=0x0000000058ef7000 nid=0x3e68 waiting on condition [0x000000005947f000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000d602d640> (a java.util.concurrent.lock
s.ReentrantLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInt
errupt(AbstractQueuedSynchronizer.java:836)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(A
bstractQueuedSynchronizer.java:870)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(Abstrac
tQueuedSynchronizer.java:1199)
        at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLo
ck.java:209)
        at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)

        at DeathLock$1.run(DeathLock.java:22)

   Locked ownable synchronizers:
        - <0x00000000d602d610> (a java.util.concurrent.locks.ReentrantLock$Nonfa
irSync)


Found one Java-level deadlock:
=============================
"mythread2":
  waiting for ownable synchronizer 0x00000000d602d610, (a java.util.concurrent.l
ocks.ReentrantLock$NonfairSync),
  which is held by "mythread1"
"mythread1":
  waiting for ownable synchronizer 0x00000000d602d640, (a java.util.concurrent.l
ocks.ReentrantLock$NonfairSync),
  which is held by "mythread2"

Java stack information for the threads listed above:
===================================================
"mythread2":
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000d602d610> (a java.util.concurrent.lock
s.ReentrantLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInt
errupt(AbstractQueuedSynchronizer.java:836)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(A
bstractQueuedSynchronizer.java:870)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(Abstrac
tQueuedSynchronizer.java:1199)
        at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLo
ck.java:209)
        at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)

        at DeathLock$2.run(DeathLock.java:34)
"mythread1":
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000000d602d640> (a java.util.concurrent.lock
s.ReentrantLock$NonfairSync)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.parkAndCheckInt
errupt(AbstractQueuedSynchronizer.java:836)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(A
bstractQueuedSynchronizer.java:870)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(Abstrac
tQueuedSynchronizer.java:1199)
        at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(ReentrantLo
ck.java:209)
        at java.util.concurrent.locks.ReentrantLock.lock(ReentrantLock.java:285)

        at DeathLock$1.run(DeathLock.java:22)

Found 1 deadlock.

五、利用jstack检测cpu飙高问题

步骤一：查看cpu占用高进程

[root@smdw tang]#top

Mem:  16333644k total,  9472968k used,  6860676k free,   165616k buffers
Swap:        0k total,        0k used,        0k free,  6665292k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND     
17850 root      20   0 7588m 112m  11m S 100.7  0.7  47:53.80 java       
 1552 root      20   0  121m  13m 8524 S  0.7  0.1  14:37.75 AliYunDun   
 3581 root      20   0 9750m 2.0g  13m S  0.7 12.9 298:30.20 java        
    1 root      20   0 19360 1612 1308 S  0.0  0.0   0:00.81 init        
    2 root      20   0     0    0    0 S  0.0  0.0   0:00.00 kthreadd    
    3 root      RT   0     0    0    0 S  0.0  0.0   0:00.14 migration/0

步骤二：查看cpu占用高线程

[root@smdw tang]#top -H -p 17850

top - 17:43:15 up 5 days,  7:31,  1 user,  load average: 0.99, 0.97, 0.91
Tasks:  32 total,   1 running,  31 sleeping,   0 stopped,   0 zombie
Cpu(s):  3.7%us,  8.9%sy,  0.0%ni, 87.4%id,  0.0%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:  16333644k total,  9592504k used,  6741140k free,   165700k buffers
Swap:        0k total,        0k used,        0k free,  6781620k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
17880 root      20   0 7588m 112m  11m R 99.9  0.7  50:47.43 java
17856 root      20   0 7588m 112m  11m S  0.3  0.7   0:02.08 java
17850 root      20   0 7588m 112m  11m S  0.0  0.7   0:00.00 java
17851 root      20   0 7588m 112m  11m S  0.0  0.7   0:00.23 java
17852 root      20   0 7588m 112m  11m S  0.0  0.7   0:02.09 java
17853 root      20   0 7588m 112m  11m S  0.0  0.7   0:02.12 java
17854 root      20   0 7588m 112m  11m S  0.0  0.7   0:02.07 java

步骤三：转换线程ID

printf "%x\n" 17880          
45d8

步骤四：定位cpu占用线程

jstack 17850|grep 45d8 -A 30
"pool-1-thread-11" #20 prio=5 os_prio=0 tid=0x00007fc860352800 nid=0x45d8 runnable [0x00007fc8417d2000]
   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 <0x00000006c6c2e708> (a java.io.BufferedOutputStream)
        at java.io.PrintStream.write(PrintStream.java:482)
        - locked <0x00000006c6c10178> (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 <0x00000006c6c26620> (a java.io.OutputStreamWriter)
        at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185)
        at java.io.PrintStream.write(PrintStream.java:527)
        - eliminated <0x00000006c6c10178> (a java.io.PrintStream)
        at java.io.PrintStream.print(PrintStream.java:597)
        at java.io.PrintStream.println(PrintStream.java:736)
        - locked <0x00000006c6c10178> (a java.io.PrintStream)
        at com.demo.guava.HardTask.call(HardTask.java:18)
        at com.demo.guava.HardTask.call(HardTask.java:9)
        at java.util.concurrent.FutureTask.run(FutureTask.java:266)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

"pool-1-thread-10" #19 prio=5 os_prio=0 tid=0x00007fc860345000 nid=0x45d7 waiting on condition [0x00007fc8418d3000]
   java.lang.Thread.State: WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000006c6c14178> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)

此外，推荐一个阿里牛人写的排查脚本show-busy-java-threads工具：https://github.com/oldratlee/useful-scripts

本文标题：jstack命令及其死锁、CPU飙高问题排查使用
本文链接：https://blog.quwenai.cn/post/8306.html
作者授权：除特别说明外，本文由 toobug 原创编译并授权 TOOBUG信息安全网 刊载发布。
版权声明：本文不使用任何协议授权，您可以任何形式自由转载或使用。

本文链接：https://blog.quwenai.cn/post/8306.html 

分享到：
本站所有内容均来自于互联网收集及用户投稿,如果想系统学习相关知识 建议在本博客【自学成才】栏目选择合适的课程进行系统化学习
-- 展开阅读全文 --