直方图设计说明¶
- 作者:
Tom Zanussi <zanussi@kernel.org>
本文档试图描述 ftrace 直方图的工作原理，以及各个部分如何映射到在 trace_events_hist.c 和 tracing_map.c 中实现它们的数据结构。
注意
所有 ftrace 直方图命令示例都假定工作目录是 ftrace 的 /tracing 目录。例如
# cd /sys/kernel/tracing
此外，这些命令显示的直方图输出通常会被截断 —— 仅显示足以说明问题的内容。
‘hist_debug’ 跟踪事件文件¶
如果编译内核时设置了 CONFIG_HIST_TRIGGERS_DEBUG，每个事件的子目录中将出现一个名为 ‘hist_debug’ 的事件文件。该文件可以随时读取，并将显示本文档中描述的一些直方图触发器内部信息。具体示例和输出将在下面的测试用例中描述。
基本直方图¶
首先是基本直方图。下面几乎是你可以对直方图做的最简单的事情 —— 在单个事件上使用单个键创建一个直方图并 cat 输出
# echo 'hist:keys=pid' >> events/sched/sched_waking/trigger
# cat events/sched/sched_waking/hist
{ pid: 18249 } hitcount: 1
{ pid: 13399 } hitcount: 1
{ pid: 17973 } hitcount: 1
{ pid: 12572 } hitcount: 1
...
{ pid: 10 } hitcount: 921
{ pid: 18255 } hitcount: 1444
{ pid: 25526 } hitcount: 2055
{ pid: 5257 } hitcount: 2055
{ pid: 27367 } hitcount: 2055
{ pid: 1728 } hitcount: 2161
Totals:
Hits: 21305
Entries: 183
Dropped: 0
这段代码的作用是：在 sched_waking 事件上创建一个直方图，使用 pid 作为键，并包含一个单一的值 hitcount（命中计数）。即使未明确指定，hitcount 也始终存在于每个直方图中。
hitcount 值是一个每个桶（per-bucket）的值，对于给定的键（在本例中是 pid），每次命中时都会自动递增。
因此，在这个直方图中，每个 pid 都有一个单独的桶，每个桶都包含该桶的一个值，用于计算针对该 pid 调用 sched_waking 的次数。
每个直方图都由一个 hist_data 结构体（struct hist_trigger_data）表示。
为了跟踪直方图中的每个键和值字段，hist_data 维护了一个名为 fields[] 的字段数组。fields[] 数组包含直方图中每个直方图值和键的 struct hist_field 表示（这里也包括变量，但稍后讨论）。因此，对于上面的直方图，我们有一个键和一个值；在本例中，这个值就是 hitcount 值。所有直方图都具有该值，无论它们是否显式定义了该值（上面的直方图就没有定义）。
每个 struct hist_field 都包含一个指向事件的 trace_event_file 中的 ftrace_event_field 的指针，以及与其相关的各种位，例如大小、偏移量、类型和一个直方图字段函数，该函数用于从 ftrace 事件缓冲区中获取字段的数据（在大多数情况下 —— 某些 hist_fields（例如 hitcount）不直接映射到跟踪缓冲区中的事件字段 —— 在这些情况下，函数实现从其他地方获取其值）。flags 字段指示它是哪种类型的字段 —— 键、值、变量、变量引用等，其中值为默认值。
除了 fields[] 数组外，另一个重要的 hist_data 数据结构是为直方图创建的 tracing_map 实例，它保存在 .map 成员中。tracing_map 实现了用于实现直方图的无锁哈希表（有关实现 tracing_map 的底层数据结构的更多讨论，请参见 kernel/trace/tracing_map.h）。就本文讨论而言，tracing_map 包含多个桶，每个桶对应一个由给定直方图键哈希得到的特定 tracing_map_elt 对象。
下面是一个图表，其第一部分描述了上面描述的直方图的 hist_data 以及相关的键和值字段。如你所见，fields 数组中有两个字段，一个是用于 hitcount 的值字段，另一个是用于 pid 键的键字段。
其下方是给定运行中 tracing_map 运行时的快照图。它试图展示对于几个假设的键和值，hist_data 字段与 tracing_map 元素之间的关系。
+------------------+
| hist_data |
+------------------+ +----------------+
| .fields[] |---->| val = hitcount |----------------------------+
+----------------+ +----------------+ |
| .map | | .size | |
+----------------+ +--------------+ |
| .offset | |
+--------------+ |
| .fn() | |
+--------------+ |
. |
. |
. |
+----------------+ <--- n_vals |
| key = pid |----------------------------|--+
+----------------+ | |
| .size | | |
+--------------+ | |
| .offset | | |
+--------------+ | |
| .fn() | | |
+----------------+ <--- n_fields | |
| unused | | |
+----------------+ | |
| | | |
+--------------+ | |
| | | |
+--------------+ | |
| | | |
+--------------+ | |
n_keys = n_fields - n_vals | |
hist_data 的 n_vals 和 n_fields 划定了 fields[] 数组的范围，并在其余代码中将键与值分开。
下面是直方图的 tracing_map 部分的运行时表示，其中包含从 fields[] 数组各个部分到 tracing_map 相应部分的指针。
tracing_map 由一个 tracing_map_entry 数组和一组预分配的 tracing_map_elt（下面简称为 map_entry 和 map_elt）组成。hist_data.map 数组中 map_entry 的总数 = map->max_elts（实际上是 map->map_size，但其中只有 max_elts 被使用。这是 map_insert() 算法所要求的属性）。
如果某个 map_entry 未被使用（意味着尚无键哈希到其中），则其 .key 值为 0，且其 .val 指针为 NULL。一旦某个 map_entry 被占用，.key 值就包含该键的哈希值，且 .val 成员指向一个 map_elt，该 map_elt 包含完整的键以及 map_elt.fields[] 数组中每个键或值的条目。map_elt.fields[] 数组中有一个条目对应直方图中的每个 hist_field，与每个直方图值相对应的持续聚合总和就保存在这里。
该图试图通过在图表之间绘制的链接来展示 hist_data.fields[] 与 map_elt.fields[] 之间的关系
+-----------+ | |
| hist_data | | |
+-----------+ | |
| .fields | | |
+---------+ +-----------+ | |
| .map |---->| map_entry | | |
+---------+ +-----------+ | |
| .key |---> 0 | |
+---------+ | |
| .val |---> NULL | |
+-----------+ | |
| map_entry | | |
+-----------+ | |
| .key |---> pid = 999 | |
+---------+ +-----------+ | |
| .val |--->| map_elt | | |
+---------+ +-----------+ | |
. | .key |---> full key * | |
. +---------+ +---------------+ | |
. | .fields |--->| .sum (val) |<-+ |
+-----------+ +---------+ | 2345 | | |
| map_entry | +---------------+ | |
+-----------+ | .offset (key) |<----+
| .key |---> 0 | 0 | | |
+---------+ +---------------+ | |
| .val |---> NULL . | |
+-----------+ . | |
| map_entry | . | |
+-----------+ +---------------+ | |
| .key | | .sum (val) or | | |
+---------+ +---------+ | .offset (key) | | |
| .val |--->| map_elt | +---------------+ | |
+-----------+ +---------+ | .sum (val) or | | |
| map_entry | | .offset (key) | | |
+-----------+ +---------------+ | |
| .key |---> pid = 4444 | |
+---------+ +-----------+ | |
| .val | | map_elt | | |
+---------+ +-----------+ | |
| .key |---> full key * | |
+---------+ +---------------+ | |
| .fields |--->| .sum (val) |<-+ |
+---------+ | 65523 | |
+---------------+ |
| .offset (key) |<----+
| 0 |
+---------------+
.
.
.
+---------------+
| .sum (val) or |
| .offset (key) |
+---------------+
| .sum (val) or |
| .offset (key) |
+---------------+
图表中使用的缩写
hist_data = struct hist_trigger_data
hist_data.fields = struct hist_field
fn = hist_field_fn_t
map_entry = struct tracing_map_entry
map_elt = struct tracing_map_elt
map_elt.fields = struct tracing_map_field
每当发生新事件且该事件关联了一个直方图触发器时，就会调用 event_hist_trigger()。event_hist_trigger() 首先处理键：对于键中的每个子键（在上面的例子中，只有一个对应于 pid 的子键），从 hist_data.fields[] 中检索表示该子键的 hist_field，并使用与该字段关联的直方图字段函数以及字段的大小和偏移量，从当前跟踪记录中获取该子键的数据。
注意，直方图字段函数过去是 hist_field 结构体中的一个函数指针。由于幽灵（Spectre）漏洞缓解措施，它被转换为一个 fn_num，并使用 hist_fn_call() 来调用与 hist_field 结构体的 fn_num 相对应的关联直方图字段函数。
一旦检索到完整的键，它就会被用来在 tracing_map 中查找该键。如果没有与该键关联的 tracing_map_elt，则会占用一个空元素并将其插入到映射中以对应新键。无论哪种情况，都会返回与该键关联的 tracing_map_elt。
一旦 tracing_map_elt 可用，就会调用 hist_trigger_elt_update()。顾名思义，这会更新元素，基本上意味着更新元素的字段。直方图中的每个键和值都关联有一个 tracing_map_field，这些字段分别对应于创建直方图时创建的键和值 hist_field。hist_trigger_elt_update() 遍历每个值的 hist_field，并且像处理键一样，使用 hist_field 的函数、大小和偏移量从当前跟踪记录中获取字段的值。一旦获取了该值，它只需将该值加到该字段不断更新的 tracing_map_field.sum 成员中。某些 hist_field 函数（例如用于 hitcount 的函数）实际上并不从跟踪记录中抓取任何内容（hitcount 函数只是将计数器总和加 1），但其思想是相同的。
一旦所有值都已更新，hist_trigger_elt_update() 即完成并返回。请注意，键中的每个子键也有对应的 tracing_map_fields，但 hist_trigger_elt_update() 不会查看它们或更新任何内容 —— 这些字段仅用于排序（排序可以在稍后进行）。
基本直方图测试¶
这是一个很好的尝试示例。它在输出中产生 3 个值字段和 2 个键字段
# echo 'hist:keys=common_pid,call_site.sym:values=bytes_req,bytes_alloc,hitcount' >> events/kmem/kmalloc/trigger
要查看调试数据，请 cat kmem/kmalloc 的 ‘hist_debug’ 文件。它将显示与其对应的直方图的触发器信息，以及与直方图关联的 hist_data 的地址（这在后面的示例中会很有用）。然后，它显示与直方图关联的 hist_fields 总数，以及其中有多少对应于键、多少对应于值的计数。
接下来，它显示每个字段的详细信息，包括字段的标志以及每个字段在 hist_data 的 fields[] 数组中的位置。这些是有用的信息，可用于验证内部情况是否正确，这在以后的示例中将变得更加有用
# cat events/kmem/kmalloc/hist_debug
# event histogram
#
# trigger info: hist:keys=common_pid,call_site.sym:vals=hitcount,bytes_req,bytes_alloc:sort=hitcount:size=2048 [active]
#
hist_data: 000000005e48c9a5
n_vals: 3
n_keys: 2
n_fields: 5
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
VAL: normal u64 value
ftrace_event_field name: bytes_req
type: size_t
size: 8
is_signed: 0
hist_data->fields[2]:
flags:
VAL: normal u64 value
ftrace_event_field name: bytes_alloc
type: size_t
size: 8
is_signed: 0
key fields:
hist_data->fields[3]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: common_pid
type: int
size: 8
is_signed: 1
hist_data->fields[4]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: call_site
type: unsigned long
size: 8
is_signed: 0
可以使用以下命令清理环境以为下一次测试做准备
# echo '!hist:keys=common_pid,call_site.sym:values=bytes_req,bytes_alloc,hitcount' >> events/kmem/kmalloc/trigger
变量¶
变量允许一个直方图触发器保存某个直方图触发器的数据，并由另一个直方图触发器检索该数据。例如，sched_waking 事件上的触发器可以捕获特定 pid 的时间戳，随后切换到该 pid 事件的 sched_switch 事件可以获取该时间戳并使用它来计算两个事件之间的时间差
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >>
events/sched/sched_waking/trigger
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0' >>
events/sched/sched_switch/trigger
从直方图数据结构的角度来看，变量被实现为另一种类型的 hist_field，对于给定的直方图触发器，它们被添加到所有值字段之后的 hist_data.fields[] 数组中。为了将它们与现有的键和值字段区分开来，赋予了它们一个新的标志类型 HIST_FIELD_FL_VAR（简称为 FL_VAR），它们还利用了 struct hist_field 中的一个新的 .var.idx 字段成员，该成员将它们映射到专门为存储和检索变量值而添加到 map_elt 的新 map_elt.vars[] 数组中的索引。下图展示了这些新元素，并添加了一个新的变量条目 ts0，它对应于上面 sched_waking 触发器中的 ts0 变量。
sched_waking 直方图¶
+------------------+
| hist_data |<-------------------------------------------------------+
+------------------+ +-------------------+ |
| .fields[] |-->| val = hitcount | |
+----------------+ +-------------------+ |
| .map | | .size | |
+----------------+ +-----------------+ |
| .offset | |
+-----------------+ |
| .fn() | |
+-----------------+ |
| .flags | |
+-----------------+ |
| .var.idx | |
+-------------------+ |
| var = ts0 | |
+-------------------+ |
| .size | |
+-----------------+ |
| .offset | |
+-----------------+ |
| .fn() | |
+-----------------+ |
| .flags & FL_VAR | |
+-----------------+ |
| .var.idx |----------------------------+-+ |
+-----------------+ | | |
. | | |
. | | |
. | | |
+-------------------+ <--- n_vals | | |
| key = pid | | | |
+-------------------+ | | |
| .size | | | |
+-----------------+ | | |
| .offset | | | |
+-----------------+ | | |
| .fn() | | | |
+-----------------+ | | |
| .flags & FL_KEY | | | |
+-----------------+ | | |
| .var.idx | | | |
+-------------------+ <--- n_fields | | |
| unused | | | |
+-------------------+ | | |
| | | | |
+-----------------+ | | |
| | | | |
+-----------------+ | | |
| | | | |
+-----------------+ | | |
| | | | |
+-----------------+ | | |
| | | | |
+-----------------+ | | |
n_keys = n_fields - n_vals | | |
| | |
这与基本情况非常相似。在上面的图表中，我们可以看到向 struct hist_field 结构体添加了一个新的 .flags 成员，并且向 hist_data.fields 添加了一个代表 ts0 变量的新条目。对于普通的值 hist_field，.flags 只是 0（对修饰符标志取模），如果该值被定义为变量，则 .flags 包含置位的 FL_VAR 位。
如你所见，ts0 条目的 .var.idx 成员包含指向包含变量值的 tracing_map_elts 的 .vars[] 数组的索引。每当设置或读取变量的值时，都会使用此 idx。分配给给定变量的 map_elt.vars idx 在调用 tracing_map_add_var() 之后，由 create_tracing_map_fields() 分配并保存在 .var.idx 中。
下面是运行时直方图的表示，它填充了映射，并对应于上面的 hist_data 和 hist_field 数据结构。
该图试图通过在图表之间绘制的链接来展示 hist_data.fields[] 与 map_elt.fields[] 和 map_elt.vars[] 之间的关系。对于每个 map_elt，你可以看到 .fields[] 成员指向键或值的 .sum 或 .offset，而 .vars[] 成员指向变量的值。两个图表之间的箭头显示了这些 tracing_map 成员与相应 hist_data fields[] 成员中的字段定义之间的链接。
+-----------+ | | |
| hist_data | | | |
+-----------+ | | |
| .fields | | | |
+---------+ +-----------+ | | |
| .map |---->| map_entry | | | |
+---------+ +-----------+ | | |
| .key |---> 0 | | |
+---------+ | | |
| .val |---> NULL | | |
+-----------+ | | |
| map_entry | | | |
+-----------+ | | |
| .key |---> pid = 999 | | |
+---------+ +-----------+ | | |
| .val |--->| map_elt | | | |
+---------+ +-----------+ | | |
. | .key |---> full key * | | |
. +---------+ +---------------+ | | |
. | .fields |--->| .sum (val) | | | |
. +---------+ | 2345 | | | |
. +--| .vars | +---------------+ | | |
. | +---------+ | .offset (key) | | | |
. | | 0 | | | |
. | +---------------+ | | |
. | . | | |
. | . | | |
. | . | | |
. | +---------------+ | | |
. | | .sum (val) or | | | |
. | | .offset (key) | | | |
. | +---------------+ | | |
. | | .sum (val) or | | | |
. | | .offset (key) | | | |
. | +---------------+ | | |
. | | | |
. +---------------->+---------------+ | | |
. | ts0 |<--+ | |
. | 113345679876 | | | |
. +---------------+ | | |
. | unused | | | |
. | | | | |
. +---------------+ | | |
. . | | |
. . | | |
. . | | |
. +---------------+ | | |
. | unused | | | |
. | | | | |
. +---------------+ | | |
. | unused | | | |
. | | | | |
. +---------------+ | | |
. | | |
+-----------+ | | |
| map_entry | | | |
+-----------+ | | |
| .key |---> pid = 4444 | | |
+---------+ +-----------+ | | |
| .val |--->| map_elt | | | |
+---------+ +-----------+ | | |
. | .key |---> full key * | | |
. +---------+ +---------------+ | | |
. | .fields |--->| .sum (val) | | | |
+---------+ | 2345 | | | |
+--| .vars | +---------------+ | | |
| +---------+ | .offset (key) | | | |
| | 0 | | | |
| +---------------+ | | |
| . | | |
| . | | |
| . | | |
| +---------------+ | | |
| | .sum (val) or | | | |
| | .offset (key) | | | |
| +---------------+ | | |
| | .sum (val) or | | | |
| | .offset (key) | | | |
| +---------------+ | | |
| | | |
| +---------------+ | | |
+---------------->| ts0 |<--+ | |
| 213499240729 | | |
+---------------+ | |
| unused | | |
| | | |
+---------------+ | |
. | |
. | |
. | |
+---------------+ | |
| unused | | |
| | | |
+---------------+ | |
| unused | | |
| | | |
+---------------+ | |
对于每个已使用的映射条目，都有一个 map_elt 指向一个 .vars 数组，该数组包含与该直方图条目关联的变量的当前值。因此，在上面中，与 pid 999 关联的时间戳是 113345679876，而 pid 4444 在相同 .var.idx 中的时间戳变量是 213499240729。
sched_switch 直方图¶
与上述 sched_waking 直方图配对的 sched_switch 直方图如下所示。sched_switch 直方图最重要的方面是它引用了上面 sched_waking 直方图上的一个变量。
直方图图表与迄今为止显示的其他图表非常相似，但它添加了变量引用。你可以看到常规的 hitcount 和键字段，以及以与 sched_waking ts0 变量相同的方式实现的新 wakeup_lat 变量，此外还有一个带有新 FL_VAR_REF（HIST_FIELD_FL_VAR_REF 的简写）标志的条目。
与新的变量引用字段关联的是几个新的 hist_field 成员：var.hist_data 和 var_ref_idx。对于变量引用，var.hist_data 与 var.idx 配合使用，它们共同唯一标识特定直方图上的特定变量。var_ref_idx 只是 var_ref_vals[] 数组的索引，每当直方图触发器更新时，该数组都会缓存每个变量的值。然后，其他代码（例如使用 var_ref_idx 值来分配参数值的跟踪动作代码）最终会访问这些结果值。
下图描述了前面提到的 sched_switch 直方图的情况
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0' >>
events/sched/sched_switch/trigger
| |
+------------------+ | |
| hist_data | | |
+------------------+ +-----------------------+ | |
| .fields[] |-->| val = hitcount | | |
+----------------+ +-----------------------+ | |
| .map | | .size | | |
+----------------+ +---------------------+ | |
+--| .var_refs[] | | .offset | | |
| +----------------+ +---------------------+ | |
| | .fn() | | |
| var_ref_vals[] +---------------------+ | |
| +-------------+ | .flags | | |
| | $ts0 |<---+ +---------------------+ | |
| +-------------+ | | .var.idx | | |
| | | | +---------------------+ | |
| +-------------+ | | .var.hist_data | | |
| | | | +---------------------+ | |
| +-------------+ | | .var_ref_idx | | |
| | | | +-----------------------+ | |
| +-------------+ | | var = wakeup_lat | | |
| . | +-----------------------+ | |
| . | | .size | | |
| . | +---------------------+ | |
| +-------------+ | | .offset | | |
| | | | +---------------------+ | |
| +-------------+ | | .fn() | | |
| | | | +---------------------+ | |
| +-------------+ | | .flags & FL_VAR | | |
| | +---------------------+ | |
| | | .var.idx | | |
| | +---------------------+ | |
| | | .var.hist_data | | |
| | +---------------------+ | |
| | | .var_ref_idx | | |
| | +---------------------+ | |
| | . | |
| | . | |
| | . | |
| | +-----------------------+ <--- n_vals | |
| | | key = pid | | |
| | +-----------------------+ | |
| | | .size | | |
| | +---------------------+ | |
| | | .offset | | |
| | +---------------------+ | |
| | | .fn() | | |
| | +---------------------+ | |
| | | .flags | | |
| | +---------------------+ | |
| | | .var.idx | | |
| | +-----------------------+ <--- n_fields | |
| | | unused | | |
| | +-----------------------+ | |
| | | | | |
| | +---------------------+ | |
| | | | | |
| | +---------------------+ | |
| | | | | |
| | +---------------------+ | |
| | | | | |
| | +---------------------+ | |
| | | | | |
| | +---------------------+ | |
| | n_keys = n_fields - n_vals | |
| | | |
| | | |
| | +-----------------------+ | |
+---------------------->| var_ref = $ts0 | | |
| +-----------------------+ | |
| | .size | | |
| +---------------------+ | |
| | .offset | | |
| +---------------------+ | |
| | .fn() | | |
| +---------------------+ | |
| | .flags & FL_VAR_REF | | |
| +---------------------+ | |
| | .var.idx |--------------------------+ |
| +---------------------+ |
| | .var.hist_data |----------------------------+
| +---------------------+
+---| .var_ref_idx |
+---------------------+
图表中使用的缩写
hist_data = struct hist_trigger_data
hist_data.fields = struct hist_field
fn = hist_field_fn_t
FL_KEY = HIST_FIELD_FL_KEY
FL_VAR = HIST_FIELD_FL_VAR
FL_VAR_REF = HIST_FIELD_FL_VAR_REF
当直方图触发器使用变量时，会创建一个带有 HIST_FIELD_FL_VAR_REF 标志的新 hist_field。对于 VAR_REF 字段，var.idx 和 var.hist_data 采用与被引用变量相同的值，以及被引用变量的大小、类型和 is_signed 值。VAR_REF 字段的 .name 设置为它引用的变量的名称。如果使用显式的 system.event.$var_ref 符号创建了变量引用，则还会设置 hist_field 的 system 和 event_name 变量。
因此，为了处理 sched_switch 直方图的事件，由于我们引用了另一个直方图上的变量，我们需要首先解析所有变量引用。这是通过从 event_hist_trigger() 调用的 resolve_var_refs() 来完成的。这会从代表 sched_switch 直方图的 hist_data 中获取 var_refs[] 数组。对于其中的每一个，使用被引用变量的 var.hist_data 以及当前的键来查找该直方图中的相应 tracing_map_elt。一旦找到，就使用被引用变量的 var.idx 通过 tracing_map_read_var(elt, var.idx) 查找变量的值，这会产生该元素（在上面的例子中是 ts0）的变量值。请注意，代表变量和变量引用的 hist_fields 具有相同的 var.idx，因此这很简单直接。
变量和变量引用测试¶
此示例在 sched_waking 事件上创建一个变量 ts0，并在 sched_switch 触发器中使用它。sched_switch 触发器还创建了自己的变量 wakeup_lat，但尚未使用它
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0' >> events/sched/sched_switch/trigger
查看 sched_waking 的 hist_debug 输出，除了常规的键和值 hist_fields 之外，我们在值字段部分看到一个带有 HIST_FIELD_FL_VAR 标志的字段，这表明该字段代表一个变量。请注意，除了包含在 var.name 字段中的变量名之外，它还包括 var.idx，这是实际变量位置在 tracing_map_elt.vars[] 数组中的索引。还要注意的是，输出显示变量与常规值位于 hist_data->fields[] 数组的同一部分
# cat events/sched/sched_waking/hist_debug
# event histogram
#
# trigger info: hist:keys=pid:vals=hitcount:ts0=common_timestamp.usecs:sort=hitcount:size=2048:clock=global [active]
#
hist_data: 000000009536f554
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: ts0
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 8
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: pid
type: pid_t
size: 8
is_signed: 1
转向 sched_switch 触发器的 hist_debug 输出，除了未使用的 wakeup_lat 变量外，我们看到了一个显示变量引用的新部分。变量引用显示在一个单独的部分中，因为除了在逻辑上与变量和值分离之外，它们实际上存在于一个单独的 hist_data 数组 var_refs[] 中。
在此示例中，sched_switch 触发器对 sched_waking 触发器上的变量 $ts0 具有引用。查看详细信息，我们可以看到被引用变量的 var.hist_data 值与之前显示的 sched_waking 触发器相匹配，并且 var.idx 值与该变量先前显示的 var.idx 值相匹配。同时显示的还有该变量引用的 var_ref_idx 值，调用触发器时该变量的值会缓存在此处供使用
# cat events/sched/sched_switch/hist_debug
# event histogram
#
# trigger info: hist:keys=next_pid:vals=hitcount:wakeup_lat=common_timestamp.usecs-$ts0:sort=hitcount:size=2048:clock=global [active]
#
hist_data: 00000000f4ee8006
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 0
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: next_pid
type: pid_t
size: 8
is_signed: 1
variable reference fields:
hist_data->var_refs[0]:
flags:
HIST_FIELD_FL_VAR_REF
name: ts0
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 000000009536f554
var_ref_idx (into hist_data->var_refs[]): 0
type: u64
size: 8
is_signed: 0
可以使用以下命令清理环境以为下一次测试做准备
# echo '!hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0' >> events/sched/sched_switch/trigger
# echo '!hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
动作和处理程序¶
在前一个示例的基础上，我们现在将对该 wakeup_lat 变量做一些事情，即将其和另一个字段作为合成事件发送。
下面的 onmatch() 动作基本上说明：每当我们有一个 sched_switch 事件时，如果我们有一个匹配的 sched_waking 事件（在本例中，如果在 sched_waking 直方图中的某个 pid 与此 sched_waking 事件上的 next_pid 字段相匹配），我们就会检索 wakeup_latency() 跟踪动作中指定的变量，并使用它们在跟踪流中生成一个新的 wakeup_latency 事件。
请注意，跟踪处理程序（例如 wakeup_latency()，其等效写法为 trace(wakeup_latency,$wakeup_lat,next_pid)）的实现方式决定了指定给跟踪处理程序的参数必须是变量。在这种情况下，$wakeup_lat 显然是一个变量，但 next_pid 不是，因为它只是命名了 sched_switch 跟踪事件中的一个字段。由于几乎每个 trace() 和 save() 动作都会这样做，因此实现了一种特殊的捷径，允许在这些情况下直接使用字段名。其工作原理是，在底层为命名的字段创建一个临时变量，而这个变量才是实际传递给跟踪处理程序的内容。在代码和文档中，这种类型的变量被称为“字段变量”。
也可以使用其他跟踪事件的直方图上的字段。在这种情况下，我们必须生成一个新的直方图和一个不幸命名为 synthetic_field 的字段（这里使用 synthetic 与合成事件无关），并将该特殊的直方图字段用作变量。
下图在结合使用 onmatch() 处理程序和 trace() 动作的 sched_switch 直方图的上下文中，说明了上面描述的新元素。
首先，我们定义 wakeup_latency 合成事件
# echo 'wakeup_latency u64 lat; pid_t pid' >> synthetic_events
接下来，像以前一样设置 sched_waking 直方图触发器
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >>
events/sched/sched_waking/trigger
最后，我们在 sched_switch 事件上创建一个直方图触发器，用于生成 wakeup_latency() 跟踪事件。在本例中，我们将 next_pid 传入 wakeup_latency 合成事件调用中，这意味着它将自动转换为字段变量
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \
onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid)' >>
/sys/kernel/tracing/events/sched/sched_switch/trigger
sched_switch 事件的图表与以前的示例类似，但显示了 hist_data 额外的 field_vars[] 数组，并显示了 field_vars 与为实现字段变量而创建的变量和引用之间的链接。详细信息讨论如下
+------------------+
| hist_data |
+------------------+ +-----------------------+
| .fields[] |-->| val = hitcount |
+----------------+ +-----------------------+
| .map | | .size |
+----------------+ +---------------------+
+---| .field_vars[] | | .offset |
| +----------------+ +---------------------+
|+--| .var_refs[] | | .offset |
|| +----------------+ +---------------------+
|| | .fn() |
|| var_ref_vals[] +---------------------+
|| +-------------+ | .flags |
|| | $ts0 |<---+ +---------------------+
|| +-------------+ | | .var.idx |
|| | $next_pid |<-+ | +---------------------+
|| +-------------+ | | | .var.hist_data |
||+>| $wakeup_lat | | | +---------------------+
||| +-------------+ | | | .var_ref_idx |
||| | | | | +-----------------------+
||| +-------------+ | | | var = wakeup_lat |
||| . | | +-----------------------+
||| . | | | .size |
||| . | | +---------------------+
||| +-------------+ | | | .offset |
||| | | | | +---------------------+
||| +-------------+ | | | .fn() |
||| | | | | +---------------------+
||| +-------------+ | | | .flags & FL_VAR |
||| | | +---------------------+
||| | | | .var.idx |
||| | | +---------------------+
||| | | | .var.hist_data |
||| | | +---------------------+
||| | | | .var_ref_idx |
||| | | +---------------------+
||| | | .
||| | | .
||| | | .
||| | | .
||| +--------------+ | | .
+-->| field_var | | | .
|| +--------------+ | | .
|| | var | | | .
|| +------------+ | | .
|| | val | | | .
|| +--------------+ | | .
|| | field_var | | | .
|| +--------------+ | | .
|| | var | | | .
|| +------------+ | | .
|| | val | | | .
|| +------------+ | | .
|| . | | .
|| . | | .
|| . | | +-----------------------+ <--- n_vals
|| +--------------+ | | | key = pid |
|| | field_var | | | +-----------------------+
|| +--------------+ | | | .size |
|| | var |--+| +---------------------+
|| +------------+ ||| | .offset |
|| | val |-+|| +---------------------+
|| +------------+ ||| | .fn() |
|| ||| +---------------------+
|| ||| | .flags |
|| ||| +---------------------+
|| ||| | .var.idx |
|| ||| +---------------------+ <--- n_fields
|| |||
|| ||| n_keys = n_fields - n_vals
|| ||| +-----------------------+
|| |+->| var = next_pid |
|| | | +-----------------------+
|| | | | .size |
|| | | +---------------------+
|| | | | .offset |
|| | | +---------------------+
|| | | | .flags & FL_VAR |
|| | | +---------------------+
|| | | | .var.idx |
|| | | +---------------------+
|| | | | .var.hist_data |
|| | | +-----------------------+
|| +-->| val for next_pid |
|| | | +-----------------------+
|| | | | .size |
|| | | +---------------------+
|| | | | .offset |
|| | | +---------------------+
|| | | | .fn() |
|| | | +---------------------+
|| | | | .flags |
|| | | +---------------------+
|| | | | |
|| | | +---------------------+
|| | |
|| | |
|| | | +-----------------------+
+|------------------|-|>| var_ref = $ts0 |
| | | +-----------------------+
| | | | .size |
| | | +---------------------+
| | | | .offset |
| | | +---------------------+
| | | | .fn() |
| | | +---------------------+
| | | | .flags & FL_VAR_REF |
| | | +---------------------+
| | +---| .var_ref_idx |
| | +-----------------------+
| | | var_ref = $next_pid |
| | +-----------------------+
| | | .size |
| | +---------------------+
| | | .offset |
| | +---------------------+
| | | .fn() |
| | +---------------------+
| | | .flags & FL_VAR_REF |
| | +---------------------+
| +-----| .var_ref_idx |
| +-----------------------+
| | var_ref = $wakeup_lat |
| +-----------------------+
| | .size |
| +---------------------+
| | .offset |
| +---------------------+
| | .fn() |
| +---------------------+
| | .flags & FL_VAR_REF |
| +---------------------+
+------------------------| .var_ref_idx |
+---------------------+
如你所见，对于一个字段变量，会创建两个 hist_fields：一个代表变量（在本例中为 next_pid），另一个用于实际从跟踪流中获取字段的值（就像常规值字段所做的那样）。这些与常规变量的创建是分开创建的，并保存在 hist_data->field_vars[] 数组中。有关这些的使用方法，请参见下文。此外，还创建了一个引用的 hist_field，这对于引用 trace() 动作中的字段变量（例如 $next_pid 变量）是必需的。
请注意，$wakeup_lat 也是一个变量引用，引用表达式 common_timestamp-$ts0 的值，因此也需要创建一个代表该引用的直方图字段条目。
当调用 hist_trigger_elt_update() 来获取常规键和值字段时，它还会调用 update_field_vars()。该函数遍历为直方图创建的每个 field_var（可从 hist_data->field_vars 获取），并调用 val->fn() 从当前跟踪记录中获取数据，然后使用变量的 var.idx 在适当的 tracing_map_elt 的变量（位于 elt->vars[var.idx]）中的 var.idx 偏移量处设置变量。
一旦所有变量都已更新，就可以从 event_hist_trigger() 中调用 resolve_var_refs()，不仅可以解析我们的 $ts0 和 $next_pid 引用，还可以解析 $wakeup_lat 引用。此时，trace() 动作可以简单地访问在 var_ref_vals[] 数组中汇集的值并生成跟踪事件。
与 save() 动作关联的字段变量也会发生相同的过程。
图表中使用的缩写
hist_data = struct hist_trigger_data
hist_data.fields = struct hist_field
field_var = struct field_var
fn = hist_field_fn_t
FL_KEY = HIST_FIELD_FL_KEY
FL_VAR = HIST_FIELD_FL_VAR
FL_VAR_REF = HIST_FIELD_FL_VAR_REF
trace() 动作字段变量测试¶
本示例在上一个测试示例的基础上，最终开始使用 wakeup_lat 变量，此外还创建了几个字段变量，然后通过 onmatch() 处理程序将它们全部传递给 wakeup_latency() 跟踪动作。
首先，我们创建 wakeup_latency 合成事件
# echo 'wakeup_latency u64 lat; pid_t pid; char comm[16]' >> synthetic_events
接下来是来自先前示例的 sched_waking 触发器
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
最后，与前一个测试示例一样，我们使用来自 sched_waking 触发器的 $ts0 引用计算并分配唤醒延迟到 wakeup_lat 变量，最后将其与几个 sched_switch 事件字段（next_pid 和 next_comm）一起使用，以生成 wakeup_latency 跟踪事件。为此，next_pid 和 next_comm 事件字段会自动转换为字段变量
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,next_comm)' >> /sys/kernel/tracing/events/sched/sched_switch/trigger
sched_waking hist_debug 输出显示与前一个测试示例相同的数据
# cat events/sched/sched_waking/hist_debug
# event histogram
#
# trigger info: hist:keys=pid:vals=hitcount:ts0=common_timestamp.usecs:sort=hitcount:size=2048:clock=global [active]
#
hist_data: 00000000d60ff61f
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: ts0
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 8
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: pid
type: pid_t
size: 8
is_signed: 1
sched_switch hist_debug 输出显示与前一个测试示例相同的键和值字段 —— 请注意，wakeup_lat 仍然在值字段部分，但新的字段变量不在那里 —— 尽管字段变量是变量，但它们被单独保存在 hist_data 的 field_vars[] 数组中。尽管字段变量和常规变量位于不同的地方，但你可以看到这些变量在 tracing_map_elt.vars[] 中的实际变量位置确实具有如预期般递增的索引：wakeup_lat 占据 var.idx = 0 的插槽，而 next_pid 和 next_comm 的字段变量的值分别为 var.idx = 1 和 var.idx = 2. 另请注意，这些与变量引用字段部分中与这些变量对应的变量引用所显示的值相同。由于有两个触发器，因此有两个 hist_data 地址，在进行匹配时也需要考虑这些地址 —— 你可以看到第一个变量引用了前一个直方图触发器上的 0 号 var.idx（参见与该触发器关联的 hist_data 地址），而第二个变量引用了 sched_switch 直方图触发器上的 0 号 var.idx，其余所有变量引用也是如此。
最后，动作跟踪变量部分仅显示 onmatch() 处理程序的系统和事件名称
# cat events/sched/sched_switch/hist_debug
# event histogram
#
# trigger info: hist:keys=next_pid:vals=hitcount:wakeup_lat=common_timestamp.usecs-$ts0:sort=hitcount:size=2048:clock=global:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,next_comm) [active]
#
hist_data: 0000000008f551b7
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 0
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: next_pid
type: pid_t
size: 8
is_signed: 1
variable reference fields:
hist_data->var_refs[0]:
flags:
HIST_FIELD_FL_VAR_REF
name: ts0
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 00000000d60ff61f
var_ref_idx (into hist_data->var_refs[]): 0
type: u64
size: 8
is_signed: 0
hist_data->var_refs[1]:
flags:
HIST_FIELD_FL_VAR_REF
name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 0000000008f551b7
var_ref_idx (into hist_data->var_refs[]): 1
type: u64
size: 0
is_signed: 0
hist_data->var_refs[2]:
flags:
HIST_FIELD_FL_VAR_REF
name: next_pid
var.idx (into tracing_map_elt.vars[]): 1
var.hist_data: 0000000008f551b7
var_ref_idx (into hist_data->var_refs[]): 2
type: pid_t
size: 4
is_signed: 0
hist_data->var_refs[3]:
flags:
HIST_FIELD_FL_VAR_REF
name: next_comm
var.idx (into tracing_map_elt.vars[]): 2
var.hist_data: 0000000008f551b7
var_ref_idx (into hist_data->var_refs[]): 3
type: char[16]
size: 256
is_signed: 0
field variables:
hist_data->field_vars[0]:
field_vars[0].var:
flags:
HIST_FIELD_FL_VAR
var.name: next_pid
var.idx (into tracing_map_elt.vars[]): 1
field_vars[0].val:
ftrace_event_field name: next_pid
type: pid_t
size: 4
is_signed: 1
hist_data->field_vars[1]:
field_vars[1].var:
flags:
HIST_FIELD_FL_VAR
var.name: next_comm
var.idx (into tracing_map_elt.vars[]): 2
field_vars[1].val:
ftrace_event_field name: next_comm
type: char[16]
size: 256
is_signed: 0
action tracking variables (for onmax()/onchange()/onmatch()):
hist_data->actions[0].match_data.event_system: sched
hist_data->actions[0].match_data.event: sched_waking
可以使用以下命令清理环境以为下一次测试做准备
# echo '!hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,next_comm)' >> /sys/kernel/tracing/events/sched/sched_switch/trigger
# echo '!hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
# echo '!wakeup_latency u64 lat; pid_t pid; char comm[16]' >> synthetic_events
action_data 和 trace() 动作¶
如上所述，当 trace() 动作生成合成事件时，合成事件的所有参数要么已经是变量，要么被转换为变量（通过字段变量），最后所有这些变量值都通过对它们的引用收集到一个 var_ref_vals[] 数组中。
然而，var_ref_vals[] 数组中的值不一定遵循与合成事件参数相同的顺序。为了解决这个问题，struct action_data 包含另一个数组 var_ref_idx[]，它将跟踪动作参数映射到 var_ref_vals[] 值。下图说明了针对 wakeup_latency() 合成事件的这种情况
+------------------+ wakeup_latency()
| action_data | event params var_ref_vals[]
+------------------+ +-----------------+ +-----------------+
| .var_ref_idx[] |--->| $wakeup_lat idx |---+ | |
+----------------+ +-----------------+ | +-----------------+
| .synth_event | | $next_pid idx |---|-+ | $wakeup_lat val |
+----------------+ +-----------------+ | | +-----------------+
. | +->| $next_pid val |
. | +-----------------+
. | .
+-----------------+ | .
| | | .
+-----------------+ | +-----------------+
+--->| $wakeup_lat val |
+-----------------+
基本上，这在合成事件探针函数 trace_event_raw_event_synth() 中的最终使用方式如下
for each field i in .synth_event
val_idx = .var_ref_idx[i]
val = var_ref_vals[val_idx]
action_data 和 onXXX() 处理程序¶
除 onmatch() 之外的直方图触发器 onXXX() 动作（例如 onmax() 和 onchange()）也会使用并在内部创建隐藏变量。此信息包含在 action_data.track_data 结构体中，并且在 hist_debug 输出中也是可见的，正如在下面的示例中所描述的那样。
通常，onmax() 或 onchange() 处理程序与 save() 和 snapshot() 动作结合使用。例如
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \
onmax($wakeup_lat).save(next_comm,prev_pid,prev_prio,prev_comm)' >>
/sys/kernel/tracing/events/sched/sched_switch/trigger
或者
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \
onmax($wakeup_lat).snapshot()' >>
/sys/kernel/tracing/events/sched/sched_switch/trigger
save() 动作字段变量测试¶
对于本示例，不生成合成事件，而是每当 onmax() 处理程序检测到达到新的最大延迟时，使用 save() 动作来保存字段值。与前一个示例一样，正在保存的值也是字段值，但在本例中，它们保存在名为 save_vars[] 的单独 hist_data 数组中。
与先前的测试示例一样，我们设置 sched_waking 触发器
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
然而，在本例中，我们设置 sched_switch 触发器以便在达到新的最大延迟时保存一些 sched_switch 字段值。对于 onmax() 处理程序和 save() 动作，都将创建变量，我们可以使用 hist_debug 文件来检查它们
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmax($wakeup_lat).save(next_comm,prev_pid,prev_prio,prev_comm)' >> events/sched/sched_switch/trigger
sched_waking hist_debug 输出显示与先前测试示例相同的数据
# cat events/sched/sched_waking/hist_debug
#
# trigger info: hist:keys=pid:vals=hitcount:ts0=common_timestamp.usecs:sort=hitcount:size=2048:clock=global [active]
#
hist_data: 00000000e6290f48
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: ts0
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 8
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: pid
type: pid_t
size: 8
is_signed: 1
sched_switch 触发器的输出显示与以前相同的值和键值，但也显示了几个新部分。
首先，动作跟踪变量部分现在显示 actions[].track_data 信息，描述用于跟踪（在本例中为运行最大值）的特殊跟踪变量和引用。actions[].track_data.var_ref 成员包含对正在跟踪的变量的引用，在本例中为 $wakeup_lat 变量。为了执行 onmax() 处理程序函数，还需要一个变量，通过在达到新最大值时进行更新来跟踪当前最大值。在这种情况下，我们可以看到已创建一个名为 ‘ __max’ 的自动生成变量，并且它在 actions[].track_data.track_var 变量中可见。
最后，在新的‘保存动作变量’部分中，我们可以看到传递给 save() 函数的 4 个参数已导致创建 4 个字段变量，以便在达到最大值时保存命名字段的值。这些变量保存在 hist_data 之外的单独 save_vars[] 数组中，因此显示在单独的部分中
# cat events/sched/sched_switch/hist_debug
# event histogram
#
# trigger info: hist:keys=next_pid:vals=hitcount:wakeup_lat=common_timestamp.usecs-$ts0:sort=hitcount:size=2048:clock=global:onmax($wakeup_lat).save(next_comm,prev_pid,prev_prio,prev_comm) [active]
#
hist_data: 0000000057bcd28d
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 0
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: next_pid
type: pid_t
size: 8
is_signed: 1
variable reference fields:
hist_data->var_refs[0]:
flags:
HIST_FIELD_FL_VAR_REF
name: ts0
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 00000000e6290f48
var_ref_idx (into hist_data->var_refs[]): 0
type: u64
size: 8
is_signed: 0
hist_data->var_refs[1]:
flags:
HIST_FIELD_FL_VAR_REF
name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 0000000057bcd28d
var_ref_idx (into hist_data->var_refs[]): 1
type: u64
size: 0
is_signed: 0
action tracking variables (for onmax()/onchange()/onmatch()):
hist_data->actions[0].track_data.var_ref:
flags:
HIST_FIELD_FL_VAR_REF
name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 0000000057bcd28d
var_ref_idx (into hist_data->var_refs[]): 1
type: u64
size: 0
is_signed: 0
hist_data->actions[0].track_data.track_var:
flags:
HIST_FIELD_FL_VAR
var.name: __max
var.idx (into tracing_map_elt.vars[]): 1
type: u64
size: 8
is_signed: 0
save action variables (save() params):
hist_data->save_vars[0]:
save_vars[0].var:
flags:
HIST_FIELD_FL_VAR
var.name: next_comm
var.idx (into tracing_map_elt.vars[]): 2
save_vars[0].val:
ftrace_event_field name: next_comm
type: char[16]
size: 256
is_signed: 0
hist_data->save_vars[1]:
save_vars[1].var:
flags:
HIST_FIELD_FL_VAR
var.name: prev_pid
var.idx (into tracing_map_elt.vars[]): 3
save_vars[1].val:
ftrace_event_field name: prev_pid
type: pid_t
size: 4
is_signed: 1
hist_data->save_vars[2]:
save_vars[2].var:
flags:
HIST_FIELD_FL_VAR
var.name: prev_prio
var.idx (into tracing_map_elt.vars[]): 4
save_vars[2].val:
ftrace_event_field name: prev_prio
type: int
size: 4
is_signed: 1
hist_data->save_vars[3]:
save_vars[3].var:
flags:
HIST_FIELD_FL_VAR
var.name: prev_comm
var.idx (into tracing_map_elt.vars[]): 5
save_vars[3].val:
ftrace_event_field name: prev_comm
type: char[16]
size: 256
is_signed: 0
可以使用以下命令清理环境以为下一次测试做准备
# echo '!hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmax($wakeup_lat).save(next_comm,prev_pid,prev_prio,prev_comm)' >> events/sched/sched_switch/trigger
# echo '!hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
几个特殊情况¶
虽然上面的内容涵盖了直方图内部原理的基础知识，但还有几个特殊情况应该讨论，因为它们往往会造成更多混淆。这些情况是其他直方图上的字段变量以及别名，这两者都在下面通过使用 hist_debug 文件的示例测试进行了描述。
其他直方图上的字段变量测试¶
本示例与先前的示例类似，但在本例中，sched_switch 触发器引用了另一个事件（即 sched_waking 事件）上的直方图触发器字段。为了实现这一点，为另一个事件创建了一个字段变量，但由于不能使用现有的直方图（因为现有的直方图是不可变的），因此会创建一个带有匹配变量的新直方图并使用它，我们将在下面显示的 hist_debug 输出中看到这一点。
首先，我们创建 wakeup_latency synthetic 事件。注意添加了 prio 字段
# echo 'wakeup_latency u64 lat; pid_t pid; int prio' >> synthetic_events
与先前的测试示例一样，我们设置 sched_waking 触发器
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
在这里，我们在 sched_switch 上设置了一个直方图触发器，使用命名 sched_waking 事件的 onmatch 处理程序发送 wakeup_latency 事件。请注意，传递给 wakeup_latency() 的第三个参数是 prio，这是一个需要为其创建字段变量的字段名。然而，sched_switch 事件上没有任何 prio 字段，因此似乎无法为其创建字段变量。匹配的 sched_waking 事件确实有一个 prio 字段，因此应该可以将其用于此目的。但主要问题在于，目前无法在现有直方图上定义新变量，因此无法将新的 prio 字段变量添加到现有的 sched_waking 直方图中。不过，可以为同一事件创建一个额外的新的‘匹配’ sched_waking 直方图（这意味着它使用相同的键和过滤器），并在该直方图上定义新的 prio 字段变量。
以下是 sched_switch 触发器
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,prio)' >> events/sched/sched_switch/trigger
这里是 sched_waking 直方图触发器的 hist_debug 信息输出。请注意，输出中显示了两个直方图：第一个是我们在前几个示例中看到的常规 sched_waking 直方图，第二个是我们为提供 prio 字段变量而创建的特殊直方图。
查看下面第二个直方图，我们看到一个名为 synthetic_prio 的变量。这是为该 sched_waking 直方图上的 prio 字段创建的字段变量
# cat events/sched/sched_waking/hist_debug
# event histogram
#
# trigger info: hist:keys=pid:vals=hitcount:ts0=common_timestamp.usecs:sort=hitcount:size=2048:clock=global [active]
#
hist_data: 00000000349570e4
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: ts0
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 8
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: pid
type: pid_t
size: 8
is_signed: 1
# event histogram
#
# trigger info: hist:keys=pid:vals=hitcount:synthetic_prio=prio:sort=hitcount:size=2048 [active]
#
hist_data: 000000006920cf38
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
ftrace_event_field name: prio
var.name: synthetic_prio
var.idx (into tracing_map_elt.vars[]): 0
type: int
size: 4
is_signed: 1
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: pid
type: pid_t
size: 8
is_signed: 1
查看下面的 sched_switch 直方图，我们可以看到对 sched_waking 上的 synthetic_prio 变量的引用，查看关联的 hist_data 地址，我们发现它确实与新直方图关联。另请注意，其他引用是对常规变量 wakeup_lat 以及常规字段变量 next_pid 的引用，其详细信息在字段变量部分中
# cat events/sched/sched_switch/hist_debug
# event histogram
#
# trigger info: hist:keys=next_pid:vals=hitcount:wakeup_lat=common_timestamp.usecs-$ts0:sort=hitcount:size=2048:clock=global:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,prio) [active]
#
hist_data: 00000000a73b67df
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 0
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: next_pid
type: pid_t
size: 8
is_signed: 1
variable reference fields:
hist_data->var_refs[0]:
flags:
HIST_FIELD_FL_VAR_REF
name: ts0
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 00000000349570e4
var_ref_idx (into hist_data->var_refs[]): 0
type: u64
size: 8
is_signed: 0
hist_data->var_refs[1]:
flags:
HIST_FIELD_FL_VAR_REF
name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 00000000a73b67df
var_ref_idx (into hist_data->var_refs[]): 1
type: u64
size: 0
is_signed: 0
hist_data->var_refs[2]:
flags:
HIST_FIELD_FL_VAR_REF
name: next_pid
var.idx (into tracing_map_elt.vars[]): 1
var.hist_data: 00000000a73b67df
var_ref_idx (into hist_data->var_refs[]): 2
type: pid_t
size: 4
is_signed: 0
hist_data->var_refs[3]:
flags:
HIST_FIELD_FL_VAR_REF
name: synthetic_prio
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 000000006920cf38
var_ref_idx (into hist_data->var_refs[]): 3
type: int
size: 4
is_signed: 1
field variables:
hist_data->field_vars[0]:
field_vars[0].var:
flags:
HIST_FIELD_FL_VAR
var.name: next_pid
var.idx (into tracing_map_elt.vars[]): 1
field_vars[0].val:
ftrace_event_field name: next_pid
type: pid_t
size: 4
is_signed: 1
action tracking variables (for onmax()/onchange()/onmatch()):
hist_data->actions[0].match_data.event_system: sched
hist_data->actions[0].match_data.event: sched_waking
可以使用以下命令清理环境以为下一次测试做准备
# echo '!hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,prio)' >> events/sched/sched_switch/trigger
# echo '!hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
# echo '!wakeup_latency u64 lat; pid_t pid; int prio' >> synthetic_events
别名测试¶
本示例与先前的示例非常相似，但演示了别名标志。
首先，我们创建 wakeup_latency 合成事件
# echo 'wakeup_latency u64 lat; pid_t pid; char comm[16]' >> synthetic_events
接下来，我们创建一个类似于先前示例的 sched_waking 触发器，但在本例中，我们将 pid 保存在 waking_pid 变量中
# echo 'hist:keys=pid:waking_pid=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
对于 sched_switch 触发器，我们不在 wakeup_latency 合成事件调用中直接使用 $waking_pid，而是创建一个名为 $woken_pid 的 $waking_pid 别名，并在合成事件调用中使用该别名
# echo 'hist:keys=next_pid:woken_pid=$waking_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,$woken_pid,next_comm)' >> events/sched/sched_switch/trigger
查看 sched_waking hist_debug 输出，除了常规字段外，我们可以看到 waking_pid 变量
# cat events/sched/sched_waking/hist_debug
# event histogram
#
# trigger info: hist:keys=pid:vals=hitcount:waking_pid=pid,ts0=common_timestamp.usecs:sort=hitcount:size=2048:clock=global [active]
#
hist_data: 00000000a250528c
n_vals: 3
n_keys: 1
n_fields: 4
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
ftrace_event_field name: pid
var.name: waking_pid
var.idx (into tracing_map_elt.vars[]): 0
type: pid_t
size: 4
is_signed: 1
hist_data->fields[2]:
flags:
HIST_FIELD_FL_VAR
var.name: ts0
var.idx (into tracing_map_elt.vars[]): 1
type: u64
size: 8
is_signed: 0
key fields:
hist_data->fields[3]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: pid
type: pid_t
size: 8
is_signed: 1
sched_switch hist_debug 输出显示已创建一个名为 woken_pid 的变量，但它也设置了 HIST_FIELD_FL_ALIAS 标志。它还设置了 HIST_FIELD_FL_VAR 标志，这就是它出现在值字段部分的原因。
尽管有这个实现细节，但别名变量实际上更像是一个变量引用；事实上，它可以被认为是对引用的引用。该实现从被引用的变量引用中复制 var_ref->fn()（在本例中为 waking_pid fn()，即 hist_field_var_ref()），并将其作为别名的 fn()。由于 hist_field_var_ref() fn() 需要它正在使用的变量引用的 var_ref_idx，因此 waking_pid 的 var_ref_idx 也被复制到别名中。最终的结果是，当检索别名的值时，它最终做的事情与原始引用会做的事情完全相同，并从 var_ref_vals[] 数组中检索相同的值。你可以在输出中注意到别名（在本例中为 woken_pid）的 var_ref_idx 与变量引用字段部分中引用（waking_pid）的 var_ref_idx 相同，从而在输出中验证这一点。
此外，一旦它获得了该值，由于它也是一个变量，它随后将该值保存到其 var.idx 中。因此，woken_pid 别名的 var.idx 为 0，当调用其 fn() 来更新自身时，它会用来自 var_ref_idx 0 的值填充它。你还会注意到，在变量引用部分有一个 woken_pid var_ref。那是对 woken_pid 别名变量的引用，你可以看到它从与 woken_pid 别名相同的 var.idx（即 0）中检索值，然后反过来将该值保存到它自己的 var_ref_idx 插槽（即 3）中，而该位置的值最终就是分配给跟踪事件调用中的 $woken_pid 插槽的值
# cat events/sched/sched_switch/hist_debug
# event histogram
#
# trigger info: hist:keys=next_pid:vals=hitcount:woken_pid=$waking_pid,wakeup_lat=common_timestamp.usecs-$ts0:sort=hitcount:size=2048:clock=global:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,$woken_pid,next_comm) [active]
#
hist_data: 0000000055d65ed0
n_vals: 3
n_keys: 1
n_fields: 4
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
HIST_FIELD_FL_ALIAS
var.name: woken_pid
var.idx (into tracing_map_elt.vars[]): 0
var_ref_idx (into hist_data->var_refs[]): 0
type: pid_t
size: 4
is_signed: 1
hist_data->fields[2]:
flags:
HIST_FIELD_FL_VAR
var.name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 1
type: u64
size: 0
is_signed: 0
key fields:
hist_data->fields[3]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: next_pid
type: pid_t
size: 8
is_signed: 1
variable reference fields:
hist_data->var_refs[0]:
flags:
HIST_FIELD_FL_VAR_REF
name: waking_pid
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 00000000a250528c
var_ref_idx (into hist_data->var_refs[]): 0
type: pid_t
size: 4
is_signed: 1
hist_data->var_refs[1]:
flags:
HIST_FIELD_FL_VAR_REF
name: ts0
var.idx (into tracing_map_elt.vars[]): 1
var.hist_data: 00000000a250528c
var_ref_idx (into hist_data->var_refs[]): 1
type: u64
size: 8
is_signed: 0
hist_data->var_refs[2]:
flags:
HIST_FIELD_FL_VAR_REF
name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 1
var.hist_data: 0000000055d65ed0
var_ref_idx (into hist_data->var_refs[]): 2
type: u64
size: 0
is_signed: 0
hist_data->var_refs[3]:
flags:
HIST_FIELD_FL_VAR_REF
name: woken_pid
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 0000000055d65ed0
var_ref_idx (into hist_data->var_refs[]): 3
type: pid_t
size: 4
is_signed: 1
hist_data->var_refs[4]:
flags:
HIST_FIELD_FL_VAR_REF
name: next_comm
var.idx (into tracing_map_elt.vars[]): 2
var.hist_data: 0000000055d65ed0
var_ref_idx (into hist_data->var_refs[]): 4
type: char[16]
size: 256
is_signed: 0
field variables:
hist_data->field_vars[0]:
field_vars[0].var:
flags:
HIST_FIELD_FL_VAR
var.name: next_comm
var.idx (into tracing_map_elt.vars[]): 2
field_vars[0].val:
ftrace_event_field name: next_comm
type: char[16]
size: 256
is_signed: 0
action tracking variables (for onmax()/onchange()/onmatch()):
hist_data->actions[0].match_data.event_system: sched
hist_data->actions[0].match_data.event: sched_waking
可以使用以下命令清理环境以为下一次测试做准备
# echo '!hist:keys=next_pid:woken_pid=$waking_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,$woken_pid,next_comm)' >> events/sched/sched_switch/trigger
# echo '!hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
# echo '!wakeup_latency u64 lat; pid_t pid; char comm[16]' >> synthetic_events