perf 静态跟踪点

下面是一个 Linux perf_events 静态跟踪点的简单示例:跟踪磁盘 I/O。
我们将使用块 I/O 跟踪点来执行此操作。有很多可供选择,这些可以显示您的存储设备被要求执行的操作以及它们的性能的详细信息。列出跟踪点:

sudo perf list ‘block:*’

block:block_touch_buffer [跟踪点事件]
block:block_dirty_buffer [跟踪点事件]
block:block_rq_abort [跟踪点事件]
block:block_rq_requeue [跟踪点事件]
block:block_rq_complete [跟踪点事件]
block:block_rq_insert [跟踪点事件]
block:block_rq_issue [跟踪点事件]
block:block_bio_bounce [跟踪点事件]
block:block_bio_complete [跟踪点事件]
block:block_bio_backmerge [跟踪点事件]
[…]
这些仅对 root 用户可见。我将使用 block_rq_complete,它跟踪 I/O 完成,并跟踪它 10 秒。这会将事件(“样本”)写入 perf.data 文件,然后我将打印该文件:

sudo perf record -e block:block_rq_complete -a sleep 10

[性能记录:唤醒1次写入数据]
[性能记录:捕获并写入 0.428 MB perf.data(~18687 个样本)]

sudo 性能脚本

    运行 30339 [000] 2083345.722767: block:block_rq_complete: 202,1 W () 12984648 + 8 [0]
    运行 30339 [000] 2083345.722857: block:block_rq_complete: 202,1 W () 12986336 + 8 [0]
    运行 30339 [000] 2083345.723180: block:block_rq_complete: 202,1 W () 12986528 + 8 [0]
交换器 0 [000] 2083345.723489:块:block_rq_complete:202,1 W () 12986496 + 8 [0]
交换器 0 [000] 2083346.745840:块:block_rq_complete:202,1 WS () 1052984 + 144 [0]

监督 30342 [000] 2083346.746571: block:block_rq_complete: 202,1 WS () 1053128 + 8 [0]
监督 30342 [000] 2083346.746663: block:block_rq_complete: 202,1 W () 12986608 + 8 [0]
运行 30342 [000] 2083346.747003: block:block_rq_complete: 202,1 W () 12986832 + 8 [0]
[…]
我在 AWS EC2 实例上对此进行了跟踪,因此这些是虚拟磁盘设备。由于虚拟化开销,虚拟磁盘会表现出较慢的 I/O,并且由于邻居导致的差异较大,因此任何可以帮助我们调整和减少 I/O 的信息在这里都比裸机系统更重要。
每个磁盘 I/O 完成都显示为一行输出。第 4 列和第 5 列很明显:时间戳(以秒为单位)和跟踪点描述。前几列是一些额外信息:on-CPU 命令和 PID,以及命中跟踪点的 CPU 编号。
其余列 (6+) 显示有关块 I/O 的详细信息。例如,阅读第一行:
202,1:存储设备主要和次要编号
W:I/O 类型(W=write,R=read,A=readahead,S=sync,…)
():可以包含块命令详细信息(例如,十六进制的 SCSI 命令)
12984648:存储设备偏移
8: size of I/O (in sectors)
[0]: errors
This is really convenient, and a similar string of goodies is baked into all static tracepoints. Of course, if you want to access this in binary, or access custom data, you can do that too.
Note that the tracepoint strings can change between kernel versions, so if you start consuming these you’ll need to watch out for changes. Here’s where this example comes from in the 3.14.5 kernel source:
include/trace/events/block.h:
TRACE_EVENT(block_rq_complete,
[…]
TP_printk(“%d,%d %s (%s) %llu + %u [%d]”,
MAJOR(__entry->dev), MINOR(__entry->dev),
__entry->rwbs, __get_str(cmd),
(unsigned long long)__entry->sector,
__entry->nr_sector, __entry->errors)
您还可以转储跟踪点格式文件作为提醒:

sudo cat /sys/kernel/debug/tracing/events/block/block_rq_complete/format

名称:block_rq_complete
编号:942
格式:
字段:无符号短 common_type;偏移量:0;尺寸:2;签名:0;
字段:无符号字符 common_flags;偏移量:2;尺寸:1;签名:0;
字段:无符号字符 common_preempt_count;偏移量:3;尺寸:1;签名:0;
字段:int common_pid;偏移量:4;尺寸:4;签名:1;

字段:dev_t 开发;偏移量:8;尺寸:4;签名:0;
字段:sector_t 扇区;偏移量:16;尺寸:8;签名:0;
字段:无符号整数 nr_sector;偏移量:24;尺寸:4;签名:0;
字段:int错误;偏移量:28;尺寸:4;签名:1;
字段:字符 rwbs[8];偏移量:32;尺寸:8;签名:1;
字段:__data_loc char[] cmd;偏移量:40;尺寸:4;签名:1;

print fmt: “%d,%d %s (%s) %llu + %u [%d]”, ((unsigned int) ((REC->dev) >> 20)), ((unsigned int) ( (REC->dev) & ((1U << 20) - 1))), REC->rwbs, __get_str(cmd), (unsigned long long)REC->sector, REC->nr_sector, REC->errors
这以 perf_events 默认读取的格式字符串结束。
perf_events 不仅可以捕获此跟踪点及其格式字符串:它还可以捕获导致事件的堆栈跟踪,并根据需要执行自定义内核过滤。
除了块 I/O,Linux 内核的许多领域也有静态跟踪点:
您还可以使用 perf_events 创建动态跟踪点(动态跟踪),以查看静态跟踪点未覆盖的区域。可能性是无止境。
有关更多示例,请参见我的perf_events页面,以及我之前关于使用 perf_events 进行 CPU 采样的文章。

转载翻译自: https://www.brendangregg.com