jstack(Java Stack Trace)简介

jstack(Java Stack Trace)简介

jstack:Java进程中线程的堆栈信息跟踪工具。
功能简介
  jstack常用来打印Java进程/core文件/远程调试端口的Java线程堆栈跟踪信息,包含当前虚拟机中所有线程正在执行的方法堆栈信息的集合。
  主要用来定位线程出现长时间停顿的原因,如线程间死锁、死循环、请求外部资源导致的长时间等待。
命令格式

jstack [ options ] pid                                      //Java进程
jstack [ options ] executable core                          //core文件
jstack [ options ] [ [email protected] ] remote-hostname-or-IP     //远程调试端口

其中options选项可有

选项 作用
-F 当正常输出的请求不被响应时,强制输出线程堆栈
-l 除了堆栈外,显示关于锁的附加信息
-m 如果调用到本地方法的话,可以显示C/C++的堆栈信息

其他说明

1、When the specified process is running on a 64-bit Java Virtual Machine, you might need to specify the -J-d64 option, for example: jstack -J-d64 -m pid.
2、In mixed mode stack trace, the -m option does not work with the remote debug server.
3、In Windows Systems where the dbgeng.dll file is not present, Debugging Tools For Windows must be installed so these tools work.

输出格式
jstack的输出是该进程下的所有线程的堆栈集合,下面是一个线程的堆栈快照信息:

catalina-exec-72" daemon prio=5 tid=114 WAITING
    at sun.misc.Unsafe.park(Native Method)
    at java.util.concurrent.locks.LockSupport.park(LockSupport.java:175)
    at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2039)
       Local Variable: java.util.concurrent.locks.AbstractQueuedSynchronizer$Node#294
    at java.util.concurrent.LinkedBlockingQueue.take(LinkedBlockingQueue.java:442)
    at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:104)
    at org.apache.tomcat.util.threads.TaskQueue.take(TaskQueue.java:32)
    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)
       Local Variable: java.util.concurrent.ThreadPoolExecutor$Worker#50
    at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
       Local Variable: org.apache.tomcat.util.threads.TaskThread$WrappingRunnable#38
    at java.lang.Thread.run(Thread.java:745)
属性 说明
catalina-exec-72 线程名称
prio 该线程JVM中的优先级
os_prio 该线程在OS中的优先级
tid JVM内的thread id (Java-level thread ID)
daemon 表明这个线程是一个守护线程
nid Native thread ID,本地操作系统相关的线程id

nid说明
This ID is highly platform dependent. It's the nid in jstack thread dumps.
On Windows, it's simply the OS-level thread ID within a process.
On Linux, it's the pid of the thread (which in turn is a light-weight process).
On Solaris, it's the thread as returned by thr_self().
On Mac OS X, it is said to be the native pthread_t value.

状 态
在jstack输出的第二行为线程的状态,在JVM中线程状态使用枚举 java.lang.Thread.State 来表示,State的定义如下:

 public enum State {
        /**
         * Thread state for a thread which has not yet started.
         */
        NEW,

        /**
         * Thread state for a runnable thread.  A thread in the runnable
         * state is executing in the Java virtual machine but it may
         * be waiting for other resources from the operating system
         * such as processor.
         */
        RUNNABLE,

        /**
         * Thread state for a thread blocked waiting for a monitor lock.
         * A thread in the blocked state is waiting for a monitor lock
         * to enter a synchronized block/method or
         * reenter a synchronized block/method after calling
         * {@link Object#wait() Object.wait}.
         */
        BLOCKED,

        /**
         * Thread state for a waiting thread.
         * A thread is in the waiting state due to calling one of the
         * following methods:
         * <ul>
         *   <li>{@link Object#wait() Object.wait} with no timeout</li>
         *   <li>{@link #join() Thread.join} with no timeout</li>
         *   <li>{@link LockSupport#park() LockSupport.park}</li>
         * </ul>
         *
         * <p>A thread in the waiting state is waiting for another thread to
         * perform a particular action.
         *
         * For example, a thread that has called <tt>Object.wait()</tt>
         * on an object is waiting for another thread to call
         * <tt>Object.notify()</tt> or <tt>Object.notifyAll()</tt> on
         * that object. A thread that has called <tt>Thread.join()</tt>
         * is waiting for a specified thread to terminate.
         */
        WAITING,

        /**
         * Thread state for a waiting thread with a specified waiting time.
         * A thread is in the timed waiting state due to calling one of
         * the following methods with a specified positive waiting time:
         * <ul>
         *   <li>{@link #sleep Thread.sleep}</li>
         *   <li>{@link Object#wait(long) Object.wait} with timeout</li>
         *   <li>{@link #join(long) Thread.join} with timeout</li>
         *   <li>{@link LockSupport#parkNanos LockSupport.parkNanos}</li>
         *   <li>{@link LockSupport#parkUntil LockSupport.parkUntil}</li>
         * </ul>
         */
        TIMED_WAITING,

        /**
         * Thread state for a terminated thread.
         * The thread has completed execution.
         */
        TERMINATED;
    }

线程图


jstack(Java Stack Trace)简介
Thread_life.png
线程状态 说明
NEW 当线程对象创建时存在的状态,此时线程不可能执行;
RUNNABLE 当调用thread.start()后,线程变成为Runnable状态。只要得到CPU,就可以执行;
RUNNING 线程正在执行;
WAITING 执行thread.join()或在锁对象调用obj.wait()等情况就会进该状态,表明线程正处于等待某个资源或条件发生来唤醒自己;
TIMED_WAITING 执行Thread.sleep(long)、thread.join(long)或obj.wait(long)等就会进该状态,与Waiting的区别在于Timed_Waiting的等待有时间限制;
BLOCKED 如果进入同步方法或同步代码块,没有获取到锁,则会进入该状态;
DEAD 线程执行完毕,或者抛出了未捕获的异常之后,会进入dead状态,表示该线程结束。
jstack日志关键字 说 明
deadlock 死锁
Waiting on condition 等待某个资源或条件发生来唤醒自己。具体需要结合jstacktrace来分析,比如线程正在sleep,网络读写繁忙而等待
Blocked 阻塞
waiting on monitor entry 在等待获取锁
in Object.wait() 获取锁后又执行obj.wait()放弃锁

==如果说系统慢,那么要特别关注Blocked,Waiting on condition==
==如果说系统的cpu耗的高,那么肯定是线程执行有死循环,那么此时要关注下Runable状态。==

  • 死锁
public class DeadLock {

    public static void main(String[] args) throws InterruptedException {
        Object obj1 = new Object();
        Object obj2 = new Object();
        Object obj3 = new Object();

        Thread t1 = new Thread(new SyncThread(obj1, obj2), "t1");
        Thread t2 = new Thread(new SyncThread(obj2, obj3), "t2");
        Thread t3 = new Thread(new SyncThread(obj3, obj1), "t3");

        t1.start();
        Thread.sleep(5000);
        t2.start();
        Thread.sleep(5000);
        t3.start();
    }

}

class SyncThread implements Runnable {
    private Object obj1;
    private Object obj2;

    public SyncThread(Object o1, Object o2) {
        this.obj1 = o1;
        this.obj2 = o2;
    }

    @Override
    public void run() {
        String name = Thread.currentThread().getName();
        System.out.println(name + " acquiring lock on " + obj1);
        synchronized (obj1) {
            System.out.println(name + " acquired lock on " + obj1);
            work();
            System.out.println(name + " acquiring lock on " + obj2);
            synchronized (obj2) {
                System.out.println(name + " acquired lock on " + obj2);
                work();
            }
            System.out.println(name + " released lock on " + obj2);
        }
        System.out.println(name + " released lock on " + obj1);
        System.out.println(name + " finished execution.");
    }

    private void work() {
        try {
            Thread.sleep(30000);
        } catch (InterruptedException e) {
            e.printStackTrace();
        }
    }
}
Found one Java-level deadlock:
=============================
"t3":
  waiting to lock monitor 0x000000000d8fb0a8 (object 0x00000007d7cd4828, a java.lang.Object),
  which is held by "t1"
"t1":
  waiting to lock monitor 0x000000000560c918 (object 0x00000007d7cd4fa0, a java.lang.Object),
  which is held by "t2"
"t2":
  waiting to lock monitor 0x000000000560de68 (object 0x00000007d7cd4818, a java.lang.Object),
  which is held by "t3"

Java stack information for the threads listed above:
===================================================
"t3":
        at com.tzx.test.SyncThread.run(DeadLock.java:41)
        - waiting to lock <0x00000007d7cd4828> (a java.lang.Object)
        - locked <0x00000007d7cd4818> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:744)
"t1":
        at com.tzx.test.SyncThread.run(DeadLock.java:41)
        - waiting to lock <0x00000007d7cd4fa0> (a java.lang.Object)
        - locked <0x00000007d7cd4828> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:744)
"t2":
        at com.tzx.test.SyncThread.run(DeadLock.java:41)
        - waiting to lock <0x00000007d7cd4818> (a java.lang.Object)
        - locked <0x00000007d7cd4fa0> (a java.lang.Object)
        at java.lang.Thread.run(Thread.java:744)
  • block范例
public class Blocked {

    public static void main(String[] args) {
        final Thread thread = new Thread() {
            @Override
            public void run() {
                synchronized (this) {
                    System.out.println(Thread.currentThread().getName());
                    try {
                        TimeUnit.SECONDS.sleep(60);
                    } catch (Exception e) {

                    }
                }
            }
        };
        thread.start();
        thread.setName("thread1");

        synchronized (thread) {
            System.out.println(Thread.currentThread().getName());
            try {
                TimeUnit.SECONDS.sleep(60);
            } catch (Exception e) {

            }
        }
    }
}
2017-11-24 18:39:59
Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.51-b03 mixed mode):
"RMI TCP Connection(2)-172.18.95.100" daemon prio=6 tid=0x000000000f958000 nid=0x2598 runnable [0x00000000109ce000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:152)
        at java.net.SocketInputStream.read(SocketInputStream.java:122)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:254)
        - locked <0x00000007d6695110> (a java.io.BufferedInputStream)
        at java.io.FilterInputStream.read(FilterInputStream.java:83)
        at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:538)
        at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:811)
        at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:670)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:744)

   Locked ownable synchronizers:
        - <0x00000007d62075b0> (a java.util.concurrent.ThreadPoolExecutor$Worker)
"JMX server connection timeout 14" daemon prio=6 tid=0x000000000fbe4000 nid=0x32f8 in Object.wait() [0x00000000105cf000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000007d62dbc78> (a [I)
        at com.sun.jmx.remote.internal.ServerCommunicatorAdmin$Timeout.run(ServerCommunicatorAdmin.java:168)
        - locked <0x00000007d62dbc78> (a [I)
        at java.lang.Thread.run(Thread.java:744)
   Locked ownable synchronizers:
        - None
"RMI Scheduler(0)" daemon prio=6 tid=0x000000000fbe3000 nid=0xcc0 waiting on condition [0x00000000104cf000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000007d61806c0> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:226)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2082)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1090)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:807)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1068)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1130)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:744)
   Locked ownable synchronizers:
        - None
"RMI TCP Connection(1)-172.18.95.100" daemon prio=6 tid=0x000000000fbe9000 nid=0x3b9c runnable [0x00000000103ce000]
   java.lang.Thread.State: RUNNABLE
        at java.net.SocketInputStream.socketRead0(Native Method)
        at java.net.SocketInputStream.read(SocketInputStream.java:152)
        at java.net.SocketInputStream.read(SocketInputStream.java:122)
        at java.io.BufferedInputStream.fill(BufferedInputStream.java:235)
        at java.io.BufferedInputStream.read(BufferedInputStream.java:254)
        - locked <0x00000007d62a64d0> (a java.io.BufferedInputStream)
        at java.io.FilterInputStream.read(FilterInputStream.java:83)
        at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:538)
        at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:811)
        at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:670)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
        at java.lang.Thread.run(Thread.java:744)

   Locked ownable synchronizers:
        - <0x00000007d6203998> (a java.util.concurrent.ThreadPoolExecutor$Worker)
"RMI TCP Accept-0" daemon prio=6 tid=0x000000000fbe6000 nid=0x38c0 runnable [0x00000000101be000]
   java.lang.Thread.State: RUNNABLE
        at java.net.DualStackPlainSocketImpl.accept0(Native Method)
        at java.net.DualStackPlainSocketImpl.socketAccept(DualStackPlainSocketImpl.java:131)
        at java.net.AbstractPlainSocketImpl.accept(AbstractPlainSocketImpl.java:398)
        at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:198)
        - locked <0x00000007d6181e30> (a java.net.SocksSocketImpl)
        at java.net.ServerSocket.implAccept(ServerSocket.java:530)
        at java.net.ServerSocket.accept(ServerSocket.java:498)
        at sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(LocalRMIServerSocketFactory.java:52)
        at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:388)
        at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:360)
        at java.lang.Thread.run(Thread.java:744)

   Locked ownable synchronizers:
        - None
"thread1" prio=6 tid=0x000000000f339000 nid=0x2728 waiting for monitor entry [0x000000000f89f000]
   java.lang.Thread.State: BLOCKED (on object monitor)
        at com.tzx.test.Blocked$1.run(Blocked.java:12)
        - waiting to lock <0x00000007d5d2a758> (a com.tzx.test.Blocked$1)

   Locked ownable synchronizers:
        - None
"Service Thread" daemon prio=6 tid=0x000000000da67000 nid=0x2de4 runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
        - None
"C2 CompilerThread1" daemon prio=10 tid=0x000000000da63800 nid=0x2ccc waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
        - None
"C2 CompilerThread0" daemon prio=10 tid=0x000000000da54800 nid=0x1aec waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
        - None
"Attach Listener" daemon prio=10 tid=0x000000000da54000 nid=0x39fc waiting on condition [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
        - None
"Signal Dispatcher" daemon prio=10 tid=0x00000000056de800 nid=0x3bac runnable [0x0000000000000000]
   java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
        - None
"Finalizer" daemon prio=8 tid=0x00000000056ce000 nid=0x778 in Object.wait() [0x000000000ed9f000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000007d5c05568> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
        - locked <0x00000007d5c05568> (a java.lang.ref.ReferenceQueue$Lock)
        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
        at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:189)

   Locked ownable synchronizers:
        - None
"Reference Handler" daemon prio=10 tid=0x000000000da14000 nid=0x1254 in Object.wait() [0x000000000ec9f000]
   java.lang.Thread.State: WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)
        - waiting on <0x00000007d5c050f0> (a java.lang.ref.Reference$Lock)
        at java.lang.Object.wait(Object.java:503)
        at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:133)
        - locked <0x00000007d5c050f0> (a java.lang.ref.Reference$Lock)

   Locked ownable synchronizers:
        - None
"main" prio=6 tid=0x00000000055e6000 nid=0x2da8 waiting on condition [0x000000000558f000]
   java.lang.Thread.State: TIMED_WAITING (sleeping)
        at java.lang.Thread.sleep(Native Method)
        at java.lang.Thread.sleep(Thread.java:340)
        at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:360)
        at com.tzx.test.Blocked.main(Blocked.java:27)
        - locked <0x00000007d5d2a758> (a com.tzx.test.Blocked$1)

   Locked ownable synchronizers:
        - None
"VM Thread" prio=10 tid=0x000000000da12000 nid=0x3434 runnable
"GC task thread#0 (ParallelGC)" prio=6 tid=0x00000000055fc000 nid=0x2da4 runnable
"GC task thread#1 (ParallelGC)" prio=6 tid=0x00000000055fe000 nid=0x10fc runnable
"GC task thread#2 (ParallelGC)" prio=6 tid=0x00000000055ff800 nid=0x32b0 runnable
"GC task thread#3 (ParallelGC)" prio=6 tid=0x0000000005602800 nid=0x534 runnable
"VM Periodic Task Thread" prio=10 tid=0x000000000f2b0800 nid=0x2f78 waiting on condition