1. 为什么内核调试总让人头疼以及Ftrace到底解决了什么搞内核开发的人都有一个共识用户态程序出了问题gdb 挂上去、打几个断点、看看调用栈大部分情况都能定位。但一旦问题出在内核态事情就完全不一样了。内核崩溃可能表现为系统直接挂死、某个进程莫名其妙变成 D 状态、网络包延迟突然飙升、文件系统写入性能断崖式下降甚至只是 dmesg 里多了一行看起来人畜无害的 warning。这些现象背后可能涉及调度器、内存管理、锁竞争、中断处理、驱动逻辑等无数个子系统而你又不能像调试用户态程序那样随便暂停内核——内核停了整个机器就停了。传统的 printk 大法当然能用但它的局限性非常明显。第一printk 本身有性能开销在高频路径上插入 printk 会改变系统的时序行为甚至让原本能复现的问题变得无法复现。第二printk 需要重新编译内核或至少重新加载模块迭代周期长。第三printk 的输出是离散的你很难从中看出函数之间的调用关系和耗时分布。第四有些代码路径在中断上下文或原子上下文中执行printk 可能导致睡眠或死锁。Ftrace 就是在这个背景下成为内核开发者工具箱里不可或缺的一件利器。它的全称是 Function Tracer最初由 Steven Rostedt 开发后来合入主线内核现在已经发展成一个庞大的跟踪框架包含 function tracer、function graph tracer、事件跟踪、动态探针、触发器、快照、过滤器等一大堆功能。最关键的是它几乎不需要你重新编译内核通过 debugfs 或 tracefs 文件系统就能在运行时开启和配置对系统的影响可以控制到非常小的程度。这篇文章适合谁看如果你正在做内核模块开发、驱动调试、性能优化或者你只是对 Linux 内核的运行行为感到好奇想找一个能实际动手的工具来观察内核在干什么那 Ftrace 就是你应该掌握的东西。我不打算把这篇写成一份手册式的文档而是按照我自己实际使用 Ftrace 排查问题的思路来组织把踩过的坑、常用的命令、容易忽略的细节都摊开来讲。2. Ftrace 的核心机制与设计思路拆解2.1 编译期插桩与运行时动态替换Ftrace 的实现依赖两个关键机制编译期插桩和运行时动态替换。内核在编译时如果开启了CONFIG_FUNCTION_TRACER编译器会在几乎每个函数的入口处插入一个对mcount或__fentry__的调用。这个调用最初只是一条 nop 指令占几个字节对性能几乎没有影响。当你在运行时通过 tracefs 开启 function tracer 时内核会把那些 nop 指令动态替换成跳转到跟踪代码的指令。关闭时再替换回 nop。这个设计非常巧妙编译期保留了跟踪能力运行时才决定是否激活避免了长期性能损耗。这里有一个容易忽略的点不是所有函数都会被插桩。标记为notrace的函数、内联函数、以及一些早期启动代码不会被跟踪。另外如果内核编译时没有开启CONFIG_DYNAMIC_FTRACE那就只能使用静态的 function tracer性能开销会大很多而且不能按需开关。所以拿到一个内核首先确认配置这是基本功。2.2 tracefs 与 debugfs 的关系早期 Ftrace 的控制接口挂在 debugfs 下面路径是/sys/kernel/debug/tracing。后来内核引入了专门的 tracefs通常挂载在/sys/kernel/tracing。两个路径下的内容基本一致但 tracefs 的挂载权限可以独立控制更适合在生产环境中限制访问。很多发行版默认只挂载了 debugfstracefs 需要手动挂载或者通过 fstab 配置。如果你发现/sys/kernel/tracing是空的先检查 tracefs 有没有挂上。mount | grep -E tracefs|debugfs # 如果没有 tracefs手动挂载 mount -t tracefs nodev /sys/kernel/tracing我个人的习惯是统一用/sys/kernel/tracing因为它的语义更清晰而且不会和 debugfs 下其他调试接口混在一起。但如果你面对的是一个老内核比如 4.x 以前可能只有 debugfs 路径可用那就用/sys/kernel/debug/tracing。2.3 跟踪数据的环形缓冲区设计Ftrace 的所有跟踪数据都写入一个 per-CPU 的环形缓冲区。每个 CPU 有自己的缓冲区写入时不需要跨 CPU 锁这是它性能高的关键原因之一。缓冲区的大小可以通过buffer_size_kb调整默认值通常不大在高频跟踪场景下很容易被写满。写满之后的行为取决于trace_options里的设置默认是覆盖旧数据也可以配置成写满即停。环形缓冲区的存在意味着你不能把它当成一个无限大的日志文件。跟踪几秒钟的高频事件就可能产生几十兆数据如果缓冲区只有几兆那你看到的只是最后那一小段。所以实际使用中要么调大缓冲区要么配合过滤器缩小跟踪范围要么使用trace_pipe实时读取而不是依赖trace文件的事后查看。2.4 事件跟踪与函数跟踪的分工Ftrace 的跟踪能力大致分两类函数跟踪和事件跟踪。函数跟踪关注的是“哪些函数被调用了、调用顺序是什么、每个函数花了多长时间”适合分析代码流程和性能热点。事件跟踪关注的是“内核在某个时刻发生了什么具体事件”比如系统调用进入退出、中断触发、调度切换、内存分配、文件系统操作等。事件是内核开发者预先埋好的静态跟踪点每个事件有明确的字段和格式比函数跟踪的信息密度更高、语义更清晰。实际排查问题时我通常先用事件跟踪快速定位到可疑的子系统然后再用函数跟踪深入看具体的调用链。两者配合使用效率比单独用某一种高得多。3. 核心细节解析与实操要点3.1 确认内核配置是否支持 Ftrace在开始之前必须先确认当前内核编译时开启了哪些 Ftrace 相关的配置。最直接的方法是查看/boot/config-$(uname -r)或者/proc/config.gz。# 如果 /proc/config.gz 存在 zcat /proc/config.gz | grep -E FTRACE|FUNCTION_TRACER|DYNAMIC_FTRACE|TRACEPOINTS # 或者查看 /boot 下的配置文件 grep -E FTRACE|FUNCTION_TRACER|DYNAMIC_FTRACE|TRACEPOINTS /boot/config-$(uname -r)必须开启的配置项包括配置项作用是否必须CONFIG_FTRACEFtrace 框架基础必须CONFIG_FUNCTION_TRACER函数跟踪必须CONFIG_DYNAMIC_FTRACE动态替换 nop强烈建议CONFIG_FUNCTION_GRAPH_TRACER函数图跟踪按需CONFIG_TRACEPOINTS静态跟踪点按需CONFIG_ENABLE_DEFAULT_TRACERS默认跟踪器按需CONFIG_STACK_TRACER栈跟踪按需如果CONFIG_DYNAMIC_FTRACE没开function tracer 一旦开启就会一直生效没法动态关闭性能影响会持续存在。这种情况下要么重新编译内核要么只用事件跟踪。3.2 可用跟踪器的查看与切换进入 tracefs 目录后available_tracers文件列出了当前内核支持的所有跟踪器。cat /sys/kernel/tracing/available_tracers # 典型输出blk function_graph wakeup_dl wakeup_rt wakeup function nopcurrent_tracer文件用于查看和设置当前激活的跟踪器。默认是nop表示不跟踪。切换到 function tracerecho function /sys/kernel/tracing/current_tracer切换到 function_graph tracerecho function_graph /sys/kernel/tracing/current_tracer注意切换跟踪器之前最好先清空缓冲区否则新旧数据混在一起分析起来很麻烦。清空命令是echo /sys/kernel/tracing/trace。3.3 过滤器的使用是高效跟踪的关键不加过滤地开启 function tracer输出量会大到无法阅读。set_ftrace_filter和set_ftrace_notrace是两个核心的过滤文件。# 只跟踪特定函数 echo vfs_read /sys/kernel/tracing/set_ftrace_filter # 跟踪某个模块的所有函数 echo :mod:ext4 /sys/kernel/tracing/set_ftrace_filter # 使用通配符 echo vfs_* /sys/kernel/tracing/set_ftrace_filter # 排除某些函数 echo schedule /sys/kernel/tracing/set_ftrace_notraceset_ftrace_filter支持通配符和模块名匹配这在调试驱动时特别有用。比如你写了一个叫mydev的模块直接echo :mod:mydev set_ftrace_filter就能把所有该模块的函数都纳入跟踪范围。对于事件跟踪过滤是通过events/目录下的filter文件完成的。每个事件都有自己的过滤表达式语法支持比较运算符、逻辑运算符和字段引用。# 只跟踪 pid 为 1234 的进程产生的 sched_switch 事件 echo next_pid 1234 /sys/kernel/tracing/events/sched/sched_switch/filter3.4 trace_pipe 与 trace 的区别trace文件是一个静态快照读取时会把当前缓冲区的内容全部输出但不会阻塞。trace_pipe是一个实时管道读取时会阻塞等待新数据适合配合cat或脚本实时消费。# 实时查看跟踪输出 cat /sys/kernel/tracing/trace_pipe # 事后查看缓冲区内容 cat /sys/kernel/tracing/trace实际使用中如果跟踪量很大trace文件可能在你读取之前就被新数据覆盖了。这时候要么调大缓冲区要么用trace_pipe实时抓取并重定向到文件。我通常的做法是先用trace_pipe抓一小段确认跟踪配置正确后再决定是否需要长时间抓取。4. 实操过程与核心环节实现4.1 场景一定位某个系统调用的内核执行路径假设你发现某个进程调用read()系统调用后延迟很高想看看内核里到底走了哪些函数、在哪里卡住了。第一步找到目标进程的 PID然后设置 function_graph tracer 并过滤到相关函数。cd /sys/kernel/tracing # 清空并设置跟踪器 echo trace echo function_graph current_tracer # 设置过滤只跟踪与 read 相关的 vfs 层函数 echo vfs_read set_ftrace_filter echo vfs_write set_ftrace_filter # 如果知道具体文件系统可以加上模块过滤 echo :mod:ext4 set_ftrace_filter # 开启跟踪 echo 1 tracing_on # 执行你的测试程序 # ... # 关闭跟踪 echo 0 tracing_on # 查看结果 cat tracefunction_graph 的输出格式是缩进的调用树每个函数后面跟着执行时间微秒。通过观察哪一层函数耗时最长就能快速定位到热点。比如你可能会看到vfs_read下面ext4_file_read_iter花了 200 微秒而其中ext4_mpage_readpages又占了 180 微秒那问题大概率出在块层或磁盘 I/O 上。实操心得function_graph 的输出量比 function tracer 大得多因为每个函数入口和出口都会记录。如果跟踪范围太宽缓冲区瞬间就满了。建议先用 function tracer 确认目标函数确实被调用了再切换到 function_graph 看细节。4.2 场景二用事件跟踪分析调度延迟调度延迟是内核性能问题里最常见的一类。Ftrace 提供了sched_switch、sched_wakeup、sched_wakeup_new等事件可以精确记录每次调度切换的时间戳和涉及的进程。cd /sys/kernel/tracing # 清空并关闭所有事件 echo trace echo 0 events/enable # 开启调度相关事件 echo 1 events/sched/sched_switch/enable echo 1 events/sched/sched_wakeup/enable # 设置过滤只关心特定进程 echo next_comm myapp events/sched/sched_switch/filter # 开启跟踪 echo 1 tracing_on # 运行测试负载 # ... echo 0 tracing_on cat trace输出里每一行都包含时间戳、CPU 号、当前进程、被切换进来的进程、优先级等信息。通过计算sched_wakeup到sched_switch之间的时间差就能得到唤醒延迟。如果延迟超过预期再结合sched_stat_runtime等事件看是不是 CPU 被其他任务占满了。4.3 场景三用 kprobe 动态跟踪任意函数Ftrace 的 kprobe 机制允许你在任意内核函数甚至函数内部的某条指令上动态插入探针不需要重新编译内核。这对于调试没有预埋 tracepoint 的代码路径特别有用。cd /sys/kernel/tracing # 在 vfs_read 入口插入 kprobe echo p:myprobe vfs_read kprobe_events # 查看已注册的 kprobe cat kprobe_events # 开启对应事件 echo 1 events/kprobes/myprobe/enable # 跟踪并查看 echo 1 tracing_on # ... 执行操作 ... echo 0 tracing_on cat trace # 清理 echo kprobe_eventskprobe 还支持获取函数参数和返回值。比如p:myprobe vfs_read file$arg1 count$arg2可以把第一个和第二个参数记录下来。返回值探针用r:前缀可以获取$retval。这个功能在排查“某个函数到底返回了什么错误码”时非常高效。注意kprobe 的语法和可用参数取决于内核版本和架构。x86_64 上$arg1到$argN对应寄存器传参但超过一定数量的参数可能取不到。另外在 kprobe 的处理函数里不能睡眠也不能访问可能缺页的用户态内存否则会导致内核崩溃。4.4 场景四用 trace-cmd 简化命令行操作直接操作 tracefs 文件系统虽然灵活但命令比较繁琐而且容易忘记清理。trace-cmd是一个用户态工具把常用的 Ftrace 操作封装成了更友好的命令行接口。# 安装以常见发行版为例 # apt install trace-cmd 或 yum install trace-cmd # 开始记录调度事件 trace-cmd record -e sched_switch -e sched_wakeup # 停止记录后查看 trace-cmd report # 只记录特定进程 trace-cmd record -P 1234 -e sched_switch # 使用 function_graph 跟踪特定函数 trace-cmd record -p function_graph -l vfs_read -l vfs_writetrace-cmd的好处是自动处理了缓冲区大小、事件启用、数据保存等细节生成的trace.dat文件可以用trace-cmd report或kernelshark图形化工具分析。对于需要反复跟踪、对比的场景用trace-cmd比手动操作文件系统效率高很多。4.5 场景五用 snapshot 保留关键时刻的现场有时候你只关心问题发生那一瞬间的内核状态而不是持续跟踪。Ftrace 的 snapshot 功能可以在不停止跟踪的情况下把当前缓冲区的内容“冻结”下来。cd /sys/kernel/tracing # 开启跟踪 echo function current_tracer echo 1 tracing_on # 在某个时刻触发快照 echo 1 snapshot # 查看快照内容 cat snapshot # 继续跟踪缓冲区不受影响这个功能在配合触发器使用时特别强大。比如你可以设置一个触发器当某个条件满足时自动拍快照这样就能精确捕获到问题发生的瞬间而不需要人工干预。5. 常见问题与排查技巧实录5.1 开启跟踪后系统变慢甚至卡死这是最常见的问题原因通常有几个跟踪范围太宽、缓冲区太小导致频繁覆盖、在中断上下文里跟踪了不该跟踪的函数。排查思路是先用最小范围的过滤器确认跟踪本身没问题再逐步扩大范围。如果系统已经卡死可以通过串口或 sysrq 强制关闭跟踪。# 紧急关闭所有跟踪 echo 0 /sys/kernel/tracing/tracing_on echo nop /sys/kernel/tracing/current_tracer避坑技巧在生产环境使用 Ftrace 之前先在测试环境验证跟踪配置。特别是 function_graph tracer它的开销比 function tracer 大一个数量级在高负载系统上可能直接导致服务不可用。5.2 trace 文件为空或只有表头可能的原因包括跟踪器没设置、tracing_on 是 0、过滤器把所有函数都排除了、缓冲区被覆盖了。按顺序检查这几个文件cat current_tracer cat tracing_on cat set_ftrace_filter cat buffer_size_kb如果set_ftrace_filter是空的function tracer 会跟踪所有函数输出量巨大但不会为空。如果过滤器设置了但匹配不到任何函数输出就会是空的。另外有些内核版本在tracing_on为 0 时仍然会记录部分事件但 function tracer 不会。5.3 kprobe 注册失败kprobe 注册失败通常有几个原因函数名拼写错误、函数被内联了、函数在.init段启动后已被释放、或者该架构不支持 kprobe。可以通过/sys/kernel/tracing/available_filter_functions查看所有可跟踪的函数名。grep vfs_read /sys/kernel/tracing/available_filter_functions如果函数不在这个列表里说明它被内联或者标记了notrace无法用 kprobe 跟踪。这时候可以尝试跟踪它的调用者或者用perf probe作为替代方案。5.4 时间戳不准确或时区不对Ftrace 的时间戳默认是相对于跟踪开始的偏移量单位是秒。可以通过trace_clock文件切换时钟源比如切换到global使用系统全局时钟或者uptime使用启动以来的时间。cat trace_clock echo global trace_clock如果发现时间戳和dmesg对不上检查一下trace_clock的设置。另外trace_options里的latency-format选项会改变时间戳的显示格式开启后会显示相对延迟而不是绝对时间。5.5 缓冲区大小调整后不生效buffer_size_kb的写入是 per-CPU 的实际总内存占用是写入值乘以 CPU 数量。如果写入失败可能是内存不足或者权限不够。另外某些内核版本在跟踪器激活时不允许调整缓冲区大小需要先切回nop。echo nop current_tracer echo 8192 buffer_size_kb cat buffer_size_kb5.6 常见问题速查表现象可能原因解决方法trace 文件为空tracing_on 为 0echo 1 tracing_on输出量太大过滤器未设置设置 set_ftrace_filter系统变慢function_graph 开销大改用 function tracer 或缩小范围kprobe 注册失败函数被内联查看 available_filter_functions时间戳混乱trace_clock 设置不当切换为 global 或 uptime缓冲区溢出buffer_size_kb 太小调大缓冲区或减少跟踪范围事件不触发事件未 enableecho 1 events/xxx/enable过滤器不生效语法错误检查 filter 文件内容6. 进阶技巧与组合使用思路6.1 用触发器实现自动化跟踪Ftrace 的触发器trigger功能可以在特定事件发生时自动执行动作比如开启/关闭跟踪、拍快照、打印栈回溯等。这在捕获偶发问题时特别有用。# 当 sched_switch 事件中 next_comm 为 myapp 时自动开启 function tracer echo next_comm myapp events/sched/sched_switch/trigger echo traceon events/sched/sched_switch/trigger # 当条件再次满足时关闭 echo traceoff events/sched/sched_switch/trigger触发器支持的动包括traceon、traceoff、snapshot、stacktrace、dump等。组合使用可以实现非常精细的跟踪策略比如“只在特定进程被调度时跟踪其他时间不跟踪”这样既捕获了关键信息又避免了缓冲区被无关数据淹没。6.2 用 stacktrace 查看调用栈在事件触发时打印调用栈可以快速了解代码的执行路径。stacktrace触发器就是干这个的。echo stacktrace events/sched/sched_switch/trigger开启后每次sched_switch事件触发时都会在 trace 输出里附带一段调用栈。这对于分析“这个事件是从哪个代码路径触发的”非常直观。不过要注意stacktrace 本身有性能开销不适合在高频事件上长期开启。6.3 用 hist 触发器做统计而不是逐条记录逐条记录事件在数据量大时很难分析。Ftrace 的 hist 触发器可以对事件字段做直方图统计直接输出聚合结果。# 统计 sched_switch 事件中 next_comm 的分布 echo hist:keysnext_comm:sorthitcount events/sched/sched_switch/trigger # 查看统计结果 cat events/sched/sched_switch/hist这个功能在分析“哪个进程被调度得最频繁”“哪个错误码出现得最多”这类问题时比逐条看 trace 高效得多。hist 触发器还支持sum、avg、max、min等聚合操作可以对时间字段做统计分析。6.4 用 trace-cmd 配合 kernelshark 做可视化分析kernelshark是 trace-cmd 的图形化前端可以把跟踪数据画成时间轴直观展示每个 CPU 上运行的进程、事件的时间分布、函数调用的嵌套关系。对于复杂的调度延迟问题图形化展示比看文本输出高效得多。# 记录数据 trace-cmd record -e sched_switch -e sched_wakeup -e irq # 用 kernelshark 打开 kernelshark trace.dat在 kernelshark 里可以缩放时间轴、筛选事件、查看每个事件的详细字段。我通常用它来快速定位延迟尖峰然后再回到命令行用 Ftrace 做精细分析。6.5 跟踪模块加载与卸载时的行为调试内核模块时模块的初始化和清理函数往往是问题高发区。可以用 Ftrace 跟踪模块加载过程中的函数调用。# 跟踪模块加载相关的内核函数 echo do_init_module set_ftrace_filter echo load_module set_ftrace_filter echo do_one_initcall set_ftrace_filter # 开启 function_graph echo function_graph current_tracer echo 1 tracing_on # 加载模块 modprobe mydev echo 0 tracing_on cat trace这样可以清楚地看到模块初始化函数被调用的顺序、每个初始化步骤的耗时、以及是否在某个环节卡住或返回错误。7. 我个人在实际操作中的几点体会Ftrace 最大的价值在于它把内核从一个黑盒变成了一个可以观察的系统。但工具越强大越需要克制。我见过太多人一上来就开 function_graph 跟踪所有函数结果系统直接卡死或者缓冲区里全是无关数据根本没法分析。正确的做法永远是先明确你要回答什么问题再选择最小的跟踪范围用过滤器把无关信息排除掉最后才开启跟踪。另一个体会是Ftrace 的输出需要结合内核源码来读。光看函数名和耗时你只能知道“哪里慢”但不知道“为什么慢”。只有对着源码看调用链才能理解每个函数在做什么、为什么会被调用、耗时是否合理。所以 Ftrace 和源码阅读是分不开的工具只是辅助真正的分析能力来自对内核代码的理解。还有一点不同内核版本的 Ftrace 接口和功能有差异。比如早期版本没有 hist 触发器tracefs 的挂载方式也不一样。在生产环境使用之前一定要确认目标内核的文档和实际行为。Documentation/trace/目录下的文档是最权威的参考虽然有些内容更新不及时但比网上大部分教程靠谱得多。最后分享一个小技巧如果你不确定某个跟踪配置会不会导致系统卡死可以先在虚拟机里试。用 QEMU 起一个和目标任务环境相近的内核在里面随便折腾确认配置没问题再上生产。这个习惯帮我避免了好几次可能的事故。
1. 为什么内核调试总让人头疼以及Ftrace到底解决了什么搞内核开发的人都有一个共识用户态程序出了问题gdb 挂上去、打几个断点、看看调用栈大部分情况都能定位。但一旦问题出在内核态事情就完全不一样了。内核崩溃可能表现为系统直接挂死、某个进程莫名其妙变成 D 状态、网络包延迟突然飙升、文件系统写入性能断崖式下降甚至只是 dmesg 里多了一行看起来人畜无害的 warning。这些现象背后可能涉及调度器、内存管理、锁竞争、中断处理、驱动逻辑等无数个子系统而你又不能像调试用户态程序那样随便暂停内核——内核停了整个机器就停了。传统的 printk 大法当然能用但它的局限性非常明显。第一printk 本身有性能开销在高频路径上插入 printk 会改变系统的时序行为甚至让原本能复现的问题变得无法复现。第二printk 需要重新编译内核或至少重新加载模块迭代周期长。第三printk 的输出是离散的你很难从中看出函数之间的调用关系和耗时分布。第四有些代码路径在中断上下文或原子上下文中执行printk 可能导致睡眠或死锁。Ftrace 就是在这个背景下成为内核开发者工具箱里不可或缺的一件利器。它的全称是 Function Tracer最初由 Steven Rostedt 开发后来合入主线内核现在已经发展成一个庞大的跟踪框架包含 function tracer、function graph tracer、事件跟踪、动态探针、触发器、快照、过滤器等一大堆功能。最关键的是它几乎不需要你重新编译内核通过 debugfs 或 tracefs 文件系统就能在运行时开启和配置对系统的影响可以控制到非常小的程度。这篇文章适合谁看如果你正在做内核模块开发、驱动调试、性能优化或者你只是对 Linux 内核的运行行为感到好奇想找一个能实际动手的工具来观察内核在干什么那 Ftrace 就是你应该掌握的东西。我不打算把这篇写成一份手册式的文档而是按照我自己实际使用 Ftrace 排查问题的思路来组织把踩过的坑、常用的命令、容易忽略的细节都摊开来讲。2. Ftrace 的核心机制与设计思路拆解2.1 编译期插桩与运行时动态替换Ftrace 的实现依赖两个关键机制编译期插桩和运行时动态替换。内核在编译时如果开启了CONFIG_FUNCTION_TRACER编译器会在几乎每个函数的入口处插入一个对mcount或__fentry__的调用。这个调用最初只是一条 nop 指令占几个字节对性能几乎没有影响。当你在运行时通过 tracefs 开启 function tracer 时内核会把那些 nop 指令动态替换成跳转到跟踪代码的指令。关闭时再替换回 nop。这个设计非常巧妙编译期保留了跟踪能力运行时才决定是否激活避免了长期性能损耗。这里有一个容易忽略的点不是所有函数都会被插桩。标记为notrace的函数、内联函数、以及一些早期启动代码不会被跟踪。另外如果内核编译时没有开启CONFIG_DYNAMIC_FTRACE那就只能使用静态的 function tracer性能开销会大很多而且不能按需开关。所以拿到一个内核首先确认配置这是基本功。2.2 tracefs 与 debugfs 的关系早期 Ftrace 的控制接口挂在 debugfs 下面路径是/sys/kernel/debug/tracing。后来内核引入了专门的 tracefs通常挂载在/sys/kernel/tracing。两个路径下的内容基本一致但 tracefs 的挂载权限可以独立控制更适合在生产环境中限制访问。很多发行版默认只挂载了 debugfstracefs 需要手动挂载或者通过 fstab 配置。如果你发现/sys/kernel/tracing是空的先检查 tracefs 有没有挂上。mount | grep -E tracefs|debugfs # 如果没有 tracefs手动挂载 mount -t tracefs nodev /sys/kernel/tracing我个人的习惯是统一用/sys/kernel/tracing因为它的语义更清晰而且不会和 debugfs 下其他调试接口混在一起。但如果你面对的是一个老内核比如 4.x 以前可能只有 debugfs 路径可用那就用/sys/kernel/debug/tracing。2.3 跟踪数据的环形缓冲区设计Ftrace 的所有跟踪数据都写入一个 per-CPU 的环形缓冲区。每个 CPU 有自己的缓冲区写入时不需要跨 CPU 锁这是它性能高的关键原因之一。缓冲区的大小可以通过buffer_size_kb调整默认值通常不大在高频跟踪场景下很容易被写满。写满之后的行为取决于trace_options里的设置默认是覆盖旧数据也可以配置成写满即停。环形缓冲区的存在意味着你不能把它当成一个无限大的日志文件。跟踪几秒钟的高频事件就可能产生几十兆数据如果缓冲区只有几兆那你看到的只是最后那一小段。所以实际使用中要么调大缓冲区要么配合过滤器缩小跟踪范围要么使用trace_pipe实时读取而不是依赖trace文件的事后查看。2.4 事件跟踪与函数跟踪的分工Ftrace 的跟踪能力大致分两类函数跟踪和事件跟踪。函数跟踪关注的是“哪些函数被调用了、调用顺序是什么、每个函数花了多长时间”适合分析代码流程和性能热点。事件跟踪关注的是“内核在某个时刻发生了什么具体事件”比如系统调用进入退出、中断触发、调度切换、内存分配、文件系统操作等。事件是内核开发者预先埋好的静态跟踪点每个事件有明确的字段和格式比函数跟踪的信息密度更高、语义更清晰。实际排查问题时我通常先用事件跟踪快速定位到可疑的子系统然后再用函数跟踪深入看具体的调用链。两者配合使用效率比单独用某一种高得多。3. 核心细节解析与实操要点3.1 确认内核配置是否支持 Ftrace在开始之前必须先确认当前内核编译时开启了哪些 Ftrace 相关的配置。最直接的方法是查看/boot/config-$(uname -r)或者/proc/config.gz。# 如果 /proc/config.gz 存在 zcat /proc/config.gz | grep -E FTRACE|FUNCTION_TRACER|DYNAMIC_FTRACE|TRACEPOINTS # 或者查看 /boot 下的配置文件 grep -E FTRACE|FUNCTION_TRACER|DYNAMIC_FTRACE|TRACEPOINTS /boot/config-$(uname -r)必须开启的配置项包括配置项作用是否必须CONFIG_FTRACEFtrace 框架基础必须CONFIG_FUNCTION_TRACER函数跟踪必须CONFIG_DYNAMIC_FTRACE动态替换 nop强烈建议CONFIG_FUNCTION_GRAPH_TRACER函数图跟踪按需CONFIG_TRACEPOINTS静态跟踪点按需CONFIG_ENABLE_DEFAULT_TRACERS默认跟踪器按需CONFIG_STACK_TRACER栈跟踪按需如果CONFIG_DYNAMIC_FTRACE没开function tracer 一旦开启就会一直生效没法动态关闭性能影响会持续存在。这种情况下要么重新编译内核要么只用事件跟踪。3.2 可用跟踪器的查看与切换进入 tracefs 目录后available_tracers文件列出了当前内核支持的所有跟踪器。cat /sys/kernel/tracing/available_tracers # 典型输出blk function_graph wakeup_dl wakeup_rt wakeup function nopcurrent_tracer文件用于查看和设置当前激活的跟踪器。默认是nop表示不跟踪。切换到 function tracerecho function /sys/kernel/tracing/current_tracer切换到 function_graph tracerecho function_graph /sys/kernel/tracing/current_tracer注意切换跟踪器之前最好先清空缓冲区否则新旧数据混在一起分析起来很麻烦。清空命令是echo /sys/kernel/tracing/trace。3.3 过滤器的使用是高效跟踪的关键不加过滤地开启 function tracer输出量会大到无法阅读。set_ftrace_filter和set_ftrace_notrace是两个核心的过滤文件。# 只跟踪特定函数 echo vfs_read /sys/kernel/tracing/set_ftrace_filter # 跟踪某个模块的所有函数 echo :mod:ext4 /sys/kernel/tracing/set_ftrace_filter # 使用通配符 echo vfs_* /sys/kernel/tracing/set_ftrace_filter # 排除某些函数 echo schedule /sys/kernel/tracing/set_ftrace_notraceset_ftrace_filter支持通配符和模块名匹配这在调试驱动时特别有用。比如你写了一个叫mydev的模块直接echo :mod:mydev set_ftrace_filter就能把所有该模块的函数都纳入跟踪范围。对于事件跟踪过滤是通过events/目录下的filter文件完成的。每个事件都有自己的过滤表达式语法支持比较运算符、逻辑运算符和字段引用。# 只跟踪 pid 为 1234 的进程产生的 sched_switch 事件 echo next_pid 1234 /sys/kernel/tracing/events/sched/sched_switch/filter3.4 trace_pipe 与 trace 的区别trace文件是一个静态快照读取时会把当前缓冲区的内容全部输出但不会阻塞。trace_pipe是一个实时管道读取时会阻塞等待新数据适合配合cat或脚本实时消费。# 实时查看跟踪输出 cat /sys/kernel/tracing/trace_pipe # 事后查看缓冲区内容 cat /sys/kernel/tracing/trace实际使用中如果跟踪量很大trace文件可能在你读取之前就被新数据覆盖了。这时候要么调大缓冲区要么用trace_pipe实时抓取并重定向到文件。我通常的做法是先用trace_pipe抓一小段确认跟踪配置正确后再决定是否需要长时间抓取。4. 实操过程与核心环节实现4.1 场景一定位某个系统调用的内核执行路径假设你发现某个进程调用read()系统调用后延迟很高想看看内核里到底走了哪些函数、在哪里卡住了。第一步找到目标进程的 PID然后设置 function_graph tracer 并过滤到相关函数。cd /sys/kernel/tracing # 清空并设置跟踪器 echo trace echo function_graph current_tracer # 设置过滤只跟踪与 read 相关的 vfs 层函数 echo vfs_read set_ftrace_filter echo vfs_write set_ftrace_filter # 如果知道具体文件系统可以加上模块过滤 echo :mod:ext4 set_ftrace_filter # 开启跟踪 echo 1 tracing_on # 执行你的测试程序 # ... # 关闭跟踪 echo 0 tracing_on # 查看结果 cat tracefunction_graph 的输出格式是缩进的调用树每个函数后面跟着执行时间微秒。通过观察哪一层函数耗时最长就能快速定位到热点。比如你可能会看到vfs_read下面ext4_file_read_iter花了 200 微秒而其中ext4_mpage_readpages又占了 180 微秒那问题大概率出在块层或磁盘 I/O 上。实操心得function_graph 的输出量比 function tracer 大得多因为每个函数入口和出口都会记录。如果跟踪范围太宽缓冲区瞬间就满了。建议先用 function tracer 确认目标函数确实被调用了再切换到 function_graph 看细节。4.2 场景二用事件跟踪分析调度延迟调度延迟是内核性能问题里最常见的一类。Ftrace 提供了sched_switch、sched_wakeup、sched_wakeup_new等事件可以精确记录每次调度切换的时间戳和涉及的进程。cd /sys/kernel/tracing # 清空并关闭所有事件 echo trace echo 0 events/enable # 开启调度相关事件 echo 1 events/sched/sched_switch/enable echo 1 events/sched/sched_wakeup/enable # 设置过滤只关心特定进程 echo next_comm myapp events/sched/sched_switch/filter # 开启跟踪 echo 1 tracing_on # 运行测试负载 # ... echo 0 tracing_on cat trace输出里每一行都包含时间戳、CPU 号、当前进程、被切换进来的进程、优先级等信息。通过计算sched_wakeup到sched_switch之间的时间差就能得到唤醒延迟。如果延迟超过预期再结合sched_stat_runtime等事件看是不是 CPU 被其他任务占满了。4.3 场景三用 kprobe 动态跟踪任意函数Ftrace 的 kprobe 机制允许你在任意内核函数甚至函数内部的某条指令上动态插入探针不需要重新编译内核。这对于调试没有预埋 tracepoint 的代码路径特别有用。cd /sys/kernel/tracing # 在 vfs_read 入口插入 kprobe echo p:myprobe vfs_read kprobe_events # 查看已注册的 kprobe cat kprobe_events # 开启对应事件 echo 1 events/kprobes/myprobe/enable # 跟踪并查看 echo 1 tracing_on # ... 执行操作 ... echo 0 tracing_on cat trace # 清理 echo kprobe_eventskprobe 还支持获取函数参数和返回值。比如p:myprobe vfs_read file$arg1 count$arg2可以把第一个和第二个参数记录下来。返回值探针用r:前缀可以获取$retval。这个功能在排查“某个函数到底返回了什么错误码”时非常高效。注意kprobe 的语法和可用参数取决于内核版本和架构。x86_64 上$arg1到$argN对应寄存器传参但超过一定数量的参数可能取不到。另外在 kprobe 的处理函数里不能睡眠也不能访问可能缺页的用户态内存否则会导致内核崩溃。4.4 场景四用 trace-cmd 简化命令行操作直接操作 tracefs 文件系统虽然灵活但命令比较繁琐而且容易忘记清理。trace-cmd是一个用户态工具把常用的 Ftrace 操作封装成了更友好的命令行接口。# 安装以常见发行版为例 # apt install trace-cmd 或 yum install trace-cmd # 开始记录调度事件 trace-cmd record -e sched_switch -e sched_wakeup # 停止记录后查看 trace-cmd report # 只记录特定进程 trace-cmd record -P 1234 -e sched_switch # 使用 function_graph 跟踪特定函数 trace-cmd record -p function_graph -l vfs_read -l vfs_writetrace-cmd的好处是自动处理了缓冲区大小、事件启用、数据保存等细节生成的trace.dat文件可以用trace-cmd report或kernelshark图形化工具分析。对于需要反复跟踪、对比的场景用trace-cmd比手动操作文件系统效率高很多。4.5 场景五用 snapshot 保留关键时刻的现场有时候你只关心问题发生那一瞬间的内核状态而不是持续跟踪。Ftrace 的 snapshot 功能可以在不停止跟踪的情况下把当前缓冲区的内容“冻结”下来。cd /sys/kernel/tracing # 开启跟踪 echo function current_tracer echo 1 tracing_on # 在某个时刻触发快照 echo 1 snapshot # 查看快照内容 cat snapshot # 继续跟踪缓冲区不受影响这个功能在配合触发器使用时特别强大。比如你可以设置一个触发器当某个条件满足时自动拍快照这样就能精确捕获到问题发生的瞬间而不需要人工干预。5. 常见问题与排查技巧实录5.1 开启跟踪后系统变慢甚至卡死这是最常见的问题原因通常有几个跟踪范围太宽、缓冲区太小导致频繁覆盖、在中断上下文里跟踪了不该跟踪的函数。排查思路是先用最小范围的过滤器确认跟踪本身没问题再逐步扩大范围。如果系统已经卡死可以通过串口或 sysrq 强制关闭跟踪。# 紧急关闭所有跟踪 echo 0 /sys/kernel/tracing/tracing_on echo nop /sys/kernel/tracing/current_tracer避坑技巧在生产环境使用 Ftrace 之前先在测试环境验证跟踪配置。特别是 function_graph tracer它的开销比 function tracer 大一个数量级在高负载系统上可能直接导致服务不可用。5.2 trace 文件为空或只有表头可能的原因包括跟踪器没设置、tracing_on 是 0、过滤器把所有函数都排除了、缓冲区被覆盖了。按顺序检查这几个文件cat current_tracer cat tracing_on cat set_ftrace_filter cat buffer_size_kb如果set_ftrace_filter是空的function tracer 会跟踪所有函数输出量巨大但不会为空。如果过滤器设置了但匹配不到任何函数输出就会是空的。另外有些内核版本在tracing_on为 0 时仍然会记录部分事件但 function tracer 不会。5.3 kprobe 注册失败kprobe 注册失败通常有几个原因函数名拼写错误、函数被内联了、函数在.init段启动后已被释放、或者该架构不支持 kprobe。可以通过/sys/kernel/tracing/available_filter_functions查看所有可跟踪的函数名。grep vfs_read /sys/kernel/tracing/available_filter_functions如果函数不在这个列表里说明它被内联或者标记了notrace无法用 kprobe 跟踪。这时候可以尝试跟踪它的调用者或者用perf probe作为替代方案。5.4 时间戳不准确或时区不对Ftrace 的时间戳默认是相对于跟踪开始的偏移量单位是秒。可以通过trace_clock文件切换时钟源比如切换到global使用系统全局时钟或者uptime使用启动以来的时间。cat trace_clock echo global trace_clock如果发现时间戳和dmesg对不上检查一下trace_clock的设置。另外trace_options里的latency-format选项会改变时间戳的显示格式开启后会显示相对延迟而不是绝对时间。5.5 缓冲区大小调整后不生效buffer_size_kb的写入是 per-CPU 的实际总内存占用是写入值乘以 CPU 数量。如果写入失败可能是内存不足或者权限不够。另外某些内核版本在跟踪器激活时不允许调整缓冲区大小需要先切回nop。echo nop current_tracer echo 8192 buffer_size_kb cat buffer_size_kb5.6 常见问题速查表现象可能原因解决方法trace 文件为空tracing_on 为 0echo 1 tracing_on输出量太大过滤器未设置设置 set_ftrace_filter系统变慢function_graph 开销大改用 function tracer 或缩小范围kprobe 注册失败函数被内联查看 available_filter_functions时间戳混乱trace_clock 设置不当切换为 global 或 uptime缓冲区溢出buffer_size_kb 太小调大缓冲区或减少跟踪范围事件不触发事件未 enableecho 1 events/xxx/enable过滤器不生效语法错误检查 filter 文件内容6. 进阶技巧与组合使用思路6.1 用触发器实现自动化跟踪Ftrace 的触发器trigger功能可以在特定事件发生时自动执行动作比如开启/关闭跟踪、拍快照、打印栈回溯等。这在捕获偶发问题时特别有用。# 当 sched_switch 事件中 next_comm 为 myapp 时自动开启 function tracer echo next_comm myapp events/sched/sched_switch/trigger echo traceon events/sched/sched_switch/trigger # 当条件再次满足时关闭 echo traceoff events/sched/sched_switch/trigger触发器支持的动包括traceon、traceoff、snapshot、stacktrace、dump等。组合使用可以实现非常精细的跟踪策略比如“只在特定进程被调度时跟踪其他时间不跟踪”这样既捕获了关键信息又避免了缓冲区被无关数据淹没。6.2 用 stacktrace 查看调用栈在事件触发时打印调用栈可以快速了解代码的执行路径。stacktrace触发器就是干这个的。echo stacktrace events/sched/sched_switch/trigger开启后每次sched_switch事件触发时都会在 trace 输出里附带一段调用栈。这对于分析“这个事件是从哪个代码路径触发的”非常直观。不过要注意stacktrace 本身有性能开销不适合在高频事件上长期开启。6.3 用 hist 触发器做统计而不是逐条记录逐条记录事件在数据量大时很难分析。Ftrace 的 hist 触发器可以对事件字段做直方图统计直接输出聚合结果。# 统计 sched_switch 事件中 next_comm 的分布 echo hist:keysnext_comm:sorthitcount events/sched/sched_switch/trigger # 查看统计结果 cat events/sched/sched_switch/hist这个功能在分析“哪个进程被调度得最频繁”“哪个错误码出现得最多”这类问题时比逐条看 trace 高效得多。hist 触发器还支持sum、avg、max、min等聚合操作可以对时间字段做统计分析。6.4 用 trace-cmd 配合 kernelshark 做可视化分析kernelshark是 trace-cmd 的图形化前端可以把跟踪数据画成时间轴直观展示每个 CPU 上运行的进程、事件的时间分布、函数调用的嵌套关系。对于复杂的调度延迟问题图形化展示比看文本输出高效得多。# 记录数据 trace-cmd record -e sched_switch -e sched_wakeup -e irq # 用 kernelshark 打开 kernelshark trace.dat在 kernelshark 里可以缩放时间轴、筛选事件、查看每个事件的详细字段。我通常用它来快速定位延迟尖峰然后再回到命令行用 Ftrace 做精细分析。6.5 跟踪模块加载与卸载时的行为调试内核模块时模块的初始化和清理函数往往是问题高发区。可以用 Ftrace 跟踪模块加载过程中的函数调用。# 跟踪模块加载相关的内核函数 echo do_init_module set_ftrace_filter echo load_module set_ftrace_filter echo do_one_initcall set_ftrace_filter # 开启 function_graph echo function_graph current_tracer echo 1 tracing_on # 加载模块 modprobe mydev echo 0 tracing_on cat trace这样可以清楚地看到模块初始化函数被调用的顺序、每个初始化步骤的耗时、以及是否在某个环节卡住或返回错误。7. 我个人在实际操作中的几点体会Ftrace 最大的价值在于它把内核从一个黑盒变成了一个可以观察的系统。但工具越强大越需要克制。我见过太多人一上来就开 function_graph 跟踪所有函数结果系统直接卡死或者缓冲区里全是无关数据根本没法分析。正确的做法永远是先明确你要回答什么问题再选择最小的跟踪范围用过滤器把无关信息排除掉最后才开启跟踪。另一个体会是Ftrace 的输出需要结合内核源码来读。光看函数名和耗时你只能知道“哪里慢”但不知道“为什么慢”。只有对着源码看调用链才能理解每个函数在做什么、为什么会被调用、耗时是否合理。所以 Ftrace 和源码阅读是分不开的工具只是辅助真正的分析能力来自对内核代码的理解。还有一点不同内核版本的 Ftrace 接口和功能有差异。比如早期版本没有 hist 触发器tracefs 的挂载方式也不一样。在生产环境使用之前一定要确认目标内核的文档和实际行为。Documentation/trace/目录下的文档是最权威的参考虽然有些内容更新不及时但比网上大部分教程靠谱得多。最后分享一个小技巧如果你不确定某个跟踪配置会不会导致系统卡死可以先在虚拟机里试。用 QEMU 起一个和目标任务环境相近的内核在里面随便折腾确认配置没问题再上生产。这个习惯帮我避免了好几次可能的事故。
平方复杂度无法被常规优化消除｜TaoToken 统一 Key 通道实测)
