系统性能追踪工具perf/strace

 2025/04/29 

perf收集系统性能

Linux性能计数器(PCL)是一个基于内核的子系统，它为收集和分析性能数据提供了一个框架。在Red Hat Enterprise Linux 8中包含了PCL和PERF。

PERF是一个功能强大的分析基础设施，它提供了一套用户空间工具用来分析收集到的性能数据

perf stat

yum install -y perf
yum -y install kernel-debug

# 查看当前可追踪的性能事件
perf list

# 追踪具体性能时间
perf stat

perf stat dd if=/dev/zero of=/dev/null bs=2048 count=10000

perf stat -e 查看指定
perf stat -a 监控整个系统

# 指定task-clock和context-switches参数进行查看
perf stat -e task-clock,context-switches -a sleep 10
 Performance counter stats for 'system wide':

         120015.45 msec task-clock                       #   12.000 CPUs utilized
             88434      context-switches                 #  736.855 /sec
      10.001622745 seconds time elapsed

perf stat性能指标类型

术语	说明	单位/备注
task-clock	任务真正占用的处理器时间	毫秒 (ms)
context-switches	上下文切换次数	次/秒
CPU-migrations	处理器迁移次数（Linux 为维持多核负载均衡，将任务从一个 CPU 迁移到另一个 CPU 的次数）	次/秒
page-faults	缺页异常次数（包括：页面未建立、页面不在内存、页面映射未建立、TLB 不命中、权限不匹配等情况触发）	次/秒（示例值：133.338 K/sec）
cycles	消耗的处理器周期数	无（可通过 `cycles / task-clock` 计算主频）
instructions	执行的指令总数	无（IPC = `instructions / cycles`）
branches	分支指令数	次/秒
branch-misses	分支预测失败次数	次/秒

perf record/perf report

记录程序的性能事件数据，生成一个名为 perf.data 的二进制文件，后续可通过 perf report 或 perf script 进行详细分析

perf record dd if=/dev/zero of=/dev/null bs=2048 count=10000
10000+0 records in
10000+0 records out
20480000 bytes (20 MB, 20 MiB) copied, 0.0120586 s, 1.7 GB/s
[ perf record: Woken up 1 times to write data ]
[ perf record: Captured and wrote 0.018 MB perf.data (51 samples) ]

# 交互式查看，默认寻找当前目录下的perf.data文件
perf report

# 非交互式查看
perf report --stdio
# ........  .......  .................  ................................
#
    25.49%  dd       [kernel.kallsyms]  [k] syscall_enter_from_user_mode
     9.80%  dd       libc.so.6          [.] __GI___libc_write
     7.84%  dd       [kernel.kallsyms]  [k] vfs_write
     5.88%  dd       [kernel.kallsyms]  [k] __audit_syscall_entry
     5.88%  dd       dd                 [.] 0x000000000000a3fb
     5.88%  dd       libc.so.6          [.] read
     3.92%  dd       [kernel.kallsyms]  [k] clear_user_original
     3.92%  dd       [kernel.kallsyms]  [k] read_zero
     3.92%  dd       [kernel.kallsyms]  [k] selinux_file_permission
     3.92%  dd       dd                 [.] 0x000000000000b580
     1.96%  dd       [kernel.kallsyms]  [k] __fdget_pos
     1.96%  dd       [kernel.kallsyms]  [k] __fget_light
....

# 指定文件查看性能数据
perf record -o 指定输出文件
perf record -o /root/per_sleep.data -a sleep 5

perf report -i 指定查看文件
perf report -i /root/per_sleep.data --stdio
# Overhead  Command          Shared Object             Symbol                                      >
# ........  ...............  ........................  ............................................>
#
    97.05%  swapper          [kernel.kallsyms]         [k] default_idle
     0.74%  swapper          [kernel.kallsyms]         [k] update_blocked_averages
     0.65%  swapper          [kernel.kallsyms]         [k] __do_softirq
     0.10%  swapper          [kernel.kallsyms]         [k] _raw_spin_unlock_irqrestore
     0.04%  swapper          [kernel.kallsyms]         [k] finish_task_switch.isra.0
     0.04%  swapper          [kernel.kallsyms]         [k] cpuidle_idle_call
     0.04%  rcu_preempt      [kernel.kallsyms]         [k] _raw_spin_unlock_irqrestore
     0.04%  swapper          [kernel.kallsyms]         [k] kmem_cache_free
...

perf archive/unpack

打包与压缩

perf archive

ls perf/
per_sleep.data  perf.data  perf.data.old  perf.data.tar.bz2

# 解压
perf archive --unpack
或
tar xvf perf.data.tar.bz2 -C ~/.debug

Found target file for unpacking: ./perf.data.tar.bz2
.build-id/19/0baf8361fd39db4ed8f784a421f6394b6a10ff
[kernel.kallsyms]/190baf8361fd39db4ed8f784a421f6394b6a10ff/
[kernel.kallsyms]/190baf8361fd39db4ed8f784a421f6394b6a10ff/kallsyms

默认解压到~/.debug的.build下
ls ~/.debug/.build-id/19/
0baf8361fd39db4ed8f784a421f6394b6a10ff

strace/ltrace追踪系统调用

系统调用/函数调用

要评估程序的性能，你必须度量程序执行的任务以及执行每个任务所需的时间。程序用它们的程序代码来完成任务。如果一个程序调用内核提供的函数，那么执行时间是在内核内部进行的。library提供的函数会导致程序在内核之外花费时间。从程序中调用”内核提供的函数是系统调用”，而由”库提供的函数称为库调用”。

strace追踪系统调用

显示进程进行的系统调用的信息。这个命令帮助标识出程序使用内核函数花费了多长时间。

yum -y install strace

# 查看uname
strace uname
输出了一堆

strace -c 统计调用次数
strace -c uname
Linux
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
  0.00    0.000000           0         1           read
  0.00    0.000000           0         1           write
  0.00    0.000000           0         3           open
  0.00    0.000000           0         5           close
  0.00    0.000000           0         4           fstat
  0.00    0.000000           0         9           mmap
  0.00    0.000000           0         4           mprotect
  0.00    0.000000           0         2           munmap
  0.00    0.000000           0         4           brk
  0.00    0.000000           0         3         3 access
  0.00    0.000000           0         1           execve

strace -p 追踪PID
strace -c -p 1189

strace -f 跟踪由进程fork产生的子进程(多线程)，如数据库、nginx

strace -e 过滤指定的systemcall类型
strace -e read -c uname -r # 只看read
3.10.0-1160.119.1.el7.x86_64
% time     seconds  usecs/call     calls    errors syscall
------ ----------- ----------- --------- --------- ----------------
  0.00    0.000000           0         1           read
------ ----------- ----------- --------- --------- ----------------
100.00    0.000000                     1           total

字段	说明
% time	该系统调用消耗的时间占总时间的百分比（所有系统调用时间的总和为 100%）
seconds	该系统调用消耗的总时间（单位：秒）
usecs/call	每次调用该系统调用所需的平均微秒时间（1 秒 = 1,000,000 微秒）
calls	该系统调用的总调用次数
errors	该系统调用执行时发生的错误次数（例如权限不足、文件不存在等）
syscall	系统调用的名称（例如 `openat`、`read`、`write`）