前言
学过操作系统的都知道,cpu是时分(time division)的,cpu不是被线程独占一直使用的,除非是那种非抢占式的。操作系统里有很多线程,每个线程的运行时间由cpu决定,cpu会分给每个线程一个时间片,时间片是一个极短的时间长度,如果在时间片内,线程一直占有,则认为是cpu100%。cpu运行速度很快,即主频非常高,除非密集型耗费cpu的运算,其它类型任务都会在小于时间片的时间内结束。
Java进程cpu100%的排查步骤,大体上都是差不多的,可能会根据不同场景有些命令稍有区别。
- 首先找出消耗cpu最高的进程PID
- 然后再根据进程PID找出进程内消耗cpu最高的线程号TID
- 最后根据线程号TID找出对应的Java线程,进行排查处理
正常情况下,我们一般将服务部署到Linux服务器上的,所以重点讲解也是在Linux服务器上的排查过程。不过考虑到,大多程序员是在Windows环境开发,或者有少数服务是部署到Windows服务器的,所以Windows和Linux两种环境都会讲解排查的过程。
样例准备
创建一个Springboot工程,简单写一个接口,死循环的创建Person对象,最终会产生内存溢出,java.lang.OutOfMemoryError: Java heap space
。
启动工程,并进行接口调用:http://localhost:8080/person/test?justDo=true
package com.nobody;
import org.springframework.web.bind.annotation.GetMapping;
import org.springframework.web.bind.annotation.RequestMapping;
import org.springframework.web.bind.annotation.RequestParam;
import org.springframework.web.bind.annotation.RestController;
import java.util.ArrayList;
import java.util.List;
/**
* @Description
* @Author Mr.nobody
* @Date 2021/3/19
* @Version 1.0.0
*/
@RestController
@RequestMapping("person")
public class PersonController {
private List<Person> persons = new ArrayList<>();
@GetMapping("test")
public Boolean test(@RequestParam boolean justDo) {
int i = 1;
if (justDo) {
while (true) {
persons.add(new Person("张三", i++));
System.out.println(persons.size());
}
}
return justDo;
}
}
Windows环境排查
首先找出消耗cpu最高的进程PID。有两种方式可以查出,一种是通过Windows任务管理器,配合CPU列和PID列找出,CPU列数字越大,代表消耗CPU越高,然后找出镜像名称是java.exe的,最后得出PID。
另外一种方式是使用微软的工具Process Explorer,此软件不仅可以查看进程的情况,还能查看线程的CPU占有率,而任务管理器只能看到进程的CPU占有率。下载来解压就直接可以使用了。
下载地址:https://docs.microsoft.com/zh-cn/sysinternals/downloads/process-explorer
打开软件后,首先找出cpu占用率最高的Java进程,如下,进程号PID是16356。
然后右击此行数据,选择Properties打开,如下:
切换到Threads列页面。既可以看到此进程内的线程信息,并且发现CPU占用率最高的线程的TID是18240,6480,11260,13888,16312等等。
打开cmd命令行工具,通过命令jstack 16356 > d:/16356.stack
,将进程的堆栈信息导出到本地D盘的16356.stack文件中。注意,导出的文件位置随意,文件名一般以进程号+stack后缀组成,当然也可以其他后缀。
上面我们排查到CPU占用率最高的线程的TID是18240,6480,11260,13888,16312,这些数字是十进制的,而导出的堆栈信息里面的线程ID是十六进制的,所以我们需先转换为16进制,即0x4740,0x1950,0x3640,0x3fb8。
然后我们打开堆栈文件16356.stack,在里面查找这些数字,首先是0x4740,发现定位到我们程序的代码30行,经检测程序,原来是死循环不断的产生Person对象,故找到原因所在。
而且通过其他3个线程ID 0x1950,0x3640,0x3fb8,在堆栈文件中,发现是GC线程的ID,从而也证明GC线程一直忙碌,表示内存不够用了,要进行内存回收,可能是Java内存回收不了,所以导致一直gc,使CPU占用率极高。
至此,问题找到原因,原来是在死循环中,不断生产Person实例,并且无法回收,不仅工作线程一直占用cpu,而且导致gc线程忙碌进行回收内存,但是回收不了,最后导致内存不足java.lang.OutOfMemoryError
。
Linux环境排查
首先使用top
命令找出cpu占用最高的进程。
再使用ps -ef | grep java
或者jps
命令查看cpu占用高的进程是否为java进程。
使用top -H -p pid
命令查询此进程的所有线程情况,发现主要有三个线程(PID为29871 29872 29873)cpu占用率高。-H表示以线程的维度显示,默认以进程维度展示。
使用命令jstack pid > pid.tdump
将此进程的线程栈导出到文件,并使用cat
命令进行查看。pid.tdump文件后缀名随意,通常以tdump结尾。
jstack 29869 > 29869.tdump
cat 29869.tdump
将前面查出的3个线程PID从10进制转为16进制,对应分别为 29871 -> 0x74af,,29872 -> 0x74b0,29873 -> 0x74b1。
发现此3个线程中有2个为gc线程和1个工作线程。gc线程忙碌表示内存不够用了,要进行内存回收,可能是java内存回收不了,导致一直gc。
使用jstat -gcutil pid
命令查看进程的堆情况,发现年轻代中Eden和老年代已使用的内存占当前容量百分比很高,并且GC频繁。
- S0:年轻代中第一个survivor(幸存区)已使用的占当前容量百分比
- S1:年轻代中第二个survivor(幸存区)已使用的占当前容量百分比
- E:年轻代中Eden(伊甸园)已使用的占当前容量百分比
- O:old代已使用的占当前容量百分比
- M:元数据区使用比例
- CCS:压缩使用比例
- YGC:从应用程序启动到采样时年轻代中gc次数
- YGCT:从应用程序启动到采样时年轻代中gc所用时间(s)
- FGC:从应用程序启动到采样时old代(全gc)gc次数
- FGCT:从应用程序启动到采样时old代(全gc)gc所用时间(s)
- GCT:从应用程序启动到采样时gc用的总时间(s)
使用jmap -dump:live,format=b,file=pid.hprof pid
命令导出堆文件,只导出live存活的对象。文件后缀名可以是任意的,因为它也是二进制的,不过通常以hprof结尾。
最后使用JDK自带的工具,JAVA_HOME/bin/jvisualvm.exe
工具分析快照。
载入快照(文件----->载入—>文件类型(堆))
选择类列表,按照大小排序,找出占用内存最大的类别,发现是Person类。
至此,问题找到原因,原来是在死循环中,不断生产Person实例,并且无法回收,不仅工作线程一直占用cpu,而且导致gc线程忙碌进行回收内存,但是回收不了,最后导致内存不足java.lang.OutOfMemoryError
。
最后简单总结下,上诉的排查过程不一定适用全部场景,不同大体上的思路大同小异。根据自己情况,使用不同的命令和工具进行分析,而且,Java的bin目录下有很多JVM性能调优监控工具,如 jps、jstack、jmap、jhat、jstat、hprof。