CPU 飙高 100% 的标准排查流程

告警：Pod CPU 987%

10 月 8 号下午，告警：

[P1] order-service CPU 使用率 987% (limit 800%) 持续 20 分钟

CPU 是 8 核 limit，987% 意味着快跑满了。接口 P99 从 120 ms 涨到 3.4 秒，部分请求超时。

这类问题有一套固定流程，我基本是条件反射地在做。但中间有几个容易踩空的地方，这次正好都遇上了。

第一步：找到是哪个进程

$ top
  PID USER      PR  NI    VIRT    RES    SHR S  %CPU %MEM     TIME+ COMMAND
    1 root      20   0   12.4g   4.2g  18924 S 987.0 27.1  82:14.32 java

K8s 里 Java 进程通常是 PID 1。

这里可以先做一个快速判断：如果是GC 线程占 CPU，那 %CPU 会体现在多个 GC task thread 上，问题性质完全不同（内存而不是死循环）。先跑一次：

$ jstat -gcutil 1 1000 5
  S0     S1     E      O      M     CCS    YGC     YGCT    FGC    FGCT
  0.00  12.31  98.44  99.87  94.21  91.33  38214  892.412   412  318.224

老年代 99.87%，Full GC 412 次、累计 318 秒。这次 CPU 高确实是 GC 引起的？别急，先继续按流程走，因为还有一种可能：业务线程死循环产生大量对象，把 GC 逼疯了。GC 频繁是果不是因，得看线程才知道。

第二步：找到是哪个线程

$ top -Hp 1
  PID USER      PR  NI    VIRT    RES    SHR S %CPU %MEM     TIME+ COMMAND
   87 root      20   0   12.4g   4.2g  18924 R 98.7 27.1  41:22.13 java
  109 root      20   0   12.4g   4.2g  18924 S 12.3 27.1   5:12.44 java
  112 root      20   0   12.4g   4.2g  18924 S  9.8 27.1   4:58.01 java

线程 87 占了 98.7%，持续 41 分钟。这是一个稳定的热点线程，不是"每个线程都占一点"的那种均匀分布。

这里有个判断技巧：

• 单个线程长期 90%+ → 死循环、正则回溯、无限重试。好排查。
• 多个线程各占差不多百分比 → 正常的计算密集负载，或者真的流量涨了。
• GC 线程（名字带 GC task thread）占大头 → 内存问题，去看 jstat 和堆转储。
• 每次 top 出来的热点线程 ID 都不一样 → 线程池在轮换，说明是大量短任务，去查 QPS 和单请求耗时。

第三步：线程 ID 转十六进制

jstack 输出的线程 nid 是十六进制，而 top 给的是十进制。转换：

$ printf '%x\n' 87
57

所以要去 jstack 里找 nid=0x57。我一般直接用一行搞定：

$ jstack 1 > /tmp/jstack.log && grep -A 40 'nid=0x57' /tmp/jstack.log

输出：

"http-nio-8080-exec-24" #87 daemon prio=5 os_prio=0 tid=0x00007f2c1c0b4800 nid=0x57 runnable [0x00007f2bd43e6000]
   java.lang.Thread.State: RUNNABLE
	at java.util.regex.Pattern$GroupTail.match(java.base@11.0.12/Pattern.java:4796)
	at java.util.regex.Pattern$BranchConn.match(java.base@11.0.12/Pattern.java:4668)
	at java.util.regex.Pattern$CharProperty.match(java.base@11.0.12/Pattern.java:3850)
	at java.util.regex.Pattern$Branch.match(java.base@11.0.12/Pattern.java:4704)
	at java.util.regex.Pattern$GroupHead.match(java.base@11.0.12/Pattern.java:4760)
	at java.util.regex.Pattern$Loop.match(java.base@11.0.12/Pattern.java:4887)
	at java.util.regex.Pattern$GroupTail.match(java.base@11.0.12/Pattern.java:4796)
	at java.util.regex.Pattern$Curly.match0(java.base@11.0.12/Pattern.java:4340)
	at java.util.regex.Pattern$Curly.match(java.base@11.0.12/Pattern.java:4290)
	at java.util.regex.Pattern$GroupHead.match(java.base@11.0.12/Pattern.java:4760)
	at java.util.regex.Pattern$Start.match(java.base@11.0.12/Pattern.java:3545)
	at java.util.regex.Matcher.search(java.base@11.0.12/Matcher.java:1728)
	at java.util.regex.Matcher.find(java.base@11.0.12/Matcher.java:745)
	at java.util.regex.Matcher.matches(java.base@11.0.12/Pattern.java:1133)
	at java.lang.String.matches(java.base@11.0.12/String.java:1971)
	at com.xxx.order.util.ValidateUtil.isValidUrl(ValidateUtil.java:34)
	at com.xxx.order.service.OrderService.submitOrder(OrderService.java:158)

定位到 ValidateUtil.java:34，是一行正则校验。

第四步：确认为什么是死循环

看代码：

public static boolean isValidUrl(String url) {
    // 第 34 行
    return url.matches("^(https?://)?([\\w-]+\\.)+[\\w-]+(/[\\w-./?%&=]*)?$");
}

问题在那个 ([\\w-]+\\.)+：嵌套的量词。外层 + 修饰一个本身含 + 的分组，当输入接近匹配但最终不匹配时，正则引擎要穷举所有分组划分方式，复杂度是指数级的。这就是灾难性回溯（Catastrophic Backtracking，也叫 ReDoS）。

我用当时的入参验证了一下：

public static void main(String[] args) {
    String s = "https://" + "a".repeat(20) + "!";   // 结尾一个非法字符
    long start = System.currentTimeMillis();
    System.out.println(s.matches("^(https?://)?([\\w-]+\\.)+[\\w-]+(/[\\w-./?%&=]*)?$"));
    System.out.println("cost=" + (System.currentTimeMillis() - start) + "ms");
}

实测：

长度每加 1，耗时大约翻倍。线上那个请求的参数长度是 48 个字符的备注字段（被误传给了 URL 校验），理论上要跑几百年。

顺带说另一个问题：String.matches() 每次调用都会重新编译 Pattern（内部调 Pattern.matches()，没有缓存）。高频调用时这部分开销也不小。

修复

三处改动：

private static final Pattern URL_PATTERN = Pattern.compile(
        "^https?://[\\w-]+(\\.[\\w-]+)+(/[\\w./?%&=-]*)?$");   // 去掉嵌套量词

public static boolean isValidUrl(String url) {
    if (url == null || url.length() > 2048) {
        return false;                                  // 先限长，挡掉超长输入
    }
    return URL_PATTERN.matcher(url).matches();         // 复用编译好的 Pattern
}

• 把 ([\\w-]+\\.)+ 改成 [\\w-]+(\\.[\\w-]+)+：+ 不再直接修饰含 + 的分组，回溯路径从指数级降到多项式级。
• 预编译 Pattern 并复用。
• 加长度上限。这一条最朴素也最有效，所有正则校验都应该先限长。

改完再测，同样 22 个 a 的输入耗时 0.08 ms。

另外我们实际业务里 URL 校验用 Apache Commons Validator 的 UrlValidator 更省事，但它是白名单式校验，行为不完全一样，当时没换。

线上恢复

修复发版之前的临时止血：那个接口的备注字段本来就不该走 URL 校验，是参数绑定写错了。我们 Apollo 上关掉了这个校验分支，CPU 5 分钟内回落到 240%。

排查时的几个坑

坑一：容器里 jstack 可能起不来。

$ jstack 1
1: Unable to open socket file: target process not responding or HotSpot VM not loaded

常见原因是容器没有 SYS_PTRACE 权限，或者 JDK 11 的 attach 机制需要进程能写 /tmp。解决：

# 用 jcmd 替代，成功率更高
$ jcmd 1 Thread.print > /tmp/jstack.log

# 或者 Dockerfile 里加
securityContext:
  capabilities:
    add: ["SYS_PTRACE"]

坑二：只抓一次 jstack 会误判。 单次快照只能看到"这一刻"线程在哪。如果热点线程每次都不一样，单看一次会得到错误结论。正确做法是连续抓 5 到 10 次，取交集：

for i in {1..10}; do
  jcmd 1 Thread.print > /tmp/jstack_$i.log
  sleep 2
done
# 统计出现次数最多的栈顶
grep -h '^	at ' /tmp/jstack_*.log | sort | uniq -c | sort -rn | head -20

如果某个栈顶在 10 次采样里出现 8 次以上，那基本就是它。

坑三：RUNNABLE 不等于在烧 CPU。 线程状态是 RUNNABLE 但可能在等网络读（socket 读在 JVM 里也是 RUNNABLE）。判断依据要结合 top -Hp 的 %CPU 列，两都对上了才算。

还有两种常见的 CPU 100%

顺便记一下我遇到过的另外两类：

HashMap 并发扩容死循环。这个只在 JDK 7 及之前会出现（JDK 8 改成尾插 + 红黑树，不再环形链表，但并发 put 仍会丢数据）。现象是 CPU 100% 且栈顶在 HashMap.get/put 的链表遍历上。修法是换 ConcurrentHashMap。

GC 线程占满。top -Hp 里全是 GC task thread，jstat 看老年代 99%+、Full GC 频次暴涨。这种不要去查业务代码，直接抓堆转储：

$ jmap -dump:format=b,file=/tmp/heap.hprof 1
$ jhat /tmp/heap.hprof        # 或者用 MAT 分析

如果是因为业务代码疯狂产生对象（比如死循环里 new），还是会回到业务线程上。所以顺序是：先看业务线程的 CPU 占比，再看 GC 线程。

先到这

《CPU 飙高 100% 的标准排查流程》这块我前前后后踩了不止一次。今天先写这些，后面想到新的再补。

参考

• 官方文档：jvm-gc-performance
• Baeldung 上的相关实战
• StackOverflow 上的相关讨论