java 分析jstack日志_望闻问切使用jstack和jmap剖析java进程各种疑难杂症

最近碰到多起java程序导致服务器cpu使用率100%的情况，下面把排查解决方法记录下来。

其实遇到这种情况，首先要保持冷静的头脑，遇事不乱。然后望闻问切，找到病根，直达病灶。所谓望闻问切就是，首先使用top找到最耗费cpu资源的进程找到，然后使用jstack, jmap等方式保存现场，然后使用top -Hp找到最好费cpu资源的线程ID，在按图索骥。同时我们也不要遗漏跟改进程有关的网络连接情况，和磁盘IO方片深入排查问题。

保存犯罪现场

第一步找到犯罪分子(Java进程ID)，和最耗费cpu资源的线程ID

1) 使用top 找到最耗费资源的java进程号 9370

2)找到该进程的 线程总个数

ps -Lfp 9370 | wc -l

#(也可以使用ps -mp 9370 查看进程运行时间 或者 ps -Tp 进程情况)

有这么多线程难怪会这么耗费cpu。

3) 找到最耗费资源的线程

#可以找到最好费资源的线程号 9374

top -Hp 9370

4) 将最耗费资源线程id转换为十六进制

可以使用下面shell命令转化线程id为十六进制的。

#把线程转为十六进制

printf '%x\n'

9374 结果是 249e

使用jstack保存栈信息

保存栈信息，同时在栈信息中查找 0x249e

jstack -l 9370 > stack.info

grep **0x249e** stack.info -A 10

列出栈信息，同时确认

到此问题已经终结，找到了问题。

jmap备份堆信息

上个案例因为是GC配置问题导致了高cpu占用率， 但是有的时候排查问题需要栈和堆结合起来一起排查。下面我举一个例子

public class DeadLock{

public static void main(String[] args){

ResourceA resourceA = new ResourceA();

ResourceB resourceB = new ResourceB();

MyThreadA threadA = new MyThreadA(resourceA, resourceB );

MyThreadB threadB = new MyThreadB(resourceA, resourceB );

threadA.start();

threadB.start();

}

}

class MyThreadA extends Thread{

private ResourceA rA;

private ResourceB rB ;

private String threadName;

public MyThreadA(ResourceA resourceA, ResourceB resourceB){

this.rA = resourceA;

this.rB = resourceB;

}

@Override

public void run(){

threadName = Thread.currentThread().getName();

consumeResource();

}

public void consumeResource(){

synchronized (this.rA){

if(!this.rA.getResourceA().equals(threadName)){

this.rA.consumerA(threadName);

System.out.println(this.threadName + " 消费 A");

try {

Thread.sleep(2000);

} catch (InterruptedException e) {

e.printStackTrace();

}

synchronized (this.rB){

if(!this.rB.getResourceB().equals(threadName)){

this.rB.consumerB(threadName);

System.out.println(this.threadName + " 消费 B");

}

}

}

}

}

}

class MyThreadB extends Thread{

private ResourceA rA;

private ResourceB rB ;

private String threadName;

public MyThreadB(ResourceA resourceA, ResourceB resourceB){

this.rA = resourceA;

this.rB = resourceB;

}

@Override

public void run(){

threadName = Thread.currentThread().getName();

consumeResource();

}

public void consumeResource(){

synchronized (this.rB){

if(!this.rB.getResourceB().equals(threadName)){

this.rB.consumerB(threadName);

System.out.println(this.threadName + " 消费 B");

}

try {

Thread.sleep(2000);

} catch (InterruptedException e) {

e.printStackTrace();

}

synchronized (this.rA){

if(!this.rA.getResourceA().equals(threadName)){

this.rA.consumerA(threadName);

System.out.println(this.threadName + " 消费 A");

}

}

}

}

}

class ResourceA{

private String resourceA = "";

public String getResourceA(){

return resourceA;

}

public void consumerA(String name){

this.resourceA = name;

}

}

class ResourceB{

private String resourceB = "";

public String getResourceB(){

return resourceB;

}

public void consumerB(String name){

this.resourceB = name;

}

}

上面很明显是一个死锁的例子。我们就结合线程的栈去和堆区来进行深入排查。

jstack -l 2300 > stack.info

jmap -dump:format=b,file=jmap.info 2300

首先打开stack文件，发现Thread-1 在等待资源 0x76ab71990；同时锁住了资源0x76ab72ab0。但是Thread-0刚好相反。那么我们可以去堆文件中看下这两个资源到地址什么。而0x76ab72ab0和0x76ab71990分别代表了内存地址。

我们使用jhat解析heap文件，视图还原0x76ab72ab0和0x76ab71990两个资源

jhat -J-d64 -J-mx3g -port 34567 ~/Desktop/jmap.info

然后打开浏览器，输入localhost:34567,查找0x76ab72ab0和0x76ab71990我们甚至可以点击进入两个对象里面查看运行时的变量值。

而且jvm很智能的检测出有死锁现象发生，并且在堆文件中提示出来了

Found one Java-level deadlock:

=============================

"Thread-1":

waiting to lock monitor 0x00007fe2f000df58 (object 0x000000076ab71990, a ResourceA),

which is held by "Thread-0"

"Thread-0":

waiting to lock monitor 0x00007fe2f000b618 (object 0x000000076ab72ab0, a ResourceB),

which is held by "Thread-1"

Java stack information for the threads listed above:

===================================================

"Thread-1":

at MyThreadB.consumeResource(DeadLock.java:85)

- waiting to lock <0x000000076ab71990> (a ResourceA)

- locked <0x000000076ab72ab0> (a ResourceB)

at MyThreadB.run(DeadLock.java:67)

"Thread-0":

at MyThreadA.consumeResource(DeadLock.java:44)

- waiting to lock <0x000000076ab72ab0> (a ResourceB)

- locked <0x000000076ab71990> (a ResourceA)

at MyThreadA.run(DeadLock.java:27)

Found 1 deadlock.

到此排查工作到一段落了。下面还有专门篇章详细讲解stack和heap文件里面的奥妙。