java 内存/cpu占用过高 问题排查
- jps 命令可参看进村id， ps 命令可查看线程id（SPID）， top命令spid和pid都叫pid
确定占用过高的SPID
根据SPID查找对应的PID
拿PID查询对应的堆栈信息
去堆栈信息中分析对应PID16进制的信息
模拟代码
package cn.jiayeli.Test;
import java.util.ArrayList;
import java.util.Arrays;
public class Te {
public static void main(String[] args) {
Arrays.asList("myThread1", "myThread2", "myThread3", "myThread4", "myThread5").stream().forEach(e -> {
new Thread(() -> {
int a = 1;
//ArrayList<Integer> list = new ArrayList<Integer>();
while (true) {
a++;
// list.add(a);
}
}, e).start();
});
}
}
1. jps 参看所有的java进程
XX]$ jps
8019 RemoteMavenServer36
7557 Main
27351 Launcher
27528 Jps
27354 Te
...
其中 27354 Te 就是我们的测试程序，参看该进程下的所有线程，如果在top里有其下面的线程则就算这个程序的问题
2. 查看该进程下的所有线程
XX]$ ps -T -p 27354
PID SPID TTY TIME CMD
27354 27354 ? 00:00:00 java
27354 27355 ? 00:00:00 java
27354 27359 ? 00:00:12 GC Thread#0
27354 27360 ? 00:00:00 G1 Main Marker
27354 27361 ? 00:00:02 G1 Conc#0
27354 27364 ? 00:00:03 G1 Refine#0
27354 27365 ? 00:00:00 G1 Young RemSet
27354 27367 ? 00:00:00 VM Thread
27354 27370 ? 00:00:00 Reference Handl
27354 27371 ? 00:00:00 Finalizer
27354 27374 ? 00:00:00 Signal Dispatch
27354 27376 ? 00:00:00 Service Thread
27354 27378 ? 00:00:00 C2 CompilerThre
27354 27380 ? 00:00:00 C1 CompilerThre
27354 27381 ? 00:00:00 Sweeper thread
27354 27386 ? 00:00:00 Common-Cleaner
27354 27392 ? 00:00:00 Monitor Ctrl-Br
27354 27393 ? 00:00:00 VM Periodic Tas
27354 27394 ? 00:00:04 myThread1
27354 27395 ? 00:00:05 myThread2
27354 27396 ? 00:00:04 myThread3
27354 27397 ? 00:00:04 myThread4
27354 27398 ? 00:00:05 myThread5
27354 27402 ? 00:00:12 GC Thread#1
27354 27403 ? 00:00:11 GC Thread#2
27354 27404 ? 00:00:11 GC Thread#3
27354 27405 ? 00:00:11 GC Thread#4
...
其中 PID：27354 SPID：27354，说明这个线程是主进程的执行线程，具体看下面的SPID
3. top 查看占用高的pid
XX]$ top
PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
27395 kuro 20 0 24.8g 13.5g 28316 R 63.6 21.5 0:03.90 myThread2
27397 kuro 20 0 24.8g 13.5g 28316 R 63.6 21.5 0:03.81 myThread4
27398 kuro 20 0 24.8g 13.5g 28316 R 60.6 21.5 0:03.80 myThread5
27364 kuro 20 0 24.8g 13.5g 28316 S 48.5 21.5 0:03.02 G1 Refine#0
27396 kuro 20 0 24.8g 13.5g 28316 S 48.5 21.5 0:03.75 myThread3
27481 kuro 20 0 24.8g 13.5g 28316 S 48.5 21.5 0:02.50 G1 Conc#1
27361 kuro 20 0 24.8g 13.5g 28316 S 45.5 21.5 0:02.50 G1 Conc#0
27394 kuro 20 0 24.8g 13.5g 28316 S 45.5 21.5 0:03.69 myThread1
27482 kuro 20 0 24.8g 13.5g 28316 S 45.5 21.5 0:02.50 G1 Conc#2
27484 kuro 20 0 24.8g 13.5g 28316 S 45.5 21.5 0:02.50 G1 Conc#4
27485 kuro 20 0 24.8g 13.5g 28316 S 45.5 21.5 0:02.50 G1 Conc#5
27487 kuro 20 0 24.8g 13.5g 28316 S 45.5 21.5 0:02.50 G1 Conc#7
27488 kuro 20 0 24.8g 13.5g 28316 S 45.5 21.5 0:02.50 G1 Conc#8
27425 kuro 20 0 24.8g 13.5g 28316 S 42.4 21.5 0:02.44 G1 Refine#
其中前三个PID线程占用较高
4. 根据上面 2 中的spid确定具体的java进程
其中 PID:27394-27398属于2中的PID：27354的SPID，即占用过高的线程是属于27394这个进程的
5. 转存堆栈
XX] jstack -l 27394 > a.dumpfile
6. 将占用过高的SPID转成16进制，去堆栈中查看具体的信息
XX]$ printf "%x\n" 27395
6b03
堆栈信息中nid=0x6b0的就是top中第一个占用的进程堆栈信息，其余类似，可以看到下面第一个日志块就算我们创建的第一个线程， 具体代码位置为 at cn.jiayeli.Test.Te.lambda$main$0(Te.java:15)
...
"myThread1" #24 prio=5 os_prio=0 cpu=5498.77ms elapsed=53.73s tid=0x00007f9e64906000 nid=0x6b03 runnable [0x00007f9e191e0000]
java.lang.Thread.State: RUNNABLE
at java.util.Arrays.copyOf(java.base@11.0.14.1/Arrays.java:3720)
at java.util.Arrays.copyOf(java.base@11.0.14.1/Arrays.java:3689)
at java.util.ArrayList.grow(java.base@11.0.14.1/ArrayList.java:238)
at java.util.ArrayList.grow(java.base@11.0.14.1/ArrayList.java:243)
at java.util.ArrayList.add(java.base@11.0.14.1/ArrayList.java:486)
at java.util.ArrayList.add(java.base@11.0.14.1/ArrayList.java:499)
at cn.jiayeli.Test.Te.lambda$main$0(Te.java:15)
--------------------------------------------------------------------
at cn.jiayeli.Test.Te$$Lambda$15/0x0000000840064c40.run(Unknown Source)
at java.lang.Thread.run(java.base@11.0.14.1/Thread.java:829)
Locked ownable synchronizers:
- None
"myThread3" #26 prio=5 os_prio=0 cpu=5127.18ms elapsed=53.73s tid=0x00007f9e64909800 nid=0x6b04 runnable [0x00007f9e18fdf000]
java.lang.Thread.State: RUNNABLE
at cn.jiayeli.Test.Te.lambda$main$0(Te.java:15)
at cn.jiayeli.Test.Te$$Lambda$15/0x0000000840064c40.run(Unknown Source)
at java.lang.Thread.run(java.base@11.0.14.1/Thread.java:829)
Locked ownable synchronizers:
- None
"myThread4" #27 prio=5 os_prio=0 cpu=5487.32ms elapsed=53.73s tid=0x00007f9e6490b000 nid=0x6b05 runnable [0x00007f9e18edf000]
java.lang.Thread.State: RUNNABLE
at cn.jiayeli.Test.Te.lambda$main$0(Te.java:15)
at cn.jiayeli.Test.Te$$Lambda$15/0x0000000840064c40.run(Unknown Source)
at java.lang.Thread.run(java.base@11.0.14.1/Thread.java:829)
Locked ownable synchronizers:
- None
"myThread5" #28 prio=5 os_prio=0 cpu=5795.98ms elapsed=53.73s tid=0x00007f9e6490d000 nid=0x6b06 runnable [0x00007f9e18ddf000]
java.lang.Thread.State: RUNNABLE
at cn.jiayeli.Test.Te.lambda$main$0(Te.java:15)
at cn.jiayeli.Test.Te$$Lambda$15/0x0000000840064c40.run(Unknown Source)
at java.lang.Thread.run(java.base@11.0.14.1/Thread.java:829)
Locked ownable synchronizers:
...
