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
98 A typical usage scenario would be the following to enable a hist
101 # echo 'hist:keys=skbaddr.hex:vals=len' > \
104 # cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
106 # echo '!hist:keys=skbaddr.hex:vals=len' > \
110 currently attached hist trigger. This information is also displayed
111 at the top of the 'hist' file when read.
126 The 'pause' parameter can be used to pause an existing hist trigger
127 or to start a hist trigger but not log any events until told to do
129 hist trigger.
131 The 'clear' parameter will clear the contents of a running hist
143 hist trigger. Any number of enable_hist and disable_hist triggers
158 would be to first set up a paused hist trigger on some event,
159 followed by an enable_hist/disable_hist pair that turns the hist
162 # echo 'hist:keys=skbaddr.hex:vals=len:pause' > \
171 The above sets up an initially paused hist trigger which is unpaused
173 which stops aggregating when the process exits and the hist trigger
183 keys or values in a hist trigger. These look like and behave as if
200 For some error conditions encountered when invoking a hist trigger
202 corresponding event's 'hist' file. Reading the hist file after an
205 be available until the next hist trigger command for that event.
213 # cat /sys/kernel/debug/tracing/events/sched/sched_wakeup/hist
217 6.2 'hist' trigger examples
221 event. The fields that can be used for the hist trigger are listed
239 We'll start by creating a hist trigger that generates a simple table
243 # echo 'hist:key=call_site:val=bytes_req' > \
246 This tells the tracing system to create a 'hist' trigger using the
250 the hist trigger that for each unique entry (call_site) in the
254 We'll let it run for awhile and then dump the contents of the 'hist'
258 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
259 # trigger info: hist:keys=call_site:vals=bytes_req:sort=hitcount:size=2048 [active]
299 hist:keys=call_site:vals=bytes_req:sort=hitcount:size=2048 [active]
325 To turn the hist trigger off, simply call up the trigger in the
328 # echo '!hist:key=call_site:val=bytes_req' > \
336 # echo 'hist:key=call_site.hex:val=bytes_req' > \
339 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
340 # trigger info: hist:keys=call_site.hex:vals=bytes_req:sort=hitcount:size=2048 [active]
381 # echo 'hist:key=call_site.sym:val=bytes_req' > \
384 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
385 # trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=hitcount:size=2048 [active]
431 # echo 'hist:key=call_site.sym:val=bytes_req:sort=bytes_req.descending' > \
434 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
435 …# trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=bytes_req.descending:size=2048 [active]
472 # echo 'hist:key=call_site.sym-offset:val=bytes_req:sort=bytes_req.descending' > \
475 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
476 …# trigger info: hist:keys=call_site.sym-offset:vals=bytes_req:sort=bytes_req.descending:size=2048 …
511 # echo 'hist:keys=call_site.sym:values=bytes_req,bytes_alloc:sort=bytes_alloc.descending' > \
514 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
515 …# trigger info: hist:keys=call_site.sym:vals=bytes_req,bytes_alloc:sort=bytes_alloc.descending:siz…
549 the hist trigger display symbolic call_sites, we can have the hist
554 # echo 'hist:keys=stacktrace:values=bytes_req,bytes_alloc:sort=bytes_alloc' > \
565 # cat /sys/kernel/debug/tracing/events/kmem/kmalloc/hist
566 …# trigger info: hist:keys=stacktrace:vals=bytes_req,bytes_alloc:sort=bytes_alloc:size=2048 [active]
657 If you key a hist trigger on common_pid, in order for example to
663 # echo 'hist:key=common_pid.execname:val=count:sort=count.descending' > \
666 # cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/hist
667 … # trigger info: hist:keys=common_pid.execname:vals=count:sort=count.descending:size=2048 [active]
698 Similarly, if you key a hist trigger on syscall id, for example to
704 # echo 'hist:key=id.syscall:val=hitcount' > \
707 # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
708 # trigger info: hist:keys=id.syscall:vals=hitcount:sort=hitcount:size=2048 [active]
758 # echo 'hist:key=id.syscall,common_pid.execname:val=hitcount:sort=id,hitcount' > \
761 # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
762 …# trigger info: hist:keys=id.syscall,common_pid.execname:vals=hitcount:sort=id.syscall,hitcount:si…
808 # echo 'hist:key=id.syscall,common_pid.execname:val=hitcount:sort=id,hitcount if id == 16' > \
811 # cat /sys/kernel/debug/tracing/events/raw_syscalls/sys_enter/hist
812 …# trigger info: hist:keys=id.syscall,common_pid.execname:vals=hitcount:sort=id.syscall,hitcount:si…
851 # echo 'hist:key=common_pid.execname,size:val=hitcount:sort=common_pid,size' > \
854 # cat /sys/kernel/debug/tracing/events/syscalls/sys_enter_recvfrom/hist
855 …# trigger info: hist:keys=common_pid.execname,size:vals=hitcount:sort=common_pid.execname,size:siz…
899 demonstrates how you can manually pause and continue a hist trigger.
904 # echo 'hist:key=child_comm:val=hitcount:size=256' > \
907 # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
908 # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [active]
936 If we want to pause the hist trigger, we can simply append :pause to
940 # echo 'hist:key=child_comm:val=hitcount:size=256:pause' >> \
943 # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
944 # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [paused]
977 # echo 'hist:key=child_comm:val=hitcount:size=256:cont' >> \
980 # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
981 # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [active]
1010 The previous example showed how to start and stop a hist trigger by
1011 appending 'pause' and 'continue' to the hist trigger command. A
1012 hist trigger can also be started in a paused state by initially
1020 it is possible to automatically start and stop a hist trigger based
1031 # echo 'hist:key=stacktrace:vals=len:pause' > \
1036 this new trigger is that it will 'unpause' the hist trigger we just
1054 trigger filter matches 'comm==wget', the netif_receive_skb hist
1059 wget command and then listing the 'hist' file will display the
1064 # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
1065 # trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused]
1141 The 'clear' hist trigger param can be used to clear the hash table.
1147 # echo 'hist:key=stacktrace:vals=len:clear' >> \
1151 the hist file::
1153 # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
1154 # trigger info: hist:keys=stacktrace:vals=len:sort=hitcount:size=2048 [paused]
1175 one enabling/disabling the hist aggregation and the other
1194 Displaying the 'hist' file should show something similar to what you
1225 The following example demonstrates how multiple hist triggers can be
1231 # echo 'hist:keys=skbaddr.hex:vals=len if len < 0' >> \
1233 # echo 'hist:keys=skbaddr.hex:vals=len if len > 4096' >> \
1235 # echo 'hist:keys=skbaddr.hex:vals=len if len == 256' >> \
1237 # echo 'hist:keys=skbaddr.hex:vals=len' >> \
1239 # echo 'hist:keys=len:vals=common_preempt_count' >> \
1244 nonsensical trigger. Note that in order to append multiple hist
1246 append them ('>' will also add the new hist trigger, but will remove
1247 any existing hist triggers beforehand).
1249 Displaying the contents of the 'hist' file for the event shows the
1252 # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist
1256 … # trigger info: hist:keys=len:vals=hitcount,common_preempt_count:sort=hitcount:size=2048 [active]
1283 # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
1320 …# trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len == 256 [act…
1332 …# trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len > 4096 [act…
1356 …# trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len < 0 [active]
1368 functions, but names can be used in a hist trigger on any event.
1372 # echo 'hist:name=foo:keys=skbaddr.hex:vals=len' > \
1374 # echo 'hist:name=foo:keys=skbaddr.hex:vals=len' > \
1378 each event's hist files at the same time::
1380 # cat /sys/kernel/debug/tracing/events/net/netif_receive_skb/hist;
1381 cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
1385 … # trigger info: hist:name=foo:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
1437 … # trigger info: hist:name=foo:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
1493 # echo 'hist:name=bar:key=stacktrace:val=hitcount' > \
1495 # echo 'hist:name=bar:key=stacktrace:val=hitcount' > \
1501 # cat /sys/kernel/debug/tracing/events/sched/sched_process_fork/hist
1502 # cat /sys/kernel/debug/tracing/events/net/netif_rx/hist
1506 # trigger info: hist:name=bar:keys=stacktrace:vals=hitcount:sort=hitcount:size=2048 [active]
1613 2.2 Inter-event hist triggers
1616 Inter-event hist triggers are hist triggers that combine values from
1634 Normally, a hist trigger specification consists of a (possibly
1641 The inter-event hist trigger extension allows fields from multiple
1644 features have been added to the hist trigger support:
1655 histogram on either event (so having the 'hist' file for either
1684 trace clocks instead, using the "clock=XXX" hist trigger attribute,
1716 # echo 'hist:keys=next_pid:vals=$ts0:ts0=common_timestamp ... >> \
1732 # echo 'hist:timer_pid=common_pid:key=timer_pid ...' >> event/trigger
1738 # echo 'hist:keys=next_pid:ts1=common_timestamp ...' >> event/trigger
1744 # echo 'hist:keys=pid:vals=$ts0,$b:ts0=common_timestamp,b=field1 ...' >> \
1751 # echo 'hist:keys=pid:ts0=common_timestamp,b=field1:vals=$ts0,$b ...' >> \
1758 # echo 'hist:keys=pid:ts0=common_timestamp:b=field1 ...' >> event/trigger
1765 # echo 'hist:keys=pid,prio:ts0=common_timestamp ...' >> event1/trigger
1766 # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp-$ts0 ...' >> event2/trigger
1771 yet another variable, 'wakeup_lat'. The hist trigger below in turn
1775 # echo 'hist:key=pid:wakeupswitch_lat=$wakeup_lat+$switchtime_lat ...' >> event3/trigger
1780 Synthetic events are user-defined events generated from hist trigger
1814 instantiated in the event subsytem - for this to happen, a 'hist
1817 how that is done using hist trigger 'onmatch' action). Once that is
1822 # echo 'hist:keys=pid,prio,lat.log2:sort=pid,lat' >> \
1829 enable filter format hist id trigger
1832 output can be displayed by reading the event's 'hist' file.
1837 A hist trigger 'action' is a function that's executed whenever a
1848 hist trigger specification.
1852 The 'onmatch(matching.event).<synthetic_event_name>(params)' hist
1889 The following hist trigger both defines the missing testpid
1895 # echo 'hist:keys=$testpid:testpid=pid:onmatch(sched.sched_wakeup_new).\
1903 # echo 'hist:keys=pid:sort=pid' >> \
1908 output in the wakeup_new_test event's hist file::
1910 # cat /sys/kernel/debug/tracing/events/synthetic/wakeup_new_test/hist
1913 latency. The following example uses a set of hist triggers to
1924 # echo 'hist:keys=$saved_pid:saved_pid=pid:ts0=common_timestamp.usecs \
1933 # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:\
1941 # echo 'hist:keys=pid,prio,lat:sort=pid,lat' >> \
1946 synthetic event's hist file::
1948 # cat /sys/kernel/debug/tracing/events/synthetic/wakeup_latency/hist
1952 The 'onmax(var).save(field,...)' hist trigger action is invoked
1958 maximum for that hist trigger entry. This allows context from the
1963 As an example the below defines a couple of hist triggers, one for
1972 # echo 'hist:keys=pid:ts0=common_timestamp.usecs \
1976 # echo 'hist:keys=next_pid:\
1986 # cat /sys/kernel/debug/tracing/events/sched/sched_switch/hist
2032 …# echo 'hist:keys=common_pid:ts0=common_timestamp.usecs if buf == "start"' > events/ftrace/print/t…
2033 …# echo 'hist:keys=common_pid:lat=common_timestamp.usecs-$ts0:onmatch(ftrace.print).latency($lat) i…
2034 # echo 'hist:keys=lat,common_pid:sort=lat' > events/synthetic/latency/trigger
2060 # cat events/synthetic/latency/hist
2063 # trigger info: hist:keys=lat,common_pid:vals=hitcount:sort=lat:size=2048 [active]
2363 # echo 'hist:keys=pid:ts0=common_timestamp.usecs' > events/sched/sched_waking/trigger
2364 …# echo 'hist:keys=common_pid:lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).latency($…
2365 # echo 'hist:keys=lat,common_pid:sort=lat' > events/synthetic/latency/trigger
2373 # cat events/synthetic/latency/hist
2376 # trigger info: hist:keys=lat,common_pid:vals=hitcount:sort=lat:size=2048 [active]