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 基础内核内置的追踪框架ftraceFunction 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 追踪mmiotraceMMIO内存映射 I/O追踪nop无操作用于事件追踪1.2 查看当前追踪器cat/sys/kernel/tracing/current_tracer实际输出nop1.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 tracerechofunction/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: 进程名和 PIDCPU#: 在哪个 CPU 核心上执行5 个标志位: irqs-off / need-resched / hardirq-softirq / preempt-depth / migrate-disableTIMESTAMP: 相对追踪开始的时间戳秒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_tracerechoschedule/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_runtime5.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 pid9893 old_pid9893 sleep-9894 [001] ..... 3924.964671: sched_process_exec: filename/usr/bin/sleep pid9894 old_pid9894sched_process_exec事件在进程执行exec()系统调用时触发可以看到ls和sleep命令的执行记录包括文件名和 PID 信息。六、perf 工具性能分析利器6.1 安装 perfapt-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 万个时钟周期IPCInstructions 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 [.] 0x00000000000b5ac5perf report 显示了 CPU 时间在各个函数上的分布50% 在内核的_raw_spin_unlock_irq50% 在 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 totalls /tmp共执行了 74 次系统调用其中 18 次 mmap、9 次 close、7 次 openat、5 次 read。有 5 次错误ioctl 1 次、access 2 次、statfs 2 次。7.2 strace -e过滤特定系统调用strace-etraceopenat,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]/stack9.1 查看进程当前系统调用sleep30SLEEP_PID$!cat/proc/$SLEEP_PID/syscallcat/proc/$SLEEP_PID/stackkill$SLEEP_PID实际输出230 0x0 0x0 0x7ffd9a439230 0x7ffd9a439220 0x0 0x0 0x7ffd9a439160 0x70113caeca7a [0] hrtimer_nanosleep0xa2/0x170 [0] common_nsleep0x43/0x60 [0] __x64_sys_clock_nanosleep0xf4/0x180 [0] x64_sys_call0x1c2c/0x25a0 [0] do_syscall_640x7f/0x180 [0] entry_SYSCALL_64_after_hwframe0x78/0x80解析/proc/[pid]/syscall: 第一个数字 230 是系统调用号clock_nanosleep后面是参数/proc/[pid]/stack: 内核栈回溯显示从硬件中断入口到当前执行点的完整调用链9.2 查看当前进程的内核栈cat/proc/self/stack实际输出[0] proc_pid_stack0xed/0x170 [0] proc_single_show0x56/0xe0 [0] seq_read_iter0x132/0x4b0 [0] seq_read0x11c/0x160 [0] vfs_read0xb4/0x3a0 [0] ksys_read0x73/0x100 [0] __x64_sys_read0x19/0x30 [0] x64_sys_call0x1bf0/0x25a0 [0] do_syscall_640x7f/0x180 [0] entry_SYSCALL_64_after_hwframe0x78/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_free10.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 接口