直方图设计说明¶
- 作者:
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’ 的事件文件。可以随时读取此文件，并将显示本文档中描述的一些 hist 触发器内部结构。具体示例和输出将在下面的测试用例中描述。
基本直方图¶
首先，是基本直方图。下面几乎是你可以用直方图做的最简单的事情 - 在单个事件上创建一个具有单个键的直方图，并 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 值是一个每个桶的值，对于给定键的每次命中都会自动递增，在这种情况下，键是 pid。
因此，在此直方图中，每个 pid 都有一个单独的桶，每个桶包含一个值，用于计算该 pid 调用 sched_waking 的次数。
每个直方图都由一个 hist_data 结构表示。
为了跟踪直方图中的每个键和值字段，hist_data 会保存一个名为 fields[] 的字段数组。 fields[] 数组是一个包含 struct hist_field 的数组，它表示直方图中的每个 val 和 key（变量也包含在此处，但稍后会讨论）。因此，对于上面的直方图，我们有一个键和一个值；在这种情况下，一个值是 hitcount 值，所有直方图都有该值，无论它们是否定义该值，而上面的直方图没有。
每个 struct hist_field 包含一个指向事件的 trace_event_file 中的 ftrace_event_field 的指针，以及与此相关的各种位，例如大小、偏移量、类型和一个 hist_field_fn_t 函数，该函数用于从 ftrace 事件缓冲区中获取字段的数据（在大多数情况下 - 某些 hist_field（例如 hitcount）不直接映射到跟踪缓冲区中的事件字段 - 在这些情况下，函数实现从其他地方获取其值）。 flags 字段指示它是什么类型的字段 - 键、值、变量、变量引用等，默认值为 value。
除了 fields[] 数组之外，另一个重要的 hist_data 数据结构是为直方图创建的 tracing_map 实例，该实例保存在 .map 成员中。 tracing_map 实现了用于实现直方图的无锁哈希表（有关实现 tracing_map 的底层数据结构的更多讨论，请参见 kernel/trace/tracing_map.h）。对于本文档，tracing_map 包含多个桶，每个桶对应于由给定直方图键哈希的特定 tracing_map_elt 对象。
下面是一个图表，第一部分描述了上面描述的直方图的 hist_data 和关联的键和值字段。如你所见，fields 数组中有两个字段，一个用于 hitcount 的 val 字段和一个用于 pid 键的 key 字段。
下面是一个运行时快照的图表，显示了给定运行的 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.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
每当发生新事件且该事件具有与之关联的 hist 触发器时，都会调用 event_hist_trigger()。 event_hist_trigger() 首先处理键：对于键中的每个子键（在上面的示例中，只有一个子键对应于 pid），从 hist_data.fields[] 中检索表示该子键的 hist_field，并且与该字段关联的 hist_field_fn_t fn() 以及该字段的大小和偏移量用于从当前跟踪记录中获取该子键的数据。
一旦检索到完整的键，它将用于在 tracing_map 中查找该键。如果不存在与该键关联的 tracing_map_elt，则会声明一个空的键并将其插入到映射中以用于新键。在任何一种情况下，都会返回与该键关联的 tracing_map_elt。
一旦 tracing_map_elt 可用，就会调用 hist_trigger_elt_update()。顾名思义，这会更新元素，这基本上意味着更新元素的字段。直方图中的每个键和值都关联一个 tracing_map_field，并且每个 tracing_map_field 都对应于创建直方图时创建的键和值 hist_field。 hist_trigger_elt_update() 遍历每个值 hist_field，并且与键一样，使用 hist_field 的 fn() 以及大小和偏移量从当前跟踪记录中获取字段的值。一旦它获得了该值，它只需将该值添加到该字段不断更新的 tracing_map_field.sum 成员中。一些 hist_field fn()（例如 hitcount）实际上没有从跟踪记录中获取任何内容（hitcount fn() 只是将计数器总和增加 1），但思路是相同的。
更新所有值后，hist_trigger_elt_update() 完成并返回。请注意，键中的每个子键也有 tracing_map_field，但 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_field 的数量，以及其中有多少对应于键，有多少对应于值。
然后，它会继续显示每个字段的详细信息，包括字段的标志和每个字段在 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
变量¶
变量允许一个 hist 触发器保存的数据被另一个 hist 触发器检索。例如，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 触发器，它们会在所有 val 字段之后被添加到 hist_data.fields[] 数组中。为了将它们与现有的键和 val 字段区分开来，它们被赋予了一个新的标志类型 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 | | |
| | |
这与基本情况非常相似。在上图中，我们可以 | | | 看到一个新的 .flags 成员已添加到 struct hist_field | | | 结构中，并且已将新条目添加到 hist_data.fields 中，表示 ts0 | | | 变量。对于普通的 val 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[] 成员指向键或 | | | val 的 .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 条目，都有一个指向 | | .vars 数组的 map_elt，该数组包含与 | | 该直方图条目关联的变量的当前值。因此，在上面的图中，与 | | pid 999 关联的时间戳为 113345679876，并且同一 | | .var.idx 中 pid 4444 的时间戳变量为 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 的简称）标志的条目。 | |
与新的 var ref 字段关联的是几个新的 hist_field | | 成员，var.hist_data 和 var_ref_idx。对于变量引用， | | var.hist_data 与 var.idx 一起，唯一地标识了 | | 特定直方图上的特定变量。 var_ref_idx | | 只是 var_ref_vals[] 数组中的索引，该数组在每次更新 hist 触发器时 | | 缓存每个变量的值。然后，其他代码（例如使用 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 触发器使用变量时，会创建一个新的 hist_field，其标志为 HIST_FIELD_FL_VAR_REF。对于 VAR_REF 字段，var.idx 和 var.hist_data 采用与引用的变量相同的值，以及引用的变量的大小、类型和 is_signed 值。 VAR_REF 字段的 .name 设置为它引用的变量的名称。如果使用显式的 system.event.$var_ref 表示法创建了变量引用，则 hist_field 的系统和 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_field 具有相同的 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_field 之外，在 val 字段部分，我们看到一个带有 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_switch 事件上的 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 与合成事件无关），并将该特殊直方图字段用作变量。
下图说明了上面在 sched_switch 直方图中使用 onmatch() 处理程序和 trace() 操作描述的新元素。
首先，我们定义 wakeup_latency 合成事件
# echo 'wakeup_latency u64 lat; pid_t pid' >> synthetic_events
接下来，像以前一样设置 sched_waking hist 触发器
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >>
events/sched/sched_waking/trigger
最后，我们在 sched_switch 事件上创建一个 hist 触发器，该触发器生成 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_field：一个表示变量（在本例中为 next_pid），另一个实际上是从跟踪流中获取字段的值，就像普通的 val 字段一样。这些字段与普通变量创建分开创建，并保存在 hist_data->field_vars[] 数组中。有关如何使用这些字段，请参见下文。此外，还创建了一个引用 hist_field，这对于引用字段变量（例如 trace() 操作中的 $next_pid 变量）是必需的。
请注意，$wakeup_lat 也是一个变量引用，引用表达式 common_timestamp-$ts0 的值，因此也需要创建一个 hist 字段条目来表示该引用。
当调用 hist_trigger_elt_update() 来获取正常的键和值字段时，它还会调用 update_field_vars()，该函数会遍历为直方图创建的每个 field_var（从 hist_data->field_vars 中获取），并调用 val->fn() 从当前跟踪记录中获取数据，然后使用 var 的 var.idx 在 elt->vars[var.idx] 中相应 tracing_map_elt 的变量中设置 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 仍然位于 val 字段部分，但新的字段变量不在那里 - 尽管字段变量是变量，但它们单独保存在 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 地址，因此在进行匹配时也需要考虑这些地址 - 你可以看到第一个变量引用了上一个 hist 触发器上的 0 var.idx（请参阅与该触发器关联的 hist_data 地址），而第二个变量引用了 sched_switch hist 触发器上的 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() 之外，hist 触发器 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() 操作字段变量测试¶
对于此示例，未使用生成合成事件，而是使用 save() 操作在 onmax() 处理程序检测到已达到新的最大延迟时保存字段值。与上一个示例一样，保存的值也是字段值，但在这种情况下，它们保存在名为 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 触发器的输出显示与之前相同的 val 和 key 值，但也显示了几个新部分。
首先，操作跟踪变量部分现在显示 actions[].track_data 信息，描述用于跟踪（在本例中为运行最大值）的特殊跟踪变量和引用。 actions[].track_data.var_ref 成员包含对正在跟踪的变量的引用，在本例中为 $wakeup_lat 变量。为了执行 onmax() 处理程序函数，还需要一个变量来跟踪当前最大值，该变量会在每次达到新的最大值时更新。在这种情况下，我们可以看到已创建一个自动生成的变量，名为 ‘ __max’，并且在 actions[].track_data.track_var 变量中可见。
最后，在新的 ‘save 操作变量’ 部分中，我们可以看到 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 触发器字段。为了完成此操作，会为另一个事件创建一个字段变量，但由于无法使用现有直方图（因为现有直方图是不可变的），因此会创建一个带有匹配变量的新直方图并使用它，我们将在下面显示的 hist_debug 输出中看到这一点。
首先，我们创建 wakeup_latency 合成事件。请注意添加了 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 上的 hist 触发器以使用命名 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 触发器的 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，而是创建 $waking_pid 的别名，名为 $woken_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 标志，这就是它出现在 val 字段部分的原因。
尽管有这个实现细节，别名变量实际上更像一个变量引用； 实际上，可以将其视为对引用的引用。 该实现从被引用的变量引用中复制 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[] 数组中检索相同的值。 您可以在输出中验证这一点，注意别名的 var_ref_idx（在本例中为 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