JAVA Thread Dump | 寿晨的博客

文章目录

1. 什么是 Thread Dump
2. Thread Dump 的特点
3. Thread Dump 能诊断的问题
4. 获取 Thread Dump
5. jstack Dump 日志文件中的线程状态
6. Thread Dump 信息
7. 案例分析

什么是 Thread Dump

Thread Dump 是非常有用的诊断 Java 应用问题的工具，每一个 Java虚拟机都有及时生成显示所有线程在某一点状态的 thread-dump 的能力。虽然各个 Java虚拟机thread dump 打印输出格式上略微有一些不同，但是 Thread dumps 出来的信息包含线程；线程的运行状态、标识和调用的堆栈；调用的堆栈包含完整的类名，所执行的方法，如果可能的话还有源代码的行数。

Thread Dump 的特点

能在各种操作系统下使用

能在各种 Java 应用服务器下使用

可以在生产环境下使用而不影响系统的性能

可以将问题直接定位到应用程序的代码行上

Thread Dump 能诊断的问题

查找内存泄露，常见的是程序里 load 大量的数据到缓存；

发现死锁线程；

获取 Thread Dump

在 Java 程序的运行会话中，使用下面方式：

Unix/Linux：CTRL-\

Windows：CTRL-BREAK

首先查找到服务器的进程号 (process id), 然后获取线程堆栈.
1. ps –ef | grep java
2. kill -3
  
  注意：一定要谨慎, 一步不慎就可能让服务器进程被杀死。kill -9 命令会杀死进程。
JVM 自带的工具获取线程堆栈:JDK 自带命令行工具获取 PID，再获取 ThreadDump:
1. jps 或 ps –ef|grepjava (获取 PID)
2. jstack [-l]<pid| tee -a jstack.log (获取 ThreadDump)
通过写 Java 程序获取了，提示一点，可以使用 JMX 来完成。
java.lang 域下有一个 Threading#dumpAllThreads(boolean, boolean) 方法，通过这个方法就可以直接拿到 ThreadDump 信息。
也可以使用 jconsole、jvisualvm、jprofile 来获取 ThreadDump 以及 HeapDump，并加以分析。当然了，如果你是一个 Java Developer，你也可以使用 Eclipse 提供的 Memory Analyzer Tool （MAT ）来替代这些工具。

jstack Dump 日志文件中的线程状态

死锁，Deadlock（重点关注）
执行中，Runnable
等待资源，Waiting on condition（重点关注）
等待获取监视器，Waiting on monitor entry（重点关注）
暂停，Suspended
对象等待中，Object.wait() 或 TIMED_WAITING
阻塞，Blocked（重点关注）
停止，Parked

含义如下所示：

Deadlock：死锁线程，一般指多个线程调用间，进入相互资源占用，导致一直等待无法释放的情况。
Runnable：一般指该线程正在执行状态中，该线程占用了资源，正在处理某个请求，有可能正在传递SQL到数据库执行，有可能在对某个文件操作，有可能进行数据类型等转换。
Waiting on condition：等待资源，或等待某个条件的发生。具体原因需结合 stacktrace 来分析。
如果堆栈信息明确是应用代码，则证明该线程正在等待资源。一般是大量读取某资源，且该资源采用了资源锁的情况下，线程进入等待状态，等待资源的读取。
又或者，正在等待其他线程的执行等。
如果发现有大量的线程都在处在 Wait on condition，从线程 stack 看，正等待网络读写，这可能是一个网络瓶颈的征兆。因为网络阻塞导致线程无法执行。
一种情况是网络非常忙，几乎消耗了所有的带宽，仍然有大量数据等待网络读写；
另一种情况也可能是网络空闲，但由于路由等问题，导致包无法正常的到达。
另外一种出现 Wait on condition 的常见情况是该线程在 sleep，等待 sleep 的时间到了时候，将被唤醒。
Blocked：线程阻塞，是指当前线程执行过程中，所需要的资源长时间等待却一直未能获取到，被容器的线程管理器标识为阻塞状态，可以理解为等待资源超时的线程。
Waiting for monitor entry 和 in Object.wait()：Monitor 是 Java 中用以实现线程之间的互斥与协作的主要手段，它可以看成是对象或者 Class 的锁。每一个对象都有，也仅有一个 monitor。从下图 1 中可以看出，每个 Monitor 在某个时刻，只能被一个线程拥有，该线程就是 “Active Thread”，而其它线程都是 “Waiting Thread”，分别在两个队列 “ Entry Set”和 “Wait Set”里面等候。在 “Entry Set”中等待的线程状态是 “Waiting for monitor entry”，而在 “Wait Set”中等待的线程状态是 “in Object.wait()”。

Thread Dump 信息

头部信息：2016-09-10 19:05:06
Full thread dump Java HotSpot(TM) Server VM (16.3-b01 mixed mode):
- 时间

- jvm 信息

线程 info信息块：”Timer-0” daemon prio=10tid=0xac190c00 nid=0xaef in Object.wait()[0xae77d000]
java.lang.Thread.State: TIMED_WAITING (on object monitor)
atjava.lang.Object.wait(Native Method)
-waiting on <0xb3885f60> (a java.util.TaskQueue) ### 继续 wait
atjava.util.TimerThread.mainLoop(Timer.java:509)
-locked <0xb3885f60> (a java.util.TaskQueue) ### 已经 locked
atjava.util.TimerThread.run(Timer.java:462)
- 线程名称：Timer-0
- 线程类型：daemon
- 优先级: 10，默认是 5
- jvm 线程 id：tid=0xac190c00，jvm 内部线程的唯一标识（通过 java.lang.Thread.getId() 获取，通常用自增方式实现。）
- 对应系统线程 id（NativeThread ID）：nid=0xaef，和 top 命令查看的线程 pid 对应，不过一个是 10 进制，一个是 16 进制。（通过命令：top -H -p pid，可以查看该进程的所有线程信息）
- 线程状态：in Object.wait().
- 起始栈地址：[0xae77d000]
- Java thread statck trace：是上面 2-7 行的信息。到目前为止这是最重要的数据，Java stack trace 提供了大部分信息来精确定位问题根源。

案例分析

实例如下：

“RMI TCP Connection(267865)-172.16.5.25” daemon prio=10 tid=0x00007fd508371000 nid=0x55ae waiting for monitor entry [0x00007fd4f8684000]
java.lang.Thread.State: BLOCKED (on object monitor)
at org.apache.log4j.Category.callAppenders(Category.java:201)

waiting to lock <0x00000000acf4d0c0> (a org.apache.log4j.Logger)
at org.apache.log4j.Category.forcedLog(Category.java:388)
at org.apache.log4j.Category.log(Category.java:853)
at org.apache.commons.logging.impl.Log4JLogger.warn(Log4JLogger.java:234)
at com.tuan.core.common.lang.cache.remote.SpyMemcachedClient.get(SpyMemcachedClient.java:110)
……

线程状态是 Blocked，阻塞状态。说明线程等待资源超时！
“ waiting to lock <0x00000000acf4d0c0>”指，线程在等待给这个 0x00000000acf4d0c0 地址上锁（英文可描述为：trying to obtain 0x00000000acf4d0c0 lock）。
在 dump 日志里查找字符串 0x00000000acf4d0c0，发现有大量线程都在等待给这个地址上锁。如果能在日志里找到谁获得了这个锁（如 locked < 0x00000000acf4d0c0 >），就可以顺藤摸瓜了。
“ waiting for monitor entry”说明此线程通过 synchronized(obj) {……} 申请进入了临界区，从而进入了下图 1 中的“Entry Set”队列，但该 obj 对应的 monitor 被其他线程拥有，所以本线程在 Entry Set 队列中等待。
第一行里， “RMI TCP Connection(267865)-172.16.5.25”是 Thread Name 。tid 指 Java Thread id。nid 指 native 线程的 id。prio 是线程优先级。 [ 0x00007fd4f8684000 ]是线程栈起始地址。

死锁：

/**
 *产生死锁程序
 * @author naughtior<wuyishch@163.com>
 * @create 2016-09-20 13:04
 */

public class DeadLock {
    private static String A="A";
    private static String B="B";
    public static void main(String[] args) {
    new DeadLock().deadLock();
}



private void deadLock(){
    Thread thread1=new Thread(new Runnable() {
        @Override
        public void run() {
            synchronized (A){
                try {
                    Thread.currentThread().sleep(2000);
                } catch (InterruptedException e) {
                    e.printStackTrace();
                }
                synchronized (B){
                    System.out.println("1");
                }
            }
        }
    });

    Thread thread2=new Thread(new Runnable() {
        @Override
        public void run() {
           synchronized (B){
               synchronized (A){
                   System.out.println("2");
               }
           }
        }
    });
    thread1.start();
    thread2.start();
  }
}

jstack 输出内容：

Found one Java-level deadlock:
=============================
"Thread-1":
waiting to lock monitor 0x000000000270a248 (object 0x00000000d5e9fbd8, a java.lang.String),
which is held by "Thread-0"
"Thread-0":
waiting to lock monitor 0x000000000270b638 (object 0x00000000d5e9fc08, a java.lang.String),
which is held by "Thread-1"

Java stack information for the threads listed above:
===================================================
"Thread-1":
at DeadLock$2.run(DeadLock.java:37)
- waiting to lock <0x00000000d5e9fbd8(a java.lang.String)
- locked <0x00000000d5e9fc08(a java.lang.String)
at java.lang.Thread.run(Thread.java:745)
"Thread-0":
at DeadLock$1.run(DeadLock.java:26)
- waiting to lock <0x00000000d5e9fc08(a java.lang.String)
- locked <0x00000000d5e9fbd8(a java.lang.String)
at java.lang.Thread.run(Thread.java:745)

Found 1 deadlock.

从上面的描述可以清楚的知道程序发生了死锁。