Lines Matching refs:hist
24 The format of a hist trigger is as follows::
26 hist:keys=<field1[,field2,...]>[:values=<field1[,field2,...]>]
50 key. If a hist trigger is given a name using the 'name' parameter,
60 'hist' triggers add a 'hist' file to each event's subdirectory.
61 Reading the 'hist' file for the event will dump the hash table in
62 its entirety to stdout. If there are multiple hist triggers
99 A typical usage scenario would be the following to enable a hist
102 # echo 'hist:keys=skbaddr.hex:vals=len' > \
105 # cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
107 # echo '!hist:keys=skbaddr.hex:vals=len' > \
111 currently attached hist trigger. This information is also displayed
112 at the top of the 'hist' file when read.
127 The 'pause' parameter can be used to pause an existing hist trigger
128 or to start a hist trigger but not log any events until told to do
130 hist trigger.
132 The 'clear' parameter will clear the contents of a running hist
144 hist trigger. Any number of enable_hist and disable_hist triggers
159 would be to first set up a paused hist trigger on some event,
160 followed by an enable_hist/disable_hist pair that turns the hist
163 # echo 'hist:keys=skbaddr.hex:vals=len:pause' > \
172 The above sets up an initially paused hist trigger which is unpaused
174 which stops aggregating when the process exits and the hist trigger
184 keys or values in a hist trigger. These look like and behave as if
201 For some error conditions encountered when invoking a hist trigger
206 6.2 'hist' trigger examples
210 event. The fields that can be used for the hist trigger are listed
228 We'll start by creating a hist trigger that generates a simple table
232 # echo 'hist:key=call_site:val=bytes_req.buckets=32' > \
235 This tells the tracing system to create a 'hist' trigger using the
239 the hist trigger that for each unique entry (call_site) in the
243 We'll let it run for awhile and then dump the contents of the 'hist'
247 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
248 # trigger info: hist:keys=call_site:vals=bytes_req:sort=hitcount:size=2048 [active]
288 hist:keys=call_site:vals=bytes_req:sort=hitcount:size=2048 [active]
314 To turn the hist trigger off, simply call up the trigger in the
317 # echo '!hist:key=call_site:val=bytes_req' > \
325 # echo 'hist:key=call_site.hex:val=bytes_req' > \
328 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
329 # trigger info: hist:keys=call_site.hex:vals=bytes_req:sort=hitcount:size=2048 [active]
370 # echo 'hist:key=call_site.sym:val=bytes_req' > \
373 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
374 # trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=hitcount:size=2048 [active]
420 # echo 'hist:key=call_site.sym:val=bytes_req:sort=bytes_req.descending' > \
423 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
424 …# trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=bytes_req.descending:size=2048 [active]
461 # echo 'hist:key=call_site.sym-offset:val=bytes_req:sort=bytes_req.descending' > \
464 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
465 …# trigger info: hist:keys=call_site.sym-offset:vals=bytes_req:sort=bytes_req.descending:size=2048 …
500 # echo 'hist:keys=call_site.sym:values=bytes_req,bytes_alloc:sort=bytes_alloc.descending' > \
503 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
504 …# trigger info: hist:keys=call_site.sym:vals=bytes_req,bytes_alloc:sort=bytes_alloc.descending:siz…
538 the hist trigger display symbolic call_sites, we can have the hist
543 # echo 'hist:keys=stacktrace:values=bytes_req,bytes_alloc:sort=bytes_alloc' > \
554 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
555 …# trigger info: hist:keys=stacktrace:vals=bytes_req,bytes_alloc:sort=bytes_alloc:size=2048 [active]
646 If you key a hist trigger on common_pid, in order for example to
652 # echo 'hist:key=common_pid.execname:val=count:sort=count.descending' > \
655 # cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/hist
656 … # trigger info: hist:keys=common_pid.execname:vals=count:sort=count.descending:size=2048 [active]
687 Similarly, if you key a hist trigger on syscall id, for example to
693 # echo 'hist:key=id.syscall:val=hitcount' > \
696 # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
697 # trigger info: hist:keys=id.syscall:vals=hitcount:sort=hitcount:size=2048 [active]
747 # echo 'hist:key=id.syscall,common_pid.execname:val=hitcount:sort=id,hitcount' > \
750 # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
751 …# trigger info: hist:keys=id.syscall,common_pid.execname:vals=hitcount:sort=id.syscall,hitcount:si…
797 # echo 'hist:key=id.syscall,common_pid.execname:val=hitcount:sort=id,hitcount if id == 16' > \
800 # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
801 …# trigger info: hist:keys=id.syscall,common_pid.execname:vals=hitcount:sort=id.syscall,hitcount:si…
840 # echo 'hist:key=common_pid.execname,size:val=hitcount:sort=common_pid,size' > \
843 # cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_recvfrom/hist
844 …# trigger info: hist:keys=common_pid.execname,size:vals=hitcount:sort=common_pid.execname,size:siz…
888 demonstrates how you can manually pause and continue a hist trigger.
893 # echo 'hist:key=child_comm:val=hitcount:size=256' > \
896 # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
897 # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [active]
925 If we want to pause the hist trigger, we can simply append :pause to
929 # echo 'hist:key=child_comm:val=hitcount:size=256:pause' >> \
932 # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
933 # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [paused]
966 # echo 'hist:key=child_comm:val=hitcount:size=256:cont' >> \
969 # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
970 # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [active]
999 The previous example showed how to start and stop a hist trigger by
1000 appending 'pause' and 'continue' to the hist trigger command. A
1001 hist trigger can also be started in a paused state by initially
1009 it is possible to automatically start and stop a hist trigger based
1020 # echo 'hist:key=stacktrace:vals=len:pause' > \
1025 this new trigger is that it will 'unpause' the hist trigger we just
1043 trigger filter matches 'comm==wget', the netif_receive_skb hist
1048 wget command and then listing the 'hist' file will display the
1053 # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
1054 # trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused]
1130 The 'clear' hist trigger param can be used to clear the hash table.
1136 # echo 'hist:key=stacktrace:vals=len:clear' >> \
1140 the hist file::
1142 # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
1143 # trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused]
1164 one enabling/disabling the hist aggregation and the other
1183 Displaying the 'hist' file should show something similar to what you
1214 The following example demonstrates how multiple hist triggers can be
1220 # echo 'hist:keys=skbaddr.hex:vals=len if len < 0' >> \
1222 # echo 'hist:keys=skbaddr.hex:vals=len if len > 4096' >> \
1224 # echo 'hist:keys=skbaddr.hex:vals=len if len == 256' >> \
1226 # echo 'hist:keys=skbaddr.hex:vals=len' >> \
1228 # echo 'hist:keys=len:vals=common_preempt_count' >> \
1233 nonsensical trigger. Note that in order to append multiple hist
1235 append them ('>' will also add the new hist trigger, but will remove
1236 any existing hist triggers beforehand).
1238 Displaying the contents of the 'hist' file for the event shows the
1241 # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
1245 … # trigger info: hist:keys=len:vals=hitcount,common_preempt_count:sort=hitcount:size=2048 [active]
1272 # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
1309 …# trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len == 256 [act…
1321 …# trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len > 4096 [act…
1345 …# trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len < 0 [active]
1357 functions, but names can be used in a hist trigger on any event.
1361 # echo 'hist:name=foo:keys=skbaddr.hex:vals=len' > \
1363 # echo 'hist:name=foo:keys=skbaddr.hex:vals=len' > \
1367 each event's hist files at the same time::
1369 # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist;
1370 cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
1374 … # trigger info: hist:name=foo:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
1426 … # trigger info: hist:name=foo:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
1482 # echo 'hist:name=bar:key=stacktrace:val=hitcount' > \
1484 # echo 'hist:name=bar:key=stacktrace:val=hitcount' > \
1490 # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
1491 # cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
1495 # trigger info: hist:name=bar:keys=stacktrace:vals=hitcount:sort=hitcount:size=2048 [active]
1602 2.2 Inter-event hist triggers
1605 Inter-event hist triggers are hist triggers that combine values from
1623 Normally, a hist trigger specification consists of a (possibly
1630 The inter-event hist trigger extension allows fields from multiple
1633 features have been added to the hist trigger support:
1644 histogram on either event (so having the 'hist' file for either
1673 trace clocks instead, using the "clock=XXX" hist trigger attribute,
1705 # echo 'hist:keys=next_pid:vals=$ts0:ts0=common_timestamp ... >> \
1721 # echo 'hist:timer_pid=common_pid:key=timer_pid ...' >> event/trigger
1727 # echo 'hist:keys=next_pid:ts1=common_timestamp ...' >> event/trigger
1733 # echo 'hist:keys=pid:vals=$ts0,$b:ts0=common_timestamp,b=field1 ...' >> \
1740 # echo 'hist:keys=pid:ts0=common_timestamp,b=field1:vals=$ts0,$b ...' >> \
1747 # echo 'hist:keys=pid:ts0=common_timestamp:b=field1 ...' >> event/trigger
1754 # echo 'hist:keys=pid,prio:ts0=common_timestamp ...' >> event1/trigger
1755 # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp-$ts0 ...' >> event2/trigger
1760 yet another variable, 'wakeup_lat'. The hist trigger below in turn
1764 # echo 'hist:key=pid:wakeupswitch_lat=$wakeup_lat+$switchtime_lat ...' >> event3/trigger
1774 # echo 'hist:keys=next_pid:timestamp_secs=common_timestamp/1000000 ...' >> event/trigger
1778 # echo 'hist:keys=next_pid:us_per_sec=1000000 ...' >> event/trigger
1779 # echo 'hist:keys=next_pid:timestamp_secs=common_timestamp/$us_per_sec ...' >> event/trigger
1784 Synthetic events are user-defined events generated from hist trigger
1836 instantiated in the event subsystem - for this to happen, a 'hist
1839 how that is done using hist trigger 'onmatch' action). Once that is
1846 enable filter format hist id trigger
1850 # echo 'hist:keys=pid,prio,lat.log2:sort=lat' >> \
1856 output can be displayed by reading the event's 'hist' file.
1858 # cat /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/hist
1862 # trigger info: hist:keys=pid,prio,lat.log2:vals=hitcount:sort=lat.log2:size=2048 [active]
1905 # echo 'hist:keys=pid,prio,lat.buckets=10:sort=lat' >> \
1910 …# trigger info: hist:keys=pid,prio,lat.buckets=10:vals=hitcount:sort=lat.buckets=10:size=2048 [act…
1938 A hist trigger 'action' is a function that's executed (in most cases
1941 When a histogram entry is added or updated, a hist trigger 'handler'
1951 that handler.action pair between colons in the hist trigger
1956 if a given handler.action combination isn't supported, the hist
1986 list)' hist trigger action is invoked whenever an event matches
2039 The following hist trigger both defines the missing testpid
2045 # echo 'hist:keys=$testpid:testpid=pid:onmatch(sched.sched_wakeup_new).\
2051 # echo 'hist:keys=$testpid:testpid=pid:onmatch(sched.sched_wakeup_new).\
2059 # echo 'hist:keys=pid:sort=pid' >> \
2064 output in the wakeup_new_test event's hist file::
2066 # cat /sys/kernel/debug/tracing/events/synthetic/wakeup_new_test/hist
2069 latency. The following example uses a set of hist triggers to
2080 # echo 'hist:keys=$saved_pid:saved_pid=pid:ts0=common_timestamp.usecs \
2089 # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:\
2097 # echo 'hist:keys=pid,prio,lat:sort=pid,lat' >> \
2102 synthetic event's hist file::
2104 # cat /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/hist
2108 The 'onmax(var).save(field,...)' hist trigger action is invoked
2114 maximum for that hist trigger entry. This allows context from the
2119 As an example the below defines a couple of hist triggers, one for
2128 # echo 'hist:keys=pid:ts0=common_timestamp.usecs \
2132 # echo 'hist:keys=next_pid:\
2142 # cat /sys/kernel/debug/tracing/events/sched/sched_switch/hist
2161 The 'onmax(var).snapshot()' hist trigger action is invoked
2167 maximum for any hist trigger entry.
2178 As an example the below defines a couple of hist triggers, one for
2190 # echo 'hist:keys=pid:ts0=common_timestamp.usecs \
2194 # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \
2207 # cat /sys/kernel/debug/tracing/events/sched/sched_switch/hist
2270 The 'onchange(var).save(field,...)' hist trigger action is invoked
2276 hist trigger entry. This allows context from the event that
2283 The 'onchange(var).snapshot()' hist trigger action is invoked
2289 hist trigger entry.
2299 As an example the below defines a hist trigger on the tcp_probe
2310 # echo 'hist:keys=dport:cwnd=snd_cwnd: \
2322 # cat /sys/kernel/debug/tracing/events/tcp/tcp_probe/hist
2396 …# echo 'hist:keys=common_pid:ts0=common_timestamp.usecs if buf == "start"' > events/ftrace/print/t…
2397 …# echo 'hist:keys=common_pid:lat=common_timestamp.usecs-$ts0:onmatch(ftrace.print).latency($lat) i…
2398 # echo 'hist:keys=lat,common_pid:sort=lat' > events/synthetic/latency/trigger
2424 # cat events/synthetic/latency/hist
2427 # trigger info: hist:keys=lat,common_pid:vals=hitcount:sort=lat:size=2048 [active]
2727 # echo 'hist:keys=pid:ts0=common_timestamp.usecs' > events/sched/sched_waking/trigger
2728 …# echo 'hist:keys=common_pid:lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).latency($…
2729 # echo 'hist:keys=lat,common_pid:sort=lat' > events/synthetic/latency/trigger
2737 # cat events/synthetic/latency/hist
2740 # trigger info: hist:keys=lat,common_pid:vals=hitcount:sort=lat:size=2048 [active]