hc
2023-12-11 d2ccde1c8e90d38cee87a1b0309ad2827f3fd30d
kernel/Documentation/trace/histogram.rst
....@@ -25,7 +25,7 @@
2525
2626 hist:keys=<field1[,field2,...]>[:values=<field1[,field2,...]>]
2727 [:sort=<field1[,field2,...]>][:size=#entries][:pause][:continue]
28
- [:clear][:name=histname1] [if <filter>]
28
+ [:clear][:name=histname1][:<handler>.<action>] [if <filter>]
2929
3030 When a matching event is hit, an entry is added to a hash table
3131 using the key(s) and value(s) named. Keys and values correspond to
....@@ -39,7 +39,7 @@
3939 will use the event's kernel stacktrace as the key. The keywords
4040 'keys' or 'key' can be used to specify keys, and the keywords
4141 'values', 'vals', or 'val' can be used to specify values. Compound
42
- keys consisting of up to two fields can be specified by the 'keys'
42
+ keys consisting of up to three fields can be specified by the 'keys'
4343 keyword. Hashing a compound key produces a unique entry in the
4444 table for each unique combination of component keys, and can be
4545 useful for providing more fine-grained summaries of event data.
....@@ -199,20 +199,8 @@
199199
200200 For some error conditions encountered when invoking a hist trigger
201201 command, extended error information is available via the
202
- corresponding event's 'hist' file. Reading the hist file after an
203
- error will display more detailed information about what went wrong,
204
- if information is available. This extended error information will
205
- be available until the next hist trigger command for that event.
206
-
207
- If available for a given error condition, the extended error
208
- information and usage takes the following form::
209
-
210
- # echo xxx > /sys/kernel/debug/tracing/events/sched/sched_wakeup/trigger
211
- echo: write error: Invalid argument
212
-
213
- # cat /sys/kernel/debug/tracing/events/sched/sched_wakeup/hist
214
- ERROR: Couldn't yyy: zzz
215
- Last command: xxx
202
+ tracing/error_log file. See Error Conditions in
203
+ :file:`Documentation/trace/ftrace.rst` for details.
216204
217205 6.2 'hist' trigger examples
218206 ---------------------------
....@@ -1022,7 +1010,7 @@
10221010
10231011 For example, suppose we wanted to take a look at the relative
10241012 weights in terms of skb length for each callpath that leads to a
1025
- netif_receieve_skb event when downloading a decent-sized file using
1013
+ netif_receive_skb event when downloading a decent-sized file using
10261014 wget.
10271015
10281016 First we set up an initially paused stacktrace trigger on the
....@@ -1507,7 +1495,7 @@
15071495 #
15081496
15091497 { stacktrace:
1510
- _do_fork+0x18e/0x330
1498
+ kernel_clone+0x18e/0x330
15111499 kernel_thread+0x29/0x30
15121500 kthreadd+0x154/0x1b0
15131501 ret_from_fork+0x3f/0x70
....@@ -1600,7 +1588,7 @@
16001588 SYSC_sendto+0xef/0x170
16011589 } hitcount: 88
16021590 { stacktrace:
1603
- _do_fork+0x18e/0x330
1591
+ kernel_clone+0x18e/0x330
16041592 SyS_clone+0x19/0x20
16051593 entry_SYSCALL_64_fastpath+0x12/0x6a
16061594 } hitcount: 244
....@@ -1765,7 +1753,7 @@
17651753 # echo 'hist:keys=pid,prio:ts0=common_timestamp ...' >> event1/trigger
17661754 # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp-$ts0 ...' >> event2/trigger
17671755
1768
-In the first line above, the event's timetamp is saved into the
1756
+In the first line above, the event's timestamp is saved into the
17691757 variable ts0. In the next line, ts0 is subtracted from the second
17701758 event's timestamp to produce the latency, which is then assigned into
17711759 yet another variable, 'wakeup_lat'. The hist trigger below in turn
....@@ -1787,6 +1775,24 @@
17871775 consisting of the name of the new event along with one or more
17881776 variables and their types, which can be any valid field type,
17891777 separated by semicolons, to the tracing/synthetic_events file.
1778
+
1779
+See synth_field_size() for available types.
1780
+
1781
+If field_name contains [n], the field is considered to be a static array.
1782
+
1783
+If field_names contains[] (no subscript), the field is considered to
1784
+be a dynamic array, which will only take as much space in the event as
1785
+is required to hold the array.
1786
+
1787
+A string field can be specified using either the static notation:
1788
+
1789
+ char name[32];
1790
+
1791
+Or the dynamic:
1792
+
1793
+ char name[];
1794
+
1795
+The size limit for either is 256.
17901796
17911797 For instance, the following creates a new event named 'wakeup_latency'
17921798 with 3 fields: lat, pid, and prio. Each of those fields is simply a
....@@ -1811,7 +1817,7 @@
18111817 /sys/kernel/debug/tracing/synthetic_events
18121818
18131819 At this point, there isn't yet an actual 'wakeup_latency' event
1814
-instantiated in the event subsytem - for this to happen, a 'hist
1820
+instantiated in the event subsystem - for this to happen, a 'hist
18151821 trigger action' needs to be instantiated and bound to actual fields
18161822 and variables defined on other events (see Section 2.2.3 below on
18171823 how that is done using hist trigger 'onmatch' action). Once that is
....@@ -1831,45 +1837,94 @@
18311837 Like any other event, once a histogram is enabled for the event, the
18321838 output can be displayed by reading the event's 'hist' file.
18331839
1834
-2.2.3 Hist trigger 'actions'
1835
-----------------------------
1840
+2.2.3 Hist trigger 'handlers' and 'actions'
1841
+-------------------------------------------
18361842
1837
-A hist trigger 'action' is a function that's executed whenever a
1838
-histogram entry is added or updated.
1843
+A hist trigger 'action' is a function that's executed (in most cases
1844
+conditionally) whenever a histogram entry is added or updated.
18391845
1840
-The default 'action' if no special function is explicity specified is
1841
-as it always has been, to simply update the set of values associated
1842
-with an entry. Some applications, however, may want to perform
1843
-additional actions at that point, such as generate another event, or
1844
-compare and save a maximum.
1846
+When a histogram entry is added or updated, a hist trigger 'handler'
1847
+is what decides whether the corresponding action is actually invoked
1848
+or not.
18451849
1846
-The following additional actions are available. To specify an action
1847
-for a given event, simply specify the action between colons in the
1848
-hist trigger specification.
1850
+Hist trigger handlers and actions are paired together in the general
1851
+form:
18491852
1850
- - onmatch(matching.event).<synthetic_event_name>(param list)
1853
+ <handler>.<action>
18511854
1852
- The 'onmatch(matching.event).<synthetic_event_name>(params)' hist
1853
- trigger action is invoked whenever an event matches and the
1854
- histogram entry would be added or updated. It causes the named
1855
- synthetic event to be generated with the values given in the
1855
+To specify a handler.action pair for a given event, simply specify
1856
+that handler.action pair between colons in the hist trigger
1857
+specification.
1858
+
1859
+In theory, any handler can be combined with any action, but in
1860
+practice, not every handler.action combination is currently supported;
1861
+if a given handler.action combination isn't supported, the hist
1862
+trigger will fail with -EINVAL;
1863
+
1864
+The default 'handler.action' if none is explicitly specified is as it
1865
+always has been, to simply update the set of values associated with an
1866
+entry. Some applications, however, may want to perform additional
1867
+actions at that point, such as generate another event, or compare and
1868
+save a maximum.
1869
+
1870
+The supported handlers and actions are listed below, and each is
1871
+described in more detail in the following paragraphs, in the context
1872
+of descriptions of some common and useful handler.action combinations.
1873
+
1874
+The available handlers are:
1875
+
1876
+ - onmatch(matching.event) - invoke action on any addition or update
1877
+ - onmax(var) - invoke action if var exceeds current max
1878
+ - onchange(var) - invoke action if var changes
1879
+
1880
+The available actions are:
1881
+
1882
+ - trace(<synthetic_event_name>,param list) - generate synthetic event
1883
+ - save(field,...) - save current event fields
1884
+ - snapshot() - snapshot the trace buffer
1885
+
1886
+The following commonly-used handler.action pairs are available:
1887
+
1888
+ - onmatch(matching.event).trace(<synthetic_event_name>,param list)
1889
+
1890
+ The 'onmatch(matching.event).trace(<synthetic_event_name>,param
1891
+ list)' hist trigger action is invoked whenever an event matches
1892
+ and the histogram entry would be added or updated. It causes the
1893
+ named synthetic event to be generated with the values given in the
18561894 'param list'. The result is the generation of a synthetic event
18571895 that consists of the values contained in those variables at the
1858
- time the invoking event was hit.
1896
+ time the invoking event was hit. For example, if the synthetic
1897
+ event name is 'wakeup_latency', a wakeup_latency event is
1898
+ generated using onmatch(event).trace(wakeup_latency,arg1,arg2).
18591899
1860
- The 'param list' consists of one or more parameters which may be
1861
- either variables or fields defined on either the 'matching.event'
1862
- or the target event. The variables or fields specified in the
1863
- param list may be either fully-qualified or unqualified. If a
1864
- variable is specified as unqualified, it must be unique between
1865
- the two events. A field name used as a param can be unqualified
1866
- if it refers to the target event, but must be fully qualified if
1867
- it refers to the matching event. A fully-qualified name is of the
1868
- form 'system.event_name.$var_name' or 'system.event_name.field'.
1900
+ There is also an equivalent alternative form available for
1901
+ generating synthetic events. In this form, the synthetic event
1902
+ name is used as if it were a function name. For example, using
1903
+ the 'wakeup_latency' synthetic event name again, the
1904
+ wakeup_latency event would be generated by invoking it as if it
1905
+ were a function call, with the event field values passed in as
1906
+ arguments: onmatch(event).wakeup_latency(arg1,arg2). The syntax
1907
+ for this form is:
1908
+
1909
+ onmatch(matching.event).<synthetic_event_name>(param list)
1910
+
1911
+ In either case, the 'param list' consists of one or more
1912
+ parameters which may be either variables or fields defined on
1913
+ either the 'matching.event' or the target event. The variables or
1914
+ fields specified in the param list may be either fully-qualified
1915
+ or unqualified. If a variable is specified as unqualified, it
1916
+ must be unique between the two events. A field name used as a
1917
+ param can be unqualified if it refers to the target event, but
1918
+ must be fully qualified if it refers to the matching event. A
1919
+ fully-qualified name is of the form 'system.event_name.$var_name'
1920
+ or 'system.event_name.field'.
18691921
18701922 The 'matching.event' specification is simply the fully qualified
18711923 event name of the event that matches the target event for the
1872
- onmatch() functionality, in the form 'system.event_name'.
1924
+ onmatch() functionality, in the form 'system.event_name'. Histogram
1925
+ keys of both events are compared to find if events match. In case
1926
+ multiple histogram keys are used, they all must match in the specified
1927
+ order.
18731928
18741929 Finally, the number and type of variables/fields in the 'param
18751930 list' must match the number and types of the fields in the
....@@ -1895,6 +1950,12 @@
18951950 # echo 'hist:keys=$testpid:testpid=pid:onmatch(sched.sched_wakeup_new).\
18961951 wakeup_new_test($testpid) if comm=="cyclictest"' >> \
18971952 /sys/kernel/debug/tracing/events/sched/sched_wakeup_new/trigger
1953
+
1954
+ Or, equivalently, using the 'trace' keyword syntax:
1955
+
1956
+ # echo 'hist:keys=$testpid:testpid=pid:onmatch(sched.sched_wakeup_new).\
1957
+ trace(wakeup_new_test,$testpid) if comm=="cyclictest"' >> \
1958
+ /sys/kernel/debug/tracing/events/sched/sched_wakeup_new/trigger
18981959
18991960 Creating and displaying a histogram based on those events is now
19001961 just a matter of using the fields and new synthetic event in the
....@@ -1926,9 +1987,9 @@
19261987 /sys/kernel/debug/tracing/events/sched/sched_waking/trigger
19271988
19281989 Then, when the corresponding thread is actually scheduled onto the
1929
- CPU by a sched_switch event, calculate the latency and use that
1930
- along with another variable and an event field to generate a
1931
- wakeup_latency synthetic event::
1990
+ CPU by a sched_switch event (saved_pid matches next_pid), calculate
1991
+ the latency and use that along with another variable and an event field
1992
+ to generate a wakeup_latency synthetic event::
19321993
19331994 # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:\
19341995 onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,\
....@@ -2000,6 +2061,214 @@
20002061 Entries: 2
20012062 Dropped: 0
20022063
2064
+ - onmax(var).snapshot()
2065
+
2066
+ The 'onmax(var).snapshot()' hist trigger action is invoked
2067
+ whenever the value of 'var' associated with a histogram entry
2068
+ exceeds the current maximum contained in that variable.
2069
+
2070
+ The end result is that a global snapshot of the trace buffer will
2071
+ be saved in the tracing/snapshot file if 'var' exceeds the current
2072
+ maximum for any hist trigger entry.
2073
+
2074
+ Note that in this case the maximum is a global maximum for the
2075
+ current trace instance, which is the maximum across all buckets of
2076
+ the histogram. The key of the specific trace event that caused
2077
+ the global maximum and the global maximum itself are displayed,
2078
+ along with a message stating that a snapshot has been taken and
2079
+ where to find it. The user can use the key information displayed
2080
+ to locate the corresponding bucket in the histogram for even more
2081
+ detail.
2082
+
2083
+ As an example the below defines a couple of hist triggers, one for
2084
+ sched_waking and another for sched_switch, keyed on pid. Whenever
2085
+ a sched_waking event occurs, the timestamp is saved in the entry
2086
+ corresponding to the current pid, and when the scheduler switches
2087
+ back to that pid, the timestamp difference is calculated. If the
2088
+ resulting latency, stored in wakeup_lat, exceeds the current
2089
+ maximum latency, a snapshot is taken. As part of the setup, all
2090
+ the scheduler events are also enabled, which are the events that
2091
+ will show up in the snapshot when it is taken at some point:
2092
+
2093
+ # echo 1 > /sys/kernel/debug/tracing/events/sched/enable
2094
+
2095
+ # echo 'hist:keys=pid:ts0=common_timestamp.usecs \
2096
+ if comm=="cyclictest"' >> \
2097
+ /sys/kernel/debug/tracing/events/sched/sched_waking/trigger
2098
+
2099
+ # echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0: \
2100
+ onmax($wakeup_lat).save(next_prio,next_comm,prev_pid,prev_prio, \
2101
+ prev_comm):onmax($wakeup_lat).snapshot() \
2102
+ if next_comm=="cyclictest"' >> \
2103
+ /sys/kernel/debug/tracing/events/sched/sched_switch/trigger
2104
+
2105
+ When the histogram is displayed, for each bucket the max value
2106
+ and the saved values corresponding to the max are displayed
2107
+ following the rest of the fields.
2108
+
2109
+ If a snapshot was taken, there is also a message indicating that,
2110
+ along with the value and event that triggered the global maximum:
2111
+
2112
+ # cat /sys/kernel/debug/tracing/events/sched/sched_switch/hist
2113
+ { next_pid: 2101 } hitcount: 200
2114
+ max: 52 next_prio: 120 next_comm: cyclictest \
2115
+ prev_pid: 0 prev_prio: 120 prev_comm: swapper/6
2116
+
2117
+ { next_pid: 2103 } hitcount: 1326
2118
+ max: 572 next_prio: 19 next_comm: cyclictest \
2119
+ prev_pid: 0 prev_prio: 120 prev_comm: swapper/1
2120
+
2121
+ { next_pid: 2102 } hitcount: 1982 \
2122
+ max: 74 next_prio: 19 next_comm: cyclictest \
2123
+ prev_pid: 0 prev_prio: 120 prev_comm: swapper/5
2124
+
2125
+ Snapshot taken (see tracing/snapshot). Details:
2126
+ triggering value { onmax($wakeup_lat) }: 572 \
2127
+ triggered by event with key: { next_pid: 2103 }
2128
+
2129
+ Totals:
2130
+ Hits: 3508
2131
+ Entries: 3
2132
+ Dropped: 0
2133
+
2134
+ In the above case, the event that triggered the global maximum has
2135
+ the key with next_pid == 2103. If you look at the bucket that has
2136
+ 2103 as the key, you'll find the additional values save()'d along
2137
+ with the local maximum for that bucket, which should be the same
2138
+ as the global maximum (since that was the same value that
2139
+ triggered the global snapshot).
2140
+
2141
+ And finally, looking at the snapshot data should show at or near
2142
+ the end the event that triggered the snapshot (in this case you
2143
+ can verify the timestamps between the sched_waking and
2144
+ sched_switch events, which should match the time displayed in the
2145
+ global maximum)::
2146
+
2147
+ # cat /sys/kernel/debug/tracing/snapshot
2148
+
2149
+ <...>-2103 [005] d..3 309.873125: sched_switch: prev_comm=cyclictest prev_pid=2103 prev_prio=19 prev_state=D ==> next_comm=swapper/5 next_pid=0 next_prio=120
2150
+ <idle>-0 [005] d.h3 309.873611: sched_waking: comm=cyclictest pid=2102 prio=19 target_cpu=005
2151
+ <idle>-0 [005] dNh4 309.873613: sched_wakeup: comm=cyclictest pid=2102 prio=19 target_cpu=005
2152
+ <idle>-0 [005] d..3 309.873616: sched_switch: prev_comm=swapper/5 prev_pid=0 prev_prio=120 prev_state=S ==> next_comm=cyclictest next_pid=2102 next_prio=19
2153
+ <...>-2102 [005] d..3 309.873625: sched_switch: prev_comm=cyclictest prev_pid=2102 prev_prio=19 prev_state=D ==> next_comm=swapper/5 next_pid=0 next_prio=120
2154
+ <idle>-0 [005] d.h3 309.874624: sched_waking: comm=cyclictest pid=2102 prio=19 target_cpu=005
2155
+ <idle>-0 [005] dNh4 309.874626: sched_wakeup: comm=cyclictest pid=2102 prio=19 target_cpu=005
2156
+ <idle>-0 [005] dNh3 309.874628: sched_waking: comm=cyclictest pid=2103 prio=19 target_cpu=005
2157
+ <idle>-0 [005] dNh4 309.874630: sched_wakeup: comm=cyclictest pid=2103 prio=19 target_cpu=005
2158
+ <idle>-0 [005] d..3 309.874633: sched_switch: prev_comm=swapper/5 prev_pid=0 prev_prio=120 prev_state=S ==> next_comm=cyclictest next_pid=2102 next_prio=19
2159
+ <idle>-0 [004] d.h3 309.874757: sched_waking: comm=gnome-terminal- pid=1699 prio=120 target_cpu=004
2160
+ <idle>-0 [004] dNh4 309.874762: sched_wakeup: comm=gnome-terminal- pid=1699 prio=120 target_cpu=004
2161
+ <idle>-0 [004] d..3 309.874766: sched_switch: prev_comm=swapper/4 prev_pid=0 prev_prio=120 prev_state=S ==> next_comm=gnome-terminal- next_pid=1699 next_prio=120
2162
+ gnome-terminal--1699 [004] d.h2 309.874941: sched_stat_runtime: comm=gnome-terminal- pid=1699 runtime=180706 [ns] vruntime=1126870572 [ns]
2163
+ <idle>-0 [003] d.s4 309.874956: sched_waking: comm=rcu_sched pid=9 prio=120 target_cpu=007
2164
+ <idle>-0 [003] d.s5 309.874960: sched_wake_idle_without_ipi: cpu=7
2165
+ <idle>-0 [003] d.s5 309.874961: sched_wakeup: comm=rcu_sched pid=9 prio=120 target_cpu=007
2166
+ <idle>-0 [007] d..3 309.874963: sched_switch: prev_comm=swapper/7 prev_pid=0 prev_prio=120 prev_state=S ==> next_comm=rcu_sched next_pid=9 next_prio=120
2167
+ rcu_sched-9 [007] d..3 309.874973: sched_stat_runtime: comm=rcu_sched pid=9 runtime=13646 [ns] vruntime=22531430286 [ns]
2168
+ rcu_sched-9 [007] d..3 309.874978: sched_switch: prev_comm=rcu_sched prev_pid=9 prev_prio=120 prev_state=R+ ==> next_comm=swapper/7 next_pid=0 next_prio=120
2169
+ <...>-2102 [005] d..4 309.874994: sched_migrate_task: comm=cyclictest pid=2103 prio=19 orig_cpu=5 dest_cpu=1
2170
+ <...>-2102 [005] d..4 309.875185: sched_wake_idle_without_ipi: cpu=1
2171
+ <idle>-0 [001] d..3 309.875200: sched_switch: prev_comm=swapper/1 prev_pid=0 prev_prio=120 prev_state=S ==> next_comm=cyclictest next_pid=2103 next_prio=19
2172
+
2173
+ - onchange(var).save(field,.. .)
2174
+
2175
+ The 'onchange(var).save(field,...)' hist trigger action is invoked
2176
+ whenever the value of 'var' associated with a histogram entry
2177
+ changes.
2178
+
2179
+ The end result is that the trace event fields specified as the
2180
+ onchange.save() params will be saved if 'var' changes for that
2181
+ hist trigger entry. This allows context from the event that
2182
+ changed the value to be saved for later reference. When the
2183
+ histogram is displayed, additional fields displaying the saved
2184
+ values will be printed.
2185
+
2186
+ - onchange(var).snapshot()
2187
+
2188
+ The 'onchange(var).snapshot()' hist trigger action is invoked
2189
+ whenever the value of 'var' associated with a histogram entry
2190
+ changes.
2191
+
2192
+ The end result is that a global snapshot of the trace buffer will
2193
+ be saved in the tracing/snapshot file if 'var' changes for any
2194
+ hist trigger entry.
2195
+
2196
+ Note that in this case the changed value is a global variable
2197
+ associated with current trace instance. The key of the specific
2198
+ trace event that caused the value to change and the global value
2199
+ itself are displayed, along with a message stating that a snapshot
2200
+ has been taken and where to find it. The user can use the key
2201
+ information displayed to locate the corresponding bucket in the
2202
+ histogram for even more detail.
2203
+
2204
+ As an example the below defines a hist trigger on the tcp_probe
2205
+ event, keyed on dport. Whenever a tcp_probe event occurs, the
2206
+ cwnd field is checked against the current value stored in the
2207
+ $cwnd variable. If the value has changed, a snapshot is taken.
2208
+ As part of the setup, all the scheduler and tcp events are also
2209
+ enabled, which are the events that will show up in the snapshot
2210
+ when it is taken at some point:
2211
+
2212
+ # echo 1 > /sys/kernel/debug/tracing/events/sched/enable
2213
+ # echo 1 > /sys/kernel/debug/tracing/events/tcp/enable
2214
+
2215
+ # echo 'hist:keys=dport:cwnd=snd_cwnd: \
2216
+ onchange($cwnd).save(snd_wnd,srtt,rcv_wnd): \
2217
+ onchange($cwnd).snapshot()' >> \
2218
+ /sys/kernel/debug/tracing/events/tcp/tcp_probe/trigger
2219
+
2220
+ When the histogram is displayed, for each bucket the tracked value
2221
+ and the saved values corresponding to that value are displayed
2222
+ following the rest of the fields.
2223
+
2224
+ If a snapshot was taken, there is also a message indicating that,
2225
+ along with the value and event that triggered the snapshot::
2226
+
2227
+ # cat /sys/kernel/debug/tracing/events/tcp/tcp_probe/hist
2228
+
2229
+ { dport: 1521 } hitcount: 8
2230
+ changed: 10 snd_wnd: 35456 srtt: 154262 rcv_wnd: 42112
2231
+
2232
+ { dport: 80 } hitcount: 23
2233
+ changed: 10 snd_wnd: 28960 srtt: 19604 rcv_wnd: 29312
2234
+
2235
+ { dport: 9001 } hitcount: 172
2236
+ changed: 10 snd_wnd: 48384 srtt: 260444 rcv_wnd: 55168
2237
+
2238
+ { dport: 443 } hitcount: 211
2239
+ changed: 10 snd_wnd: 26960 srtt: 17379 rcv_wnd: 28800
2240
+
2241
+ Snapshot taken (see tracing/snapshot). Details::
2242
+
2243
+ triggering value { onchange($cwnd) }: 10
2244
+ triggered by event with key: { dport: 80 }
2245
+
2246
+ Totals:
2247
+ Hits: 414
2248
+ Entries: 4
2249
+ Dropped: 0
2250
+
2251
+ In the above case, the event that triggered the snapshot has the
2252
+ key with dport == 80. If you look at the bucket that has 80 as
2253
+ the key, you'll find the additional values save()'d along with the
2254
+ changed value for that bucket, which should be the same as the
2255
+ global changed value (since that was the same value that triggered
2256
+ the global snapshot).
2257
+
2258
+ And finally, looking at the snapshot data should show at or near
2259
+ the end the event that triggered the snapshot::
2260
+
2261
+ # cat /sys/kernel/debug/tracing/snapshot
2262
+
2263
+ gnome-shell-1261 [006] dN.3 49.823113: sched_stat_runtime: comm=gnome-shell pid=1261 runtime=49347 [ns] vruntime=1835730389 [ns]
2264
+ kworker/u16:4-773 [003] d..3 49.823114: sched_switch: prev_comm=kworker/u16:4 prev_pid=773 prev_prio=120 prev_state=R+ ==> next_comm=kworker/3:2 next_pid=135 next_prio=120
2265
+ gnome-shell-1261 [006] d..3 49.823114: sched_switch: prev_comm=gnome-shell prev_pid=1261 prev_prio=120 prev_state=R+ ==> next_comm=kworker/6:2 next_pid=387 next_prio=120
2266
+ kworker/3:2-135 [003] d..3 49.823118: sched_stat_runtime: comm=kworker/3:2 pid=135 runtime=5339 [ns] vruntime=17815800388 [ns]
2267
+ kworker/6:2-387 [006] d..3 49.823120: sched_stat_runtime: comm=kworker/6:2 pid=387 runtime=9594 [ns] vruntime=14589605367 [ns]
2268
+ kworker/6:2-387 [006] d..3 49.823122: sched_switch: prev_comm=kworker/6:2 prev_pid=387 prev_prio=120 prev_state=R+ ==> next_comm=gnome-shell next_pid=1261 next_prio=120
2269
+ kworker/3:2-135 [003] d..3 49.823123: sched_switch: prev_comm=kworker/3:2 prev_pid=135 prev_prio=120 prev_state=T ==> next_comm=swapper/3 next_pid=0 next_prio=120
2270
+ <idle>-0 [004] ..s7 49.823798: tcp_probe: src=10.0.0.10:54326 dest=23.215.104.193:80 mark=0x0 length=32 snd_nxt=0xe3ae2ff5 snd_una=0xe3ae2ecd snd_cwnd=10 ssthresh=2147483647 snd_wnd=28960 srtt=19604 rcv_wnd=29312
2271
+
20032272 3. User space creating a trigger
20042273 --------------------------------
20052274