蚊章汇 - 火焰图
type: channel
link: https://linuxcn.bwsl.wang/tag/%E7%81%AB%E7%84%B0%E5%9B%BE/
items: 使用火焰图分析CPU性能回退问题

使用火焰图分析CPU性能回退问题
type: item
date: 2015-01-15T06:49:00+08:00
description: 你能快速定位CPU性能回退的问题么？ 如果你的工作环境非常复杂且变化快速，那么使用现有的工具是来定位这类问题是很具有挑战性的。当你花掉数周时间把根因找到时，代码已经又变更了好几轮，新的性能问题又冒了出来。幸亏有了CPU火焰图（flame graphs），CPU使用率的问题一般都比较好定位。但要处理性能回退问题，就要在修改前后的火焰图之间，不断切换对比，来找出问题所在，这感觉就是像在太阳系中搜寻冥王星。虽然，这种方法可以解决问题，但我觉得应该会有更好的办法。所以，下面就隆重介绍红/蓝差分火焰图（red/blue differential flame graphs）：上面是一副交互式SVG格式图片（链接）。图中使用了两种颜色来表示状态，红色表示增长，蓝色表示衰减。这张火焰图中各火焰的形状和大小都是和第二次抓取的profile文件对应的CPU火焰图是相同的。（其中，y轴表示栈的深度，x轴表示样本的总数，栈帧的宽度表示了profile文件中该函数出现的比例，最顶层表示正在运行的函数，再往下就是调用它的栈）在下面这个案例展示了，在系统升级后，一个工作载荷的CPU使用率上升了。 下面是对应的CPU火焰图（SVG格式）通常，在标准的火焰图中栈帧和栈塔的颜色是随机选择的。 而在红/蓝差分火焰图中，使用不同的颜色来表示两个profile文件中的差异部分。在第二个profile中deflate\_slow()函数以及它后续调用的函数运行的次数要比前一次更多，所以在上图中这个栈帧被标为了红色。可以看出问题的原因是ZFS的压缩功能被启用了，而在系统升级前这项功能是关闭的。这个例子过于简单，我甚至可以不用差分火焰图也能分析出来。但想象一下，如果是在分析一个微小的性能下降，比如说小于5%，而且代码也更加复杂的时候，问题就为那么好处理了。红/蓝差分火焰图这个事情我已经讨论了好几年了，最终我自己编写了一个我个人认为有价值的实现。它的工作原理是这样的：抓取修改前的堆栈profile1文件抓取修改后的堆栈profile2文件使用profile2来生成火焰图。（这样栈帧的宽度就是以profile2文件为基准的）使用“2 - 1”的差异来对火焰图重新上色。上色的原则是，如果栈帧在profile2中出现出现的次数更多，则标为红色，否则标为蓝色。色彩是根据修改前后的差异来填充的。这样做的目的是，同时使用了修改前后的profile文件进行对比，在进行功能验证测试或者评估代码修改对性能的影响时，会非常有用。新的火焰图是基于修改后的profile文件生成（所以栈帧的宽度仍然显示了当前的CPU消耗），通过颜色的对比，就可以了解到系统性能差异的原因。只有对性能产生直接影响的函数才会标注颜色（比如说，正在运行的函数），它所调用的子函数不会重复标注。生成红/蓝差分火焰图我已经把一个简单的代码实现推送到github上（见火焰图），其中新增了一个程序脚本，difffolded.pl。为了展示工具是如何工作的，用Linux perf\_events 来演示一下操作步骤。（你也可以使用其他profiler）抓取修改前的profile 1文件:# perf record -F 99 -a -g -- sleep 30 # perf script > out.stacks1 一段时间后 (或者程序代码修改后), 抓取profile 2文件:# perf record -F 99 -a -g -- sleep 30 # perf script > out.stacks2 现在将 profile 文件进行折叠（fold）, 再生成差分火焰图:$ git clone --depth 1 http://github.com/brendangregg/FlameGraph $ cd FlameGraph $ ./stackcollapse-perf.pl ../out.stacks1 > out.folded1 $ ./stackcollapse-perf.pl ../out.stacks2 > out.folded2 $ ./difffolded.pl out.folded1 out.folded2 | ./flamegraph.pl > diff2.svg difffolded.p只能对“折叠”过的堆栈profile文件进行操作，折叠操作是由前面的stackcollapse系列脚本完成的。（见链接火焰图）。 脚本共输出3列数据，其中一列代表折叠的调用栈，另两列为修改前后profile文件的统计数据。func_a;func_b;func_c 31 33 [...] 在上面的例子中"funca()->funcb()->func\_c()" 代表调用栈，这个调用栈在profile1文件中共出现了31次，在p…