1. 先搞清楚 ftrace 到底在追踪什么聊 Linux 动态追踪绕不开 ftrace。我在排查线上内核态抖动、IO 卡顿、调度延迟这类看不见摸不着的问题时第一反应往往不是去装一堆花哨的工具而是先cd /sys/kernel/tracing看看里面躺着什么。ftrace 是内核自带的一套 tracing 框架名字来自 function trace最初就是用来记录内核函数调用流的后来长成了一整套包含静态 tracepoint、动态 kprobe/uprobe、延迟追踪器、直方图统计的观测基础设施。它不需要编译内核模块不需要重启业务甚至不需要额外的用户态工具一个echo加一个cat就能开工。它解决的问题很具体当你的服务 P99 突然从 8ms 涨到 60msperf 告诉你 CPU 在跑哪些符号但符不符合你的预期呢不知道。strace 告诉你系统调用花了多久但内核在某个 syscall 内部又走了哪些路径、在哪个函数上卡住了、有没有关中断、有没有被抢占也不知道。ftrace 补的就是这一层——把内核里谁调用了谁、各自花了多久、在哪个 CPU 上、有没有被干扰这些信息原样吐出来。适合谁来读我把它分成三类。第一类是内核和驱动开发者拿 ftrace 看自己写的 probe 函数有没有被正确调用、返回路径对不对。第二类是应用层性能工程师想在不改代码的前提下定位某个 syscall 的内核耗时分布。第三类是运维和 SRE需要在生产机上临时开一分钟观测抓完立刻关掉把文件捞下来慢慢分析。如果你属于第三类这篇文章里关于开销控制和开关顺序的部分建议重点看。ftrace 的影响范围其实比很多人想的大。它不仅是一个独立的调试文件系统还是内核里其他追踪技术的地基——kprobe 事件、uprobe 事件、perf 的内核采样、以及大量 eBPF 工具的函数挂载能力底层都借用了 ftrace 的插桩机制和 per-CPU 环缓冲。理解了 ftrace你看很多上层工具的行为就不再是黑盒。2. 底层骨架插桩点、环缓冲和 tracefs 目录2.1 编译期插桩与运行期改写追踪点是怎么挂上去的ftrace 能做到开着几乎没开销需要时才真正生效靠的是动态插桩这一手。内核在编译时通过-pg老版本或-mfentry现代 x86_64给几乎每个函数入口插一条跳转指令这条指令正常情况下指向__fentry__里的ret也就是空转一下立刻返回。等到你用set_ftrace_filter指定了要追踪的函数内核就把那个函数入口的指令原地替换成jmp ftrace_caller或者一条 nop 改回跳转改完还要sync_core()做指令缓存同步。这里有个非常关键的设计取舍为什么不用静态埋点因为内核函数几十万个静态埋点等于每个调用都多几条指令累加起来开销不小。动态改写只在需要的函数上生效没被选中的函数理论上只多一条 5 字节的 nop 或空跳现代 CPU 对这种指令几乎零代价。为什么用-mfentry而不是老的-pg因为-pg的插桩点在被调用函数的序言之后此时栈帧已经建立拿不到真实的调用者返回地址和原始参数-mfentry把插桩点放在函数最开头参数寄存器还没被破坏这也是后来 fprobe 能在 ftrace 基础上取到函数入参的前提。理解这一点你就明白为什么 ftrace 的 function tracer 只能给你函数名 时间戳 时长 调用者而拿不到参数——插桩点虽然靠前但 function tracer 本身的设计只读返回地址。要参数就得走 kprobe 或者 fprobe这是两条不同的路。2.2 per-CPU 环缓冲为什么 ftrace 采集几乎不锁ftrace 的写入端是每个 CPU 各自一个 ring buffer追踪事件发生时当前 CPU 只往自己那份里写不需要抢全局锁。这是它能扛住高频事件的根本原因。多个 CPU 的 buffer 在读取时由内核按时间戳归并你cat trace看到的是合并后的视图。这个设计带来的第一个副作用是内存占用按 CPU 数翻倍。buffer_size_kb这个值指的是单个 CPU 的缓冲大小4 核机器设 8192 实际吃掉的是 32MB 左右。你可以通过cat per_cpu/cpu0/stats看单核的overrun计数如果这个数在涨说明事件产生速度超过了写入速度旧数据正在被覆盖。生产上抓高频事件时overrun是最该盯的指标没抓到数据比抓错数据更可怕。第二个副作用是时间戳的可比性。默认trace_clock可能是local不同 CPU 的时钟基准有细微差异跨 CPU 对齐事件顺序时会看着别扭。我一般直接echo global trace_clock代价是一点点性能换来的是时间轴绝对一致。需要极致精度时切到x86-tsc但那个时间戳人类看不懂得配合工具换算。2.3 tracefs 目录速查先认清这些文件再动手进目录先别急着 echo把下面这张表过一遍能省掉大量我明明写了怎么没反应的时间。文件/目录作用踩坑提醒available_tracers当前内核编进去的 tracer 列表没有function_graph说明内核没开CONFIG_FUNCTION_GRAPH_TRACERcurrent_tracer当前激活的 tracer切 tracer 前最好先echo 0 tracing_ontracing_on总开关关它只停写入不清空 buffertrace读取 buffer 快照是复制语义读完 buffer 还在trace_pipe消费式读取阻塞式适合边跑边看读完就没了per_cpu/cpuN/trace单核视图排查 SMP 相关问题时比看合并视图清楚set_ftrace_filter只追踪哪些函数支持通配符和:mod:语法set_ftrace_notrace排除哪些函数和上面配合做减法set_graph_functionfunction_graph 的根函数只影响 graph 模式max_graph_depthgraph 最大展开深度不设会爆栈输出也读不完events/所有 tracepoint 和动态事件kprobe 注册后也出现在这里kprobe_events/uprobe_events动态探针注册接口注册失败先看error_logerror_log注册/配置错误日志最容易被忽略、最有用的文件instances/多实例隔离多任务并发观测时必用snapshot快照区配合 panic 抓现场注意不同内核版本路径不一样。老系统在/sys/kernel/debug/tracing4.1 之后 tracefs 独立挂载到/sys/kernel/tracing两个路径通常是同一个东西符号链接或 bind mount。写脚本时用mount | grep tracefs探测一下别写死。3. 三条主线函数流、调用图、事件追踪3.1 function tracer全局函数流怎么开才不炸最简单的开场是这样cd /sys/kernel/tracing echo 0 tracing_on echo nop current_tracer echo trace echo function current_tracer echo 1 tracing_on sleep 2 echo 0 tracing_on cat trace | head -100但你如果真在业务机上这么干两秒钟能灌进来上百万条记录buffer 直接被冲爆overrun飙到几十万抓到的全是碎片。所以正确姿势是先收敛范围。set_ftrace_filter的语法值得单独记一下# 单个函数 echo vfs_read set_ftrace_filter # 通配符注意是写入时由内核解析shell 不要展开 echo tcp_* set_ftrace_filter # 追加而不覆盖用双箭头 echo udp_* set_ftrace_filter # 按模块批量筛选 echo :mod:ext4 set_ftrace_filter # 做减法排除掉噪音函数 echo vfs_* set_ftrace_filter echo vfs_read set_ftrace_notrace写完立刻cat set_ftrace_filter确认生效了几个。有个细节很多人不知道set_ftrace_filter文件读出来的时候内核会把实际匹配到的函数名全部列出来如果写了通配符但一行都没输出说明一个都没匹配上八成是函数名写错了或者被内联优化掉了。想确认某个函数到底存不存在grep一下available_filter_functions这个文件列的是所有可插桩的函数几十万行别直接cat。还有一个高频需求是只看某个进程echo $$ set_ftrace_pid这个 pid 过滤器对 function、function_graph、事件追踪都生效是生产环境最有效的手段之一。默认情况下它只跟主线程如果目标是多线程程序记得把线程 id 也加进去或者用set_event_pid配合 events 那边的开关单独控制。有些内核支持在 pid 列表里写负数表示跟随这个进程 fork 出来的子进程实际上更稳妥的做法是打开options/function-fork让 fork 出的子任务自动加入追踪集合。这里插一条实操心得function tracer 的输出里每条记录格式是任务名-pid [CPU] 时间戳: 函数名 - 调用者。那个-后面的调用者信息极其有用能让你一眼看出是哪个上层路径进来的比翻源码快得多。另外options/func_stack_trace打开后被过滤到的每个函数都会附带一份内核栈定位谁调的效率翻倍代价是每次命中都要走一遍栈回溯开销不小只在函数少、频率低的时候开。3.2 function_graph把调用耗时拆到每一层function tracer 只告诉你这个函数被调用了function_graph 告诉你这个函数内部谁花了多少时间。这是定位性能问题时最直接的工具。echo 0 tracing_on echo nop current_tracer echo trace echo set_ftrace_filter echo ksys_write set_graph_function echo 4 max_graph_depth echo function_graph current_tracer echo 1 tracing_on # 触发一次写操作 echo 1 tracing_on输出大概长这样时长列是微秒# tracer: function_graph 1) | ksys_write() { 1) 0.243 us | rw_verify_area(); 1) 0.128 us | vfs_write(); 1) 2.871 us | }max_graph_depth一定要设。不设的话一个深层调用链可能展开几百层一次采样就把 buffer 吃光而且输出嵌套缩进能把人看晕。我通常从 3 或 4 开始觉得不够再往上加。另外三个选项值得记住options/funcgraph-proc显示进程名options/funcgraph-duration显示耗时列options/funcgraph-irqs显示中断边界有和-----标记前者是中断进入后者是延迟执行options/funcgraph-tail在返回行显示函数名方便长调用链里对应。set_graph_function和set_ftrace_filter的区别是前者决定从哪个函数开始展开调用图后者决定哪些函数被采样。图里出现的所有子函数都在采样范围内但采样范围受set_ftrace_filter约束如果你先设了 filter 只保留vfs_*那 graph 里非 vfs 开头的子函数就会缺失图形出现断点。注意function_graph 的开销显著高于 function tracer因为它要同时记录进入和返回两个点而且返回时还得做深度匹配。用它的时候建议配合profile模式——function_profile_enabled打开后trace_stat/function0会给出按函数聚合的调用次数和总耗时比翻几万行原始日志高效得多。echo 1 function_profile_enabled # 跑业务 echo 0 function_profile_enabled cat trace_stat/function0 | head -30这个聚合视图输出的Hit列是调用次数Time列是累计耗时排序后能立刻看出谁是大头。有时候几十万行 trace 看不出规律这个统计表三秒钟给你答案。3.3 事件追踪静态 tracepoint 与动态 kprobe/uprobe如果 ftrace 只能追踪函数它的价值大概只发挥了一半。events 这一层才是它变成通用观测平台的转折点。静态 tracepoint 是内核开发者预先埋好的钩子events/下面按子系统分目录cat available_events能列出全部。开启方式echo 1 events/sched/sched_switch/enable # 或者批量 echo sched/* set_event # 只清空事件不影响 tracer echo set_eventtracepoint 的最大价值是语义明确。比如sched_switch直接给你prev_comm、prev_pid、prev_state、next_comm、next_pid、next_prio你不用去猜。想加过滤条件也很直接echo prev_comm nginx prev_prio 100 events/sched/sched_switch/filterfilter 表达式支持、!、、、、||、~正则匹配。这个过滤发生在内核里进不了条件的事件压根不会写进 buffer对高频事件来说这是最有效的降噪手段比抓回来再 grep 强太多。静态 tracepoint 不够用时上 kprobe。它能在任意内核函数入口和返回处插探针并取出寄存器/参数# 入口探针 echo p:do_sys_open_p do_sys_open dfd%di fname%si flags%dx kprobe_events # 返回探针 echo r:do_sys_open_r do_sys_open ret$retval kprobe_events echo 1 events/kprobes/enablex86_64 用%di %si %dx %cx %r8 %r9对应前六个参数ARM64 用%x0到%x7。想要跨架构兼容用$arg1到$argN这种写法内核帮你换算寄存器。用户态函数的探针用 uprobe语法是p:名字 可执行文件路径:偏移量readelf -sW /path/to/app | grep my_func # 得到地址 0x401136 echo p:myu /path/to/app:0x401136 arg1%di uprobe_events echo 1 events/uprobes/enable偏移量要算上符号地址和文件加载基址的差值PIE 程序更麻烦得用/proc/pid/maps里的实际基址减去文件偏移。这块坑比较多如果是给业务方做临时观测我一般建议先用r:返回探针验证路径通不通再加参数字段。提示任何动态探针注册失败第一件事是cat error_log里面会明确告诉你语法错在哪、符号找不到还是参数格式不合法。这个文件被忽略的次数多到离谱。3.4 hist 触发器与合成事件把原始日志变成统计量抓了几十万行 trace 再导出来用 awk 统计是我早年常干的事效率极低。ftrace 其实自带聚合能力。# 统计每个 prev_comm 切出的次数按次数降序 echo hist:keysprev_comm:valshitcount:sorthitcount.desc events/sched/sched_switch/trigger # 记录耗时分布 echo hist:keyscommon_pid:valshitcount:sorthitcount.desc events/sched/sched_stat_runtime/trigger输出直接是按键聚合好的表格不用再处理。hist 还支持$common_timestamp做时间差计算配合合成事件可以算延迟量。合成事件的玩法稍复杂得先定义字段类型echo sched_lat u64 lat_ns synthetic_events echo hist:keysnext_pid:ts0$common_timestamp.usecs events/sched/sched_switch/trigger echo hist:keyscommon_pid:lat_ns$common_timestamp.usecs-$ts0:onmatch(sched.sched_switch).sched_lat events/sched/sched_wakeup/trigger echo 1 events/synthetic/sched_lat/enable上面这段的意思是唤醒时记录时间戳下一次被调度上 CPU 时算出时间差作为合成事件打出去。这本质上是用 ftrace 自带的脚本能力做了一个小型延迟分析器不需要写任何代码。我第一次配通的时候确实有点上头因为它把必须写 BPF 程序的边界往后推了一大截。4. 延迟类 tracer不追函数追被谁耽误了4.1 irqsoff 与 preemptoff找到那段被关中断的时间线上出现毫秒级抖动最常见的元凶是某段代码关了中断或者关了抢占。这类问题用函数流很难看出来因为抖动的表现为没跑追踪器本身也只能看到事件稀稀拉拉。ftrace 为此专门准备了延迟追踪器。echo 0 tracing_on echo nop current_tracer echo trace echo irqsoff current_tracer echo 1 tracing_on # 跑一段时间 echo 0 tracing_on cat tracing_max_latency cat tracetracing_max_latency记录的是观测期间最长的关中断时长单位微秒。trace里给的是那次最坏情况的完整现场从关中断开始到重新开中断结束中间调用了哪些函数、耗时多少一目了然。这个功能还有个响亮的名字叫 latency tracer本质是只记录最坏那一次所以 buffer 不会被冲爆跑多久都行。对应的还有preemptoff只关抢占、preemptirqsoff两者任一。要重置记录的最大值echo 0 tracing_max_latencywakeup追踪器则针对另一类问题任务被唤醒到真正上 CPU 跑了多久。RT 场景下这个指标很关键普通场景下如果这个值异常大说明调度延迟有问题可能是 CPU 太忙、可能是优先级反转、也可能是某个关抢占区间把调度器卡住了。wakeup_rt只看 RT 任务wakeup_dl看 deadline 任务按需选择。注意这几个 tracer 需要内核配置支持CONFIG_IRQSOFF_TRACER、CONFIG_PREEMPT_TRACER没有配置的话在available_tracers里根本看不到。用之前先确认别对着空列表纳闷。4.2 配合 stack trace 与 snapshot 抓现场单看最坏延迟的函数流有时还是不够因为你想知道是谁触发了这段关中断。这时候打开options/func_stack_trace被追踪到的函数会附上内核栈。还有一个更实用的组合是 snapshotecho 1 snapshot # 出问题后 cat snapshotsnapshot 是一块独立的 buffer 区域可以在关键时刻拍照。更妙的是配合CONFIG_BOOTTIME_TRACING做启动追踪或者在内核 panic 之前手动触发快照重启后从 pstore 里把快照捞出来。我见过一次偶发的驱动挂死就是用这个方法在 panic 前抓到现场定位到一个第三方模块在中断上下文里做了不该做的事。5. 生产环境落地的成本控制与问题排查5.1 开销估算与开关顺序ftrace 的开销不是零这点必须诚实。全量 function tracer 在函数调用密集的负载上我实测过的区间大概从个位数百分比到二十几个百分比不等取决于 CPU 型号、函数调用频度和 buffer 设置。一旦用set_ftrace_filter把范围收敛到几十个函数开销基本可以忽略。function_graph 因为要记两个点同等范围下大概是 function tracer 的两倍左右。所以生产上我遵循这套开关顺序基本不会出事# 1. 先关写入再改配置 echo 0 tracing_on # 2. 复位到 nop清掉之前的 tracer echo nop current_tracer # 3. 清空 buffer 和过滤器 echo trace echo set_ftrace_filter echo set_ftrace_notrace echo set_event # 4. 按需设置过滤条件 echo vfs_* set_ftrace_filter echo $$ set_ftrace_pid # 5. 最后切 tracer 并开写入 echo function current_tracer echo 1 tracing_on顺序反了会怎样先在开了 function tracer 的情况下写 filter那段时间里全量函数都在被记录buffer 瞬间被垃圾数据填满。先开tracing_on再改 tracer 同理。这类低级错误我在早期脚本里踩过不止一次。读数据也有讲究。cat trace是把 buffer 复制一份出来数据量大时会卡住当前 shellcat trace_pipe是消费式的读走的就没了适合长时间挂着采。文件落盘我一般用cat trace /tmp/ftrace_$(date %s).log不要用重定向直接跟trace_pipe跑一整天那个文件会涨到几个 G而且中间一旦断了前面就白抓了。5.2 常见问题速查表现象可能原因排查动作current_tracer写入报 Invalidtracer 名拼错或内核没编进去cat available_tracers对照filter 写了没输出函数被内联或不存在grep 函数名 available_filter_functionstrace 里overrun飙高事件速率超过写入速率加 filter、加 pid 限制、扩buffer_size_kbkprobe 注册失败语法、符号名、寄存器名不对cat error_loguprobe 无输出偏移地址错、程序是 PIE、没加载换r:返回探针验证、查/proc/pid/maps多任务互相覆盖共用一个全局配置用instances/建独立实例时间戳跨 CPU 对不齐用了local时钟echo global trace_clock追踪后业务变慢明显范围没收窄、graph 深度太大缩 filter、降max_graph_depth多实例这块值得单独说一句。两个人同时在一台机器上抓 trace会互相踩脚你切了 tracer我这边就断了。这时候用实例隔离mkdir /sys/kernel/tracing/instances/myjob cd /sys/kernel/tracing/instances/myjob # 这里有一套独立的 trace、current_tracer、events每个实例有自己独立的 buffer 和配置互不干扰代价是多占一份内存。团队协作排查线上问题时这个功能能省掉大量协调成本。5.3 用 trace-cmd 把重复劳动脚本化trace-cmd是 ftrace 的官方前端本质是把那些echo操作封装了一层好处是可复现、可传参、报告格式规整。# 录制指定函数最大深度 4 trace-cmd record -p function_graph -g ksys_write -l ksys_write --max-graph-depth 4 \ -F -- sleep 1 # 生成报告 trace-cmd report trace.dat | head -50 # 函数级统计 trace-cmd profile -i trace.dat多实例用trace-cmd record -B myinst其余操作带上-B就行。-F表示跟随命令执行命令结束自动停止录制这个特别适合做触发一次某个操作看内核走了什么的验证。我自己给一些项目写的自检脚本基本就是trace-cmd record加几行过滤条件新人拿到就能跑不用记那些文件路径。不过我还是建议把纯手写的echo流程过一遍。工具封装越厚出问题时你越不知道它在底下干了什么尤其在老内核上 trace-cmd 版本和内核 API 不匹配的时候能看懂error_log比会敲命令重要得多。6. 我踩过的几个坑和持续观测的思路第一个坑是忽略overrun。有次抓一个偶发卡顿录了半小时的数据分析时发现关键那一次根本没抓到因为事件太密旧的被覆盖了。从那以后我养成习惯采完先看per_cpu/cpu*/stats里的 overrun非零就重采宁可用更窄的过滤条件换一次完整数据。第二个坑是内联函数。想追一个自己写的辅助函数过滤器里怎么都匹配不到后来才意识到static inline加编译优化函数体早被揉进调用者了nm vmlinux里压根没有独立符号。这种情况只能追外层函数或者干脆用 kprobe 打在源码对应的指令位置。第三个坑是 trace 的时间和业务的时钟对不上。ftrace 用common_timestamp默认单位是纳秒输出格式受trace_options里的latency-format影响有时显示成秒级小数有时是纯数字。如果要把 trace 日志和业务日志做时间对齐最好统一用global时钟并确认单位否则会得出内核卡了 3000 微秒而实际上只是格式没看清的乌龙结论。长期观测方面我不建议在生产机上常开 ftrace。它更适合做有明确问题、有明确假设、短时间高强度采集的场景。真要常态化的指标监控应该把 ftrace 抓到的特征转成周期性采集的直方图事件或者干脆把分析方法固化成专门的采集程序。ftrace 提供的是显微镜不是全天候摄像头这个定位想清楚了用起来才不会有心理负担。如果后续还想往深里走方向有两个一是把 ftrace 和 BPF 结合用 fprobe 在 ftrace 的插桩点上挂 BPF 程序既享受 ftrace 的低开销插桩又获得 BPF 的灵活处理能力二是深入研究 tracefs 的实例机制和触发器语法把常见的排查套路做成一套可复用的配置文件出问题时一行命令加载完事。这两条路我都走过一段前者上限更高后者见效更快具体选哪个看你面对的问题类型。