程序员Wiki

Java 开发人员肯定都知道 JDK的 bin 目录中有java.exe、javac.exe这两个命令行工具。下面主要介绍一些监视虚拟机和故障处理的工具。

# 一、Jvm 入门工具

TIP

jps（JavaVirtual Machine Process Status Tool）：jps是 JDK提供的一个查看当前 Java进程的小工具。显示指定系统内所有的 HotSpot 虚拟机进程。

jps常用命令： 格式为jps [options] [hostid] ，jps 可以通过 RMI协议查询开启了 RMI服务的远程虚拟机进程状态，hostid 为 RMI 注册表中的主机名。如果不输则表示当前主机。打开命令行，敲一遍感受一下。

jps # 显示进程的ID 和 类的名称
jps –l # 输出输出完全的包名，应用主类名，jar的完全路径名 
jps –v # 输出jvm参数
jps –q # 只显示java进程号
jps -m # main 方法
jps -l xxx.xxx.xx.xx # 远程查看
1
2
3
4
5
6

jps原理： Java程序在启动以后，会在 java.io.tmpdir指定的目录下，就是临时文件夹里，生成一个类似于hsperfdata_User的文件夹，这个文件夹里（在 Linux中为 /tmp/hsperfdata_{userName}/），有几个文件，名字就是 java进程的pid，因此列出当前运行的 java进程，只是把这个目录里的文件名列一下而已。 至于系统的参数什么，就可以解析这几个文件获得。

jstack（Stack Trace for Java）：JDK自带的线程堆栈分析工具，查看或导出 Java 应用程序中线程堆栈信息。

jstack 常用命令： 生成虚拟机当前时刻的线程快照。线程快照就是当前虚拟机内每一条线程正在执行的方法堆栈的集合，生成线程快照的主要目的是定位线程出现长时间停顿的原因，如线程间死锁、死循环、请求外部资源导致的长时间等待等都是导致线程长时间停顿的常见原因。线程出现停顿的时候通过 jstack 来查看各个线程的调用堆栈，就能知道没有响应线程在后台做些什么事情或者等待什么资源。命令格式为：jstack [option] pid

# 基本
jstack 2815

# java和native c/c++框架的所有栈信息
jstack -m 2815

# 额外的锁信息列表，查看是否死锁
jstack -l 2815
1
2
3
4
5
6
7
8

jstack参数：

选项 作用
-F 当 ’jstack [-l] pid’ 没有相应的时候强制打印栈信息
-l 除堆栈外，打印关于锁的附加信息，例如属于 java.util.concurrent 的 ownable synchronizers列表
-m 打印 java和 native c/c++框架的所有栈信息
-h -help 打印帮助信息

举个例子：jstack -l pid

C:\Users\86156>jstack -l 18576
"RMI Scheduler(0)" #17 daemon prio=5 os_prio=0 tid=0x000000002002a000 nid=0x3a64 waiting on condition [0x000000002184f000]
   java.lang.Thread.State: TIMED_WAITING (parking)
        at sun.misc.Unsafe.park(Native Method)
        - parking to wait for  <0x00000006c2c1e498> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
        at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:215)
        at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2078)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:1093)
        at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:809)
        at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1067)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1127)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
        at java.lang.Thread.run(Thread.java:745)

   Locked ownable synchronizers:
        - None
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16

TIP

jinfo（Configuration Info for Java）：jinfo 是 JDK 自带的命令，可以用来查看正在运行的 Java 应用程序的扩展参数，包括 Java System属性和 JVM命令行参数；也可以动态的修改正在运行的 JVM 一些参数。当系统崩溃时，jinfo可以从 core文件里面知道崩溃的 Java应用程序的配置信息。

jinfo常用命令： 显示虚拟机配置信息

# 输出当前 jvm 进程的全部参数和系统属性
jinfo pid

# 输出所有的参数
jinfo -flags pid

# 查看指定的 jvm 参数的值
jinfo -flag PrintGC pid

# 开启/关闭指定的JVM参数
jinfo -flag +PrintGC pid

# 设置flag的参数
jinfo -flag name=value pid

# 输出当前 jvm 进行的全部的系统属性 System.getProperties()
jinfo -sysprops 2815
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17

jinfo参数：

no option 输出全部的参数和系统属性
-flag name 输出对应名称的参数
-flag [+|-]name 开启或者关闭对应名称的参数
-flag name=value 设定对应名称的参数
-flags 输出全部的参数
-sysprops 输出系统属性
1
2
3
4
5
6

更多请参考：jvm 性能调优工具之 jinfo

TIP

jmap（Memory Map for Java）：生成虚拟机内存堆转储快照 dump文件， 也可以查看堆内对象示例的统计信息、查看 ClassLoader 的信息以及 finalizer 队列。

jmap常用命令： 格式为 jmap [option] pid

# 查看堆的情况
jmap -heap 2815

# dump
jmap -dump:live,format=b,file=/tmp/heap2.bin 2815
jmap -dump:format=b,file=/tmp/heap3.bin 2815

# 查看堆的占用
jmap -histo 2815 | head -10
1
2
3
4
5
6
7
8
9

jmap参数：

no option： 查看进程的内存映像信息,类似 Solaris pmap 命令。
heap： 显示Java堆详细信息
histo[:live]： 显示堆中对象的统计信息
clstats：打印类加载器信息
finalizerinfo： 显示在F-Queue队列等待Finalizer线程执行finalizer方法的对象
dump:<dump-options>：生成堆转储快照
F： 当-dump没有响应时，使用-dump或者-histo参数. 在这个模式下,live子参数无效.
help：打印帮助信息
J<flag>：指定传递给运行jmap的JVM的参数
1
2
3
4
5
6
7
8
9

jstat（JVM Statistics Monitoring Tool）：用于收集 HtoSpot 虚拟机各方面的运行状态信息，可以显示类装载、内存、垃圾收集、JIT编译等运行数据。

jstat常用命令： 格式为 jstat [option vmid [interval[s | ms] [count]] ] 参数 interval 和 count 代表查询间隔和次数。如果省略说明只查询一次。假设需要没 1000毫秒查询一次进程 2815 垃圾收集等状况，一共查询 20次，命令如下：

jstat -gc 7672 1000 20

ZGC
选项 作用
-class 监视类装载、卸载数量、总空间以及类装载所消耗的时间
-gc 监视 Java堆状况，包括 Eden区、两个 Survivor区、老年代、永久代等的容量、已用空间、GC时间合计等信息
-gccapacity 监视内容与 gc基本相同，但输出主要关注 Java堆各个区域使用到的最大、最小空间
-gcutil 监视内容与 gc基本相同，但输出主要关注已使用空间占总空间的百分比
-gccause 与 gcutil 功能一样，但是会额外输出导致上一次 GC产生的原因
-gcnew 监视新生代 GC状况
-gcnewcapacity 监视内容与 gcnew基本相同，输出主要关注使用的最大、最小空间
-gcold 监视老年代 GC状况
-gcoldcapacity 监视内容与 gcold基本相同，输出主要关注使用的最大、最小空间
-gcpermcapacity 输出永久代使用到的最大、最小空间
-compiler 输出 JIT编译器编译过的方法、耗时等信息
-printcompilation 输出已经被 JIT编译的方法

举一个使用率比较高的例子：jstat -gcutil 7672

ZGC

这台服务器的新生代 Eden区（E，表示 Eden）使用了 24.01%的空间，两个 Survivor 区（S0、S1，表示 Survivor0、Survivor1 ）S0是空的，S1 使用了 25%的空间。老年代（O，表示Old）和元空间（M，表示 Metaspace）分别使用了 27.38% 和 94.81% 的空间。程序运行以来共发生 MinorGC（YGC，表示 Young GC）4221次，YGCT 总耗时 10.147秒，发送 Full GC（FGC）3次，FGCT总耗时 0.217秒，GGC 表示所有 GC总耗时 10.365秒。

使用 jstat 工具在纯文本状态下监视虚拟机状态的变化，确实不如 VisualVM等可视化的监视工具直接以图表展现那样直观。但许多服务器管理员都习惯在文本控制台中工作，直接在控制台使用 jstat命令依然是一种常见的监控方式。

jhat（JVM Heap Anaysis Tool）：虚拟机推转储快照分析工具

jhat 命令与 jmap搭配使用，来分析 jmap生成的转储快照。但我们一般不会使用该工具。第一是一般不会在部署应用程序的服务器上直接分析 dump文件，即使可以这样做，也尽量将 dump文件复制到其他机器上进行分析，因为分析工作是一个耗时而且消耗硬件资源的过程，既然在其他机器上运行，那就没有必要受命令行工具的限制了；另一个原因是jhat工具相对比较简陋，建议使用 VsualVM，以及专业用于分析 dump文件的工具。

# 二、JVM Dump分析

Thread Dump抓取： 一般当服务器挂起，崩溃或者性能低下时，就需要抓取服务器的线程堆栈（Thread Dump）用于后续的分析。在实际运行中，往往一次 dump的信息，还不足以确认问题。为了反映线程状态的动态变化，需要接连多次做 thread dump，每次间隔10-20s，建议至少产生三次 dump信息，如果每次 dump都指向同一个问题，我们才确定问题的典型性。

【1】操作系统命令获取 ThreadDump

ps –ef | grep java
kill -3 <pid>
1
2

【2】JVM 自带的工具获取线程堆栈

#jps 或 ps –ef | grep java （获取PID）
jstack [-l ] <pid> | tee -a jstack.log（获取ThreadDump）
1
2

# Thread Dump分析

Thread Dump信息：【1】头部信息： 时间，JVM信息

2011-11-02 19:05:06  
Full thread dump Java HotSpot(TM) Server VM (16.3-b01 mixed mode):
1
2

【2】线程 INFO信息块：

1. "Timer-0" daemon prio=10 tid=0xac190c00 nid=0xaef in Object.wait() [0xae77d000] 
# 线程名称：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]，对象的内存地址，通过JVM内存查看工具，能够看出线程是在哪儿个对象上等待；
2.  java.lang.Thread.State: TIMED_WAITING (on object monitor)
3.  at java.lang.Object.wait(Native Method)
4.  -waiting on <0xb3885f60> (a java.util.TaskQueue)     # 继续wait 
5.  at java.util.TimerThread.mainLoop(Timer.java:509)
6.  -locked <0xb3885f60> (a java.util.TaskQueue)         # 已经locked
7.  at java.util.TimerThread.run(Timer.java:462)
Java thread statck trace：是上面2-7行的信息。到目前为止这是最重要的数据，Java stack trace提供了大部分信息来精确定位问题根源。
1
2
3
4
5
6
7
8
9
10
11
12
13

【3】Java thread statck trace详解： 堆栈信息应该逆向解读：程序先执行的是第7行，然后是第6行，从下往上依次类推。

- locked <0xb3885f60> (a java.util.ArrayList)
- waiting on <0xb3885f60> (a java.util.ArrayList)
1
2

也就是说对象先上锁，锁住对象0xb3885f60，然后释放该对象锁，进入waiting状态。 为啥会出现这样的情况呢？看看下面的java代码示例，就会明白：

synchronized(obj) {  
   .........  
   obj.wait();  
   .........  
}
1
2
3
4
5

如上，线程的执行过程，先用synchronized获得了这个对象的Monitor（对应于 locked <0xb3885f60> ）。当执行到obj.wait()，线程即放弃了Monitor的所有权，进入wait set队列（对应于 waiting on <0xb3885f60> ）。在堆栈的第一行信息中，进一步标明了线程在代码级的状态，例如：

java.lang.Thread.State: TIMED_WAITING (parking)
1

解释如下：

|blocked| > 此线程试图进入异步块，但锁被另一个线程占用。这个线程被阻塞，直到锁被释放。

|blocked (on thin lock)| > 这与blocked的状态相同，但所讨论的锁是一个 thin lock.

|waiting| > 这条线线程 calledObject.wait()在对象上。在其他线程向该对象发送通知之前，该线程将一直保留在那里。

|sleeping| > 这个线程调用了 sleep()，正在睡眠中

|parked| > 这条线程调用了 park()进行了阻塞

|suspended| > 线程的执行被挂起suspend() 或JVMTI代理调用。
1
2
3
4
5
6
7
8
9
10
11

# Thread 状态分析

线程的状态是一个很重要的东西，因此 thread dump中会显示这些状态，通过对这些状态的分析，能够得出线程的运行状况，进而发现可能存在的问题。线程的状态在Thread.State这个枚举类型中定义：

public enum State
{
       /**
        * 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>
        *
        * <p>A thread in the waiting state is waiting for another thread to
        * perform a particular action.
        *
        * For example, a thread that has called <tt>Object.wait()</tt>
        * on an object is waiting for another thread to call
        * <tt>Object.notify()</tt> or <tt>Object.notifyAll()</tt> on
        * that object. A thread that has called <tt>Thread.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;
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65

【1】NEW： 每一个线程，在堆内存中都有一个对应的 Thread对象。Thread t = new Thread();当刚刚在堆内存中创建Thread对象，还没有调用 t.start()方法之前，线程就处在 NEW状态。在这个状态上，线程与普通的 java对象没有什么区别，就仅仅是一个堆内存中的对象。
【2】RUNNABLE： 该状态表示线程具备所有运行条件，在运行队列中准备操作系统的调度，或者正在运行。 这个状态的线程比较正常，但如果线程长时间停留在在这个状态就不正常了，这说明线程运行的时间很长（存在性能问题），或者是线程一直得不得执行的机会（存在线程饥饿的问题）。
【3】BLOCKED： 线程正在等待获取 java对象的监视器(也叫内置锁)，即线程正在等待进入由 synchronized保护的方法或者代码块。synchronized用来保证原子性，任意时刻最多只能由一个线程进入该临界区域，其他线程只能排队等待。
【4】WAITING： 处在该线程的状态，正在等待某个事件的发生，只有特定的条件满足，才能获得执行机会。而产生这个特定的事件，通常都是另一个线程。也就是说，如果不发生特定的事件，那么处在该状态的线程一直等待，不能获取执行的机会。比如：A线程调用了 obj对象的 obj.wait()方法，如果没有线程调用 obj.notify或 obj.notifyAll，那么A线程就没有办法恢复运行； 如果 A线程调用了 LockSupport.park()，没有别的线程调用 LockSupport.unpark(A)，那么A没有办法恢复运行。
【5】TIMED_WAITING： J.U.C中很多与线程相关类，都提供了限时版本和不限时版本的API。TIMED_WAITING意味着线程调用了限时版本的API，正在等待时间流逝。当等待时间过去后，线程一样可以恢复运行。如果线程进入了 WAITING状态，一定要特定的事件发生才能恢复运行；而处在 TIMED_WAITING的线程，如果特定的事件发生或者是时间流逝完毕，都会恢复运行。
【6】TERMINATED： 线程执行完毕，执行完 run方法正常返回，或者抛出了运行时异常而结束，线程都会停留在这个状态。这个时候线程只剩下 Thread对象了，没有什么用了。

# 关键状态分析

#等待条件：线程正在休眠或等待另一个线程的通知。
Wait on condition：The thread is either sleeping or waiting to be notified by another thread.
1
2

该状态说明它在等待另一个条件的发生，来把自己唤醒，或者干脆它是调用了 sleep(n)。此时线程状态大致为以下几种：

java.lang.Thread.State: WAITING (parking)：一直等那个条件发生；
java.lang.Thread.State: TIMED_WAITING (parking或sleeping)：定时的，那个条件不到来，也将定时唤醒自己。
1
2

Waiting for Monitor Entry 和 in Object.wait()：线程正在等待获取对象的锁（其他线程可能持有该锁）。如果两个或多个线程尝试执行同步代码，就会发生这种情况。注意，锁总是针对一个对象，而不是针对单个方法。

在多线程的 JAVA程序中，实现线程之间的同步，就要说说 Monitor。Monitor是 Java中用以实现线程之间的互斥与协作的主要手段，它可以看成是对象或者 Class的锁。每一个对象都有，也仅有一个 Monitor。下面这个图，描述了线程和 Monitor之间关系，以及线程的状态转换图：

ZGC

如上图，每个 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) {
   .........
}
1
2
3

这时有两种可能性：
【1】该monitor不被其它线程拥有， Entry Set里面也没有其它等待线程。本线程即成为相应类或者对象的 Monitor的 Owner，执行临界区的代码。
【2】该monitor被其它线程拥有，本线程在 Entry Set队列中等待。

在第一种情况下，线程将处于"Runnable"的状态，而第二种情况下，线程 DUMP会显示处于"waiting for monitor entry"如下：

"Thread-0" prio=10 tid=0x08222eb0 nid=0x9 waiting for monitor entry [0xf927b000..0xf927bdb8] 
at testthread.WaitThread.run(WaitThread.java:39) 
- waiting to lock <0xef63bf08> (a java.lang.Object) 
- locked <0xef63beb8> (a java.util.ArrayList) 
at java.lang.Thread.run(Thread.java:595)
1
2
3
4
5

临界区的设置，是为了保证其内部的代码执行的原子性和完整性。但是因为临界区在任何时间只允许线程串行通过，这和我们多线程的程序的初衷是相反的。如果在多线程的程序中，大量使用 synchronized，或者不适当的使用了它，会造成大量线程在临界区的入口等待，造成系统的性能大幅下降。如果在线程 DUMP中发现了这个情况，应该审查源码，改进程序。

再看Wait Set里面的线程。当线程获得了 Monitor，进入了临界区之后，如果发现线程继续运行的条件没有满足，它则调用对象（一般就是被 synchronized 的对象）的 wait() 方法，放弃 Monitor，进入 “Wait Set”队列。只有当别的线程在该对象上调用了 notify() 或者 notifyAll()，“Wait Set”队列中线程才得到机会去竞争，但是只有一个线程获得对象的Monitor，恢复到运行态。在 “Wait Set”中的线程， DUMP中表现为：in Object.wait()如下：

"Thread-1" prio=10 tid=0x08223250 nid=0xa in Object.wait() [0xef47a000..0xef47aa38] 
 at java.lang.Object.wait(Native Method) 
 - waiting on <0xef63beb8> (a java.util.ArrayList) 
 at java.lang.Object.wait(Object.java:474) 
 at testthread.MyWaitThread.run(MyWaitThread.java:40) 
 - locked <0xef63beb8> (a java.util.ArrayList) 
 at java.lang.Thread.run(Thread.java:595) 
综上，一般CPU很忙时，则关注runnable的线程，CPU很闲时，则关注waiting for monitor entry的线程。
1
2
3
4
5
6
7
8

JDK 5.0 的 Lock：上面提到如果 synchronized和 Monitor机制运用不当，可能会造成多线程程序的性能问题。在 JDK 5.0中，引入了 Lock机制，从而使开发者能更灵活的开发高性能的并发多线程程序，可以替代以往 JDK中的 synchronized和 Monitor的 机制。但是，要注意的是，因为 Lock类只是一个普通类，JVM无从得知 Lock对象的占用情况，所以在线程 DUMP中，也不会包含关于 Lock的信息， 关于死锁等问题，就不如用 synchronized的编程方式容易识别。

# 关键状态示例

【1】显示 BLOCKED状态

package jstack;

public class BlockedState
{
    private static Object object = new Object();

    public static void main(String[] args)
    {
        Runnable task = new Runnable() {

            @Override
            public void run()
            {
                synchronized (object)
                {
                    long begin = System.currentTimeMillis();
                    long end = System.currentTimeMillis();

                    // 让线程运行5分钟,会一直持有object的监视器
                    while ((end - begin) <= 5 * 60 * 1000)
                    {
                      end = System.currentTimeMillis();
                    }
                }
            }
        };

        new Thread(task, "t1").start();
        new Thread(task, "t2").start();
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31

先获取 object的线程会执行5分钟，这5分钟内会一直持有object的监视器，另一个线程无法执行处在 BLOCKED状态：

Full thread dump Java HotSpot(TM) Server VM (20.12-b01 mixed mode):

"DestroyJavaVM" prio=6 tid=0x00856c00 nid=0x1314 waiting on condition [0x00000000]
java.lang.Thread.State: RUNNABLE

"t2" prio=6 tid=0x27d7a800 nid=0x1350 waiting for monitor entry [0x2833f000]
java.lang.Thread.State: BLOCKED (on object monitor)
     at jstack.BlockedState$1.run(BlockedState.java:17)
     - waiting to lock <0x1cfcdc00> (a java.lang.Object)
     at java.lang.Thread.run(Thread.java:662)

"t1" prio=6 tid=0x27d79400 nid=0x1338 runnable [0x282ef000]
 java.lang.Thread.State: RUNNABLE
     at jstack.BlockedState$1.run(BlockedState.java:22)
     - locked <0x1cfcdc00> (a java.lang.Object)
     at java.lang.Thread.run(Thread.java:662)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16

【2】显示 WAITING状态

package jstack;

public class WaitingState
{
    private static Object object = new Object();

    public static void main(String[] args)
    {
        Runnable task = new Runnable() {

            @Override
            public void run()
            {
                synchronized (object)
                {
                    long begin = System.currentTimeMillis();
                    long end = System.currentTimeMillis();

                    // 让线程运行5分钟,会一直持有object的监视器
                    while ((end - begin) <= 5 * 60 * 1000)
                    {
                        try
                        {
                            // 进入等待的同时,会进入释放监视器
                            object.wait();
                        } catch (InterruptedException e)
                        {
                            e.printStackTrace();
                        }
                    }
                }
            }
        };

        new Thread(task, "t1").start();
        new Thread(task, "t2").start();
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38

显示结果：

Full thread dump Java HotSpot(TM) Server VM (20.12-b01 mixed mode):

"DestroyJavaVM" prio=6 tid=0x00856c00 nid=0x1734 waiting on condition [0x00000000]
java.lang.Thread.State: RUNNABLE

"t2" prio=6 tid=0x27d7e000 nid=0x17f4 in Object.wait() [0x2833f000]
java.lang.Thread.State: WAITING (on object monitor)
     at java.lang.Object.wait(Native Method)
     - waiting on <0x1cfcdc00> (a java.lang.Object)
     at java.lang.Object.wait(Object.java:485)
     at jstack.WaitingState$1.run(WaitingState.java:26)
     - locked <0x1cfcdc00> (a java.lang.Object)
     at java.lang.Thread.run(Thread.java:662)

"t1" prio=6 tid=0x27d7d400 nid=0x17f0 in Object.wait() [0x282ef000]
java.lang.Thread.State: WAITING (on object monitor)
     at java.lang.Object.wait(Native Method)
     - waiting on <0x1cfcdc00> (a java.lang.Object)
     at java.lang.Object.wait(Object.java:485)
     at jstack.WaitingState$1.run(WaitingState.java:26)
     - locked <0x1cfcdc00> (a java.lang.Object)
     at java.lang.Thread.run(Thread.java:662)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22

可以发现 t1和 t2都处在WAITING (on object monitor)，进入等待状态的原因是调用了 in Object.wait()。通过J.U.C包下的锁和条件队列，也是这个效果，大家可以自己实践下。

【3】显示 TIMED_WAITING状态

package jstack;

import java.util.concurrent.TimeUnit;
import java.util.concurrent.locks.Condition;
import java.util.concurrent.locks.Lock;
import java.util.concurrent.locks.ReentrantLock;

public class TimedWaitingState
{
    // java的显示锁,类似java对象内置的监视器
    private static Lock lock = new ReentrantLock();

    // 锁关联的条件队列(类似于object.wait)
    private static Condition condition = lock.newCondition();

    public static void main(String[] args)
    {
        Runnable task = new Runnable() {

            @Override
            public void run()
            {
                // 加锁,进入临界区
                lock.lock();

                try
                {
                    condition.await(5, TimeUnit.MINUTES);
                } catch (InterruptedException e)
                {
                    e.printStackTrace();
                }

                // 解锁,退出临界区
                lock.unlock();
            }
        };

        new Thread(task, "t1").start();
        new Thread(task, "t2").start();
    }
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42

显示结果：

Full thread dump Java HotSpot(TM) Server VM (20.12-b01 mixed mode):

"DestroyJavaVM" prio=6 tid=0x00856c00 nid=0x169c waiting on condition [0x00000000]
java.lang.Thread.State: RUNNABLE

"t2" prio=6 tid=0x27d7d800 nid=0xc30 waiting on condition [0x2833f000]
java.lang.Thread.State: TIMED_WAITING (parking)
     at sun.misc.Unsafe.park(Native Method)
     - parking to wait for  <0x1cfce5b8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
     at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:196)
     at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2116)
     at jstack.TimedWaitingState$1.run(TimedWaitingState.java:28)
     at java.lang.Thread.run(Thread.java:662)

"t1" prio=6 tid=0x280d0c00 nid=0x16e0 waiting on condition [0x282ef000]
java.lang.Thread.State: TIMED_WAITING (parking)
     at sun.misc.Unsafe.park(Native Method)
     - parking to wait for  <0x1cfce5b8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
     at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:196)
     at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2116)
     at jstack.TimedWaitingState$1.run(TimedWaitingState.java:28)
     at java.lang.Thread.run(Thread.java:662)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22

可以看到 t1和 t2线程都处在java.lang.Thread.State: TIMED_WAITING (parking)，这个 parking代表是调用的JUC下的工具类，而不是java默认的监视器。

# 案例分析

【1】CPU飙高，load高，响应很慢
一个请求过程中多次dump，对比多次 dump文件的 runnable线程，如果执行的方法有比较大变化，说明比较正常。如果在执行同一个方法，就有一些问题了；

【2】查找占用 CPU最多的线程
使用命令：top -H -p pid（pid为被测系统的进程号），找到导致 CPU高的线程ID，对应 thread dump信息中线程的 nid，只不过一个是十进制，一个是十六进制；在thread dump中，根据 top命令查找的线程id，查找对应的线程堆栈信息；

【3】CPU使用率不高但是响应很慢
进行dump，查看是否有很多 thread struck在 i/o、数据库等地方，定位瓶颈原因；

【4】请求无法响应
多次dump，对比是否所有的 runnable线程都一直在执行相同的方法，如果是的，恭喜你，锁住了！

# 死锁

死锁经常表现为程序的停顿，或者不再响应用户的请求。从操作系统上观察，对应进程的 CPU占用率为零，很快会从top或 prstat的输出中消失。比如在下面这个示例中，是个较为典型的死锁情况：

"Thread-1" prio=5 tid=0x00acc490 nid=0xe50 waiting for monitor entry [0x02d3f000
..0x02d3fd68]
at deadlockthreads.TestThread.run(TestThread.java:31)
- waiting to lock <0x22c19f18> (a java.lang.Object)
- locked <0x22c19f20> (a java.lang.Object)

"Thread-0" prio=5 tid=0x00accdb0 nid=0xdec waiting for monitor entry [0x02cff000
..0x02cff9e8]
at deadlockthreads.TestThread.run(TestThread.java:31)
- waiting to lock <0x22c19f20> (a java.lang.Object)
- locked <0x22c19f18> (a java.lang.Object)
1
2
3
4
5
6
7
8
9
10
11

在 JAVA 5中加强了对死锁的检测。线程 Dump中可以直接报告出 Java级别的死锁，如下所示：

Found one Java-level deadlock:
=============================
"Thread-1":
waiting to lock monitor 0x0003f334 (object 0x22c19f18, a java.lang.Object),
which is held by "Thread-0"

"Thread-0":
waiting to lock monitor 0x0003f314 (object 0x22c19f20, a java.lang.Object),
which is held by "Thread-1"
1
2
3
4
5
6
7
8
9

# 热锁

热锁，也往往是导致系统性能瓶颈的主要因素。其表现特征为：由于多个线程对临界区，或者锁的竞争，可能出现：
【1】频繁的线程的上下文切换： 从操作系统对线程的调度来看，当线程在等待资源而阻塞的时候，操作系统会将之切换出来，放到等待的队列，当线程获得资源之后，调度算法会将这个线程切换进去，放到执行队列中。
【2】大量的系统调用： 因为线程的上下文切换，以及热锁的竞争，或者临界区的频繁的进出，都可能导致大量的系统调用。
【3】大部分CPU开销用在“系统态”： 线程上下文切换，和系统调用，都会导致 CPU在 “系统态 ”运行，换而言之，虽然系统很忙碌，但是 CPU用在 “用户态 ”的比例较小，应用程序得不到充分的 CPU资源。
【4】随着CPU数目的增多，系统的性能反而下降。 因为 CPU数目多，同时运行的线程就越多，可能就会造成更频繁的线程上下文切换和系统态的 CPU开销，从而导致更糟糕的性能。
上面的描述，都是一个 scalability（可扩展性）很差的系统的表现。从整体的性能指标看，由于线程热锁的存在，程序的响应时间会变长，吞吐量会降低。

那么，怎么去了解 “热锁 ”出现在什么地方呢？ 一个重要的方法是 结合操作系统的各种工具观察系统资源使用状况，以及收集Java线程的 DUMP信息，看线程都阻塞在什么方法上，了解原因，才能找到对应的解决方法。

# JVM重要线程

JVM运行过程中产生的一些比较重要的线程罗列如下：

线程名称 解释说明
Attach Listener Attach 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 Handler JVM在创建main线程后就创建Reference Handler线程，其优先级最高，为10，它主要用于处理引用对象本身（软引用、弱引用、虚引用）的垃圾回收问题 。
VM Thread 这个线程就比较牛b了，是JVM里面的线程母体，根据hotspot源码（vmThread.hpp）里面的注释，它是一个单个的对象（最原始的线程）会产生或触发所有其他的线程，这个单个的VM线程是会被其他线程所使用来做一些VM操作（如：清扫垃圾等）。

# 三、Java 调试进阶工具

【1】btrace： 首当其冲的要说的是btrace。真实生产环境&预发的排查问题大杀器。 查看当前谁调用了 ArrayList的 add方法，同时只打印当前 ArrayList的 size大于500的线程调用栈

@OnMethod(clazz = "java.util.ArrayList", method="add", location = @Location(value = Kind.CALL, clazz = "/./", method = "/./"))
public static void m(@ProbeClassName String probeClass, @ProbeMethodName String probeMethod, @TargetInstance Object instance, @TargetMethodOrField String method) {
 
    if(getInt(field("java.util.ArrayList", "size"), instance) > 479){
        println("check who ArrayList.add method:" + probeClass + "#" + probeMethod  + ", method:" + method + ", size:" + getInt(field("java.util.ArrayList", "size"), instance));
        jstack();
        println();
        println("===========================");
        println();
    }
}
1
2
3
4
5
6
7
8
9
10
11

【2】监控当前服务方法被调用时返回的值以及请求的参数

@OnMethod(clazz = "com.taobao.sellerhome.transfer.biz.impl.C2CApplyerServiceImpl", method="nav", location = @Location(value = Kind.RETURN))
public static void mt(long userId, int current, int relation, String check, String redirectUrl, @Return AnyType result) {
 
    println("parameter# userId:" + userId + ", current:" + current + ", relation:" + relation + ", check:" + check + ", redirectUrl:" + redirectUrl + ", result:" + result);
}
1
2
3
4
5

btrace 具体可以参考这里：链接 (opens new window)

WARNING

①、经过观察，1.3.9的release输出不稳定，要多触发几次才能看到正确的结果；
②、正则表达式匹配trace类时范围一定要控制，否则极有可能出现跑满CPU导致应用卡死的情况；
③、由于是字节码注入的原理，想要应用恢复到正常情况，需要重启应用；

【3】Greys： Greys是@杜琨的大作吧。说几个挺棒的功能(部分功能和btrace重合)：sc -df xxx：输出当前类的详情,包括源码位置和classloader结构；trace class method: 打印出当前方法调用的耗时情况，细分到每个方法, 对排查方法性能时很有帮助。
【4】Arthas： Arthas是基于Greys。具体请参考：调试排错 - Java应用在线调试Arthas
【5】javOSize： 就说一个功能：classes：通过修改了字节码，改变了类的内容，即时生效。 所以可以做到快速的在某个地方打个日志看看输出，缺点是对代码的侵入性太大。但是如果自己知道自己在干嘛，的确是不错的玩意儿。其他功能 Greys和 btrace都能很轻易做的到，不说了。
【6】JProfiler： 之前判断许多问题要通过JProfiler，但是现在Greys和btrace基本都能搞定了。再加上出问题的基本上都是生产环境(网络隔离)，所以基本不怎么使用了，但是还是要标记一下。

# 四、其它工具

dmesg： 如果发现自己的 java进程悄无声息的消失了，几乎没有留下任何线索，那么dmesg一发，很有可能有你想要的。sudo dmesg|grep -i kill|less 去找关键字oom_killer。找到的结果类似如下:

[6710782.021013] java invoked oom-killer: gfp_mask=0xd0, order=0, oom_adj=0, oom_scoe_adj=0
[6710782.070639] [<ffffffff81118898>] ? oom_kill_process+0x68/0x140 
[6710782.257588] Task in /LXC011175068174 killed as a result of limit of /LXC011175068174 
[6710784.698347] Memory cgroup out of memory: Kill process 215701 (java) score 854 or sacrifice child 
[6710784.707978] Killed process 215701, UID 679, (java) total-vm:11017300kB, anon-rss:7152432kB, file-rss:1232kB
1
2
3
4
5

以上表明，对应的java进程被系统的OOM Killer给干掉了，得分为854. 解释一下OOM killer（Out-Of-Memory killer），该机制会监控机器的内存资源消耗。当机器内存耗尽前，该机制会扫描所有的进程（按照一定规则计算，内存占用，时间等），挑选出得分最高的进程，然后杀死，从而保护机器。 dmesg日志时间转换公式：log实际时间=格林威治1970-01-01+(当前时间秒数-系统启动至今的秒数+dmesg打印的 log时间)秒数：date -d "1970-01-01 UTC echo "$(date +%s)-$(cat /proc/uptime|cut -f 1 -d' ')+12288812.926194"|bc seconds" 剩下的，就是看看为什么内存这么大，触发了OOM-Killer了。

(adsbygoogle = window.adsbygoogle || []).push({});

← JVM 内存结构详解 →