如何排查JAVA进程CPU和内存高占用

CPU

JAVA进程占用CPU很高，除了程序确实是属于CPU密集型之外，很多时候都是出现了死循环，或者代码死锁造成的

运行测试代码:

public class TestCPUUseHigh {
public static void main(String[] args) throws Exception {
while (true) {
//这里睡眠一下是为了防止机器受不了
Thread.sleep(10);
System.out.println(1);
}
}
}


//找到进程ID
>jps
22371 TestCPUUseHigh

//显示该进程下的所有线程，找CPU占用高的或者时间占用久的线程ID
>ps -mp 22371 -o THREAD,tid,time | sort -rn
USER %CPU PRI SCNT WCHAN USER SYSTEM TID TIME
test 0.8 - - - - - - 00:00:00
test 0.7 19 - futex_ - - 22372 00:00:00
test 0.0 19 - futex_ - - 22384 00:00:00
test 0.0 19 - futex_ - - 22383 00:00:00
test 0.0 19 - futex_ - - 22382 00:00:00
test 0.0 19 - futex_ - - 22381 00:00:00
test 0.0 19 - futex_ - - 22380 00:00:00
test 0.0 19 - futex_ - - 22379 00:00:00
test 0.0 19 - futex_ - - 22378 00:00:00
test 0.0 19 - futex_ - - 22377 00:00:00
test 0.0 19 - futex_ - - 22376 00:00:00
test 0.0 19 - futex_ - - 22375 00:00:00
test 0.0 19 - futex_ - - 22374 00:00:00
test 0.0 19 - futex_ - - 22373 00:00:00
test 0.0 19 - futex_ - - 22371 00:00:00

//我们看到22372这个ID线程占用cpu比较高,把这个ID转换成16进制
>printf "%x\n" 22372
5764

//jstack打印堆栈，并且过滤这个ID，发现问题
>jstack 22371 |grep 5764 -A 30
"main" prio=10 tid=0x00007f9524008800 nid=0x5764 waiting on condition [0x00007f95293e8000]
java.lang.Thread.State: TIMED_WAITING (sleeping)
at java.lang.Thread.sleep(Native Method)
at TestCPUHighUse.main(TestCPUHighUse.java:7)

内存

JAVA占用内存高，一般都是代码中创建了大量大对象，并且长时间不能被GC

测试代码如下：


public class TestMemoryUseHigh {
public static void main(String[] args) throws Exception {
List<TestObj> list = new ArrayList<TestObj>();
for(int i = 1 ; i < 1000 ; i++){
//放到list里，防止被垃圾回收
list.add(new TestObj());
System.out.println(i);
}
Thread.sleep(1000000);
}
private static class TestObj{
byte[] b = new byte[102400];
}
}

//进程ID
[test@dev5 ~]$ jps
27593 TestMemoryUseHigh

//一个jmap命令，内存尽收眼底
//简单说明一下
[C is a char[]
[S is a short[]
[I is a int[]
[B is a byte[]
[[I is a int[][]

[test@dev5 ~]$ jmap -histo:live 27593

num #instances #bytes class name
----------------------------------------------
1: 1525 102400792 [B
2: 5577 719008 <methodKlass>
3: 5577 638800 <constMethodKlass>
4: 372 435416 <constantPoolKlass>
5: 336 268512 <constantPoolCacheKlass>
6: 372 254264 <instanceKlassKlass>
7: 875 78336 [C
8: 432 42464 java.lang.Class
9: 605 40560 [[I
10: 566 34808 [S
11: 43 23392 <objArrayKlassKlass>
12: 856 20544 java.lang.String
13: 314 18112 [Ljava.lang.Object;
14: 999 15984 TestMemoryUseHigh$TestObj
15: 79 5688 java.lang.reflect.Field
16: 14 4824 <methodDataKlass>
17: 8 4352 <typeArrayKlassKlass>
18: 90 3600 java.lang.ref.SoftReference
19: 108 3456 java.util.Hashtable$Entry
20: 11 2288 <klassKlass>
21: 53 1928 [Ljava.lang.String;
22: 59 1888 java.util.concurrent.ConcurrentHashMap$HashEntry
23: 46 1840 java.util.concurrent.ConcurrentHashMap$Segment
24: 38 1824 sun.util.locale.LocaleObjectCache$CacheEntry
25: 46 1472 java.util.concurrent.locks.ReentrantLock$NonfairSync
26: 46 1232 [Ljava.util.concurrent.ConcurrentHashMap$HashEntry;
27: 3 1112 [I
28: 16 1024 java.net.URL
29: 6 992 [Ljava.util.Hashtable$Entry;
30: 12 960 [Ljava.util.HashMap$Entry;
31: 19 760 java.io.ObjectStreamField
32: 19 760 sun.util.locale.BaseLocale$Key
33: 18 720 java.util.LinkedHashMap$Entry
34: 22 704 java.util.HashMap$Entry
35: 43 688 java.lang.Object
36: 14 672 java.util.HashMap

Total 19653 105048560

如果要想知道各种数组里的内容，比如char[]

运行

jmap -dump:format=b,file=a.hprof <pid>

用jvisualvm载入这个文件，在char[]上右键，在实例视图中显示，就可以看到是那些内容了

顺便提一下jstack命令，上面的cpu的例子中也用到了jstack,这个命令可以打印java虚拟机当前时刻的所有线程快照
jstack 22371 命令，获取所有线程快照

线程死锁的状态是 BLOCKED ，grep BLOCKED 就可以查到死锁的线程

因为太长了，我粘贴一段说明一下，例如下面的输出：


logic worker 8_0 prio=10 tid=0x00007f4c3c3c2800 nid=0x7dd4 waiting for monitor entry [0x00007f4c0fcba000]
"java.lang.Thread.State: BLOCKED (on object monitor)"
"- waiting to lock <0x00000005c81872f8> (a java.lang.String)"

Locked ownable synchronizers:
- None

//这说明这个线程死锁了，为什么呢？注意这句话

"waiting to lock <0x00000005c81872f8> (a java.lang.String)"

说明这个线程因为正在等待这个ID的锁而死锁，我们去查查这个ID的锁那个线程拿着，jstack结果中grep这个ID

io worker 8 prio=10 tid=0x00007f4fb0e40800 nid=0x3dc8 runnable [0x00007f4f882c1000]
java.lang.Thread.State: RUNNABLE
at sun.nio.ch.EPollArrayWrapper.epollWait(Native Method)
at sun.nio.ch.EPollArrayWrapper.poll(EPollArrayWrapper.java:269)
at sun.nio.ch.EPollSelectorImpl.doSelect(EPollSelectorImpl.java:79)
at sun.nio.ch.SelectorImpl.lockAndDoSelect(SelectorImpl.java:87)
--
"- locked <0x00000005c81872f8> (a java.lang.String)"

//很明显，这个线程拿着这个ID的锁

"- locked <0x00000005c81872f8> (a java.lang.String)"

为什么这个线程拿着这个锁不释放呢？可以从代码中分析出来，有的原因是线程之间互相锁住，A线程等B线程释放锁，B线程等A线程释放锁