1. 先说清楚 ftrace 到底解决什么问题遇到一次揪心的性能事故比看一百篇文档都管用。我记得有一回线上的一台机器 CPU 使用率突然飙升到 90% 以上load 也跟着往上窜。top 一看内核线程 kworker 占了大量 CPU但具体是哪个内核函数在忙、哪个驱动在疯狂调度完全看不到。那时候用过 perf top能看出来大概是在某个驱动模块里但再往下钻就抓瞎了——用户态工具到内核态就断掉了。后来靠 ftrace 把函数调用链拉出来问题瞬间清楚了是某个网卡驱动在中断上下文里做了太重的事务处理频繁触发软中断把 CPU 吃满了。那是我第一次真正意识到ftrace 不是拿来炫技的它是你排查内核态性能问题时的“最后一道防线”。ftrace 是 Linux 内核自带的跟踪框架从内核 2.6.x 时代就开始有了发展到现在已经是内核里最成熟、最基础的追踪设施之一。它的核心能力简单粗暴记录内核里函数被调用的时间、次数、调用关系以及某个事件发生的时机和上下文。它不需要改内核源码不需要重新编译内核只要内核开启了相关配置项你就能在运行时动态地跟踪内核行为。这篇文章是“Linux 性能实战”系列的第 19 篇我们专门讲 ftrace 的入门路径。适合谁看适合三类人一是被内核态性能问题折磨过的应用开发者和运维工程师二是刚开始学内核跟踪、想找一个低成本入口的学生或初级内核开发者三是做性能调优但手里只有用户态工具、想进一步深入内核的专业人士。不需要你先成为内核专家只要会用命令行、能读懂函数名就可以上手。我不打算把 ftrace 的每个细节都铺开讲一遍那会变成又一篇“内核文档翻译”。我更想把从零开始的实际操作路径、每一步为什么要这么做、输出结果怎么读、常见坑在哪都整理出来。看完之后你至少能做到拉出一次内核函数调用轨迹定位到可疑的函数热点知道下一步该往哪个方向查。2. 准备工作确认内核支持、挂载 tracefs2.1 确认内核编译选项ftrace 虽然长期存在于内核里但具体功能取决于编译时的配置。绝大多数发行版默认内核都打开了 ftrace但嵌入式和定制内核就不一定了。动手之前先确认一下不然后面全是坑。检查方法很简单看内核配置# 确认 ftrace 相关配置是否打开 zcat /proc/config.gz | grep FTRACE # 如果 /proc/config.gz 不存在试试这个路径 grep FTRACE /boot/config-$(uname -r)正常发行版内核的输出里会有一串CONFIG_FTRACEy CONFIG_FUNCTION_TRACERy CONFIG_FUNCTION_GRAPH_TRACERy CONFIG_STACK_TRACERy CONFIG_DYNAMIC_FTRACEy CONFIG_FTRACE_SYSCALLSy CONFIG_EVENT_TRACINGyCONFIG_DYNAMIC_FTRACE 尤其重要。它允许内核在运行时有选择地启用和禁用函数的跟踪而不是编译期把所有函数都打上跟踪点——前者对性能的影响几乎可以忽略后者会产生巨大的开销。我用过一个老内核没开动态 ftrace随便 track 一个函数整个系统就慢得没法碰后来发现就是这个配置没开。如果这些配置项是 y 或 m恭喜你环境就绪。如果是 n而且你没法换内核那这篇文章后面的内容就只能看个思路实操得换机器了。2.2 挂载 tracefs 文件系统ftrace 的操作接口是一个虚拟文件系统 tracefs一般会自动挂载到 /sys/kernel/tracing老版本内核是 /sys/kernel/debug/tracing。确认方式# 直接查看是否已经挂载 mount | grep tracefs ls /sys/kernel/tracing 2/dev/null || ls /sys/kernel/debug/tracing如果没挂载手动挂一下# 手动挂载 tracefs mkdir -p /sys/kernel/tracing mount -t tracefs nodev /sys/kernel/tracing注意/sys/kernel/debug/tracing 是 debugfs 挂载后的老路径。新内核推荐用 tracefs两者理论上指向同一套接口但 tracefs 更干净不依赖 debugfs。我建议统一用 /sys/kernel/tracing。挂载之后你会看到一堆文件和目录它们就是 ftrace 的控制台。第一次看到的人会觉得眼花缭乱其实核心操作就集中在几个文件上。2.3 tracefs 目录结构速览我把最常用的几个文件和目录列出来先混个脸熟路径作用available_tracers列出当前支持的所有 tracer比如 function、function_graph、nop 等current_tracer当前激活的 tracer写入 function 或 function_graph 开启跟踪写入 nop 关闭tracing_on总开关1 表示打开0 表示暂停记录trace跟踪结果缓冲区读取内容就是当前抓到的日志trace_pipe带消费功能的日志出口读完即清适合持续读取和管道处理set_ftrace_filter函数过滤器只跟踪你写入的函数名set_ftrace_notrace反向过滤器排除某些函数比如你不关心 schedule 相关的调度噪声available_filter_functions列出所有可以被动态跟踪的内核函数events/内核事件跟踪目录比如 sched、irq、timer 等子系统事件都在这下面kprobe_events动态 kprobe 接口可以在任意指定地址或函数上插桩stack_trace记录最近一次触发栈追踪时的调用栈配合栈追踪功能使用先不用全记住对照着实操走两遍就熟了。我自己的习惯是只记四个核心文件的用法current_tracer、set_ftrace_filter、trace、tracing_on。搞定这四个大部分排查场景已经能应付了。3. 第一个实战用 function tracer 拉出函数调用轨迹3.1 开启 function tracer 的四步操作function tracer 是最基础的跟踪器它记录哪些内核函数被调用了、按什么顺序调用的。第一次跑通它的兴奋感不亚于小时候第一次烧录单片机点灯。操作其实就是一个标准套路四步cd /sys/kernel/tracing # 1. 先把当前跟踪器重置为 nop清空状态 echo nop current_tracer # 2. 清空 trace 缓冲区去掉历史数据 echo trace # 3. 打开总开关 echo 1 tracing_on # 4. 指定要跟踪的函数比如想看磁盘 IO 相关的路径 echo blkdev_direct_IO set_ftrace_filter # 5. 设置跟踪器为 function echo function current_tracer顺序上有一个讲究应该先设置过滤器再启用跟踪器。因为 current_tracer 写入 function 后内核立刻开始记录。如果顺序反了你会抓进来一堆没过滤的噪声还得重新清空再来一遍倒也不是不行但多折腾。跑完之后关闭跟踪和读取日志# 关闭总开关 echo 0 tracing_on # 读取跟踪结果 cat trace | head -50为什么先关掉 tracing_on 再看 trace因为如果你开着它又去读 trace读取动作本身也会触发内核函数的调用日志里会混入你自己造成的噪声。虽然用 head 读几行影响不大但做精细分析时清掉自噪声是良好的卫生习惯。3.2 读懂 trace 输出的每一列第一次看到 trace 输出时很多人会懵。类似这样# tracer: function # # entries-in-buffer/entries-written: 42/42 #P:8 # # TASK-PID CPU# TIMESTAMP FUNCTION # | | | | | bash-2317 [003] 12345.678901: blkdev_direct_IO - do_blockdev_direct_IO手动逐个解释一下。TASK-PID 是发起调用的进程名和进程号CPU# 是运行在哪个 CPU 上TIMESTAMP 是调用的时间戳单位是秒从系统启动开始算FUNCTION 那列是函数名加上调用来源——箭头左边是当前被调用的函数右边是它的调用者。上面这个例子含义就是进程 bash 的 PID 2317 在 CPU 3 上在 12345.678901 秒这个时刻调用了 blkdev_direct_IO而它的上一级调用者是 do_blockdev_direct_IO。箭头语法读起来像一个调用链往回推。实际操作中function tracer 的原始输出信息量极大但肉眼很难看出“瓶颈”在哪。它更多是用来做两层事一是确认某个代码路径确实被执行到二是结合过滤条件看某个慢函数的调用频次和上下文。真要定位热点还得靠 function_graph 或者 events。3.3 用过滤器聚焦目标不然会被噪声淹没function tracer 最大的坑是如果不加过滤条件抓日志抓到你机器卡死。系统里内核函数调用频率是每秒数百万次的量级trace 缓冲区很快就被写满而且 tracer 本身也会拖慢系统。解决办法就是善用 set_ftrace_filter。最基本的用法是直接写函数名也支持简单的通配符# 跟踪所有以 tcp_ 开头的函数 echo tcp_* set_ftrace_filter # 追加过滤条件注意是 追加不是覆盖 echo kfree set_ftrace_filter # 查看当前过滤列表 cat set_ftrace_filter还有一个特殊的文件 available_filter_functions列出当前内核能被动态 ftrace 跟踪的全部函数。你可以用它来确认函数名是否拼写正确# 查找跟 ext4 相关的函数有多少 grep ext4 /sys/kernel/tracing/available_filter_functions | wc -l单函数跟踪的时候function tracer 能帮你确认某个路径是否被执行但若要分析执行耗时和调用关系function_graph 明显更适合。我们下一个章节里用 function_graph 做一个更贴近真实问题的排查演练。4. 贴近实战用 function_graph 分析一次 write 系统调用的完整路径4.1 function_graph 和 function 的区别function tracer 是“单帧照片”记录每一个函数调用的瞬间function_graph 则是“视频录像”不仅记录函数调用还能体现出函数的嵌套层级、调用耗时、子函数调用关系。它的输出用缩进来表示调用深度进入函数标一个“}”退出函数标一个“}”后面跟着调用耗时微秒。这正是排查内核态性能瓶颈时最需要的哪个函数里最耗时是一眼就能看出来的。开启方式几乎一模一样只是把 current_tracer 写成 function_graphcd /sys/kernel/tracing echo nop current_tracer echo trace echo 1 tracing_on # 还是先过滤缩小范围 echo do_sys_open set_ftrace_filter echo function_graph current_tracer # 做一些触发操作比如在这台机器上打开一个文件 # 然后关闭跟踪 echo 0 tracing_on cat trace | head -1004.2 读 function_graph 的输出输出大概是这样的结构1) | do_sys_open() { 1) | getname() { 1) 0.122 us | getname_flags(); 1) | } 1) 0.083 us | get_unused_fd_flags(); 1) | do_filp_open() { 1) | path_openat() { 1) | link_path_walk() { 1) 0.110 us | inode_permission(); 1) 0.091 us | walk_component(); ... 1) 0.180 us | } 1) 0.520 us | } 1) 1.021 us | } 1) 0.054 us | fd_install(); 1) 2.830 us | }每个函数的进入和退出一目了然。最底层的“} 2.830 us”表示整个 do_sys_open 调用总共耗时 2.83 微秒它的内部嵌套了 getname、do_filp_open、fd_install 等多个子调用。如果哪一层函数耗时异常高沿着缩进往下看基本就能锁定是它内部哪个子函数拖了后腿。4.3 一个完整的排查演练定位 open 调用为什么慢假设你发现一个服务频繁打开文件很慢但不知道慢在内核哪里。用下面这套流程# 只跟踪 open 相关的内核路径 echo do_sys_open set_ftrace_filter echo function_graph current_tracer echo 1 tracing_on # 在另一个终端产生压力循环打开文件 for i in $(seq 1 100); do cat /etc/hostname /dev/null; done # 关闭并查看 echo 0 tracing_on cat trace | grep -E do_sys_open|path_openat|link_path_walk | head -50通过观察每一层的耗时就能看出延迟是出在路径解析link_path_walk、权限检查inode_permission还是文件系统具体实现ext4 相关函数上。这套方法同样适用于排查 read、write、connect、accept 等等系统调用。提示function_graph 带来的开销比 function tracer 更大生产环境最好不要长时间开启。我的经验是打开几秒钟抓一个快照就够了常年开着会放大应用延迟反而影响判断。5. 更实用的路径内核事件跟踪events5.1 events 比 function tracer 更适合日常排查function tracer 和 function_graph 虽然强大但有一个共同毛病记录的是“所有调用”过滤条件只能缩小范围信息量还是太大。而且它们依赖函数名匹配函数名的变化、inline 优化都会影响跟踪效果。内核事件跟踪tracepoints则不同。它是在内核关键路径上预先埋好的“探针”比如进程切换、中断触发、定时器到期、块设备 IO 完成这些事件语义明确、数据结构化、开销远小于 function tracer。日常性能排查我优先用 events只有当 events 不够用、需要钻到具体函数实现时才上 function tracer。事件目录就在 /sys/kernel/tracing/events/ 下面按子系统分类ls /sys/kernel/tracing/events/ # 输出类似 # block compaction enable header_event header_page irq kmem kprobes lock mmiotrace napi net oom power printk rcu rpm sched signal sock syscalls task timer tlb udp vmscan workqueue xen writeback常用的事件分类子系统典型事件使用场景schedsched_switch, sched_wakeup, sched_stat_runtime调度延迟、线程切换分析irqirq_handler_entry, irq_handler_exit, softirq_entry中断风暴、软中断瓶颈syscallssys_enter_open, sys_exit_read 等系统调用追踪blockblock_rq_issue, block_rq_complete磁盘 IO 延迟分布kmemkmalloc, kfree, mm_page_alloc内存分配热点timertimer_expire_entry, timer_expire_exit定时器堆积5.2 实战案例抓一次进程切换事件排查调度延迟时最常用的是 sched_switch 事件。开启方式如下cd /sys/kernel/tracing # 先关闭其他跟踪器 echo nop current_tracer # 启用 sched_switch 事件 echo 1 events/sched/sched_switch/enable # 清空缓冲区再开启 echo trace echo 1 tracing_on # 等几秒制造一些负载 sleep 3 echo 0 tracing_on cat trace | head -30输出大概长这样idle-0 [000] 12345.678902: sched_switch: prev_commswapper/0 prev_pid0 prev_prio120 prev_stateR next_commkworker/0:1 next_pid57 next_prio120这一行的事件含义是idle 进程PID 0让出 CPU切换到了 kworker/0:1 这个内核工作线程。prev_stateR 表示它离开 CPU 时是 Running 状态因为被抢占如果换成 S 就是可中断睡眠D 则是不可中断睡眠——这是排查 IO 卡顿极其重要的线索。5.3 事件过滤器只抓你关心的条件events 支持按字段过滤这点比 function tracer 灵活得多。比如你只关心 PID 为 1234 的进程发生了切换# 在 sched_switch 事件上追加过滤条件 echo next_pid 1234 || prev_pid 1234 events/sched/sched_switch/filter # 查看当前过滤条件 cat events/sched/sched_switch/filter过滤器支持 、!、、|| 以及简单的数值比较。这种“按需抓取”的方式能把信息量降到一个非常可控的范围。我当时排查线程频繁切换的问题就是靠这个过滤方式把目标线程的切换事件独立抓出来再用后面的 trace-cmd 做时间线分析。6. 效率工具trace-cmd 让 ftrace 如虎添翼6.1 为什么需要 trace-cmd直接操作 tracefs 文件系统有一个痛点手动 echo 来 echo 去效率太低而且多个事件、多个过滤条件组合起来shell 脚本会写得又长又乱。trace-cmd 是内核社区官方维护的命令行封装工具把上面那些繁琐的 echo 操作统一成一行命令。Debian/Ubuntu 系安装sudo apt install trace-cmdRHEL/CentOS 系sudo yum install trace-cmd6.2 record 和 report 两个核心命令trace-cmd 最常见的用法是 record 录制 report 解析# 录制 3 秒的 sched_switch 事件 trace-cmd record -e sched_switch -e sched_wakeup sleep 3 # 这个命令会生成 trace.dat 文件然后解析它 trace-cmd report trace.dat | head -50整体替代了手动操作 tracefs 的整套流程。更妙的是trace-cmd 可以同时监听多个事件还能指定 CPU# 同时监听中断和调度事件只记录 CPU0-CPU3 trace-cmd record -e irq -e sched -c 0-3 sleep 5 # 带函数图录一段 trace-cmd record -p function_graph -l do_sys_open sleep 2-p 参数直接指定 tracer 类型-l 指定过滤器函数。6.3 用 trace-cmd 和 KernelShark 做可视化分析如果抓到的数据量大、需要交互式分析KernelShark 是一个不错的配套工具。它是 kernel 官方提供的图形界面程序直接打开 trace.dat 文件能按 CPU、进程、事件类型做时间线展示。排查跨 CPU 调度延迟、中断争抢等问题时可视化时间线比看文本效率高很多。安装方式sudo apt install kernelshark打开方式kernelshark trace.dat它的界面不复杂左侧是事件列表中间是时间线右侧是事件详情。我一般先用 trace-cmd record 抓数据然后导到 KernelShark 里来回拖动时间窗口寻找异常点确定大概范围后再回到命令行用过滤条件深挖。7. 实战复盘一次真实的 CPU 飙升排查前面讲了不少命令和概念真正把这些串起来才能体现价值。讲一个最近的排查案例完整走一遍流程。7.1 现象与初步判断一台运行容器服务的物理机CPU 使用率突然从 20% 涨到 85%load 同步飙升到 30 左右。业务表现是接口响应变慢但还没完全不可用。top 看到的结果是 ksoftirqd 进程占用大量 CPU同时软中断占比si接近 40%。初步判断是软中断出了问题。软中断通常是网络收包、块设备处理、定时器触发的。需要进一步确认是哪个软中断类型、由哪个中断源引起的。7.2 用 ftrace 定位问题路径第一步先用 events 看软中断类型cd /sys/kernel/tracing echo 0 events/enable echo nop current_tracer # 开软中断相关事件 echo 1 events/irq/softirq_entry/enable echo 1 events/irq/softirq_exit/enable echo trace echo 1 tracing_on sleep 5 echo 0 tracing_on # 统计软中断类型分布 cat trace | awk {print $NF} | sort | uniq -c | sort -nr结果里 NET_RX 占了绝对大头说明是网络收包引起的软中断风暴。但还不能完全确定是哪个网卡或哪个进程在收。第二步用 function_graph 跟踪 napi_poll 这个函数——它直接干的事就是网卡收包后的轮询处理echo nop current_tracer echo trace echo napi_poll set_ftrace_filter echo function_graph current_tracer echo 1 tracing_on sleep 3 echo 0 tracing_on cat trace | head -200从 function_graph 的嵌套输出里发现 napi_poll 内部绝大多数时间花在了 tcp_ack 相关的处理上再结合网络连接数、队列长度指标最后定位到是一个业务的健康检查请求太过频繁在连接数暴涨之后引起了接收路径的调度风暴。调整了健康检查频率、聚合请求之后CPU 立刻下来了。7.3 从这次排查里沉淀的经验回头看ftrace 在整个过程中承担的角色很清晰它没有直接告诉我“为什么那么多包”但它告诉我“这些包在内核里是怎么被处理的、处理路径上的热点在哪”。排查性能问题就像剥洋葱用户态工具剥掉一层perf 剥掉一层到了内核深处就轮到 ftrace 上场了。另外一个经验是对“开多大范围的跟踪”的把握。第一次我直接 function_graph 不加过滤机器瞬间卡到 SSH 都连不上后来学会了“小步快跑”先用 events 缩小范围再用函数过滤精确跟踪每一步都是小范围、短时间、快速关闭。8. 常见坑与排查技巧实录8.1 权限问题Permission deniedtracefs 里的文件要求 root 权限。普通用户直接写会 Permission denied。临时方案是 sudo长期用可以加一个专门的跟踪组成员# 以 root 执行 mkdir -p /sys/kernel/tracing chown -R root:ftrace /sys/kernel/tracing usermod -aG ftrace your_username然后重新登录一次your_username 就能直接操作了。这个方案比每次都 sudo 方便很多特别是你要写脚本反复跑跟踪的时候。8.2 trace 文件被占用写不进去有时候你会遇到 swapper/0 或者 kworker 进程一直在写 trace你 echo nop 之后缓冲区还在涨。这是因为你的某个 shell 还在开着 tracing_on或者没把 current_tracer 切回 nop。处理办法# 先强制停掉写入 echo 0 tracing_on echo nop current_tracer echo 0 events/enable echo trace注意顺序先停 tracing_on 再切 nop避免在切换的间隙又记录一堆噪声。8.3 函数名匹配不上的问题你在 set_ftrace_filter 里写了一个函数名但发现 trace 里什么都没抓到。原因通常是函数名拼写有误或在新内核里改名了函数被内联inline了没有独立的调用点函数本身很少被调用短时间没触发先 check 一下grep your_function /sys/kernel/tracing/available_filter_functions如果没有输出说明这个函数不可被动态 ftrace 跟踪。换一个上级函数或者用 kprobe 在任意地址上插桩。8.4 跟踪开启后系统明显变慢这是动态 ftrace 正常的副作用。function_graph 全量开启性能开销可以达到 10% 到 50%具体取决于内核版本和工作负载。应对办法用 set_ftrace_filter 把跟踪范围压缩到最小尽量缩短跟踪时间抓完立刻关用 -p function 而不是 -p function_graphfunction 的开销远小于 function_graph生产环境上我的习惯是所有跟踪时间控制在 5 秒以内抓完立即关。如果一次没抓到关键信息调整过滤器再来一次而不是开着等。8.5 怎么看 trace 日志里的事件字段事件日志格式通常包含公共字段TASK-PID CPU# TIMESTAMP和事件专属字段。遇到读不懂字段的情况可以直接看事件定义cat /sys/kernel/tracing/events/sched/sched_switch/format这个 format 文件里会把每个字段的类型、名称、含义写清楚。这也是 ftrace 设计得不错的一处所有事件都自描述。8.6 快速速查表目标使用的接口关键文件/命令跟踪函数调用function tracercurrent_tracer set_ftrace_filter分析函数耗时function_graphcurrent_tracer set_ftrace_filter跟踪调度事件sched eventsevents/sched/sched_switch/enable跟踪中断事件irq eventsevents/irq/softirq_entry/enable跟踪系统调用syscalls eventsevents/syscalls/sys_enter_*/enable动态插桩任意函数kprobekprobe_events 接口一键录制解析trace-cmdtrace-cmd record report9. 下一步从入门到能实战的进阶方向到这里ftrace 的入门链路已经打通了。你可以用 function tracer 看调用路径用 function_graph 看耗时分布用 events 看结构化事件用 trace-cmd 提升操作效率。如果后面想深入有几个明确的方向可以继续走。第一个是 kprobe/uprobe 动态插桩。ftrace 的函数跟踪只能跟踪可被识别的内核函数但实际排查中经常需要跟踪某个结构体字段、某个指令地址或者跟踪用户态程序的函数。kprobe 允许你在任意内核地址插入探针uprobe 则针对用户态程序。两者结合起来几乎可以在整个系统上“为所欲为”。第二个是跟踪延迟的利器 latency tracer。内核内置了 irqsoff、preemptoff、wakeup 等专用 tracer用来排查最大关中断时间、最大抢占关闭时间、最大调度延迟。这类问题用 function_graph 很难看但专用 tracer 一行命令就能出结果。排查实时性、稳定性问题时会非常有用。第三个是把 ftrace 和 perf、eBPF 结合起来用。ftrace 的强项是细粒度内核路径追踪perf 强项是采样统计和硬件计数器eBPF 强项是灵活编程和低开销聚合。三者不是竞争关系而是互补。实际项目中我先用 perf 找热点方向再用 ftrace 深入路径最后用 eBPF 做低开销的线上监控。每层工具都有自己的位置。我个人在实际操作中的体会是ftrace 的价值不在于它多“高级”而在于它把内核的运行真相透明地摆在你面前。很多性能问题看起来神秘莫测其实只要能把调用路径看清楚、把耗时分布量出来问题就解决了一半。入门 ftrace 并不难难的是养成“先缩小范围再抓取、抓完就关、带着具体问题看数据”的习惯。希望这篇实战笔记能帮你少走一些我当年走过的弯路。