JVM探秘：线上CPU占用过高故障排查

Posted 2021-03-12 cellei

线上系统突然变得卡顿或无法访问，排除网络异常的情况下，检查服务器资源占用情况，如果CPU、内存、磁盘IO等资源占用过高，就会导致无法继续处理HTTP请求。

如果是CPU占用飙高，有可能是程序中存在死循环、死锁导致的，也有可能是内存紧张从而频繁GC导致的，要具体问题具体分析。

排查过程

这里记录一次线上CPU占用过高的故障排查过程，重点会用到jstack命令。

top命令

首先，使用top命令查看服务器资源使用情况，找到CPU占用过高的进程。

发现pid为29167的Java进程CPU占用很高，已经100%了。

ps -mp pid -o THREAD,tid,time

再通过ps命令查看这个进程的线程信息，tid为线程ID，time代表这个线程的已运行时间，通过上面的top命令，已经知道进程pid为29167，所以：

ps -mp 29167 -o THREAD,tid,time

可以看到，线程tid为29168的线程占用CPU很高，已经占用4分钟。

进制转换

把29168转换成十六进制，因为jstack输出的线程id是十六进制形式，可以使用printf "%x " tid输出线程id的十六进制。

printf "%x
" 29168

记录下29168的十六进制是71f0。

jstack查看线程状态

使用JDK自带的jstack命令，指定pid后，可以查看Java进程中各个线程的运行状态，以及每个线程的跟踪堆栈。

可以把jstack结果输出到文件，然后在文件中查找，但一般为了快速定位问题，可以直接使用grep命令根据线程id查找。

使用管道操作及grep命令，输出30行结果：

jstack 29167 | grep 71f0 -A 30

根据输出结果，线程是RUNNABLE状态，可以在跟踪堆栈中定位到异常代码。

代码分析

根据jstack的线程跟踪堆栈，定位到异常代码，下面是代码内容。

WorkDayUtil：

package com.cellei.demo;

import java.util.Calendar;

public class WorkDayUtil {

    /*查询指定月份的工作日天数，格式：yyyy-MM，例如 2018-02 */
    public static int getWorkDay(String input){
        int count = 0;
        int month = Integer.parseInt(input.substring(5, 7));
        Calendar cal = Calendar.getInstance();
        cal.set(Calendar.YEAR, Integer.parseInt(input.substring(0, 4)));
        cal.set(Calendar.MONTH,  month - 1);
        cal.set(Calendar.DATE, 1);

        while(cal.get(Calendar.MONTH) < month){
            int day = cal.get(Calendar.DAY_OF_WEEK);
            if(!(day == Calendar.SUNDAY || day == Calendar.SATURDAY)){
                count++;
            }
            cal.add(Calendar.DATE, 1);
        }
        return count;
    }
}

Application：

import com.cellei.demo.WorkDayUtil;

public class Application {

    public static void main(String[] args) {
        int count = WorkDayUtil.getWorkDay("2018-12");
    }

}

问题出现在WorkDayUtil中的while循环条件，当传入的input参数不是12月份时，循环可以正常跳出，但当input是12月份时，比如这里的“2018-12”，这里就变成了死循环，while循环条件改成这样就正常了：

while(cal.get(Calendar.MONTH) + 1 == month){

其他情况

除了死循环会导致CPU占用过高，多线程编程时，死锁也会导致同样的问题。

还有一种情况，根据jstack跟踪线程堆栈，如果跟踪到的是GC线程，有可能是GC太过频繁导致的CPU飙高，这时需要分析内存占用情况，结合jstat和jmap命令，分析堆转储快照heapdump文件，得出最终结论。

线上故障多种多样，理解排查思路，剩下的就是经验的积累。