jstack和线程dump分析

一:jstack

jstack该命令的语法格式: jstack  <pid>。能够用jps查看java进程id。这里要注意的是:
1. 不同的 JAVA虚机的线程 DUMP的创建方法和文件格式是不一样的,不同的 JVM版本号, dump信息也有区别。本文中,仅仅以 SUN的 hotspot JVM 5.0_06 为例。
2. 在实际执行中,往往一次 dump的信息,还不足以确认问题。

建议产生三次 dump信息,假设每次 dump都指向同一个问题,我们才确定问题的典型性。


二:线程分析
2.1. JVM 线程

在线程中,有一些 JVM内部的后台线程,来运行譬如垃圾回收,或者低内存的检測等等任务,这些线程往往在 JVM初始化的时候就存在。例如以下所看到的:

Html代码  收藏代码
  1. <span style="font-size: small;">  "Low Memory Detector" daemon prio=10 tid=0x081465f8 nid=0x7 runnable [0x00000000..0x00000000]  
  2.         "CompilerThread0" daemon prio=10 tid=0x08143c58 nid=0x6 waiting on condition [0x00000000..0xfb5fd798]  
  3.         "Signal Dispatcher" daemon prio=10 tid=0x08142f08 nid=0x5 waiting on condition [0x00000000..0x00000000]  
  4.         "Finalizer" daemon prio=10 tid=0x08137ca0 nid=0x4 in Object.wait() [0xfbeed000..0xfbeeddb8]  
  5.   
  6.         at java.lang.Object.wait(Native Method)  
  7.   
  8.         - waiting on <0xef600848> (a java.lang.ref.ReferenceQueue$Lock)  
  9.   
  10.         at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:116)  
  11.   
  12.         - locked <0xef600848> (a java.lang.ref.ReferenceQueue$Lock)  
  13.   
  14.         at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:132)  
  15.   
  16.         at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)  
  17.   
  18.         "Reference Handler" daemon prio=10 tid=0x081370f0 nid=0x3 in Object.wait() [0xfbf4a000..0xfbf4aa38]  
  19.   
  20.         at java.lang.Object.wait(Native Method)  
  21.   
  22.         - waiting on <0xef600758> (a java.lang.ref.Reference$Lock)  
  23.   
  24.         at java.lang.Object.wait(Object.java:474)  
  25.   
  26.         at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116)  
  27.   
  28.         - locked <0xef600758> (a java.lang.ref.Reference$Lock)  
  29.   
  30.         "VM Thread" prio=10 tid=0x08134878 nid=0x2 runnable  
  31.   
  32.         "VM Periodic Task Thread" prio=10 tid=0x08147768 nid=0x8 waiting on condition</span>  

 

     我们很多其它的是要观察用户级别的线程,例如以下所看到的:

Html代码  收藏代码
  1. <span style="font-size: small;">   "Thread-1" prio=10 tid=0x08223860 nid=0xa waiting on condition [0xef47a000..0xef47ac38]  
  2.   
  3.         at java.lang.Thread.sleep(Native Method)  
  4.   
  5.         at testthread.MySleepingThread.method2(MySleepingThread.java:53)  
  6.   
  7.         - locked <0xef63d600> (a testthread.MySleepingThread)  
  8.   
  9.         at testthread.MySleepingThread.run(MySleepingThread.java:35)  
  10.   
  11.         at java.lang.Thread.run(Thread.java:595) </span>  

我们能看到:
    * 线程的状态: waiting on condition
    * 线程的调用栈
    * 线程的当前锁住的资源: <0xef63d600>



2.2. 线程的状态分析

      正如我们刚看到的那样,线程的状态是一个重要的指标,它会显示在线程 Stacktrace的头一行结尾的地方。

那么线程常见的有哪些状态呢?线程在什么样的情况下会进入这样的状态呢?我们能从中发现什么线索?< /span>
1.1 Runnable
该状态表示线程具备全部执行条件,在执行队列中准备操作系统的调度,或者正在执行。



1.2 Wait on condition
      该状态出如今线程等待某个条件的发生。

详细是什么原因,能够结合 stacktrace来分析。最常见的情况是线程在等待网络的读写。比方当网络数据没有准备好读时。线程处于这样的等待状态,而一旦有数据准备好读之后。线程会又一次激活。读取并处理数据。在 Java引入 NewIO之前,对于每一个网络连接,都有一个相应的线程来处理网络的读写操作。即使没有可读写的数据,线程仍然堵塞在读写操作上。这样有可能造成资源浪费,并且给操作系统的线程调度也带来压力。在 NewIO里採用了新的机制。编写的server程序的性能和可扩展性都得到提高。
        假设发现有大量的线程都在处在 Wait on condition,从线程 stack看, 正等待网络读写。这可能是一个网络瓶颈的征兆。由于网络堵塞导致线程无法运行。

一种情况是网络非常忙,几 乎消耗了全部的带宽,仍然有大量数据等待网络读 写。还有一种情况也可能是网络空暇,但由于路由等问题,导致包无法正常的到达。

所以要结合系统的一些性能观察工具来综合分析,比方 netstat统计单位时间的发送包的数目,假设非常明显超过了所在网络带宽的限制 ; 观察 cpu的利用率,假设系统态的 CPU时间,相对于用户态的 CPU时间比例较高;假设程序执行在 Solaris 10平台上,能够用 dtrace工具看系统调用的情况。假设观察到 read/write的系统调用的次数或者执行时间遥遥率先;这些都指向因为网络带宽所限导致的网络瓶颈。

第二种出现 Wait on condition的常见情况是该线程在 sleep,等待 sleep的时间到了时候,将被唤醒。

1.3 Waiting for monitor entry 和 in Object.wait()
        在多线程的 JAVA程序中。实现线程之间的同步,就要说说 Monitor。 Monitor是 Java中用以实现线程之间的相互排斥与协作的主要手段。它能够看成是对象或者 Class的锁。每个对象都有。也仅有一个 monitor。

每个 Monitor在某个时刻。仅仅能被一个线程拥有,该线程就是 “Active Thread”。而其他线程都是 “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”。例如以下所看到的:

Html代码  收藏代码
  1. "Thread-0" prio=10 tid=0x08222eb0 nid=0x9 waiting for monitor entry [0xf927b000..0xf927bdb8]  
  2.   
  3. at testthread.WaitThread.run(WaitThread.java:39)  
  4.   
  5. - waiting to lock <0xef63bf08> (a java.lang.Object)  
  6.   
  7. - locked <0xef63beb8> (a java.util.ArrayList)  
  8.   
  9. at java.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(),类似于:

Html代码  收藏代码
  1. "Thread-1" prio=10 tid=0x08223250 nid=0xa in Object.wait() [0xef47a000..0xef47aa38]  
  2.   
  3.         at java.lang.Object.wait(Native Method)  
  4.   
  5.         - waiting on <0xef63beb8> (a java.util.ArrayList)  
  6.   
  7.         at java.lang.Object.wait(Object.java:474)  
  8.   
  9.         at testthread.MyWaitThread.run(MyWaitThread.java:40)  
  10.   
  11.         - locked <0xef63beb8> (a java.util.ArrayList)  
  12.   
  13.         at java.lang.Thread.run(Thread.java:595)  

细致观察上面的 DUMP信息。你会发现它有下面两行:
- locked <0xef63beb8> (a java.util.ArrayList)
- waiting on <0xef63beb8> (a java.util.ArrayList)
这里须要解释一下,为什么先 lock了这个对象,然后又 waiting on同一个对象呢?让我们看看这个线程相应的代码:

Java代码  收藏代码
  1. synchronized(obj) {  
  2.        .........  
  3.        obj.wait();  
  4.        .........  
  5. }   

线程的运行中。先用 synchronized 获得了这个对象的 Monitor(相应于 locked <0xef63beb8> )。

当运行到 obj.wait(), 线程即放弃了 Monitor的全部权,进入 “wait set”队列(相应于 waiting on <0xef63beb8> )。
        往往在你的程序中,会出现多个类似的线程。他们都有相似的 DUMP信息。这也可能是正常的。比方,在程序中,有多个服务线程,设计成从一个队列里面读取请求数据。这个队列就是 lock以及 waiting on的对象。当队列为空的时候,这些线程都会在这个队列上等待。直到队列有了数据,这些线程被 Notify。当然仅仅有一个线程获得了 lock,继续运行,而其他线程继续等待。

3. JDK 5.0 的 lock
       上面我们提到假设 synchronized和 monitor机制运用不当。可能会造成多线程程序的性能问题。在 JDK 5.0中,引入了 Lock机制,从而使开发人员能更灵活的开发高性能的并发多线程程序,能够替代以往 JDK中的 synchronized和 Monitor的 机制。

可是,要注意的是,由于 Lock类仅仅是一个普通类, JVM无从得知 Lock对象的占用情况。所以在线程 DUMP中,也不会包括关于 Lock的信息, 关于死锁等问题,就不如用 synchronized的编程方式easy识别。

4.案例分析
1.     死锁
在多线程程序的编写中,假设不适当的运用同步机制,则有可能造成程序的死锁。常常表现为程序的停顿,或者不再响应用户的请求。

比方在以下这个演示样例中,是个较为典型的死锁情况:

Java代码  收藏代码
  1. "Thread-1" prio=5 tid=0x00acc490 nid=0xe50 waiting for monitor entry [0x02d3f000  
  2.   
  3. ..0x02d3fd68]  
  4.   
  5. at deadlockthreads.TestThread.run(TestThread.java:31)  
  6.   
  7. - waiting to lock <0x22c19f18> (a java.lang.Object)  
  8.   
  9. - locked <0x22c19f20> (a java.lang.Object)  
  10.   
  11. "Thread-0" prio=5 tid=0x00accdb0 nid=0xdec waiting for monitor entry [0x02cff000  
  12.   
  13. ..0x02cff9e8]  
  14.   
  15. at deadlockthreads.TestThread.run(TestThread.java:31)  
  16.   
  17. - waiting to lock <0x22c19f20> (a java.lang.Object)  
  18.   
  19. - locked <0x22c19f18> (a java.lang.Object)  
  20.   
  21.    

 

在 JAVA 5中加强了对死锁的检測。

线程 Dump中能够直接报告出 Java级别的死锁,例如以下所看到的:

Java代码  收藏代码
  1. Found one Java-level deadlock:  
  2. =============================  
  3. "Thread-1":  
  4. waiting to lock monitor 0x0003f334 (object 0x22c19f18, a java.lang.Object),  
  5. which is held by "Thread-0"  
  6. "Thread-0":  
  7. waiting to lock monitor 0x0003f314 (object 0x22c19f20, a java.lang.Object),  
  8. which is held by "Thread-1"   

 

2.     热锁
       热锁,也往往是导致系统性能瓶颈的主要因素。其表现特征为,因为多个线程对临界区,或者锁的竞争。可能出现:
    * 频繁的线程的上下文切换:从操作系统对线程的调度来看,当 线程在等待资源而堵塞的时候,操作系统会将之切换出来,放到等待的队列,当线程获得资源之后,调度算法会将这个线程切换进去。放到运行队列中。
    * 大量的系统调用:由于线程的上下文切换,以及热锁的竞争。或 者临界区的频繁的进出。都可能导致大量的系统调用。


    * 大部分 CPU开销用在 “系统态 ”:线程上下文切换,和系统调用,都会导致 CPU在 “系统态 ”执行,换而言之,尽管系统非常忙碌。可是 CPU用在 “用户态 ”的比例较小,应用程序得不到充分的 CPU资源。
    * 随着 CPU数目的增多。系统的性能反而下降。

由于 CPU数目多,同 时执行的线程就越多,可能就会造成更频繁的线程上下文切换和系统态的 CPU开销,从而导致更糟糕的性能。


上面的描写叙述,都是一个 scalability(可扩展性)非常差的系统的表现。从总体的性能指标看,因为线程热锁的存在。程序的响应时间会变长。吞吐量会减少。< /span>
        那么,怎么去了解 “热锁 ”出如今什么地方呢?一个重要的方法还是结合操作系统的各种工具观察系统资源使用状况,以及收集 Java线程的 DUMP信息。看线程都堵塞在什么方法上,了解原因。才干找到相应的解决方法。
       我们以前遇到过这种样例,程序执行时,出现了以上指出的各种现象。通过观察操作系统的资源使用统计信息。以及线程 DUMP信息,确定了程序中热锁的存在,并发现大多数的线程状态都是 Waiting for monitor entry或者 Wait on monitor,且是堵塞在压缩和解压缩的方法上。

后来採用第三方的压缩包 javalib替代 JDK接着是存档,该系统多次的改进的性能。

版权声明:本文博主原创文章,博客,未经同意不得转载。

posted @ 2015-10-19 13:05  zfyouxi  阅读(346)  评论(0)    收藏  举报