jstack

jstack

jstack命令主要用于调试java程序运行过程中的线程堆栈信息,可以用于检测死锁,进程耗用cpu过高报警问题的排查。

$ jstack

Usage:
    jstack [-l] <pid>
    jstack -F [-m] [-l] <pid>
Options:
    -F  强制dump线程堆栈信息. 用于进程hung住,jstack <pid>命令没有响应的情况
    -m  同时打印java和本地(native)线程栈信息,m是mixed mode的简写
    -l  打印锁的额外信息

典型用法

jstack的典型用法如下:

  • qmq是部署在tomcat中的应用名
$ ps -ef | grep qmq | grep -v grep

拿到进程号,例如上面对应的是3192

  • 第二步找出该进程内最耗费CPU的线程,可以使用ps -Lfp pid或者ps -mp pid -o THREAD, tid, time或者top -Hp pid。例如用第三个top -Hp 3192
Tasks: 123 total, 0 running, 123 sleeping, 0 stopped, 0 zombie
Cpu(s): 0.3%us, 0.4%sy, 0.0%ni, 99.3%id, 0.0%wa, 0.0%hi, 0.0%si, 0.0%st
Mem: 3922688k total, 3272588k used, 650100k free, 432768k buffers
Swap: 4194296k total, 0k used, 4194296k free, 596488k cached

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
3494 tomcat 20 0 4905m 1.1g 11m S 0.3 28.4 0:51.91 java
3551 tomcat 20 0 4905m 1.1g 11m S 0.3 28.4 4:46.32 java
3588 tomcat 20 0 4905m 1.1g 11m S 0.3 28.4 0:07.35 java
3192 tomcat 20 0 4905m 1.1g 11m S 0.0 28.4 0:00.00 java
3194 tomcat 20 0 4905m 1.1g 11m S 0.0 28.4 0:00.82 java
  • TIME列就是各个Java线程耗费的CPU时间,CPU时间最长的是线程ID3551的线程,用 printf "%x\n" 3551 得到ddf

  • sudo -u tomcat jstack 3192 | grep ddf

"New I/O worker #30" daemon prio=10 tid=0x00007f44fd525800 nid=0xde4 runnable [0x00007f4530ddf000]
"DubboResponseTimeoutScanTimer" daemon prio=10 tid=0x00007f44fca88000 nid=0xddf waiting on condition [0x00007f45322e5000]

线程信息详解

jstack命令会打印出所有的线程,包括用户自己启动的线程和jvm后台线程,我们主要关注的是用户线程,如:

$ jstack 15525

Full thread dump Java HotSpot(TM) 64-Bit Server VM (25.65-b01 mixed mode):

"elasticsearch[Native][merge][T#1]" #98 daemon prio=5 os_prio=0 tid=0x00007f031c009000 nid=0x4129 waiting on condition [0x00007f02f61ee000]

   java.lang.Thread.State: WAITING (parking)
    at sun.misc.Unsafe.park(Native Method)
    - parking to wait for  <0x00000000eea589f0> (a org.elasticsearch.common.util.concurrent.EsExecutors$ExecutorScalingQueue)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.LinkedTransferQueue.awaitMatch(LinkedTransferQueue.java:737)
    at java.util.concurrent.LinkedTransferQueue.xfer(LinkedTransferQueue.java:647)
    at java.util.concurrent.LinkedTransferQueue.take(LinkedTransferQueue.java:1269)
    at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
    at java.lang.Thread.run(Thread.java:745)

....

线程dump信息说明:

  • elasticsearch[Native][merge][T#1]是我们为线程起的名字

  • daemon表示线程是否是守护线程

  • prio表示我们为线程设置的优先级

  • os_prio表示的对应的操作系统线程的优先级,由于并不是所有的操作系统都支持线程优先级,所以可能会出现都置为0的情况

  • tidjava中为这个线程的id

  • nid是这个线程对应的操作系统本地线程id,每一个java线程都有一个对应的操作系统线程

  • wait on condition表示当前线程处于等待状态,但是并没列出具体原因

  • java.lang.Thread.State: WAITING (parking)也是表示的处于等待状态,括号中的内容说明了导致等待的原因,例如这里的parking说明是因为调用了LockSupport.park方法导致等待

java.lang.Thread.State

一个Thread对象可以有多个状态,在java.lang.Thread.State中,总共定义六种状态。

  • New

线程刚刚被创建,也就是已经new过了,但是还没有调用start()方法,jstack命令不会列出处于此状态的线程信息。

  • RUNNABLE

RUNNABLE这个名字很具有欺骗性,很容易让人误以为处于这个状态的线程正在运行。事实上,这个状态只是表示,线程是可运行的。我们已经无数次提到过,一个单核CPU在同一时刻,只能运行一个线程。

  • BLOCKED

线程处于阻塞状态,正在等待一个monitor lock。通常情况下,是因为本线程与其他线程公用了一个锁。其他在线程正在使用这个锁进入某个synchronized同步方法块或者方法,而本线程进入这个同步代码块也需要这个锁,最终导致本线程处于阻塞状态。

  • WAITING

等待状态,调用以下方法可能会导致一个线程处于等待状态:Object.wait不指定超时时间、Thread.join with no timeout、LockSupport.park #java.lang.Thread.State: WAITING (parking)。

例如:对于wait()方法,一个线程处于等待状态,通常是在等待其他线程完成某个操作。本线程调用某个对象的wait()方法,其他线程处于完成之后,调用同一个对象的notify或者notifyAll()方法。Object.wait()方法只能够在同步代码块中调用。调用了wait()方法后,会释放锁。

  • TIMED_WAITING

线程等待指定的时间,对于以下方法的调用,可能会导致线程处于这个状态:

  1. Thread.sleep #java.lang.Thread.State: TIMED_WAITING (sleeping)

  2. Object.wait指定超时时间#java.lang.Thread.State: TIMED_WAITING (on object monitor)

  3. Thread.join with timeout

  4. LockSupport.parkNanos #java.lang.Thread.State: TIMED_WAITING (parking)

  5. LockSupport.parkUntil #java.lang.Thread.State: TIMED_WAITING (parking)

  • TERMINATED

线程终止。说明,对于java.lang.Thread.State: WAITING (on object monitor)java.lang.Thread.State: TIMED_WAITING (on object monitor),对于这两个状态,是因为调用了Objectwait方法(前者没有指定超时,后者指定了超时),由于wait方法肯定要在syncronized代码中编写,因此肯定是如类似以下代码导致:

synchronized(obj) {
        // .........
        obj.wait();
        // .........
}

死锁

Java 5中加强了对死锁的检测。线程Dump中可以直接报告出Java级别的死锁,如下所示:


Found one Java-level deadlock:

=============================

"Thread-1":

waiting to lock monitor 0x0003f334 (object 0x22c19f18, a java.lang.Object),

which is held by "Thread-0"

"Thread-0":

waiting to lock monitor 0x0003f314 (object 0x22c19f20, a java.lang.Object),

which is held by "Thread-1"

nid

每个线程都有一个tidnidtidjava中这个线程的编号,而nid(native id)是对应操作系统线程id。有的时候,我们会收到报警,说服务器,某个进程占用CPU过高,肯定是因为某个java线程有耗CPU资源的方法。

下一页