02 火焰图阅读与性能问题识别

摘要:

火焰图(Flame Graph)是 Brendan Gregg 在 2011 年发明的一种 Profile 数据可视化方法,它将成千上万条调用栈采样聚合为一张直观的 SVG 图表——X 轴是函数名(按字母排序),Y 轴是调用栈深度,每个矩形的宽度代表该函数在 Profile 中被采样到的比例(即它占总 CPU 时间的百分比)。火焰图之所以成为性能分析的”通用语言”,是因为它具备两个关键特性:一眼可见热点(宽的矩形就是热点)和完整的调用上下文(从栈底到栈顶可以看到完整的调用链路)。本文从火焰图的数据结构和生成原理出发,详细讲解阅读技巧,并通过多个真实场景演示如何从火焰图中识别 CPU 热点、GC 压力、锁竞争和 I/O 等待等常见性能问题。


第 1 章 火焰图的起源与设计

1.1 Profile 数据的可视化难题

01 持续性能剖析 中,我们知道 Profile 的原始数据是”调用栈 + 采样次数”的列表。一个典型的 CPU Profile 可能包含数万条不同的调用栈。如何将这些数据可视化,让工程师快速找到性能热点?

在火焰图出现之前,Profile 数据的主要可视化方式是调用树(Call Tree)表格(Table)

调用树:以树形结构展示函数的调用关系,每个节点显示该函数的 CPU 时间。问题是——当调用树的深度超过 20 层、分支超过 100 个时,树形视图变得难以浏览。工程师需要不断展开和折叠节点,很难建立全局视角。

表格:按 CPU 时间排序的函数列表,显示每个函数的”self 时间”(函数自身执行的时间,不含子调用)和”total 时间”(含子调用)。问题是——表格丢失了调用上下文。知道 serialize() 函数占了 30% 的 CPU 时间,但不知道它是被 processOrder() 调用的还是被 sendNotification() 调用的——两种情况的优化方向完全不同。

1.2 Brendan Gregg 的火焰图设计

Brendan Gregg(Netflix 高级性能工程师,《BPF Performance Tools》作者)在 2011 年设计了火焰图,解决了上述两个问题:

设计原则一:宽度 = 热点。每个矩形的宽度与它在 Profile 中被采样到的比例成正比。最宽的矩形就是最大的 CPU 时间消耗者——工程师一眼就能看到热点,不需要逐行阅读。

设计原则二:垂直方向 = 调用关系。Y 轴从下到上是从调用者到被调用者的关系。栈底(最底部)是程序的入口(如 mainThread.run),栈顶(最顶部)是实际执行代码的函数。每个矩形的上方是它调用的子函数。

设计原则三:X 轴不是时间。这是火焰图最常见的误读。X 轴的排列顺序是按函数名的字母顺序,目的是将相同函数名的调用栈合并在一起——让同一个函数的所有调用路径在视觉上聚集。X 轴的左右位置没有时间含义。

1.3 火焰图的数据结构

火焰图的底层数据结构是一棵前缀合并树(Prefix-Merged Trie)

原始采样数据(5 条调用栈,每条被采样到的次数不同):

main → handleRequest → processOrder → serialize      350 次
main → handleRequest → processOrder → queryDB         120 次
main → handleRequest → processOrder → validate         30 次
main → handleRequest → authenticate                    80 次
main → GC.collect                                      20 次
                                                 总计:600 次

合并为前缀树:

main (600)
├── handleRequest (580)
│   ├── processOrder (500)
│   │   ├── serialize (350)
│   │   ├── queryDB (120)
│   │   └── validate (30)
│   └── authenticate (80)
└── GC.collect (20)

火焰图将这棵树”拍平”为矩形堆叠图:

                  serialize (58.3%)
          processOrder (83.3%)              authenticate
     handleRequest (96.7%)                              GC
main (100%)

每一层的矩形宽度之和等于其父节点的宽度。processOrder 的宽度是 handleRequest 的 500/580 ≈ 86.2%。


第 2 章 火焰图的阅读技巧

2.1 识别热点函数

核心规则:看栈顶(最上面一行)最宽的矩形。

栈顶的矩形代表”self 时间”——函数自身正在执行的代码时间(不含它调用的子函数)。如果一个函数在栈顶占据了很宽的空间,说明它本身消耗了大量的 CPU 时间,而不是因为它调用了耗时的子函数。

在上面的例子中,serialize 在栈顶占了 58.3%——这就是最大的 CPU 热点。优化 serialize 函数本身(如换一个更快的 JSON 库、减少序列化的字段数量)是最有效的优化方向。

常见误读:看到 main 函数占了 100% 的宽度就认为 main 是热点——错。main 只是程序的入口,所有的 CPU 时间都”经过”了 mainmain 的 self 时间接近 0%(main 本身几乎不做任何计算)。热点永远在栈顶。

2.2 理解 self 时间 vs total 时间

概念含义在火焰图中的体现
Self 时间函数自身执行的时间(不含子调用)该矩形上方没有子矩形的部分
Total 时间函数从进入到退出的总时间(含子调用)该矩形的总宽度

processOrder 的 total 时间是 83.3%,但它的 self 时间只有 83.3% - 58.3%(serialize)- 20%(queryDB)- 5%(validate)= 0%——processOrder 本身几乎不消耗 CPU,所有时间都花在了它的子调用上。

这意味着:优化 processOrder 函数本身(如重构它的代码逻辑)不会有任何收益——你应该优化的是它调用的子函数 serialize

2.3 从上往下读 vs 从下往上读

从下往上读(Bottom-Up):从 main 开始,看每一层的分支——“程序入口 → 请求处理 → 业务逻辑 → 序列化”。这种读法适合理解”请求的整体执行路径”。

从上往下读(Top-Down):先看栈顶最宽的矩形(热点),然后沿着垂直方向往下看——“serialize ← processOrder ← handleRequest ← main”。这种读法适合”快速定位热点,然后追溯调用链路”。

推荐的阅读顺序

  1. 先看栈顶:找到最宽的栈顶矩形(最大的 CPU 热点)
  2. 往下追溯:沿着调用链看这个热点函数是被谁调用的
  3. 看宽度突变:在调用链中找到”宽度突然变窄”的地方——那是 CPU 时间集中的分叉点
  4. 看”平顶”:如果一个矩形的顶部很平(上方没有子矩形),说明该函数的 self 时间很高——它本身是 CPU 密集的

2.4 火焰图的颜色含义

火焰图的颜色在原始设计中没有特殊含义——Brendan Gregg 最初使用随机的暖色调(红/橙/黄),纯粹是为了视觉美观和区分相邻矩形。

但在现代工具中,颜色被赋予了语义:

工具颜色含义
Grafana Pyroscope按包名/模块着色(不同模块不同颜色)
async-profiler绿色 = Java 代码,黄色 = C/C++ 原生代码,红色 = 内核代码
Diff 火焰图红色 = 增加(比基线多),蓝色/绿色 = 减少(比基线少)

第 3 章 火焰图的变体

3.1 倒置火焰图(Icicle Graph)

传统火焰图栈底在下、栈顶在上。倒置火焰图(Icicle Graph) 将方向翻转——栈底在上、栈顶在下,看起来像倒挂的冰柱。

倒置火焰图在某些场景下更直观:当你关注”哪些入口函数消耗了最多的 CPU”时,倒置火焰图将入口函数放在最上面(视觉焦点),子调用向下展开。Grafana Pyroscope 默认使用倒置火焰图。

3.2 Diff 火焰图

Diff 火焰图是持续 Profiling 中最有用的分析手段之一。它将两个时间段的 Profile 数据做差异对比,用颜色标注变化:

  • 红色矩形:相比基线(如”正常时期”),该函数的 CPU 占比增加
  • 蓝色/绿色矩形:该函数的 CPU 占比减少
  • 白色/灰色矩形:没有显著变化

Diff 火焰图的典型用法

场景一:排查性能退化。将”本次部署后”的 Profile 与”上次部署前”的 Profile 做 Diff。红色的部分就是”新代码引入的 CPU 热点”。

场景二:排查间歇性延迟。将”延迟尖峰时段”的 Profile 与”正常时段”的 Profile 做 Diff。红色的部分就是”导致延迟升高的代码路径”。

场景三:验证优化效果。将”优化后”的 Profile 与”优化前”的 Profile 做 Diff。蓝色的部分就是”优化生效的代码路径”。

3.3 Sandwich 视图

Sandwich 视图聚焦于单个函数,同时显示它的”所有调用者(Callers)“和”所有被调用者(Callees)”:

           ┌─────────────┐
           │  Callers     │  谁调用了 serialize?
           │  (上半部分)   │  processOrder (70%), sendResponse (30%)
           ├─────────────┤
           │  serialize   │  ← 选中的函数
           ├─────────────┤
           │  Callees     │  serialize 调用了谁?
           │  (下半部分)   │  ObjectMapper.writeValueAsString (90%), ...
           └─────────────┘

Sandwich 视图回答两个问题:

  • “这个热点函数是从哪些代码路径被调用到的?“(Callers)
  • “这个函数内部的时间花在了哪些子调用上?“(Callees)

第 4 章 常见性能模式识别

4.1 模式一:CPU 计算热点

火焰图特征:栈顶有一个或几个非常宽的矩形,这些函数不是 I/O 操作也不是锁等待,而是纯计算逻辑。

典型场景

  • JSON/XML 序列化/反序列化(ObjectMapper.writeValueAsStringGson.toJson
  • 正则表达式匹配(Pattern.matcher 在复杂正则上的回溯)
  • 加密/解密(AES.encryptRSA.sign
  • 字符串拼接(大量 String.concatStringBuilder.append
  • 集合遍历(对大集合做 stream().filter().map().collect()

优化方向

  • 换更高效的库(如 Jackson → fastjson2,或启用 Jackson 的 Afterburner 模块)
  • 减少不必要的计算(如缓存正则编译结果,避免每次请求重新编译 Pattern.compile
  • 减少数据量(如只序列化必要的字段,避免返回巨大的嵌套对象)

4.2 模式二:GC 压力

火焰图特征:火焰图中出现显著比例(> 5%)的 GC 相关函数,如:

  • Java:GC.collectGCWorkerG1 Young GenerationParallelGC
  • Go:runtime.gcBgMarkWorkerruntime.gcDrainruntime.mallocgc

根因分析:GC 压力通常由过多的堆内存分配引起。此时应该结合 Allocation Profile(而非 CPU Profile)来定位分配热点。

典型场景

  • 循环内创建大量临时对象(如每次迭代 new ArrayList<>()
  • 日志框架在每次打日志时格式化字符串(如 String.format()+ 拼接)
  • 频繁的装箱/拆箱(intInteger

优化方向

  • 对象复用(使用对象池)
  • 减少临时对象分配(如使用 StringBuilder 替代字符串拼接)
  • 调整 GC 参数(如增大 Young Generation 大小、切换 GC 算法)

4.3 模式三:锁竞争

火焰图特征:在 Lock/Contention ProfileWall-clock Profile 中,出现大量的锁等待函数:

  • Java:java.util.concurrent.locks.ReentrantLock.locksynchronizedObject.wait)、ThreadPoolExecutor.getTask
  • Go:sync.Mutex.Lockruntime.semacquire

在 CPU Profile 中,锁竞争可能不明显——因为等待锁的线程不消耗 CPU。需要用 Lock Profile 或 Wall-clock Profile 才能看到。

典型场景

  • 全局单例的同步方法(如单一的数据库连接池 getConnection 加了全局锁)
  • 日志框架的同步写入(如 log4jsynchronized 方法在高并发下成为瓶颈)
  • 共享的 HashMap/ArrayList 加了全局锁而非使用 ConcurrentHashMap

优化方向

  • 减小锁粒度(将全局锁拆分为分段锁)
  • 使用无锁数据结构(ConcurrentHashMapAtomicLong
  • 使用 ThreadLocal 避免竞争
  • 异步化(如日志异步写入)

4.4 模式四:I/O 等待

火焰图特征:在 Wall-clock Profile(或 Off-CPU Profile)中,出现大量的 I/O 等待函数:

  • java.net.SocketInputStream.read(网络读取)
  • java.io.FileInputStream.read(磁盘读取)
  • sun.nio.ch.EPollSelectorImpl.doSelect(NIO 事件等待)
  • 系统调用如 epoll_waitreadwrite

在 CPU Profile 中,I/O 等待几乎不可见——因为等待 I/O 的线程让出了 CPU。

典型场景

  • 同步的数据库查询(等待数据库返回结果)
  • 同步的 HTTP 调用(等待下游服务响应)
  • 磁盘文件读写(日志写入、文件处理)

优化方向

  • 异步化 I/O(使用异步 HTTP 客户端、响应式数据库驱动)
  • 添加缓存减少 I/O 次数
  • 批量化 I/O(将多次小查询合并为一次批量查询)
  • 使用连接池减少连接建立的开销

4.5 模式五:线程饥饿

火焰图特征:火焰图中 ThreadPoolExecutor.getTask 或线程池调度相关函数占比很高——线程在等待任务,而不是执行任务。

这种模式通常伴随着CPU 使用率低但延迟高——请求在线程池队列中排队等待,而可用线程都被慢请求占用。

典型场景

  • 线程池大小配置过小
  • 少数慢请求(如慢 SQL)阻塞了线程池中的大部分线程
  • 线程池类型选择不当(使用固定大小线程池处理 I/O 密集型任务)

第 5 章 不同语言的火焰图实践

5.1 Java

Java 生态中最推荐的 Profiler 是 async-profiler——它使用 JVM 内部的 AsyncGetCallTrace API,避免了传统 Java Profiler 的 Safepoint Bias 问题。

Safepoint Bias 问题

JVM 的传统 Profiling 方法(如 jstack、JVisualVM 的 CPU Sampler)只能在 Safepoint(安全点)处采样——即 JVM 暂停所有线程进行 GC 或其他全局操作的时间点。问题在于 Safepoint 的出现与代码的 CPU 热点无关——热循环内部如果没有 Safepoint(如紧凑的数值计算循环),这些热点永远不会被采样到。async-profiler 使用 POSIX 信号机制,可以在任意时刻采样,不受 Safepoint 限制。

# async-profiler 采集 CPU Profile(持续 30 秒)
./asprof -d 30 -f profile.html <PID>
 
# 采集 Allocation Profile
./asprof -d 30 -e alloc -f alloc_profile.html <PID>
 
# 采集 Lock Contention Profile
./asprof -d 30 -e lock -f lock_profile.html <PID>
 
# 采集 Wall-clock Profile
./asprof -d 30 -e wall -f wall_profile.html <PID>

JFR(Java Flight Recorder) 是 JDK 内置的替代方案,从 JDK 11 起免费可用:

# 启动 JFR 记录
jcmd <PID> JFR.start duration=60s filename=recording.jfr
 
# 或通过 JVM 启动参数
java -XX:StartFlightRecording=duration=60s,filename=recording.jfr -jar app.jar

JFR 记录的内容比 async-profiler 更丰富——除了 CPU 和内存 Profile,还包含 GC 事件、线程状态、编译事件、I/O 事件等。可以用 JDK Mission Control 或 jfr 命令行工具分析。

5.2 Go

Go 的内置 Profiling 支持是所有主流语言中最完善的。只需导入 net/http/pprof 包,即可通过 HTTP 端点在线获取 Profile:

import _ "net/http/pprof"
 
func main() {
    go func() {
        http.ListenAndServe("localhost:6060", nil)
    }()
    // ... 业务代码 ...
}
# 采集 CPU Profile(30 秒)
go tool pprof http://localhost:6060/debug/pprof/profile?seconds=30
 
# 采集堆内存 Profile
go tool pprof http://localhost:6060/debug/pprof/heap
 
# 采集 Goroutine 堆栈
go tool pprof http://localhost:6060/debug/pprof/goroutine
 
# 采集 Mutex Contention Profile
go tool pprof http://localhost:6060/debug/pprof/mutex
 
# 在 pprof 交互界面中生成火焰图
(pprof) web    # 在浏览器中打开 SVG 火焰图

5.3 Python

Python 由于 GIL(Global Interpreter Lock)的存在,CPU Profiling 有其特殊性——多线程 Python 程序在 CPU 密集型任务上无法真正并行。

py-spy 是 Python 最推荐的 Profiler——它从进程外部采样(不需要修改 Python 代码),支持生成火焰图:

# 采集 CPU Profile 并生成火焰图
py-spy record -o profile.svg --pid <PID>
 
# 实时查看热点函数(类似 top)
py-spy top --pid <PID>

第 6 章 火焰图分析的常见误区

6.1 误区一:X 轴是时间线

再次强调——火焰图的 X 轴不是时间线。矩形在 X 轴上的位置是按函数名的字母顺序排列的,与时间无关。不要试图从”左边的函数先执行,右边的函数后执行”的角度解读火焰图。

6.2 误区二:只看 CPU Profile

CPU Profile 只能看到”CPU 正在执行”的时间——线程等待锁、等待 I/O、等待调度的时间都不会出现在 CPU Profile 中。如果你的问题是”延迟高但 CPU 不高”,CPU Profile 可能完全看不到问题。此时需要使用 Wall-clock Profile 或 Lock Profile。

选择 Profile 类型的决策

  • CPU 使用率高 → CPU Profile
  • CPU 使用率低 + 延迟高 → Wall-clock Profile
  • 线程 BLOCKED 多 → Lock Profile
  • GC 频繁 → Allocation Profile

6.3 误区三:过度关注”小”热点

如果一个函数只占 2% 的 CPU 时间,即使将它优化为 0%,也只节省了 2% 的 CPU——效果微乎其微。性能优化应该遵循 Amdahl 定律:优化收益取决于被优化部分占总时间的比例。始终优先优化最宽的矩形。

6.4 误区四:忽略采样偏差

采样 Profiling 是统计估算——如果采样数量太少(如只有 100 个样本),结果的置信度很低。一个函数在 100 个样本中被采样到 5 次(5%),其真实的 CPU 占比可能在 1%~9% 之间波动。

经验法则:至少需要 1000 个以上的采样点(约 10 秒的 Profile,100 Hz 采样频率)才能得到统计上可靠的结果。对于持续 Profiling,由于数据是长期累积的,采样数量通常足够。


参考资料

  1. Brendan Gregg (2011). Flame Graphs. https://www.brendangregg.com/flamegraphs.html
  2. Brendan Gregg (2020). BPF Performance Tools. Addison-Wesley, Chapter 2: Flame Graphs.
  3. async-profiler Documentation:https://github.com/async-profiler/async-profiler
  4. Go pprof Blog:https://go.dev/blog/pprof
  5. py-spy:https://github.com/benfred/py-spy
  6. Nitsan Wakart (2016). Why (Most) Sampling Java Profilers Are Fucking Terrible. http://psy-lob-saw.blogspot.com/
  7. Grafana Pyroscope - Flame Graph Guide:https://grafana.com/docs/pyroscope/latest/view-and-analyze-profile-data/