java通过jstack命令查询日志深入理解

小鱼儿 2023-10-08 20:54 27阅读 0赞

在分析线上问题时常使用到jstack <PID>命令将当时Java应用程序的线程堆栈dump出来。

面对jstack 日志，我们如何查看？

## 1 **首先要清楚线程的状态** ##

线程的状态有： **new、runnable、running、waiting、timed\_waiting、blocked、dead**

### 1.1 线程状态变迁图： ###

![bdb38126ea5b40d1bb7b4e909f1cf2bf.jpeg][]

### 1.2 各状态说明： ###

**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状态，表示该线程结束

### 1.3 对于jstack日志，我们要着重关注如下关键信息 ###

**Deadlock**：表示有死锁

**Waiting on condition**：等待某个资源或条件发生来唤醒自己。具体需要结合jstacktrace来分析，比如线程正在sleep，网络读写繁忙而等待

**Blocked**：阻塞

**Waiting on monitor entry**：在等待获取锁

**in Object.wait()**：获取锁后又执行obj.wait()放弃锁

### **1.4 Waiting on monitor entry** **和** **in Object.wait()的详细描述** ###

Monitor是 Java中用以实现线程之间的互斥与协作的主要手段，它可以看成是对象或者 Class的锁。每一个对象都有，也仅有一个 monitor。从下图中可以看出，每个 Monitor在某个时刻，只能被一个线程拥有，该线程就是 "Active Thread"，而其它线程都是 "Waiting Thread"，分别在两个队列 " Entry Set"和 "Wait Set"里面等候。在 "Entry Set"中等待的线程状态是 "Waiting for monitor entry"，而在 "Wait Set"中等待的线程状态是 "in Object.wait()"

## 2 举例说明 ##

### 2.1 blocked 的例子 ###

![b3b5e5628a154f1885b33816e2a293de.jpeg][]

程序先输出main,在输出thread，说明mian的线程是先获得同步锁的

执行jstack pid输出信息如下：

![0f712009e71f43558c824b787cc37cf2.jpeg][]

![74acb23e4e224c2b8fe70e9a80234bc8.jpeg][]

可以看到thread1在进行等待获取到锁，此时进入waiting for monitor entry，并是阻塞状态。

而main线程提前获取到锁，当由于调用了sleep此时进入到Timed\_waiting状态，此时man线程锁住的对象地址是7f3167cf0，而thread1正在等待获取这个锁对象。

prio：线程的优先级

tid：线程id

nid：操作系统映射的线程id, 非常关键，后面再使用jstack时补充

1103e9000和106692000 ：表示线程栈的起始地址。

从jstack日志中，可以看到：主线程获取到thread2对象上的锁，因此正在执行sleep操作，状态为TIMED\_WAINTING, 而thread2由于未获取到thread2对象上的锁，因此处于BLOCKED状态。

再细看，thread2 正在"waiting to lock <7f3167cf0>"，即试图在地址为7f3167cf0所在的对象获取锁，而该锁却被main线程占有（locked <7f3167cf0>）。main线程正在"waiting on condition"，说明正在等待某个条件触发，由jstacktrace来看，此线程正在sleep。

**经验：**

如果在jstack日志发现大量的线程在waiting to lock 某个地址，只要能查到哪个线程获取到锁就可以方便定位问题了

### 2.2 object.wait() ###

public static void main(String[] args) {
    
            final Thread thread = new Thread() {
    
                @Override
    
                public void run() {
    
                    synchronized (this) {
    
                        System.out.println(Thread.currentThread().getName());
    
                        try {
    
                            wait();
    
                        } catch (InterruptedException e) {
    
                            // TODO Auto-generated catch block
    
                            e.printStackTrace();
    
                        }
    
                    }
    
                }
    
            };
    
            thread.start();
    
            thread.setName("zouxh");//起名字，方便在线程栈里面进行查看
    
            try {
    
                TimeUnit.SECONDS.sleep(3);
    
            } catch (InterruptedException e) {
    
                // TODO Auto-generated catch block
    
                e.printStackTrace();
    
            }
    
            synchronized (thread) {
    
                System.out.println(Thread.currentThread().getName());
    
                try {
    
                    TimeUnit.SECONDS.sleep(30);
    
                } catch (InterruptedException e) {
    
                    // TODO Auto-generated catch block
    
                    e.printStackTrace();
    
                }
    
                thread.notify();
    
            }
    
        }

执行后，查看jstack的日志如下：

"zouxh" prio=5 tid=7fe18c97b800 nid=0x115e58000 in Object.wait() \[115e57000\]

java.lang.Thread.State: WAITING (on object monitor)

at java.lang.Object.wait(Native Method)

\- waiting on <7f3112fe8> (a jstat.MainWati$1)

at java.lang.Object.wait(Object.java:485)

at jstat.MainWati$1.run(MainWati.java:16)

\- locked <7f3112fe8> (a jstat.MainWati$1)

"main" prio=5 tid=7fe18c000800 nid=0x10c47b000

waiting on condition \[10c47a000\]

java.lang.Thread.State: TIMED\_WAITING (sleeping)

at java.lang.Thread.sleep(Native Method)

at java.lang.Thread.sleep(Thread.java:300)

at java.util.concurrent.TimeUnit.sleep(TimeUnit.java:328)

at jstat.MainWati.main(MainWati.java:37)

\- locked <7f3112fe8> (a jstat.MainWati$1)

可以看到由于调用了object.wait()方法的时候放弃了锁，所以zouxh这个线程就出现了object.wait()状态，线程的状态就是waiting，等待notify来进行唤醒。

由于mian线程在获得zouxh的线程锁后，调用了sleep方法，所以此时进入了wating on condition等待某一个资源，进入到time\_waiting状态。

### 2.3 waiting on conditon ###

private static BlockingQueue<String> blockingQueue = new ArrayBlockingQueue<String>(1);
    
        public static void main(String[] args) {
    
            blockingQueue.add("zouxh");
    
            try {
    
                //阻塞的添加
    
                blockingQueue.put("ssss");
    
            } catch (InterruptedException e) {
    
                // TODO Auto-generated catch block
    
                e.printStackTrace();
    
            }
    
        }

线程栈如下：

"main" prio=5 tid=7f8f65000800 nid=0x10d7bb000 waiting on condition \[10d7ba000\]

java.lang.Thread.State: WAITING (parking)

at sun.misc.Unsafe.park(Native Method)

\- parking to wait for <7f3110d80> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)

at java.util.concurrent.locks.LockSupport.park(LockSupport.java:156)

at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:1987)

at java.util.concurrent.ArrayBlockingQueue.put(ArrayBlockingQueue.java:257)

at jstat.WatingTest.main(WatingTest.java:13)

此时main线程进入了waiting on conditon状态，等待某一个资源，此时可以看到是在

a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObjec进行了等待，阻塞住了，这是由于put发生了阻塞。

## 3 总结 ##

对于jstack日志，我们要着重关注如下关键信息

**Deadlock**：表示有死锁

**Waiting on condition**：等待某个资源或条件发生来唤醒自己。具体需要结合jstacktrace来分析，比如线程正在sleep，网络读写繁忙而等待

**Blocked**：阻塞

**Waiting on monitor entry**：在等待获取锁

如果说系统慢，那么要特别关注**Blocked,Waiting on condition**

如果说系统的cpu耗的高，那么肯定是线程执行有死循环，那么此时要关注下**Runable**状态。

[bdb38126ea5b40d1bb7b4e909f1cf2bf.jpeg]: https://img-blog.csdnimg.cn/img_convert/bdb38126ea5b40d1bb7b4e909f1cf2bf.jpeg
[b3b5e5628a154f1885b33816e2a293de.jpeg]: https://img-blog.csdnimg.cn/img_convert/b3b5e5628a154f1885b33816e2a293de.jpeg
[0f712009e71f43558c824b787cc37cf2.jpeg]: https://img-blog.csdnimg.cn/img_convert/0f712009e71f43558c824b787cc37cf2.jpeg
[74acb23e4e224c2b8fe70e9a80234bc8.jpeg]: https://img-blog.csdnimg.cn/img_convert/74acb23e4e224c2b8fe70e9a80234bc8.jpeg