服务CPU突然飙到100%,用Arthas三分钟定位到问题代码

15 阅读3分钟

前言

那天下午正准备摸鱼,突然收到告警:生产环境某服务CPU使用率100%。

打开监控一看,好家伙,4核全部打满,而且已经持续了好几分钟。赶紧上服务器排查。

第一步:确认是哪个进程

先用top看一眼:

top - 14:32:01 up 89 days,  3:21,  2 users,  load average: 4.12, 3.89, 2.15
%Cpu(s): 98.7 us,  1.2 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.1 si
PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
12847 app       20   0 4.2g   1.8g  12m S  398  23.1   89:32.15 java

果然是Java进程,PID 12847,CPU占用398%(4核差不多打满)。

第二步:找到具体是哪个线程

top -Hp 12847看这个进程里的线程:

PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
12892 app       20   0 4.2g   1.8g  12m R 99.3 23.1  22:15.32 java
12893 app       20   0 4.2g   1.8g  12m R 99.1 23.1  22:14.89 java
12894 app       20   0 4.2g   1.8g  12m R 98.7 23.1  22:13.45 java
12895 app       20   0 4.2g   1.8g  12m R 98.2 23.1  22:12.78 java

4个线程都在疯狂跑。记下线程ID:12892、12893、12894、12895。

把线程ID转成16进制(jstack用的是16进制):

printf "%x\n" 12892

# 输出:325c

第三步:jstack抓线程堆栈

jstack 12847 | grep -A 30 "325c"

输出:

"pool-3-thread-1" #89 prio=5 os_prio=0 tid=0x00007f8a3c012000 nid=0x325c runnable [0x00007f8a2c1fe000]
java.lang.Thread.State: RUNNABLE
at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
at java.util.regex.Pattern$Loop.matchInit(Pattern.java:4803)
at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
...(省略N行重复的)
at com.xxx.service.ContentService.filterContent(ContentService.java:156)

破案了!是正则表达式在疯狂回溯。

Arthas更快定位

上面的方法虽然能找到问题,但步骤有点多。后来我学会了用Arthas,真的三分钟就能定位。

安装Arthas

curl -O https://arthas.aliyun.com/arthas-boot.jar
java -jar arthas-boot.jar

选择要attach的Java进程,进入Arthas控制台。

thread命令直接看CPU最高的线程

thread -n 3

输出:

"pool-3-thread-1" Id=89 cpuUsage=98.32% deltaTime=983ms time=1345623ms RUNNABLE
at java.util.regex.Pattern$GroupHead.match(Pattern.java:4658)
at java.util.regex.Pattern$Loop.match(Pattern.java:4785)
at java.util.regex.Pattern$GroupTail.match(Pattern.java:4717)
at com.xxx.service.ContentService.filterContent(ContentService.java:156)
at com.xxx.controller.ContentController.submit(ContentController.java:42)

一条命令就定位到了,比top + jstack方便太多。

profiler火焰图

如果想更直观地看CPU消耗分布:

profiler start

# 等待30秒采样

profiler stop --format html

会生成一个火焰图HTML文件,哪个方法占用CPU多一目了然。

问题根因

找到问题代码后,看了一下:

// ContentService.java:156
public String filterContent(String content) {
    // 这个正则有问题
    String pattern = "(a]表达式导致的CPU 100%问题,通常有以下几个原因:

### 1. 回溯陷阱(Catastrophic Backtracking)

像`(a+)+b`这种嵌套量词,遇到不匹配的字符串时,会产生指数级的回溯。

### 2. 解决方案

**方案一:优化正则表达式**

```java
// 避免嵌套量词
// 坏:(a+)+
// 好:a+

// 使用原子组或占有量词
// 好:(?>a+)+ 或 a++

方案二:设置超时

// Java 9+ 支持
Pattern pattern = Pattern.compile(regex);
Matcher matcher = pattern.matcher(input).timeout(1000, TimeUnit.MILLISECONDS);

方案三:换用其他库

<dependency>
    <groupId>com.google.re2j</groupId>
    <artifactId>re2j</artifactId>
    <version>1.7</version>
</dependency>

RE2J使用的是线性时间的算法,不会出现回溯问题。

其他常见的CPU 100%场景

死循环

while (true) {
    // 忘了加退出条件或sleep
}

用Arthas的thread -n 3一眼就能看到卡在哪一行。

锁竞争

多个线程疯狂抢锁,虽然不是死锁,但CPU也会打满。用thread -b可以看到阻塞情况。

频繁GC

如果是GC线程占用CPU高,需要用jstat -gcutil或者看GC日志排查。

远程排查小技巧

有时候问题发生在远程服务器上,SSH连上去操作比较麻烦。我现在习惯用星空组网工具把服务器和本地打通,直接在本地IDEA里远程连接Arthas,体验好很多。特别是需要下载火焰图或者heap dump的时候,内网直传比scp快多了。

总结

CPU 100%问题排查流程:

  1. top 确认是哪个进程
  2. top -Hp <pid> 找到CPU高的线程
  3. jstack 或 Arthas thread -n 3 看线程堆栈
  4. 根据堆栈定位问题代码

Arthas真的是线上排查神器,强烈推荐还没用过的同学试试。