CPUs执行所有软件,并且是性能分析的常见起点。如果发现工作负载受到CPU限制(即“CPU绑定”),可以进一步使用与CPU和处理器相关的工具进行调查。有无数的采样分析器和度量工具可帮助您了解CPU使用情况。然而(也许令人惊讶的是),BPF追踪在CPU分析的许多领域仍然可以提供更深入的帮助。
学习目标:
■ 理解CPU模式、CPU调度器的行为以及CPU缓存
■ 了解使用BPF进行CPU调度器、使用情况和硬件分析的领域
■ 学习成功分析CPU性能的策略
■ 解决消耗CPU资源的短生命周期进程问题
■ 发现并量化运行队列延迟问题
■ 通过分析栈跟踪和函数计数来确定CPU使用率
■ 确定线程阻塞并离开CPU的原因
■ 通过跟踪系统调用了解系统CPU时间
■ 调查软中断和硬中断引起的CPU消耗
■ 使用bpftrace一行命令以自定义方式探索CPU使用情况
本章从您理解CPU分析所需的背景开始,总结了CPU调度器和CPU缓存的行为。我探讨了BPF可以回答的问题,并提供了一个总体策略。为了避免重复造轮子并指导进一步的分析,我首先总结了传统CPU工具,然后是BPF工具,包括BPF一行命令的列表。本章以可选练习结束。
6.1 Background
本节涵盖了CPU基础知识、BPF的能力以及CPU分析的建议策略。
6.1.1 CPU Fundamentals
CPU模式
CPU和其他资源由运行在特权状态下的内核管理,这种特权状态称为系统模式。用户级应用程序则在用户模式下运行,只能通过内核请求访问资源。这些请求可以是显式的,例如系统调用,也可以是隐式的,比如由内存加载和存储引发的页面错误。内核追踪CPU空闲时间以及在用户模式和系统模式下的CPU时间。各种性能工具显示了这种用户/系统时间分割。
内核通常只在需要fan时运行,由系统调用和中断触发。也有一些例外,例如在后台运行的系统维护线程,消耗CPU资源。例如,在非一致存储访问(NUMA)系统上平衡内存页面的内核例程,可以在没有用户级应用程序显式请求的情况下消耗大量CPU资源(这可以进行调整或禁用)。一些文件系统还有后台例程,例如定期验证数据完整性的校验和。
CPU调度器
内核还负责通过CPU调度器在消费者之间共享CPU资源。主要的消费者是属于进程或内核例程的线程(也称为任务)。其他CPU消费者包括中断例程:这些可以是由运行软件引发的软中断,或由硬件引发的硬中断。
图6-1展示了CPU调度器,描述了线程如何在运行队列中等待执行机会,以及它们如何在不同线程状态之间移动。
这个图表显示了三种线程状态:ON-PROC表示正在CPU上运行的线程,RUNNABLE表示可以运行但正在等待轮到它们执行的线程,SLEEP表示因等待其他事件(包括不可中断等待)而被阻塞的线程。在运行队列上等待的线程按优先级值排序,这些值可以由内核或用户进程设置,以提升更重要任务的性能。虽然调度最初是通过运行队列实现的,并且术语和心理模型仍然用于描述等待任务,但Linux CFS调度器实际上使用未来任务执行的红黑树。
本书使用基于这些线程状态的术语: "on CPU"指代ON-PROC,而 "off CPU"指代所有其他状态,即线程未在CPU上运行时的状态。
线程以两种方式离开CPU:(1)自愿地,如果它们因I/O、锁或休眠而阻塞;或者(2)非自愿地,如果它们超过了分配的CPU时间,并因此被调度程序使其它线程可以运行,或者被优先级更高的线程抢占。当CPU从一个进程或线程切换到另一个时,它会切换地址空间和其他元数据;这称为上下文切换。
图6-1还显示了线程迁移。如果一个线程处于可运行状态并在运行队列中等待,而另一个CPU处于空闲状态,调度程序可以将该线程迁移到空闲CPU的运行队列中,以便更快地执行。作为性能优化,调度程序使用逻辑来避免成本预期超过收益时的迁移,更倾向于在同一CPU上运行忙碌线程,以保持CPU缓存处于热状态。
CPU缓存
尽管图6-1展示了CPU的软件视图(调度程序),图6-2提供了CPU缓存的硬件视图。
根据处理器型号和类型的不同,通常会有多层CPU缓存,它们在大小和延迟上逐级增加。它们从第一级缓存开始,该级别分为独立的指令缓存(I$)和数据缓存(D$),容量较小(几KB)且速度快(纳秒级)。缓存以最后一级缓存(LLC)结束,该级别容量大(几MB)但速度较慢。在具有三级缓存的处理器上,LLC也同时兼作第三级缓存。第一级和第二级缓存通常是每个CPU核心独享的,而第三级缓存通常是在整个插槽(socket)上共享的。内存管理单元(MMU)负责将虚拟地址转换为物理地址,还有其自己的缓存,称为转换后备缓冲器(TLB)。
几十年来,CPU通过提高时钟速度、增加核心数和硬件线程数量来进行扩展。内存带宽和延迟也有所改善,特别是通过增加和扩大CPU缓存的方式。然而,与CPU核心相比,内存性能的提升并没有达到同样的程度。工作负载已经受到内存性能限制(称为“内存限制”),而非CPU核心。
进一步阅读:
这篇简要概述为您提供了一些使用工具之前必备的基本知识。有关CPU软件和硬件的更深入讨论可在《系统性能》的第6章中找到[Gregg 13b]。
6.1.2 BPF Capabilities
传统性能工具提供了各种关于CPU使用情况的见解。例如,它们可以显示进程的CPU利用率、上下文切换率和运行队列长度。这些传统工具在下一节中进行了总结。
BPF跟踪工具可以提供许多额外的详细信息,回答如下问题:
- 新创建的进程是什么?它们的生命周期如何?
- 系统时间为什么高?系统调用是否是罪魁祸首?它们在做什么?
- 每次唤醒后,线程在CPU上的花费时间有多长?
- 线程在运行队列上等待的时间有多长?
- 运行队列的最大长度是多少?
- 运行队列在多个CPU之间是否平衡?
- 线程为什么会自愿离开CPU?离开多长时间?
- 哪些软中断和硬中断正在占用CPU?
- 当其他运行队列上有可用工作时,CPU多久闲置一次?
- 每个应用请求的LLC命中率是多少?
通过在调度器和系统调用事件的跟踪点、调度器内部函数的kprobes、应用程序级函数的uprobes以及定时采样和低级CPU活动的PMC来实现这些问题的回答。这些事件源还可以混合使用:一个BPF程序可以使用uprobes获取应用程序上下文,然后将其与已经instrumented的PMC事件关联起来。例如,这样的程序可以显示每个应用请求的LLC命中率。
BPF提供的指标可以按事件或摘要统计进行检查,并以直方图显示分布。还可以获取堆栈跟踪以显示事件原因。所有这些活动都通过内核中的BPF映射和输出缓冲区进行了优化以提高效率。
事件源
表6-1列出了用于检测CPU使用情况的事件源。
开销
在跟踪调度器事件时,效率尤为重要,因为诸如上下文切换之类的调度器事件可能每秒发生数百万次。虽然BPF程序很短且执行速度快(微秒级),但为每个上下文切换执行它们可能会导致这种微小的开销累积成可测量甚至显著的影响。在最坏的情况下,调度器跟踪可能会给系统增加超过10%的开销。如果没有优化BPF,这种开销将是难以接受的高昂费用。
使用BPF进行调度器跟踪可以用于短期的即时分析,但需要理解会有开销。可以通过测试或实验来量化这种开销,以确定:如果CPU利用率从一秒钟到下一秒钟保持稳定,在运行和不运行BPF工具时的差异是多少?
CPU工具可以通过不对频繁的调度器事件进行仪器化来避免开销。不频繁发生的事件,如进程执行和线程迁移(每秒最多几千次事件),可以带来可忽略的开销。定时采样(分析)还将开销限制在固定的采样率,将开销降至可以忽略的程度。
6.1.3 Strategy
如果你对CPU性能分析还不熟悉,可能不知道从何开始,应该分析哪个目标和使用哪种工具。以下是建议的整体策略,供参考:
1. 在使用分析工具之前,请确保有一个CPU工作负载在运行。检查系统的CPU利用率(例如使用mpstat(1)),确保所有CPU仍然在线(并且没有因某种原因被离线)。
2. 确认工作负载是否受限于CPU性能。
a. 查看系统范围内或单个CPU的高CPU利用率(例如使用mpstat(1))。
b. 查看高运行队列延迟(例如使用BCC的runqlat(1))。像容器这样的软件限制可能会人为地限制进程可用的CPU资源,因此一个应用程序可能在大部分空闲系统上受限于CPU。通过研究运行队列延迟可以识别这种反直觉的情况。
3. 量化CPU使用率,包括系统范围内的百分比利用率以及按进程、CPU模式和CPU ID进行的细分。这可以通过传统工具完成(例如mpstat(1)、top(1))。查找单个进程、模式或CPU的高利用率。
a. 对于高系统时间,通过进程和调用类型频率计数系统调用,并检查参数以查找低效性(例如使用perf(1)、bpftrace的单行命令和BCC的sysstat(8))。
4. 使用分析器对采样堆栈进行采样,可以通过CPU火焰图进行可视化。许多CPU问题可以通过浏览这样的火焰图找到。
5. 针对分析器确定的CPU消耗者,考虑编写自定义工具以显示更多上下文。分析器显示正在运行的函数,但不显示它们操作的参数和对象,这可能需要理解CPU使用情况。例如:
a. 内核模式:如果文件系统在执行对文件的stat()操作时消耗CPU资源,那么它们的文件名是什么?(例如可以使用BCC的statsnoop(8)来确定,或者一般使用BPF工具的tracepoints或kprobes。)
b. 用户模式:如果一个应用程序正在忙于处理请求,这些请求是什么?(如果没有应用程序特定的工具,可以使用USDT或uprobes和BPF工具开发一个。)
6. 测量硬件中断的时间,因为这段时间在基于定时器的分析器中可能不可见(例如BCC的hardirqs(1))。
7. 浏览并执行本章节列出的BPF工具中的工具。
8. 使用PMCs测量每周期的CPU指令数(IPC),以高层次解释CPU的停滞程度(例如使用perf(1))。可以使用更多的PMCs来探索低缓存命中率(例如BCC的llcstat)、温度停滞等等。
接下来的章节会更详细地解释这个过程中涉及的工具。
6.2 Traditional Tools
传统工具(参见表6-2)可以为每个进程(线程)和每个CPU提供CPU利用率指标,可自愿和非自愿上下文切换率,平均运行队列长度以及在运行队列上等待的总时间。分析器可以显示和量化正在运行的软件,而基于PMC的工具可以显示CPU在周期级别上的运行情况。除了解决问题外,传统工具还可以提供线索,指导您进一步使用BPF工具。这些工具根据其来源和测量类型进行了分类:内核统计信息、硬件统计信息和事件跟踪。
以下各节总结了这些工具的关键功能。更多的使用方法和解释,请参考它们的man页面和其他资源,包括《Systems Performance》[Gregg 13b]。
6.2.1 Kernel Statistics
Kernel statistics tools utilize statistical sources within the kernel, often accessible via the /proc interface. One advantage of these tools is that the metrics are typically enabled by the kernel itself, resulting in minimal additional overhead when using them. Moreover, they often permit access by non-root users.
**负载平均数**
uptime(1) 是几个打印系统负载平均数的命令之一:
```bash
$ uptime
00:34:10 up 6:29, 1 user, load average: 20.29, 18.90, 18.70
```
最后三个数字分别是1分钟、5分钟和15分钟的负载平均数。通过比较这些数字,您可以确定在过去约15分钟内负载是增加、减少还是稳定的。这个输出来自一个48-CPU的生产云实例,显示在比较1分钟(20.29)和15分钟(18.70)的负载平均数时,负载略有增加。
负载平均数不是简单的平均值,而是指数衰减移动总和,反映超过1分钟、5分钟和15分钟的时间段。这些汇总的指标显示了系统的需求:处于CPU可运行状态的任务以及处于不可中断等待状态的任务[72]。如果您假设负载平均数显示了CPU负载,您可以将它们除以CPU数量,以查看系统是否运行在CPU饱和状态,这将由超过1.0的比率表示。然而,负载平均数存在一些问题,包括它们包括不可中断任务(阻塞在磁盘I/O和锁中的任务),这对其解释构成了怀疑,因此它们仅在长时间内观察趋势时才真正有用。您必须使用其他工具,比如基于BPF的offcputime(8),来查看负载是基于CPU还是不可中断时间的。有关offcputime(8)的信息,请参见第6.3.9节,有关测量不可中断I/O的更多信息,请参见第14章。
top
top(1) 工具以进程详细信息表格的形式显示最消耗CPU的顶级进程,同时显示系统的头部摘要信息:
这段文字描述的是一个生产实例的输出,显示了仅有一个消耗CPU资源的进程:一个Java进程总共消耗了1681%的CPU,这个数字是在所有CPU上的总和。对于这个拥有48个CPU的系统,输出显示这个Java进程占据了总体CPU容量的35%。这与系统范围内的CPU平均利用率相符,头部摘要显示为34.6%(用户占比33.2%,系统占比1.4%)。
top(1) 尤其有助于识别由意外进程引起的CPU负载问题。常见的软件bug类型会导致线程陷入无限循环,这种情况可以很容易地通过top(1)找到,因为它会显示100% CPU运行的进程。进一步的分析可以使用性能分析器和BPF工具确认进程是否被卡在循环中,而不是在忙于处理工作。
top(1) 默认刷新屏幕,使其像实时仪表板一样工作。这也是一个问题:问题可能会在你截取屏幕截图之前出现和消失。将工具输出和截图添加到工单系统中对追踪性能问题和与他人分享信息至关重要。如pidstat(1)可用于此类目的,打印进程CPU使用的滚动输出;如果已使用监控系统,则可能已经记录了进程的CPU使用情况。
还有其他top(1)的变体,如htop(1),具有更多的自定义选项。不幸的是,许多top(1)变体侧重于视觉增强而非性能指标,使它们看起来更美观,但无法揭示原始top(1)以外的问题。例外包括tiptop(1),它使用PMCs作为数据来源;atop(1),它使用进程事件显示短暂的进程;以及biotop(8)和tcptop(8)工具,它们使用BPF(我开发的)作为数据源。
mpstat
mpstat(1)可以用来检查每个CPU的指标:
由于在这个有48个CPU的系统上,mpstat(1)每秒会打印48行输出,每行总结一个CPU的情况,因此这里显示的输出已被截断。这些输出可以用来识别平衡问题,即一些CPU的利用率很高,而其他CPU则处于空闲状态。CPU的不平衡可能由多种原因引起,比如配置错误的应用程序使用的线程池大小过小,无法充分利用所有CPU;软件限制将进程或容器限制在部分CPU上;以及软件bug。
时间在各个CPU之间被分为多种模式,包括硬中断时间(%irq)和软中断时间(%soft)。可以进一步使用hardirqs(8)和softirqs(8)的BPF工具来进行调查。
6.2.2 Hardware Statistics
硬件也可以作为统计数据的有用来源,特别是在CPU上可用的性能监控计数器(PMC)。PMC在第二章中介绍过。
perf(1)
Linux的perf(1)是一个多功能工具,支持不同的仪器来源和数据展示方式。它首次添加到Linux内核中是在2.6.31版本(2009年),被认为是标准的Linux性能分析器,其代码可以在Linux源代码的 tools/perf 目录下找到。我已经发布了一个详细的使用perf的指南 [73]。它的许多强大功能之一是能够在计数模式下使用PMC:
perf stat命令用-e参数指定要计数的事件。如果没有提供这些参数,它会默认使用基本的PMC集合,或者如果使用了-d参数,则使用扩展的集合,如下所示。输出和使用方式会根据你使用的Linux版本和处理器类型可用的PMC而略有不同。这个例子展示了在Linux 4.15上使用perf(1)。
根据你的处理器类型和perf版本,你可以使用perf list来获取PMC的详细列表。
这个输出显示了你可以在-e参数中使用的别名。例如,你可以在所有CPU上统计这些事件(使用-a,这最近变成了默认行为),并以1000毫秒的间隔打印输出:
这个输出显示了系统范围内这些事件的每秒速率。
有数百种PMC可用,详细记录在处理器供应商的指南中 [Intel 16] [AMD 10]。你可以与特定模型寄存器(MSR)一起使用PMC,以确定CPU内部组件的性能如何,CPU的当前时钟速率,它们的温度和能耗,CPU互连和内存总线的吞吐量等等。
tlbstat
作为PMC的一个示例用途,我开发了tlbstat工具来统计和总结与转换后备缓冲区(TLB)相关的PMC。我的目标是分析Linux内核页表隔离(KPTI)补丁的性能影响,这些补丁是为了解决Spectre漏洞 [74] [75]。
tlbstat打印以下列:
- K_CYCLES:CPU周期(每1000个单位)
- K_INSTR:CPU指令(每1000个单位)
- IPC:每周期指令数
- DTLB_WALKS:数据TLB行走(计数)
- ITLB_WALKS:指令TLB行走(计数)
- K_DTLBCYC:至少一个页面失效处理程序(PMH)活跃时,数据TLB行走的周期数(每1000个单位)
- K_ITLBCYC:至少一个PMH活跃时,指令TLB行走的周期数(每1000个单位)
- DTLB%:数据TLB活跃周期占总周期的比率
- ITLB%:指令TLB活跃周期占总周期的比率
之前显示的输出来自一项压力测试,其中KPTI的开销最大:显示数据TLB占27%的CPU周期,指令TLB占22%的CPU周期。这意味着系统范围内一半的CPU资源被用于内存管理单元服务虚拟到物理地址的转换。如果tlbstat在生产工作负载中显示类似的数字,你可能需要将优化工作集中在TLB上。
6.2.3 Hardware Sampling
perf(1)可以在不同的模式下使用PMC,在这种模式下选择一个计数,在每个计数的频率下,一个PMC事件会导致发送中断到内核,以便它可以捕获事件状态。例如,下面的命令记录了所有CPU上持续10秒钟的L3缓存未命中事件的堆栈跟踪(-g),其中“-e ...”用于指定事件:
```
perf record -a -g -e ... -- sleep 10
```
这里的`sleep 10`是一个用来设置持续时间的虚拟命令。
这个输出展示了一个单独的堆栈跟踪样本。堆栈按从子到父的顺序列出,本例中显示了导致L3缓存未命中事件的内核函数。
请注意,尽可能使用支持精确事件基础抽样(PEBS)的PMC来最小化中断偏移问题。
PMC硬件抽样也可以触发BPF程序。例如,可以在内核上下文中通过BPF对抽样的堆栈跟踪进行频率计数,而不是通过perf缓冲区将所有样本的堆栈跟踪转储到用户空间,以提高效率。
6.2.4 Timed Sampling
许多性能分析器支持基于定时器的抽样(在定时间隔内捕获指令指针或堆栈跟踪)。这些分析器提供了一个粗略的、成本较低的视图,用于查看哪些软件消耗了CPU资源。有不同类型的分析器,一些仅在用户模式下运行,而另一些在内核模式下也能操作。通常更倾向于使用内核模式分析器,因为它们可以捕获内核和用户级堆栈,提供更完整的视图。
perf
perf(1) 是一个基于内核的性能分析器,支持通过软件事件或PMC进行定时抽样:它默认使用目前最精确的技术。在这个例子中,它以每秒每CPU 99次的频率(即99 Hertz)在30秒内捕获所有CPU上的堆栈:
# perf record -F 99 -a -g -- sleep 30
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.661 MB perf.data (2890 samples) ]
选择99 Hertz 而不是100 Hertz,是为了避免与其他软件例程的同步采样,否则会使样本产生偏差。这在第18章中有更详细的解释。选择大约100而不是比如10或10000,是为了在详细程度和开销之间取得平衡:如果太低,就无法得到足够的样本来完整地查看执行过程,包括大和小的代码路径;如果太高,样本的开销会影响性能和结果的准确性。
当运行这个perf(1)命令时,它会将样本写入一个perf.data文件:通过使用内核缓冲区和最优化的文件系统写入次数来进行优化。输出告诉我们它只需要唤醒一次来写入这些数据。
可以使用perf report来汇总输出,或者使用perf script来逐个样本进行转储。例如:
perf report的摘要显示了从根到子函数的函数树。(顺序可以反转,这在早期版本中是默认的。)不幸的是,从这个输出样本中很难得出什么确凿的结论——完整的输出有六千行。而perf script的完整输出,每个事件都进行了转储,有超过六万行。在更繁忙的系统上,这些分析文件可能会轻松达到这个大小的10倍。在这种情况下的解决方案是将堆栈样本可视化为火焰图。
CPU火焰图
火焰图在第2章引入,能够可视化堆栈跟踪。它们非常适合CPU分析,现在已经广泛用于CPU分析。
图6-3中的火焰图总结了前一节捕获的相同的分析数据。
当这些数据被呈现为火焰图时,很容易看出名为iperf的进程正在消耗所有的CPU资源,以及具体是如何消耗的:通过sock_sendmsg()函数,导致两个高频CPU函数,即copy_user_enhanced_fast_string()和move_freepages_block(),显示为两个高原。在右侧是一个向后延伸到TCP接收路径的塔形结构;这表示iperf正在执行一个回环测试。
以下是使用perf(1)创建CPU火焰图的步骤,以便在49赫兹的频率下对堆栈进行30秒的采样,以及我的原始火焰图实现:
```bash
# git clone https://github.com/brendangregg/FlameGraph
# cd FlameGraph
# perf record -F 49 -ag -- sleep 30
# perf script --header | ./stackcollapse-perf.pl | ./flamegraph.pl > flame1.svg
```
stackcollapse-perf.pl程序将perf script的输出转换为flamegraph.pl程序可读的标准格式。FlameGraph仓库中还有其他分析器的转换工具。flamegraph.pl程序将生成一个包含嵌入式JavaScript以实现交互性的SVG格式的火焰图文件。flamegraph.pl支持许多选项进行自定义:运行`flamegraph.pl --help`获取详细信息。
我建议保存`perf script --header`的输出以备后续分析。Netflix开发了一个新的火焰图实现,使用d3和一个额外的工具FlameScope,可以读取perf script的输出并将其可视化为亚秒偏移热图,以便选择时间范围查看火焰图。[76] [77]
Internals
当perf(1)进行定时采样时,它会尝试使用基于PMC的硬件CPU周期溢出事件触发非可屏蔽中断(NMI)进行采样。然而,在云环境中,许多实例类型未启用PMC。这可以在dmesg(1)中看到:
```bash
# dmesg | grep PMU
[ 2.827349] Performance Events: unsupported p6 CPU model 85 no PMU driver,
software events only.
```
在这些系统上,perf(1)会回退到基于hrtimer的软件中断。当使用-v参数运行perf时可以看到这一点:
```bash
# perf record -F 99 -a -v
Warning:
The cycles event is not supported, trying to fall back to cpu-clock-ticks
[...]
```
这种软件中断通常是足够的,但请注意,它无法中断一些内核代码路径,如禁用IRQ的路径(包括调度和硬件事件中的某些代码路径)。因此,生成的性能分析数据会缺少这些代码路径的样本。
关于PMC的更多信息,请参阅第2章中的第2.12节。
6.2.5 Event Statistics and Tracing
工具可以追踪事件,也可用于CPU分析。传统的Linux工具包括perf(1)和Ftrace。这些工具不仅可以追踪事件并保存每个事件的详细信息,还可以在内核上下文中计算事件次数。
perf
perf(1)可以对tracepoints、kprobes、uprobes以及最近新增的USDT probes进行仪器化。这些功能能够提供CPU资源消耗的逻辑上下文。
例如,考虑一个系统中整体CPU利用率很高的问题,但在top(1)中找不到明显的负责进程。问题可能是短暂的进程。为了验证这个假设,可以使用perf script对系统范围内的sched_process_exec tracepoint进行计数,以展示exec()家族系统调用的速率:
输出显示,执行的进程包括名称为make、sh和cmake的进程,这让我怀疑是软件构建造成的问题。短暂的进程是一个如此常见的问题,以至于专门有一个用于此的BPF工具:execsnoop(8)。输出中的字段包括:进程名称、PID、[CPU]、时间戳(秒)、事件名称和事件参数。
perf(1)有一个专门用于CPU调度器分析的特殊子命令,称为perf sched。它使用转储和后处理的方法来分析调度器行为,并提供各种报告,可以显示每次唤醒的CPU运行时间、平均和最大调度延迟,以及ASCII可视化,展示每个CPU上的线程执行情况和迁移。以下是一些示例输出:
输出内容详尽,将所有调度器上下文切换事件以线条摘要显示,包括睡眠时间(等待时间)、调度延迟(sch延迟)和CPU运行时间,所有时间单位均为毫秒。此输出显示了一个睡眠了1秒的sleep(1)命令,以及一个运行了9.9毫秒并睡眠了19.9毫秒的cc1进程。
perf sched子命令可以帮助解决多种类型的调度器问题,包括与内核调度器实现相关的问题(内核调度器是一个复杂的代码,需要平衡多种需求)。然而,转储和后处理的风格成本高昂:例如,这个示例在一个八核系统上记录了1秒钟的调度器事件,生成了一个1.9兆字节的perf.data文件。在一个更大、更繁忙的系统上,并且持续时间更长的情况下,该文件可能会达到数百兆字节,这可能会导致生成文件所需的CPU时间增加,同时文件系统I/O写入磁盘也会成为问题。
为了理解如此多的调度器事件,通常会对perf(1)的输出进行可视化。perf(1)还有一个用于自身可视化的timechart子命令。
在可能的情况下,我建议使用BPF而不是perf sched,因为它可以进行内核摘要,回答类似的问题并生成结果(例如,runqlat(8)和runqlen(8)工具,在第6.3.3节和第6.3.4节中有详细介绍)。
Ftrace
Ftrace是由Steven Rostedt开发的一组不同的跟踪功能,首次添加到Linux 2.6.27(2008年)。与perf(1)类似,它也可以通过跟踪点和其他事件来探索CPU使用的上下文。
例如,我的perf-tools集合[78]主要使用Ftrace进行仪器化,包括funccount(8)用于函数计数。这个示例通过匹配以"ext"开头的文件系统调用来统计ext4文件系统的调用次数:
这里的输出已被截断,仅显示了最常用的函数。最常见的是ext4_getattr(),在跟踪过程中调用了7285次。
函数调用会消耗CPU资源,它们的名称通常可以提供执行工作负载的线索。在函数名称含糊不清的情况下,通常可以在网上找到函数的源代码,并阅读以理解其功能。这在Linux内核函数中尤为真实,因为它们是开源的。
Ftrace具有许多有用的预定义能力,最近的增强功能添加了直方图和更多的频率计数("hist triggers")。与BPF不同,Ftrace并非完全可编程,因此不能用于获取数据并以完全自定义的方式展示它们。
6.3 BPF Tools
本节介绍了用于CPU性能分析和故障排除的BPF工具。它们显示在图6-4中,并列在表6-3中。
这些工具要么来自于第4章和第5章中介绍的BCC和bpftrace存储库,要么是为本书而创建的。有些工具同时出现在BCC和bpftrace中。表6-3列出了本节涵盖的工具的来源(BT是bpftrace的简称)。
关于来自BCC和bpftrace的工具,请参阅它们的存储库获取完整和更新的工具选项和功能列表。以下是一些最重要功能的摘要。
6.3.1 execsnoop
execsnoop(8)3是一个BCC和bpftrace工具,用于跟踪系统范围内新进程的执行。它可以找出消耗CPU资源的短生命周期进程的问题,并且还可以用于调试软件执行,包括应用程序的启动脚本。
以下是BCC版本的示例输出:
这个工具捕获了用户使用SSH登录系统的时刻,以及启动的进程,包括sshd(8)、groups(1)和mesg(1)。它还显示了系统活动记录器sar将指标写入日志的进程,包括sa1(8)和sadc(8)。
使用execsnoop(8)查找消耗资源的短生命周期进程的高频率。它们很难被发现,因为它们可能非常短暂,在像top(1)或监控代理这样的工具能够检测到它们之前就消失了。第1章展示了一个例子,其中一个启动脚本在循环中未能启动应用程序,影响了系统的性能。使用execsnoop(8)很容易发现了这个问题。execsnoop(8)已经被用于调试许多生产问题:来自后台作业的干扰、应用程序启动缓慢或失败、容器启动缓慢或失败等等。
execsnoop(8)跟踪execve(2)系统调用(常用的exec(2)变体),并显示execve(2)的参数和返回值的详细信息。这可以捕获遵循fork(2)/clone(2)->exec(2)序列的新进程,以及重新执行自身的进程。一些应用程序在创建工作进程池时,可能仅使用fork(2)或clone(2)而不调用exec(2)。这些不会出现在execsnoop(8)的输出中,因为它们没有调用execve(2)。这种情况应该是不常见的:应用程序应该创建工作线程池,而不是进程池。
由于进程执行的速率预计相对较低(<1000/秒),因此这个工具的开销预计可以忽略不计。
BCC
BCC版本支持多种选项,包括:
- -x:包括失败的exec()操作
- -n pattern:仅打印包含特定模式的命令
- -l pattern:仅打印其参数包含特定模式的命令
- --max-args args:指定要打印的最大参数数目(默认为20个)
bpftrace
以下是bpftrace版本的execsnoop(8)代码,总结了其核心功能。这个版本打印基本列,不支持选项:
BEGIN打印标题。为了捕获exec()事件,通过跟踪点syscalls:sys_enter_execve来实现,打印自程序开始运行以来的时间、进程ID,以及命令名和参数。它使用了join()函数来处理来自跟踪点args->argv字段的参数,以便将命令名和参数打印在同一行上。
未来版本的bpftrace可能会改变join()的行为,使其返回一个字符串而不是直接打印出来,这会使得这段代码变成:
```
tracepoint:syscalls:sys_enter_execve
{
printf("%-10u %-5d %s\n", elapsed / 1000000, pid, join(args->argv));
}
```
BCC版本同时对execve()系统调用的进入和返回进行了仪器化,以便打印返回值。bpftrace程序也可以轻松增强以实现这一点。
请参阅第13章中的类似工具threadsnoop(8),它跟踪线程的创建而不是进程的执行。
6.3.2 exitsnoop
exitsnoop(8)是一个BCC工具,用于跟踪进程退出的时间,显示它们的运行时间和退出原因。运行时间指的是进程从创建到终止的时间,包括在CPU上和CPU外的时间。与execsnoop(8)类似,exitsnoop(8)可以帮助调试短暂进程的问题,提供不同的信息来帮助理解这种工作负载。例如:
这个输出显示了许多短命进程的退出,如cmake(1)、sh(1)和make(1):正在运行软件构建。一个sleep(1)进程在1.00秒后成功退出(退出码为0),另一个sleep(1)进程由于接收到KILL信号在7.31秒后退出。还捕获到一个名为"DOM Worker"的线程在221.25秒后退出。
该工具通过仪器化sched:sched_process_exit跟踪点及其参数来工作,同时使用bpf_get_current_task()函数从任务结构中读取启动时间(这是一个不稳定的接口细节)。由于这个跟踪点的触发应该很少,因此该工具的开销应该可以忽略不计。
命令行用法:
```
exitsnoop [options]
```
选项包括:
- `-p PID`:仅测量指定PID的进程
- `-t`:包括时间戳
- `-x`:只跟踪失败(非零退出原因)
目前还没有bpftrace版本的exitsnoop(8),但对于正在学习bpftrace编程的人来说,创建这样一个版本可能是一个有用的练习。
6.3.3 runqlat
runqlat(8)是一个BCC和bpftrace工具,用于测量CPU调度延迟,通常称为运行队列延迟(即使不再使用运行队列实现)。它有助于识别和量化CPU饱和问题,即CPU资源需求超过其服务能力的情况。runqlat(8)测量的指标是每个线程(任务)等待在CPU上运行的时间。
以下是在一个使用48个CPU的生产API实例上运行runqlat(8),系统整体CPU利用率约为42%。runqlat(8)的参数为"10 1",表示设置一个10秒的间隔,并且只输出一次:
这个输出显示,大部分时间线程等待时间少于15微秒,在直方图中的模式介于两到15微秒之间。这相对来说很快——是一个健康系统的例子,并且对于运行在42% CPU利用率的系统来说是符合预期的。偶尔在这个例子中,运行队列的延迟会高达八到十六毫秒,但这些属于离群值。
runqlat(8)通过对调度器唤醒和上下文切换事件进行仪表化来工作,以确定从唤醒到运行的时间。这些事件在繁忙的生产系统中可能非常频繁,每秒超过一百万次。即使BPF已经进行了优化,在这些速率下,每个事件增加一微秒的开销也可能导致明显的额外负担。请谨慎使用。
错误配置的构建
这里是另一个比较的例子。这次是一个拥有36个CPU的构建服务器正在进行软件构建,由于错误地将并行作业数设置为72个,导致CPU过载:
现在分布呈三峰形,最慢的模式集中在8到16毫秒的区间。这显示线程有显著的等待时间。
这个特定问题可以通过其他工具和指标轻松识别。例如,sar(1)可以显示CPU利用率(-u)和运行队列指标(-q):
这个sar(1)的输出显示CPU空闲率为0%,平均运行队列大小为72(包括正在运行和可运行的任务)—超过了36个可用的CPU。
第15章包含了一个runqlat(8)的示例,展示了每个容器的延迟情况。
BCC
BCC版本的命令行用法:
runqlat [options] [interval [count]]
选项包括:
- -m:以毫秒打印输出
- -P:按进程ID打印直方图
- --pidnss:按PID命名空间打印直方图
- -p PID:仅跟踪指定的进程ID
- -T:在输出中包含时间戳
-T 选项对于在每个间隔输出中加入时间标记非常有用。例如,runqlat -T 1 可以生成每秒带时间戳的输出。
bpftrace
以下是bpftrace版本runqlat(8)的代码,概述了其核心功能。这个版本不支持选项。
该程序在 sched_wakeup 和 sched_wakeup_new 的跟踪点上记录一个时间戳,以 args->pid 作为键,该键表示内核线程ID。
在 sched_switch 动作中,如果前一个状态仍为可运行状态(TASK_RUNNING),则在 args->prev_pid 上存储一个时间戳。这处理了一种被动的上下文切换情况,在线程离开 CPU 时,它会立即返回到运行队列。该动作还会检查下一个可运行进程是否存储了时间戳,如果是,则计算时间差并将其存储在 @usecs 直方图中。
由于使用了 TASK_RUNNING,因此读取了 linux/sched.h 头文件(#include),以便其定义可用。
BCC 版本可以按 PID 进行分解,而此 bpftrace 版本可以通过向 @usecs 映射添加 pid 键来轻松实现相同的修改。在 BCC 中的另一个增强功能是跳过对 PID 为 0 的记录,以排除调度内核空闲线程的延迟。同样,该程序也可以轻松修改以执行相同的操作。
6.3.4 runqlen
runqlen(8) 是一个 BCC 和 bpftrace 工具,用于对 CPU 运行队列的长度进行采样,计算等待执行的任务数量,并将其呈现为线性直方图。这可以用来进一步分析运行队列延迟问题,或作为更便宜的近似方法。
以下展示了在一个具有48个CPU的生产API实例上运行的 BCC 的 runqlet(8)。该实例的系统整体CPU利用率约为42%(与之前显示的 runqlat(8) 相同)。runqlen(8) 的参数为 "10 1",表示设置10秒的采样间隔,并且只输出一次:
这显示大部分时间运行队列长度为零,这意味着线程无需等待执行。
我将运行队列长度描述为次要的性能指标,而运行队列延迟则是主要指标。与长度不同,延迟直接且成比例地影响性能。想象一下在杂货店排队结账。对你来说,更重要的是排队的长度还是实际等待的时间?运行队列延迟 (runqlat(8)) 更为重要。那么为什么要使用 runqlen(8) 呢?
首先,runqlen(8) 可用于进一步分析在 runqlat(8) 中发现的问题,并解释延迟为何变高。其次,runqlen(8) 使用99赫兹的定时采样,而 runqlat(8) 则跟踪调度器事件。与 runqlat(8) 的调度器跟踪相比,这种定时采样的开销微乎其微。对于全天候监控,可能更倾向于首先使用 runqlen(8) 来识别问题(因为成本更低),然后临时使用 runqlat(8) 来量化延迟。
四个线程,一个CPU
在这个示例中,有四个繁忙线程的CPU工作负载被绑定到CPU 0。执行了带有 -C 选项的 runqlen(8),以显示每个CPU的直方图:
CPU 0 上的运行队列长度为三:一个线程在CPU上运行,另外三个线程在等待。这种每个CPU的输出对于检查调度器的平衡非常有用。
BCC
BCC 版本的命令行用法:
runqlen [options] [interval [count]]
选项包括:
- -C:按CPU打印直方图
- -O:打印运行队列占用情况
- -T:在输出中包含时间戳
运行队列占用是一个单独的指标,显示了有线程等待的时间百分比。在需要单一指标进行监控、报警和绘图时,这有时是非常有用的。
bpftrace
以下是 bpftrace 版本的 runqlen(8) 代码,概述了其核心功能。此版本不支持选项。
该程序需要引用 cfs_rq 结构的 nr_running 成员,但是标准内核头文件中并未提供这个结构。因此,程序首先定义了一个 cfs_rq_partial 结构体,足以获取所需的成员。一旦 BTF 可用(详见第2章),这种解决方法可能就不再需要。
主要事件是 profile:hz:99 探针,它以99赫兹在所有CPU上对运行队列长度进行采样。长度是通过从当前任务结构体到其所在运行队列的路径来获取,然后读取运行队列的长度。如果内核源代码发生变化,可能需要调整这些结构体和成员名称。
您可以通过向 @runqlen 添加一个 cpu 键来让这个 bpftrace 版本按CPU进行分解。
6.3.5 runqslower
runqslower(8)12 是一个BCC工具,列出超过可配置阈值的运行队列延迟实例,并显示遭受延迟的进程及其持续时间。以下示例来自一个拥有48个CPU的生产API实例,当前系统范围内CPU利用率为45%:
这段输出显示,在13秒的时间内,出现了10次运行队列延迟超过默认的阈值10000微秒(10毫秒)。对于一个有55%空闲CPU余地的服务器来说,这可能看起来令人惊讶,但这是一个繁忙的多线程应用程序,直到调度程序能够将线程迁移到空闲的CPU上,某些运行队列不平衡是可能的。此工具可以确认受影响的应用程序。
当前,此工具通过使用 kprobes 监视内核函数 ttwu_do_wakeup()、wake_up_new_task() 和 finish_task_switch() 实现。将来的版本应该转向使用调度器的 tracepoints,采用类似于之前 bpftrace 版本 runqlat(8) 的代码。由于 kprobes 的成本,即使 runqslower(8) 没有打印任何输出,它在忙碌系统上的开销与 runqlat(8) 相似,可能会导致显著的性能开销。
命令行用法:
runqslower [选项] [min_us]
选项包括:
- -p PID:仅测量该进程
默认阈值为10000微秒。
6.3.6 cpudist
cpudist(8)13 是一个BCC工具,用于显示每个线程唤醒的CPU时间分布情况。这可用于帮助表征CPU工作负载,提供后续调优和设计决策的详细信息。例如,来自一个拥有48个CPU的生产实例:
这个输出显示,生产应用通常只在CPU上花费很短的时间:从0到127微秒不等。
这是一个CPU密集型的工作负载,比可用CPU更多的繁忙线程,并且使用毫秒级的直方图(使用选项 -m):
现在出现了一个持续时间从4到15毫秒的CPU模式:这很可能是线程耗尽其调度器时间片,并遇到非自愿的上下文切换。
这个工具被用来帮助理解 Netflix 生产环境中的一次变更,一款机器学习应用程序开始运行快了三倍。使用 perf(1) 命令显示上下文切换率下降了,而 cpudist(8) 被用来解释这个变化的影响:应用程序现在通常在两到四毫秒之间运行,然后才会遇到上下文切换;而之前,它在被中断上下文切换前只能运行零到三微秒。
cpudist(8) 通过跟踪调度器上下文切换事件工作,这在繁忙的生产负载上可能非常频繁(每秒超过一百万次事件)。与 runqlat(8) 类似,这个工具的开销可能很大,因此请谨慎使用。
命令行用法:
cpudist [选项] [间隔 [次数]]
选项包括:
- -m:以毫秒打印输出(默认为微秒)
- -O:显示非CPU时间而不是CPU时间
- -P:按进程打印直方图
- -p PID:仅测量该进程
目前还没有 cpudist(8) 的 bpftrace 版本。我已经拒绝创建一个,并将其作为本章末尾的一个可选练习添加进去。
6.3.7 cpufreq
cpufreq(8)对CPU频率进行采样,并将其显示为系统范围的直方图,同时包括每个进程的名称直方图。这仅适用于改变频率的CPU调频管理器,如powersave,可用于确定应用程序运行的时钟速度。例如:
这显示,整个系统中,CPU频率通常在1200到1400 MHz范围内,因此这是一个大部分时间处于空闲状态的系统。Java进程遇到的频率类似,只有少数样本(在采样时有18个)达到了3.0到3.2 GHz范围。这个应用程序主要进行磁盘I/O操作,导致CPU进入节能状态。Python3进程通常以全速运行。
该工具通过跟踪频率变化的跟踪点来确定每个CPU的速度,然后以100赫兹的频率对其进行采样。性能开销应该很低,几乎可以忽略不计。前述输出来自一个使用powersave调频管理器设置的系统,如在/sys/devices/system/cpu/cpufreq/.../scaling_governor中设置的那样。当系统设置为performance调频管理器时,此工具将不显示任何内容,因为不再有频率变化需要进行监控:CPU被固定在最高频率。
这是我刚发现的一个生产工作负载的摘录:
显示生产应用程序nginx经常以较低的CPU时钟频率运行。CPU的调频管理器未被设置为performance,而是默认为powersave模式。
cpufreq(8)的源代码来自于:
频率变化是通过power:cpu_frequency跟踪点进行追踪,并保存在一个@curfreq的BPF映射中,按CPU分类,以便在采样时进行后续查找。直方图跟踪的频率范围从0到5000 MHz,步长为200 MHz;如果需要,可以在工具中调整这些参数。
6.3.8 profile
profile(8)是一个BCC工具,它以定时间隔对堆栈跟踪进行采样,并报告堆栈跟踪的频率计数。这是BCC中最有用的工具之一,用于理解CPU消耗,因为它总结了几乎所有消耗CPU资源的代码路径。(有关更多CPU消费者,请参阅第6.3.14节中的hardirqs(8)工具。)它还可以以相对可以忽略不计的开销使用,因为事件率被固定为采样率,可以进行调整。
默认情况下,该工具在所有CPU上以49赫兹采样用户和内核堆栈跟踪。可以使用选项进行自定义,并且在输出开始时会打印设置。例如:
输出显示堆栈跟踪列表,格式为函数列表,后跟破折号("-"),括号内是进程名称和PID,最后是该堆栈跟踪的计数。堆栈跟踪按照频率计数的顺序从少到多进行打印。
在本例中,完整输出共有17,254行,并在此处进行了截断,只展示了首尾两个堆栈跟踪。最频繁的堆栈跟踪显示了通过vfs_write()并以get_page_from_freelist()结束的路径,在采样过程中出现了2673次。
CPU火焰图
火焰图是堆栈跟踪的可视化,可以帮助您快速理解profile(8)的输出。这些图表在第2章中介绍过。
为支持火焰图,profile(8)可以使用-f选项生成折叠格式的输出:堆栈跟踪打印在一行上,函数之间用分号分隔。例如,将30秒的profile写入out.stacks01文件并包括内核注释(-a):
这里仅展示了最后三行。此输出可以输入到我原始的火焰图软件中生成CPU火焰图:
```bash
$ git clone https://github.com/brendangregg/FlameGraph
$ cd FlameGraph
$ ./flamegraph.pl --color=java < ../out.stacks01 > out.svg
```
flamegraph.pl支持不同的颜色调色板。此处使用的java调色板利用了内核注释("_[k]")选择颜色色调。生成的SVG显示在图6-5中。
这个火焰图显示,最热门的代码路径以get_page_from_freelist_()和__free_pages_ok_()结尾,这些是最宽的塔楼,宽度与它们在profile中的频率成比例。在浏览器中,这个SVG支持点击缩放,以便展开窄塔楼并阅读其函数。
profile(8)与其他CPU分析器的不同之处在于,它在内核空间中计算频率计数以提高效率。其他基于内核的分析器,如perf(1),会将每个采样的堆栈跟踪发送到用户空间,然后在那里进行后处理以生成摘要。这可能会消耗大量CPU资源,并且根据调用方式,还可能涉及文件系统和磁盘I/O来记录样本。而profile(8)避免了这些开销。
命令行用法:
profile [选项] [-F 频率]
可用选项包括:
- -U:仅包括用户级堆栈
- -K:仅包括内核级堆栈
- -a:包括帧注释(例如内核帧的 "_[k]")
- -d:在内核/用户堆栈之间包括分隔符
- -f:以折叠格式提供输出
- -p PID:仅对该进程进行分析
bpftrace
profile(8)的核心功能可以作为bpftrace的一行命令实现:
bpftrace -e 'profile:hz:49 /pid/ { @samples[ustack, kstack, comm] = count(); }'
这会使用用户堆栈、内核堆栈和进程名称作为键来进行频率统计。包含对pid的过滤以确保它非零:这排除了CPU空闲线程的堆栈。这一行命令可以根据需要进行定制。
6.3.9 offcputime
offcputime(8)16是一个BCC和bpftrace工具,用于总结线程在阻塞和脱离CPU状态下花费的时间,并显示堆栈跟踪来解释原因。对于CPU分析,该工具解释了为什么线程未在CPU上运行。它是profile(8)的补充;它们共同展示了系统中线程的整体时间:profile(8)显示在CPU上的时间,而offcputime(8)显示脱离CPU的时间。
以下示例展示了来自BCC的offcputime(8),追踪五秒钟的情况:
输出已被截断,仅显示了从数百个打印信息中选取的三个堆栈。每个堆栈显示内核帧(如果存在),然后是用户级帧,接着是进程名称和PID,最后是此组合观察到的总时间,以微秒计。第一个堆栈显示iperf(1)在sk_stream_wait_memory()中因内存阻塞,总计5毫秒。第二个堆栈显示iperf(1)通过sk_wait_data()等待套接字上的数据,总计1.02秒。最后一个堆栈显示offcputime(8)工具本身在select(2)系统调用中等待了5.00秒;这很可能是因为命令行上指定的5秒超时。
需要注意的是,在所有三个堆栈中,用户级堆栈跟踪都是不完整的。这是因为它们以libc结束,并且此版本不支持帧指针。这在offcputime(8)中更为明显,因为阻塞堆栈经常通过系统库如libc或libpthread。请参阅第2章、第12章、第13章和第18章中有关堆栈跟踪问题及解决方案的讨论,特别是第13.2.9节。
offcputime(8)已被用于发现各种生产问题,包括发现在锁获取中意外阻塞的时间和相关的堆栈跟踪。
offcputime(8)的工作原理是通过检测上下文切换并记录线程从离开CPU到返回的时间,同时记录堆栈跟踪。为了效率,这些时间和堆栈跟踪在内核上下文中进行频率统计。然而,上下文切换事件可能非常频繁,而此工具的开销对于繁忙的生产工作负载可能会变得显著(例如,>10%)。最好仅在短时间内运行此工具,以最小化对生产环境的影响。
Off-CPU Time Flame Graphs
与profile(8)类似,offcputime(8)的输出可能非常冗长,因此您可能更喜欢将其作为火焰图来查看,尽管这种火焰图与第二章介绍的类型不同。offcputime(8)可以被视为一种“离CPU时间”火焰图,而不是CPU火焰图。
以下示例创建了一个针对内核堆栈的5秒离CPU时间火焰图:
```bash
# offcputime -fKu 5 > out.offcputime01.txt
$ flamegraph.pl --hash --bgcolors=blue --title="Off-CPU Time Flame Graph" < out.offcputime01.txt > out.offcputime01.svg
```
我使用了`--bgcolors`来将背景色更改为蓝色,以便与CPU火焰图进行视觉区分。您也可以使用`--colors`来更改帧的颜色,我已经发布了许多使用蓝色调色板的离CPU火焰图。
这些命令生成了图6-6中显示的火焰图。
这个火焰图主要显示了正在休眠等待工作的线程。您可以点击应用程序的名称来放大查看感兴趣的部分。有关离CPU时间火焰图的更多信息,包括具有完整用户堆栈跟踪的示例,请参阅第12章、第13章和第14章。
BCC
命令行用法:
offcputime [选项] [持续时间]
选项包括:
- -f:以折叠格式打印输出
- -p PID:仅测量指定进程
- -u:仅跟踪用户线程
- -k:仅跟踪内核线程
- -U:仅显示用户堆栈跟踪
- -K:仅显示内核堆栈跟踪
这些选项中的一些可以通过筛选仅记录一个PID或堆栈类型来帮助减少开销。
bpftrace
以下是bpftrace版本的offcputime(8)代码,概述了其核心功能。此版本支持可选的PID参数用于指定要跟踪的目标进程:
这个程序在一个 `finish_task_switch()` 的 kprobe 中记录了线程离开 CPU 的时间戳,并且还对开始运行的线程的离 CPU 时间进行了累加。
6.3.10 syscount
syscount(8)是一个BCC和bpftrace工具,用于统计系统范围内的系统调用。它被包含在本章中,因为它可以作为调查高系统CPU时间案例的起点。
以下输出显示了来自BCC的syscount(8),以每秒系统调用率(-i 1)打印在生产实例上的情况:
这个输出每秒显示了前10个系统调用及其时间戳。最频繁的系统调用是 futex(2),达到每秒超过150,000次的调用。要进一步探索每个系统调用,可以查阅各自的man手册获取文档,并使用更多的BPF工具来跟踪和检查它们的参数(例如,BCC 的 trace(8) 或 bpftrace 的一行命令)。在某些情况下,运行 strace(1) 可能是理解特定系统调用如何使用的最快方法,但要记住,当前基于 ptrace 的 strace(1) 实现可能会使目标应用程序的性能减慢数百倍,这可能会在许多生产环境中引发严重问题(例如,超过延迟 SLOs 或触发故障切换)。在尝试过BPF工具后,应将 strace(1) 视为最后的手段。可以使用 -P 选项按进程ID进行计数:
这个Java进程每秒进行近 300,000 次系统调用。其他工具显示,在这个有 48 个CPU 的系统中,这些调用仅占据了系统时间的 1.6%。
该工具通过对 raw_syscalls:sys_enter 这个跟踪点进行插装来工作,而不是通常的 syscalls:sys_enter_* 跟踪点。原因是 raw_syscalls:sys_enter 能够看到所有的系统调用,使得初始化插装更加快速。缺点是它只提供系统调用的ID,需要将其转换回名称。BCC 提供了一个库调用 syscall_name() 来完成这个转换。
对于非常高的系统调用率,这个工具可能会带来明显的开销。举例来说,我在一个CPU上进行了3.2百万次/秒/CPU的系统调用率压力测试。在运行 syscount(8) 时,工作负载减慢了30%。这有助于估计在生产环境中的开销:在一个每秒 300,000 次系统调用的 48-CPU 实例中,每CPU每秒大约执行 6000 次系统调用,因此预计会遭遇到 0.06% 的减速(30% × 6250 / 3200000)。我试图直接在生产环境中测量这个值,但由于工作负载的变化,这个值太小以至于无法测量。
BCC
命令行用法:
syscount [选项] [-i 间隔] [-d 持续时间]
可用选项包括:
■ -T TOP:打印指定数量的前几项
■ -L:显示系统调用的总时间(延迟)
■ -P:按进程计数
■ -p PID:仅测量指定PID的进程
在第13章中展示了 -L 选项的示例。
bpftrace
有一个 bpftrace 版本的 syscount(8),具有核心功能,但你也可以使用以下这个单行命令:
在这种情况下,所有 316 个系统调用跟踪点被插装(针对此内核版本),并对探测点名称进行了频率计数。当前在程序启动和关闭时会有延迟来插装所有 316 个跟踪点。最好使用单个 raw_syscalls:sys_enter 跟踪点,就像 BCC 一样,但这会需要额外的步骤将系统调用ID转换回系统调用名称。这在第14章中作为示例包含进去。
6.3.11 argdist and trace
argdist(8) 和 trace(8) 在第4章中介绍,它们是 BCC 工具,可以以自定义方式检查事件。作为 syscount(8) 的补充,如果发现某个系统调用频繁调用,你可以使用这些工具来进行更详细的检查。
例如,read(2) 系统调用在之前的 syscount(8) 输出中频繁出现。你可以使用 argdist(8) 来通过插装系统调用跟踪点或其内核函数,总结其参数和返回值。对于跟踪点,你需要找到参数名称,可以使用带有 -v 选项的 BCC 工具 tplist(8) 打印出这些名称:
使用 argdist(8) 作为直方图 (-H) 来总结的话,count 参数表示了 read(2) 的大小。
这个输出显示,在 16 到 31 字节范围内和 1024 到 2047 字节范围内有许多读取操作。可以使用 argdist(8) 的 -C 选项代替 -H,将大小总结为频率计数而不是直方图。
这显示了自从进入系统调用以来请求的读取大小。将其与系统调用退出时的返回值进行比较,后者是实际读取的字节数:
这些主要是零字节或一字节的读取操作。
由于其内核内摘要,argdist(8) 对于检查频繁调用的系统调用非常有用。而 trace(8) 则打印每个事件的输出,适合检查不太频繁的系统调用,显示每个事件的时间戳和其他细节。
bpftrace
使用 bpftrace 的一行命令可以实现这种级别的系统调用分析。例如,检查请求的读取大小作为直方图:
bpftrace有一个专门的存储桶用于负值("(..., 0)"),这些值是 read(2) 返回的错误码,用于指示错误。你可以编写一个 bpftrace 的一行命令来将这些值打印为频率计数(如第五章所示),或者作为线性直方图,以便可以看到各个数字:
```bash
# bpftrace -e 't:syscalls:sys_exit_read /args->ret < 0/ {
@ = lhist(- args->ret, 0, 100, 1); }'
```
正在附加 1 个探针...
^C
@:
[11, 12) 123 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@|
这个输出显示错误码 11 总是被返回。查看 Linux 头文件 (asm-generic/errno-base.h):
```c
#define EAGAIN 11 /* Try again */
```
错误码 11 是指“再试一次”,这是在正常操作中可能出现的错误状态。
6.3.12 funccount
funccount(8),在第四章中介绍,是一个 BCC 工具,可以对函数和其他事件进行频率计数。它可以用来提供软件 CPU 使用的更多上下文,显示哪些函数被调用以及调用频率。
profile(8) 可能能够显示某个函数在 CPU 上很活跃,但它无法解释为什么:这个函数是否运行缓慢,或者只是每秒被调用数百万次。
例如,通过以下方式,在一个繁忙的生产实例上对内核 TCP 函数进行频率计数,匹配以 "tcp_" 开头的函数:
这个输出显示,在跟踪期间,tcp_md5_do_lookup() 被调用最频繁,达到了 510,000 次。
可以使用 -i 参数生成每个间隔的输出。例如,前面 profile(8) 的输出显示函数 get_page_from_freelist() 在 CPU 上很活跃。这是因为它经常被调用,还是因为它运行缓慢?可以通过测量它的每秒调用率来判断:
该函数每秒被调用超过五十万次。
这是通过对函数进行动态跟踪实现的:它使用 kprobes 跟踪内核函数和 uprobes 跟踪用户级函数(kprobes 和 uprobes 在第二章中有详细解释)。该工具的开销与函数的调用率相关。一些函数,比如 malloc() 和 get_page_from_freelist(),经常发生,因此跟踪它们可能会显著减慢目标应用程序,超过 10% 的额外开销,请谨慎使用。有关更多关于理解开销的信息,请参见第18章的第18.1节。
命令行用法:
funccount [选项] [-i 间隔] [-d 持续时间] 模式
选项包括:
■ -r: 使用正则表达式进行模式匹配
■ -p PID: 仅测量此进程
模式:
■ name 或 p:name: 对名为 name() 的内核函数进行仪器化
■ lib:name: 对名为 name() 的库 lib 中的用户级函数进行仪器化
■ path:name: 对路径为 path 的文件中名为 name() 的用户级函数进行仪器化
■ t:system:name: 仪器化名为 system:name 的跟踪点
■ *: 通配符,匹配任何字符串(通配符)
有关更多示例,请参见第4章的第4.5节。
bpftrace
将funccount(8)的核心功能实现为bpftrace的一行命令:
# bpftrace -e 'k:tcp_* { @[probe] = count(); }'
正在挂载 320 个探针...
[...]
@[kprobe:tcp_release_cb]: 153001
@[kprobe:tcp_v4_md5_lookup]: 154896
@[kprobe:tcp_gro_receive]: 177187
可以调整此命令以进行每个间隔的输出,例如,通过添加以下内容:
interval:s:1 { print(@); clear(@); }
与BCC一样,跟踪频繁调用的函数时要小心,因为它们可能会产生显著的开销。
6.3.13 softirqs
softirqs(8) 是一个BCC工具,用于显示服务软中断(soft IRQs,软中断)的时间。系统范围内的软中断时间可以从不同的工具中轻松获取。例如,mpstat(1) 将其显示为 %soft。还可以通过 /proc/softirqs 显示软中断事件的计数。而BCC的 softirqs(8) 工具不同之处在于它可以显示每个软中断的时间,而不是事件计数。
例如,在一个具有48个CPU的生产实例上进行了10秒的跟踪:
这个输出显示,在服务 net_rx 方面花费的时间最多,总共达到了 1358 毫秒。这是相当显著的,因为在这个拥有48个CPU的系统上,这相当于CPU时间的3%。
softirqs(8) 通过使用 irq:softirq_enter 和 irq:softirq_exit 跟踪点工作。这个工具的开销与事件速率相关,对于繁忙的生产系统和高网络数据包速率可能较高。请谨慎使用并检查开销。
命令行用法:
softirqs [选项] [间隔 [次数]]
选项包括:
- -d:将IRQ时间显示为直方图
- -T:在输出中包含时间戳
可以使用 -d 选项来探索分布并识别在处理这些中断时是否存在延迟异常值。
bpftrace
尽管不存在 softirqs(8) 的 bpftrace 版本,但可以创建一个。以下的一行命令是一个起点,通过向量 ID 计数 IRQs:
# bpftrace -e 'tracepoint:irq:softirq_entry { @[args->vec] = count(); }'
正在附加1个探针...
^C
@[3]: 11
@[6]: 45
@[0]: 395
@[9]: 405
@[1]: 524
@[7]: 561
这些向量 ID 可以像 BCC 工具一样通过查找表将其转换为软中断的名称。确定在软中断中花费的时间涉及跟踪 irq:softirq_exit 跟踪点。
6.3.14 hardirqs
hardirqs(8) 是一个 BCC 工具,用于显示在处理硬中断 (hard IRQs) 时花费的时间。系统范围内的硬中断时间可以从不同的工具中轻松获取。例如,mpstat(1) 显示为 %irq。还有 /proc/interrupts 可以显示硬中断事件的计数。BCC 的 hardirqs(8) 工具不同之处在于它可以显示每个硬中断的时间,而不是事件计数。
例如,在一个有48个CPU的生产实例上进行了10秒的跟踪:
这个输出显示,在这个10秒的跟踪中,几个名为 eth0-Tx-Rx* 的硬中断总共花费了大约50毫秒的时间。
hardirqs(8) 可以提供对于 CPU 使用情况的洞察,这是 CPU 分析器无法看到的。请参见第6.2.4节的内部部分,了解在缺乏硬件性能监视单元的云实例上进行分析的方法。
该工具目前通过动态跟踪 handle_irq_event_percpu() 内核函数实现,尽管未来版本应该会切换到 irq:irq_handler_entry 和 irq:irq_handler_exit 这两个跟踪点。
命令行用法:
hardirqs [选项] [间隔 [次数]]
选项包括:
- -d:将 IRQ 时间显示为直方图
- -T:在输出中包含时间戳
选项 -d 可用于探索分布并识别在处理这些中断时是否存在延迟异常值。
6.3.15 smpcalls
smpcalls(8) 是一个 bpftrace 工具,用于跟踪和总结 SMP 调用函数(也称为交叉调用)中的时间。这些函数允许一个 CPU 在其他 CPU 上运行函数,包括所有其他 CPU,在大型多处理器系统上可能会成为一项昂贵的活动。例如,在一个有36个CPU的系统上:
这是我第一次运行这个工具,它立即识别出一个问题:aperfmperf_snapshot_khz 交叉调用相对频繁且较慢,最高达到128微秒。
smpcalls(8) 的源代码是:
许多SMP调用通过kprobes跟踪 smp_call_function_single() 和 smp_call_function_many() 内核函数。进入这些函数时,远程CPU函数作为第二个参数,bpftrace 通过 arg1 访问并按线程ID存储以供kretprobe查找。然后,bpftrace 的 ksym() 内置函数将其转换为可读的符号。
有一个特殊的SMP调用未涵盖在这些函数中,即 smp_send_reschedule(),它通过 native_smp_send_reschedule() 进行跟踪。希望将来的内核版本支持SMP调用的跟踪点,以简化对这些调用的跟踪。
@time_ns 直方图键可以修改为包括内核堆栈跟踪和进程名称:
@time_ns[comm, kstack, ksym(@func[tid])] = hist(nsecs - @ts[tid]);
这样可以为慢调用提供更多详细信息:
这个输出显示,该进程是 snmp-pass,一个监控代理程序,正在执行一个 open() 系统调用,最终进入 cpuinfo_open() 和一个昂贵的交叉调用。使用另一个BPF工具 opensnoop(8),很快确认了这种行为:
这个输出显示,snmp-pass 每秒钟都在读取 /proc/cpuinfo 文件!这个文件中的大部分内容不会改变,除了 "cpu MHz" 字段。
对软件的检查显示,它读取 /proc/cpuinfo 文件只是为了计算处理器的数量;实际上并没有使用 "cpu MHz" 字段。这是一个不必要的操作,消除它应该会带来一些小但容易的优势。
在Intel处理器上,这些SMP调用最终实现为x2APIC IPI(处理器间中断)调用,包括 x2apic_send_IPI()。这些也可以被插装,如第6.4.2节所示。
6.3.16 llcstat
llcstat(8)23 是一个使用性能计数器(PMCs)来显示进程级别的最后级缓存(LLC)失效率和命中率的BCC工具。PMCs的介绍在第2章。
例如,来自一个包含48个CPU的生产实例:
这个输出显示,Java进程(线程)的命中率非常高,超过了99%。
这个工具通过使用性能计数器(PMCs)的溢出采样来工作,其中每个缓存引用或失效的一部分触发一个BPF程序来读取当前运行的进程并记录统计信息。默认阈值为100,可以使用 `-c` 参数进行调整。这种百分之一的采样帮助保持了低开销(如果需要的话,可以调整为更高的数字);然而,与此相关的一些采样问题也存在。例如,一个进程可能偶然地比引用更频繁地溢出失效,这是没有意义的(因为失效是引用的一个子集)。
命令行用法:
```
llcstat [选项] [持续时间]
```
选项包括:
- `-c SAMPLE_PERIOD`:仅对每这么多事件中的一个进行采样
llcstat(8)的有趣之处在于它是第一个在定时采样之外使用PMCs的BCC工具。
6.3.17 Other Tools
其他值得一提的BPF工具包括:
- **cpuwalk(8)** 是来自bpftrace的工具,它对进程运行在哪些CPU上进行采样,并将结果打印为线性直方图。这提供了CPU负载均衡的直方图视图。
- **cpuunclaimed(8)** 是来自BCC的实验性工具,它采样CPU运行队列的长度,并确定空闲CPU和运行队列上仍处于可运行状态的线程之间的情况有多频繁。这种情况有时是由于CPU亲和性引起的,但如果频繁发生,可能是调度程序配置错误或者bug的迹象。
- **loads(8)** 是bpftrace的一个示例,用于获取BPF工具的负载平均数。正如之前讨论的,这些数字可能具有误导性。
- **vltrace** 是由Intel开发中的工具,它将是strace(1)的基于BPF的版本,可用于进一步表征消耗CPU时间的系统调用。
这些工具提供了对系统性能和资源利用情况更深入的分析和理解。
6.4 BPF One-Liners
这部分提供了BCC和bpftrace的一行命令示例。在可能的情况下,同一个一行命令会使用BCC和bpftrace来实现。
6.4.1 BCC
跟踪带有参数的新进程:
- **execsnoop**
显示谁在执行什么:
- **trace 't:syscalls:sys_enter_execve "-> %s", args->filename'**
按进程显示系统调用计数:
- **syscount -P**
按系统调用名称显示系统调用计数:
- **syscount**
以49赫兹的频率对PID为189的用户级堆栈进行采样:
- **profile -F 49 -U -p 189**
对所有堆栈跟踪和进程名称进行采样:
- **profile**
统计以 "vfs_" 开头的内核函数调用次数:
- **funccount 'vfs_*'**
通过 pthread_create() 跟踪新线程:
- **trace /lib/x86_64-linux-gnu/libpthread-2.27.so:pthread_create**
6.4.2 bpftrace
跟踪带有参数的新进程:
- **bpftrace -e 'tracepoint:syscalls:sys_enter_execve { join(args->argv); }'**
显示谁在执行什么:
- **bpftrace -e 'tracepoint:syscalls:sys_enter_execve { printf("%s -> %s\n", comm, str(args->filename)); }'**
按程序显示系统调用计数:
- **bpftrace -e 'tracepoint:raw_syscalls:sys_enter { @[comm] = count(); }'**
按进程显示系统调用计数:
- **bpftrace -e 'tracepoint:raw_syscalls:sys_enter { @[pid, comm] = count(); }'**
按系统调用探针名称显示系统调用计数:
- **bpftrace -e 'tracepoint:syscalls:sys_enter_* { @[probe] = count(); }'**
按系统调用函数显示系统调用计数:
- **bpftrace -e 'tracepoint:raw_syscalls:sys_enter { @[sym(*(kaddr("sys_call_table") + args->id * 8))] = count(); }'**
以99赫兹的频率采样运行中的进程名称:
- **bpftrace -e 'profile:hz:99 { @[comm] = count(); }'**
以49赫兹的频率对PID为189的用户级堆栈进行采样:
- **bpftrace -e 'profile:hz:49 /pid == 189/ { @[ustack] = count(); }'**
对所有堆栈跟踪和进程名称进行采样:
- **bpftrace -e 'profile:hz:49 { @[ustack, stack, comm] = count(); }'**
以99赫兹的频率采样运行中的CPU,并将其显示为线性直方图:
- **bpftrace -e 'profile:hz:99 { @cpu = lhist(cpu, 0, 256, 1); }'**
统计以 "vfs_" 开头的内核函数调用次数:
- **bpftrace -e 'kprobe:vfs_* { @[func] = count(); }'**
按名称和内核堆栈统计SMP调用次数:
- **bpftrace -e 'kprobe:smp_call* { @[probe, kstack(5)] = count(); }'**
按名称和内核堆栈统计Intel x2APIC调用次数:
- **bpftrace -e 'kprobe:x2apic_send_IPI* { @[probe, kstack(5)] = count(); }'**
通过 pthread_create() 跟踪新线程:
- **bpftrace -e 'u:/lib/x86_64-linux-gnu/libpthread-2.27.so:pthread_create { printf("%s by %s (%d)\n", probe, comm, pid); }'**
6.5 Optional Exercises
如果未指定,可以使用bpftrace或BCC来完成以下任务:
1. 使用execsnoop(8)显示man ls命令的新进程。
2. 在生产或本地系统上,使用execsnoop(8)带有-t选项,并将输出记录到日志文件中,持续10分钟。你发现了哪些新进程?
3. 在测试系统上,创建一个过载的CPU。这会创建两个绑定到CPU 0的CPU密集型线程:
```
taskset -c 0 sh -c 'while :; do :; done' &
taskset -c 0 sh -c 'while :; do :; done' &
```
现在使用uptime(1)(负载平均值)、mpstat(1)(-P ALL)、runqlen(8)和runqlat(8)来描述CPU 0上的工作负载。(完成后记得终止工作负载。)
4. 开发一个工具/一行命令,仅对CPU 0采样内核堆栈。
5. 使用profile(8)捕获内核CPU堆栈,以确定以下工作负载消耗了多少CPU时间:
```
dd if=/dev/nvme0n1p3 bs=8k iflag=direct | dd of=/dev/null bs=1
```
将infile(if=)设备修改为本地磁盘(查看df -h找到候选设备)。你可以进行系统范围的profile,或者针对每个dd(1)进程进行过滤。
6. 生成Exercise 5输出的CPU火焰图。
7. 使用offcputime(8)捕获内核CPU堆栈,以确定Exercise 5的工作负载中阻塞时间的消耗情况。
8. 为Exercise 7的输出生成一个off-CPU时间火焰图。
9. execsnoop(8)仅能看到调用exec(2)(execve(2))的新进程,尽管有些进程可能只调用fork(2)或clone(2)而没有调用exec(2)(例如,工作进程的创建)。编写一个名为procsnoop(8)的新工具,尽可能显示所有新进程的详细信息。你可以跟踪fork()和clone(),或者使用sched跟踪点,或者采取其他方法。
10. 开发一个bpftrace版本的softirqs(8),打印softirq名称。
11. 在bpftrace中实现cpudist(8)。
12. 使用cpudist(8)(任何版本),显示自愿和非自愿上下文切换的单独直方图。
13. (高级,未解决)开发一个工具,显示在CPU亲和性等待中任务花费的时间直方图:在其他CPU空闲但由于缓存热度而没有迁移(参见kernel.sched_migration_cost_ns,task_hot()可能是内联的且不可跟踪,以及can_migrate_task())。
6.6 Summary
这一章节总结了系统如何利用CPU,并且使用传统工具(如统计数据、分析器和追踪器)进行分析的方法。此外,本章还展示了如何使用BPF工具来发现短期进程的问题,详细检查运行队列延迟,分析CPU使用效率,计算函数调用次数,并显示软中断和硬中断的CPU使用情况。