★ FEATURED ARTICLE 如果想要给Linux内核“拍CT”ftrace可以说是最顺手的X光机。它是内核自带的一个追踪框架最初只是用来跟踪内核函数的调用关系后来一步步扩展成了集函数追踪、静态事件、动态插桩于一体的调试利器。很多系统卡顿、进程调度异常、驱动中断抖动之类的问题用perf或strace看半天只能看到表象真正想定位到是哪段内核代码耗时高最后都得落到ftrace上面来。这篇文章是这个系列的第3篇前面我们已经把trace机制的整体轮廓和常用排查手段聊过了这一篇专门拆ftrace的原理。适合正在做内核驱动开发、系统性能调优或者单纯想搞明白“内核到底是怎么被追踪的”的工程师。即使你是刚接触内核的新手跟着文章亲手操作一遍也能很快建立起对ftrace的完整认知。1. 内容整体设计与思路拆解1.1 ftrace到底在解决什么问题内核是一个大黑盒业务进程一旦陷入系统调用执行流就进入了内核态。这时候你想知道它内部到底走了哪些函数、每个函数耗了多少时间普通调试器基本插不进手因为内核的地址空间和用户态完全隔离。传统的做法是在怀疑的函数里手动加printk但改代码重新编译内核模块代价太高而且频繁打印本身就会改变时序掩盖问题现场。ftrace的思路完全不一样。它把追踪能力直接内建到内核中你的内核镜像在编译时就已经给每个函数预留了一个“挂钩位”。运行的时候你再决定要不要挂上钩子、挂什么钩子不用重新编译甚至可以只跟踪某个子系统的特定函数。这就好比电路板设计阶段就给每个测试点留好了焊盘平时不焊任何东西需要诊断时才用跳线连上示波器。经过这么多年的演进ftrace现在能做的事情远不止函数跟踪。它下面挂了三个层次的能力最底层是动态函数插桩也就是给函数入口打补丁中间一层是各种tracepoint事件内核开发者已经预埋好的“观测点”再往上是kprobe/uprobe可以让你在任意函数地址或用户态地址插入探测逻辑。写这篇文章的时候我想的就是把这些层次拆开讲透而不是只给一堆命令。1.2 静态插桩与动态插桩的取舍很多初学者第一反应是ftrace是不是靠调试符号或者模拟器在截获函数调用不是。真实机制涉及一种“静态编译 动态改写”的组合策略。内核在编译时会通过-pg或-fpatchable-function-entry等编译器选项在每个函数的入口处预留一小段“空指令”位置。传统-pg选项会产生对mcount的调用而专门适配ftrace的方式是生成几个字节的NOP指令这几个NOP就是将来打补丁的位置。这段空间位于函数序言之前不属于任何单独函数却是所有函数都经过的共同入口。等设备运行时如果你启动了function tracerftrace会把这些NOP指令原地改写为一条跳转指令跳到它自己的钩子函数ftrace_caller上。钩子函数保存现场后读取你要的记录项写入内核的环形缓冲区然后恢复现场跳回原函数继续执行。不用的时候它再把跳转指令改回NOP让函数走最原始的路径接近零开销。这种“动态插桩”的好处是巨大的。你可以在生产环境里随时开始追踪不用重启、不用带额外的调试内核而且可以按函数名精确过滤把观测范围收敛到最小。相对的tracepoint属于静态插桩编译时就确定了位置好处是代码路径非常稳定缺点是你只能观察预埋好的位置。动态插桩和静态事件两者是互补的关系后面会详细说明。1.3 ftrace的核心调度链路前面说的钩子函数只是入口整个追踪过程还有一条完整的调度链路。以function tracer为例当一个被跟踪的函数刚要执行时跳转指令把控制权交给ftrace的专用入口这里会做一次轻量级判断当前CPU是否打开了trace开关当前进程是否需要被过滤掉如果都不满足就直接原路返回开销只多几条指令。如果决定记录钩子函数会拿到当前函数地址和调用者返回地址从地址反查函数名连同时间戳、进程信息一起写入per-CPU的环形缓冲区。这里有个很巧的设计每个CPU都有自己的独立缓冲区避免多核竞争锁这也是ftrace在压力环境下仍然可用的关键。再往上一层所有tracepoint事件最终也是把记录写到这个环形缓冲区只是入口不一样。而perf工具打开内核事件时其实也是从ftrace的这套基础设施上取数据。所以你看理解了ftrace的环形缓冲区和钩子机制很多工具的原理都能串起来了。2. 核心细节解析与实操要点2.1 tracefs文件系统逐个看现代内核里ftrace的对外接口主要在tracefs文件系统挂载点通常是/sys/kernel/tracing。如果你在旧文档里看到/sys/kernel/debug/tracing那是老内核把它挂在了debugfs下面新内核推荐独立挂载mount -t tracefs nodev /sys/kernel/tracing许多发行版开机已经挂好了。进入这个目录你会看到一大堆文件初次接触容易懵。我按用途把它们归纳一下你查的时候就有数了。文件/目录作用典型操作available_tracers列出当前内核支持的tracer类型cat查看包括function、function_graph等current_tracer当前正在使用的tracer写入function或nop来切换trace静态读取缓冲区内容cat trace查看已记录的追踪结果trace_pipe实时流式读取cat trace_pipe持续输出新记录tracing_on全局开关0停止1恢复echo 0 tracing_on冻结当前现场set_ftrace_filter设置要跟踪的函数白名单echo tcp_sendmsg set_ftrace_filterset_ftrace_notrace设置黑名单把不想看的高频函数排除在外available_filter_functions列出所有可被动态插桩的函数用grep过滤出你关心的子系统events/所有tracepoint事件所在目录echo 1 events/sched/sched_switch/enablebuffer_size_kb设置per-CPU环形缓冲区大小echo 2048 buffer_size_kbmax_graph_depthfunction_graph最大递归深度echo 3 max_graph_depthcurrent_stack_trace导出当前栈回溯配合特定tracer排查栈溢出时有用current_tracer的设计有点反直觉它一次只能启用一个主追踪器。新手最容易犯的错是先写了function然后又想去开事件发现事件没反应。这时候不是因为事件坏了而是当前tracer占用着主路径事件要等tracer切回nop后才能真正输出。2.2 function与function_graph到底怎么选function是基础的函数调用记录器它只记录“哪些函数被调用了”不显示调用关系。打开后的输出大致长这样# tracer: function # TASK-PID CPU# TIMESTAMP FUNCTION # | | | | | kworker-1462 [001] 34.192837 tcp_sendmsg kworker-1462 [001] 34.192838 tcp_sendmsg kworker-1462 [001] 34.192839 tcp_write_xmit注意FUNCTION列只是被调用的函数名你看不出它是由谁调用的。function_graph则不一样它记录的是函数的进入和退出并用缩进展示层级关系。对于读懂一条调用链来说function_graph直观得多2) | tcp_sendmsg() { 2) 0.200 us | tcp_sendmsg_locked(); 2) 0.100 us | tcp_rate_check_app_limited(); 2) 0.900 us | }但代价也明显图形化记录需要同时处理进入和退出两个事件记录数量几乎翻倍追加的时间戳和缩进处理也会抬高CPU开销。所以我的建议是先通过function粗筛出可疑函数再用function_graph精读调用链不要一上来就开全量图形追踪。实操里要特别注意set_ftrace_filter的使用。你不想把整个内核都跟踪下来否则环形缓冲区几秒就塞满系统会变得极其卡顿。较好的方式是先看available_filter_functions里有没有你怀疑的函数如果有就精确到函数名没有才考虑通配符grep tcp_ /sys/kernel/tracing/available_filter_functions echo tcp_sendmsg tcp_write_xmit tcp_recvmsg set_ftrace_filter echo function_graph current_tracer用空格分隔多个函数比用通配符安全得多。*tcp*这种写法很容易误伤一票无关函数CPU直接被拖垮。2.3 动态补丁机制是如何安全落地的把NOP改成跳转指令听起来简单在内核里做却要考虑到一个残酷的现实同一时刻可能有几十个核在并发执行这些函数入口。如果你只改了指令还没准备好跳转目标某个CPU跳到半路上就会发现目标地址不对直接崩溃。ftrace的处理方式是典型的RCU式安全切换。它先把跳转目标指向一个统一入口然后通过stop_machine机制让所有CPU短暂同步到安全点在安全点更新所有要修改的调用点最后恢复运行。这么做的细节是即使某个CPU已经执行到了旧代码它也只会走到同一套统一的入口而不会访问半修改的中间状态。新版内核还用了patchable-function-entry选项配合跳转范围检查确保每条跳转指令都不要跨过过长的地址偏移避免因远跳转占用过多指令槽。另一个安全设计是黑名单机制。某些函数不能被动态修改例如用于修改这段代码本身的函数、一部分RCU和调度原子的相关路径。内核在初始化时就会把它们列入available_filter_functions之外你在文件里根本看不到它们。这一点你不用手动规避内核已经做了。2.4 事件追踪与环形缓冲区的配合逻辑如果只靠动态函数插桩追踪的粒度还是偏大。内核里大量关键动作发生得非常快比如一次调度切换、一次中断的进入退出如果只记录函数调用你要从海量的函数名里自己演绎上下文效率很低。于是就有了tracepoint事件。events/目录下按子系统组织了上千个事件比较常用的有sched、irq、kmem、block、syscalls、net等。每个事件都有固定的格式记录的是结构化字段比如sched_switch事件会记录上一个进程、下一个进程、切换原因等。开启方式echo 1 /sys/kernel/tracing/events/sched/sched_switch/enable echo 1 /sys/kernel/tracing/events/irq/irq_handler_entry/enable cat /sys/kernel/tracing/trace_pipe事件数据和函数追踪数据最终都进同一个per-CPU环形缓冲区。这个缓冲区用的是无锁化的定长记录每个CPU一份读取时按CPU顺序导出。你可以利用buffer_size_kb把单个CPU的缓冲调大但不要无脑调太大因为缓冲区也是内核内存太大会挤压page cache。遇到高并发追踪需求更推荐用trace_pipe实时消费而不是攒在缓冲区里事后一次性读。3. 实操过程与核心环节实现3.1 五分钟跑通一次函数调用链观察下面完整演示一次从挂载到观察的流程目标是想看看某个TCP数据发送函数内部大概经过了哪些调用。真机环境可能函数名有差异但流程是通用的。# 1. 确保tracefs已经挂载 mount -t tracefs nodev /sys/kernel/tracing cd /sys/kernel/tracing # 2. 先停掉已有的追踪从干净状态开始 echo 0 tracing_on echo nop current_tracer echo trace # 3. 设置过滤函数并切换到function_graph echo tcp_sendmsg tcp_write_xmit tcp_recvmsg set_ftrace_filter echo function_graph current_tracer # 4. 打开开关并触发一次网络收发可以用任意客户端请求本机服务 echo 1 tracing_on curl -s http://127.0.0.1/ /dev/null sleep 1 # 5. 冻结现场并查看 echo 0 tracing_on head -80 trace我故意在流程里加入了多次开关设计。如果你一上来就打开追踪很难保证看到的记录和你想定位的动作严格对应。先关掉再清空操作完再开动作结束后立刻关掉这样缓冲区里留下的几乎就是你关注的那段时间。看输出的时候重点观察缩进和耗时。同一行缩进层级表示嵌套深度括号闭合表示函数退出。如果某个函数下方很长时间没有闭合括号可能它内部等待了锁或者睡眠了这就是排查延迟的线索。另外要记住function_graph显示的时间是该函数自身执行时间加子函数时间的累计值。3.2 用事件追踪做一次调度延迟快照函数级追踪信息量大但在排查“为什么我的实时线程没有及时调度”这类问题时事件模型更合适。调度延迟涉及进程状态切换、CPU负载均衡、唤醒方式等多个维度函数级调用你很难看出因果。假设你有一个周期性任务理想是每10ms运行一次但实际有几次延迟到了50ms。这时可以只开调度关键事件cd /sys/kernel/tracing echo 0 tracing_on echo nop current_tracer echo trace # 开启关键的调度和中断相关事件 echo 1 events/sched/sched_wakeup/enable echo 1 events/sched/sched_switch/enable echo 1 events/irq/irq_handler_entry/enable echo 1 events/irq/irq_handler_exit/enable echo 1 tracing_on # 运行你的任务几秒钟 sleep 5 echo 0 tracing_on cat trace /tmp/sched_trace.txt查看结果时按时间轴搜索那几个异常延迟点前后的sched_wakeup记录看唤醒发生在哪个CPU上目标进程之前在什么状态下阻塞中间是否有中断长时间占用了CPU。如果发现irq_handler_entry和irq_handler_exit之间时间跨度特别大问题很可能就在这个中断处理程序里。事件追踪的干扰比函数图追踪小很多因为事件只在预定义点触发不像函数追踪那样每个函数都要过一道判断。这也提醒我们能先精确定位到“是调度问题还是中断问题”这个层面再决定是否深入函数追踪。3.3 用kprobe造一个专属于你的探针有时候内核预置的tracepoint不够用你怀疑某个驱动函数异常但内核里没有对应事件。kprobe就是为这种情况准备的你可以指定一个要探测的内核函数地址在它执行前或返回后插入自定义逻辑。和tracepoint不同kprobe不一定要求函数名在某个“白名单”里只要内核符号表里存在就行。查看符号和实现探测# 先确认函数符号存在 grep mysub_drv /proc/kallsyms cd /sys/kernel/tracing # 创建一个kprobe事件获取函数入参的指令指针寄存器值 echo p:myprobe mysub_drv ip$arg1 kprobe_events echo r:myret mysub_drv ret$retval kprobe_events echo 1 events/kprobes/myprobe/enable echo 1 events/kprobes/myret/enable cat trace_pipep:前缀表示在函数入口探测r:前缀表示在函数返回处探测。参数可以用$arg1、$arg2这种抽象形式内核会尽量根据函数栈帧找到对应的寄存器或内存位置。$retval是返回值。用kprobe有两个常见坑。一是函数名写错或符号地址不存在创建事件后kprobe_events会静默失败或返回错误你可以通过cat kprobe_events确认有没有生成对应行。二是某些被标记为NOKPROBE的函数不能探测比如产生kprobe缺页异常的处理路径强行探测会导致递归。这种情况内核会直接拒绝不用太担心。3.4 如何结合perf和ftrace缩小排查半径讲了这么多ftrace的细节并不意味着你以后所有问题都直接上ftrace。实际工作中更高效的路径是先用perf或者分析工具圈定大致方向再用ftrace去定点放大。比如你用perf top发现某个CPU内核态占比很高但看不清具体执行路径。这种场景下可以先用ftrace的function衰减频率做一个热点函数粗筛按调用次数频率过滤掉高频细节保留时间占比大的函数。或者直接在该CPU上开启function_graph并限制追踪窗口时间缩到1~2秒内观察热点函数内部到底卡在哪。简单说就是把perf当作望远镜先定位问题在哪个范围ftrace当作显微镜再深入看具体路径。两者结合使用比单用任何一个都高效也能避免一开始就被ftrace的细节淹没。4. 常见问题与排查技巧实录4.1 定位一次真实的内核延迟事件我处理过一类很典型的“卡顿反馈”问题。某开发者负责一个用户态高频采集程序时不时报告单次采集耗时从正常几毫秒跳到几百毫秒。用perf抓用户态栈只能看到程序在read()系统调用里阻塞但是read内部为什么慢perf显得无能为力。当时我在内核侧开了这样一组追踪先切到function_graph过滤掉无关函数只留do_sys_openat2、vfs_read、filemap_fault这几个疑似路径同时开启了events/irq/irq_handler_entry和events/irq/irq_handler_exit。跑了一轮之后看到irq_handler_entry到irq_handler_exit单次耗时竟然有200ms问题根本不在文件系统而是在某块raid卡的中断处理里。后来针对那部分驱动代码做了优化单次采集耗时降回了正常范围。这个案例说明一个很宝贵的经验遇到耗时峰值不要先急着怀疑业务代码先把“CPU时间是不是被内核中断抢占了”这种底层因素排除掉。中断事件虽然看起来不起眼但通常都是延迟异常的元凶。4.2 追踪没生效、数据为空时怎么自查用ftrace的时候最常遇到的就是“我明明echo了怎么trace里什么都没有”。这种问题大多出在几个可控点上。这里给一个排查顺序现象先检查什么备注开了function没有记录current_tracer是不是被覆盖先echo nop current_tracer再重开事件enable后看不到数据主tracer占用着输出路径切回nop再观察事件过滤函数生效了但没有调用记录某个高频函数确实没被调用用available_filter_functions确认名字有数据但很快被冲掉环形缓冲区太小调大buffer_size_kb开启function后系统卡死或极慢过滤范围太宽停掉追踪缩小过滤范围trace_pipe读取一直卡住等待新数据阻塞CtrlC退出即停不影响后续追踪过程中如果遇到系统明显变慢最快的止损手段是直接echo 0 tracing_on这会立刻冻结所有追踪逻辑让函数走回NOP路径系统基本能马上恢复。注意即使tracing_on关闭之前累积在缓冲区里的数据仍然在trace文件里还能继续读取。实践上我习惯在打开追踪之前先写一个很小的Shell脚本包含清空、设过滤、开事件、记录、关开关的完整序列这样出了问题能快速重跑。手动一条条敲命令特别容易输错文件名。4.3 控制追踪开销的三板斧ftrace本身尽量做了轻量化但能记录的路径一旦铺开开销依然可观。如果你是在生产环境做短时诊断有几个关键的调参手段必须掌握。第一板斧是控制过滤范围。set_ftrace_filter里写几个函数和写一整类函数开销差距是数量级的。优先精确到函数名必要时用set_ftrace_notrace把已知高频函数剔除。第二板斧是缩小采样窗口。很多人习惯开着追踪跑半天再去翻日志找蛛丝马迹。其实ftrace更适合“预埋触发”的模式先在需要观测的路径附近设置探测关着追踪跑业务出现问题后立刻打开追踪再复现一次问题复现完马上关掉。窗口越短数据越精准开销也越小。第三板斧是关注buffer_size_kb和tracing_cpumask。如果你只关心单核行为可以用tracing_cpumask把追踪限制到特定CPU减少一半以上的缓冲和输出压力。因为环形缓冲区是per-CPU独立的限制CPU还可以避免多核数据交叉看时间线更容易对齐。4.4 容器与多环境下的注意事项在容器里面跑ftrace首先要确认宿主机内核是否开启了相关配置。常见的几个配置项包括CONFIG_FTRACE、CONFIG_FUNCTION_TRACER、CONFIG_KPROBE_EVENTS、CONFIG_TRACEPOINTS。即便容器里面看不了/boot/config-*也可以查看宿主机或确实读取到挂载路径时试跑一下能出数据就说明内核是支持的。另一个容易被忽略的是权限问题。tracefs默认trace等文件可能是root可写有些发行版会通过tracefs的挂载选项做限制。为了安全生产环境建议不要长期保留tracefs挂载权限。需要追踪时挂载用完及时卸载避免被他人滥用。如果你需要在开机启动阶段就自动做追踪可以把要执行的echo命令放到rc.local或系统服务里但要注意设置tracing_on为0等到目标服务窗口你再手动打开。很多工程师把追踪打开了忘关结果几天后回来发现内核缓冲区写满了性能一直受影响这个“追完就关”的习惯一定要养成。5. 从原理到实践的一些个人体会前面写了很多拆解和命令最后聊聊我在实际工作中怎么看待ftrace。它在Linux调试工具链里的地位有点像外科医生手里的内窥镜你不用把整个身体切开但可以伸进一根带摄像头的细管精准看到病灶区域。而它和perf这类采样式工具的区别在于ftrace更擅长回答“这段代码到底怎么走的”perf更擅长回答“整段时间哪里最忙”。我个人的建议是遇到一个典型的性能问题先记录好正常的基线数据再考虑开ftrace。否则一旦追踪窗口打开系统的行为已经发生改变你看到的数据可能不是真实状态下的表现。最后再分享一个我自己用下来的小技巧在排查完之后不要急着删掉trace文件可以把事件定义和过滤名单保存下来写成一个小脚本放到项目的doc目录里。下次再遇到类似问题一键复现同样的追踪环境不用从头回忆当时用的哪几个事件、哪几个函数能省下很多时间。
阅读完成 · 觉得有帮助？
)
