做性能分析的人应该都有同一个体会iowait这个指标看是很好看的真正想抓到具体是谁引起的就跟大海捞针一样。我猜你和我一开始一样习惯从top里的%wa、/proc/stat里的iowait字段出发拿两个采样点一减得出一段平均百分比。这个数值做整体评估能用但要命的是它只能回答“系统有多忙”永远回答不了“是哪条IO路径、哪个进程、哪次内核调用把CPU的时间耗在等待上”。尤其出现一次8秒的IO卡顿你想知道到底是磁盘慢还是文件系统锁住了传统工具基本无能为力。所以我转向了内核事件追踪最终落在register_kretprobe上。它的核心价值在于可以在目标函数返回的那一刻触发回调让我把“IO请求从发起到完成”的耗时精确算出来而不是靠采样去猜。这篇文章会把register_kretprobe的注册流程、handler写法、参数与返回值的处理逻辑讲透再给出一段改进后的内核模块示例它能把iowait的来源从系统聚合层面下探到进程和函数调用层面。适合正在用kprobe/hook做性能分析、或者想把自己抓取iowait的小工具做得更精确的人参考。1. 为什么非要动register_kretprobe而不是继续读/proc/stat1.1 iowait的统计口径它天生是个“猜”出来的字段我后来把自己的老程序翻出来看发现它做了一件很标准但也很无奈的事定时读/proc/stat找到cpu那一行的第5个字段也就是iowait的累计jiffies然后前后相减除以采样间隔得到一个百分比。这个做法本身没错问题出在iowait字段的定义上。从Linux 2.6开始iowait被定义为“CPU处于空闲状态同时系统仍有IO请求等待处理”的时间。关键就在“空闲状态”四个字。Linux的cpu统计是按状态累加的iowait本质上是idle状态的一个子集。换句话说它统计的是“CPU刚好没有其他任务可跑同时IO还没有完成”的那段CPU时间它并不统计某个进程自己阻塞在IO写/读上的时间。这就带来一个很反直觉的结果一个程序A发起大量IO请求另一个程序B占满CPU内核会因为B在跑而认为CPU不空闲于是iowait百分比可能很低反过来如果整个系统只有一个等待读盘的进程CPU空着等IOiowait就会非常高。这种口径对整个系统的“空闲但等IO”程度有指示意义但要做进程级归因它是天然做不到的。再加上/proc/stat是周期性快照两次采样之间所有瞬时尖峰都会被抹平。我曾经遇到过一个数据目录每10分钟触发一次IO阻塞每次持续200毫秒左右用1秒间隔采样的老程序看iowait一直在2%上下完全没有暴露问题但业务方反馈的耗时抖动非常明显。这就是采样粒度导致的盲区。1.2 采样轮询做不了的事事件追踪刚好能补上采样做不到的是“在事件发生的瞬间拿到现场信息”。Kprobe机制做的事情就是在内核函数的入口或出口打桩你注册一个探测点内核在执行到该函数时会先触发一个回调等你的回调返回后再继续执行原函数。整个过程对原函数调用者透明不需要重新编译内核也不需要改目标模块的代码。我最早用的是kprobe也就是在函数入口打点。后来发现kprobe有一个天然的缺陷它只能告诉你“函数开始执行了”不能直接告诉你“这个函数跑了多久”。想测量一个IO等待函数的耗时最直接的做法是在入口记录时间戳、在出口再记录一次时间戳然后把差值累加到对应的进程上。出口怎么打点呢没有出口的kretprobe就只能手动去猜函数什么时候返回显然不靠谱。kretprobe就是专门干这个的它在函数入口处接管返回地址等函数准备ret时先跳到一个trampoline在trampoline里调用你注册的返回handler然后再真正返回。和kprobe配合起来天然形成一对起止事件。对抓取iowait来说这意味着我不用再引入一个采样线程反复去读proc而是让被探测的进程在“从IO阻塞中醒来”那一刻自己带着PID、耗时、调用栈信息来找我。2. register_kretprobe的API拆解与注册流程2.1 先认识kretprobe结构体和两个回调函数用register_kretprobe之前先定义一个struct kretprobe实例。这个结构体里最核心的是符号名和两个回调struct kretprobe { struct kprobe kp; // 内嵌的kprobe用于函数入口打点 kretprobe_handler_t handler; // 函数返回时调用的回调 kretprobe_handler_t entry_handler; // 函数入口时调用的回调可选 int maxactive; // 最大同时活跃实例数 int nmissed; // 丢失的返回事件计数 ... };其中kp字段里的symbol_name决定你要探测哪个函数。注册后内核会在该函数入口写入一条断点指令CPU执行到那里会陷入异常处理流程最终触发entry_handler当函数返回时handler触发。我自己在写模块时最常忽略的是entry_handler与handler的分工。很多人只写handler在返回回调里才开始记录时间戳。这么做有一个问题你只能拿到函数返回那一刻的信息拿不到函数入口时刻关于调用者的上下文。所以在iowait这类场景里我强烈建议在entry_handler里用current-pid记录一下当前进程同时把时间戳存到一个per-instance的私有数据里然后在返回回调里读取并结算。为什么强调per-instance因为同一个函数可能被多个进程同时调用如果用一个全局变量保存入口时间戳A进程刚进入、还没返回B进程又进入了第二次入口时间戳会把第一次的覆盖掉。这种并发竞争在IO场景里非常常见。老版本内核可以用kretprobe实例里保存私有数据但更稳妥的做法是从pt_regs里带上下文或者用hash表按调用者标识区分。2.2 注册、注销和返回值语义注册和注销的接口本身不复杂int register_kretprobe(struct kretprobe *rp); void unregister_kretprobe(struct kretprobe *rp);register_kretprobe执行成功后返回0。我在实际使用中遇到最多的非0返回值是-EINVAL通常是symbol_name为空或者handler为空的低级错误。另一个常见的是-ENOENT说明找不到对应符号。这类问题排查起来很直接先grep /proc/kallsyms确认符号存在再确认模块CONFIG_KPROBES已经开启。注销时有个容易被忽略的点unregister_kretprobe并不是同步等所有正在执行的handler结束。如果你的模块在退出时立刻释放了一个返回handler要用的数据结构就可能出现handler还在跑、数据已经被我free掉的情况。我在自己的模块里会在退出时先unregister_kretprobe然后用rcu_barrier()或者一个几百毫秒的等待来确保所有在途调用都结束再释放私有数据。虽然有点笨但稳。2.3 handler里能干什么、不能干什么这是kretprobe新手最容易踩雷的地方我列几条硬规则不能在handler里调用可能睡眠的函数比如kmalloc(GFP_KERNEL)、mutex_lock、printk刷屏。因为kretprobe的handler运行在中断或异常上下文睡眠会直接导致内核崩溃或死锁。不能调用可能再次触发同一探测点的函数。比如在io_schedule的返回handler里去调io_schedule就会形成递归断点栈直接爆掉。尽量使用per-CPU变量或者预分配的哈希表来记录状态避免分配内存。我的做法是模块加载时预先分配一个固定大小的hash桶handler里只做插入和读取不涉及运行时分配。handler本身执行时间要短。它毕竟是在原函数返回路径上插入的额外工作每次几百纳秒可以接受但如果handler里做复杂的字符串格式化、遍历大链表对高频函数的影响会是灾难性的。2.4 拿到函数的参数和返回值哪些是靠谱的kretprobe的返回handler在x86_64上可以通过struct pt_regs *regs访问寄存器。regs_return_value(regs)这个宏就是用来取函数返回值的通常对应rax寄存器。但我不建议在iowait场景里过度依赖返回值。原因有两个第一很多你感兴趣的探测函数是void类型比如submit_bio、bio_endio、io_schedule根本没有返回值可读第二返回handler执行时函数已经结束了某些架构上寄存器内容可能已经被trampoline改动跨架构的行为不完全一致。我的习惯是需要参数就在entry_handler里从regs读取并保存需要返回值就在handler里谨慎使用regs_return_value能不用就不用。对于iowait测量我们要的不是“返回值”而是“耗时”所以时间戳方案永远是第一选择。把这两个回调配合起来就构成一套完整的起止测量模型。3. 重构后的iowait抓取程序从系统聚合到进程级定位3.1 我原来的抓取程序为什么只能“看个大概”我原来的程序逻辑用一句话说就是每隔1秒读一次/proc/stat把iowait差值算成百分比打印到屏幕上。代码上看非常干净但它在实际排障中给不了任何有效的方向。有一次客户反馈某个存储节点卡顿我拉起这个程序iowait一直只有5%左右但是他们的业务延迟从10毫秒飙到了800毫秒。后来手动抓blktrace才发现有一个目录在做周期性全量扫描大量小IO堆积在NVMe队列里这些IO不一定会让CPU进入idle状态因为机器上还有别的程序在跑所以iowait被稀释了。那一刻我意识到抓取iowait的目标不应该是一个“系统百分比”而是“到底谁在等什么”。传统采样工具做不到这一点只能靠内核埋点来做。3.2 新的埋点设计测量一次IO等待的起止边界我把改进目标定成抓取进程在io_schedule里实际等待的时间并按PID聚合。io_schedule是内核中一个标志性的“等IO”路径当进程因为IO阻塞而准备让出CPU时会走这套逻辑。从它进入到返回这段时间大致可以认为“这个进程在等待IO完成”。虽然它不等于系统级iowait字段的直接值但它能回答“哪个进程、在哪个时间段、等了多久”这才是排查真正需要的信息。设计思路如下在io_schedule的入口回调里记录当前时间戳和当前进程PID在io_schedule的返回回调里计算耗时把耗时累加到该PID的统计结构里同时维护一个延迟直方图统计延迟大于某个阈值的次数定时把按PID聚合的数据输出到/proc或内核日志方便用户态读取。这样替换掉原来的/proc/stat轮询逻辑后我再去看系统卡顿能直接看到是PID 1234的备份进程在某个时间段内累计等待了3秒钟而且分布集中在128ms到256ms的延迟桶里。这比一个笼统的百分比有用得多。3.3 内核模块实例按进程聚合IO等待时间下面是我实际跑过的一个简化版本只保留了最关键的部分。为了可读性我把hash表操作尽量简化实际生产环境里还需要加锁和内存回收。#include linux/kernel.h #include linux/module.h #include linux/kprobes.h #include linux/ktime.h #include linux/sched.h #include linux/slab.h #include linux/hashtable.h #include linux/uaccess.h struct io_proc_stat { struct hlist_node node; pid_t pid; u64 total_wait_ns; // 累计等待时间 u64 count; // 等待次数 u64 max_wait_ns; // 最大单次等待时间 }; static DEFINE_HASHTABLE(io_stat_table, 8); static struct kretprobe io_sched_krp; static int io_sched_entry(struct kretprobe_instance *ri, struct pt_regs *regs) { // 入口处直接记录pid和当前时间到kretprobe的私有字段 // 这里用per-CPU变量或栈上的数据会更稳示例用current即可 ri-data (void *)current-pid; return 0; } static int io_sched_return(struct kretprobe_instance *ri, struct pt_regs *regs) { struct io_proc_stat *p; pid_t pid (pid_t)(unsigned long)ri-data; u64 delta_ns; u64 now_ns ktime_get_ns(); static u64 last_entry_ns; // 演示用实际不建议全局变量并发做入口时间 // 示意逻辑入口时间由另一个per-instance字段保存 // delta计算省略实际需要从ri-data取两个值避免全局竞争 delta_ns now_ns - last_entry_ns; hash_for_each_possible(io_stat_table, p, node, pid) { if (p-pid pid) { p-total_wait_ns delta_ns; p-count; if (delta_ns p-max_wait_ns) p-max_wait_ns delta_ns; return 0; } } p kzalloc(sizeof(*p), GFP_ATOMIC); if (!p) return 0; p-pid pid; p-total_wait_ns delta_ns; p-count 1; p-max_wait_ns delta_ns; hash_add(io_stat_table, p-node, pid); return 0; } static int __init io_wait_probe_init(void) { int ret; io_sched_krp.kp.symbol_name io_schedule; io_sched_krp.handler io_sched_return; io_sched_krp.entry_handler io_sched_entry; io_sched_krp.maxactive 64; ret register_kretprobe(io_sched_krp); if (ret 0) { pr_err(register_kretprobe failed: %d\n, ret); return ret; } pr_info(io_schedule kretprobe registered\n); return 0; } static void __exit io_wait_probe_exit(void) { struct io_proc_stat *p; struct hlist_node *tmp; int bkt; unregister_kretprobe(io_sched_krp); hash_for_each_safe(io_stat_table, bkt, tmp, p, node) { pr_info(pid %d: count%llu total%llu max%llu ns\n, p-pid, p-count, p-total_wait_ns, p-max_wait_ns); hash_del(p-node); kfree(p); } } module_init(io_wait_probe_init); module_exit(io_wait_probe_exit); MODULE_LICENSE(GPL);这段代码里我用了一个偷懒的全局变量来模拟入口时间戳这在多核并发下是不对的只是为了展示结构。真正交付使用时我会把开始时间也放进ri-data同时把pid和时间戳打包成一个小结构体。你看到这段代码时请务必把它替换成per-instance数据保存。3.4 输出怎么看从“百分比”到“画像”模块卸载时打印出来的信息大概是这样的pid 456: count120 total204800000 max268400000 ns pid 789: count35 total9800000 max12000000 ns这里的含义是PID 456的进程总共被捕获到120次IO等待累计等待204毫秒左右单次最长等待约268毫秒。这组数据放到实际排障里基本能直接锁定造成IO卡顿的进程。如果你想定位到具体文件或块设备还可以把io_schedule入口的当前进程current拿到手后再读取它的fs_struct来获取工作目录或者用current-mm-path关联可执行文件进一步把“进程画像”补全。我还加过一类直方图统计把单次等待时间分档到1ms、1ms-10ms、10ms-100ms、100ms这四类。因为延迟均值容易被极端值带偏直方图能更直观反映等待分布。比如总次数不多但100ms档出现好几次说明不是持续高负载而是偶发长尾阻塞。这两类信息配合在一起比单纯一个平均延迟更能指导下一步排查方向。4. 实战中踩过的坑从nmissed到递归都要小心4.1 maxactive别乱填kretprobe实例上限与事件丢失maxactive决定了系统可以同时追踪多少个未返回的该函数调用。比如你探测的是一个被块设备完成回调频繁调用的函数同一时间可能有大量进程都在这个函数里没有返回如果超过了maxactivekretprobe就会丢弃一部分出口事件但入口事件仍然计数导致出现“有入口、没出口”的数据丢失。如何判断丢没丢看io_sched_krp.nmissed。这个值在注册后只增不减。我一开始把io_schedule的maxactive设置成16结果高并发IO下nmissed隔几分钟就涨几千统计出来的等待次数只有真实次数的一半。后来调成128再观察nmissed就基本稳定不涨了。注意maxactive并不是越大越好。每个活跃实例都会占用栈空间和跟踪slot调太大会增加内存开销和栈溢出的风险。对io_schedule这种阻塞型函数实际同时进入的进程数等于IO等待中的进程数64到128通常足够对高频短函数反而应该靠缩短handler时间来控制开销。4.2 在handler里睡眠把自己和专业排障工具拉开差距前面提过handler里不能睡眠但我不止一次看到新手在返回handler里用printk打印每个IO事件。你以为只是打印日志实际上printk在特定条件下需要等待console锁这会直接影响原函数的返回路径轻则延迟抖动重则在锁竞争激烈时造成死锁。一次我在压测环境里挂了一个打印全部IO事件的模块压测刚开始性能就掉了7%。排查时发现每一次IO完成都要消耗几微秒在打印上等于把IO路径拖慢了。后来我改成只累加统计值每10秒输出一次聚合结果性能开销立刻降到可以忽略的程度。另一个教训是不要用可能调用到被探测函数的锁。返回handler里我一开始用了一个普通spinlock保护hash表结果该spinlock在别的驱动路径里也被同一个进程持有而那个驱动路径又触发了io_schedule虽然概率极低但一旦撞上就是自陷死锁。现在我的做法是使用spin_lock_irqsave或者per-CPU分区统计尽量减少共享状态。4.3 高频函数别乱挂选错探测点的代价kretprobe的代价是双重的每进入一次函数CPU要多走一次断点异常流程每返回一次又多走一次trampoline跳转。如果你把探测点挂在一个被调用千万次每秒的快路径函数上比如copy_page_to_iter或schedule本身模块加载后系统吞吐量会肉眼可见地下降。我踩过的具体例子是探测blk_account_io_done这个函数本身不慢但它会被每个完成IO调用而完成IO的数量在高速NVMe场景下非常高。加载模块后fio的IOPS从350k掉到了310k损失超过10%。后来我把探测点改成按采样周期开启比如每5秒开启1秒用“间歇式探测”来换性能虽然会漏掉一些事件但对长时间运行的生产环境更友好。判断一个函数适不适合挂载可以用perf stat或者/proc/kallsyms里的函数热度做初步评估也可以先小流量验证nmissed和性能损耗再决定要不要长期开启。4.4 多核时间戳与乱序返回用per-CPU还是全局哈希我的第一版模块用了一个全局变量保存入口时间戳跑单核测试一切正常一上多核就出现负数耗时。原因是两个CPU上的进程同时进入io_schedule后进入的进程把前面进程记录的时间戳覆盖了前面的进程返回时计算出来的耗时就会变成“返回时间减去别人入口的时间”加上进程调度延迟偶尔还会出现负值。解决负数耗时的关键是让每个in-flight调用拥有独立的状态槽。内核为此提供了struct kretprobe_instance的私有数据区域ri-data它和“这一次函数调用”是一一绑定的。我在entry_handler里把pid和开始时间打包存到ri-datareturn handler里再从同一个ri里读回来就不会出现跨实例覆盖。还有一种更轻量的做法是使用per-CPU变量记录时间戳但要注意进程可能在CPU之间迁移如果入口在CPU0、出口在CPU1而per-CPU变量不共享就会读到一个空值或旧值。对 IO等待测量这类长时间阻塞场景ri-data更可靠。4.5 为什么没有直接换eBPF一次克制的选择很多人会问现在用eBPF不是更方便吗确实通过kprobe/kretprobe类型的BPF程序同样可以在用户态写程序、动态挂载不需要编译内核模块还有BCC或libbpf这种成熟工具链。但我的实际情况是目标环境的内核版本较老且不允许随便升级内核。eBPF在那套系统上可用性不稳定而内核模块方式虽然重启需要重新加载但至少生命周期可以完全自己控制。另外对于“按进程精确累计等待时间”这种逻辑用传统内核模块处理起来心智负担更低调试时也能直接看日志。我不排斥eBPF它在很多现代系统上是更好的选择但一个工具是否合适取决于你手里的生产环境到底是什么样。我最终留下的落地形态是轻量内核模块负责采集用户态脚本负责读取和画图这和eBPF的整体架构思路其实一脉相承。我的体会是register_kretprobe这种老派而直接的方式在今天依然能派上大用场。尤其是当你面对一个内核版本老旧、不能轻易动系统的环境时一个几十行的小模块往往比折腾一整套新工具链更快见效。抓取iowait的关键从来不是指标本身而是你能不能把一次等待的起点和终点都精确地抓到并且和具体的进程、具体的函数上下文关联起来。把这件事做透你的性能排障起点就不再是百分比而是画像和证据。最后分享一个小技巧任何基于kretprobe的抓取模块都先开着nmissed跑一天确认事件没有丢失再来谈统计准确性扎实的基础铺垫永远比炫酷的统计图表更重要。