Back to JDK Tools and Utilities

See Also JavaJava Virtual Machine

jstack

1. A thread state

A thread state. A thread can be in one of the following states:

A thread can be in only one state at a given point in time. These states are virtual machine states which do not reflect any operating system thread states.

2. Thread Trace in Linux

定位引起高CPU的具体线程

## top -p pid  #输入H(Show Threads On) 此时输出的pid已经是线程id了
#top -p 20485

top - 15:48:31 up 769 days, 22:23,  2 users,  load average: 0.10, 0.08, 1.00
Tasks:   3 total,   0 running,   3 sleeping,   0 stopped,   0 zombie
Cpu(s):  0.3%us,  0.1%sy,  0.0%ni, 99.5%id,  0.1%wa,  0.0%hi,  0.0%si,  0.0%st
Mem:  65921144k total, 62778080k used,  3143064k free,   310376k buffers
Swap: 16777208k total,   672076k used, 16105132k free, 48673416k cached

  PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND                                                                   
20487 root      20   0 7203m 1.7g 5552 S 6600.0  2.7   7:09.42 java                                                                     
20485 root      20   0 7203m 1.7g 5552 S  0.0  2.7   0:00.00 java                                                                       
20486 root      20   0 7203m 1.7g 5552 S  0.0  2.7   0:04.36 java 

## 打印线程ID的16进制值
# printf "%x\n" 20487
5007
## 输出对应线程堆栈信息
# jstack 20485 | grep 5007
"Gang worker#0 (Parallel GC Threads)" prio=10 tid=0x00007f8d4401b800 nid=0x5007 runnable

3. Thread Trace for Java

Stack Trace for Java

3.1. [waiting for monitor entry]BLOCKED

在等待进入一个临界区 ,所以它在“Entry Set”队列中等待

jvm_schedule.png

jstack <jvm process id>

"nioEventLoopGroup-3-16" prio=10 tid=0x00007f5de0045800 nid=0x3322 waiting for monitor entry [0x00007f5e41bd9000]
   java.lang.Thread.State: BLOCKED (on object monitor)
  at org.apache.log4j.Category.callAppenders(Category.java:204)
  - waiting to lock <0x00000007958987a0> (a org.apache.log4j.spi.RootLogger)

如果大量线程处在BLOCKED,可能是一个全局锁阻塞住了大量线程。以上这种阻塞日志,在我们的问题JVM中共出现了25个(总线程数是70)。

从服务日志的输出看,时断时续非常明显,系统负载以及内存、CPU和IO等都不高。因此问题一目了然在log4j。

定位发现log4j日志的确有问题:log4j.rootLogger=INFO, Console, System, SystemError, socket,ping socket服务地址解析很慢,且时延大于10ms

socket日志服务现在已经无人认领,直接干掉后,阻塞线程为零,系统吞吐恢复正常

3.2. [waiting on condition]WAITING/TIMED_WAITING

在等待另一个条件的发生,来把自己唤醒,或者干脆它是调用了 sleep(N)

如果大量线程处在WAITING,可能是它们在等待获取第三方资源,尤其是第三方网络资源,迟迟获取不到Response,导致大量线程进入等待状态。 所以如果你发现有大量的线程都处在 Wait on condition,从线程堆栈看,正等待网络读写,这可能是一个网络瓶颈的征兆,因为网络阻塞导致线程无法执行。

3.2.1. WAITING (parking)

一直等那个条件发生

3.2.2. TIMED_WAITING (parking/sleeping)

定时的,那个条件不到来,也将定时唤醒自己

3.3. [in Object.wait()]WAITING/TIMED_WAITING (on object monitor)

"Timer-0" daemon prio=10 tid=0x00007fb360a60800 nid=0xb682 in Object.wait() [0x00007fb3369ee000]
   java.lang.Thread.State: TIMED_WAITING (on object monitor)
        at java.lang.Object.wait(Native Method)

说明线程获得了Monitor之后,又调用了 java.lang.Object.wait()方法。

当线程获得了 Monitor,如果发现线程继续运行的条件没有满足,它则调用对象(一般就是被 synchronized 的对象)的 wait() 方法,放弃了 Monitor,进入 “Wait Set”队列。

4. Treads分析工具

https://www.ibm.com/developerworks/community/groups/service/html/communitystart?communityUuid=2245aa39-fa5c-4475-b891-14c205f7333c

##下载分析工具
wget ftp://public.dhe.ibm.com/software/websphere/appserv/support/tools/jca/jca457.jar
## dump thread to local file
jstack -l <pid> stack.file
java -Xmx500m -jar jca457.jar
##直接打开stack.file看分析结果

5. Reference


CategoryTool

MainWiki: jstack (last edited 2016-04-12 01:20:53 by twotwo)