Administrator
发布于 2022-05-07 / 10176 阅读
272

Async-profiler 火焰图定位性能热点

压测时 CPU 打满,top 却看不出热点

上个月我们对订单导出服务做容量评估,用 JMeter 打 800 并发。奇怪的是:应用进程 CPU 占用 760%(8 核几乎跑满),但业务代码里我自认为的"重计算"那段——一个金额汇总循环——在抽样栈里占比不到 8%。同事在群里问:"你那个汇总到底慢在哪?我看着 CPU 全给占了。"

当时我用的是 JDK 自带的 jstack 定时抽样,但那是 Safepoint 采样,很多 native 与系统调用采不到,结论失真。这次我换上了 async-profiler。

采样原理:它和 jstack 根本不是一回事

async-profiler 不依赖 Safepoint。它通过 AsyncGetCallTrace API 在信号(SIGPROF)触发时直接抓取调用栈,还能接入 Linux 的 perf_events 做内核态采样。好处有两个:能抓到 Safepoint 之外的栈,也不会因为"采样偏向 Safepoint"而漏掉真正的热点。

它是非侵入式的:不修改字节码、不产生 STW,对生产进程基本无感。线下压测先跑 CPU profile:

# 对 PID 1821 的进程采样 60 秒,输出火焰图 svg
$ ./profiler.sh -d 60 -f /tmp/flame_cpu.svg 1821

采样间隔默认 10ms(-i 可调),属于统计采样而非逐条指令计数,所以火焰图看的是比例关系,不是绝对值。

On-CPU:真凶是 JSON 序列化

火焰图打开,最宽的"平顶"不是汇总循环,而是 com.fasterxml.jackson.databind.ser...serialize 占到了 41%。导出接口每次把 2 万条订单转 JSON 再写 CSV,jackson 的反射式序列化吃掉了近一半 CPU。

换成预编译的 ObjectWriter 并关掉用不到的特性后:

ObjectWriter writer = objectMapper
        .configure(SerializationFeature.FAIL_ON_EMPTY_BEANS, false)
        .writerFor(OrderExportDTO.class);   // 预绑定类型,跳过运行时类型推断
// 之前:每次 new ObjectMapper + 反射找字段,约 18 ms/千条
// 之后:复用 writer,约 6.3 ms/千条

重新压测,同 800 并发下 CPU 从 760% 降到 430%,导出吞吐从 1.1 万条/秒提到 2.0 万条/秒。

Off-CPU:另一个被忽略的坑

CPU 降下来后接口 P99 还有 320 ms 的毛刺。此时 On-CPU 火焰图已经很干净,但 AsyncGetCallTrace 抓不到"线程在等什么"。我改用 Off-CPU 的 wall-clock 模式,它统计的是线程不在 CPU 上运行的时间(阻塞在锁、IO、网络):

# 按墙上时钟采样,能覆盖阻塞时间
$ ./profiler.sh -e wall -d 30 -f /tmp/flame_wall.svg 1821

结果指向 java.net.SocketInputStream.socketRead0 占 37%——导出时每条订单都去 Redis 查一次用户昵称,2 万次网络往返。把昵称在查询阶段用一条 WHERE id IN (...) 批量拉回本地 Map 再拼接,P99 从 320 ms 降到 90 ms。

On-CPU 与 Off-CPU 怎么选

  • On-CPU(默认 -e cpu):看"在 CPU 上跑的时间花在哪",适合计算热点。
  • Off-CPU(wall-clock):看"为什么慢但 CPU 不高",适合锁竞争、网络/磁盘 IO 阻塞。

顺手抓一张内存火焰图

alloc 模式能定位哪些代码在疯狂 new 对象,对排查 GC 压力很有用:

$ ./profiler.sh -e alloc -d 60 -f /tmp/flame_alloc.svg 1821

跑完发现 BigDecimal 临时对象每秒分配 1.2 GB,金额累计算法每加一次就 new 一个。改成 double 累加、最后格式化一次,Young GC 频率从每 4 秒一次降到每 17 秒一次。

一轮压测的三张图

指标优化前优化后
导出吞吐1.1 万条/秒2.0 万条/秒
CPU 占用(800 并发)760%430%
接口 P99320 ms90 ms
Young GC 间隔4 秒17 秒

小结

  • jstack 是 Safepoint 采样,会漏掉 Safepoint 之外的热点;async-profiler 用信号 + AsyncGetCallTrace,更准。
  • CPU 打满先看 On-CPU 火焰图找计算热点;接口慢但 CPU 不高看 Off-CPU(wall 模式)。
  • 别只信"我以为的热点"。我把 41% 的 jackson 当成 8% 的汇总循环,差点白优化。
  • alloc 模式顺手能挖出 GC 压力来源,一次压测把三件事都看了。

这次最大的收获不是那几个优化点,而是一个习惯:压测完第一件事不是调参数,是先抓一张火焰图。没有数据支撑的"我觉得慢在这",九成是错的。

参考