Jstack来判断死循环、线程等待、死锁、IO等待情况

介绍

上一篇介绍了jstack基本用法，在一篇里将对具体的几种情况进行演示和分析。

死循环

示例代码

package jstack;

public class Demo1 {
	public static void loop() {
		while (true) {
		}
	}
	public static void main(String[] args) {
		loop();
	}
}

编译，运行，用jstack输出结果，参考上篇操作（下同）。

这里主要是观测结果，分析结果。
省去上篇里介绍的一些通用线程（下同）。
选出的main函数的调用栈，如下：

"main" #1 prio=5 os_prio=0 tid=0x000000000215d800 nid=0x1224 runnable [0x000000000251f000]
   java.lang.Thread.State: RUNNABLE
	at jstack.Demo1.loop(Demo1.java:5)
	at jstack.Demo1.main(Demo1.java:9)

在多次打出函数的调用栈时，可以发现程序一直在loop函数的第5行。从而在源代码中去查看相关代码，来诊断代码。

线程等待

示例代码

package jstack;

import java.util.concurrent.ExecutorService;
import java.util.concurrent.Executors;

public class Demo2 {
	public static void main(String[] args) {
		ExecutorService ex = Executors.newCachedThreadPool();
		ex.execute(new Runnable() {
			@Override
			public void run() {
				synchronized (this) {
					try {
						wait();
					} catch (InterruptedException e) {
						e.printStackTrace();
					}
				}
			}
		});
	}
}

线程进入同步块中后，调用wait等待通知。

jstack打印的结果为

"pool-1-thread-1" #10 prio=5 os_prio=0 tid=0x00000000585ff800 nid=0x40c in Object.wait() [0x00000000590cf000]
   java.lang.Thread.State: WAITING (on object monitor)
	at java.lang.Object.wait(Native Method)
	- waiting on <0x00000000d61e0e60> (a jstack.Demo2$1)
	at java.lang.Object.wait(Unknown Source)
	at jstack.Demo2$1.run(Demo2.java:14)
	- locked <0x00000000d61e0e60> (a jstack.Demo2$1)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
	at java.lang.Thread.run(Unknown Source)

可以看到线程在WAITING状态，等待的位置在jstack.Demo2$1,$1表示是一个匿名类，也就是程序中的第14行。

wait为什么要在synchronized里呢，不然会抛出IllegalMonitorStateException。
因为当前线程必须拥有此对象监视器。

死锁

所谓死锁，是指两个或两个以上的进程在执行过程中，因争夺资源而造成的一种互相等待的现象，若无外力作用，它们都将无法推进下去。

示例代码

package jstack;

public class DeadLockThreadDemo extends Thread {

	private Object lock1 = null;
	private Object lock2 = null;

	public DeadLockThreadDemo(Object lock1, Object lock2) {
		this.lock1 = lock1;
		this.lock2 = lock2;
	}

	@Override
	public void run() {
		System.out.println(Thread.currentThread().getName() + " info:  lock1->" + lock1 + ", lock2" + lock2);
		synchronized (lock1) {
			System.out.println(Thread.currentThread().getName() + " enter synchronized " + lock1);
			try {
				Thread.sleep(2000);
			} catch (InterruptedException e) {
				e.printStackTrace();
			}
			synchronized (lock2) {
				System.out.println(Thread.currentThread().getName() + "enter synchronized " + lock2);
				System.out.println("exec...");
			}
		}
	}
}

这是一个线程类。先获取到第一个锁，等待2秒，模拟线程执行，再获取第二个锁，再输出。

package jstack;

public class Demo3 {
	public static void main(String[] args) {
		Object lock1 = new Object();
		Object lock2 = new Object();
		new DeadLockThreadDemo(lock1, lock2).start();
		new DeadLockThreadDemo(lock2, lock1).start();
	}
}

这是执行函数，初始化的时候，按先后不同的顺序执行。

console输出的结果可能是

Thread-0 info:  lock1->java.lang.Object@43e8772d, lock2java.lang.Object@4d2f9120
Thread-0 enter synchronized java.lang.Object@43e8772d
Thread-1 info:  lock1->java.lang.Object@4d2f9120, lock2java.lang.Object@43e8772d
Thread-1 enter synchronized java.lang.Object@4d2f9120

可以看到线程0拿到43e8772d对象的锁。可以看到线程1拿到4d2f9120对象的锁。
但是互要对方手上的锁。这样就互相等待下去，形成死锁。

用jstack查看结果

"Thread-1" #11 prio=5 os_prio=0 tid=0x0000000058716800 nid=0xf30 waiting for monitor entry [0x00000000596ee000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at jstack.DeadLockThreadDemo.run(DeadLockThreadDemo.java:24)
	- waiting to lock <0x00000000d6257f40> (a java.lang.Object)
	- locked <0x00000000d6257f50> (a java.lang.Object)

"Thread-0" #10 prio=5 os_prio=0 tid=0x0000000058716000 nid=0x12e0 waiting for monitor entry [0x000000005945f000]
   java.lang.Thread.State: BLOCKED (on object monitor)
	at jstack.DeadLockThreadDemo.run(DeadLockThreadDemo.java:24)
	- waiting to lock <0x00000000d6257f50> (a java.lang.Object)
	- locked <0x00000000d6257f40> (a java.lang.Object)


Found one Java-level deadlock:
=============================
"Thread-1":
  waiting to lock monitor 0x0000000057095ce8 (object 0x00000000d6257f40, a java.lang.Object),
  which is held by "Thread-0"
"Thread-0":
  waiting to lock monitor 0x0000000057098628 (object 0x00000000d6257f50, a java.lang.Object),
  which is held by "Thread-1"

Java stack information for the threads listed above:
===================================================
"Thread-1":
	at jstack.DeadLockThreadDemo.run(DeadLockThreadDemo.java:24)
	- waiting to lock <0x00000000d6257f40> (a java.lang.Object)
	- locked <0x00000000d6257f50> (a java.lang.Object)
"Thread-0":
	at jstack.DeadLockThreadDemo.run(DeadLockThreadDemo.java:24)
	- waiting to lock <0x00000000d6257f50> (a java.lang.Object)
	- locked <0x00000000d6257f40> (a java.lang.Object)

Found 1 deadlock.

显示找到了一个死锁。

IO等待

示例代码

package jstack;

import java.io.IOException;

public class Demo4 {
	public static void main(String[] args) throws IOException {
        int i = System.in.read();
        System.out.println(i);
	}
}

用jstack输出

"main" #1 prio=5 os_prio=0 tid=0x000000000220e000 nid=0x890 runnable [0x00000000024de000]
   java.lang.Thread.State: RUNNABLE
	at java.io.FileInputStream.readBytes(Native Method)
	at java.io.FileInputStream.read(Unknown Source)
	at java.io.BufferedInputStream.fill(Unknown Source)
	at java.io.BufferedInputStream.read(Unknown Source)
	- locked <0x00000000d61597e0> (a java.io.BufferedInputStream)
	at jstack.Demo4.main(Demo4.java:7)

可以看到线程在运行中，但一直在readBytes的本地方法中。

参考

IllegalMonitorStateException on wait() call
正确理解线程等待和释放(wait/notify)
jstack简单使用
线上高CPU占用