调试排错 - 线程Dump分析

Thread Dump介绍什么是Thread DumpThread Dump是非常有用的诊断Java应用问题的工具。每一个Java虚拟机都有及时生成所有线程在某一点状态的thread-dump的能力虽然各个 Java虚拟机打印的thread dump略有不同但是 大多都提供了当前活动线程的快照及JVM中所有Java线程的堆栈跟踪信息堆栈信息一般包含完整的类名及所执行的方法如果可能的话还有源代码的行数。Thread Dump特点能在各种操作系统下使用能在各种Java应用服务器下使用能在生产环境下使用而不影响系统的性能能将问题直接定位到应用程序的代码行上Thread Dump抓取一般当服务器挂起崩溃或者性能低下时就需要抓取服务器的线程堆栈Thread Dump用于后续的分析。在实际运行中往往一次 dump的信息还不足以确认问题。为了反映线程状态的动态变化需要接连多次做thread dump每次间隔10-20s建议至少产生三次 dump信息如果每次 dump都指向同一个问题我们才确定问题的典型性。操作系统命令获取ThreadDumpps –ef|grep java kill-3pid注意一定要谨慎, 一步不慎就可能让服务器进程被杀死。kill -9 命令会杀死进程。JVM 自带的工具获取线程堆栈jps 或 ps –ef|grep java 获取PID jstack[-l]pid|tee-a jstack.log获取ThreadDumpThread Dump分析Thread Dump信息头部信息时间JVM信息2011-11-0219:05:06Fullthread dumpJavaHotSpot(TM)ServerVM(16.3-b01 mixed mode):线程INFO信息块1.Timer-0daemon prio10tid0xac190c00nid0xaefinObject.wait()[0xae77d000]# 线程名称Timer-0线程类型daemon优先级:10默认是5 #JVM线程idtid0xac190c00JVM内部线程的唯一标识通过java.lang.Thread.getId()获取通常用自增方式实现。 # 对应系统线程idNativeThreadIDnid0xaef和top命令查看的线程pid对应不过一个是10进制一个是16进制。通过命令top-H-p pid可以查看该进程的所有线程信息 # 线程状态inObject.wait() # 起始栈地址[0xae77d000]对象的内存地址通过JVM内存查看工具能够看出线程是在哪儿个对象上等待2.java.lang.Thread.State:TIMED_WAITING(on object monitor)3.atjava.lang.Object.wait(NativeMethod)4.-waiting on0xb3885f60(ajava.util.TaskQueue)# 继续wait5.atjava.util.TimerThread.mainLoop(Timer.java:509)6.-locked0xb3885f60(ajava.util.TaskQueue)# 已经locked7.atjava.util.TimerThread.run(Timer.java:462)Java thread statck trace是上面2-7行的信息。到目前为止这是最重要的数据Java stack trace提供了大部分信息来精确定位问题根源。Java thread statck trace详解堆栈信息应该逆向解读程序先执行的是第7行然后是第6行依次类推。-locked0xb3885f60(ajava.util.ArrayList)-waiting on0xb3885f60(ajava.util.ArrayList)也就是说对象先上锁锁住对象0xb3885f60然后释放该对象锁进入waiting状态。为啥会出现这样的情况呢看看下面的java代码示例就会明白synchronized(obj){.........obj.wait();.........}如上线程的执行过程先用 synchronized 获得了这个对象的 Monitor对应于 locked 0xb3885f60 。当执行到 obj.wait()线程即放弃了 Monitor的所有权进入 “wait set”队列对应于 waiting on 0xb3885f60 。在堆栈的第一行信息中进一步标明了线程在代码级的状态例如java.lang.Thread.State:TIMED_WAITING(parking)解释如下|blocked|Thisthread triedtoenterasynchronized block,but the lock was taken by anotherthread.Thisthread isblocked until the lock gets released.|blocked(on thin lock)|Thisis the same state asblocked,but the lock in question is a thin lock.|waiting|Thisthread calledObject.wait()on anobject.Thethread will remain there until some otherthread sends a notificationtothatobject.|sleeping|Thisthreadcalledjava.lang.Thread.sleep().|parked|Thisthreadcalledjava.util.concurrent.locks.LockSupport.park().|suspended|Thethreads execution wassuspended byjava.lang.Thread.suspend()or aJVMTIagent call.Thread状态分析线程的状态是一个很重要的东西因此thread dump中会显示这些状态通过对这些状态的分析能够得出线程的运行状况进而发现可能存在的问题。线程的状态在Thread.State这个枚举类型中定义publicenumState{/** * Thread state for a thread which has not yet started. */NEW,/** * Thread state for a runnable thread. A thread in the runnable * state is executing in the Java virtual machine but it may * be waiting for other resources from the operating system * such as processor. */RUNNABLE,/** * Thread state for a thread blocked waiting for a monitor lock. * A thread in the blocked state is waiting for a monitor lock * to enter a synchronized block/method or * reenter a synchronized block/method after calling * {link Object#wait() Object.wait}. */BLOCKED,/** * Thread state for a waiting thread. * A thread is in the waiting state due to calling one of the * following methods: * ul * li{link Object#wait() Object.wait} with no timeout/li * li{link #join() Thread.join} with no timeout/li * li{link LockSupport#park() LockSupport.park}/li * /ul * * pA thread in the waiting state is waiting for another thread to * perform a particular action. * * For example, a thread that has called ttObject.wait()/tt * on an object is waiting for another thread to call * ttObject.notify()/tt or ttObject.notifyAll()/tt on * that object. A thread that has called ttThread.join()/tt * is waiting for a specified thread to terminate. */WAITING,/** * Thread state for a waiting thread with a specified waiting time. * A thread is in the timed waiting state due to calling one of * the following methods with a specified positive waiting time: * ul * li{link #sleep Thread.sleep}/li * li{link Object#wait(long) Object.wait} with timeout/li * li{link #join(long) Thread.join} with timeout/li * li{link LockSupport#parkNanos LockSupport.parkNanos}/li * li{link LockSupport#parkUntil LockSupport.parkUntil}/li * /ul */TIMED_WAITING,/** * Thread state for a terminated thread. * The thread has completed execution. */TERMINATED;}NEW每一个线程在堆内存中都有一个对应的Thread对象。Thread t new Thread();当刚刚在堆内存中创建Thread对象还没有调用t.start()方法之前线程就处在NEW状态。在这个状态上线程与普通的java对象没有什么区别就仅仅是一个堆内存中的对象。RUNNABLE该状态表示线程具备所有运行条件在运行队列中准备操作系统的调度或者正在运行。 这个状态的线程比较正常但如果线程长时间停留在在这个状态就不正常了这说明线程运行的时间很长存在性能问题或者是线程一直得不得执行的机会存在线程饥饿的问题。BLOCKED线程正在等待获取java对象的监视器(也叫内置锁)即线程正在等待进入由synchronized保护的方法或者代码块。synchronized用来保证原子性任意时刻最多只能由一个线程进入该临界区域其他线程只能排队等待。WAITING处在该线程的状态正在等待某个事件的发生只有特定的条件满足才能获得执行机会。而产生这个特定的事件通常都是另一个线程。也就是说如果不发生特定的事件那么处在该状态的线程一直等待不能获取执行的机会。比如A线程调用了obj对象的obj.wait()方法如果没有线程调用obj.notify或obj.notifyAll那么A线程就没有办法恢复运行 如果A线程调用了LockSupport.park()没有别的线程调用LockSupport.unpark(A)那么A没有办法恢复运行TIMED_WAITINGJ.U.C中很多与线程相关类都提供了限时版本和不限时版本的API。TIMED_WAITING意味着线程调用了限时版本的API正在等待时间流逝。当等待时间过去后线程一样可以恢复运行。如果线程进入了WAITING状态一定要特定的事件发生才能恢复运行而处在TIMED_WAITING的线程如果特定的事件发生或者是时间流逝完毕都会恢复运行。TERMINATED线程执行完毕执行完run方法正常返回或者抛出了运行时异常而结束线程都会停留在这个状态。这个时候线程只剩下Thread对象了没有什么用了。关键状态分析Wait on conditionThe thread is either sleeping or waiting to be notified by another thread.该状态说明它在等待另一个条件的发生来把自己唤醒或者干脆它是调用了 sleep(n)。此时线程状态大致为以下几种java.lang.Thread.State:WAITING(parking)一直等那个条件发生java.lang.Thread.State:TIMED_WAITING(parking或sleeping)定时的那个条件不到来也将定时唤醒自己。Waiting for Monitor Entry 和 in Object.wait()The thread is waiting to get the lock for an object (some other thread may be holding the lock). This happens if two or more threads try to execute synchronized code. Note that the lock is always for an object and not for individual methods.在多线程的JAVA程序中实现线程之间的同步就要说说 Monitor。Monitor是Java中用以实现线程之间的互斥与协作的主要手段它可以看成是对象或者Class的锁。每一个对象都有也仅有一个 Monitor。下面这个图描述了线程和 Monitor之间关系以及线程的状态转换图如上图每个Monitor在某个时刻只能被一个线程拥有该线程就是 “ActiveThread”而其它线程都是 “Waiting Thread”分别在两个队列“Entry Set”和“Wait Set”里等候。在“Entry Set”中等待的线程状态是“Waiting for monitor entry”而在“Wait Set”中等待的线程状态是“in Object.wait()”。先看“Entry Set”里面的线程。我们称被 synchronized保护起来的代码段为临界区。当一个线程申请进入临界区时它就进入了“Entry Set”队列。对应的 code就像synchronized(obj){.........}这时有两种可能性该 monitor不被其它线程拥有 Entry Set里面也没有其它等待线程。本线程即成为相应类或者对象的 Monitor的 Owner执行临界区的代码。该 monitor被其它线程拥有本线程在 Entry Set队列中等待。在第一种情况下线程将处于 “Runnable”的状态而第二种情况下线程 DUMP会显示处于 “waiting for monitor entry”。如下Thread-0prio10tid0x08222eb0nid0x9waitingformonitor entry[0xf927b000..0xf927bdb8]attestthread.WaitThread.run(WaitThread.java:39)-waitingtolock0xef63bf08(ajava.lang.Object)-locked0xef63beb8(ajava.util.ArrayList)atjava.lang.Thread.run(Thread.java:595)临界区的设置是为了保证其内部的代码执行的原子性和完整性。但是因为临界区在任何时间只允许线程串行通过这和我们多线程的程序的初衷是相反的。如果在多线程的程序中大量使用 synchronized或者不适当的使用了它会造成大量线程在临界区的入口等待造成系统的性能大幅下降。如果在线程 DUMP中发现了这个情况应该审查源码改进程序。再看“Wait Set”里面的线程。当线程获得了 Monitor进入了临界区之后如果发现线程继续运行的条件没有满足它则调用对象一般就是被 synchronized 的对象的 wait() 方法放弃 Monitor进入 “Wait Set”队列。只有当别的线程在该对象上调用了 notify() 或者 notifyAll()“Wait Set”队列中线程才得到机会去竞争但是只有一个线程获得对象的Monitor恢复到运行态。在 “Wait Set”中的线程 DUMP中表现为 in Object.wait()。如下Thread-1prio10tid0x08223250nid0xainObject.wait()[0xef47a000..0xef47aa38]atjava.lang.Object.wait(NativeMethod)-waiting on0xef63beb8(ajava.util.ArrayList)atjava.lang.Object.wait(Object.java:474)attestthread.MyWaitThread.run(MyWaitThread.java:40)-locked0xef63beb8(ajava.util.ArrayList)atjava.lang.Thread.run(Thread.java:595)综上一般CPU很忙时则关注runnable的线程CPU很闲时则关注waiting for monitor entry的线程。JDK 5.0 的 Lock上面提到如果 synchronized和 monitor机制运用不当可能会造成多线程程序的性能问题。在 JDK 5.0中引入了 Lock机制从而使开发者能更灵活的开发高性能的并发多线程程序可以替代以往 JDK中的 synchronized和 Monitor的 机制。但是要注意的是因为 Lock类只是一个普通类JVM无从得知 Lock对象的占用情况所以在线程 DUMP中也不会包含关于 Lock的信息 关于死锁等问题就不如用 synchronized的编程方式容易识别。案例分析问题场景CPU飙高load高响应很慢一个请求过程中连续取3-5个ThreadDump间隔5-10秒对比多次dump文件的runnable线程查找占用CPU最多的线程使用命令top -H -p pidpid为被测系统的进程号找到导致CPU高的线程ID对应thread dump信息中线程的nid只不过一个是十进制一个是十六进制在thread dump中根据top命令查找的线程id查找对应的线程堆栈信息可能存在的问题如果执行的方法有比较大变化说明比较正常。如果在执行同一个方法就有一些问题了例如某个计算方法在循环中大量计算或数据库查询没有使用索引。或者请求无法响应检查是否有死锁ThreadDump开头会明确提示查看大量线程是否处于BLOCKED状态锁竞争分析线程是否在WAITING某个条件但永远等不到死锁死锁经常表现为程序的停顿或者不再响应用户的请求。从操作系统上观察对应进程的CPU占用率为零很快会从top或prstat的输出中消失。比如在下面这个示例中是个较为典型的死锁情况Thread-1prio5tid0x00acc490nid0xe50waitingformonitor entry[0x02d3f000..0x02d3fd68]atdeadlockthreads.TestThread.run(TestThread.java:31)-waitingtolock0x22c19f18(ajava.lang.Object)-locked0x22c19f20(ajava.lang.Object)Thread-0prio5tid0x00accdb0nid0xdecwaitingformonitor entry[0x02cff000..0x02cff9e8]atdeadlockthreads.TestThread.run(TestThread.java:31)-waitingtolock0x22c19f20(ajava.lang.Object)-locked0x22c19f18(ajava.lang.Object)在 JAVA 5中加强了对死锁的检测。线程 Dump中可以直接报告出 Java级别的死锁如下所示FoundoneJava-level deadlock:Thread-1:waitingtolockmonitor0x0003f334(object0x22c19f18,ajava.lang.Object),which is held byThread-0Thread-0:waitingtolockmonitor0x0003f314(object0x22c19f20,ajava.lang.Object),which is held byThread-1热锁热锁也往往是导致系统性能瓶颈的主要因素。其表现特征为由于多个线程对临界区或者锁的竞争可能出现频繁的线程的上下文切换从操作系统对线程的调度来看当线程在等待资源而阻塞的时候操作系统会将之切换出来放到等待的队列当线程获得资源之后调度算法会将这个线程切换进去放到执行队列中。大量的系统调用因为线程的上下文切换以及热锁的竞争或者临界区的频繁的进出都可能导致大量的系统调用。大部分CPU开销用在“系统态”线程上下文切换和系统调用都会导致 CPU在 “系统态 ”运行换而言之虽然系统很忙碌但是CPU用在 “用户态 ”的比例较小应用程序得不到充分的 CPU资源。随着CPU数目的增多系统的性能反而下降。因为CPU数目多同时运行的线程就越多可能就会造成更频繁的线程上下文切换和系统态的CPU开销从而导致更糟糕的性能。上面的描述都是一个 scalability可扩展性很差的系统的表现。从整体的性能指标看由于线程热锁的存在程序的响应时间会变长吞吐量会降低。那么怎么去了解 “热锁 ”出现在什么地方呢一个重要的方法是 结合操作系统的各种工具观察系统资源使用状况以及收集Java线程的DUMP信息看线程都阻塞在什么方法上了解原因才能找到对应的解决方法。内存泄漏关联分析症状频繁Full GC内存不释放ThreadDump分析步骤1. 结合HeapDump分析2. 在ThreadDump中查找持有大量对象的线程3. 检查线程的调用栈找到创建这些对象的业务逻辑典型发现静态集合不断添加对象且不及时清理。JVM重要线程JVM运行过程中产生的一些比较重要的线程罗列如下线程名称解释说明Attach ListenerAttach Listener 线程是负责接收到外部的命令而对该命令进行执行的并把结果返回给发送者。通常我们会用一些命令去要求JVM给我们一些反馈信息如java -version、jmap、jstack等等。 如果该线程在JVM启动的时候没有初始化那么则会在用户第一次执行JVM命令时得到启动。Signal Dispatcher前面提到Attach Listener线程的职责是接收外部JVM命令当命令接收成功后会交给signal dispather线程去进行分发到各个不同的模块处理命令并且返回处理结果。signal dispather线程也是在第一次接收外部JVM命令时进行初始化工作。CompilerThread0用来调用JITing实时编译装卸class 。 通常JVM会启动多个线程来处理这部分工作线程名称后面的数字也会累加例如CompilerThread1。Concurrent Mark-Sweep GC Thread并发标记清除垃圾回收器就是通常所说的CMS GC线程 该线程主要针对于老年代垃圾回收。ps启用该垃圾回收器需要在JVM启动参数中加上-XX:UseConcMarkSweepGC。DestroyJavaVM执行main()的线程在main执行完后调用JNI中的 jni_DestroyJavaVM() 方法唤起DestroyJavaVM 线程处于等待状态等待其它线程Java线程和Native线程退出时通知它卸载JVM。每个线程退出时都会判断自己当前是否是整个JVM中最后一个非deamon线程如果是则通知DestroyJavaVM 线程卸载JVM。Finalizer Thread这个线程也是在main线程之后创建的其优先级为10主要用于在垃圾收集前调用对象的finalize()方法关于Finalizer线程的几点1) 只有当开始一轮垃圾收集时才会开始调用finalize()方法因此并不是所有对象的finalize()方法都会被执行2) 该线程也是daemon线程因此如果虚拟机中没有其他非daemon线程不管该线程有没有执行完finalize()方法JVM也会退出3) JVM在垃圾收集时会将失去引用的对象包装成Finalizer对象Reference的实现并放入ReferenceQueue由Finalizer线程来处理最后将该Finalizer对象的引用置为null由垃圾收集器来回收4) JVM为什么要单独用一个线程来执行finalize()方法呢如果JVM的垃圾收集线程自己来做很有可能由于在finalize()方法中误操作导致GC线程停止或不可控这对GC线程来说是一种灾难Low Memory Detector这个线程是负责对可使用内存进行检测如果发现可用内存低分配新的内存空间。Reference HandlerJVM在创建main线程后就创建Reference Handler线程其优先级最高为10它主要用于处理引用对象本身软引用、弱引用、虚引用的垃圾回收问题 。VM Thread这个线程就比较牛b了是JVM里面的线程母体根据hotspot源码vmThread.hpp里面的注释它是一个单个的对象最原始的线程会产生或触发所有其他的线程这个单个的VM线程是会被其他线程所使用来做一些VM操作如清扫垃圾等。