跳转上文:一篇教你Linux内核性能剖析的方法学和主要工具(上文)
三、off-cpu分析off-cpu分析更多关注延迟问题,所以我们首先要获知延迟的分布,这个时候我们最好使用直方图。之后,我们可以过度到用off-cpu火焰图等进一步分析off-CPU在等什么,而在lock contention的场合,则可以使用perf lock来进一步进行锁的分析。
直方图直方图深入人心,哪怕什么工具都没有,纯粹地用Linux内核也可以划出直方图。这个功能位于菜单tracer->Histogram triggers,通过内核tracepoints实现。
下面我们随便举个例子,看看mm/vmscan.c中shrink_inactive_list()一般回收page个数的分布。注意,这纯粹是一个栗子,不对应任何的实际工程。
在直方图中,我们关心2个点,一个是key,一个是value。比如我们以回收页面的个数为key,回收到这一key值页面个数的次数为value。
我们在include/trace/events/vmscan.h和mm/vmscan.c中增加这个trace:
trace_mm_vmscan_nr_reclaimed(nr_reclaimed, 1);这句话表示回收nr_reclaimed个页面的次数增加1。
现在我们使能tracer,以nr_reclaimed为key, times为value,按照times降序排列:
运行系统,触发一些内存回收动作,采样到一些值后,直接读取直方图:
从直方图可看出,实验场景中,回收到32个pages的机会最多,占据76598次,其次是回收到1个、0个和2个的。
下面我们把所有采样复原,改为依据nr_reclaimed升序显示:
复原:
开启新的采样:
运行系统,触发一些内存回收动作,采样到一些值后,直接读取直方图:
有的童鞋说,我现在关注的是延迟时间的分布,不是nr_reclaimed。这完全不影响我们的原理,比如latency单位是us,我想搜集0-5ms, 5-10ms, 10-15ms, 15-20ms各个档次的分布,我只需要trace:
trace_xxx_sys_yyy_latency(latency/5000, 1);
后面在hist中,0-5ms会是一行,5-10ms会是一行,依此类推。另外,内核里面统计延迟可用类似的代码逻辑(来源于kernel/dma/map_benchmark.c的map_benchmark_thread函数):
eBPF/BCC中本身内嵌多个直方图工具,可满足许多常见的生活必须,比如之前演示的biolatency,还有这些已经自带:
bitehist.py: Block I/O size histogram.
argdist: Display function parameter values as a histogram or frequency count.
bitesize: Show per process I/O size histogram.
btrfsdist: Summarize btrfs operation latency distribution as a histogram.
cpudist: Summarize on- and off-CPU time per task as a histogram.
dbstat: Summarize MySQL/PostgreSQL query latency as a histogram.
ext4dist: Summarize ext4 operation latency distribution as a histogram.
funcinterval: Time interval between the same function as a histogram.
runqlat: Run queue (scheduler) latency as a histogram.
runqlen: Run queue length as a histogram.
xfsdist: Summarize XFS operation latency distribution as a histogram.
zfsdist: Summarize ZFS operation latency distribution as a histogram.
funclatency这个笔者也经常用,比如看一下vfs_read()这个函数的执行时间分布,只需要把函数名加在funclatency之后就好:
我们看到vfs_read()在实验场景,一般延迟是8-16us之间占据第一名。但是偶尔也能大到惊人的4294967296ns,也就是4.2秒,从直方图最后一行可以看出,这些可能就是outlier了。
eBPF/BCC可以依附于kprobe、tracepoints上,在eBPF/BCC上定制直方图,只用写非常简单的脚本即可,因为直方图是其本身内嵌的功能。比如在patch【7】中,笔者想知道kernel/sched/fair.c的select_idle_cpu()在进程被唤醒的时候,统计选中与target同cluster idle CPU,不同cluster idle CPU和没找到idle cpu的比例,只需要写一个简单的脚本:
这个脚本的关键是涂了红色的三行,定义了一个直方图对象dist,然后就在里面通过dist.increment(e)增加采样点,最后通过b["dist"].print_linear_hist("idle")把直方图画出来:
eBPF/BCC里面有许多直方图的例子,我们定制自己的直方图的时候,依葫芦画瓢就好。
更多linux内核视频教程文档资料免费领取后台私信【内核】自行获取.
Linux内核源码/内存调优/文件系统/进程管理/设备驱动/网络协议栈-学习视频教程-腾讯课堂
off-cpu火焰图实际上,eBPF/BCC的代码仓库已经写好了off-cpu工具,可以直接拿来用:
https://github.com/iovisor/bcc/blob/master/tools/offcputime.py
它的原理是抓捕内核进行进程上下文切换的时间和backtrace,比如可以对finish_task_switch()内核函数施加探针。因为我们在这个点可以知道什么进程被切换走了,什么进程被切换回来的,结合这些点的backtrace搜集,我们就可以得到睡眠和唤醒的调用栈,以及时间差。可以在这个函数加tracepoint,但是没有tracepoint的情况下,我们也可以直接attach kprobe探针。
finish_task_switch()的函数原型是:
可见参数prev是被切换走的进程,而我们通过current可以拿到当前的进程,也即我们切入的进程。通过下面的算法,即可求出整个off-cpu区间的时间和backtrace:
通过在内核finish_task_switch()的kprobe点上插入eBPF/BCC代码来完成这个算法,这样不需要修改和重新编译内核。之后,我们可以把eBPF/BCC捕获的数据,借助flamegraph工具,绘制出off-cpu火焰图。
下面给一个非常简单的案例,在我的Ubuntu x86 PC上面运行以下代码,创建32个进程,每个进程申请1G内存,然后循环执行:16字节对齐的时候写入一个字节,1MB对齐的时候睡眠30us。
测试内核是5.11.0-49-generic,内核未开启抢占,但是允许PREEMPT_VOLUNTARY:
# CONFIG_PREEMPT_NONE is not set
CONFIG_PREEMPT_VOLUNTARY=y
# CONFIG_PREEMPT is not set
测试的环境开启了zRAM的swap,但是关闭了磁盘相关的swap:
捕获a.out 30秒的off-cpu数据,并绘制火焰图。
得到如下火焰图:
从以上火焰图可以看出,a.out的延迟主要是3个方面原因:
- 发生在其用户态代码本身调用的nanosleep()上;
- 发生在page_fault的处理上;
- 时间片到期后, timer中断进来,把它切换走。
我们把这3个块分别画3个圆圈:
火焰图的纵向是backtrace,横向是每一种情况的off-cpu时间,横向越宽代表这个调用stack上的off-cpu时间越久。
假设我们shrink_inactive_list()这个函数特别感兴趣,则可点击shrink_inactive_list()这个函数,单独查看这个函数的off-cpu细节,我们发现,它其中一半的off-cpu是因为它自己调用了一个msleep(),还有很大一部分发上在它主动call了_cond_resched(),然后CPU被别人抢走;如果我们关注mutex_lock() 的延迟,则显然发生在shrink_inactive_list() -> shrink_page_list() -> add_to_swap -> get_swap_pages() -> mutex_lock()这个路径上。
如果我们把焦点移到kswapd,我们还是运行上面的a.out代码,但是我们捕获和分析的对象换为kswapd。捕获kswapd的off-cpu数据30秒并绘制off-cpu火焰图。
绘制出来的kswapd的off-cpu火焰图如下:
可见多数延迟发生在kswapd各种路径下(比如shrink_inactive_list -> shrink_page_list路径)主动调用_cond_resched()出让CPU,还有一部分延迟发生在最右边的shrink_slab的i915显卡驱动的slab shrink,点击放大它:
从上图可以看出,我们在内存回收shrink_slab()的时候,被i915驱动的i915_gem_shrink()堵住了,而i915_gem_shrink()被一个mutex_lock_interruptible()堵住了,所以i915驱动持有的一个mutex实际上给shrink_slab()是添堵了。
特别有意思的是,这个off-cpu火焰图,还可以变成双层的off-wake火焰图。比如A进程等一个锁睡眠了,B进程是持有锁的人,B唤醒了A,在off-wake火焰图上,它会以双层调用栈的形式进行展示。比如在a.out引起匿名页频繁swap的情况下,抓一下kswapd的off-wake火焰图:
得到的图如下:
从图上可以完整看出,kswapd off-cpu的原因和唤醒者。比如画红圈的区域,kswapd因为调用kswapd_try_to_sleep()而主动进入睡眠,a.out在swap in的过程中do_swap_page()因而需要alloc_pages()的时候因为申请内存的压力,唤醒了kswapd内核线程。天蓝色的是kswapd,淡蓝色的是唤醒者。唤醒者的调用栈是从上到下,off-cpu的kswapd的调用栈是从下到上,中间通过灰色隔离带隔开。这种描述方式,确实看起来比较惊艳有木有?
Lock Contention分析在使能内核CONFIG_LOCKDEP 和CONFIG_LOCK_STAT 选项的情况下,我们可以通过perf lock来进行lock的contention分析。其实perf lock主要是利用了内核一系列的锁的tracepoints,比如trace_lock_acquired(lock, ip)、trace_lock_acquired(lock, ip)、trace_lock_release(lock, ip)等。
在我运行一个匿名页频繁swap out/in的系统里,抓取lock情况:
然后生成报告:
看起来&rq->__lock、ptlock_ptr(page)、&lruvec->lru_lock的竞争比较激烈。尤其是&lruvec->lru_lock,由于contention比较多,total wait时间比较大。这里要特别留意一点,lock contention不一定是off-cpu的,可能也有on-cpu的,对于mutex, rwsem更多是off-cpu的;spinlock,则更多是on-cpu的。
对于off-cpu以及相关的延迟问题,我们需要通过直方图获知延迟分布、off-cpu/off-wakeup火焰图获知off-cpu的原因和唤醒者,如果是锁竞争的情况,则进一步通过内核perf lock剖析锁竞争。
四、总结性能优化经常是一个全栈的工作,对工程师的要求也比较高。它是一个很难用一篇文章完整描述清楚的话题,所以本文更多只是起一个提纲挈领的作用,许多话题有待以后有机会进一步展开。文中疏漏,在所难免,还请读者朋友海涵。最后推荐给亲爱的读者朋友们2本书:
- BrenDan Gregg的《System Performance Enterprise and the Cloud(Second Edition)》;
- Denis Bakhvalor的《Performance Analysis and Tuning on Modern CPUs》
,