Lines Matching +full:trigger +full:- +full:value
15 2. Histogram Trigger Command
18 A histogram trigger command is an event trigger command that
24 The format of a hist trigger is as follows::
31 using the key(s) and value(s) named. Keys and values correspond to
33 numeric fields - on an event hit, the value(s) will be added to a
35 in place of an explicit value field - this is simply a count of
37 value will be automatically created and used as the only value.
45 useful for providing more fine-grained summaries of event data.
50 key. If a hist trigger is given a name using the 'name' parameter,
52 name, and trigger hits will update this common data. Only triggers
54 'compatible' if the fields named in the trigger share the same
63 attached to an event, there will be a table for each trigger in the
64 output. The table displayed for a named trigger will be the same as
68 followed by the set of value fields for the entry. By default,
69 numeric fields are displayed as base-10 integers. This can be
74 .hex display a number as a hex value
76 .sym-offset display an address as a symbol and offset
79 .log2 display log2 value rather than raw number
82 .percent display a number of percentage value
83 .graph display a bar-graph of a value
91 - only the 'hex' modifier can be used for values (because values
94 - the 'execname' modifier can only be used on a 'common_pid'. The
95 reason for this is that the execname is simply the 'comm' value
97 which is the same as the common_pid value saved by the event
98 tracing code. Trying to apply that comm value to other pid
100 pid-specific comm fields in the event itself.
103 trigger, read its current contents, and then turn it off::
106 /sys/kernel/tracing/events/net/netif_rx/trigger
111 /sys/kernel/tracing/events/net/netif_rx/trigger
113 The trigger file itself can be read to show the details of the
114 currently attached hist trigger. This information is also displayed
119 are in terms of hashtable entries - if a run uses more entries than
122 128 and 131072 (any non- power-of-2 number specified will be rounded
125 The 'sort' parameter can be used to specify a value field to sort
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.
136 trigger and leave its current paused/active state.
140 existing trigger, rather than via the '>' operator, which will cause
141 the trigger to be removed through truncation.
145 value field which is not a 'raw hitcount'. For example,
149 - enable_hist/disable_hist
152 event conditionally start and stop another event's already-attached
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,
173 /sys/kernel/tracing/events/net/netif_receive_skb/trigger
176 /sys/kernel/tracing/events/sched/sched_process_exec/trigger
179 /sys/kernel/tracing/events/sched/sched_process_exit/trigger
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
190 ------------------------
193 keys or values in a hist trigger. These look like and behave as if
208 --------------------------
210 For some error conditions encountered when invoking a hist trigger
215 6.2 'hist' trigger examples
216 ---------------------------
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
242 /sys/kernel/tracing/events/kmem/kmalloc/trigger
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
257 # trigger info: hist:keys=call_site:vals=bytes_req:sort=hitcount:size=2048 [active]
291 specified in the trigger, followed by the value(s) also specified in
292 the trigger. At the beginning of the output is a line that displays
293 the trigger info, which can also be displayed by reading the
294 'trigger' file::
296 # cat /sys/kernel/tracing/events/kmem/kmalloc/trigger
301 times the event trigger was hit, the 'Entries' field shows the total
309 which wasn't specified in the trigger. Also notice that in the
310 trigger info output, there's a parameter, 'sort=hitcount', which
311 wasn't specified in the trigger either. The reason for that is that
312 every trigger implicitly keeps a count of the total number of hits
315 absence of a user-specified sort parameter, is used as the default
318 The value 'hitcount' can be used in place of an explicit value in
323 To turn the hist trigger off, simply call up the trigger in the
324 command history and re-execute it with a '!' prepended::
327 /sys/kernel/tracing/events/kmem/kmalloc/trigger
332 value, simply append '.hex' to the field name in the trigger::
335 /sys/kernel/tracing/events/kmem/kmalloc/trigger
338 # trigger info: hist:keys=call_site.hex:vals=bytes_req:sort=hitcount:size=2048 [active]
372 Even that's only marginally more useful - while hex values do look
375 instead. To have an address displayed as symbolic value instead,
376 simply append '.sym' or '.sym-offset' to the field name in the
377 trigger::
380 /sys/kernel/tracing/events/kmem/kmalloc/trigger
383 # trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=hitcount:size=2048 [active]
430 /sys/kernel/tracing/events/kmem/kmalloc/trigger
433 …# trigger info: hist:keys=call_site.sym:vals=bytes_req:sort=bytes_req.descending:size=2048 [active]
468 name, just use 'sym-offset' instead::
470 # echo 'hist:key=call_site.sym-offset:val=bytes_req:sort=bytes_req.descending' > \
471 /sys/kernel/tracing/events/kmem/kmalloc/trigger
474 …# trigger info: hist:keys=call_site.sym-offset:vals=bytes_req:sort=bytes_req.descending:size=2048 …
510 /sys/kernel/tracing/events/kmem/kmalloc/trigger
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
548 trigger additionally display the complete set of kernel stack traces
550 value 'common_stacktrace' for the key parameter::
553 /sys/kernel/tracing/events/kmem/kmalloc/trigger
555 The above trigger will use the kernel stack trace in effect when an
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
659 keeps a per-process sum of total bytes read::
662 /sys/kernel/tracing/events/syscalls/sys_enter_read/trigger
665 … # trigger info: hist:keys=common_pid.execname:vals=count:sort=count.descending:size=2048 [active]
667 { common_pid: gnome-terminal [ 3196] } hitcount: 280 count: 1093512
671 { common_pid: dbus-daemon-lau [ 8703] } hitcount: 49 count: 47739
674 { common_pid: dbus-daemon [ 772] } hitcount: 10 count: 12396
676 { common_pid: nm-dhcp-client. [ 8701] } hitcount: 6 count: 7424
684 { common_pid: upstart-dbus-br [ 2740] } hitcount: 21 count: 21
685 { common_pid: nm-dispatcher.a [ 8696] } hitcount: 1 count: 16
686 { common_pid: indicator-datet [ 2904] } hitcount: 1 count: 16
688 { common_pid: rtkit-daemon [ 2052] } hitcount: 1 count: 8
696 Similarly, if you key a hist trigger on syscall id, for example to
703 /sys/kernel/tracing/events/raw_syscalls/sys_enter/trigger
706 # trigger info: hist:keys=id.syscall:vals=hitcount:sort=hitcount:size=2048 [active]
751 system call id and pid - the end result is essentially a table
752 that keeps a per-pid sum of system call hits. The results are
757 /sys/kernel/tracing/events/raw_syscalls/sys_enter/trigger
760 …# trigger info: hist:keys=id.syscall,common_pid.execname:vals=hitcount:sort=id.syscall,hitcount:si…
762 …{ id: sys_read [ 0], common_pid: rtkit-daemon [ 1877] } hitcount: …
764 …{ id: sys_read [ 0], common_pid: console-kit-dae [ 3400] } hitcount: …
766 …{ id: sys_read [ 0], common_pid: deja-dup-monito [ 3543] } hitcount: …
768 …{ id: sys_read [ 0], common_pid: evolution-calen [ 3048] } hitcount: …
770 …{ id: sys_read [ 0], common_pid: nm-applet [ 3022] } hitcount: …
777 …{ id: sys_ioctl [ 16], common_pid: gnome-terminal [ 3199] } hitcount: …
783 …{ id: sys_waitid [247], common_pid: upstart-dbus-br [ 2690] } hitcount: …
784 …{ id: sys_waitid [247], common_pid: upstart-dbus-br [ 2688] } hitcount: …
792 …{ id: sys_eventfd2 [290], common_pid: ibus-ui-gtk3 [ 2760] } hitcount: …
807 /sys/kernel/tracing/events/raw_syscalls/sys_enter/trigger
810 …# trigger info: hist:keys=id.syscall,common_pid.execname:vals=hitcount:sort=id.syscall,hitcount:si…
813 …{ id: sys_ioctl [ 16], common_pid: evolution-addre [ 8571] } hitcount: …
827 …{ id: sys_ioctl [ 16], common_pid: avahi-daemon [ 896] } hitcount: …
841 The compound key examples used a key and a sum value (hitcount) to
850 /sys/kernel/tracing/events/syscalls/sys_enter_recvfrom/trigger
853 …# trigger info: hist:keys=common_pid.execname,size:vals=hitcount:sort=common_pid.execname,size:siz…
863 { common_pid: gnome-terminal [ 3199], size: 4 } hitcount: 2
893 key is treated as a single entity for hashing purposes, the sub-keys
897 demonstrates how you can manually pause and continue a hist trigger.
903 /sys/kernel/tracing/events/sched/sched_process_fork/trigger
906 # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [active]
909 { child_comm: ibus-daemon } hitcount: 1
915 { child_comm: evolution-alarm } hitcount: 2
920 { child_comm: evolution-sourc } hitcount: 4
923 { child_comm: nm-dispatcher.a } hitcount: 8
925 { child_comm: dbus-daemon } hitcount: 8
926 { child_comm: glib-pacrunner } hitcount: 10
934 If we want to pause the hist trigger, we can simply append :pause to
935 the command that started the trigger. Notice that the trigger info
939 /sys/kernel/tracing/events/sched/sched_process_fork/trigger
942 # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [paused]
948 { child_comm: ibus-daemon } hitcount: 1
950 { child_comm: evolution-alarm } hitcount: 2
955 { child_comm: evolution-sourc } hitcount: 4
961 { child_comm: dbus-daemon } hitcount: 20
962 { child_comm: nm-dispatcher.a } hitcount: 20
964 { child_comm: glib-pacrunner } hitcount: 59
971 To manually continue having the trigger aggregate events, append
972 :cont instead. Notice that the trigger info displays as [active]
976 /sys/kernel/tracing/events/sched/sched_process_fork/trigger
979 # trigger info: hist:keys=child_comm:vals=hitcount:sort=hitcount:size=256 [active]
985 { child_comm: ibus-daemon } hitcount: 1
987 { child_comm: evolution-alarm } hitcount: 2
991 { child_comm: evolution-sourc } hitcount: 4
998 { child_comm: dbus-daemon } hitcount: 22
999 { child_comm: nm-dispatcher.a } hitcount: 22
1001 { child_comm: glib-pacrunner } hitcount: 59
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
1011 starting the trigger with ':pause' appended. This allows you to
1012 start the trigger only when you're ready to start collecting data
1013 and not before. For example, you could start the trigger in a
1015 then pause the trigger again when done.
1017 Of course, doing this manually can be difficult and error-prone, but
1018 it is possible to automatically start and stop a hist trigger based
1023 netif_receive_skb event when downloading a decent-sized file using
1026 First we set up an initially paused stacktrace trigger on the
1030 /sys/kernel/tracing/events/net/netif_receive_skb/trigger
1032 Next, we set up an 'enable_hist' trigger on the sched_process_exec
1034 this new trigger is that it will 'unpause' the hist trigger we just
1041 /sys/kernel/tracing/events/sched/sched_process_exec/trigger
1049 /sys/kernel/tracing/events/sched/sched_process_exit/trigger
1052 trigger filter matches 'comm==wget', the netif_receive_skb hist
1053 trigger is disabled.
1060 $ wget https://www.kernel.org/pub/linux/kernel/v3.x/patch-3.19.xz
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.
1146 /sys/kernel/tracing/events/net/netif_receive_skb/trigger
1152 # trigger info: hist:keys=common_stacktrace:vals=len:sort=hitcount:size=2048 [paused]
1166 /sys/kernel/tracing/events/sched/sched_process_exec/trigger
1169 /sys/kernel/tracing/events/sched/sched_process_exit/trigger
1171 If you read the trigger files for the sched_process_exec and
1176 # cat /sys/kernel/tracing/events/sched/sched_process_exec/trigger
1180 # cat /sys/kernel/tracing/events/sched/sched_process_exit/trigger
1190 $ wget https://www.kernel.org/pub/linux/kernel/v3.x/patch-3.19.xz
1200 # entries-in-buffer/entries-written: 183/1426 #P:4
1202 # _-----=> irqs-off
1203 # / _----=> need-resched
1204 # | / _---=> hardirq/softirq
1205 # || / _--=> preempt-depth
1207 # TASK-PID CPU# |||| TIMESTAMP FUNCTION
1209 … wget-15108 [000] ..s1 31769.606929: netif_receive_skb: dev=lo skbaddr=ffff88009c353100 len=60
1210 … wget-15108 [000] ..s1 31769.606999: netif_receive_skb: dev=lo skbaddr=ffff88009c353200 len=60
1211 … dnsmasq-1382 [000] ..s1 31769.677652: netif_receive_skb: dev=lo skbaddr=ffff88009c352b00 len=130
1212 … dnsmasq-1382 [000] ..s1 31769.685917: netif_receive_skb: dev=lo skbaddr=ffff88009c352200 len=138
1214 …irq/29-iwlwifi-559 [002] ..s. 31772.031529: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d433d0…
1215 …irq/29-iwlwifi-559 [002] ..s. 31772.031572: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d43220…
1216 …irq/29-iwlwifi-559 [002] ..s. 31772.032196: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d43310…
1217 …irq/29-iwlwifi-559 [002] ..s. 31772.032761: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d43300…
1218 …irq/29-iwlwifi-559 [002] ..s. 31772.033220: netif_receive_skb: dev=wlan0 skbaddr=ffff88009d432e0…
1230 /sys/kernel/tracing/events/net/netif_receive_skb/trigger
1232 /sys/kernel/tracing/events/net/netif_receive_skb/trigger
1234 /sys/kernel/tracing/events/net/netif_receive_skb/trigger
1236 /sys/kernel/tracing/events/net/netif_receive_skb/trigger
1238 /sys/kernel/tracing/events/net/netif_receive_skb/trigger
1242 nonsensical trigger. Note that in order to append multiple hist
1244 append them ('>' will also add the new hist trigger, but will remove
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.
1371 /sys/kernel/tracing/events/net/netif_receive_skb/trigger
1373 /sys/kernel/tracing/events/net/netif_rx/trigger
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]
1492 /sys/kernel/tracing/events/sched/sched_process_fork/trigger
1494 /sys/kernel/tracing/events/net/netif_rx/trigger
1504 …# trigger info: hist:name=bar:keys=common_stacktrace:vals=hitcount:sort=hitcount:size=2048 [active]
1611 2.2 Inter-event hist triggers
1612 -----------------------------
1614 Inter-event hist triggers are hist triggers that combine values from
1616 from an inter-event histogram can in turn become the source for
1620 The most important example of an inter-event quantity that can be used
1623 inter-event quantity, note that because the support is completely
1625 in an inter-event quantity.
1632 Normally, a hist trigger specification consists of a (possibly
1635 specification in this case consists of individual key and value
1639 The inter-event hist trigger extension allows fields from multiple
1640 events to be referenced and combined into a multi-event histogram
1642 features have been added to the hist trigger support:
1644 - In order to compute an inter-event quantity, a value from one
1648 - The computation of inter-event quantities and their combination
1650 expressions to variables (+ and -).
1652 - A histogram consisting of inter-event quantities isn't logically a
1658 These synthetic events are full-fledged events just like any other
1662 - A set of 'actions' can be associated with histogram entries -
1667 - Trace events don't have a 'timestamp' associated with them, but
1672 field in the trace format but rather is a synthesized value that
1677 A note on inter-event timestamps: If common_timestamp is used in a
1682 trace clocks instead, using the "clock=XXX" hist trigger attribute,
1684 pseudo-file.
1689 -------------------------
1693 event that has a matching key - if a variable is saved for a histogram
1697 A variable's value is normally available to any subsequent event until
1700 'read-once' - once it's used by an expression in a subsequent event,
1715 event/trigger
1724 Because 'vals=' is used, the common_timestamp variable value above
1725 will also be summed as a normal histogram value would (though for a
1728 The below shows that a key value can also be saved in the same way::
1730 # echo 'hist:timer_pid=common_pid:key=timer_pid ...' >> event/trigger
1734 as a value::
1736 # echo 'hist:keys=next_pid:ts1=common_timestamp ...' >> event/trigger
1743 event/trigger
1750 event/trigger
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
1776 division operators (+-\*/).
1779 divisor is not a constant), the result will be -1.
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
1793 ----------------------
1795 Synthetic events are user-defined events generated from hist trigger
1847 instantiated in the event subsystem - for this to happen, a 'hist
1848 trigger action' needs to be instantiated and bound to actual fields
1850 how that is done using hist trigger 'onmatch' action). Once that is
1857 enable filter format hist id trigger
1862 /sys/kernel/tracing/events/synthetic/wakeup_latency/trigger
1873 # trigger info: hist:keys=pid,prio,lat.log2:vals=hitcount:sort=lat.log2:size=2048 [active]
1917 /sys/kernel/tracing/events/synthetic/wakeup_latency/trigger
1921 …# trigger info: hist:keys=pid,prio,lat.buckets=10:vals=hitcount:sort=lat.buckets=10:size=2048 [act…
1924 { pid: 2067, prio: 9, lat: ~ 0-9 } hitcount: 220
1925 { pid: 2068, prio: 9, lat: ~ 0-9 } hitcount: 157
1926 { pid: 2070, prio: 9, lat: ~ 0-9 } hitcount: 100
1927 { pid: 2067, prio: 120, lat: ~ 0-9 } hitcount: 6
1928 { pid: 2065, prio: 120, lat: ~ 0-9 } hitcount: 2
1929 { pid: 2066, prio: 120, lat: ~ 0-9 } hitcount: 2
1930 { pid: 2069, prio: 9, lat: ~ 0-9 } hitcount: 122
1931 { pid: 2069, prio: 120, lat: ~ 0-9 } hitcount: 8
1932 { pid: 2070, prio: 120, lat: ~ 0-9 } hitcount: 1
1933 { pid: 2068, prio: 120, lat: ~ 0-9 } hitcount: 7
1934 { pid: 2066, prio: 9, lat: ~ 0-9 } hitcount: 365
1935 { pid: 2064, prio: 120, lat: ~ 0-9 } hitcount: 35
1936 { pid: 2065, prio: 9, lat: ~ 0-9 } hitcount: 998
1937 { pid: 2071, prio: 9, lat: ~ 0-9 } hitcount: 85
1938 { pid: 2065, prio: 9, lat: ~ 10-19 } hitcount: 2
1939 { pid: 2064, prio: 120, lat: ~ 10-19 } hitcount: 2
1952 …mmon_timestamp.usecs,st=common_stacktrace if prev_state == 2' >> events/sched/sched_switch/trigger
1953 …elta=common_timestamp.usecs-$ts,s=$st:onmax($delta).trace(block_lat,prev_pid,$delta,$s)' >> events…
1959 # entries-in-buffer/entries-written: 2/2 #P:8
1961 # _-----=> irqs-off/BH-disabled
1962 # / _----=> need-resched
1963 # | / _---=> hardirq/softirq
1964 # || / _--=> preempt-depth
1965 # ||| / _-=> migrate-disable
1967 # TASK-PID CPU# ||||| TIMESTAMP FUNCTION
1969 <idle>-0 [005] d..4. 521.164922: block_lat: pid=0 delta=8322 stack=STACK:
1981 <...>-2 [004] d..4. 525.184257: block_lat: pid=2 delta=76 stack=STACK:
1996 …echo 'hist:keys=delta.buckets=100,stack.stacktrace:sort=delta' > events/synthetic/block_lat/trigger
2001 …# trigger info: hist:keys=delta.buckets=100,stack.stacktrace:vals=hitcount:sort=delta.buckets=100:…
2003 { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520
2015 { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520
2031 { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520
2047 { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520
2062 { delta: ~ 0-99, stack.stacktrace __schedule+0xa19/0x1520
2075 { delta: ~ 100-199, stack.stacktrace __schedule+0xa19/0x1520
2097 2.2.3 Hist trigger 'handlers' and 'actions'
2098 -------------------------------------------
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'
2107 Hist trigger handlers and actions are paired together in the general
2113 that handler.action pair between colons in the hist trigger
2119 trigger will fail with -EINVAL;
2133 - onmatch(matching.event) - invoke action on any addition or update
2134 - onmax(var) - invoke action if var exceeds current max
2135 - onchange(var) - invoke action if var changes
2139 - trace(<synthetic_event_name>,param list) - generate synthetic event
2140 - save(field,...) - save current event fields
2141 - snapshot() - snapshot the trace buffer
2143 The following commonly-used handler.action pairs are available:
2145 - onmatch(matching.event).trace(<synthetic_event_name>,param list)
2148 list)' hist trigger action is invoked whenever an event matches
2171 fields specified in the param list may be either fully-qualified
2176 fully-qualified name is of the form 'system.event_name.$var_name'
2201 The following hist trigger both defines the missing testpid
2209 /sys/kernel/tracing/events/sched/sched_wakeup_new/trigger
2215 /sys/kernel/tracing/events/sched/sched_wakeup_new/trigger
2222 /sys/kernel/tracing/events/synthetic/wakeup_new_test/trigger
2244 /sys/kernel/tracing/events/sched/sched_waking/trigger
2251 # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:\
2254 /sys/kernel/tracing/events/sched/sched_switch/trigger
2260 /sys/kernel/tracing/events/synthetic/wakeup_latency/trigger
2268 - onmax(var).save(field,.. .)
2270 The 'onmax(var).save(field,...)' hist trigger action is invoked
2271 whenever the value of 'var' associated with a histogram entry
2276 maximum for that hist trigger entry. This allows context from the
2292 /sys/kernel/tracing/events/sched/sched_waking/trigger
2295 wakeup_lat=common_timestamp.usecs-$ts0:\
2298 /sys/kernel/tracing/events/sched/sched_switch/trigger
2300 When the histogram is displayed, the max value and the saved
2306 common_timestamp-ts0: 0
2312 common_timestamp-ts0: 0
2321 - onmax(var).snapshot()
2323 The 'onmax(var).snapshot()' hist trigger action is invoked
2324 whenever the value of 'var' associated with a histogram entry
2329 maximum for any hist trigger entry.
2354 /sys/kernel/tracing/events/sched/sched_waking/trigger
2356 # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \
2360 /sys/kernel/tracing/events/sched/sched_switch/trigger
2362 When the histogram is displayed, for each bucket the max value
2367 along with the value and event that triggered the global maximum::
2383 triggering value { onmax($wakeup_lat) }: 572 \
2395 as the global maximum (since that was the same value that
2406 …<...>-2103 [005] d..3 309.873125: sched_switch: prev_comm=cyclictest prev_pid=2103 prev_prio=19…
2407 …<idle>-0 [005] d.h3 309.873611: sched_waking: comm=cyclictest pid=2102 prio=19 target_cpu=005
2408 …<idle>-0 [005] dNh4 309.873613: sched_wakeup: comm=cyclictest pid=2102 prio=19 target_cpu=005
2409 …<idle>-0 [005] d..3 309.873616: sched_switch: prev_comm=swapper/5 prev_pid=0 prev_prio=120 p…
2410 …<...>-2102 [005] d..3 309.873625: sched_switch: prev_comm=cyclictest prev_pid=2102 prev_prio=19…
2411 …<idle>-0 [005] d.h3 309.874624: sched_waking: comm=cyclictest pid=2102 prio=19 target_cpu=005
2412 …<idle>-0 [005] dNh4 309.874626: sched_wakeup: comm=cyclictest pid=2102 prio=19 target_cpu=005
2413 …<idle>-0 [005] dNh3 309.874628: sched_waking: comm=cyclictest pid=2103 prio=19 target_cpu=005
2414 …<idle>-0 [005] dNh4 309.874630: sched_wakeup: comm=cyclictest pid=2103 prio=19 target_cpu=005
2415 …<idle>-0 [005] d..3 309.874633: sched_switch: prev_comm=swapper/5 prev_pid=0 prev_prio=120 p…
2416 …<idle>-0 [004] d.h3 309.874757: sched_waking: comm=gnome-terminal- pid=1699 prio=120 target_…
2417 …<idle>-0 [004] dNh4 309.874762: sched_wakeup: comm=gnome-terminal- pid=1699 prio=120 target_…
2418 …<idle>-0 [004] d..3 309.874766: sched_switch: prev_comm=swapper/4 prev_pid=0 prev_prio=120 p…
2419 …gnome-terminal--1699 [004] d.h2 309.874941: sched_stat_runtime: comm=gnome-terminal- pid=1699 r…
2420 … <idle>-0 [003] d.s4 309.874956: sched_waking: comm=rcu_sched pid=9 prio=120 target_cpu=007
2421 <idle>-0 [003] d.s5 309.874960: sched_wake_idle_without_ipi: cpu=7
2422 … <idle>-0 [003] d.s5 309.874961: sched_wakeup: comm=rcu_sched pid=9 prio=120 target_cpu=007
2423 …<idle>-0 [007] d..3 309.874963: sched_switch: prev_comm=swapper/7 prev_pid=0 prev_prio=120 p…
2424 …rcu_sched-9 [007] d..3 309.874973: sched_stat_runtime: comm=rcu_sched pid=9 runtime=13646 [n…
2425 …rcu_sched-9 [007] d..3 309.874978: sched_switch: prev_comm=rcu_sched prev_pid=9 prev_prio=12…
2426 …<...>-2102 [005] d..4 309.874994: sched_migrate_task: comm=cyclictest pid=2103 prio=19 orig_cpu…
2427 <...>-2102 [005] d..4 309.875185: sched_wake_idle_without_ipi: cpu=1
2428 …<idle>-0 [001] d..3 309.875200: sched_switch: prev_comm=swapper/1 prev_pid=0 prev_prio=120 p…
2430 - onchange(var).save(field,.. .)
2432 The 'onchange(var).save(field,...)' hist trigger action is invoked
2433 whenever the value of 'var' associated with a histogram entry
2438 hist trigger entry. This allows context from the event that
2439 changed the value to be saved for later reference. When the
2443 - onchange(var).snapshot()
2445 The 'onchange(var).snapshot()' hist trigger action is invoked
2446 whenever the value of 'var' associated with a histogram entry
2451 hist trigger entry.
2453 Note that in this case the changed value is a global variable
2455 trace event that caused the value to change and the global value
2461 As an example the below defines a hist trigger on the tcp_probe
2463 cwnd field is checked against the current value stored in the
2464 $cwnd variable. If the value has changed, a snapshot is taken.
2475 /sys/kernel/tracing/events/tcp/tcp_probe/trigger
2477 When the histogram is displayed, for each bucket the tracked value
2478 and the saved values corresponding to that value are displayed
2482 along with the value and event that triggered the snapshot::
2500 triggering value { onchange($cwnd) }: 10
2511 changed value for that bucket, which should be the same as the
2512 global changed value (since that was the same value that triggered
2520 …gnome-shell-1261 [006] dN.3 49.823113: sched_stat_runtime: comm=gnome-shell pid=1261 runtime=4…
2521 …kworker/u16:4-773 [003] d..3 49.823114: sched_switch: prev_comm=kworker/u16:4 prev_pid=773 pr…
2522 …gnome-shell-1261 [006] d..3 49.823114: sched_switch: prev_comm=gnome-shell prev_pid=1261 prev_…
2523 …kworker/3:2-135 [003] d..3 49.823118: sched_stat_runtime: comm=kworker/3:2 pid=135 runtime=53…
2524 …kworker/6:2-387 [006] d..3 49.823120: sched_stat_runtime: comm=kworker/6:2 pid=387 runtime=95…
2525 …kworker/6:2-387 [006] d..3 49.823122: sched_switch: prev_comm=kworker/6:2 prev_pid=387 prev_p…
2526 …kworker/3:2-135 [003] d..3 49.823123: sched_switch: prev_comm=kworker/3:2 prev_pid=135 prev_p…
2527 …<idle>-0 [004] ..s7 49.823798: tcp_probe: src=10.0.0.10:54326 dest=23.215.104.193:80 mark=0…
2529 3. User space creating a trigger
2530 --------------------------------
2533 ring buffer. This can also act like an event, by writing into the trigger
2558 …o 'hist:keys=common_pid:ts0=common_timestamp.usecs if buf == "start"' > events/ftrace/print/trigger
2559 …n_pid:lat=common_timestamp.usecs-$ts0:onmatch(ftrace.print).latency($lat) if buf == "end"' >> even…
2560 # echo 'hist:keys=lat,common_pid:sort=lat' > events/synthetic/latency/trigger
2571 # ./cyclictest -p80 -d0 -i250 -n -a -t --tracemark -b 1000
2573 -p80 : run threads at priority 80
2574 -d0 : have all threads run at the same interval
2575 -i250 : start the interval at 250 microseconds (all threads will do this)
2576 -n : sleep with nanosleep
2577 -a : affine all threads to a separate CPU
2578 -t : one thread per available CPU
2579 --tracemark : enable trace mark writing
2580 -b 1000 : stop if any latency is greater than 1000 microseconds
2582 Note, the -b 1000 is used just to make --tracemark available.
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 …id:lat=common_timestamp.usecs-$ts0:onmatch(sched.sched_waking).latency($lat) if buf == "end"' > ev…
2891 # echo 'hist:keys=lat,common_pid:sort=lat' > events/synthetic/latency/trigger
2902 # trigger info: hist:keys=lat,common_pid:vals=hitcount:sort=lat:size=2048 [active]