直方图设计说明¶
- 作者:
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 表示的数组(变量也包含在此处,但稍后讨论)。因此,对于上面的直方图,我们有一个键和一个值;在本例中,一个值是 hitcount 值,所有直方图都有该值,无论是否定义该值,上面的直方图都没有定义该值。
每个 struct hist_field 都包含一个指向事件的 trace_event_file 中的 ftrace_event_field 的指针,以及与该指针相关的各种位,例如大小、偏移量、类型和一个 hist_field_fn_t 函数,该函数用于从 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 的 val 字段和一个用于 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_entrys 数组和一组 | | 预分配的 tracing_map_elts 组成(下面缩写为 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。
一旦 tracing_map_elt 可用,就会调用 hist_trigger_elt_update()。顾名思义,这将更新元素,这基本上意味着更新元素的字段。tracing_map_field 与直方图中的每个键和值相关联,并且这些字段中的每一个都对应于创建直方图时创建的键和值 hist_fields。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_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
变量¶
变量允许一个 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_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 | | |
| | |
这与基本情况非常相似。在上图中,我们可以看到一个新的 `.flags` 成员已添加到 `struct hist_field` 结构中,并且一个新的条目已添加到 `hist_data.fields` 中,表示 `ts0` 变量。对于一个普通的 `val hist_field`,`.flags` 只是 0(取模修饰符标志),但如果该值被定义为变量,则 `.flags` 包含设置的 `FL_VAR` 位。
正如你所见,`ts0` 条目的 `.var.idx` 成员包含到 `tracing_map_elts` 的 `.vars[]` 数组中的索引,该数组包含变量值。每当设置或读取变量的值时,都会使用此索引。分配给给定变量的 `map_elt.vars` 索引在调用 `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 | | |
| | | |
+---------------+ | |
对于每个使用的映射条目,都有一个指向 `.vars` 数组的 `map_elt`,该数组包含与该直方图条目关联的变量的当前值。因此,在上面,与 pid 999 关联的时间戳是 113345679876,并且在相同的 `.var.idx` 中,pid 4444 的时间戳变量是 213499240729。
sched_switch 直方图 | | ---------------------- | |
下面显示了与上述 `sched_waking` 直方图配对的 `sched_switch` 直方图。 `sched_switch` 直方图最重要的方面是它引用了上面 `sched_waking` 直方图上的一个变量。
直方图图与到目前为止显示的其他图非常相似,但它添加了变量引用。你可以看到正常的命中计数和键字段,以及以与 `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`,其标志为 `HIST_FIELD_FL_VAR_REF`。对于 `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` 直方图中有一个与此 `sched_switch` 事件上的 `next_pid` 字段匹配的 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` 直方图触发器。
# 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`,另一个实际上是从跟踪流中获取字段的值,就像普通的 `val` 字段一样。这些字段与正常的变量创建分开创建,并保存在 `hist_data->field_vars[]` 数组中。请参阅下面有关如何使用它们的说明。此外,还会创建一个引用 `hist_field`,这是引用跟踪操作中的字段变量(如 `$next_pid` 变量)所必需的。
请注意,`$wakeup_lat` 也是一个变量引用,引用表达式 `common_timestamp-$ts0` 的值,因此也需要创建一个表示该引用的 `hist field` 条目。
当调用 `hist_trigger_elt_update()` 来获取正常的键和值字段时,它还会调用 `update_field_vars()`,它会遍历为直方图创建的每个 `field_var`,并从 `hist_data->field_vars` 中获得这些变量,并调用 `val->fn()` 以从当前跟踪记录中获取数据,然后使用变量的 `var.idx` 在 `elt->vars[var.idx]` 中适当的 `tracing_map_elt` 的变量处设置该变量。
更新所有变量后,可以从 `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()` trace 操作。
首先,我们创建 `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` trace 事件。为此,`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` 地址,在进行匹配时还需要考虑这些地址 - 您可以看到第一个变量引用前一个历史触发器上的 `var.idx = 0`(请参阅与该触发器关联的 `hist_data` 地址),而第二个变量引用 `sched_switch` 历史触发器上的 `var.idx = 0`,其余的变量引用也是如此。
最后,操作跟踪变量部分仅显示 `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[]` 数组中的值不一定遵循与合成事件参数相同的顺序。为了解决这个问题,结构体 `action_data` 包含另一个数组 `var_ref_idx[]`,该数组将 trace 操作参数映射到 `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() 操作字段变量测试¶
对于此示例,不生成合成事件,而是使用 `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()` 函数的 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` 合成事件。注意 `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` 上的历史触发器,以使用 `onmatch` 处理程序发送一个名为 `sched_waking` 事件的 `wakeup_latency` 事件。请注意,传递给 `wakeup_latency()` 的第三个参数是 `prio`,它是一个字段名称,需要为其创建字段变量。但是,`sched_switch` 事件上没有任何 `prio` 字段,因此似乎不可能为其创建字段变量。匹配的 `sched_waking` 事件确实有一个 `prio` 字段,因此应该可以将其用于此目的。问题在于,目前无法在现有直方图上定义新变量,因此无法向现有 `sched_waking` 直方图添加新的 `prio` 字段变量。但是,可以为同一事件创建额外的新的“匹配” `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` 标志,这就是它出现在 `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`)与变量引用字段部分中引用 `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),并且最终这个位置的值会被分配给 trace 事件调用中的 `$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