Java问题定位之Java线程堆栈分析

淩亂°似流年 2022-04-22 10:15 221阅读 0赞

# Java问题定位之Java线程堆栈分析 #

置顶 2016年11月22日 16:14:51 [weiweicao0429][] 阅读数：9737 标签： [java][][jdk][][栈][Link 1][内存溢出][Link 2][性能][Link 3] 更多

个人分类： [java开发][java 1][性能测试][Link 4][linux][]

采用Java开发的大型应用系统越来越大，越来越复杂，很多系统集成在一起，整个系统看起来像个黑盒子。系统运行遭遇问题（系统停止响应，运行越来越慢，或者性能低下，甚至系统宕掉），如何速度命中问题的根本原因是我们接下来讲的目的。本系列文章将Java问题定位的方法体系化，提供一种以黑盒子方式进行问题定位的思路：如何使用线程堆栈进行性能瓶颈分析？如何分析内存泄漏？如何分析系统挂死？

## 目录 ##

*  总述
 *  如何输出线程堆栈？
 *  如何解读线程堆栈？
    
     *  线程的解读
     *  锁的解读
     *  线程状态的解读

## 总述 ##

什么是线程堆栈？线程堆栈也称线程调用堆栈，是虚拟机中线程（包括锁）状态的一个瞬间快照，即系统在某一个时刻所有线程的运行状态，包括每一个线程的调用堆栈，锁的持有情况。虽然不同的虚拟机打印出来的格式有些不同，但是线程堆栈的信息都包含：

1、线程名字，id，线程的数量等。

2、线程的运行状态，锁的状态（锁被哪个线程持有，哪个线程在等待锁等）

3、调用堆栈（即函数的调用层次关系）调用堆栈包含完整的类名，所执行的方法，源代码的行数。

借助堆栈信息可以帮助分析很多问题，如线程死锁，锁争用，死循环，识别耗时操作等等。在多线程场合下的稳定性问题分析和性能问题分析，线程堆栈分析湿最有效的方法，在多数情况下，无需对系统了解就可以进行相应的分析。

由于线程堆栈是系统某个时刻的线程运行状况（即瞬间快照），对于历史痕迹无法追踪。只能结合日志分析。总的来说线程堆栈是多线程类应用程序非功能型问题定位的最有效手段，最善于分析如下类型问题：

*  系统无缘无故的cpu过高
 *  系统挂起，无响应
 *  系统运行越来越慢
 *  性能瓶颈（如无法充分利用cpu等）
 *  线程死锁，死循环等
 *  由于线程数量太多导致的内存溢出（如无法创建线程等）

借助线程堆栈可以帮助我们缩小范围，找到突破口。线程堆栈分析很多时候不需要源代码，在很多场合都有优势。下面我们就开始我们的线程堆栈之旅。

## 如何输出线程堆栈？ ##

Java虚拟机提供了线程转储（thread dump）的后门，通过这个后门可以把线程堆栈打印出来。通常我们将堆栈信息重定向到一个文件中，便于我们分析，由于信息量太大，很可能超出控制台缓冲区的最大行数限制造成信息丢失。这里介绍一个jdk自带的打印线程堆栈的工具，jstack用于打印出给定的[Java][]进程ID或core file或远程调试服务的[Java][]堆栈信息。

示例：$jstack –l 23561 >> xxx.dump

命令 : $jstack \[option\] pid >> 文件

>>表示输出到文件尾部，实际运行中，往往一次dump的信息，还不足以确认问题，建议产生三次dump信息，如果每次dump都指向同一个问题，我们才确定问题的典型性。

## 如何解读线程堆栈？ ##

### 线程的解读 ###

如下面一段java源代码程序：

![Center][]

![53185999][]

通过上节的介绍的方法打印堆栈信息，我们只关注java用户线程，其他由虚拟机自动创建的，在实际分析中，只关心java用户线程即可。

1.  `"main" prio=1 tid=0x0805c988 nid=0xd28 runnable [0xfff65000..0xfff659c8]`
2.  `at java.lang.String.indexOf(String.java:1352)`
3.  `at java.io.PrintStream.write(PrintStream.java:460)`
4.  `- locked <0xc8bf87d8> (a java.io.PrintStream)`
5.  `at java.io.PrintStream.print(PrintStream.java:602)`
6.  `at MyTest.fun2(MyTest.java:16)`
7.  `- locked <0xc8c1a098> (a java.lang.Object)`
8.  `at MyTest.fun1(MyTest.java:8)`
9.  `- locked <0xc8c1a090> (a java.lang.Object)`
10. `at MyTest.main(MyTest.java:26)`

从上面的main线程看，线程堆栈里面的最直观的信息是当前线程的调用上下文，即从哪个函数调用到哪个函数（从下往上看），正执行到哪一类的哪一行，借助这些信息，我们就对当前系统正在做什么一目了然。

![Center 1][]

![53185999][]

另外，从main线程的堆栈中，有-locked<0xc8c1a090>(a java.lang.Object) 语句，这表示该线程已经占用了锁，其中0xc8c1a090表示锁ID，这个锁ID是系统自动生成的，我们只需要知道每次打印堆栈，同一个ID表示是同一个锁即可

![Center 2][]

![53185999][]

其中"线程对应的本地线程Id号"所指的本地线程是指该java虚拟机所对应的虚拟机中的本地线程，我们知道java是解析型语言，执行的实体是java虚拟机，因此java代码是依附于java虚拟机的本地线程执行的，之前文章中讲过，当启动一个线程时，是创建一个native本地线程，本地线程才是真实的线程实体，为了更加深入理解本地线程和java线程的关系，我们可以通过以下方式将java虚拟机的本地线程打印出来：

1、试用ps -ef|grep java  获得java进行id

2、试用pstack<java pid> 获得java虚拟机本地线程的堆栈

从操作系统打印出来的虚拟机的本地线程看，本地线程数量和java线程数量是相同的，说明二者是一一对应的关系。

我们获取的本地线程堆栈如下：

![Center 3][]

这个本地线程号如何与java线程堆栈文件对应起来呢，每一个线程都有tid,nid的属性，通过这些属性可以对应相应的本地线程，我们先看java线程第一行，里面有一个属性是nid，

main" prio=1 tid=0x0805c988 nid=0xd28 runnable [0xfff65000..0xfff659c8]

其中nid是native thread id，也就是本地线程中的LWPID,二者是相同的，只不过java线程中的nid用16进制表示，本地线程的id用十进制表示。3368的十六进制表示0xd28，在java线程堆栈中查找nid为0xd28就是本地线程对应的java线程。

![Center 4][]

### 锁的解读 ###

在介绍线程堆栈的解读方法之前，先介绍一点关于多线程的知识，即wait和sleep的重要区别。wait和sleep有一个共同点，就是二者都把当前线程阻塞住，我们叫睡眠或等待，二者有着本质区别：

*  wait（）  当线程执行到wait（）方法上，当前线程会释放监视锁，此时其他线程可以占有该锁，一旦wait()方法执行完成，当前线程继续持有该锁，直到执行完锁的作用域。结合notify()，可以实现两个线程之间的通信，一个线程可以通过这种方法通知另一个线程继续执行，完成线程之间的配合。wait()锁的示意图

![Center 5][]

在wait（5000）这个期间，当前线程会释放它占用的锁，其他线程有机会获得到该锁，当wait（5000）结束后，当前线程继续获取该锁的使用权。满足以下条件之一，wait退出：

1、达到等待时间之后，自动退出

2、其他线程调用了该锁的notify方法，如果多个线程在等待同一个锁，只有一个线程会被通知到。

*  sleep() 和锁操作无关，如果该方法恰好在一个锁的保护范围内，当前线程即使执行sleep的时候，仍然保持监视锁。

![Center 6][]

sleep方法是线程的一个静态方法，实际上和锁操作无关，不会产生特别的锁，如果原来持有，现在仍然持有，如果原来没有，现在仍然没有。

从上面介绍的线程堆栈看，线程堆栈中包含直接信息为：线程个数，每个线程调用的方法堆栈，当前锁的状态。从线程个数可以直接数出来，线程调用的方法堆栈，从下向上看，表示了当前线程调用哪个类哪个方法，锁的状态看起来需要一些技巧，与锁相关的重要信息如下：

*  当一个线程占有一个锁的时候，线程堆栈会打印一个－locked<0x22bffb60>
 *  当一个线程正在等在其他线程释放该锁，线程堆栈会打印一个－waiting to lock<0x22bffb60>
 *  当一个线程占有一个锁，但又执行在该锁的wait上，线程堆栈中首先打印locked,然后打印－waiting on <0x22c03c60>

在线程堆栈中与锁相关的三个最重要的特征字：locked,waiting to lock,waiting on 了解这三个特征字，就可以对锁进行分析了。

一般情况下，当一个或一些线程正在等待一个锁的时候，应该有一个线程占用了这个锁，即如果有一个线程正在等待一个锁，该锁必然被另一个线程占用，从线程堆栈中看，如果看到waiting to lock<0x22bffb60>,应该也应该有locked<0x22bffb60>,大多数情况下确实如此，但是有些情况下，会发现线程堆栈中可能根本没有locked<0x22bffb60>,而只有waiting to ，这是什么原因呢，实际上，在一个线程释放锁和另一个线程被唤醒之间有一个时间窗，如果这个期间，恰好打印堆栈信息，那么只会找到waiting to ，但是找不到locked 该锁的线程，当然不同的JAVA虚拟机有不同的实现策略，不一定会立刻响应请求，也许会等待正在执行的线程执行完成。

### 线程状态的解读 ###

借助线程堆栈信息，可以分析很多问题，其中cpu的消耗分析也是线程堆栈分析的一个重要内容。

java线程状态有以下几类：

*  RUNNABLE 从虚拟机的角度看，线程正在运行状态。

处于RUNNABLE状态的线程是不是一定会消耗cpu呢，不一定，像socket IO操作，线程正在从网络上读取数据，尽管线程状态RUNNABLE，但实际上网络io，线程绝大多数时间是被挂起的，只有当数据到达后，线程才会被唤起，挂起发生在本地代码（native）中，虚拟机根本不一致，不像显式的调用sleep和wait方法，虚拟机才能知道线程的真正状态，但在本地代码中的挂起，虚拟机无法知道真正的线程状态，因此一概显示为RUNNABLE。

![Center 7][]

*  TIMED\_WAITING(on object monitor)表示当前线程被挂起一段时间，说明该线程正在执行obj.wait(ing time)方法，该线程不消耗cpu。

![Center 8][]

*  TIMED\_WAITING(sleeping) 表示当前线程被挂起一段时间，正在执行Thread.sleep(int time )方法，如：

![Center 9][]

*  WAITING(on object monitor)当前线程被挂起，正在执行无参数的obj.wait()方法，只能通过notify唤醒，因此不消耗cpu

![Center 10][]

总结：

*  处于timed\_waiting,waiting状态的线程一定不消耗cpu，处于runnable状态的线程不一定会消耗cpu，要结合当前线程代码的性质判断，是否消耗cpu
 *  如果是纯java运算代码，则消耗cpu
 *  如果网络io，很少消耗cpu
 *  如果是本地代码，集合本地代码的性质，可以通过pstack获取本地的线程堆栈，如果是纯运算代码，则消耗cpu，如果被挂起，则不消耗，如果是io，则不怎么消耗cpu。

[weiweicao0429]: https://me.csdn.net/weiweicao0429
[java]: http://so.csdn.net/so/search/s.do?q=java&t=blog
[jdk]: http://so.csdn.net/so/search/s.do?q=jdk&t=blog
[Link 1]: http://so.csdn.net/so/search/s.do?q=%E6%A0%88&t=blog
[Link 2]: http://so.csdn.net/so/search/s.do?q=%E5%86%85%E5%AD%98%E6%BA%A2%E5%87%BA&t=blog
[Link 3]: http://so.csdn.net/so/search/s.do?q=%E6%80%A7%E8%83%BD&t=blog
[java 1]: https://blog.csdn.net/weiweicao0429/article/category/1739043
[Link 4]: https://blog.csdn.net/weiweicao0429/article/category/1423183
[linux]: https://blog.csdn.net/weiweicao0429/article/category/1824975
[Java]: http://lib.csdn.net/base/17
[Center]: /images/20220422/80aed9b5bb16427a9adf41120344a6ad.png
[53185999]: /images/20220422/c88968ac938c4001b714b9ad582ff9de.png
[Center 1]: /images/20220422/383256fb30f441ab8ce9b4c0c9fa3c2a.png
[Center 2]: /images/20220422/13a44445b5b24d9bbd9341fada08e9d9.png
[Center 3]: /images/20220422/6002a1175bbb45a3a1a9a93ca6e2a6b4.png
[Center 4]: /images/20220422/a02255f25cc84e85aa3938325e323ffb.png
[Center 5]: /images/20220422/a392e3b3325e4673ba9b1b751e8efb95.png
[Center 6]: /images/20220422/ad2ab1d4e56d4da694c3e7a64db29e08.png
[Center 7]: /images/20220422/444487eb4fe44a7081dd22e1a83c73b4.png
[Center 8]: /images/20220422/1158943ef3db497c906683c313dda23e.png
[Center 9]: /images/20220422/a059ad7ae29443c1ade8fa64b547e1fc.png
[Center 10]: /images/20220422/da6f3903e7cb4ef7a4ec7138f35b19ed.png