给系统定位问题,知识、经验是关键基础,数据时依据,工具是运用知识处理数据的手段。
数据:运行日志 异常堆栈 GC日志 线程快照(threaddump/javacore文件) 堆转储快照(heapdump/hprof文件)
一 JDK命令行工具
1 jps 虚拟机进程状况工具
常用的几个参数:
-l 输出java应用程序的main class的完整包
-q 仅显示pid,不显示其它任何相关信息
-m 输出传递给main方法的参数
-v 输出传递给JVM的参数。在诊断JVM相关问题的时候,这个参数可以查看JVM相关参数的设置
2 jstat 虚拟机统计信息监视工具
jstat [ generalOption | outputOptions vmid [interval[s|ms] [count]] ]
vmid是虚拟机ID,在Linux/Unix系统上一般就是进程ID。interval是采样时间间隔。count是采样数目。比如下面输出的是GC信息,采样时间间隔为250ms,采样数为4:
1
2
3
4
5
6
|
root@ubuntu:/
# jstat -gc 21711 250 4
S0C S1C S0U S1U EC EU OC OU PC PU YGC YGCT FGC FGCT GCT
192.0 192.0 64.0 0.0 6144.0 1854.9 32000.0 4111.6 55296.0 25472.7 702 0.431 3 0.218 0.649
192.0 192.0 64.0 0.0 6144.0 1972.2 32000.0 4111.6 55296.0 25472.7 702 0.431 3 0.218 0.649
192.0 192.0 64.0 0.0 6144.0 1972.2 32000.0 4111.6 55296.0 25472.7 702 0.431 3 0.218 0.649
192.0 192.0 64.0 0.0 6144.0 2109.7 32000.0 4111.6 55296.0 25472.7 702 0.431 3 0.218 0.649
|
要明白上面各列的意义,先看JVM堆内存布局:
1
2
|
堆内存 = 年轻代 + 年老代 + 永久代
年轻代 = Eden区 + 两个Survivor区(From和To)
|
现在来解释各列含义:
1
2
3
4
5
6
7
|
S0C、S1C、S0U、S1U:Survivor 0
/1
区容量(Capacity)和使用量(Used)
EC、EU:Eden区容量和使用量
OC、OU:年老代容量和使用量
PC、PU:永久代容量和使用量
YGC、YGCT:年轻代GC次数和GC耗时
FGC、FGCT:Full GC次数和Full GC耗时
GCT:GC总耗时
|
3 jinfo java配置信息工具
观察运行中的java程序的运行环境参数:参数包括Java System属性和JVM命令行参数
实例:jinfo 2083
其中2083就是java进程id号,可以用jps得到这个id号。
输出内容太多了,不在这里一一列举,大家可以自己尝试这个命令。
4 jmap Java内存映像工具
jmap(Memory Map)和 jhat(Java Heap Analysis Tool)
jmap用来查看堆内存使用状况,一般结合jhat使用。
jmap语法格式如下:
1
2
3
|
jmap [option] pid
jmap [option] executable core
jmap [option] [server-
id
@]remote-
hostname
-or-ip
|
1
|
jmap -permstat pid
|
打印进程的类加载器和类加载器加载的持久代对象信息,输出:类加载器名称、对象是否存活(不可靠)、对象地址、父类加载器、已加载的类大小等信息
使用jmap -heap pid查看进程堆内存使用情况,包括使用的GC算法、堆配置参数和各代中堆内存使用情况。
使用jmap -histo[:live] pid 查看堆内存中的对象数目、大小统计直方图,如果带上live则只统计活对象
还有一个很常用的情况是:用jmap把进程内存使用情况dump到文件中,再用jhat分析查看。jmap进行dump命令格式如下:
1
|
jmap -dump:
format
=b,
file
=dumpFileName
|
1
2
3
|
root@ubuntu:/
# jmap -dump:format=b,file=/tmp/dump.dat 21711
Dumping heap to
/tmp/dump
.dat ...
Heap dump
file
created
|
dump出来的文件可以用MAT、VisualVM等工具查看,这里用jhat查看
1
2
3
4
5
6
7
8
9
10
|
root@ubuntu:/
# jhat -port 9998 /tmp/dump.dat
Reading from
/tmp/dump
.dat...
Dump
file
created Tue Jan 28 17:46:14 CST 2014
Snapshot
read
, resolving...
Resolving 132207 objects...
Chasing references, expect 26 dots..........................
Eliminating duplicate references..........................
Snapshot resolved.
Started HTTP server on port 9998
Server is ready.
|
5 jstack命令(Java Stack Trace)
jstack主要用来查看某个Java进程内的线程堆栈信息。语法格式如下:
1
2
3
|
jstack [option] pid
jstack [option] executable core
jstack [option] [server-
id
@]remote-
hostname
-or-ip
|
命令行参数选项说明如下:
1
2
|
-l long listings,会打印出额外的锁信息,在发生死锁时可以用jstack -l pid来观察锁持有情况
-m mixed mode,不仅会输出Java堆栈信息,还会输出C
/C
++堆栈信息(比如Native方法)
|
jstack可以定位到线程堆栈,根据堆栈信息我们可以定位到具体代码,所以它在JVM性能调优中使用得非常多。下面我们来一个实例找出某个Java进程中最耗费CPU的Java线程并定位堆栈信息,
用到的命令有ps、top、printf、jstack、grep。
第一步先找出Java进程ID,我部署在服务器上的Java应用名称为mrf-center:
1
2
|
root@ubuntu:/
# ps -ef | grep mrf-center | grep -v grep
root 21711 1 1 14:47 pts
/3
00:02:10 java -jar mrf-center.jar
|
得到进程ID为21711
第二步找出该进程内最耗费CPU的线程 top -Hp pid
输出如下:
TIME列就是各个Java线程耗费的CPU时间,CPU时间最长的是线程ID为21742的线程
1
|
printf
"%x\n"
21742
|
得到21742的十六进制值为54ee,下面会用到。
OK,下一步终于轮到jstack上场了,它用来输出进程21711的堆栈信息,然后根据线程ID的十六进制值grep,如下:
1
2
|
root@ubuntu:/
# jstack 21711 | grep 54ee
"PollIntervalRetrySchedulerThread"
prio=10 tid=0x00007f950043e000 nid=0x54ee
in
Object.wait() [0x00007f94c6eda000]
|
可以看到CPU消耗在PollIntervalRetrySchedulerThread这个类的Object.wait(),我找了下我的代码,定位到下面的代码:
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
|
// Idle wait
getLog().info(
"Thread ["
+ getName() +
"] is idle waiting..."
);
schedulerThreadState = PollTaskSchedulerThreadState.IdleWaiting;
long
now = System.currentTimeMillis();
long
waitTime = now + getIdleWaitTime();
long
timeUntilContinue = waitTime - now;
synchronized
(sigLock) {
try
{
if
(!halted.get()) {
sigLock.wait(timeUntilContinue);
}
}
catch
(InterruptedException ignore) {
}
}
|
它是轮询任务的空闲等待代码,上面的sigLock.wait(timeUntilContinue)就对应了前面的Object.wait()。