监控告警发过来的时候,某台应用服务器load从平时的1.2涨到23,top里排第一的是一个java进程,CPU列显示782%,机器是16核。重启能缓半小时,之后照旧。
这种时候先别急着重启,重启完证据就没了,下次还得从头查。
先分清是us高还是sy高
top看到java进程CPU高,第一步不是抓栈,而是看这CPU花在用户态还是内核态。顶部那行 %Cpu(s): 92.1 us, 6.3 sy就够用:us高基本是业务代码在跑,sy高多半是线程数过多、锁竞争激烈或者网络小包收发太频繁,两种情况的排查方向完全不一样。
sy高的先去查上下文切换。vmstat 1里cs列每秒上万,用pidstat -w -p 12345 1再看一眼,自愿切换占大头,一般是线程池开太大或者synchronized抢得厉害。us高的继续往下走。
把高CPU的线程挑出来
top默认看进程,加 -H参数才列线程。跑起来之后按P排CPU,记下第一列的PID,那是线程id,十进制的:
top -Hp 12345
假设挑出来的线程id是4567。jstack输出里的nid是十六进制的,得先转一下:
printf '%x\n' 4567 # 输出 11d7
抓线程栈并对上号
转完之后抓栈。JDK 8用jstack,JDK 11之后用jcmd更稳,两者输出基本一致。8u361、11.0.21、17.0.9这几个版本上都实测过,nid的写法没变:
jstack -l 12345 > /tmp/stack1.txt # 或者 jcmd 12345 Thread.print > /tmp/stack1.txt
拿十六进制的nid去搜,-A 25是多看25行上下文,光看一行栈顶容易误判:
grep -A 25 'nid=0x11d7' /tmp/stack1.txt
搜出来大致长这样,线程状态是RUNNABLE,栈顶就是当前正在执行的方法:
"http-nio-8080-exec-7" #32 daemon prio=5 os_prio=0 tid=0x00007f2c4c0e8000 nid=0x11d7 runnable [0x00007f2c1b7fe000] java.lang.Thread.State: RUNNABLE at java.util.regex.Pattern$Loop.match(Pattern.java:4835) at java.util.regex.Pattern$GroupTail.match(Pattern.java:4773) at com.xxx.service.ValidateService.checkMobile(ValidateService.java:88)
Pattern$Loop和Pattern$GroupTail反复出现,基本就能断定是正则回溯。
这个坑踩过不止一次。
手机号校验的正则从网上抄来的,写法里带嵌套量词,正常输入没问题,遇到长串的脏数据直接把CPU吃满。
只抓一次不够
单次快照容易误判。某个线程刚好在做一次正常的序列化,抓到它就当成元凶,改完发现一点用没有。稳妥做法是连抓三次,每次间隔5秒,三个文件里都停在同一段栈上的,才是真的热点:
for i in 1 2 3; do jstack -l 12345 > /tmp/stack$i.txt; sleep 5; done
现场没条件写循环就直接敲三遍。
容器里的几个坑
现在大部分Java服务跑在容器里,jstack经常报 "Unable to open socket file: target process not responding or HotSpot VM not loaded"。原因一般就两个:一是基础镜像只装了JRE没装JDK,压根没有jstack这个命令;二是JVM是容器的PID 1,attach机制对PID 1有限制。
基础镜像这块,eclipse-temurin的17.0.9、21.0.2两个tag都带完整JDK,把Dockerfile里的jre换成jdk就解决了。镜像不方便改,用jattach 1.5的静态二进制也能把栈抓出来:
jattach 12345 threaddump > /tmp/stack1.txt
还有一种情况:JDK 11之前的版本不认cgroup限制。容器限了2核,JVM按宿主机的核数算GC线程数和ForkJoinPool并行度,8个GC线程抢2核的配额,CPU直接打满。JDK 8u191之后加了UseContainerSupport并且默认开启,比这更早的版本要显式加 -XX:+UseContainerSupport。
GC线程占高是另一回事
如果top -H里排前面的是 "GC task thread" 或者 "VM Thread",那不是业务代码的事,是堆不够用或者有内存泄漏。看GC情况:
jstat -gcutil 12345 1000
FGC列一秒涨好几次、OU一直贴在99%,说明回收不出来。这时候抓业务栈没意义,得先把堆dump下来看是谁占着。启动参数里建议常年开着 -XX:+HeapDumpOnOutOfMemoryError和 -XX:HeapDumpPath=/data/dump,真出事的时候不至于抓瞎。
常见的几个代码原因
正则回溯排第一,嵌套量词比如 (a+)+ 这种写法,输入稍微长一点就是指数级耗时。JSON序列化排第二,之前碰到过一个服务,Jackson的ObjectMapper每次writeValueAsString一个几MB的对象,量一上来CPU就下不去。剩下的还有while循环里没sleep空转、日志里大量打印异常堆栈,以及JDK 7时代HashMap并发扩容成环的经典问题,JDK 8改成尾插法之后不会成环了,但并发改HashMap照样丢数据。
拿不准的时候上async-profiler 2.9,跑30秒出一张火焰图,热点一眼看出来,比人肉grep栈快得多:
./profiler.sh -d 30 -f /tmp/flame.html 12345
不想装东西,Arthas 3.7.2的thread -n 3直接列出CPU占用最高的三个线程和它们的栈,attach上去就能用,完事shutdown退出,对线上影响很小。2024年之后Arthas 4.0.x也出来了,命令用法没变。
查完把结论落到监控上。CPU打满这种事通常不是第一次,告警规则里加一条us持续5分钟超过80% 就通知,比等load涨到20才被发现强得多。