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
102 A typical usage scenario would be the following to enable a hist
105 # echo 'hist:keys=skbaddr.hex:vals=len' > \
108 # cat /sys/kernel/tracing/events/net/netif_rx/hist
110 # echo '!hist:keys=skbaddr.hex:vals=len' > \
114 currently attached hist trigger. This information is also displayed
115 at the top of the 'hist' file when read.
130 The 'pause' parameter can be used to pause an existing hist trigger
131 or to start a hist trigger but not log any events until told to do
133 hist trigger.
135 The 'clear' parameter will clear the contents of a running hist
146 'hist:...:vals=hitcount:nohitcount' is rejected, but
147 'hist:...:vals=hitcount.percent:nohitcount' is OK.
153 hist trigger. Any number of enable_hist and disable_hist triggers
168 would be to first set up a paused hist trigger on some event,
169 followed by an enable_hist/disable_hist pair that turns the hist
172 # echo 'hist:keys=skbaddr.hex:vals=len:pause' > \
181 The above sets up an initially paused hist trigger which is unpaused
183 which stops aggregating when the process exits and the hist trigger
193 keys or values in a hist trigger. These look like and behave as if
210 For some error conditions encountered when invoking a hist trigger
215 6.2 'hist' trigger examples
219 event. The fields that can be used for the hist trigger are listed
237 We'll start by creating a hist trigger that generates a simple table
241 # echo 'hist:key=call_site:val=bytes_req.buckets=32' > \
244 This tells the tracing system to create a 'hist' trigger using the
248 the hist trigger that for each unique entry (call_site) in the
252 We'll let it run for awhile and then dump the contents of the 'hist'
256 # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
257 # trigger info: hist:keys=call_site:vals=bytes_req:sort=hitcount:size=2048 [active]
297 hist:keys=call_site:vals=bytes_req:sort=hitcount:size=2048 [active]
323 To turn the hist trigger off, simply call up the trigger in the
326 # echo '!hist:key=call_site:val=bytes_req' > \
334 # echo 'hist:key=call_site.hex:val=bytes_req' > \
337 # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
338 # trigger info: hist:keys=call_site.hex:vals=bytes_req:sort=hitcount:size=2048 [active]
379 # echo 'hist:key=call_site.sym:val=bytes_req' > \
382 # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
383 # trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=hitcount:size=2048 [active]
429 # echo 'hist:key=call_site.sym:val=bytes_req:sort=bytes_req.descending' > \
432 # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
433 …# trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=bytes_req.descending:size=2048 [active]
470 # echo 'hist:key=call_site.sym-offset:val=bytes_req:sort=bytes_req.descending' > \
473 # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
474 …# trigger info: hist:keys=call_site.sym-offset:vals=bytes_req:sort=bytes_req.descending:size=2048 …
509 # echo 'hist:keys=call_site.sym:values=bytes_req,bytes_alloc:sort=bytes_alloc.descending' > \
512 # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
513 …# trigger info: hist:keys=call_site.sym:vals=bytes_req,bytes_alloc:sort=bytes_alloc.descending:siz…
547 the hist trigger display symbolic call_sites, we can have the hist
552 # echo 'hist:keys=common_stacktrace:values=bytes_req,bytes_alloc:sort=bytes_alloc' > \
563 # cat /sys/kernel/tracing/events/kmem/kmalloc/hist
564 …# trigger info: hist:keys=common_stacktrace:vals=bytes_req,bytes_alloc:sort=bytes_alloc:size=2048 …
655 If you key a hist trigger on common_pid, in order for example to
661 # echo 'hist:key=common_pid.execname:val=count:sort=count.descending' > \
664 # cat /sys/kernel/tracing/events/syscalls/sys_enter_read/hist
665 … # trigger info: hist:keys=common_pid.execname:vals=count:sort=count.descending:size=2048 [active]
696 Similarly, if you key a hist trigger on syscall id, for example to
702 # echo 'hist:key=id.syscall:val=hitcount' > \
705 # cat /sys/kernel/tracing/events/raw_syscalls/sys_enter/hist
706 # trigger info: hist:keys=id.syscall:vals=hitcount:sort=hitcount:size=2048 [active]
756 # echo 'hist:key=id.syscall,common_pid.execname:val=hitcount:sort=id,hitcount' > \
759 # cat /sys/kernel/tracing/events/raw_syscalls/sys_enter/hist
760 …# trigger info: hist:keys=id.syscall,common_pid.execname:vals=hitcount:sort=id.syscall,hitcount:si…
806 # echo 'hist:key=id.syscall,common_pid.execname:val=hitcount:sort=id,hitcount if id == 16' > \
809 # cat /sys/kernel/tracing/events/raw_syscalls/sys_enter/hist
810 …# trigger info: hist:keys=id.syscall,common_pid.execname:vals=hitcount:sort=id.syscall,hitcount:si…
849 # echo 'hist:key=common_pid.execname,size:val=hitcount:sort=common_pid,size' > \
852 # cat /sys/kernel/tracing/events/syscalls/sys_enter_recvfrom/hist
853 …# trigger info: hist:keys=common_pid.execname,size:vals=hitcount:sort=common_pid.execname,size:siz…
897 demonstrates how you can manually pause and continue a hist trigger.
902 # echo 'hist:key=child_comm:val=hitcount:size=256' > \
905 # cat /sys/kernel/tracing/events/sched/sched_process_fork/hist
906 # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [active]
934 If we want to pause the hist trigger, we can simply append :pause to
938 # echo 'hist:key=child_comm:val=hitcount:size=256:pause' >> \
941 # cat /sys/kernel/tracing/events/sched/sched_process_fork/hist
942 # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [paused]
975 # echo 'hist:key=child_comm:val=hitcount:size=256:cont' >> \
978 # cat /sys/kernel/tracing/events/sched/sched_process_fork/hist
979 # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [active]
1008 The previous example showed how to start and stop a hist trigger by
1009 appending 'pause' and 'continue' to the hist trigger command. A
1010 hist trigger can also be started in a paused state by initially
1018 it is possible to automatically start and stop a hist trigger based
1029 # echo 'hist:key=common_stacktrace:vals=len:pause' > \
1034 this new trigger is that it will 'unpause' the hist trigger we just
1052 trigger filter matches 'comm==wget', the netif_receive_skb hist
1057 wget command and then listing the 'hist' file will display the
1062 # cat /sys/kernel/tracing/events/net/netif_receive_skb/hist
1063 # trigger info: hist:keys=common_stacktrace:vals=len:sort=hitcount:size=2048 [paused]
1139 The 'clear' hist trigger param can be used to clear the hash table.
1145 # echo 'hist:key=common_stacktrace:vals=len:clear' >> \
1149 the hist file::
1151 # cat /sys/kernel/tracing/events/net/netif_receive_skb/hist
1152 # trigger info: hist:keys=common_stacktrace:vals=len:sort=hitcount:size=2048 [paused]
1173 one enabling/disabling the hist aggregation and the other
1192 Displaying the 'hist' file should show something similar to what you
1223 The following example demonstrates how multiple hist triggers can be
1229 # echo 'hist:keys=skbaddr.hex:vals=len if len < 0' >> \
1231 # echo 'hist:keys=skbaddr.hex:vals=len if len > 4096' >> \
1233 # echo 'hist:keys=skbaddr.hex:vals=len if len == 256' >> \
1235 # echo 'hist:keys=skbaddr.hex:vals=len' >> \
1237 # echo 'hist:keys=len:vals=common_preempt_count' >> \
1242 nonsensical trigger. Note that in order to append multiple hist
1244 append them ('>' will also add the new hist trigger, but will remove
1245 any existing hist triggers beforehand).
1247 Displaying the contents of the 'hist' file for the event shows the
1250 # cat /sys/kernel/tracing/events/net/netif_receive_skb/hist
1254 … # trigger info: hist:keys=len:vals=hitcount,common_preempt_count:sort=hitcount:size=2048 [active]
1281 # trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
1318 …# trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len == 256 [act…
1330 …# trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len > 4096 [act…
1354 …# trigger info: hist:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 if len < 0 [active]
1366 functions, but names can be used in a hist trigger on any event.
1370 # echo 'hist:name=foo:keys=skbaddr.hex:vals=len' > \
1372 # echo 'hist:name=foo:keys=skbaddr.hex:vals=len' > \
1376 each event's hist files at the same time::
1378 # cat /sys/kernel/tracing/events/net/netif_receive_skb/hist;
1379 cat /sys/kernel/tracing/events/net/netif_rx/hist
1383 … # trigger info: hist:name=foo:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
1435 … # trigger info: hist:name=foo:keys=skbaddr.hex:vals=hitcount,len:sort=hitcount:size=2048 [active]
1491 # echo 'hist:name=bar:key=common_stacktrace:val=hitcount' > \
1493 # echo 'hist:name=bar:key=common_stacktrace:val=hitcount' > \
1499 # cat /sys/kernel/tracing/events/sched/sched_process_fork/hist
1500 # cat /sys/kernel/tracing/events/net/netif_rx/hist
1504 …# trigger info: hist:name=bar:keys=common_stacktrace:vals=hitcount:sort=hitcount:size=2048 [active]
1611 2.2 Inter-event hist triggers
1614 Inter-event hist triggers are hist triggers that combine values from
1632 Normally, a hist trigger specification consists of a (possibly
1639 The inter-event hist trigger extension allows fields from multiple
1642 features have been added to the hist trigger support:
1653 histogram on either event (so having the 'hist' file for either
1682 trace clocks instead, using the "clock=XXX" hist trigger attribute,
1714 # echo 'hist:keys=next_pid:vals=$ts0:ts0=common_timestamp ... >> \
1730 # echo 'hist:timer_pid=common_pid:key=timer_pid ...' >> event/trigger
1736 # echo 'hist:keys=next_pid:ts1=common_timestamp ...' >> event/trigger
1742 # echo 'hist:keys=pid:vals=$ts0,$b:ts0=common_timestamp,b=field1 ...' >> \
1749 # echo 'hist:keys=pid:ts0=common_timestamp,b=field1:vals=$ts0,$b ...' >> \
1756 # echo 'hist:keys=pid:ts0=common_timestamp:b=field1 ...' >> event/trigger
1763 # echo 'hist:keys=pid,prio:ts0=common_timestamp ...' >> event1/trigger
1764 # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp-$ts0 ...' >> event2/trigger
1769 yet another variable, 'wakeup_lat'. The hist trigger below in turn
1773 # echo 'hist:key=pid:wakeupswitch_lat=$wakeup_lat+$switchtime_lat ...' >> event3/trigger
1783 # echo 'hist:keys=next_pid:timestamp_secs=common_timestamp/1000000 ...' >> event/trigger
1787 # echo 'hist:keys=next_pid:us_per_sec=1000000 ...' >> event/trigger
1788 # echo 'hist:keys=next_pid:timestamp_secs=common_timestamp/$us_per_sec ...' >> event/trigger
1795 Synthetic events are user-defined events generated from hist trigger
1847 instantiated in the event subsystem - for this to happen, a 'hist
1850 how that is done using hist trigger 'onmatch' action). Once that is
1857 enable filter format hist id trigger
1861 # echo 'hist:keys=pid,prio,lat.log2:sort=lat' >> \
1867 output can be displayed by reading the event's 'hist' file::
1869 # cat /sys/kernel/tracing/events/synthetic/wakeup_latency/hist
1873 # trigger info: hist:keys=pid,prio,lat.log2:vals=hitcount:sort=lat.log2:size=2048 [active]
1916 # echo 'hist:keys=pid,prio,lat.buckets=10:sort=lat' >> \
1921 …# trigger info: hist:keys=pid,prio,lat.buckets=10:vals=hitcount:sort=lat.buckets=10:size=2048 [act…
1952 …# echo 'hist:keys=next_pid:ts=common_timestamp.usecs,st=common_stacktrace if prev_state == 2' >> …
1953 …# echo 'hist:keys=prev_pid:delta=common_timestamp.usecs-$ts,s=$st:onmax($delta).trace(block_lat,pr…
1996 …# echo 'hist:keys=delta.buckets=100,stack.stacktrace:sort=delta' > events/synthetic/block_lat/trig…
1997 # cat events/synthetic/block_lat/hist
2001 …# trigger info: hist:keys=delta.buckets=100,stack.stacktrace:vals=hitcount:sort=delta.buckets=100:…
2100 A hist trigger 'action' is a function that's executed (in most cases
2103 When a histogram entry is added or updated, a hist trigger 'handler'
2113 that handler.action pair between colons in the hist trigger
2118 if a given handler.action combination isn't supported, the hist
2148 list)' hist trigger action is invoked whenever an event matches
2201 The following hist trigger both defines the missing testpid
2207 # echo 'hist:keys=$testpid:testpid=pid:onmatch(sched.sched_wakeup_new).\
2213 # echo 'hist:keys=$testpid:testpid=pid:onmatch(sched.sched_wakeup_new).\
2221 # echo 'hist:keys=pid:sort=pid' >> \
2226 output in the wakeup_new_test event's hist file::
2228 # cat /sys/kernel/tracing/events/synthetic/wakeup_new_test/hist
2231 latency. The following example uses a set of hist triggers to
2242 # echo 'hist:keys=$saved_pid:saved_pid=pid:ts0=common_timestamp.usecs \
2251 # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:\
2259 # echo 'hist:keys=pid,prio,lat:sort=pid,lat' >> \
2264 synthetic event's hist file::
2266 # cat /sys/kernel/tracing/events/synthetic/wakeup_latency/hist
2270 The 'onmax(var).save(field,...)' hist trigger action is invoked
2276 maximum for that hist trigger entry. This allows context from the
2281 As an example the below defines a couple of hist triggers, one for
2290 # echo 'hist:keys=pid:ts0=common_timestamp.usecs \
2294 # echo 'hist:keys=next_pid:\
2304 # cat /sys/kernel/tracing/events/sched/sched_switch/hist
2323 The 'onmax(var).snapshot()' hist trigger action is invoked
2329 maximum for any hist trigger entry.
2340 As an example the below defines a couple of hist triggers, one for
2352 # echo 'hist:keys=pid:ts0=common_timestamp.usecs \
2356 # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \
2369 # cat /sys/kernel/tracing/events/sched/sched_switch/hist
2432 The 'onchange(var).save(field,...)' hist trigger action is invoked
2438 hist trigger entry. This allows context from the event that
2445 The 'onchange(var).snapshot()' hist trigger action is invoked
2451 hist trigger entry.
2461 As an example the below defines a hist trigger on the tcp_probe
2472 # echo 'hist:keys=dport:cwnd=snd_cwnd: \
2484 # cat /sys/kernel/tracing/events/tcp/tcp_probe/hist
2558 …# echo 'hist:keys=common_pid:ts0=common_timestamp.usecs if buf == "start"' > events/ftrace/print/t…
2559 …# echo 'hist:keys=common_pid:lat=common_timestamp.usecs-$ts0:onmatch(ftrace.print).latency($lat) i…
2560 # echo 'hist:keys=lat,common_pid:sort=lat' > events/synthetic/latency/trigger
2586 # cat events/synthetic/latency/hist
2589 # trigger info: hist:keys=lat,common_pid:vals=hitcount:sort=lat:size=2048 [active]
2889 # echo 'hist:keys=pid:ts0=common_timestamp.usecs' > events/sched/sched_waking/trigger
2890 …# echo 'hist:keys=common_pid:lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).latency($…
2891 # echo 'hist:keys=lat,common_pid:sort=lat' > events/synthetic/latency/trigger
2899 # cat events/synthetic/latency/hist
2902 # trigger info: hist:keys=lat,common_pid:vals=hitcount:sort=lat:size=2048 [active]