我们有一个基于 Sled(Rust 编写的嵌入式 KV 数据库)的内部缓存服务,CPU 使用率超过了 100%。通过 OpenResty XRay 的 Rust CPU 剖析,我们把 CPU 消耗追踪到了两条热代码路径——sled::tree::Tree::insertget_inner(后者占了近 40% 的 CPU 时间),并精确定位到具体源码行,全程无需修改代码、无需重新编译。

本教程将逐步演示整个分析过程。下面展示的热代码路径,是 OpenResty XRay 自动分析和解读 Rust 语言级别的 CPU 火焰图得来的。

问题:基于 Sled 的缓存服务 CPU 使用率超过 100%

Sled 是一个由 Rust 编写的嵌入式 KV 数据库,我们的内部缓存服务就构建在它之上。在 top 中可以看到,该进程的 CPU 使用率持续超过 100%。

top 输出显示基于 Rust Sled 的缓存服务进程 CPU 使用率超过 100%

用引导式分析剖析运行中的 Rust 进程

让我们使用 OpenResty XRay 来检查这个未经修改的进程。您可以对它进行实时分析并找出原因,无需改动代码、无需重新编译。这类分析的运行时开销非常低,我们在《OpenResty XRay 对 Rust 应用的性能影响实测》一文中做过量化测量。

打开 OpenResty XRay 的 Web 控制台,确认当前查看的是正确的机器,然后进入 “Guided Analysis”(引导式分析)页面。这里可以看到系统能诊断的不同类型的问题。

OpenResty XRay 引导式分析页面列出可诊断的问题类型,包括 High CPU Usage

选择 “High CPU Usage”,然后选择前面的 Sled 应用,以及消耗超过 100% CPU 资源的那个进程——也就是我们之前在 top 中看到的。

引导式分析的进程选择步骤,显示 CPU 使用率超过 100% 的 Sled 进程

应用类型默认就是 Rust,语言级别这里也只有 “Rust”。最大分析时间保持默认的 300 秒不变,开始分析。系统会持续执行多轮分析;第一轮完成后,对这个例子来说已经足够,停止分析后系统自动生成了一份分析报告。

针对 Rust Sled 进程高 CPU 问题自动生成的引导式分析报告

解读 Rust CPU 火焰图:第一热代码路径

报告展示了占用 CPU 时间最多的第一条 Rust 代码路径。

OpenResty XRay 报告的第一热 Rust 代码路径,顶层为 sled::tree::Tree::insert

第一个函数 sled::tree::Tree::insert 在 Sled 中用于数据插入。

报告标注 sled::tree::Tree::insert 为第一热函数,用于向 Sled 树中插入数据

点击 “More” 查看详情。

点击报告条目上的 More 按钮展开该热路径的详细分析

上面的热代码路径是从下面这张 Rust 级别的 CPU 火焰图中自动推导出来的。

OpenResty XRay 据以自动推导出 insert 热路径的 Rust 级别 CPU 火焰图

下面是报告针对当前问题给出的更详细的解释和建议:Explanation 部分逐一说明了 insert 及其调用链上各个函数,Suggestions 部分则给出了批量写入(sled::Batch)、并发、参数调优等优化方向。

报告的 Explanation 与 Suggestions 部分:解释 insert 调用链各函数并给出批量写入、并发、调参等优化建议

点击这个图标可以放大火焰图。

点击图标放大 Rust CPU 火焰图以查看调用细节

点击 insert 函数的框查看更多详情。

在放大的火焰图中点击 insert 函数框查看其内部调用

在左侧,可以看到 view_for_key 函数占比较大——这是 Sled 库中为给定 key 获取快照视图的函数。

放大后的火焰图显示 view_for_key 函数在 insert 路径中占比较大

在右侧,pagecache 是 Sled 的一个组件,用于按页面管理数据。写入的数据首先存储在 pagecache 的内存页面中,当批次写满时,再通过刷盘持久化。

火焰图右侧显示 Sled 的 pagecache 组件按内存页面管理写入数据

继续点击放大。

继续放大火焰图查看 pagecache 之下的调用

可以看到 Glibc 中的 realloc 函数——libc 的内存分配函数在这个负载下比较热。

火焰图中 Glibc 的 realloc 内存分配函数在该负载下成为热点

从火焰图跳转到 Sled 的源码

在终端上,用 find 命令在 cargo 缓存中找到 Sled 库的源码目录。

在终端用 find 命令在 cargo 缓存中定位 Sled 库源码目录

复制找到的目录,进入 Sled 源码目录。

复制 find 得到的路径并进入 Sled 源码目录

回到火焰图,将鼠标悬停在 insert 函数的绿框上:提示框中会显示这个函数的源文件名。

火焰图提示框显示 insert 函数的源文件路径

提示框中给出的源码行号是 164。

提示框显示 insert 函数对应的源码行号为 164

点击这个图标,复制该函数的源文件路径。

点击图标复制 insert 函数的源文件路径

用您喜欢的编辑器打开源文件,粘贴刚才复制的文件路径(这里用的是 vim)。

在 vim 中打开粘贴的 Sled 源文件路径

OpenResty XRay 的提示跳转到第 164 行。

按提示在编辑器中跳转到 Sled 源码第 164 行

这行代码就在 insert 函数内部。

编辑器中打开的 Sled 源码定位到第 164 行,位于 insert 函数体内

第二热代码路径:get_inner 与 view_for_key

接下来查看第二条代码路径。第二热的代码路径消耗了近 40% 的 CPU 时间。

消耗近 40% CPU 时间的第二热 Rust 代码路径,顶层为 get_inner

顶层的函数调用 get_inner 是 Sled 库内部用于查找数据的函数。

报告标注 get_inner 为第二热路径顶层函数,负责 Sled 的数据查找

get 函数是库对外暴露的取数接口,它在内部调用了 get_inner 函数。

get 是 Sled 对外暴露的取数接口,内部调用 get_inner

点击 “More” 查看详情。

点击 More 展开 get_inner 热路径的详细分析

放大火焰图,查看 get_inner 函数调用的详情。

放大火焰图查看 get_inner 的调用细节

继续放大 get_inner

进一步放大 get_inner 函数在火焰图中的子调用

可以看到,get_inner 函数内的大部分 CPU 时间同样被前面提到的 view_for_key 函数占用。

火焰图显示 get_inner 内大部分 CPU 时间被 view_for_key 函数占用

sled::lru::Lru::accessed 函数在 Rust 的 Sled 库中用于更新 LRU 缓存中条目的访问状态,并返回需要剔除的页面 ID 列表。

火焰图细节显示 get_inner 路径内 sled::lru::Lru::accessed 更新 LRU 缓存状态

全自动 Rust CPU 分析报告

OpenResty XRay 也可以自动监控在线进程,并显示分析报告。

OpenResty XRay 自动监控在线进程并生成分析报告

切换到 “Insights” 页面。

切换到 OpenResty XRay 控制台的 Insights 页面

您可以在 “Insights” 页面中找到以日和周为周期的报告,因此其实不是非得用 “Guided Analysis” 功能。

OpenResty XRay 的 Insights 页面显示自动生成的日报和周报 CPU 分析报告

当然,“Guided Analysis” 对于应用的开发和演示还是很有用的。在 Insights 的日报中,可以看到该进程的 CPU 使用率(min 102%、avg 107%、max 113%),以及按占比排序的最热 Rust 代码路径。

Insights 日报显示 sled-cache 进程 CPU min 102%/avg 107%/max 113% 及按占比排序的最热 Rust 代码路径

除了 CPU 时间,OpenResty XRay 还能以同样非侵入的方式追踪 Rust 程序中的 panic,以及诊断 Rust 应用的高磁盘 I/O 问题

常见问题

如何在不修改代码的情况下剖析 Rust 程序的 CPU 使用?

使用基于动态追踪的非侵入式剖析工具。OpenResty XRay 直接分析正在运行的、未经修改的 Rust 进程:在引导式分析中选中目标进程,它就会对进程采样并生成 Rust 语言级别的 CPU 火焰图——无需重新编译,也无需在目标进程中插桩。

如何找出哪个 Rust 函数消耗的 CPU 最多?

对进程采样得到 Rust 级别的 CPU 火焰图,然后让 OpenResty XRay 从火焰图中自动推导出最热的代码路径——不需要人工解读火焰图。在本文的 Sled 案例中,它报告 sled::tree::Tree::insert 是第一热路径,还直接指出了具体的源码行号(第 164 行)。

我们基于 Sled 的服务为什么会占用超过 100% 的 CPU?

在这个案例中,CPU 时间集中在两条路径上:一是经由 sled::tree::Tree::insert 的数据插入——其中 view_for_key 和 pagecache 写入占大头,Glibc 的 realloc 内存分配函数也比较热;二是经由 get_inner 的数据查找,消耗了近 40% 的 CPU 时间,同样主要花在 view_for_key 上。

关于 OpenResty XRay

OpenResty XRay 是一个动态追踪产品,它可以自动分析运行中的应用,以解决性能问题、行为问题和安全漏洞,并提供可行的建议。在底层实现上,OpenResty XRay 由我们的 Y 语言 驱动,可以在不同环境下支持多种不同的运行时,如 Stap+、eBPF+、GDB 和 ODB。

关于作者

章亦春是开源 OpenResty® 项目创始人兼 OpenResty Inc. 公司 CEO 和创始人。

章亦春(Github ID: agentzh),生于中国江苏,现定居美国湾区。他是中国早期开源技术和文化的倡导者和领军人物,曾供职于多家国际知名的高科技企业,如 Cloudflare、雅虎、阿里巴巴, 是 “边缘计算”、“动态追踪 “和 “机器编程 “的先驱,拥有超过 22 年的编程及 16 年的开源经验。作为拥有超过 4000 万全球域名用户的开源项目的领导者。他基于其 OpenResty® 开源项目打造的高科技企业 OpenResty Inc. 位于美国硅谷中心。其主打的两个产品 OpenResty XRay(利用动态追踪技术的非侵入式的故障剖析和排除工具)和 OpenResty Edge(最适合微服务和分布式流量的全能型网关软件),广受全球众多上市及大型企业青睐。在 OpenResty 以外,章亦春为多个开源项目贡献了累计超过百万行代码,其中包括,Linux 内核、Nginx、LuaJITGDBSystemTapLLVM、Perl 等,并编写过 60 多个开源软件库。

关注我们

如果您喜欢本文,欢迎关注我们 OpenResty Inc. 公司的博客网站 。也欢迎扫码关注我们的微信公众号:

我们的微信公众号

翻译

我们提供了英文版原文和中译版(本文)。我们也欢迎读者提供其他语言的翻译版本,只要是全文翻译不带省略,我们都将会考虑采用,非常感谢!