Histogram 설계 노트

Histogram 설계 노트 소개

이 문서는 GPL-2.0으로 배포되는 `Histogram Design Notes`이며 저자는 Tom Zanussi `<[email protected]>`다.

ftrace histogram의 동작 방식과 각 구성 요소가 `trace_events_hist.c` 및 `tracing_map.c`의 구현 자료 구조에 어떻게 대응하는지를 설명한다.

모든 ftrace histogram 명령 예시는 현재 작업 directory가 ftrace의 `/tracing` directory라고 가정한다.

	# cd /sys/kernel/tracing

명령에 대해 표시하는 histogram 출력은 대체로 생략되어 있으며, 설명에 필요한 부분만 제시한다.

.. SPDX-License-Identifier: GPL-2.0

======================
Histogram Design Notes
======================

:Author: Tom Zanussi <[email protected]>

This document attempts to provide a description of how the ftrace
histograms work and how the individual pieces map to the data
structures used to implement them in trace_events_hist.c and
tracing_map.c.

.. note::
   All the ftrace histogram command examples assume the working
   directory is the ftrace /tracing directory. For example::

	# cd /sys/kernel/tracing

   Also, the histogram output displayed for those commands will be
   generally be truncated - only enough to make the point is displayed.

`hist_debug` trace event 파일

커널을 `CONFIG_HIST_TRIGGERS_DEBUG`와 함께 빌드하면 각 event 하위 directory에 `hist_debug`라는 event 파일이 나타난다. 언제든 이 파일을 읽어 이 문서에서 설명하는 hist trigger 내부 상태 일부를 확인할 수 있다. 구체적인 예와 출력은 뒤의 test case에서 설명한다.

'hist_debug' trace event files
==============================

If the kernel is compiled with CONFIG_HIST_TRIGGERS_DEBUG set, an
event file named 'hist_debug' will appear in each event's
subdirectory.  This file can be read at any time and will display some
of the hist trigger internals described in this document. Specific
examples and output will be described in test cases below.

기본 histogram과 hitcount

가장 단순한 histogram은 event 하나에 key 하나를 지정해 만들고 그 출력을 읽는 형태다. 다음 예시는 `sched_waking` event에서 `pid`를 key로 사용한다.

  # 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

이 명령은 `pid`를 key로 하는 `sched_waking` histogram을 만들며 값은 `hitcount` 하나다. `hitcount`를 명시하지 않아도 모든 histogram에는 이 값이 항상 존재한다.

`hitcount`는 key가 적중할 때마다 자동으로 증가하는 bucket별 값이다. 따라서 이 histogram은 pid마다 별도의 bucket을 만들고, 각 bucket에는 해당 pid에 대해 `sched_waking`이 호출된 횟수가 저장된다.

Basic histograms
================

First, basic histograms.  Below is pretty much the simplest thing you
can do with histograms - create one with a single key on a single
event and cat the output::

  # 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

What this does is create a histogram on the sched_waking event using
pid as a key and with a single value, hitcount, which even if not
explicitly specified, exists for every histogram regardless.

The hitcount value is a per-bucket value that's automatically
incremented on every hit for the given key, which in this case is the
pid.

So in this histogram, there's a separate bucket for each pid, and each
bucket contains a value for that bucket, counting the number of times
sched_waking was called for that pid.

`hist_data`와 `hist_field`

각 histogram은 `struct hist_trigger_data`인 `hist_data`로 표현된다.

`hist_data.fields[]` 배열은 histogram의 각 value와 key를 나타내는 `struct hist_field`를 보관한다. variable도 이 배열에 포함되지만 뒤에서 별도로 다룬다. 앞의 예에는 key 하나와 value 하나가 있으며, 명시하지 않아도 존재하는 `hitcount`가 그 value다.

각 `struct hist_field`는 event의 `trace_event_file`에 속한 `ftrace_event_field` 포인터와 size, offset, type 같은 정보, 그리고 ftrace event buffer에서 field 데이터를 가져오는 `hist_field_fn_t` 함수를 가진다. `hitcount`처럼 trace buffer의 event field에 직접 대응하지 않는 field는 함수가 다른 위치에서 값을 얻는다.

`flags`는 key, value, variable, variable reference 등 field 유형을 나타내며 기본 유형은 value다.

`fields[]`와 함께 중요한 `hist_data` 구성 요소는 `.map`에 저장되는 `tracing_map` instance다. `tracing_map`은 histogram을 구현하는 lock-free hash table이며 저수준 자료 구조는 `kernel/trace/tracing_map.h`에 자세히 설명되어 있다. 여기서는 특정 histogram key의 hash에 대응하는 `tracing_map_elt` 객체를 bucket마다 가진다고 보면 된다.

Each histogram is represented by a hist_data struct.

To keep track of each key and value field in the histogram, hist_data
keeps an array of these fields named fields[].  The fields[] array is
an array containing struct hist_field representations of each
histogram val and key in the histogram (variables are also included
here, but are discussed later). So for the above histogram we have one
key and one value; in this case the one value is the hitcount value,
which all histograms have, regardless of whether they define that
value or not, which the above histogram does not.

Each struct hist_field contains a pointer to the ftrace_event_field
from the event's trace_event_file along with various bits related to
that such as the size, offset, type, and a hist_field_fn_t function,
which is used to grab the field's data from the ftrace event buffer
(in most cases - some hist_fields such as hitcount don't directly map
to an event field in the trace buffer - in these cases the function
implementation gets its value from somewhere else).  The flags field
indicates which type of field it is - key, value, variable, variable
reference, etc., with value being the default.

The other important hist_data data structure in addition to the
fields[] array is the tracing_map instance created for the histogram,
which is held in the .map member.  The tracing_map implements the
lock-free hash table used to implement histograms (see
kernel/trace/tracing_map.h for much more discussion about the
low-level data structures implementing the tracing_map).  For the
purposes of this discussion, the tracing_map contains a number of
buckets, each bucket corresponding to a particular tracing_map_elt
object hashed by a given histogram key.

`fields[]` 배열 배치

앞 histogram의 `hist_data`에는 `hitcount` value field 하나와 `pid` key field 하나가 있다. 아래 구조는 원문의 첫 ASCII 그림을 배열 경계와 field 속성 중심으로 다시 나타낸 것이다.

`hist_data.n_vals`와 `hist_data.n_fields`는 `fields[]` 배열의 유효 범위를 정하고, 나머지 코드가 value와 key를 구분할 수 있게 한다.

Below is a diagram the first part of which describes the hist_data and
associated key and value fields for the histogram described above.  As
you can see, there are two fields in the fields array, one val field
for the hitcount and one key field for the pid key.

Below that is a diagram of a run-time snapshot of what the tracing_map
might look like for a given run.  It attempts to show the
relationships between the hist_data fields and the tracing_map
elements for a couple hypothetical keys and values.::

  +------------------+
  | 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   |  |

The hist_data n_vals and n_fields delineate the extent of the fields[]
array and separate keys from values for the rest of the code.

`tracing_map` 실행 시 구조

실행 중 `tracing_map`은 `tracing_map_entry` 배열과 미리 할당된 `tracing_map_elt` 집합으로 구성된다. 원문 그림에서는 각각 `map_entry`와 `map_elt`로 줄여 쓴다.

`hist_data.map`의 전체 `map_entry` 수는 실제로 `map->map_size`지만 그중 `map->max_elts`개만 사용한다. 이는 `map_insert()` 알고리즘이 요구하는 성질이다.

사용하지 않은 `map_entry`는 `.key`가 `0`이고 `.val`이 `NULL`이다. entry가 점유되면 `.key`에는 key hash 값이 들어가고 `.val`은 full key와 각 key/value field 항목을 보유한 `map_elt`를 가리킨다.

`map_elt.fields[]`에는 histogram의 각 `hist_field`에 대응하는 항목이 하나씩 있다. histogram value에 대해 계속 집계되는 합계는 이 배열의 `.sum`에 저장되고, key field에는 정렬에 사용할 `.offset`이 저장된다.

그림에서 사용하는 약어는 다음과 같다.

  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

Below is a run-time representation of the tracing_map part of the
histogram, with pointers from various parts of the fields[] array
to corresponding parts of the tracing_map.

The tracing_map consists of an array of tracing_map_entrys and a set
of preallocated tracing_map_elts (abbreviated below as map_entry and
map_elt).  The total number of map_entrys in the hist_data.map array =
map->max_elts (actually map->map_size but only max_elts of those are
used.  This is a property required by the map_insert() algorithm).

If a map_entry is unused, meaning no key has yet hashed into it, its
.key value is 0 and its .val pointer is NULL.  Once a map_entry has
been claimed, the .key value contains the key's hash value and the
.val member points to a map_elt containing the full key and an entry
for each key or value in the map_elt.fields[] array.  There is an
entry in the map_elt.fields[] array corresponding to each hist_field
in the histogram, and this is where the continually aggregated sums
corresponding to each histogram value are kept.

The diagram attempts to show the relationship between the
hist_data.fields[] and the map_elt.fields[] with the links drawn
between diagrams::

  +-----------+		                                                 |  |
  | 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) |
                                                      +---------------+

Abbreviations used in the diagrams::

  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 발생 시 key 조회와 value 갱신

hist trigger가 연결된 새 event가 발생하면 `event_hist_trigger()`가 호출된다. 먼저 key의 각 subkey를 처리한다. 앞 예에서는 pid 하나뿐이며, 이를 나타내는 `hist_field`를 `hist_data.fields[]`에서 얻는다. 해당 field의 `hist_field_fn_t fn()`, size, offset을 사용해 현재 trace record에서 subkey 데이터를 추출한다.

완전한 key를 얻으면 `tracing_map`에서 조회한다. key와 연결된 `tracing_map_elt`가 없으면 비어 있는 element를 점유해 새 key로 map에 삽입한다. 어느 경우든 해당 key의 `tracing_map_elt`를 반환한다.

element를 얻으면 `hist_trigger_elt_update()`를 호출해 element의 field들을 갱신한다. 각 histogram key와 value에는 `tracing_map_field`가 하나씩 있으며, histogram 생성 때 만들어진 key/value `hist_field`와 대응한다.

`hist_trigger_elt_update()`는 각 value `hist_field`를 순회하고 key 처리와 마찬가지로 `fn()`, size, offset을 이용해 현재 trace record에서 값을 가져온다. 그런 다음 해당 값을 계속 누적되는 `tracing_map_field.sum`에 더한다. `hitcount`의 `fn()`처럼 trace record에서 값을 읽지 않고 counter 합계를 `1` 늘리는 경우도 있지만 원리는 같다.

모든 value를 갱신하면 함수가 반환한다. 각 key subkey에도 `tracing_map_field`가 있지만 `hist_trigger_elt_update()`는 이를 읽거나 갱신하지 않는다. key field는 나중에 수행할 수 있는 정렬을 위해서만 존재한다.

Whenever a new event occurs and it has a hist trigger associated with
it, event_hist_trigger() is called.  event_hist_trigger() first deals
with the key: for each subkey in the key (in the above example, there
is just one subkey corresponding to pid), the hist_field that
represents that subkey is retrieved from hist_data.fields[] and the
hist_field_fn_t fn() associated with that field, along with the
field's size and offset, is used to grab that subkey's data from the
current trace record.

Once the complete key has been retrieved, it's used to look that key
up in the tracing_map.  If there's no tracing_map_elt associated with
that key, an empty one is claimed and inserted in the map for the new
key.  In either case, the tracing_map_elt associated with that key is
returned.

Once a tracing_map_elt available, hist_trigger_elt_update() is called.
As the name implies, this updates the element, which basically means
updating the element's fields.  There's a tracing_map_field associated
with each key and value in the histogram, and each of these correspond
to the key and value hist_fields created when the histogram was
created.  hist_trigger_elt_update() goes through each value hist_field
and, as for the keys, uses the hist_field's fn() and size and offset
to grab the field's value from the current trace record.  Once it has
that value, it simply adds that value to that field's
continually-updated tracing_map_field.sum member.  Some hist_field
fn()s, such as for the hitcount, don't actually grab anything from the
trace record (the hitcount fn() just increments the counter sum by 1),
but the idea is the same.

Once all the values have been updated, hist_trigger_elt_update() is
done and returns.  Note that there are also tracing_map_fields for
each subkey in the key, but hist_trigger_elt_update() doesn't look at
them or update anything - those exist only for sorting, which can
happen later.

기본 histogram 내부 구조 테스트

이 테스트는 출력에 value field 세 개와 key field 두 개를 만든다.

  # echo 'hist:keys=common_pid,call_site.sym:values=bytes_req,bytes_alloc,hitcount' >> events/kmem/kmalloc/trigger

`kmem/kmalloc`의 `hist_debug` 파일을 읽으면 해당 histogram의 trigger 정보와 연결된 `hist_data` 주소가 표시된다. 이 주소는 뒤의 예에서 활용된다. 이어서 전체 `hist_field` 수와 그중 key와 value에 해당하는 수를 보여 준다.

각 field에 대해서는 flags와 `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

다음 테스트를 위해 아래 명령으로 이 histogram trigger를 제거할 수 있다.

  # echo '!hist:keys=common_pid,call_site.sym:values=bytes_req,bytes_alloc,hitcount' >> events/kmem/kmalloc/trigger

Basic histogram test
--------------------

This is a good example to try.  It produces 3 value fields and 2 key
fields in the output::

  # echo 'hist:keys=common_pid,call_site.sym:values=bytes_req,bytes_alloc,hitcount' >> events/kmem/kmalloc/trigger

To see the debug data, cat the kmem/kmalloc's 'hist_debug' file. It
will show the trigger info of the histogram it corresponds to, along
with the address of the hist_data associated with the histogram, which
will become useful in later examples.  It then displays the number of
total hist_fields associated with the histogram along with a count of
how many of those correspond to keys and how many correspond to values.

It then goes on to display details for each field, including the
field's flags and the position of each field in the hist_data's
fields[] array, which is useful information for verifying that things
internally appear correct or not, and which again will become even
more useful in further examples::

  # 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

The commands below can be used to clean things up for the next test::

  # echo '!hist:keys=common_pid,call_site.sym:values=bytes_req,bytes_alloc,hitcount' >> events/kmem/kmalloc/trigger

Histogram 변수 모델

variable을 사용하면 한 hist trigger가 저장한 데이터를 다른 hist trigger가 나중에 가져올 수 있다. 예를 들어 `sched_waking` trigger가 특정 pid의 timestamp를 저장하고, 이후 그 pid로 전환하는 `sched_switch` event가 timestamp를 읽어 두 event 사이의 시간 차이를 계산할 수 있다.

  # 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

histogram 자료 구조에서 variable은 또 다른 `hist_field` 유형으로 구현되며, 해당 trigger의 모든 value field 바로 뒤에 있는 `hist_data.fields[]`에 추가된다. 기존 key/value와 구분하기 위해 `HIST_FIELD_FL_VAR`, 줄여서 `FL_VAR` flag를 사용한다.

`struct hist_field`의 새 `.var.idx` 구성원은 variable을 `map_elt.vars[]` 배열의 index에 연결한다. 이 배열은 variable 값을 저장하고 검색하기 위해 `map_elt`에 추가됐다. 다음 `sched_waking` 구조에는 위 trigger의 `ts0` variable에 대응하는 항목이 포함된다.

Variables
=========

Variables allow data from one hist trigger to be saved by one hist
trigger and retrieved by another hist trigger.  For example, a trigger
on the sched_waking event can capture a timestamp for a particular
pid, and later a sched_switch event that switches to that pid event
can grab the timestamp and use it to calculate a time delta between
the two events::

  # 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

In terms of the histogram data structures, variables are implemented
as another type of hist_field and for a given hist trigger are added
to the hist_data.fields[] array just after all the val fields.  To
distinguish them from the existing key and val fields, they're given a
new flag type, HIST_FIELD_FL_VAR (abbreviated FL_VAR) and they also
make use of a new .var.idx field member in struct hist_field, which
maps them to an index in a new map_elt.vars[] array added to the
map_elt specifically designed to store and retrieve variable values.
The diagram below shows those new elements and adds a new variable
entry, ts0, corresponding to the ts0 variable in the sched_waking
trigger above.

`sched_waking` variable field 배치

기본 histogram과 마찬가지로 `hist_data.fields[]`에는 value, variable, key가 순서대로 배치된다. 원문의 ASCII 그림은 다음과 같이 구조화할 수 있다.

`struct hist_field`에는 `.flags`가 추가됐고 `ts0`를 나타내는 새 entry가 `hist_data.fields[]`에 들어간다. 일반 value `hist_field`의 `.flags`는 modifier flag를 제외하면 `0`이지만 variable로 정의된 value에는 `FL_VAR` bit가 설정된다.

`ts0` entry의 `.var.idx`는 variable 값을 담는 `tracing_map_elt.vars[]` index다. variable 값을 설정하거나 읽을 때 항상 이 index를 사용한다. `create_tracing_map_fields()`는 `tracing_map_add_var()`를 호출한 뒤 해당 variable에 배정된 `map_elt.vars` index를 `.var.idx`에 저장한다.

sched_waking histogram
----------------------

.. code-block::

  +------------------+
  | 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   | | |
                                                                          | | |

This is very similar to the basic case.  In the above diagram, we can
see a new .flags member has been added to the struct hist_field
struct, and a new entry added to hist_data.fields representing the ts0
variable.  For a normal val hist_field, .flags is just 0 (modulo
modifier flags), but if the value is defined as a variable, the .flags
contains a set FL_VAR bit.

As you can see, the ts0 entry's .var.idx member contains the index
into the tracing_map_elts' .vars[] array containing variable values.
This idx is used whenever the value of the variable is set or read.
The map_elt.vars idx assigned to the given variable is assigned and
saved in .var.idx by create_tracing_map_fields() after it calls
tracing_map_add_var().

`sched_waking` variable의 실행 시 저장

실행 중 map이 채워지면 `hist_data.fields[]` 정의는 각 `map_elt`의 `.fields[]` 및 `.vars[]`와 연결된다. `.fields[]` 항목은 key의 `.offset` 또는 value의 `.sum`을 가리키고, `.vars[]` 항목은 variable의 실제 값을 보관한다.

사용 중인 map entry마다 variable의 현재 값을 담는 `.vars` 배열을 가리키는 `map_elt`가 있다. 따라서 pid 999와 pid 4444는 동일한 `.var.idx`를 사용해도 각자의 `map_elt.vars[]`에서 서로 다른 timestamp를 보관한다.

Below is a representation of the histogram at run-time, which
populates the map, along with correspondence to the above hist_data and
hist_field data structures.

The diagram attempts to show the relationship between the
hist_data.fields[] and the map_elt.fields[] and map_elt.vars[] with
the links drawn between diagrams.  For each of the map_elts, you can
see that the .fields[] members point to the .sum or .offset of a key
or val and the .vars[] members point to the value of a variable.  The
arrows between the two diagrams show the linkages between those
tracing_map members and the field definitions in the corresponding
hist_data fields[] members.::

  +-----------+		                                                  | | |
  | 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        |     | |
                                                      |               |     | |
                                                      +---------------+     | |

For each used map entry, there's a map_elt pointing to an array of
.vars containing the current value of the variables associated with
that histogram entry.  So in the above, the timestamp associated with
pid 999 is 113345679876, and the timestamp variable in the same
.var.idx for pid 4444 is 213499240729.

`sched_switch` variable reference

앞의 `sched_waking` histogram과 짝을 이루는 `sched_switch` histogram의 핵심은 다른 histogram의 variable을 참조한다는 점이다. 일반 `hitcount`와 key 외에 `wakeup_lat` variable이 `ts0`와 같은 방식으로 만들어지고, `HIST_FIELD_FL_VAR_REF`를 줄인 `FL_VAR_REF` field가 추가된다.

variable reference field에는 `var.hist_data`와 `var_ref_idx`가 추가된다. `var.hist_data`와 `var.idx`를 함께 사용하면 특정 histogram의 특정 variable을 고유하게 식별할 수 있다. `var_ref_idx`는 hist trigger를 갱신할 때 각 참조 값을 cache하는 `var_ref_vals[]`의 index다. trace action 같은 코드는 이 index로 parameter 값을 배정한다.

  # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0' >>
          events/sched/sched_switch/trigger

그림에서 사용하는 약어는 다음과 같다.

  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 trigger가 variable을 사용하면 `HIST_FIELD_FL_VAR_REF` flag를 가진 새 `hist_field`가 만들어진다. VAR_REF field의 `var.idx`, `var.hist_data`, size, type, `is_signed`는 참조 대상 variable과 같은 값을 사용하며 `.name`은 참조한 variable 이름이다. 명시적 `system.event.$var_ref` 표기로 만들었다면 `hist_field.system`과 `event_name`도 설정된다.

다른 histogram의 variable을 참조하므로 `event_hist_trigger()`는 먼저 `resolve_var_refs()`를 호출한다. 이 함수는 `sched_switch`의 `hist_data.var_refs[]`를 순회하고 각 reference의 `var.hist_data`와 현재 key로 대상 histogram의 `tracing_map_elt`를 찾는다. 이어서 `tracing_map_read_var(elt, var.idx)`로 값을 읽어 `ts0`를 얻는다. variable과 variable reference의 `var.idx`가 같기 때문에 같은 slot을 직접 찾을 수 있다.

sched_switch histogram
----------------------

The sched_switch histogram paired with the above sched_waking
histogram is shown below.  The most important aspect of the
sched_switch histogram is that it references a variable on the
sched_waking histogram above.

The histogram diagram is very similar to the others so far displayed,
but it adds variable references.  You can see the normal hitcount and
key fields along with a new wakeup_lat variable implemented in the
same way as the sched_waking ts0 variable, but in addition there's an
entry with the new FL_VAR_REF (short for HIST_FIELD_FL_VAR_REF) flag.

Associated with the new var ref field are a couple of new hist_field
members, var.hist_data and var_ref_idx.  For a variable reference, the
var.hist_data goes with the var.idx, which together uniquely identify
a particular variable on a particular histogram.  The var_ref_idx is
just the index into the var_ref_vals[] array that caches the values of
each variable whenever a hist trigger is updated.  Those resulting
values are then finally accessed by other code such as trace action
code that uses the var_ref_idx values to assign param values.

The diagram below describes the situation for the sched_switch
histogram referred to before::

  # 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        |
                           +---------------------+

Abbreviations used in the diagrams::

  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

When a hist trigger makes use of a variable, a new hist_field is
created with flag HIST_FIELD_FL_VAR_REF.  For a VAR_REF field, the
var.idx and var.hist_data take the same values as the referenced
variable, as well as the referenced variable's size, type, and
is_signed values.  The VAR_REF field's .name is set to the name of the
variable it references.  If a variable reference was created using the
explicit system.event.$var_ref notation, the hist_field's system and
event_name variables are also set.

So, in order to handle an event for the sched_switch histogram,
because we have a reference to a variable on another histogram, we
need to resolve all variable references first.  This is done via the
resolve_var_refs() calls made from event_hist_trigger().  What this
does is grabs the var_refs[] array from the hist_data representing the
sched_switch histogram.  For each one of those, the referenced
variable's var.hist_data along with the current key is used to look up
the corresponding tracing_map_elt in that histogram.  Once found, the
referenced variable's var.idx is used to look up the variable's value
using tracing_map_read_var(elt, var.idx), which yields the value of
the variable for that element, ts0 in the case above.  Note that both
the hist_fields representing both the variable and the variable
reference have the same var.idx, so this is straightforward.

Variable 및 variable reference 테스트

이 예시는 `sched_waking` event에 `ts0` variable을 만들고 `sched_switch` trigger에서 사용한다. `sched_switch`는 자체 `wakeup_lat` variable도 만들지만 아직 다른 곳에서 사용하지 않는다.

  # 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`의 value field 영역에는 일반 key/value 외에 `HIST_FIELD_FL_VAR` field가 나타난다. `var.name`은 variable 이름, `var.idx`는 실제 variable 위치인 `tracing_map_elt.vars[]`의 index다. variable은 일반 value와 같은 `hist_data.fields[]` value 영역에 위치한다.

  # 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` variable과 별도로 variable reference 영역이 나타난다. reference는 논리적으로 value/variable과 다르고 실제로도 별도 `hist_data.var_refs[]` 배열에 저장되므로 독립된 절로 출력된다.

이 trigger의 `$ts0` reference에서 `var.hist_data`는 앞서 출력한 `sched_waking`의 주소와 일치하고 `var.idx`도 `ts0`의 index와 같다. `var_ref_idx`는 trigger 호출 때 참조 값을 cache하는 위치다.

  # 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

다음 테스트를 위해 아래 두 명령으로 `sched_switch`와 `sched_waking` histogram을 제거한다.

  # 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

Variable and variable reference test
------------------------------------

This example creates a variable on the sched_waking event, ts0, and
uses it in the sched_switch trigger.  The sched_switch trigger also
creates its own variable, wakeup_lat, but nothing yet uses it::

  # 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

Looking at the sched_waking 'hist_debug' output, in addition to the
normal key and value hist_fields, in the val fields section we see a
field with the HIST_FIELD_FL_VAR flag, which indicates that that field
represents a variable.  Note that in addition to the variable name,
contained in the var.name field, it includes the var.idx, which is the
index into the tracing_map_elt.vars[] array of the actual variable
location.  Note also that the output shows that variables live in the
same part of the hist_data->fields[] array as normal values::

  # 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

Moving on to the sched_switch trigger hist_debug output, in addition
to the unused wakeup_lat variable, we see a new section displaying
variable references.  Variable references are displayed in a separate
section because in addition to being logically separate from
variables and values, they actually live in a separate hist_data
array, var_refs[].

In this example, the sched_switch trigger has a reference to a
variable on the sched_waking trigger, $ts0.  Looking at the details,
we can see that the var.hist_data value of the referenced variable
matches the previously displayed sched_waking trigger, and the var.idx
value matches the previously displayed var.idx value for that
variable.  Also displayed is the var_ref_idx value for that variable
reference, which is where the value for that variable is cached for
use when the trigger is invoked::

  # 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

The commands below can be used to clean things up for the next test::

  # 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

Action과 handler 개요

앞 예시에 이어 이제 `wakeup_lat` variable과 다른 field 하나를 synthetic event로 전송한다.

`onmatch()` action은 `sched_switch` event가 발생했을 때 대응하는 `sched_waking` event가 있는지 검사한다. 여기서는 `sched_waking` histogram의 pid가 현재 `sched_switch.next_pid`와 일치하면 `wakeup_latency()` trace action에 지정된 variable을 가져와 trace stream에 새 `wakeup_latency` event를 생성한다.

`wakeup_latency()` 같은 trace handler는 `trace(wakeup_latency,$wakeup_lat,next_pid)`로도 쓸 수 있으며 parameter로 variable만 받도록 구현돼 있다. `$wakeup_lat`은 variable이지만 `next_pid`는 `sched_switch` trace event field 이름이다. `trace()`와 `save()`에서 field 이름을 자주 직접 사용하므로, 내부에서 그 field를 위한 임시 variable을 만들어 handler에 전달하는 shortcut을 제공한다. 코드와 문서에서는 이를 field variable이라고 부른다.

다른 trace event histogram의 field도 사용할 수 있다. 이 경우 새 histogram과 `synthetic_field`라는 특수 histogram field를 만들어 variable로 사용한다. 여기서 synthetic이라는 이름은 synthetic event와 관계없다.

Actions and Handlers
====================

Adding onto the previous example, we will now do something with that
wakeup_lat variable, namely send it and another field as a synthetic
event.

The onmatch() action below basically says that whenever we have a
sched_switch event, if we have a matching sched_waking event, in this
case if we have a pid in the sched_waking histogram that matches the
next_pid field on this sched_switch event, we retrieve the
variables specified in the wakeup_latency() trace action, and use
them to generate a new wakeup_latency event into the trace stream.

Note that the way the trace handlers such as wakeup_latency() (which
could equivalently be written trace(wakeup_latency,$wakeup_lat,next_pid)
are implemented, the parameters specified to the trace handler must be
variables.  In this case, $wakeup_lat is obviously a variable, but
next_pid isn't, since it's just naming a field in the sched_switch
trace event.  Since this is something that almost every trace() and
save() action does, a special shortcut is implemented to allow field
names to be used directly in those cases.  How it works is that under
the covers, a temporary variable is created for the named field, and
this variable is what is actually passed to the trace handler.  In the
code and documentation, this type of variable is called a 'field
variable'.

Fields on other trace event's histograms can be used as well.  In that
case we have to generate a new histogram and an unfortunately named
'synthetic_field' (the use of synthetic here has nothing to do with
synthetic events) and use that special histogram field as a variable.

The diagram below illustrates the new elements described above in the
context of the sched_switch histogram using the onmatch() handler and
the trace() action.

`onmatch()`와 synthetic event 설정

먼저 `lat`와 `pid` field를 가진 `wakeup_latency` synthetic event를 정의한다.

  # echo 'wakeup_latency u64 lat; pid_t pid' >> synthetic_events

그다음 앞과 같은 `sched_waking` hist trigger를 만든다.

  # echo 'hist:keys=pid:ts0=common_timestamp.usecs' >>
          events/sched/sched_waking/trigger

마지막으로 `sched_switch` event에 hist trigger를 만들고 `wakeup_latency()` trace event를 생성한다. `next_pid`를 synthetic event 호출에 직접 전달하므로 자동으로 field variable로 변환된다.

  # 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

First, we define the wakeup_latency synthetic event::

  # echo 'wakeup_latency u64 lat; pid_t pid' >> synthetic_events

Next, the sched_waking hist trigger as before::

  # echo 'hist:keys=pid:ts0=common_timestamp.usecs' >>
          events/sched/sched_waking/trigger

Finally, we create a hist trigger on the sched_switch event that
generates a wakeup_latency() trace event.  In this case we pass
next_pid into the wakeup_latency synthetic event invocation, which
means it will be automatically converted into a field variable::

  # 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

The diagram for the sched_switch event is similar to previous examples
but shows the additional field_vars[] array for hist_data and shows
the linkages between the field_vars and the variables and references
created to implement the field variables.  The details are discussed
below::

Field variable 자료 구조와 실행 경로

`sched_switch`의 `hist_data`에는 기존 `.fields[]`, `.map`, `.var_refs[]` 외에 `.field_vars[]`가 추가된다. 원문의 ASCII 그림은 field variable을 구현하기 위해 생성되는 variable/value 쌍과 세 variable reference의 연결을 보여 준다.

field variable 하나에는 두 `hist_field`가 만들어진다. 하나는 `next_pid` variable을 나타내고, 다른 하나는 일반 value field처럼 trace stream에서 실제 field 값을 가져온다. 이 쌍은 일반 variable 생성과 별도로 만들어져 `hist_data->field_vars[]`에 저장된다. `trace()` action에서 `$next_pid`를 참조하려면 reference `hist_field`도 추가로 필요하다.

`$wakeup_lat` 역시 `common_timestamp-$ts0` 식의 값을 참조하는 variable reference이므로 그 reference를 나타내는 hist field entry가 필요하다.

`hist_trigger_elt_update()`는 일반 key/value field를 가져올 때 `update_field_vars()`도 호출한다. 이 함수는 `hist_data->field_vars`의 각 `field_var`를 순회하며 `val->fn()`으로 현재 trace record의 데이터를 얻고, variable의 `var.idx`를 이용해 해당 `tracing_map_elt`의 `elt->vars[var.idx]`에 값을 저장한다.

모든 variable을 갱신한 뒤 `event_hist_trigger()`에서 `resolve_var_refs()`를 호출하면 `$ts0`, `$next_pid`, `$wakeup_lat` reference를 모두 resolve할 수 있다. 이 시점의 `trace()` action은 `var_ref_vals[]`에 모인 값을 읽어 trace event를 생성하면 된다.

`save()` action에 연결된 field variable도 같은 과정을 거친다.

그림에서 사용하는 약어는 다음과 같다.

  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

    +------------------+
    | 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        |
                             +---------------------+

As you can see, for a field variable, two hist_fields are created: one
representing the variable, in this case next_pid, and one to actually
get the value of the field from the trace stream, like a normal val
field does.  These are created separately from normal variable
creation and are saved in the hist_data->field_vars[] array.  See
below for how these are used.  In addition, a reference hist_field is
also created, which is needed to reference the field variables such as
$next_pid variable in the trace() action.

Note that $wakeup_lat is also a variable reference, referencing the
value of the expression common_timestamp-$ts0, and so also needs to
have a hist field entry representing that reference created.

When hist_trigger_elt_update() is called to get the normal key and
value fields, it also calls update_field_vars(), which goes through
each field_var created for the histogram, and available from
hist_data->field_vars and calls val->fn() to get the data from the
current trace record, and then uses the var's var.idx to set the
variable at the var.idx offset in the appropriate tracing_map_elt's
variable at elt->vars[var.idx].

Once all the variables have been updated, resolve_var_refs() can be
called from event_hist_trigger(), and not only can our $ts0 and
$next_pid references be resolved but the $wakeup_lat reference as
well.  At this point, the trace() action can simply access the values
assembled in the var_ref_vals[] array and generate the trace event.

The same process occurs for the field variables associated with the
save() action.

Abbreviations used in the diagram::

  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()` action field variable 테스트

이 예시는 앞의 테스트에서 한 단계 더 나아가 `wakeup_lat` variable을 실제로 사용한다. 여기에 field variable 두 개를 만들고, `onmatch()` handler를 통해 세 값을 모두 `wakeup_latency()` trace action에 전달한다.

먼저 `lat`, `pid`, `comm` field를 가진 `wakeup_latency` synthetic event를 만든다.

  # echo 'wakeup_latency u64 lat; pid_t pid; char comm[16]' >> synthetic_events

다음으로 앞 예제와 동일한 `sched_waking` trigger를 설정한다.

  # echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger

마지막으로 `sched_waking` trigger의 `$ts0` reference를 이용해 wakeup latency를 계산하고 `wakeup_lat` variable에 대입한다. 이 값과 `sched_switch` event의 `next_pid`, `next_comm` field를 함께 사용해 `wakeup_latency` trace event를 생성한다. 이 용도를 위해 `next_pid`와 `next_comm`은 자동으로 field variable로 변환된다.

  # 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` 출력은 앞 테스트와 동일하다. `ts0`는 `var.idx = 0`에 저장된 `HIST_FIELD_FL_VAR` value이고 `pid`는 key field다.

  # 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`에도 앞 테스트와 같은 key 및 value field가 나타난다. `wakeup_lat`는 계속 value field 영역에 있지만 새 field variable은 그곳에 없다. field variable 역시 variable이지만 `hist_data.field_vars[]` 배열에 별도로 보관되기 때문이다. 저장 위치는 달라도 실제 variable slot은 하나의 `tracing_map_elt.vars[]`에서 연속 index를 사용한다. 따라서 `wakeup_lat`는 `var.idx = 0`, `next_pid`와 `next_comm` field variable은 각각 `var.idx = 1`, `var.idx = 2`를 차지한다.

variable reference 영역에도 같은 index가 표시된다. 두 trigger에는 서로 다른 `hist_data` 주소가 있으므로 reference를 식별할 때 주소까지 함께 봐야 한다. 첫 reference `$ts0`는 이전 `sched_waking` histogram의 `var.idx = 0`을 가리키고, 두 번째 `$wakeup_lat`와 나머지 field variable reference는 `sched_switch` histogram의 slot을 가리킨다.

action tracking variables 영역은 `onmatch()` handler가 비교할 system과 event 이름만 보여 준다. 이 예에서는 각각 `sched`와 `sched_waking`이다.

  # 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

다음 세 명령은 이어지는 테스트를 위해 `sched_switch` trigger, `sched_waking` trigger, `wakeup_latency` synthetic event를 역순으로 제거한다.

  # 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

trace() action field variable test
----------------------------------

This example adds to the previous test example by finally making use
of the wakeup_lat variable, but in addition also creates a couple of
field variables that then are all passed to the wakeup_latency() trace
action via the onmatch() handler.

First, we create the wakeup_latency synthetic event::

  # echo 'wakeup_latency u64 lat; pid_t pid; char comm[16]' >> synthetic_events

Next, the sched_waking trigger from previous examples::

  # echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger

Finally, as in the previous test example, we calculate and assign the
wakeup latency using the $ts0 reference from the sched_waking trigger
to the wakeup_lat variable, and finally use it along with a couple
sched_switch event fields, next_pid and next_comm, to generate a
wakeup_latency trace event.  The next_pid and next_comm event fields
are automatically converted into field variables for this purpose::

  # 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

The sched_waking hist_debug output shows the same data as in the
previous test example::

  # 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

The sched_switch hist_debug output shows the same key and value fields
as in the previous test example - note that wakeup_lat is still in the
val fields section, but that the new field variables are not there -
although the field variables are variables, they're held separately in
the hist_data's field_vars[] array.  Although the field variables and
the normal variables are located in separate places, you can see that
the actual variable locations for those variables in the
tracing_map_elt.vars[] do have increasing indices as expected:
wakeup_lat takes the var.idx = 0 slot, while the field variables for
next_pid and next_comm have values var.idx = 1, and var.idx = 2.  Note
also that those are the same values displayed for the variable
references corresponding to those variables in the variable reference
fields section.  Since there are two triggers and thus two hist_data
addresses, those addresses also need to be accounted for when doing
the matching - you can see that the first variable refers to the 0
var.idx on the previous hist trigger (see the hist_data address
associated with that trigger), while the second variable refers to the
0 var.idx on the sched_switch hist trigger, as do all the remaining
variable references.

Finally, the action tracking variables section just shows the system
and event name for the onmatch() handler::

  # 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

The commands below can be used to clean things up for the next test::

  # 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()` action

앞에서 설명했듯 `trace()` action이 synthetic event를 만들 때 모든 parameter는 이미 variable이거나 field variable을 통해 variable로 변환된다. 그런 다음 이 variable 값의 reference를 해석해 `var_ref_vals[]` 배열에 모은다.

그러나 `var_ref_vals[]`의 값 순서는 synthetic event parameter 순서와 반드시 같지 않다. 이를 해결하기 위해 `struct action_data`에는 `action_data.var_ref_idx[]` 배열이 하나 더 있으며, 각 trace action parameter를 대응하는 `var_ref_vals[]` 값에 매핑한다. `action_data.synth_event`는 synthetic event의 field 순서를 제공하고, 같은 위치의 `var_ref_idx[i]`가 실제 값의 index를 알려 준다.

synthetic event probe 함수 `trace_event_raw_event_synth()`에서는 각 `.synth_event` field `i`에 대해 `.var_ref_idx[i]`를 읽어 `val_idx`를 얻고, `var_ref_vals[val_idx]`에서 실제 값을 가져오는 방식으로 이 매핑을 사용한다.

  for each field i in .synth_event
    val_idx = .var_ref_idx[i]
    val = var_ref_vals[val_idx]

action_data and the trace() action
----------------------------------

As mentioned above, when the trace() action generates a synthetic
event, all the parameters to the synthetic event either already are
variables or are converted into variables (via field variables), and
finally all those variable values are collected via references to them
into a var_ref_vals[] array.

The values in the var_ref_vals[] array, however, don't necessarily
follow the same ordering as the synthetic event params.  To address
that, struct action_data contains another array, var_ref_idx[] that
maps the trace action params to the var_ref_vals[] values.  Below is a
diagram illustrating that for the wakeup_latency() synthetic event::

  +------------------+     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 |
                                                     +-----------------+

Basically, how this ends up getting used in the synthetic event probe
function, trace_event_raw_event_synth(), is as follows::

  for each field i in .synth_event
    val_idx = .var_ref_idx[i]
    val = var_ref_vals[val_idx]

`action_data`와 `onXXX()` handler

`onmatch()` 이외의 hist trigger `onXXX()` action, 예를 들어 `onmax()`와 `onchange()`도 숨겨진 variable을 내부적으로 만들어 사용한다. 이 정보는 `action_data.track_data` 구조체에 들어 있으며, 뒤 예제에서 설명할 `hist_debug` 출력에서도 확인할 수 있다.

일반적으로 `onmax()` 또는 `onchange()` handler는 `save()` 및 `snapshot()` action과 함께 사용한다. 아래 첫 명령은 새 최대 wakeup latency가 관측될 때 여러 `sched_switch` field를 저장하고, 두 번째 명령은 새 최대값에서 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

or::

  # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \
          onmax($wakeup_lat).snapshot()' >>
          /sys/kernel/tracing/events/sched/sched_switch/trigger

action_data and the onXXX() handlers
------------------------------------

The hist trigger onXXX() actions other than onmatch(), such as onmax()
and onchange(), also make use of and internally create hidden
variables.  This information is contained in the
action_data.track_data struct, and is also visible in the hist_debug
output as will be described in the example below.

Typically, the onmax() or onchange() handlers are used in conjunction
with the save() and snapshot() actions.  For example::

  # 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

or::

  # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \
          onmax($wakeup_lat).snapshot()' >>
          /sys/kernel/tracing/events/sched/sched_switch/trigger

`save()` action field variable 테스트

이 예제는 synthetic event를 생성하는 대신 `onmax()` handler가 새 최대 latency를 감지할 때마다 `save()` action으로 field 값을 저장한다. 앞 예제처럼 저장 대상은 event field지만, 이번에는 `hist_data.save_vars[]`라는 별도 배열에 보관한다.

먼저 이전 테스트와 같은 `sched_waking` trigger를 설정한다.

  # echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger

그다음 새 최대 latency가 관측될 때 `sched_switch`의 `next_comm`, `prev_pid`, `prev_prio`, `prev_comm`을 저장하도록 `sched_switch` trigger를 설정한다. `onmax()` handler와 `save()` action 양쪽에서 내부 variable이 생성되며, 이를 `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` 출력은 이전 테스트와 동일하다. `ts0` variable은 `var.idx = 0`에 있고 `pid`가 key다.

  # 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` 출력의 기존 value와 key도 앞과 같지만, action tracking variables와 save action variables라는 두 영역이 새로 나타난다.

action tracking variables 영역의 `actions[].track_data`는 실행 중 최대값을 추적하는 특수 variable과 reference를 설명한다. `actions[].track_data.var_ref`는 추적 대상인 `$wakeup_lat` reference를 담는다. `onmax()`가 현재 최대값과 비교하려면 새 최대값이 나올 때마다 갱신되는 variable도 필요하므로, 자동 생성된 `__max` variable이 `actions[].track_data.track_var`에 들어간다.

save action variables 영역에서는 `save()`의 네 parameter 때문에 네 field variable이 만들어진 것을 볼 수 있다. 최대값이 갱신되는 순간 이름으로 지정한 field 값을 저장하려는 variable이며, 일반 field variable과 구분해 `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

다음 두 명령은 다음 테스트를 위해 `sched_switch`의 `onmax().save()` trigger와 `sched_waking` trigger를 제거한다.

  # 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

save() action field variable test
---------------------------------

For this example, instead of generating a synthetic event, the save()
action is used to save field values whenever an onmax() handler
detects that a new max latency has been hit.  As in the previous
example, the values being saved are also field values, but in this
case, are kept in a separate hist_data array named save_vars[].

As in previous test examples, we set up the sched_waking trigger::

  # echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger

In this case, however, we set up the sched_switch trigger to save some
sched_switch field values whenever we hit a new maximum latency.  For
both the onmax() handler and save() action, variables will be created,
which we can use the hist_debug files to examine::

  # 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

The sched_waking hist_debug output shows the same data as in the
previous test examples::

  # 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

The output of the sched_switch trigger shows the same val and key
values as before, but also shows a couple new sections.

First, the action tracking variables section now shows the
actions[].track_data information describing the special tracking
variables and references used to track, in this case, the running
maximum value.  The actions[].track_data.var_ref member contains the
reference to the variable being tracked, in this case the $wakeup_lat
variable.  In order to perform the onmax() handler function, there
also needs to be a variable that tracks the current maximum by getting
updated whenever a new maximum is hit.  In this case, we can see that
an auto-generated variable named ' __max' has been created and is
visible in the actions[].track_data.track_var variable.

Finally, in the new 'save action variables' section, we can see that
the 4 params to the save() function have resulted in 4 field variables
being created for the purposes of saving the values of the named
fields when the max is hit.  These variables are kept in a separate
save_vars[] array off of hist_data, so are displayed in a separate
section::

  # 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

The commands below can be used to clean things up for the next test::

  # 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

혼동하기 쉬운 특수 사례

앞 절까지 histogram 내부 구조의 기본을 다뤘지만, 더 혼동하기 쉬운 특수 사례 두 가지가 남아 있다. 하나는 다른 histogram의 field variable이고 다른 하나는 alias다. 아래에서는 둘 다 `hist_debug`를 이용한 테스트로 설명한다.

A couple special cases
======================

While the above covers the basics of the histogram internals, there
are a couple of special cases that should be discussed, since they
tend to create even more confusion.  Those are field variables on other
histograms, and aliases, both described below through example tests
using the hist_debug files.

다른 histogram의 field variable 테스트

이 예제는 앞선 예제와 비슷하지만 `sched_switch` trigger가 다른 event인 `sched_waking`의 hist trigger field를 참조한다. 이를 위해 상대 event의 field variable이 필요하다. 기존 histogram은 생성 후 변경할 수 없으므로 matching variable을 가진 새 histogram을 만들어 사용하며, 이 구조가 아래 `hist_debug` 출력에 나타난다.

먼저 `prio` field가 추가된 `wakeup_latency` synthetic event를 만든다.

  # echo 'wakeup_latency u64 lat; pid_t pid; int prio' >> synthetic_events

그다음 이전 테스트와 같은 `sched_waking` trigger를 설정한다.

  # echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger

`sched_switch`에는 `sched_waking` event를 지정한 `onmatch()` handler를 만들고 `wakeup_latency()`의 세 번째 parameter로 `prio`를 전달한다. `prio`는 field variable이 필요하지만 `sched_switch` event에는 해당 field가 없고, matching event인 `sched_waking`에는 존재한다. 이미 존재하는 histogram에는 새 variable을 추가할 수 없으므로, 같은 key와 filter를 사용하는 추가 matching `sched_waking` histogram을 만들고 그곳에 `prio` field variable을 정의한다.

이 동작을 요청하는 `sched_switch` trigger는 다음과 같다.

  # 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`에는 histogram 두 개가 표시된다. 첫 번째는 이전 예제에서 본 일반 `sched_waking` histogram이고, 두 번째는 `prio` field variable을 제공하기 위해 자동 생성된 특수 histogram이다.

두 번째 histogram의 `synthetic_prio` variable이 바로 `sched_waking.prio` field용 field variable이다. `HIST_FIELD_FL_VAR`가 설정되고 `ftrace_event_field name`은 `prio`, `var.idx`는 이 보조 histogram의 `0`이다.

  # 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` histogram에는 `sched_waking`의 `synthetic_prio` reference가 나타난다. `var.hist_data`가 새 matching histogram 주소인 `000000006920cf38`이므로 올바른 histogram과 연결됐음을 확인할 수 있다. 나머지 reference는 일반 variable `wakeup_lat`, 일반 field variable `next_pid`, 그리고 기존 `sched_waking`의 `ts0`다.

`field_vars[]`에는 현재 event에 실제로 존재하는 `next_pid`만 들어간다. `synthetic_prio`는 현재 event field가 아니라 matching histogram의 variable reference이므로 이 배열에 추가되지 않는다. action tracking 영역은 `onmatch()` 대상이 `sched.sched_waking`임을 기록한다.

  # 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

다음 세 명령은 `sched_switch` trigger, 기존 `sched_waking` trigger, `wakeup_latency` synthetic event를 제거한다. matching histogram은 action과 함께 관리되므로 trigger 제거 과정에서 정리된다.

  # 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

Test of field variables on other histograms
-------------------------------------------

This example is similar to the previous examples, but in this case,
the sched_switch trigger references a hist trigger field on another
event, namely the sched_waking event.  In order to accomplish this, a
field variable is created for the other event, but since an existing
histogram can't be used, as existing histograms are immutable, a new
histogram with a matching variable is created and used, and we'll see
that reflected in the hist_debug output shown below.

First, we create the wakeup_latency synthetic event.  Note the
addition of the prio field::

  # echo 'wakeup_latency u64 lat; pid_t pid; int prio' >> synthetic_events

As in previous test examples, we set up the sched_waking trigger::

  # echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger

Here we set up a hist trigger on sched_switch to send a wakeup_latency
event using an onmatch handler naming the sched_waking event.  Note
that the third param being passed to the wakeup_latency() is prio,
which is a field name that needs to have a field variable created for
it.  There isn't however any prio field on the sched_switch event so
it would seem that it wouldn't be possible to create a field variable
for it.  The matching sched_waking event does have a prio field, so it
should be possible to make use of it for this purpose.  The problem
with that is that it's not currently possible to define a new variable
on an existing histogram, so it's not possible to add a new prio field
variable to the existing sched_waking histogram.  It is however
possible to create an additional new 'matching' sched_waking histogram
for the same event, meaning that it uses the same key and filters, and
define the new prio field variable on that.

Here's the sched_switch trigger::

  # 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

And here's the output of the hist_debug information for the
sched_waking hist trigger.  Note that there are two histograms
displayed in the output: the first is the normal sched_waking
histogram we've seen in the previous examples, and the second is the
special histogram we created to provide the prio field variable.

Looking at the second histogram below, we see a variable with the name
synthetic_prio.  This is the field variable created for the prio field
on that sched_waking histogram::

  # 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

Looking at the sched_switch histogram below, we can see a reference to
the synthetic_prio variable on sched_waking, and looking at the
associated hist_data address we see that it is indeed associated with
the new histogram.  Note also that the other references are to a
normal variable, wakeup_lat, and to a normal field variable, next_pid,
the details of which are in the field variables section::

  # 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

The commands below can be used to clean things up for the next test::

  # 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

Alias 테스트

이 예제는 앞선 예제와 매우 비슷하지만 alias flag가 어떻게 동작하는지 보여 준다.

먼저 `wakeup_latency` synthetic event를 만든다.

  # echo 'wakeup_latency u64 lat; pid_t pid; char comm[16]' >> synthetic_events

다음으로 앞 예제와 비슷한 `sched_waking` trigger를 만들되, 이번에는 pid를 `waking_pid` variable에 저장한다.

  # echo 'hist:keys=pid:waking_pid=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger

`sched_switch` trigger에서는 `$waking_pid`를 synthetic event 호출에 직접 쓰지 않는다. 대신 `$waking_pid`의 alias인 `$woken_pid`를 만들고 synthetic event parameter로 사용한다.

  # 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`에는 일반 field 외에 `waking_pid` variable이 보인다. `waking_pid`는 event의 `pid` field 값을 저장하는 `HIST_FIELD_FL_VAR`이고 `var.idx = 0`이다. `ts0`는 그다음 slot인 `var.idx = 1`에 있다.

  # 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` variable에는 `HIST_FIELD_FL_ALIAS`와 `HIST_FIELD_FL_VAR`가 함께 설정된다. variable이기도 하므로 일반 value field 영역에 표시된다.

구현 세부에서 alias variable은 variable reference에 더 가깝고, reference에 대한 reference로 생각할 수 있다. 구현은 참조 대상인 `waking_pid` variable reference의 `var_ref->fn()`을 alias에 복사한다. 이 함수는 `hist_field_var_ref()`이며, 사용하는 reference의 `var_ref_idx`도 함께 복사한다. 따라서 alias 값을 가져오면 원본 reference와 같은 동작을 수행해 `var_ref_vals[]`의 같은 값을 읽는다. 출력에서 `woken_pid` alias와 `waking_pid` reference의 `var_ref_idx`가 모두 `0`인 것으로 확인할 수 있다.

alias는 동시에 variable이므로 얻은 값을 자신의 `var.idx`에도 저장한다. `woken_pid` alias는 `var_ref_idx = 0`에서 읽은 값을 `var.idx = 0`에 기록한다. variable reference 영역의 별도 `woken_pid` reference는 이 alias variable의 `var.idx = 0`을 다시 읽어 자신의 `var_ref_idx = 3` slot에 저장한다. 마지막으로 그 slot의 값이 trace event 호출의 `$woken_pid` parameter에 배정된다.

  # 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

다음 세 명령은 alias 테스트의 `sched_switch` trigger, `sched_waking` trigger, `wakeup_latency` synthetic event를 제거한다.

  # 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

Alias test
----------

This example is very similar to previous examples, but demonstrates
the alias flag.

First, we create the wakeup_latency synthetic event::

  # echo 'wakeup_latency u64 lat; pid_t pid; char comm[16]' >> synthetic_events

Next, we create a sched_waking trigger similar to previous examples,
but in this case we save the pid in the waking_pid variable::

  # echo 'hist:keys=pid:waking_pid=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger

For the sched_switch trigger, instead of using $waking_pid directly in
the wakeup_latency synthetic event invocation, we create an alias of
$waking_pid named $woken_pid, and use that in the synthetic event
invocation instead::

  # 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

Looking at the sched_waking hist_debug output, in addition to the
normal fields, we can see the waking_pid variable::

  # 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

The sched_switch hist_debug output shows that a variable named
woken_pid has been created but that it also has the
HIST_FIELD_FL_ALIAS flag set.  It also has the HIST_FIELD_FL_VAR flag
set, which is why it appears in the val field section.

Despite that implementation detail, an alias variable is actually more
like a variable reference; in fact it can be thought of as a reference
to a reference.  The implementation copies the var_ref->fn() from the
variable reference being referenced, in this case, the waking_pid
fn(), which is hist_field_var_ref() and makes that the fn() of the
alias.  The hist_field_var_ref() fn() requires the var_ref_idx of the
variable reference it's using, so waking_pid's var_ref_idx is also
copied to the alias.  The end result is that when the value of alias
is retrieved, in the end it just does the same thing the original
reference would have done and retrieves the same value from the
var_ref_vals[] array.  You can verify this in the output by noting
that the var_ref_idx of the alias, in this case woken_pid, is the same
as the var_ref_idx of the reference, waking_pid, in the variable
reference fields section.

Additionally, once it gets that value, since it is also a variable, it
then saves that value into its var.idx.  So the var.idx of the
woken_pid alias is 0, which it fills with the value from var_ref_idx 0
when its fn() is called to update itself.  You'll also notice that
there's a woken_pid var_ref in the variable refs section.  That is the
reference to the woken_pid alias variable, and you can see that it
retrieves the value from the same var.idx as the woken_pid alias, 0,
and then in turn saves that value in its own var_ref_idx slot, 3, and
the value at this position is finally what gets assigned to the
$woken_pid slot in the trace event invocation::

  # 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

The commands below can be used to clean things up for the next test::

  # 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