我刚刚在内核上下文中将 CPU 外堆栈与唤醒堆栈相结合，这是我以前从未做过的。这允许一种新型的分析和可视化：尾流外火焰图。在这篇文章中，我将总结 CPU 外时间分析、唤醒时间分析和关闭唤醒时间分析，并以火焰图的形式展示这些示例。为了分析，我将Linux eBPF与我开发和共享的一些新的bcc前端工具一起使用。

CPU 外时间火焰图

CPU 外分析是对所有线程阻塞事件（磁盘 I/O、网络 I/O、锁定、休眠、交换等）及其堆栈跟踪的分析，是对 CPU 分析的补充。我在上一篇文章[1]中介绍了它，我使用Linux eBPF来分析事件，但最后说我必须进一步钻取阻塞的堆栈。

为了说明 CPU 外分析的局限性，当我的系统使用 “tar” 执行文件系统归档时，我创建了以下 CPU 外时间火焰图。命令（来自bcc[2]和FlameGraph[3]）是：

# offcputime -fu 10 > out.offcpu# flamegraph.pl --color=io --countname=us < out.offcpu > offcpu.svg

-u 选项仅显示用户模式线程，不包括内核线程。这是结果（SVG）：

单击以缩放。这将显示被阻止和脱离 CPU 的堆栈跟踪，以及它们被阻止的总持续时间作为其宽度，用于 10 秒配置文件。

单击右下角的“tar”（或单击右上角的“搜索”按钮并输入“tar”即可找到它）。看到那些阻塞堆栈跟踪了吗？8.4秒的总读取文件（通过vfs_read（））和608毫秒的总读取目录（sys_getdents（）等）。棒！这是 CPU 外时间火焰图运行良好的示例。

现在“重置缩放”并查看左侧的“gzip”。它在 sys_read（） 上总共被阻止了 8.8 秒，因此它在文件描述符上被阻止。好的，这有点用，但我们想知道更多：文件描述符是什么，为什么读取总共需要 8.8 秒？

仅靠这些 CPU 外堆栈也无法完全解释许多其他路径：例如，sys_select（） 中的路径。

唤醒时间火焰图

睡眠线程被其他线程唤醒。由于内核对此进行管理，因此我们可以跟踪这些内核唤醒事件，并在唤醒时检查唤醒器线程的堆栈跟踪。

为此，我在密件抄送中添加了一个新工具，唤醒时间。与offcputime一样，它目前正在使用eBPF黑客[4]，直到内核提供堆栈支持。以下唤醒时间火焰图是使用以下方法创建的：

# wakeuptime -fu 10 > out.wakeup# flamegraph.pl --color=waker --countname=us < out.wakeup > wakeup.svg 

为了区分，选择了不同的调色板。这是结果（SVG）：

现在，堆栈跟踪显示唤醒时的唤醒器线程。底部框架是唤醒线程的名称，顶部框架是目标线程的名称。宽度对应于从目标线程阻塞到发送唤醒的时间。这应该是大部分阻塞时间。它可能会排除在唤醒后等待要计划的运行队列所花费的一点时间。

看到顶部的“焦油”了吗？单击它。该路径显示块 I/O 中断事件。这是磁盘 I/O 完成，并唤醒焦油。非常好。这些数字与之前的火焰图不太匹配，因为我在不同时间收集了这些配置文件。

现在在顶部找到“gzip”（顶部是唤醒器的目标），它是最右边的列。单击它。所以gzip被焦油写醒了。这是有道理的，因为存档实际上是：

# tar cf - /usr /var | gzip > /mnt/scratch/backup.tar

所以 gzip 在等待 tar 时被阻塞，而 tar 在等待磁盘 I/O 时被阻塞。完整的图片在 CPU 外和唤醒器火焰图中都有解释。

gzip 也出现在底部，负责唤醒各种其他线程，尽管我认为这更多地与正在处理的挂起中断（handle_irq路径）有关，而不是特定于 gzip。我可能会改进该工具未来版本中的呈现方式。

关断唤醒时间火焰图

让我们将 CPU 外时间火焰图与唤醒时间火焰图结合起来。我使用另一个新工具 offwaketime 完成了此操作，该工具将这些堆栈组合在内核上下文中以提高效率。

# offwaketime -fu 10 > out.offwake# flamegraph.pl --color=chain --countname=us < out.offwake > offwake.svg 

下面是一个示例 （SVG）：

底部堆栈（蓝色）是 CPU 外堆栈。顶部是唤醒器堆栈，颜色为浅绿色，框架顺序相反。为什么？我发现这更合乎逻辑：自上而下显示唤醒路径，自下而上显示 CPU 外阻塞路径。它们在中间相遇，有一个灰色的分隔线。唤醒器堆栈的顶部是唤醒器任务名称。此布局在右侧有注释。

关醒时间火焰图布局

由于我们又回到了将目标线程放在底部（如 CPU 外火焰图），因此找到“tar”作为底部框架。单击它。您可以看到 CPU 外堆栈，然后是唤醒堆栈，从而详细说明了块 I/O 的处理方式。

您还可以找到“gzip”作为底部框架。最上面的框架是“焦油”，唤醒任务。它们的堆栈一起显示。

要阅读这些唤醒时间火焰图，请从底部帧开始查找被阻止的任务，然后继续自下而上阅读。第一个堆栈显示线程阻塞的主要原因（CPU 外），第二个堆栈显示次要原因（唤醒）。最顶部是唤醒器任务名称。

限制和改进

由于我的 eBPF 堆栈黑客的限制，这个 offwaketime 程序将唤醒器帧截断到 10 的深度。此限制将在将来的版本中删除，这些版本还应包括应用程序上下文的用户级堆栈。由于 tar 和 gzip 是简单的程序，我们可以猜测它们在没有用户级堆栈的情况下在做什么。然而，对于大型应用程序，内核上下文本身可能是模棱两可的，我们可能需要用户级堆栈来更好地理解火焰图。

另一个限制是，当唤醒器线程在另一个线程上被阻塞时，一个唤醒堆栈可能不足以解释延迟的来源。此 SVG 中的一个例子是“sshd”，它在内核工作线程“kworker/u16：2”上被阻止（它本身在火焰图中不存在，因为我使用 offwaketime -u 排除了内核线程）。在下一篇文章中，我将展示当我们包含内核线程以及多个唤醒器堆栈时会发生什么。

我还在尝试如何最好地将唤醒器堆栈与 CPU 外堆栈相关联。在我的当前版本中，新唤醒的线程检查一个 eBPF 映射，其中唤醒器堆栈按线程 ID 存储。这工作正常，但可能有改进的余地，尤其是在如何测量和呈现时间方面。

奖金

我在收集示例时不小心发现 cron 正在执行，并看到了这个（原始 SVG）：

这是一个“dumpsystemstats”脚本，收集各种系统统计信息。由于我已经刷新了文件系统缓存，因此许多调用的进程不再缓存，需要从磁盘读取。

火焰图描绘了为什么dumpsystemstats需要很长时间才能执行的全貌。通过将鼠标悬停在原始 SVG 上，我可以读取时间并量化每条路径。解释枚举：

子进程的路径名打开，它们的磁盘 I/O 通过 do_open_execat（） 需要 12 毫秒。触发磁盘 I/O 以加载指令文本的初始进程执行需要 90 毫秒。大部分时间是通过 sys_wait4（） 等待子进程执行，耗时 266 毫秒。显示子进程退出并唤醒其父进程的路径。调用的每个进程名称。猫总共花了 15 毫秒，日期总共花了 29 毫秒，依此类推。

这里没有标记的是右侧的薄塔，sys_newstat（） 需要 11 毫秒。dumpsystemstats 的总运行时间为 386 毫秒，可以解释。

我应该注意，我用于此枚举的顺序可能反映了实际的执行顺序，也可能不反映。我们不知道哪些塔是在哪些其他塔之前执行的，因为x轴是按字母顺序排列的，而不是时间的流逝（这是火焰图）。但是，对于主要用例（提供时间细分），排序并不重要。作为一名性能工程师，这已经确定了许多需要研究的领域，并对其进行了量化。

总结

现在有四种类型的火焰图用于调查线程所花费的时间：

CPU 火焰图：显示 CPU 上的时间（CPU 使用率）。CPU 外时间火焰图：显示线程阻塞的原因。唤醒时间火焰图：显示被唤醒的阻塞线程。唤醒时间火焰图：显示线程阻塞的原因以及唤醒线程的原因。

最后两个是这篇文章中介绍的，以及使用Linux bcc / eBPF实现的版本：wakeuptime和offwaketime。这些工具的当前版本有各种限制，包括仅内核堆栈。随着eBPF和BCC的继续开发，这些限制应该在将来消除。

最后三个可以解决许多涉及阻塞事件和 CPU 外时间的问题，但不是所有问题，因为唤醒堆栈可能不够用。尽管如此，它们仍然是性能分析工具箱的有用补充，作为分析所有阻塞事件的一种方法：I/O、锁、分页、交换、睡眠等。