ARTICLE DETAIL

资讯详情

深耕网站建设与运营推广的一线实战洞察。

Java线上CPU飙高不用慌:Arthas 5分钟定位问题代码的完整排查指南

Java线上CPU飙高不用慌:Arthas 5分钟定位问题代码的完整排查指南 线上又报警了某台服务器的CPU使用率直接飙到95%以上接口响应时间翻了好几倍。这时候先别急着重启重启虽然能解一时之急但如果根因没找到过几天它还会再犯。我在这类问题上踩过不少坑最顺手的一套工具组合就是Arthas。它是阿里开源的一款Java诊断工具专门干“线上问题定位”这类脏活累活。这篇文章我就以“CPU使用率高”这个最常见的场景为例完整梳理一遍用 Arthas 从“看到报警”到“定位到具体哪一行代码”的全过程。不管你是刚接触 Arthas 还是已经会用几个命令这篇文章都能帮你把排查思路串起来。适合遇到线上卡顿、CPU飙升、想快速定位问题的 Java 开发、运维和 SRE 同学参考。1. CPU排查路径从传统三板斧到Arthas1.1 传统方式为什么慢top加jstack的局限先说最传统的排查方式大多数人都经历过接到报警登上服务器先top看一眼哪个进程占用高再top -Hp pid找到具体线程然后把线程ID转成十六进制执行jstack pid | grep -A 30 nid从线程栈里找线索。这一套流程的问题在于操作链条太长。每一步都要手动执行、手动转换、手动翻栈而且jstack打出来的线程栈是一个“瞬时快照”如果问题线程是间歇性出现的比如每隔几秒才疯狂消耗一次CPU你抓到快照的时机不对屏幕上全是WAITING、TIMED_WAITING的线程真正出问题的那个线程根本不在里面。更麻烦的是生产环境往往有权限管控jstack命令不一定能直接执行有时候你还得先找运维配合等权限批下来现场早就变了。这套传统方式不是不能用而是效率太低特别是在“线程频繁切换、问题间歇性出现”的场景下你很难靠一两次jstack命中目标。1.2 Arthas的解题思路动态增强与实时观测Arthas 的出现把整个流程大大缩短了。它是一个 Java Agent启动后可以 attach 到目标 JVM 进程上全程不需要重启应用也不需要额外装代理。它的核心价值在于“动态观测”你可以在不修改代码、不重启服务的前提下实时查看 JVM 内部的各种状态。对应到 CPU 排查这个场景Arthas 有两个非常趁手的命令dashboard一屏看全局包括 CPU、内存、GC、线程概况相当于把top、jstat、jstack的活儿全包了。thread专门定位线程问题可以直接按 CPU 占用排序一键找出最耗 CPU 的线程并且自动帮你把线程ID转换成十六进制直接打印线程栈连jstack的转换环节都省了。这就是 Arthas 的思路把“发现问题 - 定位线程 - 查看线程栈”这几步压缩成两三个命令让你把精力集中在“分析问题原因”上而不是浪费在“执行命令和转换格式”上。2. 实操流程5分钟定位CPU使用率最高线程2.1 第一步启动Arthas并attach到目标进程拿到一台 CPU 飙高的服务器第一步不是立刻执行top而是先确认目标进程的 PID。执行top看一眼找到 CPU 占用最高的那个 Java 进程记下 PID。假设这个 PID 是 12345。然后下载并启动 Arthascurl -O https://arthas.aliyun.com/arthas-boot.jar java -jar arthas-boot.jar启动之后Arthas 会列出当前机器上的所有 Java 进程让你输入序号选择要 attach 的进程。这里有一个小技巧直接带上 PID 参数启动可以跳过选择步骤java -jar arthas-boot.jar 12345注意Arthas 启动需要和目标进程使用同一个系统用户如果权限不足会 attach 失败。另外生产环境上执行这类诊断工具最好先在测试环境验证一遍确认不会有副作用再上生产。attach 成功之后会进入 Arthas 的交互终端提示符变成[arthas12345]$这时候就可以开始诊断了。2.2 第二步用dashboard快速掌握全局状态在 Arthas 交互终端里敲dashboard会输出一张信息非常密集的“仪表盘”左侧是线程概况会显示当前有多少线程在 RUNNABLE 状态、各个状态的数量分布中间是 JVM 内存使用情况包括堆内存各区域Eden、Survivor、Old的使用量右上角是 GC 相关数据比如 GC 次数、GC 耗时右下角是运行时信息包括 JVM 版本、操作系统信息等。这个命令最大的价值是帮你快速判断方向如果发现 Old 区在持续增长、GC 次数高得离谱那 CPU 飙升很可能和 GC 有关系如果 GC 数据正常那就把注意力放在线程状态上。比如我上次排查一个服务dashboard一刷出来Old 区已经用了 90% 多Full GC 次数一直在往上跳这时候基本不用看线程栈大概率是内存问题导致的 CPU 飙升。反过来如果 GC 次数很低内存也没啥压力那问题基本就锁定在线程身上的死循环或锁竞争了。看一眼全局敲q退出 dashboard进入下一步。2.3 第三步用thread命令按CPU占用抓线程这是整个排查流程里最核心的一步。直接执行thread -n 3这个命令的意思是找出当前 CPU 占用率最高的前3个线程并直接打印它们的线程栈。执行结果大致长这样简化版http-nio-8080-exec-10 Id42 RUNNABLE at com.example.OrderService.calculate(OrderService.java:123) at com.example.OrderService.getOrder(OrderService.java:98) at com.example.controller.OrderController.detail(OrderController.java:56) at java.base/java.lang.Thread.run(Thread.java:834)看到这个结果你基本已经走到问题门口了。线程名、线程 ID、线程状态、调用栈全都在这里不需要手动做任何转换。thread -n 3的执行原理是Arthas 会定时采样所有线程的 CPU 占用情况借助 JMX 的ThreadMXBean按 CPU 时间排序然后取前 N 个再针对这几个线程抓取线程栈。所以它能做到“谁占用高就抓谁”比盲目 jstack 精准得多。如果这个命令输出了结果但线程栈指向的是一些线程池内部的方法比如ThreadPoolExecutor$Worker.run别急往下多看几层业务代码一般就在调用链中间几行。2.4 第四步解读线程栈定位具体代码位置拿到了线程栈接下来就是“读栈”的功夫了。这里有个经验之谈盯住 RUNNABLE 状态的线程栈里最底层那几个at开头的行也就是栈顶位置。因为如果一个线程在疯狂消耗 CPU它一定是处于 RUNNABLE 状态并且反复执行某个方法。举个最常见的例子pool-3-thread-1 Id88 RUNNABLE at java.util.HashMap.putVal(HashMap.java:625) at java.util.HashMap.put(HashMap.java:612) at com.example.cache.LocalCacheManager.put(LocalCacheManager.java:89) at com.example.cache.LocalCacheManager.rebuild(LocalCacheManager.java:67) at com.example.cache.LocalCacheManager.run(LocalCacheManager.java:55) at java.lang.Thread.run(Thread.java:834)看到HashMap.putVal还有自己的rebuild方法基本就是在循环往一个本地缓存里塞数据而且这个缓存可能在无限重建。顺着栈去看LocalCacheManager.java:67那行代码大概率能找到一个没有退出条件的 while 循环。读栈的经验总结成一句话先看线程状态RUNNABLE 优先怀疑再看栈顶CPU 密集操作集中在栈顶最后顺着栈中间找自己的业务代码。陌生的框架类名先跳过找包名里带着自己公司域名的行那是项目经理的入口。3. 定位到代码之后高频CPU问题类型深度拆解3.1 死循环和空转最常见也最容易忽略死循环是 CPU 飙高的第一大元凶但很多死循环写得并不“明显”比如这种while (true) { // 没有break也没有条件判断 ListOrder orders orderMapper.selectByStatus(0); process(orders); }看代码一眼就能发现问题但线上查的时候有效信息全在线程栈里。你用thread -n 3抓到栈之后如果看到while对应的字节码在反复执行基本就是死循环。还有一种更难发现的空转比如一个线程在等待某个条件发生变化但这个条件永远不变public void run() { while (!isReady) { // 啥也没干纯空转 } }这种代码不会报错也不会产生业务日志但 CPU 一直被打满。线程栈上会看到这个run方法始终处于 RUNNABLE 状态。Arthas 还有一招可以确认连续执行两次thread -n 3如果同一个线程、同一个栈位置每次都出现那基本实锤了。3.2 频繁GC导致CPU飙升容易被误判的方向很多时候CPU 飙升不是业务代码真的在“计算”而是 JVM 在疯狂 GC。GC 本身也是 CPU 密集操作尤其是 Full GC它会触发整个堆的扫描和整理CPU 消耗非常高。判断 GC 导致的 CPU 飙升dashboard里的 GC 数据是最好的证据。如果看到gc.ps_scavenge.count或gc.ps_marksweep.count短时间内猛涨或者 GC 耗时占比很高那重点就不是线程栈了而是对象分配和内存占用。这时候用 Arthas 的memory命令看一下堆内存分布再用trace命令追踪某个高频方法的耗时和调用次数往往能找到“疯狂创建对象”的源头。比如我曾经遇到过一个案例代码里在循环里频繁new一个大对象作为临时变量导致 Eden 区很快打满Minor GC 频率陡然上升连带 CPU 飙高。提示排查 CPU 问题时先看 GC 再抓线程栈。GC 数据能帮你少走一半弯路。如果 GC 次数和耗时都正常再集中精力分析线程栈。3.3 锁竞争和自旋等待一个容易被忽略的CPU消耗点Java 里的锁竞争也会消耗 CPU尤其是使用synchronized或ReentrantLock且竞争非常激烈的时候。你以为线程在“等锁”它确实在等但 JVM 的锁膨胀机制会让它在自旋等待时持续占用 CPU。这种场景下thread -n 3抓到的线程栈会很有意思线程状态可能显示为 RUNNABLE栈上能看到sun.misc.Unsafe.park或者AbstractQueuedSynchronizer相关的方法。举个例子pool-1-thread-5 Id120 RUNNABLE at java.base/jdk.internal.misc.Unsafe.park(Native Method) at java.util.concurrent.locks.LockSupport.park(LockSupport.java:341) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquireQueued(...) at java.util.concurrent.locks.AbstractQueuedSynchronizer.acquire(...) at java.util.concurrent.locks.ReentrantLock$NonfairSync.lock(...) at com.example.InventoryService.deduct(InventoryService.java:45)这种情况CPU 飙升只是症状真正的病因是对同一个锁的竞争太激烈。解决思路通常有三类减少锁的粒度、用读写锁替代互斥锁、或者引入无锁数据结构。Arthas 这个时候还能辅助看“谁在长时间持有锁”用thread -b命令可以找出当前阻塞其他线程的线程对分析死锁和锁竞争非常有帮助。3.4 日志刷屏最隐蔽的CPU杀手还有一种很隐蔽的情况代码本身没问题但日志框架在疯狂输出。比如某个方法在循环里打了 debug 日志而生产环境日志级别配置成了 DEBUG。日志刷屏对 CPU 的消耗来自两个方面一个是字符串拼接日志框架要把日志消息拼成字符串另一个是 I/O 写入尤其是写文件、写 Kafka、写 ES。线程栈上你会看到频繁出现log4j、logback、slf4j相关的类名。遇到这种情况处理方式分两步先通过 Arthas 的logger命令查看当前各类的日志级别确认是否被调成了 DEBUG再到对应的代码位置看日志是不是在循环里打的如果日志量非常大即使级别对也要考虑加缓存或采样。3.5 正则回溯和序列化等重型操作定位后优化代码最后提一类比较“高级”的 CPU 消耗正则表达式的灾难性回溯、大规模 JSON/XML 序列化、深层递归。这些操作的特点是非常消耗 CPU且线程栈上能看到明确的类名。比如正则回溯线程栈里会看到类似java.util.regex.Pattern$Loop.match反复出现。这类问题的优化方向通常是避免在循环里用正则、使用预编译的 Pattern 对象、或者用更简单的字符串匹配替代。同样大对象序列化可以考虑改用更高效的序列化框架。诊断特长操作时Arthas 更强大的功能是trace它可以追踪某个方法的内部耗时分布精确到每个子调用这对于定位“方法内部哪一行最耗时”非常有用。比如trace com.example.OrderService calculate执行后它会打印calculate方法内部所有子调用的耗时统计一眼就能看到是查询数据库慢还是正则处理慢还是其他计算逻辑慢。4. 常见问题与排查技巧实录4.1 attach不上目标进程怎么办实际工作中Arthas attach 不上进程的情况非常常见尤其是高版本 JDK 和容器环境。最常见的报错是com.sun.tools.attach.AttachNotSupportedException原因是 JDK 缺少 attach 模块。不同 JDK 版本解决方案不太一样JDK 8 及以下确认 JDK 里有tools.jarArthas 依赖它实现 attach。JDK 9确认 JDK 里包含jdk.attach模块有些精简版 JDK 会去掉这个模块。容器环境确认进程是在同一个 PID namespace 里docker exec进容器后再启动 Arthas。还有一个很实际的问题Arthas attach 后目标进程会多出一个 Agent 线程虽然通常影响很小但在极端低配机器上还是要注意观察。我用的时候一般盯一下 dashboard如果负载升高明显就赶紧排查完退出。4.2 线程栈全是线程池的名字怎么对应到业务thread -n 3抓出来的线程名如果是pool-1-thread-1这种说明线程是用Executors或者自定义线程池创建的。问题是线程池名字看不出它是哪个业务模块的。这时候有两个处理办法建议开发时给线程池自定义ThreadFactory并起一个有意义的名字比如order-async-pool-thread-1。这是治本的办法排查问题能省很多时间。如果已经是踩坑现场那就看线程栈里的业务类名通过栈中间的包名和类名反推是哪条业务链路。比如看到com.example.wechat.PushService大概率是微信推送相关的线程池。这里我特别推荐一个方法结合 Arthas 的ognl命令直接查看这个线程池的内部状态。比如ognl -c com.example.config.ThreadPoolConfig threadPoolgetActiveCount()具体表达式要看你的静态字段怎么定义但思路是通过 ognl 直接读取线程池的活跃线程数、队列大小、任务数判断线程池是不是被任务塞满了。4.3 抓到的线程栈指向不明确或者线程一直在变间歇性问题是最难抓的因为thread -n 3每次抓到的线程可能都不一样。这种情况下我建议做“连续采样”多执行几次thread -n 3把结果汇总看哪些线程反复出现。反复出现的那个就是重点怀疑对象。还有一招是看线程的累计 CPU 时间Arthas 的thread命令有一个参数--cpu可以指定采样时间。比如thread -n 5 --cpu 3000这个命令会用 300ms 的采样窗口去统计 CPU 占用相比默认参数更容易抓到那些“不是一直都在跑、但每隔一会儿就猛跑一下”的线程。4.4 定位到“线程栈顶层是框架代码”怎么办线程栈的顶层如果是netty、kafka、dubbo这些框架的代码很多人就卡住了不知道该不该继续查。我的经验是框架层的代码大概率不是根因根因在框架回调到业务代码的那一层。比如 Netty 的NioEventLoop在执行你注册的 handler 时如果 handler 里面写了耗时操作栈上会同时出现 Netty 框架代码和你的业务代码。顺着栈往下翻看到自己的 Service、DAO 或者 Controller 的时候那才是问题所在。如果真的全栈都是框架代码连一个业务类都没有那大概率是框架本身内部的问题比如版本 bug、内部线程数配置不合理。这种时候可以搜一下当前框架版本的 issue比死磕线程栈效率高。另外一个技巧是使用stack命令反向查询指定某个你认为可疑的业务方法让 Arthas 打印出所有调用这个方法的地方。比如stack com.example.OrderService getOrder这样就能把问题范围缩小到具体调用链路上方便追溯是哪条入口触发的高频调用。5. 一整套排查流程的串联以真实案例收尾最后分享一个我实际处理过的完整案例把这套流程串起来。那次是一个电商促销活动晚上八点刚过监控报警两台应用服务器 CPU 使用率同时飙到 99%接口平均响应时间从 50ms 涨到了 2 秒。我先top确认了进程查明是订单服务PID 20461然后启动 Arthas attach。进入交互终端后第一件事是dashboard结果发现 GC 数据非常平稳Old 区占用只有 30% 左右再敲thread -n 3抓到的结果里名列前茅的线程栈高度相似。打印出的线程栈指向了一个PriceCalculateService的calcPromotion方法栈顶是java.util.regex.Pattern$Loop.match。这个信号非常明确正则匹配出了问题而且calcPromotion内部在大量调用正则。我顺着代码一查发现calcPromotion里有个对优惠券编码的校验用了一个复杂正则去匹配券码中“前缀日期随机数字”的格式。正常情况没问题但活动当天运营批量导入了一批“特殊渠道券”券码格式不合法导致正则引擎开始进行灾难性回溯。一个券码可能就会让匹配耗时几十毫秒并发一高CPU 直接被打满。定位到这个原因之后处理方案很简单把正则预编译成Pattern常量同时增加一个长度和字符集的前置校验先过滤掉明显不合法的券码再走正则。改造上线后CPU 降回正常水平接口响应时间恢复到了 40ms 左右。这个案例其实是很多 CPU 问题的缩影表面上是 CPU 高根子上可能是正则、是 GC、是死循环、是锁竞争。Arthas 帮我们把问题从“CPU 高”快速引导到“具体代码行”剩下的分析工作就靠对业务的理解了。先说结论排查 CPU 使用率高问题我个人的习惯是“先全局再局部先排除 GC 再抓线程抓住线程就往业务代码翻”。遇到问题不要慌着重启重启意味着丢失现场而 Arthas 的价值恰恰是让你在“现场”把问题看清楚。多花十分钟在诊断上可能就省下未来好几个小时的加班排查时间。
返回列表