2026/10/27 13:01:12

Linux ftrace动态追踪:tracefs、function_graph与内核性能排查

Linux ftrace动态追踪:tracefs、function_graph与内核性能排查 Linux 动态追踪这个词很多时候被讲得很玄好像非得挂上 eBPF、非得装一套完整的观测栈才叫“追踪”。真到现场你会发现最可靠的那套东西一直安静地躺在内核里——ftrace。我第一次被它救是在一台不方便装任何第三方工具链的机器上某个外设驱动加载偶尔要八百多毫秒日志干干净净往生产内核里塞打印又不敢。当时手上只有 tracefs 那几个文件靠 function_graph 一层层往下看二十分钟锁定了位置问题出在一段轮询硬件就绪标志的循环里用的是固定延时而不是带超时的等待。从那以后我的排查顺序就改了先看 ftrace 能给什么再决定要不要上更重的方案。这篇不打算写成手册翻译。我想讲的是ftrace 这套东西到底由哪几块拼起来、每块解决什么问题、开起来之后输出怎么读、读的时候哪些地方最容易看走眼、开销到什么程度还敢在线上用。适合已经能登机器敲命令、但每次看到current_tracer和events/就犯怵的人也适合用了很久 perf但没系统摸过内核自带追踪底座的人。1. ftrace 不是“一个工具”而是内核自带的一整套追踪底座很多人对 ftrace 的第一印象是“那个能打印所有函数调用的东西”这个印象不算错但把它当工具看会限制你。它的本体是内核源码树里kernel/trace/那一整块子系统对外只暴露一个文件系统接口也就是 tracefs。你在命令行敲的每一个echo本质都是在给这个子系统改配置、开开关。理解这一点很关键因为它的能力是分层的不是并列的几个功能。最底下是统一的 per-CPU 环形缓冲区所有数据最终都写进这里往上一层是钩子层包括编译期插进去的函数调用钩子、静态 tracepoint、动态的 kprobe/uprobe再往上是tracer 层function、function_graph、各种 latency tracer 都是在这一层做的不同“采样策略”最上面是触发与聚合层hist trigger、synthetic event 这些让你在内核里就把统计做完不用把海量原始记录搬出来。我把这个分层画成文字是因为它能解释掉 90% 的困惑。比如你纳闷“为什么 function_graph 的输出里能夹着 sched_switch 事件”答案就是它们写的是同一个 buffer比如你不理解“为什么设了 buffer_size_kb 还是丢数据”答案在 per-CPU 那层的模型上。后面每一章其实都在拆这几层。1.1 编译期那一下钩子是怎么塞进每个函数里的1.1 编译期那一下钩子是怎么塞进每个函数里的要让 function tracer 能知道“函数被调用了”编译器必须配合。老一点的实现是给每个函数插一个mcount调用靠-pg编译选项后来换成了-fpatchable-function-entry在函数入口留出几个 NOP 的位置运行时再把 NOP 热补丁成跳转指令这就是dynamic ftrace。这个演进带来的最大变化是不开追踪的时候开销几乎为零——NOP 就是 NOP。这件事对你有什么实际意义两个。第一只要内核配了CONFIG_DYNAMIC_FTRACE你可以放心地在生产内核里保留这套能力不用为了“万一要查问题”而专门编译一个调试内核。第二一旦你把current_tracer从nop改成function那几万个 NOP 会在一瞬间全部被改写成跳转这个动作本身就有成本所以不要在高频路径上反复开关 tracer要么一次性开到位要么干脆用 instance 隔一个独立的 buffer 出来。还有个坑值得提前说不是所有函数都能被追踪。标了notrace的函数、部分内联掉的函数、以及编译器优化掉的函数都不会出现在available_filter_functions里。你写了过滤规则却没生效第一件事就是去这个文件里grep一下确认目标函数到底在不在名单上而不是怀疑语法写错了。1.2 tracefs 里那几十个文件按四层能力归类就清楚了第一次lstracefs 目录的人基本都会被劝退几十个文件平铺在一起看不出结构。我习惯把它们按上面说的四层归类找文件的速度会快很多。层代表文件/目录作用缓冲区层buffer_size_kb、buffer_total_size_kb、trace_clock、trace、trace_pipe、per_cpu/控制容量、时间基准以及怎么把数据取出来钩子层available_filter_functions、set_ftrace_filter、set_ftrace_notrace、kprobe_events、uprobe_events、events/决定“哪些点被挂上钩子”tracer 层available_tracers、current_tracer、tracing_on、max_graph_depth、tracing_thresh决定“钩子触发后记录什么、记多细”触发层events/*/*/trigger、synthetic_events、hist把原始记录在核内聚合成结论这张表建议存下来。你会发现绝大多数“我要查 X 该动哪个文件”的问题都能在这四行里找到答案。比如“我只想看某个进程”那是钩子层的set_ftrace_pid“我想知道某函数的耗时分布”那是触发层的 hist trigger而不是去翻trace。1.3 和 perf、eBPF 的边界在哪里经常被问都有 perf 了为什么还要 ftrace我的回答一般分三种情况。第一种是环境限制。有些机器内核裁得很干净perf 用户态工具没装甚至perf_event_open被策略挡掉但 tracefs 通常还在只要没关CONFIG_TRACEFS。这种时候 ftrace 是唯一能立刻上手的选项而且它不需要编译、不需要装包、不需要额外权限以外的依赖。第二种是问题形态。如果你要问的是“这个函数被谁调的、调用链长什么样、每一层花了多久”function_graph 的输出直观程度至今没有对手perf 的 callgraph 采样在短时、低频的路径上经常采不到而 function_graph 是全量记录一次就够。第三种是成本和精度。全量记录意味着开销高这正是 ftrace 的短板。函数调用密度大的场景下functiontracer 的开销量级可能到两位数百分比function_graph更重。所以我的习惯是先用 ftrace 定位到具体函数和大致路径再用 perf 或采样类手段做长时间、低开销的量化统计。两者不是替代关系是先后关系。eBPF 则是另一条线它强在可编程和低开销的聚合但入门门槛、内核版本依赖、以及某些环境下的加载限制都是现实问题。我见过太多人一上来就写 BPF 程序结果卡在权限和版本上半天其实那个问题用events/加一个 hist trigger 五分钟就能出结论。2. 三分钟跑通 function tracer但别急着读输出跑通这件事本身没有任何难度难的是跑通之后你怎么判断自己看到的东西是可信的。这一章先把最短路径走一遍然后把过滤和隔离这两件容易被跳过的事讲透——它们直接决定你后面读到的数据有没有意义。2.1 挂载点确认与内核配置自检路径有两个老内核在/sys/kernel/debug/tracing新一些的内核会独立挂一个 tracefs 到/sys/kernel/tracing。我通常先看后者没有再回退到前者。如果两个都空检查一下挂载mount | grep -E tracefs|debugfs # 没挂的话 mount -t tracefs nodev /sys/kernel/tracing进目录第一件事是cat available_tracers。输出里能看到function、function_graph、nop可能还有blk和一堆 latency 类 tracer。如果没有function_graph说明内核没开CONFIG_FUNCTION_GRAPH_TRACER这一项没法补只能换机器或者换方案。同理events/目录空着多半是CONFIG_FTRACE_SYSCALLS、CONFIG_KPROBE_EVENTS之类没配。注意不要在生产内核上随手echo function current_tracer就去cat trace。函数调用密度高的机器上几秒钟就能写出几十万行终端会卡住缓冲区也会被冲掉。永远先设过滤再开。2.2 五条命令的最短闭环我脑子里的标准动作是这样的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 -50每一步都有必要。先关tracing_on是为了防止在改配置的过程中有事件写进来污染数据echo nop current_tracer是彻底清掉上一轮挂的钩子只清trace不清 tracer那些钩子还在改过滤规则的时候会有额外开销echo trace才是清缓冲区。顺序反了你会看到上一次的残留数据混在里面。读输出时head那几十行里最重要的信息是哪些函数在反复出现。如果满屏都是mutex_lock、_raw_spin_lock、kfree说明你抓的范围太大了这些是任何路径都会走的通用函数噪音极高。2.3 set_ftrace_filter 的写法与三个常见错过滤是这个工具能不能用的分水岭。语法看着简单实际用起来有几个地方很容易写错。写法含义常见误用schedule精确匹配一个函数函数被内联了写了没反应tcp_*通配符匹配匹配范围过大反而更慢:mod:mydev匹配某模块内全部函数模块名写错静默失败*foo*bar*中间通配性能差优先用前缀匹配三个坑记一下。第一写入是累加的不是覆盖。你echo a set_ftrace_filter再echo b set_ftrace_filter结果里是两个函数。要清空得echo set_ftrace_filter要删单个得echo !a set_ftrace_filter。很多人以为第二次写入覆盖了第一次结果追踪范围莫名其妙变大。第二过滤只对function和function_graph生效对events/下的静态事件无效。想过滤事件得在事件那一层用filter文件这是两套机制别混。第三写入之后一定要回读确认cat set_ftrace_filter | wc -l。如果输出是 0说明你的规则一条都没匹配上后面无论怎么开都是空的。2.4 用 pid 过滤和独立 instance 把噪音挡在外面set_ftrace_pid是我用得最多的一个开关。把目标进程的 pid 写进去之后就只记录这个进程上下文里发生的函数调用。对于“某个服务偶发卡顿”这类问题它能把噪音直接砍掉两个数量级。但要注意它的语义记录的是在该进程上下文里执行的调用不是“这个进程调用的所有内核路径”。当它被调度出去、内核在处理别的任务时那些记录会消失。还有如果目标进程 fork 了子进程默认不跟需要开options/function-fork。再往上一层是 instance。mkdir instances/foo会创建一个完全独立的追踪实例有自己的 buffer、自己的 tracer、自己的过滤规则和开关。这个设计的价值在于你可以让一个实例长期开着做后台记录另一个实例临时做排查两者互不干扰。做长期观测的时候我基本都用 instance因为直接改全局配置太容易误伤别人正在用的东西。3. function_graph 才是排查耗时问题的主力如果说functiontracer 是用来“看谁被调了”那function_graph就是用来“看这次调用花了多久、时间花在哪一层”。我实际排查里用它的时候远多于前者因为绝大部分性能类问题的答案都在耗时结构里而不是在“有没有被调用”这个布尔值上。3.1 输出格式逐列拆解先看一段典型输出我按列解释1) 1.234 us | } /* 注释 */ 1) | foo() { 1) 12.345 us | bar(); 1) 15.678 us | }最左边的1)是 CPU 编号也可以配成显示进程名和 pid靠options/funcgraph-proc切。紧接着那一列是这个函数从进入到返回的总耗时注意它包含子调用。号和^号是有含义的表示耗时超过tracing_thresh默认 10 微秒^表示超过阈值的十倍。这两个符号是我扫长输出时唯一的抓手一眼就能挑出慢的地方。|这个竖线表示调用层级缩进越深调用栈越深。函数名后面跟{的是进入行跟}的是返回行返回行上的耗时和进入行上的耗时对同一函数是一致的。/* ... */里的注释是内核主动标注的延迟原因比如期间发生了中断、发生了调度、或者某段代码被标了延迟标记这个信息非常值钱它能直接告诉你“这段时间不是我的代码在跑”。3.2 缩进深度与 max_graph_depth 的取舍function_graph的缩进是有上限的由max_graph_depth控制。默认值通常够用但在深度调用链里比如文件系统路径一路下探你会看到输出在某一层突然“断掉”没有对应的}看着像数据丢了。这不是 bug。深度到顶之后更深的调用不再被记录所以父函数的耗时里包含了没显示出来的部分父子时间对不上是正常的。我遇到过有人拿这个当“内核丢事件”去查白折腾半天。实际用法上我的建议是默认别调大。深度越大每条记录的处理成本越高输出越难读。更有效的做法反过来——用set_graph_function精确指定起点让记录从你关心的那个函数开始前面的调用链全部不记。比如你怀疑某段初始化慢就把模块入口函数写进去输出的第一行就是它非常干净。3.3 一次 probe 偶发超时的完整排查链路说个具体的。某块板子上一个外设驱动在启动时偶尔要八百多毫秒正常情况只要几毫秒日志里没有任何报错。这个“偶发”意味着不能靠加打印反复试。第一步先确认耗时到底在不在 probe 里。我把驱动注册的入口函数写进set_graph_functioncurrent_tracer设成function_graphtracing_thresh保持默认开启后重启一次服务。输出里那个入口函数的耗时确实在毫秒到几百毫秒之间跳。第二步看那几百毫秒落在哪个子调用上。把输出按耗时排序和^标记的行一目了然锁定了中间一段几十行的调用。这段里面有一个明显的/* 500 us */注释说明这段时间被切走了但旁边的函数耗时又不足以解释总时长。第三步怀疑延时等待。这时候换思路把options/funcgraph-irqs打开让中断和软中断的边界也在输出里体现出来同时在同一个实例里把events/timer/timer_start和events/sched/sched_switch也开上让定时器和调度事件混进同一条时间线。这一混问题就浮出来了那段“空白”时间里进程被调度出去过而定时器事件的间隔正好是固定的几十毫秒。第四步回到代码。那是一段轮询硬件就绪标志的循环写法是“检查标志没好就固定延时 N 毫秒再试”重试次数有上限但延时没有退避。硬件偶尔响应慢的时候几次重试直接累积成几百毫秒。改成带总超时、并且延时递增的等待之后最坏情况压到了几十毫秒以内。整个过程里真正解决问题的信息只有两条空白时间段有多长以及这期间发生了什么。function_graph 提供了前者混入的事件提供了后者。这也是我为什么一直强调“同一个 buffer”这个设计——把不同来源的记录放进同一条时间线比在几个工具的输出之间对时间戳靠谱得多。3.4 读图时最容易看走眼的三件事第一件是把父函数的耗时当成自己的。foo()那一行写着 15 微秒不代表 foo 自己的代码跑了 15 微秒它包含了 bar 的 12 微秒。真正属于 foo 自身的只有 3 微秒左右。判断“哪里慢”要看相邻两层之间的差值而不是看绝对值最大那一行。第二件是忽略中断上下文的记录。默认配置下中断里发生的函数调用也会被记录它们和进程上下文混在一起缩进关系看着是连续的实际上已经被打断了。开options/funcgraph-irqs能缓解但更稳妥的判断方法是看那个/* ... */注释内核标出来的延迟基本都在告诉你“这里被打断了”。第三件是时间戳的基准。默认是本地时钟多核场景下不同 CPU 的记录拼在一起顺序可能是错的。这个问题足够重要我单独放在第五章讲。4. trace events 与 kprobe不改代码拿到参数值function和function_graph只能告诉你“函数被调了、花了多久”但排查里更常见的问题是“传进来的参数是什么”。这个问题用 events 层解决不需要改一行代码也不用重启服务。4.1 events 目录的组织方式events/下面按子系统分目录sched/、irq/、block/、net/、syscalls/等等每个子系统下面是具体事件每个事件目录里有一套标准文件enable开关、format格式定义、filter过滤表达式、trigger触发器、id编号。format是必须看的。它列出来这个事件能取哪些字段、每个字段的类型和偏移。写过滤表达式或者取参的时候字段名必须和format里完全一致大小写错了就是静默失败——不会报错只是没数据。打开方式有两种单个开关或者批量# 单个 echo 1 events/sched/sched_switch/enable # 按子系统批量 echo 1 events/irq/enable # 用 set_event 一次性写多个 echo sched/sched_switch sched/sched_wakeup set_event关的时候对应写 0或者echo set_event清空。这里有个细节set_event里的内容和各个enable文件是联动的你在set_event里写了一条对应事件的enable就变成 1反过来也一样。4.2 kprobe_events 的语法拆开讲静态事件覆盖面有限真正灵活的是 kprobe。往kprobe_events写一行定义就凭空造出一个事件。基本形态是p:事件名 函数名 取参列表p是入口探针换成r就是返回探针能取到返回值# 入口探针取第一个参数 echo p:my_open vfs_open file$arg1 kprobe_events # 返回探针取返回值 echo r:my_open_ret vfs_open ret$retval kprobe_events # 打开事件并加过滤 echo 1 events/kprobes/my_open/enable echo common_pid 1234 events/kprobes/my_open/filter取参有几个来源我整理成表写法取值来源说明$arg1…$argN函数参数新内核推荐可读性最好$retval返回值只能用在r:探针上$comm当前进程名排查时非常有用%di、%si等寄存器老内核的写法需自己知道 ABI0(%di):string内存解引用取指针指向的字符串/结构体$stack1栈上数据慎用容易取到垃圾值写完之后事件目录在events/kprobes/事件名/。用完记得清掉echo kprobe_events会删除所有动态探针否则这些探针会一直挂在那里每次调用都触发一次记录白白吃性能。4.3 用 hist trigger 把统计做在核内这是我觉得最被低估的一块。原始记录再多你能读的也就几百行但 hist trigger 能在内核里直接做完聚合你只看结果。# 按进程统计调用次数取前 20 echo hist:keyscommon_pid:valshitcount:sorthitcount:size20 \ events/kprobes/my_open/trigger cat events/kprobes/my_open/hist这段的意思是以common_pid为键分组统计每组命中次数按次数排序取前 20。输出直接就是一张表谁调得多一目了然完全不用把原始数据拉出来。再进一步latency字段能对两个事件之间的时间差做直方图。典型用法是给“函数进入”和“函数返回”各挂一个探针用 latency 聚合直接拿到耗时的分布——不是平均值是分布长尾一眼可见。这个东西的价值在于它把“偶发”变成了“可量化”你不再需要靠运气去抓那一次异常。4.4 取参失败的四类典型错第一类是参数位置搞错。$arg1的编号是从调用约定推出来的遇到结构体按值传递、或者参数被寄存器拆分的情况编号和源码里的位置对不上。这时候老老实实去看format里生成的字段或者对照反汇编确认。第二类是探针点选在函数中间。c 编译器会做各种优化同一个函数可能被拆成多段某些路径根本不会走你挂的那个入口。表现就是“明明调了这个函数但我的探针没触发”。第三类是返回探针拿不到正确值。r:探针挂的位置在函数真正返回之后某些内联或者尾调用优化的场景下行为会有差异。如果发现$retval一直是 0 或者明显不对先确认这个函数没有被编译器特殊处理。第四类是结构体解引用拿到垃圾。0(%di):string这类写法不会做任何安全校验指针为空或者指向已释放内存的时候取出来的是脏数据有时候还会把内核搞得不稳。我的原则是能在format里看到的字段优先用非要解引用的话只在自己完全确定生命周期的地方用。5. 环形缓冲区决定了你看到的是不是真相这一章我想单独拿出来因为它是我见过最多“结论完全反了”的地方。前面所有的配置、过滤、取参都做得对最后败在缓冲区模型上太亏了。5.1 per-CPU buffer 和你以为的“全局有序”差多远ftrace 的缓冲区是每个 CPU 一个。这样设计是为了避免多核抢同一把锁代价是不同 CPU 上的记录之间没有严格的全序关系合并输出的时候是按各自的时间戳做近似拼接。平时你不容易察觉因为大部分调用链跑在同一个 CPU 上。但一旦涉及跨核交互——比如一个进程在 CPU0 发信号另一个在 CPU3 响应或者中断在某个核上触发、软中断在另一个核上执行——拼接出来的顺序就可能和真实顺序相反。判断方法很简单看输出的 CPU 那一列。如果同一段逻辑里 CPU 编号在跳就得警惕。想缓解的话trace_clock切到全局时钟让所有 CPU 用同一个递增源。代价是有一点额外开销但换来的顺序可靠性完全值得。5.2 buffer_size_kb 到底是每 CPU 还是总量这是一个高频误解。buffer_size_kb是单个 CPU的容量buffer_total_size_kb是只读的总量。你写 1408在 8 核机器上实际占用接近 11MB而不是 1.4MB。所以调这个值之前先算一下目标机器的核数。我一般的做法是短时抓取几秒内给每 CPU 几千 KB 就够长时间低频率记录给到每 CPU 几万 KB但别一上来就写个很大的数字分配本身有成本而且写大了以后读trace也会很慢。这里还有个隐藏问题缓冲区满了会覆盖旧数据而且不报错。你以为抓到了完整的现场实际上最早的那段已经被冲掉了。判断的方法是看per_cpu/cpuN/stats里的overrun计数非零就说明丢过。做长时记录时这个字段我必看。5.3 trace 和 trace_pipe 的差别不只是“一个阻塞一个不阻塞”两个文件看着都像读数据行为完全不同trace是快照式读取读的时候会短暂停一下写入读完数据还在再读一遍还是那些。适合“停下来仔细看”。trace_pipe是流式消费读走一条就少一条没有数据时阻塞等待。适合“一边跑一边看”也适合接到管道里做后续处理。选错了会有后果。想持续观察却用了trace你得反复读全量越读越慢想在出错后回看现场却用了trace_pipe如果读取程序没及时消费数据就被后面的新记录挤掉了。我的习惯是交互式排查用trace脚本化持续采集用trace_pipe。5.4 一次“看起来数据很全结论完全反了”的复盘说个典型事故。某次排查一个请求偶尔失败的问题从trace里看到的信息是先出现了失败日志相关的事件然后才看到请求进入的事件。于是第一反应是“请求还没进来就失败了肯定是上游的问题”。实际原因是两条记录跑在不同的 CPU 上本地时钟基准不同合并时顺序被排反了。真实顺序是请求进入、处理、失败完全正常。这次误判浪费了大半天还差点把锅甩给隔壁模块。复盘下来有两条经验。一是任何跨 CPU 的时间顺序判断先切全局时钟再说别拿本地时钟的输出下结论。二是看到不符合直觉的顺序时先怀疑工具而不是先怀疑代码尤其是时间差在微秒级别的时候。加上common_pid和 CPU 编号做交叉验证能挡掉绝大部分这类误判。6. 开销、线上操作与什么时候该换工具最后聊聊边界。ftrace 的开销不是一个固定数字它跟你的过滤范围、调用密度、buffer 大小、是否开 graph 强相关。给一个绝对值是不负责任的但给出量级和判断方法是可以的。6.1 各类 tracer 的量级差异与实测方法粗略的相对关系是这样的方案相对开销适用场景nop接近零平时常驻随时待命静态事件少量开启很低长时间观测关心特定事件function 窄过滤中低确认某几个函数是否被调用function 宽过滤中高短时摸底看清调用面function_graph高排查耗时结构秒级窗口kprobe 解引用取参中高取参数注意生命周期“大概多高”这种描述没意义自己测才靠谱。方法很简单找一个有代表性的业务路径在不开追踪和开追踪两种情况下各跑一遍比较耗时。这个对比一定要在你自己的机器、自己的内核、自己的负载下做别人给的数字参考价值有限。还有一个常被忽略的点关闭追踪之后钩子的移除不是瞬时的。改current_tracer为nop之后最好再确认一下set_ftrace_filter里的内容也清掉了避免下次误用的时候带着上一轮的规则。6.2 线上短时抓取的标准动作清单在不能随便折腾的环境里我固定走这套流程用instances/建一个独立实例不碰全局配置先设过滤再设 tracer最后开tracing_on设定明确的抓取窗口用sleep或者外部定时绝不让它无限期开着抓完立刻tracing_on写 0把trace内容重定向到文件再慢慢分析不要在线cat收尾时把实例里的 tracer 设回nop、过滤清空、必要时rmdir掉实例。第 5 条特别重要。在终端里直接cat一个几十万行的 trace终端渲染本身就可能是瓶颈还会让你误以为是系统卡了。重定向到文件然后less、grep、awk处理效率和体验差很多。注意抓取窗口宁可短一点抓两次也不要一次开很久。缓冲区满了会覆盖你拿到的可能是一段“看起来完整但缺了开头”的数据比没有更误导人。6.3 出现这三个信号就别硬扛了第一个信号是目标函数调用频率极高。比如你想追踪的是网络收包路径上的某个函数每秒几十万次那function_graph基本没法用输出量和开销都不可接受。这种场景应该转向事件层加 hist 聚合或者干脆换采样类方案。第二个信号是你需要的是长期、低开销的量化指标。ftrace 适合短时、精确、一次性的定位不适合挂在那里跑一整天做趋势统计。长时间观测请用聚合别用原始记录。第三个信号是你需要复杂的条件逻辑和跨事件关联。hist trigger 能做的事情不少但遇到“A 事件之后 5 毫秒内出现 B 事件才记录”这种带时间窗的复杂条件表达式会写得很难维护可读性急剧下降。这种时候就该考虑更可编程的方案了工具选型的意义在于把复杂度放在合适的地方。我个人在实际操作中的体会是ftrace 最大的价值不是它功能多强而是它永远在那儿。不用装、不用编译、不用申请权限、不用担心版本不匹配登上去就能用。真正把排查效率拉开的往往不是用了多先进的工具而是手边这个最朴素的工具你有没有练熟。把set_ftrace_filter的匹配规则、function_graph的读数顺序、trace_clock的影响这几件事变成本能剩下的查询和分析都是在这几个动作上做组合。