Java Trouble Shooting - 使用线程栈
什么是线程栈(thread dump)
线程栈是某个时间点，JVM全部线程的活动状态的一个汇总；经过线程栈，能够查看某个时间点，各个线程正在作什么，一般使用线程栈来定位软件运行时的各类问题，例如 CPU 使用率特别高，或者是响应很慢，性能大幅度下滑。
线程栈包含了多个线程的活动信息，一个线程的活动信息一般看起来以下所示：java
"main" prio=10 tid=0x00007faac0008800 nid=0x9f0 waiting on condition [0x00007faac6068000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at ThreadDump.main(ThreadDump.java:4)
这条线程的线程栈信息包含了如下这些信息：linux
- 线程的名字：其中 main 就是线程的名字，须要注意的是，当使用
Thread类来建立一条线程，而且没有指定线程的名字时，这条线程的命名规则为 Thread-i，i 表明数字。若是使用ThreadFactory来建立线程，则线程的命名规则为 pool-i-thread-j，i 和 j 分别表明数字。 - 线程的优先级：prio=10 表明线程的优先级为 10
- 线程 id：tid=0x00007faac0008800 表明线程 id 为 0x00007faac0008800，而 nid=0x9f0 表明该线程对应的操做系统级别的线程 id。所谓的 nid，换种说法就是 native id。在操做系统中，分为内核级线程和用户级线程，JVM 的线程是用户态线程，内核不知情，但每一条 JVM 的线程都会映射到操做系统一条具体的线程
- 线程的状态：java.lang.Thread.State: TIMED_WAITING (sleeping) 以及 waiting on condition 表明线程当前的状态
- 线程占用的内存地址：[0x00007faac6068000] 表明当前线程占用的内存地址
- 线程的调用栈：at java.lang.Thread.sleep(Native Method)* 以及它以后的相相似的信息，表明线程的调用栈
回顾线程状态
- NEW：线程初建立，未运行
- RUNNABLE：线程正在运行，但不必定消耗 CPU
- BLOCKED：线程正在等待另一个线程释放锁
- WAITING：线程执行了
wait, join, park方法 - TIMED_WAITING：线程调用了
sleep, wait, join, park方法，与 WAITING 状态不一样的是，这些方法带有表示时间的参数。
例如如下代码：算法
public static void main(String[] args) throws InterruptedException {
int sum = 0;
while (true) {
int i = 0;
int j = 1;
sum = i + j;
}
}
main 线程对应的线程栈就是数据库
"main" prio=10 tid=0x00007fe1b4008800 nid=0x1292 runnable [0x00007fe1bd88f000]
java.lang.Thread.State: RUNNABLE
at ThreadDump.main(ThreadDump.java:7)
其状态为 RUNNABLE微信
若是是如下代码，两个线程会竞争同一个锁，其中只有一个线程能得到锁，而后进行 sleep(time)，从而进入 TIMED_WAITING 状态，另一个线程因为等待锁，会进入 BLOCKED 状态。ide
public static void main(String[] args) throws InterruptedException {
Thread t1 = new Thread(new Runnable() {
@Override
public void run() {
try {
fun1();
} catch (InterruptedException e) {
e.printStackTrace();
}
}
});
t1.setDaemon(false);
t1.setName("MyThread1");
Thread t2 = new Thread(new Runnable() {
@Override
public void run() {
try {
fun2();
} catch (InterruptedException e) {
e.printStackTrace();
}
}
});
t2.setDaemon(false);
t2.setName("MyThread2");
t1.start();
t2.start();
*/
}
private static synchronized void fun1() throws InterruptedException {
System.out.println("t1 acquire");
Thread.sleep(Integer.MAX_VALUE);
}
private static synchronized void fun2() throws InterruptedException {
System.out.println("t2 acquire");
Thread.sleep(Integer.MAX_VALUE);
}
对应的线程栈为：工具
"MyThread2" prio=10 tid=0x00007ff1e40b1000 nid=0x12eb waiting for monitor entry [0x00007ff1e07f6000]
java.lang.Thread.State: BLOCKED (on object monitor)
at ThreadDump.fun2(ThreadDump.java:45)
- waiting to lock <0x00000000eb8602f8> (a java.lang.Class for ThreadDump)
at ThreadDump.access$100(ThreadDump.java:1)
at ThreadDump$2.run(ThreadDump.java:25)
at java.lang.Thread.run(Thread.java:745)
"MyThread1" prio=10 tid=0x00007ff1e40af000 nid=0x12ea waiting on condition [0x00007ff1e08f7000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at ThreadDump.fun1(ThreadDump.java:41)
- locked <0x00000000eb8602f8> (a java.lang.Class for ThreadDump)
at ThreadDump.access$000(ThreadDump.java:1)
at ThreadDump$1.run(ThreadDump.java:10)
at java.lang.Thread.run(Thread.java:745)
能够看到，t1 线程的调用栈里有这么一句 - locked <0x00000000eb8602f8> (a java.lang.Class for ThreadDump)，说明它得到了锁，而且进行 sleep(sometime) 操做，所以状态为 TIMED_WAITING。而 t2 线程因为获取不到锁，因此在它的调用栈里能看到 - waiting to lock <0x00000000eb8602f8> (a java.lang.Class for ThreadDump)，说明它正在等待锁，所以进入 BLOCKED 状态。性能
对于 WAITING 状态的线程栈，可使用如下代码来模拟制造：ui
private static final Object lock = new Object();
public static void main(String[] args) throws InterruptedException {
synchronized (lock) {
lock.wait();
}
}
获得的线程栈为：this
"main" prio=10 tid=0x00007f1fdc008800 nid=0x13fe in Object.wait() [0x00007f1fe1fec000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000eb860640> (a java.lang.Object)
at java.lang.Object.wait(Object.java:503)
at ThreadDump.main(ThreadDump.java:7)
- locked <0x00000000eb860640> (a java.lang.Object)
如何输出线程栈
因为线程栈反映的是 JVM 在某个时间点的线程状态，所以分析线程栈时，为避免偶然性，有必要多输出几份进行分析。如下以 HOT SPOT JVM 为例，首先能够经过如下两种方式获得 JVM 的进程 ID。
-
jps 命令
[root@localhost ~]# jps 5163 ThreadDump 5173 Jps
-
ps -ef | grep java
[root@localhost ~]# ps -ef | grep java root 5163 2479 0 01:18 pts/0 00:00:00 java ThreadDump root 5185 2553 0 01:18 pts/1 00:00:00 grep --color=auto java
接下来经过 JDK 自带的 jstack 命令
[root@localhost ~]# jstack 5163
2017-04-21 01:19:41
Full thread dump Java HotSpot(TM) 64-Bit Server VM (24.79-b02 mixed mode):
"Attach Listener" daemon prio=10 tid=0x00007f72b8001000 nid=0x144c waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Service Thread" daemon prio=10 tid=0x00007f72d4095000 nid=0x1433 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread1" daemon prio=10 tid=0x00007f72d4092800 nid=0x1432 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"C2 CompilerThread0" daemon prio=10 tid=0x00007f72d4090000 nid=0x1431 waiting on condition [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Signal Dispatcher" daemon prio=10 tid=0x00007f72d408e000 nid=0x1430 runnable [0x0000000000000000]
java.lang.Thread.State: RUNNABLE
"Finalizer" daemon prio=10 tid=0x00007f72d4065000 nid=0x142f in Object.wait() [0x00007f72d9b83000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000eb804858> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:135)
- locked <0x00000000eb804858> (a java.lang.ref.ReferenceQueue$Lock)
at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:151)
at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:209)
"Reference Handler" daemon prio=10 tid=0x00007f72d4063000 nid=0x142e in Object.wait() [0x00007f72d9c84000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000eb804470> (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 <0x00000000eb804470> (a java.lang.ref.Reference$Lock)
"main" prio=10 tid=0x00007f72d4008800 nid=0x142c in Object.wait() [0x00007f72dc971000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
- waiting on <0x00000000eb860620> (a java.lang.Object)
at java.lang.Object.wait(Object.java:503)
at ThreadDump.main(ThreadDump.java:7)
- locked <0x00000000eb860620> (a java.lang.Object)
"VM Thread" prio=10 tid=0x00007f72d405e800 nid=0x142d runnable
"VM Periodic Task Thread" prio=10 tid=0x00007f72d40a0000 nid=0x1434 waiting on condition
JNI global references: 107
便可将线程栈输出到控制台。若输出信息过多，在控制台上不方便分析，则能够将输出信息重定向到文件中，以下所示：
jstack 5163 > thread.stack
若系统中没有 jstack 命令，由于 jstack 命令是 JDK 带的，而有的环境只安装了 JRE 环境。则能够用 kill -3 命令来代替，kill -3 pid。Java虚拟机提供了线程转储(Thread dump)的后门， 经过这个后门， 能够将线程堆栈打印出来。 这个后门就是经过向Java进程发送一个QUIT信号， Java虚拟机收到该信号以后， 将系
统当前的JAVA线程调用堆栈打印出来。
如果有运行图形界面的环境，也可使用一些图形化的工具，例如 JVisualVM 来生成线程栈文件。
使用线程栈定位问题
发现死锁
当两个或多个线程正在等待被对方占有的锁， 死锁就会发生。 死锁会致使两个线程没法继续运行， 被永远挂起。
如下代码会产生死锁
/**
*
*
* @author beanlam
* @version 1.0
*
*/
public class ThreadDump {
public static void main(String[] args) throws InterruptedException {
Object lock1 = new Object();
Object lock2 = new Object();
new Thread1(lock1, lock2).start();
new Thread2(lock1, lock2).start();
}
private static class Thread1 extends Thread {
Object lock1 = null;
Object lock2 = null;
public Thread1(Object lock1, Object lock2) {
this.lock1 = lock1;
this.lock2 = lock2;
this.setName(getClass().getSimpleName());
}
public void run() {
synchronized (lock1) {
try {
Thread.sleep(2);
} catch(Exception e) {
e.printStackTrace();
}
synchronized (lock2) {
}
}
}
}
private static class Thread2 extends Thread {
Object lock1 = null;
Object lock2 = null;
public Thread2(Object lock1, Object lock2) {
this.lock1 = lock1;
this.lock2 = lock2;
this.setName(getClass().getSimpleName());
}
public void run() {
synchronized (lock2) {
try {
Thread.sleep(2);
} catch(Exception e) {
e.printStackTrace();
}
synchronized (lock1) {
}
}
}
}
}
对应的线程栈是
"Thread2" prio=10 tid=0x00007f9bf40a1000 nid=0x1472 waiting for monitor entry [0x00007f9bf8944000]
java.lang.Thread.State: BLOCKED (on object monitor)
at ThreadDump$Thread2.run(ThreadDump.java:63)
- waiting to lock <0x00000000eb860498> (a java.lang.Object)
- locked <0x00000000eb8604a8> (a java.lang.Object)
"Thread1" prio=10 tid=0x00007f9bf409f000 nid=0x1471 waiting for monitor entry [0x00007f9bf8a45000]
java.lang.Thread.State: BLOCKED (on object monitor)
at ThreadDump$Thread1.run(ThreadDump.java:38)
- waiting to lock <0x00000000eb8604a8> (a java.lang.Object)
- locked <0x00000000eb860498> (a java.lang.Object)
Found one Java-level deadlock:
=============================
"Thread2":
waiting to lock monitor 0x00007f9be4004f88 (object 0x00000000eb860498, a java.lang.Object),
which is held by "Thread1"
"Thread1":
waiting to lock monitor 0x00007f9be40062c8 (object 0x00000000eb8604a8, a java.lang.Object),
which is held by "Thread2"
Java stack information for the threads listed above:
===================================================
"Thread2":
at ThreadDump$Thread2.run(ThreadDump.java:63)
- waiting to lock <0x00000000eb860498> (a java.lang.Object)
- locked <0x00000000eb8604a8> (a java.lang.Object)
"Thread1":
at ThreadDump$Thread1.run(ThreadDump.java:38)
- waiting to lock <0x00000000eb8604a8> (a java.lang.Object)
- locked <0x00000000eb860498> (a java.lang.Object)
Found 1 deadlock.
能够看到，当发生了死锁的时候，堆栈中直接打印出了死锁的信息 Found one Java-level deadlock: ，并给出了分析信息。
要避免死锁的问题， 惟一的办法是修改代码。死锁可能会致使整个系统的瘫痪， 具体的严重程度取决于这些线程执行的是什么性质的功能代码， 要想恢复系统， 临时也是惟一的规避办法是将系统重启。
定位 CPU 太高的缘由
首先须要借助操做系统提供的一些工具，来定位消耗 CPU 太高的 native 线程。不一样的操做系统，提供的不一样的 CPU 统计命令以下所示：
| 操做系统 | solaris | linux | aix |
|---|---|---|---|
| 命令名称 | prstat -L <pid> | top -p <pid> | ps -emo THREAD |
以 Linux 为例，首先经过 top -p <pid> 输出该进程的信息，而后输入 H，查看全部的线程的统计状况。
top - 02:04:54 up 2:43, 3 users, load average: 0.10, 0.05, 0.05 Threads: 13 total, 0 running, 13 sleeping, 0 stopped, 0 zombie %Cpu(s): 97.74 us, 0.2 sy, 0.0 ni, 2.22 id, 0.0 wa, 0.0 hi, 0.0 si, 0.0 st KiB Mem: 1003456 total, 722012 used, 281444 free, 0 buffers KiB Swap: 2097148 total, 62872 used, 2034276 free. 68880 cached Mem PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND 3368 zmw2 25 0 256m 9620 6460 R 93.3 0.7 5:42.06 java 3369 zmw2 15 0 256m 9620 6460 S 0.0 0.7 0:00.00 java 3370 zmw2 15 0 256m 9620 6460 S 0.0 0.7 0:00.00 java 3371 zmw2 15 0 256m 9620 6460 S 0.0 0.7 0:00.00 java 3372 zmw2 15 0 256m 9620 6460 S 0.0 0.7 0:00.00 java 3373 zmw2 15 0 256m 9620 6460 S 0.0 0.7 0:00.00 java 3374 zmw2 15 0 256m 9620 6460 S 0.0 0.7 0:00.00 java 3375 zmw2 15 0 256m 9620 6460 S 0.0 0.7 0:00.00 java
这个命令输出的 PID 表明的是 native 线程的 id，如上所示，id 为 3368 的 native 线程消耗 CPU 最高。在Java Thread Dump文件中， 每一个线程都有tid=...nid=...的属性， 其中nid就是native thread id， 只不过nid中用16进制来表示。 例如上面的例子中3368的十六进制表示为0xd28.在Java线程中查找nid=0xd28便是本地线程对应Java线程。
"main" prio=1 tid=0x0805c988 nid=0xd28 runnable [0xfff65000..0xfff659c8] at java.lang.String.indexOf(String.java:1352) at java.io.PrintStream.write(PrintStream.java:460) - locked <0xc8bf87d8> (a java.io.PrintStream) at java.io.PrintStream.print(PrintStream.java:602) at MyTest.fun2(MyTest.java:16) - locked <0xc8c1a098> (a java.lang.Object) at MyTest.fun1(MyTest.java:8) - locked <0xc8c1a090> (a java.lang.Object) at MyTest.main(MyTest.java:26)
致使 CPU 太高的缘由有如下几种缘由：
- Java 代码死循环
- Java 代码使用了复杂的算法，或者频繁调用
- JVM 自身的代码致使 CPU 很高
若是在Java线程堆栈中找到了对应的线程ID,而且该Java线程正在执行Native code,说明致使CPU太高的问题代码在JNI调用中，此时须要打印出 Native 线程的线程栈，在 linux 下，使用 pstack <pid> 命令。
若是在 native 线程堆栈中能够找到对应的消耗 CPU 太高的线程 id，能够直接定位为 native 代码的问题。
可是有可能在 native 线程堆栈中找不到对应的消耗 CPU 太高的线程 id，这多是由于 JNI 调用中从新建立的线程来执行， 那么在 Java 线程堆栈中就不存在该线程的信息，也有多是虚拟机自身代码致使的 CPU 太高， 如堆内存使用太高致使的频繁 FULL GC ，或者 JVM 的 Bug。
定位性能降低缘由
性能降低通常是因为资源不足所致使。若是资源不足， 那么有大量的线程在等待资源， 打印的线程堆栈若是发现大量的线程停在一样的调用上下文上， 那么就说明该系统资源是瓶颈。
致使资源不足的缘由可能有：
- 资源数量配置太少（ 如链接池链接配置过少等）， 而系统当前的压力比较大， 资源不足致使了某些线程不能及时得到资源而等待在那里(即挂起)
- 得到资源的线程把持资源时间过久， 致使资源不足，例如如下代码：
void fun1() {
Connection conn = ConnectionPool.getConnection();//获取一个数据库链接
//使用该数据库链接访问数据库
//数据库返回结果，访问完成
//作其它耗时操做,但这些耗时操做数据库访问无关，
conn.close(); //释放链接回池
}
- 设计不合理致使资源占用时间太久， 如SQL语句设计不恰当， 或者没有索引致使的数据库访问太慢等。
- 资源用完后， 在某种异常状况下， 没有关闭或者回池， 致使可用资源泄漏或者减小， 从而致使资源竞争。
定位系统假死缘由
致使系统挂死的缘由有不少， 其中有一个最多见的缘由是线程挂死。每次打印线程堆栈， 该线程必然都在同一个调用上下文上， 所以定位该类型的问题原理是，经过打印屡次堆栈， 找出对应业务逻辑使用的线程， 经过对比先后打印的堆栈确认该线程执行的代码段是否一直没有执行完成。 经过打印屡次堆栈， 找到挂起的线程（ 即不退出）。
致使线程没法退出的缘由可能有：
- 线程正在执行死循环的代码
- 资源不足或者资源泄漏， 形成当前线程阻塞在锁对象上（ 即wait在锁对象上）， 长期得不到唤醒(notify)。
- 若是当前程序和外部通讯， 当外部程序挂起无返回时， 也会致使当前线程挂起。
相关文章
- 1. Network trouble shooting
- 2. 无法使用UI configuration的trouble shooting
- 3. Ubuntu上Docker安装Trouble Shooting
- 4. split job 报错的trouble shooting过程
- 5. DTG and trouble shooting tools (更新中)
- 6. Linux 常见的trouble shooting故障排错
- 7. mysql trouble shooting---- 从库中止同步lock_wait_timeout_exceeded_try_restarting_transaction
- 8. Linux 操做系统启动流程以及trouble shooting
- 9. “举报”阿里巴巴 Arthas，大幅下降 OOM Trouble shooting 门槛
- 10. Trouble Shooting的一些感想（实时补充）
- 更多相关文章...
- • 在Java程序中使用Redis - Redis教程
- • TortoiseSVN 使用教程 - SVN 教程
- • Java 8 Stream 教程
- • Git可视化极简易教程 — Git GUI使用方法
相关标签/搜索
每日一句
-
每一个你不满意的现在，都有一个你没有努力的曾经。
欢迎关注本站公众号,获取更多信息
相关文章
- 1. Network trouble shooting
- 2. 无法使用UI configuration的trouble shooting
- 3. Ubuntu上Docker安装Trouble Shooting
- 4. split job 报错的trouble shooting过程
- 5. DTG and trouble shooting tools (更新中)
- 6. Linux 常见的trouble shooting故障排错
- 7. mysql trouble shooting---- 从库中止同步lock_wait_timeout_exceeded_try_restarting_transaction
- 8. Linux 操做系统启动流程以及trouble shooting
- 9. “举报”阿里巴巴 Arthas，大幅下降 OOM Trouble shooting 门槛
- 10. Trouble Shooting的一些感想（实时补充）