给一个系统定位问题的时候,知识、经验是关键基础,数据是依据,工具是运用知识处理数据的手段。这里说的数据包括:运行日志、异常堆栈、GC日志、线程快照(threaddump/javacore文件)、堆转储快照(heapdump/hprof文件)等。经常使用适当的虚拟机监控和分析的工具可以加快我们分析数据、定位解决问题的速度。
JDK的bin目录中有“java.exe”、“javac.exe”这两个最常见的命令行工具,应该在座的各位都有接触过,通过这两个工具,我们可以实现使用记事本编写java程序以及运行java程序。
可以看到,JDK中的工具都十分小巧,因为这些命令行工具大多数是jdk/lib/tools.jar类库的一层薄包装而已,它们主要的功能代码是在tools类库中实现的。
如果读者在工作中需要监控运行于JDK 1.5的虚拟机之上的程序,在程序启动时请添加参数“-Dcom.sun.management.jmxremote”开启JMX管理功能,否则由于部分工具都是基于JMX,它们都将会无法使用,如果被监控程序运行于JDK1.6的虚拟机之上,那JMX管理默认是开启的,虚拟机启动时无须再添加任何参数。
jps:虚拟机进程状况工具
功能:可以列出正在运行的虚拟机进程,并显示虚拟机执行主类(Main Class,main()函数所在的类)名称以及这些进程的本地虚拟机唯一ID(Local Virtual Machine Identifier,LVMID)。
虽然功能比较单一,但它是使用频率最高的JDK命令行工具,因为其他的JDK工具大多需要输入它查询到的LVMID来确定要监控的是哪一个虚拟机进程。对于本地虚拟机进程来说,LVMID与操作系统的进程ID(Process Identifier,PID)是一致的,使用Windows的任务管理器或者UNIX的ps命令也可以查询到虚拟机进程的LVMID,但如果同时启动了多个虚拟机进程,无法根据进程名称定位时,那就只能依赖jps命令显示主类的功能才能区分了。
jsp命令格式:
jps[options][hostid]
jps执行样例:
D:\Develop\Java\jdk1.6.0_21\bin>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注册表中注册的主机名。
jstat:虚拟机统计信息监视工具
功能:jstat(JVM Statistics Monitoring Tool)是用于监视虚拟机各种运行状态信息的命令行工具。
它可以显示本地或者远程虚拟机进程中的类装载、内存、垃圾收集、JIT编译等运行数据,在没有GUI图形界面,只提供了纯文本控制台环境的服务器上,它将是运行期定位虚拟机性能问题的首选工具。
jstat命令格式为:
jstat[option vmid[interval[s|ms][count]]]
对于命令格式中的VMID与LVMID需要特别说明一下:如果是本地虚拟机进程,VMID与LVMID是一致的,如果是远程虚拟机进程,那VMID的格式应当是:
[protocol:][//]lvmid[@hostname[:port]/servername]
参数interval和count代表查询间隔和次数,如果省略这两个参数,说明只查询一次。假设需要每250毫秒查询一次进程2764垃圾收集状况,一共查询20次,那命令应当是:
jstat-gc 2764 250 20
选项option代表着用户希望查询的虚拟机信息,主要分为3类:类装载、垃圾收集、运行期编译状况,如下:
jstat执行样例
D:\Develop\Java\jdk1.6.0_21\bin>jstat-gcutil 2764
S0 S1 E O P YGC YGCT FGC FGCT GCT
0.00 0.00 6.20 41.42 47.20 16 0.105 3 0.472 0.577
结果表明:这台服务器的新生代Eden区(E,表示Eden)使用了6.2%的空间,两个Survivor区(S0、S1,表示Survivor0、Survivor1)里面都是空的,老年代(O,表示Old)和永久代(P,表示Permanent)则分别使用了41.42%和47.20%的空间。程序运行以来共发生Minor GC(YGC,表示Young GC)16次,总耗时0.105秒,发生Full GC(FGC,表示FullGC)3次,Full GC总耗时(FGCT,表示Full GC Time)为0.472秒,所有GC总耗时(GCT,表示GC Time)为0.577秒。
jinfo:Java配置信息工具
功能:jinfo(Configuration Info for Java)的作用是实时地查看和调整虚拟机各项参数。
使用jps命令的-v参数可以查看虚拟机启动时显式指定的参数列表,但如果想知道未被显式指定的参数的系统默认值,除了去找资料外,就只能使用jinfo的-flag选项进行查询了。
jinfo命令格式:
jinfo[option]pid
执行样例:查询CMSInitiatingOccupancyFraction参数值。
C:\>jinfo-flag CMSInitiatingOccupancyFraction 1444
-XX:CMSInitiatingOccupancyFraction=85
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下使用。
jmap命令格式:
jmap[option]vmid
option选项的合法值与具体含义
使用jmap生成dump文件
C:\Users\IcyFenix>jmap-dump:format=b,file=eclipse.bin 3500
Dumping heap to C:\Users\IcyFenix\eclipse.bin……
Heap dump file created
jhat:虚拟机堆转储快照分析工具
功能:jhat(JVM Heap Analysis Tool)命令与jmap搭配使用,来分析jmap生成的堆转储快照。
jhat内置了一个微型的HTTP/HTML服务器,生成dump文件的分析结果后,可以在浏览器中查看。不过在实际工作中,除非笔者手上真的没有别的工具可用,否则一般都不会去直接使用jhat命令来分析dump文件,主要原因有二:
- 一是一般不会在部署应用程序的服务器上直接分析dump文件,即使可以这样做,也会尽量将dump文件复制到其他机器上进行分析,因为分析工作是一个耗时而且消耗硬件资源的过程,既然都要在其他机器进行,就没有必要受到命令行工具的限制了。
- 另一个原因是jhat的分析功能相对来说比较简陋。
使用jhat分析dump文件
C:\Users\IcyFenix>jhat eclipse.bin
Reading from eclipse.bin……
Dump file created Fri Nov 19 22:07:21 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/就可以看到分析结果
分析结果默认是以包为单位进行分组显示,分析内存泄漏问题主要会使用到其中的“Heap Histogram”(与jmap-histo功能一样)与OQL页签的功能,前者可以找到内存中总容量最大的对象,后者是标准的对象查询语言,使用类似SQL的语法对内存中的对象进行查询统计。
jstack:Java堆栈跟踪工具
功能:jstack(Stack Trace for Java)命令用于生成虚拟机当前时刻的线程快照(一般称为threaddump或者javacore文件)。
线程快照就是当前虚拟机内每一条线程正在执行的方法堆栈的集合,生成线程快照的主要目的是定位线程出现长时间停顿的原因,如线程间死锁、死循环、请求外部资源导致的长时间等待等都是导致线程长时间停顿的常见原因。线程出现停顿的时候通过jstack来查看各个线程的调用堆栈,就可以知道没有响应的线程到底在后台做些什么事情,或者等待着什么资源。
jstack命令格式:
jstack[option]vmid
option选项的合法值与具体含义
使用jstack查看线程堆栈(部分结果)
C:\Users\IcyFenix>jstack-l 3500
2010-11-19 23:11:26
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(Executor.java: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的大部分功能,在实际项目中不妨调用这个方法做个管理员页面,可以随时使用浏览器来查看线程堆栈。
查看线程状况的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>
HSDIS:JIT生成代码反汇编
功能:它的作用是让HotSpot的-XX:+PrintAssembly指令调用它来把动态生成的本地代码还原为汇编代码输出,同时还生成了大量非常有价值的注释,这样我们就可以通过输出的代码来分析问题。
测试代码
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);
}
}
编译这段代码,并使用以下命令执行:
java-XX:+PrintAssembly-Xcomp-XX:CompileCommand=dontinline,*Bar.sum-XX:Compi leCommand=compileonly,*Bar.sum test.Bar
其中,参数 -Xcomp是让虚拟机以编译模式执行代码,这样代码可以“偷懒”,不需要执行足够次数来预热就能触发JIT编译。两个 -XX:CompileCommand意思是让编译器不要内联sum()并且只编译sum(), -XX:+PrintAssembly就是输出反汇编内容。如果一切顺利的话,那么屏幕上会出现类似下面所示的内容:
测试代码
[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:做两次加法,求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:方法返回。