虚拟机性能监控和故障处理工具

虚拟机性能监控和故障处理工具

一. 引文

为一个系统定位问题时,知识、经验是关键基础,数据是依据,工具是运用知识处理数据手段。

数据包括:

  • 运行日志、
  • 异常堆栈、
  • GC日志、
  • 线程快照(threaddump/javacore文件)、
  • 堆转储快照(headdump/hprof文件)等。

学会使用虚拟机性能监控和故障处理工具可以加快我们分析数据、定位解决问题的速度。


二. JDK的命令行工具

JDK中的bin目录除了java.exe和javac.exe这两个常用的命令行工具还有其他程序,这些程序中包括一些虚拟机性能监控和故障处理工具,能在处理应用程序性能问题、定位故障是发挥巨大作用。

命令行工具都比较小巧,主要的功能代码都在tools类库中实现。如果使用Linux版本的JDK,会发现很多工具是由Shell脚本写成,可以直接用vim打开。

JDK开发团队选择采用Java代码来实现这些监控工具是有用意的:当应用程序部署到生产环境后,无论是直接接触物理服务器还是远程到Telnet到服务器上都可能会受到限制,借助tools.jar类库里面的接口,我们可以直接在应用程序中实现功能强大的监控分析功能。

名称 主要作用
jps JVM Process Status Tool,显式指定系统内所有的HotSpot虚拟机进程
jstat JVM Statistics Monitoring Tool,用于收集HotSpot虚拟机各方面的运行数据
jinfo Configuration Info for Java,显式虚拟机配置信息
jmap Memory Map for Java,生成虚拟机的内存转储快照(heapdump文件)
jhat JVM Heap Dump Browser,用于分析heapdump文件,它会建立一个HTTP/HTML服务器,让用户可以在浏览器上查看分析结果
jstack Stack Trace for Java,显示虚拟机的线程快照

2.1 jps-虚拟机进程状况工具

JVM Process Status Tool,除了名字像UNIX的ps命令外,其功能也类似于ps命令:可以列出正在运行的虚拟机进程,并显示虚拟机执行主类(Main Class,main() 函数所在的类)名称以及这些进程的本地虚拟机唯一ID(Local Virtual Machine Identifer,LVMD)。

虽然功能单一,但其是使用频率最高的JDK命令行工具,其他工具大多需要输入它查询到的LVMID来确定要监控的是哪一个虚拟机进程。

对于本地虚拟机进程来说,LVMID与操作系统的进程ID(Process Identifier,PID)是一致的,使用Windows平台的任务管理器或UNIX平台的ps命令也可以查到LVMID,但若同时启动了多个虚拟机进程,无法根据进程名称进行定位时,就只能依赖于jps命令显式主类的功能来进行区分了。

1
2
3
4
5
6
7
8
# jps命令格式
$ jps [ options ] [ hostid ]

# jps执行样例
$ jps -l
2388 D:\Develop\glassfish\bin\..\modules\admin-cli.jar
2764 com.sun.enterprise.glassfish.bootstrap.ASMain
3788 sun.tools.jps.Jps

jps可以通过RMI协议查询开启了RMI服务的远程虚拟机进程状态,hostid为RMI注册表中注册的主机名。jps其他常用选项如下表。

选项 作用
-q 只输出LVMID,省略主类的名称
-m 输出虚拟机进程启动时传递给主类main()函数的参数
-l 输出主类的全名,如果进程执行的是Jar包,输出Jar路径
-v 输出虚拟机进程启动时JVM参数

2.2 jstat-虚拟机统计信息监视工具

JVM Statistics Monitoring Tool,是用于监视虚拟机各种运行状态信息的命令行工具。可以显示本地或远程虚拟机进程中的类装载、内存、垃圾收集、JIT编译等运行数据,在没有GUI图形界面,只提供了纯文本控制台环境的服务器上,它将是运行期定位虚拟机性能问题的首选工具

1
2
# jstat命令格式为:
$ jstat [ option vmid [interval[s|ms] [count] ] ]

对于命令格式中的VMID与LVMID需要特别说明一下:如果是本地虚拟机进程,VMID与LVMID是一致的,如果是远程虚拟机进程,那VMID的格式应当是:

1
[protocol:][//]lvmid[@hostname[:port]/servername]

参数interval和count代表查询间隔和次数,如果省略这两个参数,说明只查询一次。假设需要每250毫秒查询一次进程2764垃圾收集的状况,一共查询20次,那命令应当是:

1
2
3
4
5
6
$ jstat -gc 2764 250 20
S0C S1C S0U S1U EC EU OC OU MC MU CCSC CCSU YGC YGCT FGC FGCT GCT
7168.0 6656.0 1511.0 0.0 333824.0 208191.9 353792.0 113784.1 103060.0 99135.0 11452.0 10707.6 60 0.636 4 0.616 1.253
7168.0 6656.0 1511.0 0.0 333824.0 208191.9 353792.0 113784.1 103060.0 99135.0 11452.0 10707.6 60 0.636 4 0.616 1.253
7168.0 6656.0 1511.0 0.0 333824.0 208196.0 353792.0 113784.1 103060.0 99135.0 11452.0 10707.6 60 0.636 4 0.616 1.253
...

选项option代表着用户希望查询的虚拟机信息,主要分为3类:类装载、垃圾收集和运行期编译状况,具体选项及作用请参考表4-3中的描述。

jstat工具主要选项

举一例监视一台刚刚启动的GlassFish v3服务器的内存状况的例子来演示如何查看监视结果。监视参数与输出结果如代码清单4-1所示。

jstat执行样例

查询结果表明:

  • S0、S1:两个Survivor区(S0、S1,表示Survivor0、Survivor1)里面都是空的。
  • E:新生代Eden区(E,表示Eden)使用了6.2%的空间。
  • O:老年代(O,表示Old)使用了41.42%的空间。
  • P:永久代(P,表示Permanent)使用了47.20%的空间。
  • YGC:程序运行以来共发生Minor GC(YGC,表示Young GC)16次。
  • TGCT:Minor GC总耗时0.105 秒。
  • FGC:发生Full GC(FGC,表示Full GC)3次
  • FGCT:Full GC总耗时(FGCT,表示Full GC Time)为0.472秒。
  • GCT:所有GC总耗时(GCT,表示GC Time)为0.577秒。

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

2.3 jinfo-Java配置信息工具

jinfo(Configuration Info for Java)的作用是实时地查看和调整虚拟机的各项参数。使用jps命令的-v参数可以查看虚拟机启动时显式指定的参数列表,但如果想知道未被显式指定的参数的系统默认值,除了去找资料外,就只能使用jinfo的flag选项进行查询了(如果只限于JDK 1.6或以上版本的话,使用 java -XX:+PrintFlagsFinal 查看参数默认值也是一个很好的选择),jinfo还可以使用sysprops选项把虚拟机进程的 System.getProperties() 的内容打印出来。

这个命令在JDK 1.5时期已经随着Linux版的JDK发布,当时只提供了信息查询的功能,JDK 1.6之后,jinfo在Windows和Linux平台都有提供,并且加入了运行期修改参数的能力,可以使用 -flag [+|-] name-flag name = value 修改一部分运行期可写的虚拟机参数值。JDK 1.6中,jinfo对于Windows平台的功能仍然有较大的限制,只提供了最基本的-flag选项。

1
2
3
4
5
6
# jinfo命令格式:
$ jinfo [ option ] pid

# 执行样例:查询CMSInitiatingOccupancyFraction参数值。
$ jinfo -flag CMSInitiatingOccupancyFraction 1444
-XX:CMSInitiatingOccupancyFraction=85

2.4 jmap-Java内存映像工具

jmap(Memory Map for Java)命令用于生成堆转储快照(一般称为heapdump或dump文件)。如果不使用jmap命令,要想获取Java堆转储快照还有一些比较“暴力”的手段:

  • -XX:HeapDumpOnOutOfMemoryError 参数,可以让虚拟机在OOM异常出现之后自动生成dump文件
  • 通过 -XX:HeapDumpOnCtrlBreak 参数则可以使用 Ctrl + Break 键让虚拟机生成dump文件
  • 在Linux系统下通过 Kill-3 命令发送进程退出信号“恐吓”一下虚拟机,也能拿到dump文件。

jmap的作用并不仅仅是为了获取dump文件,它还可以查询finalize执行队列,Java堆和永久代的详细信息,如空间使用率、当前用的是哪种收集器等。

和jinfo命令一样,jmap有不少功能在Windows平台下都是受限的,除了生成dump文件的-dump选项和用于查看每个类的实例、空间占用统计的-histo选项所有操作系统都提供之外,其余选项都只能在Linux/Solaris下使用。

1
2
# jmap命令格式:
$ jmap [ option ] vmid

option选项的合法值与具体含义如表4-4所示

jmap工具主要选项

使用jmap生成一个正在运行的Eclipse的dump快照文件,例子中的3500是通过jps命令查询到的LVMID:

1
2
3
4
5
$ jmap -dump:format=b,file=eclipse.bin 3500
Dumping heap to C:\Users\IcyFenix\eclipse.bin……
Heap dump file created
# 常用
$ jmap -dump:format=b,file=xxx.dump 13870

查看Java堆详细信息:

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
$ jmap -heap 61017
Attaching to process ID 61017, please wait...
Debugger attached successfully.
Server compiler detected.
JVM version is 25.181-b13

using thread-local object allocation.
# 看出使用了Parallel GC收集器
Parallel GC with 8 thread(s)

Heap Configuration:
MinHeapFreeRatio = 0
MaxHeapFreeRatio = 100
# 堆最大内存
MaxHeapSize = 1073741824 (1024.0MB)
NewSize = 89128960 (85.0MB)
MaxNewSize = 357564416 (341.0MB)
OldSize = 179306496 (171.0MB)
NewRatio = 2
SurvivorRatio = 8
# 当前元空间大小
MetaspaceSize = 21807104 (20.796875MB)
CompressedClassSpaceSize = 1073741824 (1024.0MB)
# 最大元空间大小
MaxMetaspaceSize = 17592186044415 MB
G1HeapRegionSize = 0 (0.0MB)

Heap Usage:
PS Young Generation
Eden Space:
capacity = 353370112 (337.0MB)
used = 66019256 (62.96086883544922MB)
free = 287350856 (274.0391311645508MB)
18.682750396275733% used
From Space:
capacity = 1572864 (1.5MB)
used = 1330296 (1.2686691284179688MB)
free = 242568 (0.23133087158203125MB)
84.57794189453125% used
To Space:
capacity = 2097152 (2.0MB)
used = 0 (0.0MB)
free = 2097152 (2.0MB)
0.0% used
PS Old Generation
capacity = 457703424 (436.5MB)
used = 341160408 (325.35591888427734MB)
free = 116543016 (111.14408111572266MB)
74.53743846146102% used

34932 interned Strings occupying 3427568 bytes.

2.5 jhat-虚拟机堆转储快照分析工具

Sun JDK提供jhat(JVM Heap Analysis Tool)命令与jmap搭配使用,来分析jmap生成的堆转储快照。jhat内置了一个微型的HTTP/HTML服务器,生成dump文件的分析结果后,可以在浏览器中查看。

不过实事求是地说,在实际工作中,除非真的没有别的工具可用,否则一般都不会去直接使用jhat命令来分析dump文件,主要原因有二:一是一般不会在部署应用程序的服务器上直接分析dump文件,即使可以这样做,也会尽量将dump文件拷贝到其他机器上进行分析,因为分析工作是一个耗时而且消耗硬件资源的过程,既然都要在其他机器上进行,就没必要受到命令行工具的限制了。另外一个原因是jhat的分析功能相对来说比较简陋,后文将会介绍到VisualVM,以及专业用于分析dump文件的Eclipse Memory Analyzer、IBM HeapAnalyzer等工具,都能实现比jhat更强大更专业的分析功能。代码清单4-3演示了使用jhat分析上一节采用jmap生成的Eclipse IDE的内存快照文件。

1
2
3
4
5
6
7
8
9
10
11
--代码清单4-3 使用jhat分析dump文件
C:\Users\IcyFenix>jhat eclipse.bin
Reading from eclipse.bin……
Dump file created Fri Nov 19 220721 CST 2010
Snapshot read, resolving……
Resolving 1225951 objects……
Chasing references, expect 245 dots……
Eliminating duplicate references……
Snapshot resolved.
Started HTTP server on port 7000
Server is ready.

屏幕显示“Server is ready.”的提示后,用户在浏览器中键入http://localhost:7000/就可以看到分析结果,如图4-3所示。

jhat的分析结果

分析结果默认以包为单位进行分组显示,分析内存泄漏问题主要会使用到其中的“Heap Histogram”(与jmap-histo功能一样)与OQL页签的功能,前者可以找到内存中总容量最大的对象,后者是标准的对象查询语言,使用类似SQL的语法对内存中的对象进行查询统计。

2.6 jstack:Java堆栈跟踪工具

jstack(Stack Trace for Java)命令用于生成虚拟机当前时刻的线程快照(一般称为threaddump或javacore文件)。线程快照就是当前虚拟机内每一条线程正在执行的方法堆栈的集合,生成线程快照的主要目的是定位线程出现长时间停顿的原因,如线程间死锁、死循环、请求外部资源导致的长时间等待等都是导致线程长时间停顿的常见原因。线程出现停顿的时候通过jstack来查看各个线程的调用堆栈,就可以知道没有响应的线程到底在后台做些什么事情,或者等待着什么资源。

1
2
--jstack命令格式:
jstack [ option ] vmid

option选项的合法值与具体含义如表4-5所示。

jstack工具的主要选项

代码清单4-4是使用jstack查看Eclipse线程堆栈的例子,例子中的3500是通过jps命令查询到的LVMID。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
代码清单4-4 使用jstack查看线程堆栈(部分结果)
C:\Users\IcyFenix>jstack-l 3500
2010-11-19 231126
Full thread dump Java HotSpot(TM)64-Bit Server VM(17.1-b03 mixed mode):
"[ThreadPool Manager] - Idle Thread" daemon prio=6 tid=0x0000000039dd4000 nid=0xf50 in Object.wait() [0x000000003c96f000]
java.lang.Thread.State:WAITING(on object monitor)
at java.lang.Object.wait(Native Method)
-waiting on<0x0000000016bdcc60>(a org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor)
at java.lang.Object.wait(Object.java:485
at org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor.run(Exe 106
-locked<0x0000000016bdcc60>(a org.eclipse.equinox.internal.util.impl.tpt.threadpool.Executor)

Locked ownable synchronizers:
-None

在JDK 1.5中,java.lang.Thread类新增了一个getAllStackTraces()方法用于获取虚拟机中所有线程的StackTraceElement对象。使用这个方法可以通过简单的几行代码就完成jstack的大部分功能,在实际项目中不妨调用这个方法做个管理员页面,可以随时使用浏览器来查看线程堆栈,如代码清单4-5所示,这是书作者的一个小经验。

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
代码清单4-5 查看线程状况的JSP页面
<%@ page import="java.util.Map"%>

<html>
<head>
<title>服务器线程信息</title>
</head>
<body>
<pre>
<%
for(Map.Entry<Thread, StackTraceElement[]>stackTrace: Thread.getAllStackTraces().entrySet()){
Thread thread=(Thread)stackTrace.getKey();
StackTraceElement[]stack=(StackTraceElement[]) stackTrace.getValue();
if(thread.equals(Thread.currentThread())){
continue;
}
out.print("\n线程:"+thread.getName()+"\n");
for(StackTraceElement element:stack){
out.print("\t"+element+"\n");
}
}
%>
</pre>
</body>
</html>

2.7 HSDIS:JIT生成代码反汇编

在Java虚拟机规范中,详细描述了虚拟机指令集中每条指令的执行过程、执行前后对操作数栈、局部变量表的影响等细节。这些细节描述与Sun的早期虚拟机高度吻合,但随着技术的发展,高性能虚拟机真正的细节实现方式已经渐渐与虚拟机规范所描述的方式产生了越来越大的差距,虚拟机规范的描述逐渐成了虚拟机实现的“概念模型”——即实现只能保证规范描述等效。基于这个原因,我们分析程序的执行语义问题(虚拟机做了什么)时,在字节码层面上分析完全可行,但分析程序的执行行为问题(虚拟机是怎样做的、性能如何)时,在字节码层面上分析就没有什么意义了,需要通过其他方式解决。

分析程序如何执行,通过软件调试工具(CDB、Windbg等)来断点调试是最常见的手段,但这样的调试方式在Java虚拟机中会遇到很大的困难,因为大量执行代码是通过JIT编译器动态生成到CodeBuffer中的,没有很简单的手段来处理这种混合模式的调试。基于这种背景来引入HSDIS插件。

HSDIS是一个Sun官方推荐的HotSpot虚拟机JIT编译代码的反汇编插件,它包含在HotSpot虚拟机的源码中,但没有提供编译后的程序。可以在Project Kenai网站下载到单独的源码。它的作用是让HotSpot的-XX:+PrintAssembly指令调用它来把动态生成的本地代码还原为汇编代码输出,同时还生成了大量非常有价值的注释,这样我们就可以通过输出的代码来分析问题。我们可以根据自己的操作系统和CPU类型从Project Kenai网站上下载编译好的插件,直接放到JDK_HOME/jre/bin/client和JDK_HOME/jre/bin/server目录中即可。

如果使用的是Debug或FastDebug版的HotSpot,可以直接通过-XX:+PrintAssembly指令使用插件;如果使用的是Product版的HotSpot,还需要额外加入一个-XX:+UnlockDiagnosticVMOptions参数。以下简单测试代码演示如何使用插件。

1
2
3
4
5
6
7
8
9
10
11
12
public class Bar {
int a = 1;
static int b = 2;

public int sum(int c) {
return a + b + c;
}

public static void main(String[] args) {
new Bar.sum(3);
}
}

编译这段代码,并使用以下命令执行。

1
java -XX:+PrintAssembly -Xcomp -XX:CompileCommand=dontinline,*Bar.sum -XX:CompileCommand=compileonly,*Bar.sum test.Bar

其中,-Xcomp是让虚拟机以编译模式执行代码,这样代码可以“偷懒”,不需要执行足够次数来预热就可以触发JIT编译(此指令在较新的HotSpot中被移除了,可以加个循环预热代码从而触发JIT编译)。两个-XX:CompileCommand意思是让编译器不要内联sum()并且只编译sum(),-XX:+PrintAssembly就是输出反汇编内容。

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
[Disassembling for mach='i386']
[Entry Point]
[Constants]
# {method} 'sum' '(I)I' in 'test/Bar'
# this: ecx = 'test/Bar'
# parm0: edx = int
# [sp+0x20] (sp of caller)
……
0x01cac407: cmp 0x4(%ecx),%eax
0x01cac40a: jne 0x01c6b050 ; {runtime_call}
[Verified Entry Point]
0x01cac410: mov %eax,-0x8000(%esp)
0x01cac417: push %ebp
0x01cac418: sub $0x18,%esp ;*aload_0
; - test.Bar::sum@0 (line 8)
;; block B0 [0, 10]

0x01cac41b: mov 0x8(%ecx),%eax ;*getfield a
; - test.Bar::sum@1 (line 8)
0x01cac41e: mov $0x3d2fad8,%esi ; {oop(a
'java/lang/Class' = 'test/Bar')}
0x01cac423: mov 0x68(%esi),%esi ;*getstatic b
; - test.Bar::sum@4 (line 8)
0x01cac426: add %esi,%eax
0x01cac428: add %edx,%eax
0x01cac42a: add $0x18,%esp
0x01cac42d: pop %ebp
0x01cac42e: test %eax,0x2b0100 ; {poll_return}
0x01cac434: ret

代码并不多,一句一句来看:

  1. mov %eax,-0x8000(%esp):检查栈溢。
  2. push %ebp:保存上一栈帧基址。
  3. sub $0x18,%esp:给新帧分配空间。
  4. mov 0x8(%ecx),%eax:取实例变量a,这里0x8(%ecx)就是ecx+0x8的意思,前面“[Constants]”节中提示了“this:ecx = ‘test/Bar’”,即ecx寄存器中放的就是this对象的地址。偏移0x8是越过this对象的对象头,之后就是实例变量a的内存位置。这次是访问“Java堆”中的数据。
  5. mov $0x3d2fad8,%esi:取test.Bar在方法区的指针。
  6. mov 0x68(%esi),%esi:取类变量b,这次是访问“方法区”中的数据。
  7. add %esi,%eax 、add %edx,%eax:做2次加法,求a+b+c的值,前面的代码把a放在eax中,把b放在esi中,而c在[Constants]中提示了,“parm0:edx = int”,说明c在edx中。
  8. add $0x18,%esp:撤销栈帧。
  9. pop %ebp:恢复上一栈帧。
  10. test %eax,0x2b0100:轮询方法返回处的SafePoint
  11. ret:方法返回。[/list]

三. JDK的可视化工具

JDK中除了提供大量的命令行工具外,还有两个功能强大的可视化工具:JConsole和VisualVM,这两个工具是JDK的正式成员,没有被贴上“unsupported and experimental”的标签。

其中JConsole是在JDK 1.5时期就已经提供的虚拟机监控工具,而VisualVM在JDK 1.6 Update7中才首次发布,现在已经成为Sun(Oracle)主力推动的多合一故障处理工具,并且已经从JDK中分离出来成为可以独立发展的开源项目。

如果使用的是非Sun系列的JDK,非HotSpot的虚拟机,就需要使用对应的工具进行分析,如:

  • IBM的Support Assistant、Heap Analyzer、Javacore Analyzer、Garbage
  • Collector Analyzer适用于IBM J9 VM。
  • HP的HPjmeter、HPjtune适用于HP-UX、SAP、HotSpot VM。
  • Eclipse的Memory Analyzer Tool(MAT)适用于HP-UX、SAP、HotSpot VM
  • 安装IBM DTFJ插件后可支持IBM J9 VM。
  • BEA的JRockit Mission Control,适用于JRockit VM。

3.1 JConsole:Java监视与管理控制台

JConsole(Java Monitoring and Management Console)是一款基于JMX的可视化监视和管理的工具。它管理部分的功能是针对JMX MBean进行管理,由于MBean可以使用代码、中间件服务器的管理控制台或者所有符合JMX规范的软件进行访问,所以本节中将会着重介绍JConsole监视部分的功能。

3.1.1 启动JConsole

通过JDK/bin目录下的“jconsole.exe”启动JConsole后,将自动搜索出本机运行的所有虚拟机进程,不需要用户自己再使用jps来查询了,如图4-4所示。双击选择其中一个进程即可开始监控,也可以使用下面的“远程进程”功能来连接远程服务器,对远程虚拟机进行监控。

JConsole连接页面

从图4-4中可以看到作者的机器现在运行了Eclipse、JConsole和MonitoringTest一共三个本地虚拟机进程,其中MonitoringTest就是作者准备的“反面教材”代码之一。双击它进入JConsole主界面,可以看到主界面里共包括“概述”、“内存”、“线程”、“类”、“VM摘要”和“MBean”六个页签,如图4-5所示。

JConsole主界面

“概述”页签显示的是整个虚拟机主要运行数据的概览,其中包括“堆内存使用情况”、“线程”、“类”、“CPU使用情况”四项信息的曲线图,这些曲线图是后面“内存”、“线程”、“类”页签的信息汇总,具体内容将在后面介绍。

3.1.2 内存监控

“内存”页签相当于可视化的jstat命令,用于监视受收集器管理的虚拟机内存(Java堆和永久代)的变化趋势。我们通过运行下列代码清单中的代码来体验一下它的监视功能。运行时设置的虚拟机参数为:-Xms100m-Xmx100m-XX:+UseSerialGC,这段代码的作用是以64KB/50毫秒的速度往Java堆中填充数据,一共填充1000次,使用JConsole的“内存”页签进行监视,观察曲线和柱状指示图的变化。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
/**
*内存占位符对象,一个OOMObject大约占64K
*/
static class OOMObject{
public byte[] placeholder = new byte[64*1024];
}

public static void fillHeap (int num) throws InterruptedException{
List<OOMObject> list = new ArrayList<OOMObject>();
for(int i=0; i<num; i++) {
//稍作延时,令监视曲线的变化更加明显
Thread.sleep(50);
list.add(new OOMObject());
}
System.gc();
}

public static void main(String[]args) throws Exception{
fillHeap(1000);
}

程序运行后,在“内存”页签中可以看到内存池Eden区的运行趋势呈现折线状,如图4-6所示。而监视范围扩大至整个堆后,会发现曲线是一条向上增长的平滑曲线。 并且从柱状图可以看到,在1000次循环执行结束,运行了System.gc()后,虽然整个新生代Eden和Survivor区都基本被清空了,但是代表老年代的柱状图仍然保持峰值状态,说明被填充进堆中的数据在System.gc()方法执行之后仍然存活着。作者的分析就到此为止,提两个小问题供读者思考一下,答案稍后给出。

  1. 虚拟机启动参数只限制了Java堆为100MB,没有指定-Xmn参数,能否从监控图中估计出新生代有多大?
  2. 为何执行了System.gc()之后,图4-6中代表老年代的柱状图仍然显示为峰值状态,代码需要如何调整才能让System.gc()回收掉填充到堆中的对象?

Eden区内存变化状况

问题1的答案:图4-6显示Eden空间为27328KB,因为没有设置-XX:SurvivorRadio参数,所以Eden与Survivor空间比例为默认值8:1,因此整个新生代空间大约为27328KB×125%=34160KB。

问题2的答案:System.gc()之后,空间未能回收是因为List list对象仍然存活着,fillHeap()方法仍然没有退出,因此list对象在执行 System.gc()时仍然处于作用域之内。如果把System.gc()移动到fillHeap()方法外,调用就可以回收掉全部内存。

3.1.3 线程监控

如果上面的“内存”页签相当于可视化的jstat命令的话,“线程”页签的功能则相当于可视化的jstack命令,遇到线程停顿的时候可以使用这个页签进行监控分析。前面讲解jstack命令的时候提到过线程长时间停顿的主要原因有:等待外部资源(数据库连接、网络资源、设备资源等)、死循环、锁等待(活锁和死锁)。通过代码清单4-7分别演示一下这几种情况。

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
/**
*线程死循环演示
*/
public static void createBusyThread() {
Thread thread = new Thread(new Runnable(){
@Override
public void run(){
while(true);//第41行
}
},"testBusyThread");
thread.start();
}

/**
*线程锁等待演示
*/
public static void createLockThread(final Object lock) {
Thread thread=new Thread(new Runnable(){
@Override
public void run() {
synchronized(lock) {
try{
lock.wait();
}catch(InterruptedException e) {
e.printStackTrace();
}
}
}
},"testLockThread");
thread.start();
}

public static void main(String[]args) throws Exception{
BufferedReader br = new BufferedReader(new InputStreamReader(System.in));
br.readLine();
createBusyThread();
r.readLine();
bject obj=new Object();
reateLockThread(obj);
}

程序运行后,首先在“线程”页签中选择main线程,如图4-7所示。堆栈追踪显示 BufferedReader在readBytes方法中等待System.in的键盘输入,这时候线程为 Runnable状态,Runnable状态的进程会被分配运行时间,但readBytes方法检查到流没有更新时会立刻归还执行令牌,这种等待只消耗很小的CPU资源。

main线程

接着监控testBusyThread线程,如图4-8所示,testBusyThread线程一直在执行空循环,从堆栈追踪中可以看到一直停留在MonitoringTest.java代码的41行,41行为while(true)。这时候线程为Runnable状态,而且没有归还线程执行令牌的动作,会在空循环上用尽全部执行时间直到线程切换,这种等待会消耗较多的CPU资源。

testBusyThread线程

testLockThread线程

图4-9显示testLockThread线程在等待着lock对象的notify或notifyAll方法的出现,线程这时候处在WAITING状态,在被唤醒前不会被分配执行时间。

testLockThread线程正处于正常的活锁等待状态,只要lock对象的notify()或 notifyAll()方法被调用,这个线程便能激活以继续执行。下列代码清单演示了一个无法再被激活的死锁等待。

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
/**
*线程死锁等待演示
*/
static class SynAddRunalbe implements Runnable{
int a, b;

public SynAddRunalbe(int a, int b){
this.a=a;
this.b=b;
}

@Override
public void run(){
synchronized(Integer.valueOf(a)){
synchronized(Integer.valueOf(b)){
System.out.println(a+b);
}
}
}
}

public static void main(String[]args){
for(int i=0;i<100;i++){
new Thread(new SynAddRunalbe(12)).start();
new Thread(new SynAddRunalbe(21)).start();
}
}

这段代码开了200个线程分别去计算1+2及2+1的值,其实for循环是可省略的,两个线程也可能会导致死锁,不过那样概率太小,需要尝试运行很多次才能看到效果。如果运气不是特别差的话,带for循环的版本最多运行2~3次就会遇到线程死锁,程序无法结束。造成死锁的原因是Integer.valueOf()方法基于减少对象创建次数 和节省内存的考虑,[-128,127]之间的数字会被缓存,当valueOf()方法在这个范围之内传入参数,将直接返回缓存中的对象。也就是说代码中调用了200次 Integer.valueOf()方法一共就只返回了两个不同的对象。假如在某个线程的两 个synchronized块之间发生了一次线程切换,就会出现线程A等着被线程B持有的 Integer.valueOf(1),线程B又等着被线程A持有的Integer.valueOf(2),结果大家都跑不下去的情景。

出现线程死锁之后,点击JConsole线程面板的“检测到死锁”的按钮,将出现一个新的“死锁”页签,如图4-10所示。

线程死锁

图中很清晰地显示线程Thread-43在等待一个被线程Thread-12持有Integer对象,而点击线程Thread-12则显示它也在等待一个Integer对象,被线程Thread-43持有,这样两个线程就互相卡住,都不存在等到锁释放的希望了。

3.2 VisualVM:多合一故障处理工具

VisualVM(All-in-One Java Troubleshooting Tool)是到目前为止,随JDK发布的功能最强大的运行监视和故障处理程序,并且可以预见在未来一段时间内都是官方主力发展的虚拟机故障处理工具。官方在VisualVM的软件说明中写上了“All-in-One”的描述字样,预示着它除了运行监视、故障处理外,还提供了很多其他方面的功能。如性能分析(Profiling),VisualVM的性能分析功能甚至比起JProfiler、YourKit等专业且收费的Profiling工具都不会逊色多少,而且VisualVM的还有一个很大优点:不需要被监视的程序基于特殊Agent运行,因此它对应用程序的实际性能的影响很小,使得它可以直接应用在生产环境中。这个优点是JProfiler、YourKit等工具无法与之媲美的。

3.2.1 VisualVM兼容范围与插件安装

VisualVM基于NetBeans平台开发,因此它一开始就具备了插件扩展功能的特性。

通过插件扩展支持,VisualVM可以做到:

  • 显示虚拟机进程及进程的配置和环境信息(jps、jinfo)。
  • 监视应用程序的CPU、GC、堆、方法区及线程的信息(jstat、jstack)。
  • dump及分析堆转储快照(jmap、jhat)。
  • 方法级的程序运行性能分析,找出被调用最多、运行时间最长的方法。
  • 离线程序快照:收集程序的运行时配置、线程dump、内存dump等信息建立一个快照,可以将快照发送开发者处进行Bug反馈。
  • 其他plugins的无限的可能性……

VisualVM在JDK 1.6 update 7中才首次出现,但并不意味着它只能监控运行于JDK 1.6上的程序,它具备很强的向下兼容能力,甚至能向下兼容至近10年前发布的JDK 1.4.2平台,这对无数已经处于实施、维护状态的项目很有意义。当然,并非所有的功能都能完美地向下兼容,主要特性的兼容性如表4-6所示。

VisualVM主要特性的兼容性列表

首次启动VisualVM后,读者先不必着急找应用程序进行监测,因为现在VisualVM还 没有加载任何插件,虽然基本的监视、线程面板的功能主程序都以默认插件的形式 提供了,但是不给VisualVM装任何扩展插件,就相当于放弃了它最精华的功能,和没有安装任何应用软件操作系统差不多。

插件可以手工安装,在网站上下载*.nbm包后,点击“工具”→“插件”→“已下 载”菜单,然后在弹出的对话框中指定nbm包路径便可进行安装,插件安装后存放在 JDK_HOME/lib/visualvm/visualvm中。不过手工安装并不常用,使用VisualVM 的自动安装功能已经可以找到所需的大多数插件,在有网络连接的环境下,点击“工具”→“插件”菜单,弹出如图4-11所示的插件页签,在页签的“可用插 件”中列举了当前版本VisualVM可以使用的插件,选中插件后在右边窗口将显示这个插件的基本信息,如开发者、版本、功能描述等。

VisualVM插件页签

大家可以根据自己的工作需要和兴趣选择合适的插件,然后点击安装按钮,弹出如 图4-12所示的下载进度窗口,跟着提示操作稍后即可安装完成。

VisualVM插件安装过程

安装完插件后,选择一个需要监视的程序就进入程序的主界面了,如图4-13所示。根据读者选择安装插件数量的不同,看到的页签可能和图4-13中的会有差异。

VisualVM主界面

VisualVM中“概述”、“监视”、“线程”、“MBeans”的功能与前面介绍的JConsole差别不大,读者根据上一节的内容类比使用即可,下面挑选几个特色功能和插件进行介绍。

3.2.2 生成和浏览堆转储快照

在VisualVM中生成dump文件有两种方式,可以执行下列任一操作:

  • 在“应用程序”窗口中右键单击应用程序节点,然后选择“堆Dump”。
  • 在“应用程序”窗口中双击应用程序节点以打开应用程序标签,然后在“监视”标 签中单击“堆Dump”。

生成了dump文件之后,应用程序页签将在该堆的应用程序下增加一个以[heapdump] 开头的子节点,并且在主页签中打开该转储快照,如图4-14所示。如果需要把dump文件保存或发送出去,要在heapdump节点上右键选择“另存为”菜单,否则当VisualVM关闭时,生成的dump文件会被当做临时文件被删除掉。要打开一个已经存在的dump文件,通过文件菜单中的“装入”功能,选择硬盘上的dump文件即可。

浏览dump文件

从堆页签中的“摘要”面板可以看到应用程序dump时的运行时参数、System.getProperties()的内容、线程堆栈等信息,“类”面板则是以类为统 计口径统计类的实例数量和容量信息,“实例”面板不能直接使用,因为不能确定 用户想查看哪个类的实例,所以需要通过“类”面板进入,在“类”中选择一个关 心的类后双击鼠标,即可在“实例”中看见此类中500个实例的具体属性信息。“OQL控制台”面板里面就是运行OQL查询语句的,同jhat里面介绍的OQL功能 一样。如果需要了解具体OQL语法和使用,可参见本书附录D的内容。

3.2.3 分析程序性能

在Profiler页签中,VisualVM提供了程序运行期间方法级的CPU执行时间分析及内存分析,进行Profiling分析肯定会对程序运行性能有比较大的影响,所以一般不在生产环境中使用这项功能。

要开始分析,先选择“CPU”和“内存”按钮中的一个,然后切换到应用程序中对程序进行操作,VisualVM会记录到这段时间中应用程序执行过的方法。如果是CPU分析,将会统计每个方法的执行次数、执行耗时;如果是内存分析则会统计每个方法 关联的对象数及这些对象所占的空间。分析结束后,点击“停止”按钮结束监控过 程,如图4-15所示。

对应用程序进行CPU执行时间分析

注意:在JDK 1.5之后,在Client模式下的虚拟机加入并且自动开启了类共享—这是一个在多虚拟机进程中共享rt.jar中的类数据以提高加载速度和节省内存的优化,而根据相关Bug报告的反映,VisualVM的Profiler功能可能会因为类共享而导致被 监视的应用程序崩溃,所以读者进行Profiling前,最好在被监视的程序中使用Xshare:off参数来关闭类共享优化。

图4-15中是对Eclipse IDE一段操作的录制和分析结果,读者分析自己的应用程序 时,可以根据实际业务的复杂程度与方法的时间和调用次数做比较,找到最有优化价值的方法。

3.2.4 BTrace动态日志跟踪

BTrace是一个很“有趣”的VisualVM插件,本身也是可以独立运行的程序。它的作用是在不停止目标程序运行的前提下,通过HotSpot虚拟机的HotSwap技术动态加入原本并不存在的调试代码。这项功能对实际生产中的程序很有意义:经常遇到程序出现问题,但排查错误的一些必要信息,譬如方法参数、返回值等,在开发时并没有打印到日志之中,以至于不得不停掉服务,通过调试增量来加入日志代码以解决问题。当遇到生产环境服务无法随便停止时,缺一两句日志导致排错进行不下去是一件非常郁闷的事情。

在VisualVM中安装了BTrace插件后,应用程序面板右键点击要调试的程序,会出现“Trace Application”菜单,点击将进入BTrace面板。这个面板里面看起来就像一个简单的Java程序开发环境,里面还有一小段Java代码,如图4-16所示。

BTrace动态跟踪

作者准备了一段很简单的Java代码来演示BTrace的功能:产生两个1000以内的随机整数,输出这2个数字相加的结果,如代码清单4-9BTrace跟踪演示所示。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
public class BTraceTest{
public int add(int a, int b){
return a+b;
}

public static void main(String[]args) throws IOException {
BTraceTest test = new BTraceTest();
BufferedReader reader = new BufferedReader(new InputStreamReader(System.in));
for(int i=0;i<10;i++){
reader.readLine();
int a = (int)Math.round(Math.random()*1000);
int b = (int)Math.round(Math.random()*1000);
System.out.println(test.add(a, b));
}
}
}

程序运行后,在VisualVM中打开该程序的监视,在BTrace页签填充TracingScript的内容,输入调试代码如代码清单4-10BTrace调试代码所示。

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
/*BTrace Script Template*/
import com.sun.btrace.annotations.*;
import static com.sun.btrace.BTraceUtils.*;

@BTrace
public class TracingScript{

@OnMethod(clazz="org.fenixsoft.monitoring.BTraceTest",
method="add",
location=@Location(Kind.RETURN))
public static void func(@Self org.fenixsoft.monitoring.BTraceTest instance, int a, int b, @Return int result){
println("调用堆栈:");
jstack();
println(strcat("方法参数A:", str(a)));
println(strcat("方法参数B:", str(b)));
println(strcat("方法结果:", str(result)));
}
}

点击“Start”按钮后稍等片刻,编译完成后,可见Output面板中出现“BTrace code successfuly deployed”的字样。程序运行的时候在Output面板将会输出 如图4-17所示的调试信息。

BTrace跟踪结果

BTrace的用法还有许多,打印调用堆栈、参数、返回值只是最基本的应用,在它的 网站上有使用BTrace进行性能监视、定位连接泄漏、内存泄漏、解决多线程竞争问题等的使用例子,有兴趣的读者可以去网上了解相关信息。


参考:

🔗 《深入理解Java虚拟机》