Java问题排查：CPU过载问题

场景描述

在使用Jenkins时发现服务是真的卡顿，如上图所示（真实的数据没了，就放个当前的截图），假如使用"top"命令发现Java进程CPU占用过高，基本上接近 CPU核数 * 100%时，则可以执行以下操作。

方式一

步骤一：获取Java的进程PID

[root@localhost ~]# ps -aux | grep java | grep -v grep
jenkins    958  1.0 23.3 3688052 907380 ?      Ssl  09:39   6:07 /etc/alternatives/java -Dcom.sun.akuma.Daemon=daemonized -Djava.awt.headless=true -DJENKINS_HOME=/var/lib/jenkins -jar /usr/lib/jenkins/jenkins.war --logfile=/var/log/jenkins/jenkins.log --webroot=/var/cache/jenkins/war --daemon --httpPort=8080 --debug=5 --handlerCountMax=100 --handlerCountMaxIdle=20
root     27081  0.0  0.0 113184  1388 ?        S    09:18   0:00 /bin/sh /usr/local/apache-jmeter-5.2.1/bin/jmeter-server -Djava.rmi.server.hostname=******
root     27083  0.0  0.0 113184  1448 ?        S    09:18   0:00 /bin/sh /usr/local/apache-jmeter-5.2.1/bin/jmeter -Dserver_port=1099 -s -j jmeter-server.log -Djava.rmi.server.hostname=10.25.78.134
root     27111  0.0  3.1 3607700 120788 ?      Sl   09:18   0:32 /usr/bin/java -server -XX:+HeapDumpOnOutOfMemoryError -Xms1g -Xmx1g -XX:MaxMetaspaceSize=256m -XX:+UseG1GC -XX:MaxGCPauseMillis=100 -XX:G1ReservePercent=20 -Djava.security.egd=file:/dev/urandom -Duser.language=en -Duser.region=EN -jar /usr/local/apache-jmeter-5.2.1/bin/ApacheJMeter.jar -Dserver_port=1099 -s -j jmeter-server.log -Djava.rmi.server.hostname=******

步骤二：导出CPU占用高进程的线程栈

jstack pid >> java_stack.txt

步骤三：查看对应进程的哪个线程占用CPU过高

top -H -p PID

步骤四：将线程的PID转换为16进制,大写转换为小写

echo "obase=16; PID" | bc

步骤五：在第二步导出的Java.txt中查找转换成为16进制的线程PID。找到对应的线程栈。

步骤六：分析负载高的线程栈都是什么业务操作。优化程序并处理问题。

方式二

步骤一：使用top 定位到占用CPU高的进程PID

top

步骤二：获取线程信息，并找到占用CPU高的线程

ps -mp pid -o THREAD,tid,time | sort -rn 

步骤三：将需要的线程ID转换为16进制格式

printf "%x\n" tid

步骤四：打印线程的堆栈信息

jstack pid |grep tid -A 30

注意事项：

以我们最近出现的一个实际故障为例，介绍怎么定位和解决这类问题。

根据top命令，发现PID为28555的Java进程占用CPU高达200%，出现故障。

通过ps aux | grep PID命令，可以进一步确定是tomcat进程出现了问题。但是，怎么定位到具体线程或者代码呢？

步骤一：首先显示线程列表:

命令：ps -mp pid -o THREAD,tid,time

找到了耗时最高的线程28802，占用CPU时间快两个小时了！

步骤二：将需要的线程ID转换为16进制格式

命令：printf "%x\n" tid

步骤三：打印线程的堆栈信息

命令：jstack pid |grep tid -A 30

步骤四：分析具体问题

现在来分析下具体的代码：ShortSocketIO.readBytes(ShortSocketIO.java:106)

ShortSocketIO是应用封装的一个用短连接Socket通信的工具类。readBytes函数的代码如下：

public byte[] readBytes(int length) throws IOException {

    if ((this.socket == null) || (!this.socket.isConnected())) {

        throw new IOException("++++ attempting to read from closed socket");

    }

    byte[] result = null;

    ByteArrayOutputStream bos = new ByteArrayOutputStream();

    if (this.recIndex >= length) {

           bos.write(this.recBuf, 0, length);

           byte[] newBuf = new byte[this.recBufSize];

           if (this.recIndex > length) {

               System.arraycopy(this.recBuf, length, newBuf, 0, this.recIndex - length);

           }

           this.recBuf = newBuf;

           this.recIndex -= length;

    } else {

           int totalread = length;

           if (this.recIndex > 0) {

                totalread -= this.recIndex;

                bos.write(this.recBuf, 0, this.recIndex);

                this.recBuf = new byte[this.recBufSize];

                this.recIndex = 0;

    }

    int readCount = 0;

    while (totalread > 0) {

         if ((readCount = this.in.read(this.recBuf)) > 0) {

                if (totalread > readCount) {

                      bos.write(this.recBuf, 0, readCount);

                      this.recBuf = new byte[this.recBufSize];

                      this.recIndex = 0;

               } else {

                     bos.write(this.recBuf, 0, totalread);

                     byte[] newBuf = new byte[this.recBufSize];

                     System.arraycopy(this.recBuf, totalread, newBuf, 0, readCount - totalread);

                     this.recBuf = newBuf;

                     this.recIndex = (readCount - totalread);

             }

             totalread -= readCount;

        }

   }

}

问题就出在标红的代码部分。如果this.in.read()返回的数据小于等于0时，循环就一直进行下去了。而这种情况在网络拥塞的时候是可能发生的，至于具体怎么修改就看业务逻辑应该怎么对待这种特殊情况了。

问题解决

问题一：Unable to open socket file: target process not responding or HotSpot VM not loaded

此时可能是说明 28604 进程不是此用户启动的。

1. 通过ps命令可以查看到这个进程 然后切换到此用户下面。
2. 切换到/tmp目录，查找是否有此用户的以 hsperfdata_用户名 的目录
3. 进目录看有没有jstack执行的进程号, 如果有，则直接使用 jstack pid 执行即可。如果没有，不要浪费时间了。执行不了的。可能会报 not permited 或上述错误。
4. 通过 jstat -gcutil pid 时间间隔(ms) 查看 jc 信息

jstat -gcutil 13179 1000
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT     GCT   
 99.95   0.00  49.14  14.96  91.97  84.24     10    0.444     3    0.317    0.761
 99.95   0.00  49.14  14.96  91.97  84.24     10    0.444     3    0.317    0.761
 99.95   0.00  49.14  14.96  91.97  84.24     10    0.444     3    0.317    0.761
 99.95   0.00  49.14  14.96  91.97  84.24     10    0.444     3    0.317    0.761
 99.95   0.00  49.14  14.96  91.97  84.24     10    0.444     3    0.317    0.761
 99.95   0.00  49.14  14.96  91.97  84.24     10    0.444     3    0.317    0.761
 99.95   0.00  49.14  14.96  91.97  84.24     10    0.444     3    0.317    0.761
 99.95   0.00  49.14  14.96  91.97  84.24     10    0.444     3    0.317    0.761
 .........

字段名	含义
S0	年轻代第一个幸存区（survivor）使用容量占用百分比
S1	年轻代第二个幸存区（survivor）使用容量占用百分比
E	年轻代伊甸园区（eden）使用容量占用百分比
O	老年代使用容量占用百分比
P	perm代使用容量占用百分比（JDK7-）
M	MetaSpace元空间使用容量占用百分比（JDK8+）
CCS	压缩使用比例
YGC	从应用程序启动到当前采样时年轻代gc的次数
YGCT	从应用程序启动到当前采样时年轻代gc的时间
FGC	从应用程序启动到当前采样时老年代gc的次数
FGCT	从应用程序启动到当前采样时老年代gc的时间
GCT	从应用程序启动到当前采样时gc总耗时

技巧总结

1、top命令：Linux命令。可以查看实时的CPU使用情况。也可以查看最近一段时间的CPU使用情况。

2、PS命令：linux命令。强大的进程状态监控命令。可以查看进程以及进程中线程的当前CPU使用情况。属于当前状态的采样数据。

3、jstack：Java提供的命令。可以查看某个进程的当前线程栈运行情况。根据这个命令的输出可以定位某个进程的所有线程的当前运行状态、运行代码，以及是否死锁等等。

4、pstack：Linux命令。可以查看某个进程的当前线程栈运行情况。