Linux 事件追踪深度实操：ftrace、perf、strace 与 ltrace-开发者社区

Linux 事件追踪深度实操：ftrace、perf、strace 与 ltrace

服务器环境: Ubuntu 24.04.4 LTS, 内核 6.8.0-106-generic, x86_64
实操时间: 2026-09-08
核心目标: 在真实服务器上实操 ftrace 函数追踪、perf 性能分析、strace 系统调用追踪和 ltrace 库函数追踪，掌握 Linux 事件追踪的完整工具链。

前言

事件追踪是理解系统行为的终极工具。当系统出现性能问题、行为异常或需要深入理解内核工作流程时，追踪工具能让你看到系统内部的真实运作。Linux 提供了从轻量级到重量级的完整追踪工具链：ftrace 追踪内核函数、perf 分析性能事件、strace 追踪系统调用、ltrace 追踪库函数。本文将在一台真实的 Ubuntu 24.04 服务器上，逐一实操这些工具。

一、ftrace 基础：内核内置的追踪框架

ftrace（Function Tracer）是内核内置的追踪框架，不需要安装任何额外软件，通过/sys/kernel/tracing/目录的文件接口进行配置。

1.1 查看可用追踪器

cat/sys/kernel/tracing/available_tracers

实际输出：

timerlat osnoise hwlat blk mmiotrace function_graph wakeup_dl wakeup_rt wakeup function nop

追踪器说明：

追踪器	功能
function	追踪所有内核函数调用
function_graph	以调用图形式展示函数调用关系和耗时
wakeup	追踪唤醒最高优先级任务的延迟
wakeup_rt	追踪唤醒实时任务的延迟
wakeup_dl	追踪唤醒 Deadline 任务的延迟
hwlat	硬件延迟检测器
osnoise	操作系统噪声检测
timerlat	定时器延迟检测
blk	块设备 I/O 追踪
mmiotrace	MMIO（内存映射 I/O）追踪
nop	无操作（用于事件追踪）

1.2 查看当前追踪器

cat/sys/kernel/tracing/current_tracer

实际输出：

nop

1.3 tracing 目录结构

ls/sys/kernel/tracing/|head-30

实际输出：

available_events available_filter_functions available_filter_functions_addrs available_tracers buffer_percent buffer_size_kb buffer_subbuf_size_kb buffer_total_size_kb current_tracer dynamic_events dyn_ftrace_total_info enabled_functions error_log events free_buffer function_profile_enabled hwlat_detector instances kprobe_events kprobe_profile max_graph_depth options per_cpu printk_formats README rv saved_cmdlines saved_cmdlines_size saved_tgids

二、function 追踪器：追踪内核函数调用

2.1 启用 function tracer

echofunction>/sys/kernel/tracing/current_tracerecho1>/sys/kernel/tracing/tracing_onsleep1echo0>/sys/kernel/tracing/tracing_oncat/sys/kernel/tracing/trace|head-30

实际输出：

# tracer: function # # entries-in-buffer/entries-written: 185572/223707 #P:8 # # _-----=> irqs-off/BH-disabled # / _----=> need-resched # | / _---=> hardirq/softirq # || / _--=> preempt-depth # ||| / _-=> migrate-disable # |||| / delay # TASK-PID CPU# ||||| TIMESTAMP FUNCTION # | | | ||||| | | bash-9863 [006] ..... 3917.100792: mutex_unlock <-tracing_set_tracer bash-9863 [006] ..... 3917.100794: __f_unlock_pos <-ksys_write bash-9863 [006] ..... 3917.100794: mutex_unlock <-__f_unlock_pos bash-9863 [006] ..... 3917.100794: syscall_exit_to_user_mode_prepare <-syscall_exit_to_user_mode bash-9863 [006] ..... 3917.100794: task_work_run <-syscall_exit_to_user_mode bash-9863 [006] ..... 3917.100794: _raw_spin_lock_irq <-task_work_run bash-9863 [006] d..1. 3917.100795: _raw_spin_unlock_irq <-task_work_run bash-9863 [006] ..... 3917.100795: task_mm_cid_work <-task_work_run bash-9863 [006] ..... 3917.100795: __cond_resched <-task_work_run bash-9863 [006] ..... 3917.100795: mem_cgroup_handle_over_high <-syscall_exit_to_user_mode bash-9863 [006] ..... 3917.100795: blkcg_maybe_throttle_current <-syscall_exit_to_user_mode bash-9863 [006] ..... 3917.100796: __rseq_handle_notify_resume <-syscall_exit_to_user_mode bash-9863 [006] ..... 3917.100796: rseq_ip_fixup <-__rseq_handle_notify_resume bash-9863 [006] ..... 3917.100796: rseq_get_rseq_cs <-rseq_ip_fixup bash-9863 [006] ..... 3917.100796: rseq_update_cpu_node_id <-__rseq_handle_notify_resume bash-9863 [006] d.... 3917.100797: fpregs_assert_state_consistent <-arch_exit_to_user_mode_prepare.isra.0 bash-9863 [006] d.... 3917.100797: switch_fpu_return <-arch_exit_to_user_mode_prepare.isra.0 bash-9863 [006] ..... 3917.100812: x64_sys_call <-do_syscall_64

输出格式解读：

TASK-PID: 进程名和 PID
CPU#: 在哪个 CPU 核心上执行
5 个标志位: irqs-off / need-resched / hardirq-softirq / preempt-depth / migrate-disable
TIMESTAMP: 相对追踪开始的时间戳（秒）
FUNCTION: 被调用的函数，<-后面是调用者

1 秒内捕获了 185572 条函数调用记录，展示了内核函数调用的密集程度。

三、function_graph 追踪器：函数调用图

function_graph 追踪器以缩进的调用图形式展示函数调用关系，并测量每个函数的执行时间。

echofunction_graph>/sys/kernel/tracing/current_tracerecho1>/sys/kernel/tracing/tracing_onsleep1echo0>/sys/kernel/tracing/tracing_oncat/sys/kernel/tracing/trace|head-40

实际输出：

# tracer: function_graph # # CPU DURATION FUNCTION CALLS # | | | | | | | 4) 1.461 us | mutex_unlock(); 4) 0.131 us | syscall_exit_to_user_mode_prepare(); 4) 0.139 us | fpregs_assert_state_consistent(); 4) | x64_sys_call() { 4) | __x64_sys_dup2() { 4) | ksys_dup3() { 4) 0.131 us | _raw_spin_lock(); 4) 0.120 us | expand_files(); 4) | do_dup2() { 4) 0.200 us | _raw_spin_unlock(); 4) | filp_close() { 4) | filp_flush() { 4) 0.129 us | dnotify_flush(); 4) 0.141 us | locks_remove_posix(); 4) 0.579 us | } 4) | fput() { 4) | task_work_add() { 4) 0.131 us | kick_process(); 4) 0.370 us | } 4) 0.610 us | } 4) 1.499 us | } 4) 2.040 us | } 4) 2.710 us | } 4) 2.931 us | } 4) 3.179 us | } 4) 0.120 us | syscall_exit_to_user_mode_prepare(); 4) | task_work_run() { 4) 0.130 us | _raw_spin_lock_irq(); 4) 0.130 us | _raw_spin_unlock_irq(); 4) | ____fput() { 4) | __fput() { 4) 0.120 us | __cond_resched(); 4) 0.120 us | locks_remove_file(); 4) 0.111 us | ima_file_free(); 4) | mutex_lock() { 4) 0.120 us | __cond_resched();

function_graph 的优势：

缩进展示了函数的嵌套调用层次
每个函数的执行时间以微秒（us）为单位显示
可以直观看到哪个函数耗时最长
适合分析特定代码路径的性能瓶颈

四、追踪特定函数：set_ftrace_filter

当 function tracer 输出过多时，可以使用过滤器只追踪特定函数：

echofunction>/sys/kernel/tracing/current_tracerecho'schedule'>/sys/kernel/tracing/set_ftrace_filterecho1>/sys/kernel/tracing/tracing_onsleep2echo0>/sys/kernel/tracing/tracing_oncat/sys/kernel/tracing/trace|head-30

实际输出：

# tracer: function # # entries-in-buffer/entries-written: 310/310 #P:8 # # _-----=> irqs-off/BH-disabled # / _----=> need-resched # | / _---=> hardirq/softirq # || / _--=> preempt-depth # ||| / _-=> migrate-disable # |||| / delay # TASK-PID CPU# ||||| TIMESTAMP FUNCTION # | | | ||||| | | uniagentd-5784 [002] ..... 3921.567596: schedule <-schedule_hrtimeout_range_clock bash-9878 [005] ..... 3921.567617: schedule <-do_wait sleep-9879 [007] ..... 3921.568195: schedule <-do_nanosleep rcu_preempt-17 [004] ..... 3921.568324: schedule <-schedule_timeout uniagentd-5767 [001] ..... 3921.572039: schedule <-schedule_hrtimeout_range_clock rcu_preempt-17 [004] ..... 3921.572259: schedule <-rcu_gp_kthread uniagentd-5789 [003] ..... 3921.572330: schedule <-schedule_hrtimeout_range_clock uniagentd-5787 [000] ..... 3921.578725: schedule <-schedule_hrtimeout_range_clock uniagentd-5789 [003] ..... 3921.582396: schedule <-schedule_hrtimeout_range_clock

过滤后只显示schedule函数的调用，2 秒内捕获了 310 条记录。可以看到schedule被多种路径调用：schedule_hrtimeout_range_clock、do_nanosleep、schedule_timeout、rcu_gp_kthread等。

五、Trace Events：事件追踪

5.1 查看可用事件子系统

ls/sys/kernel/tracing/events/|head-30

实际输出：

alarmtimer amd_cpu avc block bpf_test_run bpf_trace bridge btrfs cgroup clk compaction context_tracking cpuhp cros_ec csd dev devfreq devlink dma_fence drm enable error_report exceptions ext4 fib fib6 filelock filemap fs_dax ftrace

系统共有124 个事件子系统，涵盖调度、内存、网络、文件系统、块设备等各个方面。

5.2 查看调度事件

ls/sys/kernel/tracing/events/sched/|head-20

实际输出：

enable filter sched_kthread_stop sched_kthread_stop_ret sched_kthread_work_execute_end sched_kthread_work_execute_start sched_kthread_work_queue_work sched_migrate_task sched_move_numa sched_pi_setprio sched_process_exec sched_process_exit sched_process_fork sched_process_free sched_process_hang sched_process_wait sched_skip_vma_numa sched_stat_blocked sched_stat_iowait sched_stat_runtime

5.3 启用特定事件并追踪

echo1>/sys/kernel/tracing/events/sched/sched_process_exec/enableecho1>/sys/kernel/tracing/tracing_onls/tmp>/dev/nullsleep1echo0>/sys/kernel/tracing/tracing_oncat/sys/kernel/tracing/trace|head-20

实际输出：

# tracer: nop # # entries-in-buffer/entries-written: 2/2 #P:8 # # _-----=> irqs-off/BH-disabled # / _----=> need-resched # | / _---=> hardirq/softirq # || / _--=> preempt-depth # ||| / _-=> migrate-disable # |||| / delay # TASK-PID CPU# ||||| TIMESTAMP FUNCTION # | | | ||||| | | ls-9893 [006] ..... 3924.963893: sched_process_exec: filename=/usr/bin/ls pid=9893 old_pid=9893 sleep-9894 [001] ..... 3924.964671: sched_process_exec: filename=/usr/bin/sleep pid=9894 old_pid=9894

sched_process_exec事件在进程执行exec()系统调用时触发，可以看到ls和sleep命令的执行记录，包括文件名和 PID 信息。

六、perf 工具：性能分析利器

6.1 安装 perf

apt-getinstall-ylinux-tools-common linux-tools-$(uname-r)

6.2 perf list：查看可用事件

perf list|head-40

实际输出：

branch-instructions OR branches [Hardware event] branch-misses [Hardware event] cache-misses [Hardware event] cache-references [Hardware event] cpu-cycles OR cycles [Hardware event] instructions [Hardware event] stalled-cycles-frontend OR idle-cycles-frontend [Hardware event] alignment-faults [Software event] bpf-output [Software event] cgroup-switches [Software event] context-switches OR cs [Software event] cpu-clock [Software event] cpu-migrations OR migrations [Software event] dummy [Software event] emulation-faults [Software event] major-faults [Software event] minor-faults [Software event] page-faults OR faults [Software event] task-clock [Software event] tool: duration_time user_time system_time cache: L1-dcache-loads OR cpu/L1-dcache-loads/ L1-dcache-load-misses OR cpu/L1-dcache-load-misses/ L1-dcache-prefetches OR cpu/L1-dcache-prefetches/ L1-icache-loads OR cpu/L1-icache-loads/ L1-icache-load-misses OR cpu/L1-icache-load-misses/ dTLB-loads OR cpu/dTLB-loads/ dTLB-load-misses OR cpu/dTLB-load-misses/ iTLB-loads OR cpu/iTLB-loads/ iTLB-load-misses OR cpu/iTLB-load-misses/ branch-loads OR cpu/branch-loads/ branch-load-misses OR cpu/branch-load-misses/

6.3 perf stat：统计性能事件

perfstat-einstructions,cycles,cache-missesls/tmp

实际输出：

Performance counter stats for 'ls /tmp': 1,718,511 instructions # 1.18 insn per cycle 1,460,205 cycles 19,571 cache-misses 0.000792108 seconds time elapsed 0.000000000 seconds user 0.000823000 seconds sys

分析：ls /tmp执行了 171 万条指令，146 万个时钟周期，IPC（Instructions Per Cycle）为 1.18，有 19571 次缓存未命中。总耗时 0.79 毫秒。

6.4 perf record + report：采样分析

perf record-ecpu-clock-o/tmp/perf.data --ls/tmp perf report-i/tmp/perf.data--stdio|head-30

实际输出：

# Samples: 2 of event 'cpu-clock' # Event count (approx.): 500000 # # Overhead Command Shared Object Symbol # ........ ....... ................. ........................ # 50.00% ls [kernel.kallsyms] [k] _raw_spin_unlock_irq 50.00% ls libc.so.6 [.] 0x00000000000b5ac5

perf report 显示了 CPU 时间在各个函数上的分布：50% 在内核的_raw_spin_unlock_irq，50% 在 libc 的某个函数。

6.5 perf 事件分类

硬件事件：

perf list hw

实际输出：

branch-instructions OR branches [Hardware event] branch-misses [Hardware event] cache-misses [Hardware event] cache-references [Hardware event] cpu-cycles OR cycles [Hardware event] instructions [Hardware event] stalled-cycles-frontend OR idle-cycles-frontend [Hardware event]

软件事件：

perf list sw

实际输出：

alignment-faults [Software event] bpf-output [Software event] cgroup-switches [Software event] context-switches OR cs [Software event] cpu-clock [Software event] cpu-migrations OR migrations [Software event] dummy [Software event] emulation-faults [Software event] major-faults [Software event] minor-faults [Software event] page-faults OR faults [Software event] task-clock [Software event]

Tracepoint 事件：

perf list tracepoint|head-30

实际输出：

alarmtimer:alarmtimer_cancel [Tracepoint event] alarmtimer:alarmtimer_fired [Tracepoint event] alarmtimer:alarmtimer_start [Tracepoint event] alarmtimer:alarmtimer_suspend [Tracepoint event] amd_cpu:amd_pstate_perf [Tracepoint event] avc:selinux_audited [Tracepoint event] block:block_bio_backmerge [Tracepoint event] block:block_bio_bounce [Tracepoint event] block:block_bio_complete [Tracepoint event] block:block_bio_frontmerge [Tracepoint event] block:block_bio_queue [Tracepoint event] block:block_bio_remap [Tracepoint event] block:block_dirty_buffer [Tracepoint event] block:block_getrq [Tracepoint event] block:block_io_done [Tracepoint event] block:block_io_start [Tracepoint event] block:block_plug [Tracepoint event] block:block_rq_complete [Tracepoint event] block:block_rq_error [Tracepoint event] block:block_rq_insert [Tracepoint event] block:block_rq_issue [Tracepoint event] block:block_rq_merge [Tracepoint event] block:block_rq_remap [Tracepoint event] block:block_rq_requeue [Tracepoint event] block:block_split [Tracepoint event] block:block_touch_buffer [Tracepoint event] block:block_unplug [Tracepoint event] bpf_test_run:bpf_test_finish [Tracepoint event] bpf_trace:bpf_trace_printk [Tracepoint event] bridge:br_fdb_add [Tracepoint event]

七、strace：系统调用追踪

7.1 strace -c：统计系统调用

strace-cls/tmp

实际输出：

% time seconds usecs/call calls errors syscall ------ ----------- ----------- --------- --------- ---------------- 0.00 0.000000 0 5 read 0.00 0.000000 0 1 write 0.00 0.000000 0 9 close 0.00 0.000000 0 8 fstat 0.00 0.000000 0 18 mmap 0.00 0.000000 0 5 mprotect 0.00 0.000000 0 1 munmap 0.00 0.000000 0 3 brk 0.00 0.000000 0 1 1 ioctl 0.00 0.000000 0 2 pread64 0.00 0.000000 0 2 2 access 0.00 0.000000 0 1 execve 0.00 0.000000 0 2 2 statfs 0.00 0.000000 0 1 arch_prctl 0.00 0.000000 0 2 getdents64 0.00 0.000000 0 7 openat 0.00 0.000000 0 1 set_tid_address 0.00 0.000000 0 1 set_robust_list 0.00 0.000000 0 1 prlimit64 0.00 0.000000 0 1 getrandom 0.00 0.000000 0 1 statx 0.00 0.000000 0 1 rseq ------ ----------- ----------- --------- --------- ---------------- 100.00 0.000000 0 74 5 total

ls /tmp共执行了 74 次系统调用，其中 18 次 mmap、9 次 close、7 次 openat、5 次 read。有 5 次错误（ioctl 1 次、access 2 次、statfs 2 次）。

7.2 strace -e：过滤特定系统调用

strace-etrace=openat,read,writels/tmp|head-20

实际输出：

openat(AT_FDCWD, "/etc/ld.so.cache", O_RDONLY|O_CLOEXEC) = 3 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libselinux.so.1", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libc.so.6", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\3\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\220\243\2\0\0\0\0\0"..., 832) = 832 openat(AT_FDCWD, "/lib/x86_64-linux-gnu/libpcre2-8.so.0", O_RDONLY|O_CLOEXEC) = 3 read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\0\0\0\0\0\0\0\0"..., 832) = 832 openat(AT_FDCWD, "/proc/filesystems", O_RDONLY|O_CLOEXEC) = 3 read(3, "nodev\tsysfs\nnodev\ttmpfs\nnodev\tbd"..., 1024) = 400 read(3, "", 1024) = 0 openat(AT_FDCWD, "/usr/lib/locale/locale-archive", O_RDONLY|O_CLOEXEC) = 3 openat(AT_FDCWD, "/tmp", O_RDONLY|O_NONBLOCK|O_CLOEXEC|O_DIRECTORY) = 3 write(1, "CmsSignatureVerify-\nfork_demo\nfo"..., 686

可以看到ls命令的完整 I/O 流程：打开共享库缓存 → 加载共享库 → 读取/proc/filesystems→ 打开 locale-archive → 打开/tmp目录 → 写入结果到 stdout。

八、ltrace：库函数追踪

ltrace 追踪程序调用的库函数（如 malloc、free、printf 等）：

ltrace-cls/tmp

实际输出：

CmsSignatureVerify- fork_demo fork_demo.c ...

ltrace 在某些系统上可能输出较少，因为现代程序可能使用静态链接或直接系统调用。

九、/proc/[pid]/syscall 和 /proc/[pid]/stack

9.1 查看进程当前系统调用

sleep30&SLEEP_PID=$!cat/proc/$SLEEP_PID/syscallcat/proc/$SLEEP_PID/stackkill$SLEEP_PID

实际输出：

230 0x0 0x0 0x7ffd9a439230 0x7ffd9a439220 0x0 0x0 0x7ffd9a439160 0x70113caeca7a [<0>] hrtimer_nanosleep+0xa2/0x170 [<0>] common_nsleep+0x43/0x60 [<0>] __x64_sys_clock_nanosleep+0xf4/0x180 [<0>] x64_sys_call+0x1c2c/0x25a0 [<0>] do_syscall_64+0x7f/0x180 [<0>] entry_SYSCALL_64_after_hwframe+0x78/0x80

解析：

/proc/[pid]/syscall: 第一个数字 230 是系统调用号（clock_nanosleep），后面是参数
/proc/[pid]/stack: 内核栈回溯，显示从硬件中断入口到当前执行点的完整调用链

9.2 查看当前进程的内核栈

cat/proc/self/stack

实际输出：

[<0>] proc_pid_stack+0xed/0x170 [<0>] proc_single_show+0x56/0xe0 [<0>] seq_read_iter+0x132/0x4b0 [<0>] seq_read+0x11c/0x160 [<0>] vfs_read+0xb4/0x3a0 [<0>] ksys_read+0x73/0x100 [<0>] __x64_sys_read+0x19/0x30 [<0>] x64_sys_call+0x1bf0/0x25a0 [<0>] do_syscall_64+0x7f/0x180 [<0>] entry_SYSCALL_64_after_hwframe+0x78/0x80

这展示了cat命令读取/proc/self/stack时的内核调用栈：从entry_SYSCALL_64_after_hwframe（系统调用入口）到proc_pid_stack（读取栈信息的函数）。

十、ftrace 高级配置

10.1 追踪选项

cat/sys/kernel/tracing/trace_options|head-20

实际输出：

print-parent nosym-offset nosym-addr noverbose noraw nohex nobin noblock nofields trace_printk annotate nouserstacktrace nosym-userobj noprintk-msg-only context-info nolatency-format record-cmd norecord-tgid overwrite nodisable_on_free

10.2 追踪时钟源

cat/sys/kernel/tracing/trace_clock

实际输出：

[local] global counter uptime perf mono mono_raw boot tai x86-tsc

[local]表示当前使用本地时钟。可选的时钟源包括：

local: 每 CPU 本地时钟
global: 全局时钟
counter: 简单计数器
uptime: 系统运行时间
mono: 单调时钟
boot: 启动时间
x86-tsc: x86 时间戳计数器

总结

本文在真实的 Ubuntu 24.04 服务器上，全面实操了 Linux 事件追踪工具链：

ftrace 基础：了解了 11 种可用追踪器，掌握了通过/sys/kernel/tracing/配置追踪的方法
function 追踪器：捕获了 1 秒内 18 万条内核函数调用记录，理解了输出格式
function_graph 追踪器：以调用图形式展示了函数嵌套关系和微秒级耗时
函数过滤：使用set_ftrace_filter精确追踪schedule函数，减少输出噪声
Trace Events：启用了sched_process_exec事件，追踪进程执行
perf 工具：使用perf stat统计性能事件、perf record/report进行采样分析
perf 事件分类：了解了硬件事件、软件事件和 Tracepoint 事件的区别
strace：统计和过滤系统调用，分析了ls命令的完整 I/O 流程
ltrace：追踪库函数调用
/proc 接口：通过/proc/[pid]/syscall和/proc/[pid]/stack查看进程的实时系统调用和内核栈

事件追踪是系统级调试和性能优化的核心技能。掌握这些工具，你将能够：

定位性能瓶颈（perf + function_graph）
理解内核行为（ftrace + trace events）
调试程序问题（strace + ltrace）
分析系统调用和内核栈（/proc 接口）

Linux 事件追踪深度实操：ftrace、perf、strace 与 ltrace