直方圖設計說明¶
- 作者:
Tom Zanussi <zanussi@kernel.org>
本文件試圖描述 ftrace 直方圖的工作原理,以及各個部分如何對映到用於在 trace_events_hist.c 和 tracing_map.c 中實現它們的資料結構。
- 注意:所有 ftrace 直方圖命令示例都假定工作目錄是 ftrace /tracing 目錄。例如
此外,為這些命令顯示的直方圖輸出通常會被截斷 - 只顯示足夠說明問題的部分。
# cd /sys/kernel/tracing
此外,對於這些命令顯示的直方圖輸出通常會被截斷 - 只顯示足夠說明問題的內容。
‘hist_debug’ 跟蹤事件檔案¶
如果核心編譯時設定了 CONFIG_HIST_TRIGGERS_DEBUG,則每個事件的子目錄中都會出現一個名為 ‘hist_debug’ 的事件檔案。可以隨時讀取此檔案,並將顯示本文件中描述的一些 hist 觸發器內部結構。具體示例和輸出將在下面的測試用例中描述。
基本直方圖¶
首先,是基本直方圖。下面幾乎是你可以用直方圖做的最簡單的事情 - 在單個事件上建立一個具有單個鍵的直方圖,並 cat 輸出
# echo 'hist:keys=pid' >> events/sched/sched_waking/trigger
# cat events/sched/sched_waking/hist
{ pid: 18249 } hitcount: 1
{ pid: 13399 } hitcount: 1
{ pid: 17973 } hitcount: 1
{ pid: 12572 } hitcount: 1
...
{ pid: 10 } hitcount: 921
{ pid: 18255 } hitcount: 1444
{ pid: 25526 } hitcount: 2055
{ pid: 5257 } hitcount: 2055
{ pid: 27367 } hitcount: 2055
{ pid: 1728 } hitcount: 2161
Totals:
Hits: 21305
Entries: 183
Dropped: 0
這會建立一個關於 sched_waking 事件的直方圖,使用 pid 作為鍵,並帶有一個值 hitcount,即使未明確指定,每個直方圖都存在該值。
hitcount 值是一個每個桶的值,對於給定鍵的每次命中都會自動遞增,在這種情況下,鍵是 pid。
因此,在此直方圖中,每個 pid 都有一個單獨的桶,每個桶包含一個值,用於計算該 pid 呼叫 sched_waking 的次數。
每個直方圖都由一個 hist_data 結構表示。
為了跟蹤直方圖中的每個鍵和值欄位,hist_data 會儲存一個名為 fields[] 的欄位陣列。 fields[] 陣列是一個包含 struct hist_field 的陣列,它表示直方圖中的每個 val 和 key(變數也包含在此處,但稍後會討論)。因此,對於上面的直方圖,我們有一個鍵和一個值;在這種情況下,一個值是 hitcount 值,所有直方圖都有該值,無論它們是否定義該值,而上面的直方圖沒有。
每個 struct hist_field 包含一個指向事件的 trace_event_file 中的 ftrace_event_field 的指標,以及與此相關的各種位,例如大小、偏移量、型別和一個 hist_field_fn_t 函式,該函式用於從 ftrace 事件緩衝區中獲取欄位的資料(在大多數情況下 - 某些 hist_field(例如 hitcount)不直接對映到跟蹤緩衝區中的事件欄位 - 在這些情況下,函式實現從其他地方獲取其值)。 flags 欄位指示它是什麼型別的欄位 - 鍵、值、變數、變數引用等,預設值為 value。
除了 fields[] 陣列之外,另一個重要的 hist_data 資料結構是為直方圖建立的 tracing_map 例項,該例項儲存在 .map 成員中。 tracing_map 實現了用於實現直方圖的無鎖雜湊表(有關實現 tracing_map 的底層資料結構的更多討論,請參見 kernel/trace/tracing_map.h)。對於本文件,tracing_map 包含多個桶,每個桶對應於由給定直方圖鍵雜湊的特定 tracing_map_elt 物件。
下面是一個圖表,第一部分描述了上面描述的直方圖的 hist_data 和關聯的鍵和值欄位。如你所見,fields 陣列中有兩個欄位,一個用於 hitcount 的 val 欄位和一個用於 pid 鍵的 key 欄位。
下面是一個執行時快照的圖表,顯示了給定執行的 tracing_map 的可能樣子。它試圖顯示 hist_data 欄位和幾個假設的鍵和值的 tracing_map 元素之間的關係。
+------------------+
| hist_data |
+------------------+ +----------------+
| .fields[] |---->| val = hitcount |----------------------------+
+----------------+ +----------------+ |
| .map | | .size | |
+----------------+ +--------------+ |
| .offset | |
+--------------+ |
| .fn() | |
+--------------+ |
. |
. |
. |
+----------------+ <--- n_vals |
| key = pid |----------------------------|--+
+----------------+ | |
| .size | | |
+--------------+ | |
| .offset | | |
+--------------+ | |
| .fn() | | |
+----------------+ <--- n_fields | |
| unused | | |
+----------------+ | |
| | | |
+--------------+ | |
| | | |
+--------------+ | |
| | | |
+--------------+ | |
n_keys = n_fields - n_vals | |
hist_data n_vals 和 n_fields 劃定了 fields[] | | 陣列的範圍,並將鍵與程式碼其餘部分的值分開。 | |
下面是直方圖的 tracing_map 部分的執行時表示 | | ,帶有從 fields[] 陣列的各個部分指向 | | tracing_map 的相應部分的指標。 | |
tracing_map 由一組 tracing_map_entry 和一組 | | 預先分配的 tracing_map_elt(下面縮寫為 map_entry 和 | | map_elt)組成。 hist_data.map 陣列中 map_entry 的總數為 | | map->max_elts(實際上是 map->map_size,但只使用了 max_elts)。 | | 這是 map_insert() 演算法的要求)。 | |
如果 map_entry 未使用,意味著還沒有鍵被雜湊到其中,它的 | | .key 值為 0,.val 指標為 NULL。一旦 map_entry 被 | | 宣告,.key 值包含鍵的雜湊值,.val 成員指向 | | 包含完整鍵的 map_elt,以及 map_elt.fields[] 陣列中 | | 每個鍵或值的條目。 map_elt.fields[] 陣列中有一個 | | 條目對應於直方圖中的每個 hist_field,這就是 | | 儲存與每個直方圖值對應的不斷累加的總和的地方。 | |
該圖試圖顯示 | | hist_data.fields[] 和 map_elt.fields[] 之間的關係 | | ,連結在圖表之間繪製
+-----------+ | |
| hist_data | | |
+-----------+ | |
| .fields | | |
+---------+ +-----------+ | |
| .map |---->| map_entry | | |
+---------+ +-----------+ | |
| .key |---> 0 | |
+---------+ | |
| .val |---> NULL | |
+-----------+ | |
| map_entry | | |
+-----------+ | |
| .key |---> pid = 999 | |
+---------+ +-----------+ | |
| .val |--->| map_elt | | |
+---------+ +-----------+ | |
. | .key |---> full key * | |
. +---------+ +---------------+ | |
. | .fields |--->| .sum (val) |<-+ |
+-----------+ +---------+ | 2345 | | |
| map_entry | +---------------+ | |
+-----------+ | .offset (key) |<----+
| .key |---> 0 | 0 | | |
+---------+ +---------------+ | |
| .val |---> NULL . | |
+-----------+ . | |
| map_entry | . | |
+-----------+ +---------------+ | |
| .key | | .sum (val) or | | |
+---------+ +---------+ | .offset (key) | | |
| .val |--->| map_elt | +---------------+ | |
+-----------+ +---------+ | .sum (val) or | | |
| map_entry | | .offset (key) | | |
+-----------+ +---------------+ | |
| .key |---> pid = 4444 | |
+---------+ +-----------+ | |
| .val | | map_elt | | |
+---------+ +-----------+ | |
| .key |---> full key * | |
+---------+ +---------------+ | |
| .fields |--->| .sum (val) |<-+ |
+---------+ | 65523 | |
+---------------+ |
| .offset (key) |<----+
| 0 |
+---------------+
.
.
.
+---------------+
| .sum (val) or |
| .offset (key) |
+---------------+
| .sum (val) or |
| .offset (key) |
+---------------+
圖表中使用的縮寫
hist_data = struct hist_trigger_data
hist_data.fields = struct hist_field
fn = hist_field_fn_t
map_entry = struct tracing_map_entry
map_elt = struct tracing_map_elt
map_elt.fields = struct tracing_map_field
每當發生新事件且該事件具有與之關聯的 hist 觸發器時,都會呼叫 event_hist_trigger()。 event_hist_trigger() 首先處理鍵:對於鍵中的每個子鍵(在上面的示例中,只有一個子鍵對應於 pid),從 hist_data.fields[] 中檢索表示該子鍵的 hist_field,並且與該欄位關聯的 hist_field_fn_t fn() 以及該欄位的大小和偏移量用於從當前跟蹤記錄中獲取該子鍵的資料。
一旦檢索到完整的鍵,它將用於在 tracing_map 中查詢該鍵。如果不存在與該鍵關聯的 tracing_map_elt,則會宣告一個空的鍵並將其插入到對映中以用於新鍵。在任何一種情況下,都會返回與該鍵關聯的 tracing_map_elt。
一旦 tracing_map_elt 可用,就會呼叫 hist_trigger_elt_update()。顧名思義,這會更新元素,這基本上意味著更新元素的欄位。直方圖中的每個鍵和值都關聯一個 tracing_map_field,並且每個 tracing_map_field 都對應於建立直方圖時建立的鍵和值 hist_field。 hist_trigger_elt_update() 遍歷每個值 hist_field,並且與鍵一樣,使用 hist_field 的 fn() 以及大小和偏移量從當前跟蹤記錄中獲取欄位的值。一旦它獲得了該值,它只需將該值新增到該欄位不斷更新的 tracing_map_field.sum 成員中。一些 hist_field fn()(例如 hitcount)實際上沒有從跟蹤記錄中獲取任何內容(hitcount fn() 只是將計數器總和增加 1),但思路是相同的。
更新所有值後,hist_trigger_elt_update() 完成並返回。請注意,鍵中的每個子鍵也有 tracing_map_field,但 hist_trigger_elt_update() 不會檢視它們或更新任何內容 - 這些欄位僅用於排序,排序可能會在以後發生。
基本直方圖測試¶
這是一個很好的嘗試示例。它在輸出中生成 3 個值欄位和 2 個鍵欄位
# echo 'hist:keys=common_pid,call_site.sym:values=bytes_req,bytes_alloc,hitcount' >> events/kmem/kmalloc/trigger
要檢視除錯資料,請 cat kmem/kmalloc 的 ‘hist_debug’ 檔案。它將顯示與其對應的直方圖的觸發器資訊,以及與直方圖關聯的 hist_data 的地址,這在後面的示例中會變得很有用。然後,它將顯示與直方圖關聯的總 hist_field 的數量,以及其中有多少對應於鍵,有多少對應於值。
然後,它會繼續顯示每個欄位的詳細資訊,包括欄位的標誌和每個欄位在 hist_data 的 fields[] 陣列中的位置,這些資訊對於驗證內部內容是否正確非常有用,並且在以後的示例中會變得更加有用
# cat events/kmem/kmalloc/hist_debug
# event histogram
#
# trigger info: hist:keys=common_pid,call_site.sym:vals=hitcount,bytes_req,bytes_alloc:sort=hitcount:size=2048 [active]
#
hist_data: 000000005e48c9a5
n_vals: 3
n_keys: 2
n_fields: 5
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
VAL: normal u64 value
ftrace_event_field name: bytes_req
type: size_t
size: 8
is_signed: 0
hist_data->fields[2]:
flags:
VAL: normal u64 value
ftrace_event_field name: bytes_alloc
type: size_t
size: 8
is_signed: 0
key fields:
hist_data->fields[3]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: common_pid
type: int
size: 8
is_signed: 1
hist_data->fields[4]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: call_site
type: unsigned long
size: 8
is_signed: 0
可以使用以下命令來清理內容以進行下一個測試
# echo '!hist:keys=common_pid,call_site.sym:values=bytes_req,bytes_alloc,hitcount' >> events/kmem/kmalloc/trigger
變數¶
變數允許一個 hist 觸發器儲存的資料被另一個 hist 觸發器檢索。例如,sched_waking 事件上的觸發器可以捕獲特定 pid 的時間戳,稍後切換到該 pid 事件的 sched_switch 事件可以獲取時間戳並使用它來計算兩個事件之間的時間增量
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >>
events/sched/sched_waking/trigger
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0' >>
events/sched/sched_switch/trigger
就直方圖資料結構而言,變數被實現為另一種型別的 hist_field,對於給定的 hist 觸發器,它們會在所有 val 欄位之後被新增到 hist_data.fields[] 陣列中。為了將它們與現有的鍵和 val 欄位區分開來,它們被賦予了一個新的標誌型別 HIST_FIELD_FL_VAR(縮寫為 FL_VAR),並且它們還利用了 struct hist_field 中的一個新的 .var.idx 欄位成員,該成員將它們對映到新增到 map_elt 的新 map_elt.vars[] 陣列中的索引,該陣列專門用於儲存和檢索變數值。下圖顯示了這些新元素,並添加了一個新的變數條目 ts0,對應於上面 sched_waking 觸發器中的 ts0 變數。
sched_waking 直方圖 ----------------------
+------------------+
| hist_data |<-------------------------------------------------------+
+------------------+ +-------------------+ |
| .fields[] |-->| val = hitcount | |
+----------------+ +-------------------+ |
| .map | | .size | |
+----------------+ +-----------------+ |
| .offset | |
+-----------------+ |
| .fn() | |
+-----------------+ |
| .flags | |
+-----------------+ |
| .var.idx | |
+-------------------+ |
| var = ts0 | |
+-------------------+ |
| .size | |
+-----------------+ |
| .offset | |
+-----------------+ |
| .fn() | |
+-----------------+ |
| .flags & FL_VAR | |
+-----------------+ |
| .var.idx |----------------------------+-+ |
+-----------------+ | | |
. | | |
. | | |
. | | |
+-------------------+ <--- n_vals | | |
| key = pid | | | |
+-------------------+ | | |
| .size | | | |
+-----------------+ | | |
| .offset | | | |
+-----------------+ | | |
| .fn() | | | |
+-----------------+ | | |
| .flags & FL_KEY | | | |
+-----------------+ | | |
| .var.idx | | | |
+-------------------+ <--- n_fields | | |
| unused | | | |
+-------------------+ | | |
| | | | |
+-----------------+ | | |
| | | | |
+-----------------+ | | |
| | | | |
+-----------------+ | | |
| | | | |
+-----------------+ | | |
| | | | |
+-----------------+ | | |
n_keys = n_fields - n_vals | | |
| | |
這與基本情況非常相似。在上圖中,我們可以 | | | 看到一個新的 .flags 成員已新增到 struct hist_field | | | 結構中,並且已將新條目新增到 hist_data.fields 中,表示 ts0 | | | 變數。對於普通的 val hist_field,.flags 只是 0(模數 | | | 修飾符標誌),但如果該值被定義為變數,則 .flags | | | 包含一組 FL_VAR 位。 | | |
如你所見,ts0 條目的 .var.idx 成員包含變數值的 | | | tracing_map_elts 的 .vars[] 陣列的索引。 | | | 每當設定或讀取變數的值時,都會使用此 idx。 | | | 分配給給定變數的 map_elt.vars idx 在呼叫 | | | tracing_map_add_var() 後由 create_tracing_map_fields() | | | 分配和儲存在 .var.idx 中。 | | |
下面是直方圖在執行時的表示 | | | ,它會填充對映,以及與上面的 hist_data 和 | | | hist_field 資料結構的對應關係。 | | |
該圖試圖顯示 | | | hist_data.fields[] 和 map_elt.fields[] 以及 map_elt.vars[] 之間的關係 | | | ,連結在圖表之間繪製。對於每個 map_elt,你都可以 | | | 看到 .fields[] 成員指向鍵或 | | | val 的 .sum 或 .offset,而 .vars[] 成員指向變數的值。 | | | 兩個圖表之間的箭頭顯示了這些 | | | tracing_map 成員與相應的 | | | hist_data fields[] 成員中的欄位定義之間的連結。
+-----------+ | | |
| hist_data | | | |
+-----------+ | | |
| .fields | | | |
+---------+ +-----------+ | | |
| .map |---->| map_entry | | | |
+---------+ +-----------+ | | |
| .key |---> 0 | | |
+---------+ | | |
| .val |---> NULL | | |
+-----------+ | | |
| map_entry | | | |
+-----------+ | | |
| .key |---> pid = 999 | | |
+---------+ +-----------+ | | |
| .val |--->| map_elt | | | |
+---------+ +-----------+ | | |
. | .key |---> full key * | | |
. +---------+ +---------------+ | | |
. | .fields |--->| .sum (val) | | | |
. +---------+ | 2345 | | | |
. +--| .vars | +---------------+ | | |
. | +---------+ | .offset (key) | | | |
. | | 0 | | | |
. | +---------------+ | | |
. | . | | |
. | . | | |
. | . | | |
. | +---------------+ | | |
. | | .sum (val) or | | | |
. | | .offset (key) | | | |
. | +---------------+ | | |
. | | .sum (val) or | | | |
. | | .offset (key) | | | |
. | +---------------+ | | |
. | | | |
. +---------------->+---------------+ | | |
. | ts0 |<--+ | |
. | 113345679876 | | | |
. +---------------+ | | |
. | unused | | | |
. | | | | |
. +---------------+ | | |
. . | | |
. . | | |
. . | | |
. +---------------+ | | |
. | unused | | | |
. | | | | |
. +---------------+ | | |
. | unused | | | |
. | | | | |
. +---------------+ | | |
. | | |
+-----------+ | | |
| map_entry | | | |
+-----------+ | | |
| .key |---> pid = 4444 | | |
+---------+ +-----------+ | | |
| .val |--->| map_elt | | | |
+---------+ +-----------+ | | |
. | .key |---> full key * | | |
. +---------+ +---------------+ | | |
. | .fields |--->| .sum (val) | | | |
+---------+ | 2345 | | | |
+--| .vars | +---------------+ | | |
| +---------+ | .offset (key) | | | |
| | 0 | | | |
| +---------------+ | | |
| . | | |
| . | | |
| . | | |
| +---------------+ | | |
| | .sum (val) or | | | |
| | .offset (key) | | | |
| +---------------+ | | |
| | .sum (val) or | | | |
| | .offset (key) | | | |
| +---------------+ | | |
| | | |
| +---------------+ | | |
+---------------->| ts0 |<--+ | |
| 213499240729 | | |
+---------------+ | |
| unused | | |
| | | |
+---------------+ | |
. | |
. | |
. | |
+---------------+ | |
| unused | | |
| | | |
+---------------+ | |
| unused | | |
| | | |
+---------------+ | |
對於每個使用的 map 條目,都有一個指向 | | .vars 陣列的 map_elt,該陣列包含與 | | 該直方圖條目關聯的變數的當前值。因此,在上面的圖中,與 | | pid 999 關聯的時間戳為 113345679876,並且同一 | | .var.idx 中 pid 4444 的時間戳變數為 213499240729。 | |
sched_switch 直方圖 | | ---------------------- | |
下面顯示了與上面的 sched_waking 配對的 sched_switch 直方圖 | | 。 | | sched_switch 直方圖最重要的方面是 | | 它引用了上面 sched_waking 直方圖上的一個變數。 | |
直方圖圖與目前顯示的 | | 非常相似,但它添加了變數引用。你可以看到正常的 hitcount 和 | | 鍵欄位,以及以 | | 與 sched_waking ts0 變數相同的方式實現的新 wakeup_lat 變數, | | 但此外還有一個帶有新的 FL_VAR_REF(HIST_FIELD_FL_VAR_REF 的簡稱)標誌的條目。 | |
與新的 var ref 欄位關聯的是幾個新的 hist_field | | 成員,var.hist_data 和 var_ref_idx。對於變數引用, | | var.hist_data 與 var.idx 一起,唯一地標識了 | | 特定直方圖上的特定變數。 var_ref_idx | | 只是 var_ref_vals[] 陣列中的索引,該陣列在每次更新 hist 觸發器時 | | 快取每個變數的值。然後,其他程式碼(例如使用 var_ref_idx | | 值來分配引數值的跟蹤操作程式碼)最終可以訪問這些生成的值。 | |
下圖描述了之前引用的 sched_switch 的情況 | | 直方圖
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0' >> | |
events/sched/sched_switch/trigger | |
| |
+------------------+ | |
| hist_data | | |
+------------------+ +-----------------------+ | |
| .fields[] |-->| val = hitcount | | |
+----------------+ +-----------------------+ | |
| .map | | .size | | |
+----------------+ +---------------------+ | |
+--| .var_refs[] | | .offset | | |
| +----------------+ +---------------------+ | |
| | .fn() | | |
| var_ref_vals[] +---------------------+ | |
| +-------------+ | .flags | | |
| | $ts0 |<---+ +---------------------+ | |
| +-------------+ | | .var.idx | | |
| | | | +---------------------+ | |
| +-------------+ | | .var.hist_data | | |
| | | | +---------------------+ | |
| +-------------+ | | .var_ref_idx | | |
| | | | +-----------------------+ | |
| +-------------+ | | var = wakeup_lat | | |
| . | +-----------------------+ | |
| . | | .size | | |
| . | +---------------------+ | |
| +-------------+ | | .offset | | |
| | | | +---------------------+ | |
| +-------------+ | | .fn() | | |
| | | | +---------------------+ | |
| +-------------+ | | .flags & FL_VAR | | |
| | +---------------------+ | |
| | | .var.idx | | |
| | +---------------------+ | |
| | | .var.hist_data | | |
| | +---------------------+ | |
| | | .var_ref_idx | | |
| | +---------------------+ | |
| | . | |
| | . | |
| | . | |
| | +-----------------------+ <--- n_vals | |
| | | key = pid | | |
| | +-----------------------+ | |
| | | .size | | |
| | +---------------------+ | |
| | | .offset | | |
| | +---------------------+ | |
| | | .fn() | | |
| | +---------------------+ | |
| | | .flags | | |
| | +---------------------+ | |
| | | .var.idx | | |
| | +-----------------------+ <--- n_fields | |
| | | unused | | |
| | +-----------------------+ | |
| | | | | |
| | +---------------------+ | |
| | | | | |
| | +---------------------+ | |
| | | | | |
| | +---------------------+ | |
| | | | | |
| | +---------------------+ | |
| | | | | |
| | +---------------------+ | |
| | n_keys = n_fields - n_vals | |
| | | |
| | | |
| | +-----------------------+ | |
+---------------------->| var_ref = $ts0 | | |
| +-----------------------+ | |
| | .size | | |
| +---------------------+ | |
| | .offset | | |
| +---------------------+ | |
| | .fn() | | |
| +---------------------+ | |
| | .flags & FL_VAR_REF | | |
| +---------------------+ | |
| | .var.idx |--------------------------+ |
| +---------------------+ |
| | .var.hist_data |----------------------------+
| +---------------------+
+---| .var_ref_idx |
+---------------------+
圖表中使用的縮寫
hist_data = struct hist_trigger_data
hist_data.fields = struct hist_field
fn = hist_field_fn_t
FL_KEY = HIST_FIELD_FL_KEY
FL_VAR = HIST_FIELD_FL_VAR
FL_VAR_REF = HIST_FIELD_FL_VAR_REF
當 hist 觸發器使用變數時,會建立一個新的 hist_field,其標誌為 HIST_FIELD_FL_VAR_REF。對於 VAR_REF 欄位,var.idx 和 var.hist_data 採用與引用的變數相同的值,以及引用的變數的大小、型別和 is_signed 值。 VAR_REF 欄位的 .name 設定為它引用的變數的名稱。如果使用顯式的 system.event.$var_ref 表示法建立了變數引用,則 hist_field 的系統和 event_name 變數也會設定。
因此,為了處理 sched_switch 直方圖的事件,因為我們引用了另一個直方圖上的一個變數,我們需要首先解析所有變數引用。這是透過從 event_hist_trigger() 呼叫的 resolve_var_refs() 來完成的。它從表示 sched_switch 直方圖的 hist_data 中獲取 var_refs[] 陣列。對於其中的每一個,引用的變數的 var.hist_data 以及當前鍵都用於在該直方圖中查詢對應的 tracing_map_elt。找到後,引用的變數的 var.idx 用於使用 tracing_map_read_var(elt, var.idx) 查詢變數的值,在本例中為 ts0。請注意,表示變數和變數引用的 hist_field 具有相同的 var.idx,因此這很簡單。
變數和變數引用測試¶
此示例在 sched_waking 事件上建立變數 ts0,並在 sched_switch 觸發器中使用它。 sched_switch 觸發器還建立了自己的變數 wakeup_lat,但目前尚未使用它
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0' >> events/sched/sched_switch/trigger
檢視 sched_waking ‘hist_debug’ 輸出,除了正常的鍵和值 hist_field 之外,在 val 欄位部分,我們看到一個帶有 HIST_FIELD_FL_VAR 標誌的欄位,這表明該欄位表示一個變數。請注意,除了變數名稱(包含在 var.name 欄位中)之外,它還包括 var.idx,它是 tracing_map_elt.vars[] 陣列的實際變數位置的索引。另請注意,輸出顯示變數與普通值位於 hist_data->fields[] 陣列的同一部分
# cat events/sched/sched_waking/hist_debug
# event histogram
#
# trigger info: hist:keys=pid:vals=hitcount:ts0=common_timestamp.usecs:sort=hitcount:size=2048:clock=global [active]
#
hist_data: 000000009536f554
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: ts0
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 8
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: pid
type: pid_t
size: 8
is_signed: 1
轉到 sched_switch 觸發器 hist_debug 輸出,除了未使用的 wakeup_lat 變數之外,我們看到一個顯示變數引用的新部分。變數引用顯示在單獨的部分中,因為除了在邏輯上與變數和值分開之外,它們實際上位於一個單獨的 hist_data 陣列 var_refs[] 中。
在此示例中,sched_switch 觸發器引用 sched_waking 觸發器上的變數 $ts0。檢視詳細資訊,我們可以看到引用的變數的 var.hist_data 值與先前顯示的 sched_waking 觸發器匹配,並且 var.idx 值與先前顯示的該變數的 var.idx 值匹配。還顯示了該變數引用的 var_ref_idx 值,這是在呼叫觸發器時快取該變數的值以供使用的地方
# cat events/sched/sched_switch/hist_debug
# event histogram
#
# trigger info: hist:keys=next_pid:vals=hitcount:wakeup_lat=common_timestamp.usecs-$ts0:sort=hitcount:size=2048:clock=global [active]
#
hist_data: 00000000f4ee8006
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 0
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: next_pid
type: pid_t
size: 8
is_signed: 1
variable reference fields:
hist_data->var_refs[0]:
flags:
HIST_FIELD_FL_VAR_REF
name: ts0
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 000000009536f554
var_ref_idx (into hist_data->var_refs[]): 0
type: u64
size: 8
is_signed: 0
可以使用以下命令來清理內容以進行下一個測試
# echo '!hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0' >> events/sched/sched_switch/trigger
# echo '!hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
操作和處理程式¶
在上一個示例的基礎上,我們現在將對 wakeup_lat 變數執行某些操作,即將它和另一個欄位作為合成事件傳送。
下面的 onmatch() 操作基本上表示,每當我們有 sched_switch 事件時,如果我們有匹配的 sched_waking 事件,在這種情況下,如果我們在 sched_waking 直方圖中有一個 pid 與此 sched_switch 事件上的 next_pid 欄位匹配,我們會檢索 wakeup_latency() 跟蹤操作中指定的變數,並使用它們在跟蹤流中生成一個新的 wakeup_latency 事件。
請注意,諸如 wakeup_latency() 之類的跟蹤處理程式(可以等效地寫為 trace(wakeup_latency,$wakeup_lat,next_pid))的實現方式要求指定給跟蹤處理程式的引數必須是變數。在這種情況下,$wakeup_lat 顯然是一個變數,但 next_pid 不是,因為它只是命名 sched_switch 跟蹤事件中的一個欄位。由於幾乎每個 trace() 和 save() 操作都會執行此操作,因此實現了一個特殊的快捷方式,允許直接在這些情況下使用欄位名稱。它的工作方式是在底層,為命名的欄位建立一個臨時變數,而這個變數實際上被傳遞給跟蹤處理程式。在程式碼和文件中,這種型別的變數稱為“欄位變數”。
也可以使用其他跟蹤事件直方圖上的欄位。在這種情況下,我們必須生成一個新的直方圖和一個不幸命名的“synthetic_field”(這裡的 synthetic 與合成事件無關),並將該特殊直方圖欄位用作變數。
下圖說明了上面在 sched_switch 直方圖中使用 onmatch() 處理程式和 trace() 操作描述的新元素。
首先,我們定義 wakeup_latency 合成事件
# echo 'wakeup_latency u64 lat; pid_t pid' >> synthetic_events
接下來,像以前一樣設定 sched_waking hist 觸發器
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >>
events/sched/sched_waking/trigger
最後,我們在 sched_switch 事件上建立一個 hist 觸發器,該觸發器生成 wakeup_latency() 跟蹤事件。在這種情況下,我們將 next_pid 傳遞到 wakeup_latency 合成事件呼叫中,這意味著它將自動轉換為欄位變數
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \
onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid)' >>
/sys/kernel/tracing/events/sched/sched_switch/trigger
sched_switch 事件的圖表與以前的示例類似,但顯示了 hist_data 的附加 field_vars[] 陣列,並顯示了 field_vars 和為實現欄位變數而建立的變數和引用之間的連結。詳細資訊將在下面討論
+------------------+
| hist_data |
+------------------+ +-----------------------+
| .fields[] |-->| val = hitcount |
+----------------+ +-----------------------+
| .map | | .size |
+----------------+ +---------------------+
+---| .field_vars[] | | .offset |
| +----------------+ +---------------------+
|+--| .var_refs[] | | .offset |
|| +----------------+ +---------------------+
|| | .fn() |
|| var_ref_vals[] +---------------------+
|| +-------------+ | .flags |
|| | $ts0 |<---+ +---------------------+
|| +-------------+ | | .var.idx |
|| | $next_pid |<-+ | +---------------------+
|| +-------------+ | | | .var.hist_data |
||+>| $wakeup_lat | | | +---------------------+
||| +-------------+ | | | .var_ref_idx |
||| | | | | +-----------------------+
||| +-------------+ | | | var = wakeup_lat |
||| . | | +-----------------------+
||| . | | | .size |
||| . | | +---------------------+
||| +-------------+ | | | .offset |
||| | | | | +---------------------+
||| +-------------+ | | | .fn() |
||| | | | | +---------------------+
||| +-------------+ | | | .flags & FL_VAR |
||| | | +---------------------+
||| | | | .var.idx |
||| | | +---------------------+
||| | | | .var.hist_data |
||| | | +---------------------+
||| | | | .var_ref_idx |
||| | | +---------------------+
||| | | .
||| | | .
||| | | .
||| | | .
||| +--------------+ | | .
+-->| field_var | | | .
|| +--------------+ | | .
|| | var | | | .
|| +------------+ | | .
|| | val | | | .
|| +--------------+ | | .
|| | field_var | | | .
|| +--------------+ | | .
|| | var | | | .
|| +------------+ | | .
|| | val | | | .
|| +------------+ | | .
|| . | | .
|| . | | .
|| . | | +-----------------------+ <--- n_vals
|| +--------------+ | | | key = pid |
|| | field_var | | | +-----------------------+
|| +--------------+ | | | .size |
|| | var |--+| +---------------------+
|| +------------+ ||| | .offset |
|| | val |-+|| +---------------------+
|| +------------+ ||| | .fn() |
|| ||| +---------------------+
|| ||| | .flags |
|| ||| +---------------------+
|| ||| | .var.idx |
|| ||| +---------------------+ <--- n_fields
|| |||
|| ||| n_keys = n_fields - n_vals
|| ||| +-----------------------+
|| |+->| var = next_pid |
|| | | +-----------------------+
|| | | | .size |
|| | | +---------------------+
|| | | | .offset |
|| | | +---------------------+
|| | | | .flags & FL_VAR |
|| | | +---------------------+
|| | | | .var.idx |
|| | | +---------------------+
|| | | | .var.hist_data |
|| | | +-----------------------+
|| +-->| val for next_pid |
|| | | +-----------------------+
|| | | | .size |
|| | | +---------------------+
|| | | | .offset |
|| | | +---------------------+
|| | | | .fn() |
|| | | +---------------------+
|| | | | .flags |
|| | | +---------------------+
|| | | | |
|| | | +---------------------+
|| | |
|| | |
|| | | +-----------------------+
+|------------------|-|>| var_ref = $ts0 |
| | | +-----------------------+
| | | | .size |
| | | +---------------------+
| | | | .offset |
| | | +---------------------+
| | | | .fn() |
| | | +---------------------+
| | | | .flags & FL_VAR_REF |
| | | +---------------------+
| | +---| .var_ref_idx |
| | +-----------------------+
| | | var_ref = $next_pid |
| | +-----------------------+
| | | .size |
| | +---------------------+
| | | .offset |
| | +---------------------+
| | | .fn() |
| | +---------------------+
| | | .flags & FL_VAR_REF |
| | +---------------------+
| +-----| .var_ref_idx |
| +-----------------------+
| | var_ref = $wakeup_lat |
| +-----------------------+
| | .size |
| +---------------------+
| | .offset |
| +---------------------+
| | .fn() |
| +---------------------+
| | .flags & FL_VAR_REF |
| +---------------------+
+------------------------| .var_ref_idx |
+---------------------+
如你所見,對於欄位變數,會建立兩個 hist_field:一個表示變數(在本例中為 next_pid),另一個實際上是從跟蹤流中獲取欄位的值,就像普通的 val 欄位一樣。這些欄位與普通變數建立分開建立,並儲存在 hist_data->field_vars[] 陣列中。有關如何使用這些欄位,請參見下文。此外,還建立了一個引用 hist_field,這對於引用欄位變數(例如 trace() 操作中的 $next_pid 變數)是必需的。
請注意,$wakeup_lat 也是一個變數引用,引用表示式 common_timestamp-$ts0 的值,因此也需要建立一個 hist 欄位條目來表示該引用。
當呼叫 hist_trigger_elt_update() 來獲取正常的鍵和值欄位時,它還會呼叫 update_field_vars(),該函式會遍歷為直方圖建立的每個 field_var(從 hist_data->field_vars 中獲取),並呼叫 val->fn() 從當前跟蹤記錄中獲取資料,然後使用 var 的 var.idx 在 elt->vars[var.idx] 中相應 tracing_map_elt 的變數中設定 var.idx 偏移量處的變數。
更新所有變數後,可以從 event_hist_trigger() 呼叫 resolve_var_refs(),並且不僅可以解析我們的 $ts0 和 $next_pid 引用,還可以解析 $wakeup_lat 引用。此時,trace() 操作可以簡單地訪問在 var_ref_vals[] 陣列中組裝的值並生成跟蹤事件。
save() 操作關聯的欄位變數也會發生相同的過程。
圖表中使用的縮寫
hist_data = struct hist_trigger_data
hist_data.fields = struct hist_field
field_var = struct field_var
fn = hist_field_fn_t
FL_KEY = HIST_FIELD_FL_KEY
FL_VAR = HIST_FIELD_FL_VAR
FL_VAR_REF = HIST_FIELD_FL_VAR_REF
trace() 操作欄位變數測試¶
此示例透過最終使用 wakeup_lat 變數新增到之前的測試示例,但此外還建立了幾個欄位變數,然後透過 onmatch() 處理程式將它們全部傳遞給 wakeup_latency() 跟蹤操作。
首先,我們建立 wakeup_latency 合成事件
# echo 'wakeup_latency u64 lat; pid_t pid; char comm[16]' >> synthetic_events
接下來,是來自先前示例的 sched_waking 觸發器
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
最後,與之前的測試示例一樣,我們使用來自 sched_waking 觸發器的 $ts0 引用計算和分配喚醒延遲給 wakeup_lat 變數,並最終使用它以及幾個 sched_switch 事件欄位 next_pid 和 next_comm 來生成 wakeup_latency 跟蹤事件。 next_pid 和 next_comm 事件欄位會自動轉換為用於此目的的欄位變數
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,next_comm)' >> /sys/kernel/tracing/events/sched/sched_switch/trigger
sched_waking hist_debug 輸出顯示與之前測試示例中相同的資料
# cat events/sched/sched_waking/hist_debug
# event histogram
#
# trigger info: hist:keys=pid:vals=hitcount:ts0=common_timestamp.usecs:sort=hitcount:size=2048:clock=global [active]
#
hist_data: 00000000d60ff61f
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: ts0
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 8
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: pid
type: pid_t
size: 8
is_signed: 1
sched_switch hist_debug 輸出顯示與之前測試示例中相同的鍵和值欄位 - 請注意,wakeup_lat 仍然位於 val 欄位部分,但新的欄位變數不在那裡 - 儘管欄位變數是變數,但它們單獨儲存在 hist_data 的 field_vars[] 陣列中。儘管欄位變數和普通變數位於不同的位置,但你可以看到 tracing_map_elt.vars[] 中這些變數的實際變數位置確實具有如預期的那樣增加的索引:wakeup_lat 佔用 var.idx = 0 插槽,而 next_pid 和 next_comm 的欄位變數的值為 var.idx = 1 和 var.idx = 2。另請注意,這些值與變數引用欄位部分中與這些變數對應的變數引用顯示的值相同。由於有兩個觸發器,因此也有兩個 hist_data 地址,因此在進行匹配時也需要考慮這些地址 - 你可以看到第一個變數引用了上一個 hist 觸發器上的 0 var.idx(請參閱與該觸發器關聯的 hist_data 地址),而第二個變數引用了 sched_switch hist 觸發器上的 0 var.idx,其餘的變數引用也是如此。
最後,操作跟蹤變數部分僅顯示 onmatch() 處理程式的系統和事件名稱
# cat events/sched/sched_switch/hist_debug
# event histogram
#
# trigger info: hist:keys=next_pid:vals=hitcount:wakeup_lat=common_timestamp.usecs-$ts0:sort=hitcount:size=2048:clock=global:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,next_comm) [active]
#
hist_data: 0000000008f551b7
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 0
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: next_pid
type: pid_t
size: 8
is_signed: 1
variable reference fields:
hist_data->var_refs[0]:
flags:
HIST_FIELD_FL_VAR_REF
name: ts0
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 00000000d60ff61f
var_ref_idx (into hist_data->var_refs[]): 0
type: u64
size: 8
is_signed: 0
hist_data->var_refs[1]:
flags:
HIST_FIELD_FL_VAR_REF
name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 0000000008f551b7
var_ref_idx (into hist_data->var_refs[]): 1
type: u64
size: 0
is_signed: 0
hist_data->var_refs[2]:
flags:
HIST_FIELD_FL_VAR_REF
name: next_pid
var.idx (into tracing_map_elt.vars[]): 1
var.hist_data: 0000000008f551b7
var_ref_idx (into hist_data->var_refs[]): 2
type: pid_t
size: 4
is_signed: 0
hist_data->var_refs[3]:
flags:
HIST_FIELD_FL_VAR_REF
name: next_comm
var.idx (into tracing_map_elt.vars[]): 2
var.hist_data: 0000000008f551b7
var_ref_idx (into hist_data->var_refs[]): 3
type: char[16]
size: 256
is_signed: 0
field variables:
hist_data->field_vars[0]:
field_vars[0].var:
flags:
HIST_FIELD_FL_VAR
var.name: next_pid
var.idx (into tracing_map_elt.vars[]): 1
field_vars[0].val:
ftrace_event_field name: next_pid
type: pid_t
size: 4
is_signed: 1
hist_data->field_vars[1]:
field_vars[1].var:
flags:
HIST_FIELD_FL_VAR
var.name: next_comm
var.idx (into tracing_map_elt.vars[]): 2
field_vars[1].val:
ftrace_event_field name: next_comm
type: char[16]
size: 256
is_signed: 0
action tracking variables (for onmax()/onchange()/onmatch()):
hist_data->actions[0].match_data.event_system: sched
hist_data->actions[0].match_data.event: sched_waking
可以使用以下命令來清理內容以進行下一個測試
# echo '!hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,next_comm)' >> /sys/kernel/tracing/events/sched/sched_switch/trigger
# echo '!hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
# echo '!wakeup_latency u64 lat; pid_t pid; char comm[16]' >> synthetic_events
action_data 和 trace() 操作¶
如上所述,當 trace() 操作生成合成事件時,合成事件的所有引數要麼已經是變數,要麼轉換為變數(透過欄位變數),最後所有這些變數值都透過對它們的引用收集到 var_ref_vals[] 陣列中。
但是,var_ref_vals[] 陣列中的值不一定遵循與合成事件引數相同的順序。為了解決這個問題,struct action_data 包含另一個數組 var_ref_idx[],該陣列將跟蹤操作引數對映到 var_ref_vals[] 值。下圖說明了 wakeup_latency() 合成事件的情況
+------------------+ wakeup_latency()
| action_data | event params var_ref_vals[]
+------------------+ +-----------------+ +-----------------+
| .var_ref_idx[] |--->| $wakeup_lat idx |---+ | |
+----------------+ +-----------------+ | +-----------------+
| .synth_event | | $next_pid idx |---|-+ | $wakeup_lat val |
+----------------+ +-----------------+ | | +-----------------+
. | +->| $next_pid val |
. | +-----------------+
. | .
+-----------------+ | .
| | | .
+-----------------+ | +-----------------+
+--->| $wakeup_lat val |
+-----------------+
基本上,這最終如何在合成事件探針函式 trace_event_raw_event_synth() 中使用如下
for each field i in .synth_event
val_idx = .var_ref_idx[i]
val = var_ref_vals[val_idx]
action_data 和 onXXX() 處理程式¶
除了 onmatch() 之外,hist 觸發器 onXXX() 操作(例如 onmax() 和 onchange())也使用並內部建立隱藏變數。此資訊包含在 action_data.track_data 結構中,並且在 hist_debug 輸出中也是可見的,如下面的示例中所述。
通常,onmax() 或 onchange() 處理程式與 save() 和 snapshot() 操作結合使用。例如
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \
onmax($wakeup_lat).save(next_comm,prev_pid,prev_prio,prev_comm)' >>
/sys/kernel/tracing/events/sched/sched_switch/trigger
或
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \
onmax($wakeup_lat).snapshot()' >>
/sys/kernel/tracing/events/sched/sched_switch/trigger
save() 操作欄位變數測試¶
對於此示例,未使用生成合成事件,而是使用 save() 操作在 onmax() 處理程式檢測到已達到新的最大延遲時儲存欄位值。與上一個示例一樣,儲存的值也是欄位值,但在這種情況下,它們儲存在名為 save_vars[] 的單獨 hist_data 陣列中。
與之前的測試示例一樣,我們設定 sched_waking 觸發器
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
但是,在這種情況下,我們設定 sched_switch 觸發器以在我們達到新的最大延遲時儲存一些 sched_switch 欄位值。對於 onmax() 處理程式和 save() 操作,都會建立變數,我們可以使用 hist_debug 檔案來檢查這些變數
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmax($wakeup_lat).save(next_comm,prev_pid,prev_prio,prev_comm)' >> events/sched/sched_switch/trigger
sched_waking hist_debug 輸出顯示與先前測試示例中相同的資料
# cat events/sched/sched_waking/hist_debug
#
# trigger info: hist:keys=pid:vals=hitcount:ts0=common_timestamp.usecs:sort=hitcount:size=2048:clock=global [active]
#
hist_data: 00000000e6290f48
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: ts0
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 8
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: pid
type: pid_t
size: 8
is_signed: 1
sched_switch 觸發器的輸出顯示與之前相同的 val 和 key 值,但也顯示了幾個新部分。
首先,操作跟蹤變數部分現在顯示 actions[].track_data 資訊,描述用於跟蹤(在本例中為執行最大值)的特殊跟蹤變數和引用。 actions[].track_data.var_ref 成員包含對正在跟蹤的變數的引用,在本例中為 $wakeup_lat 變數。為了執行 onmax() 處理程式函式,還需要一個變數來跟蹤當前最大值,該變數會在每次達到新的最大值時更新。在這種情況下,我們可以看到已建立一個自動生成的變數,名為 ‘ __max’,並且在 actions[].track_data.track_var 變數中可見。
最後,在新的 ‘save 操作變數’ 部分中,我們可以看到 save() 函式的 4 個引數已導致建立了 4 個欄位變數,用於在達到最大值時儲存命名欄位的值。這些變數儲存在 hist_data 上的單獨 save_vars[] 陣列中,因此顯示在單獨的部分中
# cat events/sched/sched_switch/hist_debug
# event histogram
#
# trigger info: hist:keys=next_pid:vals=hitcount:wakeup_lat=common_timestamp.usecs-$ts0:sort=hitcount:size=2048:clock=global:onmax($wakeup_lat).save(next_comm,prev_pid,prev_prio,prev_comm) [active]
#
hist_data: 0000000057bcd28d
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 0
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: next_pid
type: pid_t
size: 8
is_signed: 1
variable reference fields:
hist_data->var_refs[0]:
flags:
HIST_FIELD_FL_VAR_REF
name: ts0
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 00000000e6290f48
var_ref_idx (into hist_data->var_refs[]): 0
type: u64
size: 8
is_signed: 0
hist_data->var_refs[1]:
flags:
HIST_FIELD_FL_VAR_REF
name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 0000000057bcd28d
var_ref_idx (into hist_data->var_refs[]): 1
type: u64
size: 0
is_signed: 0
action tracking variables (for onmax()/onchange()/onmatch()):
hist_data->actions[0].track_data.var_ref:
flags:
HIST_FIELD_FL_VAR_REF
name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 0000000057bcd28d
var_ref_idx (into hist_data->var_refs[]): 1
type: u64
size: 0
is_signed: 0
hist_data->actions[0].track_data.track_var:
flags:
HIST_FIELD_FL_VAR
var.name: __max
var.idx (into tracing_map_elt.vars[]): 1
type: u64
size: 8
is_signed: 0
save action variables (save() params):
hist_data->save_vars[0]:
save_vars[0].var:
flags:
HIST_FIELD_FL_VAR
var.name: next_comm
var.idx (into tracing_map_elt.vars[]): 2
save_vars[0].val:
ftrace_event_field name: next_comm
type: char[16]
size: 256
is_signed: 0
hist_data->save_vars[1]:
save_vars[1].var:
flags:
HIST_FIELD_FL_VAR
var.name: prev_pid
var.idx (into tracing_map_elt.vars[]): 3
save_vars[1].val:
ftrace_event_field name: prev_pid
type: pid_t
size: 4
is_signed: 1
hist_data->save_vars[2]:
save_vars[2].var:
flags:
HIST_FIELD_FL_VAR
var.name: prev_prio
var.idx (into tracing_map_elt.vars[]): 4
save_vars[2].val:
ftrace_event_field name: prev_prio
type: int
size: 4
is_signed: 1
hist_data->save_vars[3]:
save_vars[3].var:
flags:
HIST_FIELD_FL_VAR
var.name: prev_comm
var.idx (into tracing_map_elt.vars[]): 5
save_vars[3].val:
ftrace_event_field name: prev_comm
type: char[16]
size: 256
is_signed: 0
可以使用以下命令來清理內容以進行下一個測試
# echo '!hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmax($wakeup_lat).save(next_comm,prev_pid,prev_prio,prev_comm)' >> events/sched/sched_switch/trigger
# echo '!hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
幾個特殊情況¶
雖然以上內容涵蓋了直方圖內部的基本知識,但應討論幾個特殊情況,因為它們往往會造成更多混淆。這些情況是其他直方圖上的欄位變數和別名,下面將透過使用 hist_debug 檔案的示例測試來描述這兩種情況。
其他直方圖上的欄位變數測試¶
此示例與之前的示例類似,但在這種情況下,sched_switch 觸發器引用另一個事件(即 sched_waking 事件)上的 hist 觸發器欄位。為了完成此操作,會為另一個事件建立一個欄位變數,但由於無法使用現有直方圖(因為現有直方圖是不可變的),因此會建立一個帶有匹配變數的新直方圖並使用它,我們將在下面顯示的 hist_debug 輸出中看到這一點。
首先,我們建立 wakeup_latency 合成事件。請注意添加了 prio 欄位
# echo 'wakeup_latency u64 lat; pid_t pid; int prio' >> synthetic_events
與之前的測試示例一樣,我們設定 sched_waking 觸發器
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
在這裡,我們設定 sched_switch 上的 hist 觸發器以使用命名 sched_waking 事件的 onmatch 處理程式傳送 wakeup_latency 事件。請注意,傳遞給 wakeup_latency() 的第三個引數是 prio,這是一個需要為其建立欄位變數的欄位名稱。但是,sched_switch 事件上沒有任何 prio 欄位,因此似乎無法為其建立欄位變數。匹配的 sched_waking 事件確實有一個 prio 欄位,因此應該可以使用它來達到此目的。問題在於當前無法在現有直方圖上定義新變數,因此無法將新的 prio 欄位變數新增到現有的 sched_waking 直方圖。但是,可以為同一事件建立一個額外的新的“匹配”sched_waking 直方圖,這意味著它使用相同的鍵和過濾器,並在該直方圖上定義新的 prio 欄位變數。
這是 sched_switch 觸發器
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,prio)' >> events/sched/sched_switch/trigger
這是 sched_waking hist 觸發器的 hist_debug 資訊的輸出。請注意,輸出中顯示了兩個直方圖:第一個是我們在之前的示例中看到的正常 sched_waking 直方圖,第二個是我們建立的特殊直方圖,用於提供 prio 欄位變數。
檢視下面的第二個直方圖,我們看到一個名為 synthetic_prio 的變數。這是為該 sched_waking 直方圖上的 prio 欄位建立的欄位變數
# cat events/sched/sched_waking/hist_debug
# event histogram
#
# trigger info: hist:keys=pid:vals=hitcount:ts0=common_timestamp.usecs:sort=hitcount:size=2048:clock=global [active]
#
hist_data: 00000000349570e4
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: ts0
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 8
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: pid
type: pid_t
size: 8
is_signed: 1
# event histogram
#
# trigger info: hist:keys=pid:vals=hitcount:synthetic_prio=prio:sort=hitcount:size=2048 [active]
#
hist_data: 000000006920cf38
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
ftrace_event_field name: prio
var.name: synthetic_prio
var.idx (into tracing_map_elt.vars[]): 0
type: int
size: 4
is_signed: 1
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: pid
type: pid_t
size: 8
is_signed: 1
檢視下面的 sched_switch 直方圖,我們可以看到對 sched_waking 上的 synthetic_prio 變數的引用,並檢視關聯的 hist_data 地址,我們看到它確實與新的直方圖關聯。另請注意,其他引用是對正常變數 wakeup_lat 和對正常欄位變數 next_pid 的引用,它們的詳細資訊在欄位變數部分中
# cat events/sched/sched_switch/hist_debug
# event histogram
#
# trigger info: hist:keys=next_pid:vals=hitcount:wakeup_lat=common_timestamp.usecs-$ts0:sort=hitcount:size=2048:clock=global:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,prio) [active]
#
hist_data: 00000000a73b67df
n_vals: 2
n_keys: 1
n_fields: 3
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
var.name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
type: u64
size: 0
is_signed: 0
key fields:
hist_data->fields[2]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: next_pid
type: pid_t
size: 8
is_signed: 1
variable reference fields:
hist_data->var_refs[0]:
flags:
HIST_FIELD_FL_VAR_REF
name: ts0
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 00000000349570e4
var_ref_idx (into hist_data->var_refs[]): 0
type: u64
size: 8
is_signed: 0
hist_data->var_refs[1]:
flags:
HIST_FIELD_FL_VAR_REF
name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 00000000a73b67df
var_ref_idx (into hist_data->var_refs[]): 1
type: u64
size: 0
is_signed: 0
hist_data->var_refs[2]:
flags:
HIST_FIELD_FL_VAR_REF
name: next_pid
var.idx (into tracing_map_elt.vars[]): 1
var.hist_data: 00000000a73b67df
var_ref_idx (into hist_data->var_refs[]): 2
type: pid_t
size: 4
is_signed: 0
hist_data->var_refs[3]:
flags:
HIST_FIELD_FL_VAR_REF
name: synthetic_prio
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 000000006920cf38
var_ref_idx (into hist_data->var_refs[]): 3
type: int
size: 4
is_signed: 1
field variables:
hist_data->field_vars[0]:
field_vars[0].var:
flags:
HIST_FIELD_FL_VAR
var.name: next_pid
var.idx (into tracing_map_elt.vars[]): 1
field_vars[0].val:
ftrace_event_field name: next_pid
type: pid_t
size: 4
is_signed: 1
action tracking variables (for onmax()/onchange()/onmatch()):
hist_data->actions[0].match_data.event_system: sched
hist_data->actions[0].match_data.event: sched_waking
可以使用以下命令來清理內容以進行下一個測試
# echo '!hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,prio)' >> events/sched/sched_switch/trigger
# echo '!hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
# echo '!wakeup_latency u64 lat; pid_t pid; int prio' >> synthetic_events
別名測試¶
此示例與之前的示例非常相似,但演示了別名標誌。
首先,我們建立 wakeup_latency 合成事件
# echo 'wakeup_latency u64 lat; pid_t pid; char comm[16]' >> synthetic_events
接下來,我們建立一個類似於之前示例的 sched_waking 觸發器,但在這種情況下,我們將 pid 儲存在 waking_pid 變數中
# echo 'hist:keys=pid:waking_pid=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
對於 sched_switch 觸發器,我們沒有直接在 wakeup_latency 合成事件呼叫中使用 $waking_pid,而是建立 $waking_pid 的別名,名為 $woken_pid,並在合成事件呼叫中使用它
# echo 'hist:keys=next_pid:woken_pid=$waking_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,$woken_pid,next_comm)' >> events/sched/sched_switch/trigger
檢視 sched_waking 的 hist_debug 輸出,除了正常的欄位外,我們還可以看到 waking_pid 變數。
# cat events/sched/sched_waking/hist_debug
# event histogram
#
# trigger info: hist:keys=pid:vals=hitcount:waking_pid=pid,ts0=common_timestamp.usecs:sort=hitcount:size=2048:clock=global [active]
#
hist_data: 00000000a250528c
n_vals: 3
n_keys: 1
n_fields: 4
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
ftrace_event_field name: pid
var.name: waking_pid
var.idx (into tracing_map_elt.vars[]): 0
type: pid_t
size: 4
is_signed: 1
hist_data->fields[2]:
flags:
HIST_FIELD_FL_VAR
var.name: ts0
var.idx (into tracing_map_elt.vars[]): 1
type: u64
size: 8
is_signed: 0
key fields:
hist_data->fields[3]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: pid
type: pid_t
size: 8
is_signed: 1
sched_switch 的 hist_debug 輸出顯示已建立一個名為 woken_pid 的變數,但它也設定了 HIST_FIELD_FL_ALIAS 標誌。 它還設定了 HIST_FIELD_FL_VAR 標誌,這就是它出現在 val 欄位部分的原因。
儘管有這個實現細節,別名變數實際上更像一個變數引用; 實際上,可以將其視為對引用的引用。 該實現從被引用的變數引用中複製 var_ref->fn(),在本例中為 waking_pid 的 fn(),即 hist_field_var_ref(),並將其作為別名的 fn()。 hist_field_var_ref() fn() 需要它使用的變數引用的 var_ref_idx,因此 waking_pid 的 var_ref_idx 也被複制到別名。 最終結果是,當檢索別名的值時,最終它只是執行與原始引用相同的操作,並從 var_ref_vals[] 陣列中檢索相同的值。 您可以在輸出中驗證這一點,注意別名的 var_ref_idx(在本例中為 woken_pid)與引用的 var_ref_idx(waking_pid)在變數引用欄位部分中的 var_ref_idx 相同。
此外,一旦它獲得該值,由於它也是一個變數,它會將該值儲存到它的 var.idx 中。 因此,woken_pid 別名的 var.idx 為 0,當呼叫其 fn() 以更新自身時,它會用來自 var_ref_idx 0 的值填充它。 您還會注意到變數引用部分中有一個 woken_pid var_ref。 這是對 woken_pid 別名變數的引用,您可以看到它從與 woken_pid 別名相同的 var.idx(0)中檢索該值,然後依次將其值儲存在它自己的 var_ref_idx 插槽中(3),而此位置的值最終被分配給跟蹤事件呼叫中的 $woken_pid 插槽。
# cat events/sched/sched_switch/hist_debug
# event histogram
#
# trigger info: hist:keys=next_pid:vals=hitcount:woken_pid=$waking_pid,wakeup_lat=common_timestamp.usecs-$ts0:sort=hitcount:size=2048:clock=global:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,$woken_pid,next_comm) [active]
#
hist_data: 0000000055d65ed0
n_vals: 3
n_keys: 1
n_fields: 4
val fields:
hist_data->fields[0]:
flags:
VAL: HIST_FIELD_FL_HITCOUNT
type: u64
size: 8
is_signed: 0
hist_data->fields[1]:
flags:
HIST_FIELD_FL_VAR
HIST_FIELD_FL_ALIAS
var.name: woken_pid
var.idx (into tracing_map_elt.vars[]): 0
var_ref_idx (into hist_data->var_refs[]): 0
type: pid_t
size: 4
is_signed: 1
hist_data->fields[2]:
flags:
HIST_FIELD_FL_VAR
var.name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 1
type: u64
size: 0
is_signed: 0
key fields:
hist_data->fields[3]:
flags:
HIST_FIELD_FL_KEY
ftrace_event_field name: next_pid
type: pid_t
size: 8
is_signed: 1
variable reference fields:
hist_data->var_refs[0]:
flags:
HIST_FIELD_FL_VAR_REF
name: waking_pid
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 00000000a250528c
var_ref_idx (into hist_data->var_refs[]): 0
type: pid_t
size: 4
is_signed: 1
hist_data->var_refs[1]:
flags:
HIST_FIELD_FL_VAR_REF
name: ts0
var.idx (into tracing_map_elt.vars[]): 1
var.hist_data: 00000000a250528c
var_ref_idx (into hist_data->var_refs[]): 1
type: u64
size: 8
is_signed: 0
hist_data->var_refs[2]:
flags:
HIST_FIELD_FL_VAR_REF
name: wakeup_lat
var.idx (into tracing_map_elt.vars[]): 1
var.hist_data: 0000000055d65ed0
var_ref_idx (into hist_data->var_refs[]): 2
type: u64
size: 0
is_signed: 0
hist_data->var_refs[3]:
flags:
HIST_FIELD_FL_VAR_REF
name: woken_pid
var.idx (into tracing_map_elt.vars[]): 0
var.hist_data: 0000000055d65ed0
var_ref_idx (into hist_data->var_refs[]): 3
type: pid_t
size: 4
is_signed: 1
hist_data->var_refs[4]:
flags:
HIST_FIELD_FL_VAR_REF
name: next_comm
var.idx (into tracing_map_elt.vars[]): 2
var.hist_data: 0000000055d65ed0
var_ref_idx (into hist_data->var_refs[]): 4
type: char[16]
size: 256
is_signed: 0
field variables:
hist_data->field_vars[0]:
field_vars[0].var:
flags:
HIST_FIELD_FL_VAR
var.name: next_comm
var.idx (into tracing_map_elt.vars[]): 2
field_vars[0].val:
ftrace_event_field name: next_comm
type: char[16]
size: 256
is_signed: 0
action tracking variables (for onmax()/onchange()/onmatch()):
hist_data->actions[0].match_data.event_system: sched
hist_data->actions[0].match_data.event: sched_waking
可以使用以下命令來清理內容以進行下一個測試
# echo '!hist:keys=next_pid:woken_pid=$waking_pid:wakeup_lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,$woken_pid,next_comm)' >> events/sched/sched_switch/trigger
# echo '!hist:keys=pid:ts0=common_timestamp.usecs' >> events/sched/sched_waking/trigger
# echo '!wakeup_latency u64 lat; pid_t pid; char comm[16]' >> synthetic_events