用户态程序出问题可以 strace、gdb，内核出问题靠什么？答案是动态追踪三件套：ftrace 看调用路径、kprobe 在任意指令打点、perf 做采样统计。本文先讲清三者的机制差异与适用场景，再用一个完整可运行的模型模拟器复现函数图追踪、延迟直方图和热点统计的真实输出形态，让你读到工具输出时不再陌生。

一、三件套的分工哲学

一句话记忆：ftrace 看路，kprobe 看点，perf 看面。三者底层共享 tracepoint 和环形缓冲（relay/perf buffer）等基础设施。

二、完整可运行模型模拟器（Python 3，约 100 行）

下面程序用装饰器式的打点复现三种工具的输出形态：函数图调用树、kprobe 延迟直方图、perf 热点统计：

#!/usr/bin/env python3
"""ftrace/kprobe/perf 模型模拟：函数追踪、延迟直方图、调用栈、热点统计"""
import random, time
random.seed(42)

# ---------- ftrace 函数图追踪 ----------
class FTrace:
    def __init__(self):
        self.trace = []
        self.stack = []
    def enter(self, fn):
        ts = time.perf_counter()
        self.stack.append((fn, ts))
        self.trace.append(('enter', fn, ts, len(self.stack) - 1))
    def exit(self):
        fn, ts0 = self.stack.pop()
        ts = time.perf_counter()
        self.trace.append(('exit', fn, ts, len(self.stack),
                           (ts - ts0) * 1e6))

ft = FTrace()

def vfs_read():
    ft.enter('vfs_read'); do_read(); ft.exit()

def do_read():
    ft.enter('do_read')
    page_cache_lookup()
    if random.random() < 0.3:
        do_page_fault()
    ft.exit()

def page_cache_lookup():
    ft.enter('page_cache_lookup'); time.sleep(0.0002); ft.exit()

def do_page_fault():
    ft.enter('do_page_fault'); time.sleep(0.001); alloc_page(); ft.exit()

def alloc_page():
    ft.enter('alloc_page'); time.sleep(0.0003); ft.exit()

for _ in range(3):
    vfs_read()

print('=== ftrace 函数图追踪模拟（3 次 vfs_read 调用） ===')
for rec in ft.trace:
    if rec[0] == 'enter':
        print('  ' * rec[3] + '-> %s()' % rec[1])
    else:
        print('  ' * rec[3] + '<- %s() 耗时 %.0fus' % (rec[1], rec[4]))

# ---------- kprobe 延迟直方图 ----------
print()
print('=== kprobe 延迟统计模拟（vfs_read 延迟直方图，100 次采样） ===')
lats = []
for _ in range(100):
    base = random.gauss(50, 15)
    if random.random() < 0.08:
        base += random.gauss(200, 50)   # 8% 慢路径（缺页）
    lats.append(max(1, base))

buckets = {'1-32us': 0, '32-64us': 0, '64-128us': 0,
           '128-256us': 0, '>256us': 0}
for l in lats:
    if l < 32: buckets['1-32us'] += 1
    elif l < 64: buckets['32-64us'] += 1
    elif l < 128: buckets['64-128us'] += 1
    elif l < 256: buckets['128-256us'] += 1
    else: buckets['>256us'] += 1

for k, v in buckets.items():
    print('  %-10s %3d %s' % (k, v, '#' * (v // 2)))
lats_sorted = sorted(lats)
print('p50=%.0fus p95=%.0fus p99=%.0fus max=%.0fus' % (
    lats_sorted[49], lats_sorted[94], lats_sorted[98],
    lats_sorted[-1]))

# ---------- perf 热点统计 ----------
print()
print('=== perf 热点函数统计模拟（1000 次采样） ===')
funcs = ['page_cache_lookup', 'do_page_fault', 'vfs_read',
         'schedule', 'idle', 'copy_to_user', 'alloc_page']
weights = [35, 20, 12, 10, 8, 10, 5]
samples = random.choices(funcs, weights=weights, k=1000)
from collections import Counter
cnt = Counter(samples)
print('  函数                 采样数  占比')
for name, c in cnt.most_common():
    print('  %-20s %5d %5.1f%%' % (name, c, c / 10))

三、真实运行输出与解读

以上代码在 Python 3 下原样运行，输出如下：

=== ftrace 函数图追踪模拟（3 次 vfs_read 调用） ===
-> vfs_read()
  -> do_read()
    -> page_cache_lookup()
    <- page_cache_lookup() 耗时 4669us
  <- do_read() 耗时 4672us
<- vfs_read() 耗时 4675us
-> vfs_read()
  -> do_read()
    -> page_cache_lookup()
    <- page_cache_lookup() 耗时 245us
    -> do_page_fault()
      -> alloc_page()
      <- alloc_page() 耗时 358us
    <- do_page_fault() 耗时 1420us
  <- do_read() 耗时 1667us
<- vfs_read() 耗时 1670us
（第 3 次形态与第 2 次相同，约 1674us）

=== kprobe 延迟统计模拟（vfs_read 延迟直方图，100 次采样） ===
  1-32us       9 ####
  32-64us     62 ###############################
  64-128us    18 #########
  128-256us    5 ##
  >256us       6 ###
p50=55us p95=261us p99=318us max=356us

=== perf 热点函数统计模拟（1000 次采样） ===
  函数                 采样数  占比
  page_cache_lookup      345  34.5%
  do_page_fault          186  18.6%
  vfs_read               130  13.0%
  schedule               114  11.4%
  copy_to_user            97   9.7%
  idle                    77   7.7%
  alloc_page              51   5.1%

三种输出形态各自讲了一个故事：

四、真实工具速查表

# ftrace：追踪 vfs_read 的函数图（tracefs）
cd /sys/kernel/tracing
echo function_graph > current_tracer
echo vfs_read > set_ftrace_filter
echo 1 > tracing_on; sleep 1; echo 0 > tracing_on
cat trace

# kprobe：统计 vfs_read 调用次数与参数
cd /sys/kernel/tracing
echo 'p:myprobe vfs_read file=%di' > kprobe_events
echo 1 > events/kprobes/myprobe/enable
cat trace_pipe

# perf：采样 10 秒热点 + 延迟直方图思路
perf record -F 99 -g sleep 10      # 99Hz 采样带调用栈
perf report --stdio | head -30
# 直方图用 eBPF/bpftrace 更方便：
bpftrace -e 'kprobe:vfs_read { @start[tid] = nsecs }
  kretprobe:vfs_read /@start[tid]/ {
    @lat = hist(nsecs - @start[tid]); delete(@start[tid]) }'

五、理论分析

5.1 fentry 插桩与运行时替换

编译器 -pg 选项让每个内核函数开头多一条 call fentry 指令。ftrace 启动时把全内核几十万条这样的 call 全部换成 5 字节 nop（运行时热 patching，靠 text_poke 安全修改代码段）；开启某个 tracer 时再把目标函数的 nop 换回 call。这个『平时是 nop、用时才激活』的设计让 ftrace 关闭时的开销精确为零——动态追踪与静态埋点的本质差异就在这里。

5.2 采样的统计学

perf 的 99Hz 采样是有意选的：避开与 100Hz/1000Hz 的定时器中断共振（锁步采样会系统性偏倚）。采样数 N 时占比 p 的 95% 置信区间约 p±2√(p(1-p)/N)——1000 次采样下 34.5% 的占比置信区间约 ±3%，这解释了为什么 perf 官方建议至少跑几百毫秒、别拿 10 次采样下结论。

5.3 观察者效应

所有追踪都有开销：function graph tracer 每次进出让函数贵几十纳秒，kprobe 断点命中是微秒级。追踪高频函数（如 schedule）时开销可能扭曲被测系统本身。工程纪律：能用 tracepoint（静态埋点，关闭时零开销）就不用 kprobe，能用 kprobe 就不用全量 function tracer。

六、工程应用

七、常见误区

八、参考文献

  1. S. Rostedt (2008-2010). ftrace: Function Tracer 系列文档与 LWN 文章（ftrace 作者的一手阐述）。
  2. Linux kernel documentation: Documentation/trace/ftrace.rst、kprobes.rst、tracepoints.rst。
  3. B. Gregg (2020). Systems Performance (2nd ed.) 第 2、13 章：观测工具与内核分析方法论。Addison-Wesley.
  4. B. Gregg (2019). BPF Performance Tools. Addison-Wesley.（bpftrace 直方图与动态追踪的实战手册）
  5. perf 官方文档与源码: tools/perf/Documentation 目录。
← 返回文章列表