Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 1 | Event Tracing |
| 2 | |
| 3 | Documentation written by Theodore Ts'o |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 4 | Updated by Li Zefan and Tom Zanussi |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 5 | |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 6 | 1. Introduction |
| 7 | =============== |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 8 | |
| 9 | Tracepoints (see Documentation/trace/tracepoints.txt) can be used |
| 10 | without creating custom kernel modules to register probe functions |
| 11 | using the event tracing infrastructure. |
| 12 | |
| 13 | Not all tracepoints can be traced using the event tracing system; |
| 14 | the kernel developer must provide code snippets which define how the |
| 15 | tracing information is saved into the tracing buffer, and how the |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 16 | tracing information should be printed. |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 17 | |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 18 | 2. Using Event Tracing |
| 19 | ====================== |
| 20 | |
| 21 | 2.1 Via the 'set_event' interface |
| 22 | --------------------------------- |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 23 | |
| 24 | The events which are available for tracing can be found in the file |
GeunSik Lim | 52ad51e | 2009-09-07 21:37:17 +0900 | [diff] [blame] | 25 | /sys/kernel/debug/tracing/available_events. |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 26 | |
| 27 | To enable a particular event, such as 'sched_wakeup', simply echo it |
GeunSik Lim | 52ad51e | 2009-09-07 21:37:17 +0900 | [diff] [blame] | 28 | to /sys/kernel/debug/tracing/set_event. For example: |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 29 | |
GeunSik Lim | 52ad51e | 2009-09-07 21:37:17 +0900 | [diff] [blame] | 30 | # echo sched_wakeup >> /sys/kernel/debug/tracing/set_event |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 31 | |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 32 | [ Note: '>>' is necessary, otherwise it will firstly disable |
| 33 | all the events. ] |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 34 | |
| 35 | To disable an event, echo the event name to the set_event file prefixed |
| 36 | with an exclamation point: |
| 37 | |
GeunSik Lim | 52ad51e | 2009-09-07 21:37:17 +0900 | [diff] [blame] | 38 | # echo '!sched_wakeup' >> /sys/kernel/debug/tracing/set_event |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 39 | |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 40 | To disable all events, echo an empty line to the set_event file: |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 41 | |
GeunSik Lim | 52ad51e | 2009-09-07 21:37:17 +0900 | [diff] [blame] | 42 | # echo > /sys/kernel/debug/tracing/set_event |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 43 | |
| 44 | To enable all events, echo '*:*' or '*:' to the set_event file: |
| 45 | |
GeunSik Lim | 52ad51e | 2009-09-07 21:37:17 +0900 | [diff] [blame] | 46 | # echo *:* > /sys/kernel/debug/tracing/set_event |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 47 | |
| 48 | The events are organized into subsystems, such as ext4, irq, sched, |
| 49 | etc., and a full event name looks like this: <subsystem>:<event>. The |
| 50 | subsystem name is optional, but it is displayed in the available_events |
| 51 | file. All of the events in a subsystem can be specified via the syntax |
| 52 | "<subsystem>:*"; for example, to enable all irq events, you can use the |
| 53 | command: |
| 54 | |
GeunSik Lim | 52ad51e | 2009-09-07 21:37:17 +0900 | [diff] [blame] | 55 | # echo 'irq:*' > /sys/kernel/debug/tracing/set_event |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 56 | |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 57 | 2.2 Via the 'enable' toggle |
| 58 | --------------------------- |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 59 | |
GeunSik Lim | 52ad51e | 2009-09-07 21:37:17 +0900 | [diff] [blame] | 60 | The events available are also listed in /sys/kernel/debug/tracing/events/ hierarchy |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 61 | of directories. |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 62 | |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 63 | To enable event 'sched_wakeup': |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 64 | |
GeunSik Lim | 52ad51e | 2009-09-07 21:37:17 +0900 | [diff] [blame] | 65 | # echo 1 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 66 | |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 67 | To disable it: |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 68 | |
GeunSik Lim | 52ad51e | 2009-09-07 21:37:17 +0900 | [diff] [blame] | 69 | # echo 0 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 70 | |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 71 | To enable all events in sched subsystem: |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 72 | |
GeunSik Lim | 52ad51e | 2009-09-07 21:37:17 +0900 | [diff] [blame] | 73 | # echo 1 > /sys/kernel/debug/tracing/events/sched/enable |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 74 | |
Michal Sojka | 6afb1c6 | 2009-09-10 08:02:21 +0200 | [diff] [blame] | 75 | To enable all events: |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 76 | |
GeunSik Lim | 52ad51e | 2009-09-07 21:37:17 +0900 | [diff] [blame] | 77 | # echo 1 > /sys/kernel/debug/tracing/events/enable |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 78 | |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 79 | When reading one of these enable files, there are four results: |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 80 | |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 81 | 0 - all events this file affects are disabled |
| 82 | 1 - all events this file affects are enabled |
| 83 | X - there is a mixture of events enabled and disabled |
| 84 | ? - this file does not affect any event |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 85 | |
Li Zefan | 020e5f8 | 2009-07-01 10:47:05 +0800 | [diff] [blame] | 86 | 2.3 Boot option |
| 87 | --------------- |
| 88 | |
| 89 | In order to facilitate early boot debugging, use boot option: |
| 90 | |
| 91 | trace_event=[event-list] |
| 92 | |
Li Zefan | 03d646e | 2009-12-21 14:27:24 +0800 | [diff] [blame] | 93 | event-list is a comma separated list of events. See section 2.1 for event |
| 94 | format. |
Li Zefan | 020e5f8 | 2009-07-01 10:47:05 +0800 | [diff] [blame] | 95 | |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 96 | 3. Defining an event-enabled tracepoint |
| 97 | ======================================= |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 98 | |
Li Zefan | 143c145 | 2009-05-19 14:43:15 +0800 | [diff] [blame] | 99 | See The example provided in samples/trace_events |
Theodore Ts'o | abd4144 | 2009-04-11 15:51:18 -0400 | [diff] [blame] | 100 | |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 101 | 4. Event formats |
| 102 | ================ |
| 103 | |
| 104 | Each trace event has a 'format' file associated with it that contains |
| 105 | a description of each field in a logged event. This information can |
| 106 | be used to parse the binary trace stream, and is also the place to |
| 107 | find the field names that can be used in event filters (see section 5). |
| 108 | |
| 109 | It also displays the format string that will be used to print the |
| 110 | event in text mode, along with the event name and ID used for |
| 111 | profiling. |
| 112 | |
| 113 | Every event has a set of 'common' fields associated with it; these are |
| 114 | the fields prefixed with 'common_'. The other fields vary between |
| 115 | events and correspond to the fields defined in the TRACE_EVENT |
| 116 | definition for that event. |
| 117 | |
| 118 | Each field in the format has the form: |
| 119 | |
| 120 | field:field-type field-name; offset:N; size:N; |
| 121 | |
| 122 | where offset is the offset of the field in the trace record and size |
| 123 | is the size of the data item, in bytes. |
| 124 | |
| 125 | For example, here's the information displayed for the 'sched_wakeup' |
| 126 | event: |
| 127 | |
Tao Ma | bfc672d | 2011-01-05 14:07:54 +0800 | [diff] [blame] | 128 | # cat /sys/kernel/debug/tracing/events/sched/sched_wakeup/format |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 129 | |
| 130 | name: sched_wakeup |
| 131 | ID: 60 |
| 132 | format: |
| 133 | field:unsigned short common_type; offset:0; size:2; |
| 134 | field:unsigned char common_flags; offset:2; size:1; |
| 135 | field:unsigned char common_preempt_count; offset:3; size:1; |
| 136 | field:int common_pid; offset:4; size:4; |
| 137 | field:int common_tgid; offset:8; size:4; |
| 138 | |
| 139 | field:char comm[TASK_COMM_LEN]; offset:12; size:16; |
| 140 | field:pid_t pid; offset:28; size:4; |
| 141 | field:int prio; offset:32; size:4; |
| 142 | field:int success; offset:36; size:4; |
| 143 | field:int cpu; offset:40; size:4; |
| 144 | |
| 145 | print fmt: "task %s:%d [%d] success=%d [%03d]", REC->comm, REC->pid, |
| 146 | REC->prio, REC->success, REC->cpu |
| 147 | |
| 148 | This event contains 10 fields, the first 5 common and the remaining 5 |
| 149 | event-specific. All the fields for this event are numeric, except for |
| 150 | 'comm' which is a string, a distinction important for event filtering. |
| 151 | |
| 152 | 5. Event filtering |
| 153 | ================== |
| 154 | |
| 155 | Trace events can be filtered in the kernel by associating boolean |
| 156 | 'filter expressions' with them. As soon as an event is logged into |
| 157 | the trace buffer, its fields are checked against the filter expression |
| 158 | associated with that event type. An event with field values that |
| 159 | 'match' the filter will appear in the trace output, and an event whose |
| 160 | values don't match will be discarded. An event with no filter |
| 161 | associated with it matches everything, and is the default when no |
| 162 | filter has been set for an event. |
| 163 | |
| 164 | 5.1 Expression syntax |
| 165 | --------------------- |
| 166 | |
| 167 | A filter expression consists of one or more 'predicates' that can be |
| 168 | combined using the logical operators '&&' and '||'. A predicate is |
| 169 | simply a clause that compares the value of a field contained within a |
| 170 | logged event with a constant value and returns either 0 or 1 depending |
| 171 | on whether the field value matched (1) or didn't match (0): |
| 172 | |
| 173 | field-name relational-operator value |
| 174 | |
| 175 | Parentheses can be used to provide arbitrary logical groupings and |
| 176 | double-quotes can be used to prevent the shell from interpreting |
| 177 | operators as shell metacharacters. |
| 178 | |
| 179 | The field-names available for use in filters can be found in the |
| 180 | 'format' files for trace events (see section 4). |
| 181 | |
| 182 | The relational-operators depend on the type of the field being tested: |
| 183 | |
| 184 | The operators available for numeric fields are: |
| 185 | |
Steven Rostedt | 1a891cf | 2013-06-12 13:16:25 -0400 | [diff] [blame] | 186 | ==, !=, <, <=, >, >=, & |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 187 | |
| 188 | And for string fields they are: |
| 189 | |
Steven Rostedt (Red Hat) | c3e13c7 | 2013-06-17 10:59:17 -0400 | [diff] [blame] | 190 | ==, !=, ~ |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 191 | |
Steven Rostedt (Red Hat) | c3e13c7 | 2013-06-17 10:59:17 -0400 | [diff] [blame] | 192 | The glob (~) only accepts a wild card character (*) at the start and or |
| 193 | end of the string. For example: |
| 194 | |
| 195 | prev_comm ~ "*sh" |
| 196 | prev_comm ~ "sh*" |
| 197 | prev_comm ~ "*sh*" |
| 198 | |
| 199 | But does not allow for it to be within the string: |
| 200 | |
| 201 | prev_comm ~ "ba*sh" <-- is invalid |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 202 | |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 203 | 5.2 Setting filters |
| 204 | ------------------- |
| 205 | |
| 206 | A filter for an individual event is set by writing a filter expression |
| 207 | to the 'filter' file for the given event. |
| 208 | |
| 209 | For example: |
| 210 | |
Tao Ma | bfc672d | 2011-01-05 14:07:54 +0800 | [diff] [blame] | 211 | # cd /sys/kernel/debug/tracing/events/sched/sched_wakeup |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 212 | # echo "common_preempt_count > 4" > filter |
| 213 | |
| 214 | A slightly more involved example: |
| 215 | |
Tao Ma | bfc672d | 2011-01-05 14:07:54 +0800 | [diff] [blame] | 216 | # cd /sys/kernel/debug/tracing/events/signal/signal_generate |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 217 | # echo "((sig >= 10 && sig < 15) || sig == 17) && comm != bash" > filter |
| 218 | |
| 219 | If there is an error in the expression, you'll get an 'Invalid |
| 220 | argument' error when setting it, and the erroneous string along with |
| 221 | an error message can be seen by looking at the filter e.g.: |
| 222 | |
Tao Ma | bfc672d | 2011-01-05 14:07:54 +0800 | [diff] [blame] | 223 | # cd /sys/kernel/debug/tracing/events/signal/signal_generate |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 224 | # echo "((sig >= 10 && sig < 15) || dsig == 17) && comm != bash" > filter |
| 225 | -bash: echo: write error: Invalid argument |
| 226 | # cat filter |
| 227 | ((sig >= 10 && sig < 15) || dsig == 17) && comm != bash |
| 228 | ^ |
| 229 | parse_error: Field not found |
| 230 | |
| 231 | Currently the caret ('^') for an error always appears at the beginning of |
| 232 | the filter string; the error message should still be useful though |
| 233 | even without more accurate position info. |
| 234 | |
| 235 | 5.3 Clearing filters |
| 236 | -------------------- |
| 237 | |
| 238 | To clear the filter for an event, write a '0' to the event's filter |
| 239 | file. |
| 240 | |
| 241 | To clear the filters for all events in a subsystem, write a '0' to the |
| 242 | subsystem's filter file. |
| 243 | |
| 244 | 5.3 Subsystem filters |
| 245 | --------------------- |
| 246 | |
| 247 | For convenience, filters for every event in a subsystem can be set or |
| 248 | cleared as a group by writing a filter expression into the filter file |
Thomas Weber | 8839316 | 2010-03-16 11:47:56 +0100 | [diff] [blame] | 249 | at the root of the subsystem. Note however, that if a filter for any |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 250 | event within the subsystem lacks a field specified in the subsystem |
| 251 | filter, or if the filter can't be applied for any other reason, the |
| 252 | filter for that event will retain its previous setting. This can |
| 253 | result in an unintended mixture of filters which could lead to |
| 254 | confusing (to the user who might think different filters are in |
| 255 | effect) trace output. Only filters that reference just the common |
| 256 | fields can be guaranteed to propagate successfully to all events. |
| 257 | |
| 258 | Here are a few subsystem filter examples that also illustrate the |
| 259 | above points: |
| 260 | |
Thomas Weber | 8839316 | 2010-03-16 11:47:56 +0100 | [diff] [blame] | 261 | Clear the filters on all events in the sched subsystem: |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 262 | |
| 263 | # cd /sys/kernel/debug/tracing/events/sched |
| 264 | # echo 0 > filter |
| 265 | # cat sched_switch/filter |
| 266 | none |
| 267 | # cat sched_wakeup/filter |
| 268 | none |
| 269 | |
| 270 | Set a filter using only common fields for all events in the sched |
Thomas Weber | 8839316 | 2010-03-16 11:47:56 +0100 | [diff] [blame] | 271 | subsystem (all events end up with the same filter): |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 272 | |
| 273 | # cd /sys/kernel/debug/tracing/events/sched |
| 274 | # echo common_pid == 0 > filter |
| 275 | # cat sched_switch/filter |
| 276 | common_pid == 0 |
| 277 | # cat sched_wakeup/filter |
| 278 | common_pid == 0 |
| 279 | |
| 280 | Attempt to set a filter using a non-common field for all events in the |
Thomas Weber | 8839316 | 2010-03-16 11:47:56 +0100 | [diff] [blame] | 281 | sched subsystem (all events but those that have a prev_pid field retain |
Tom Zanussi | 95b6960 | 2009-09-10 23:13:51 -0500 | [diff] [blame] | 282 | their old filters): |
| 283 | |
| 284 | # cd /sys/kernel/debug/tracing/events/sched |
| 285 | # echo prev_pid == 0 > filter |
| 286 | # cat sched_switch/filter |
| 287 | prev_pid == 0 |
| 288 | # cat sched_wakeup/filter |
| 289 | common_pid == 0 |
Tom Zanussi | ac38fb8 | 2013-10-24 08:59:30 -0500 | [diff] [blame] | 290 | |
Steven Rostedt (Red Hat) | 627645f | 2015-11-03 16:37:15 -0500 | [diff] [blame] | 291 | 5.4 PID filtering |
| 292 | ----------------- |
| 293 | |
| 294 | The set_event_pid file in the same directory as the top events directory |
| 295 | exists, will filter all events from tracing any task that does not have the |
| 296 | PID listed in the set_event_pid file. |
| 297 | |
| 298 | # cd /sys/kernel/debug/tracing |
| 299 | # echo $$ > set_event_pid |
| 300 | # echo 1 > events/enabled |
| 301 | |
| 302 | Will only trace events for the current task. |
| 303 | |
| 304 | To add more PIDs without losing the PIDs already included, use '>>'. |
| 305 | |
| 306 | # echo 123 244 1 >> set_event_pid |
| 307 | |
| 308 | |
Tom Zanussi | ac38fb8 | 2013-10-24 08:59:30 -0500 | [diff] [blame] | 309 | 6. Event triggers |
| 310 | ================= |
| 311 | |
| 312 | Trace events can be made to conditionally invoke trigger 'commands' |
| 313 | which can take various forms and are described in detail below; |
| 314 | examples would be enabling or disabling other trace events or invoking |
| 315 | a stack trace whenever the trace event is hit. Whenever a trace event |
| 316 | with attached triggers is invoked, the set of trigger commands |
| 317 | associated with that event is invoked. Any given trigger can |
| 318 | additionally have an event filter of the same form as described in |
| 319 | section 5 (Event filtering) associated with it - the command will only |
| 320 | be invoked if the event being invoked passes the associated filter. |
| 321 | If no filter is associated with the trigger, it always passes. |
| 322 | |
| 323 | Triggers are added to and removed from a particular event by writing |
| 324 | trigger expressions to the 'trigger' file for the given event. |
| 325 | |
| 326 | A given event can have any number of triggers associated with it, |
| 327 | subject to any restrictions that individual commands may have in that |
| 328 | regard. |
| 329 | |
| 330 | Event triggers are implemented on top of "soft" mode, which means that |
| 331 | whenever a trace event has one or more triggers associated with it, |
| 332 | the event is activated even if it isn't actually enabled, but is |
| 333 | disabled in a "soft" mode. That is, the tracepoint will be called, |
| 334 | but just will not be traced, unless of course it's actually enabled. |
| 335 | This scheme allows triggers to be invoked even for events that aren't |
| 336 | enabled, and also allows the current event filter implementation to be |
| 337 | used for conditionally invoking triggers. |
| 338 | |
| 339 | The syntax for event triggers is roughly based on the syntax for |
| 340 | set_ftrace_filter 'ftrace filter commands' (see the 'Filter commands' |
| 341 | section of Documentation/trace/ftrace.txt), but there are major |
| 342 | differences and the implementation isn't currently tied to it in any |
| 343 | way, so beware about making generalizations between the two. |
| 344 | |
| 345 | 6.1 Expression syntax |
| 346 | --------------------- |
| 347 | |
| 348 | Triggers are added by echoing the command to the 'trigger' file: |
| 349 | |
| 350 | # echo 'command[:count] [if filter]' > trigger |
| 351 | |
| 352 | Triggers are removed by echoing the same command but starting with '!' |
| 353 | to the 'trigger' file: |
| 354 | |
| 355 | # echo '!command[:count] [if filter]' > trigger |
| 356 | |
| 357 | The [if filter] part isn't used in matching commands when removing, so |
| 358 | leaving that off in a '!' command will accomplish the same thing as |
| 359 | having it in. |
| 360 | |
| 361 | The filter syntax is the same as that described in the 'Event |
| 362 | filtering' section above. |
| 363 | |
| 364 | For ease of use, writing to the trigger file using '>' currently just |
| 365 | adds or removes a single trigger and there's no explicit '>>' support |
| 366 | ('>' actually behaves like '>>') or truncation support to remove all |
| 367 | triggers (you have to use '!' for each one added.) |
| 368 | |
| 369 | 6.2 Supported trigger commands |
| 370 | ------------------------------ |
| 371 | |
| 372 | The following commands are supported: |
| 373 | |
| 374 | - enable_event/disable_event |
| 375 | |
| 376 | These commands can enable or disable another trace event whenever |
| 377 | the triggering event is hit. When these commands are registered, |
| 378 | the other trace event is activated, but disabled in a "soft" mode. |
| 379 | That is, the tracepoint will be called, but just will not be traced. |
| 380 | The event tracepoint stays in this mode as long as there's a trigger |
| 381 | in effect that can trigger it. |
| 382 | |
| 383 | For example, the following trigger causes kmalloc events to be |
| 384 | traced when a read system call is entered, and the :1 at the end |
| 385 | specifies that this enablement happens only once: |
| 386 | |
| 387 | # echo 'enable_event:kmem:kmalloc:1' > \ |
| 388 | /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger |
| 389 | |
| 390 | The following trigger causes kmalloc events to stop being traced |
| 391 | when a read system call exits. This disablement happens on every |
| 392 | read system call exit: |
| 393 | |
| 394 | # echo 'disable_event:kmem:kmalloc' > \ |
| 395 | /sys/kernel/debug/tracing/events/syscalls/sys_exit_read/trigger |
| 396 | |
| 397 | The format is: |
| 398 | |
| 399 | enable_event:<system>:<event>[:count] |
| 400 | disable_event:<system>:<event>[:count] |
| 401 | |
| 402 | To remove the above commands: |
| 403 | |
| 404 | # echo '!enable_event:kmem:kmalloc:1' > \ |
| 405 | /sys/kernel/debug/tracing/events/syscalls/sys_enter_read/trigger |
| 406 | |
| 407 | # echo '!disable_event:kmem:kmalloc' > \ |
| 408 | /sys/kernel/debug/tracing/events/syscalls/sys_exit_read/trigger |
| 409 | |
| 410 | Note that there can be any number of enable/disable_event triggers |
| 411 | per triggering event, but there can only be one trigger per |
| 412 | triggered event. e.g. sys_enter_read can have triggers enabling both |
| 413 | kmem:kmalloc and sched:sched_switch, but can't have two kmem:kmalloc |
| 414 | versions such as kmem:kmalloc and kmem:kmalloc:1 or 'kmem:kmalloc if |
| 415 | bytes_req == 256' and 'kmem:kmalloc if bytes_alloc == 256' (they |
| 416 | could be combined into a single filter on kmem:kmalloc though). |
| 417 | |
| 418 | - stacktrace |
| 419 | |
| 420 | This command dumps a stacktrace in the trace buffer whenever the |
| 421 | triggering event occurs. |
| 422 | |
| 423 | For example, the following trigger dumps a stacktrace every time the |
| 424 | kmalloc tracepoint is hit: |
| 425 | |
| 426 | # echo 'stacktrace' > \ |
| 427 | /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger |
| 428 | |
| 429 | The following trigger dumps a stacktrace the first 5 times a kmalloc |
| 430 | request happens with a size >= 64K |
| 431 | |
| 432 | # echo 'stacktrace:5 if bytes_req >= 65536' > \ |
| 433 | /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger |
| 434 | |
| 435 | The format is: |
| 436 | |
| 437 | stacktrace[:count] |
| 438 | |
| 439 | To remove the above commands: |
| 440 | |
| 441 | # echo '!stacktrace' > \ |
| 442 | /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger |
| 443 | |
| 444 | # echo '!stacktrace:5 if bytes_req >= 65536' > \ |
| 445 | /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger |
| 446 | |
| 447 | The latter can also be removed more simply by the following (without |
| 448 | the filter): |
| 449 | |
| 450 | # echo '!stacktrace:5' > \ |
| 451 | /sys/kernel/debug/tracing/events/kmem/kmalloc/trigger |
| 452 | |
| 453 | Note that there can be only one stacktrace trigger per triggering |
| 454 | event. |
| 455 | |
| 456 | - snapshot |
| 457 | |
| 458 | This command causes a snapshot to be triggered whenever the |
| 459 | triggering event occurs. |
| 460 | |
| 461 | The following command creates a snapshot every time a block request |
| 462 | queue is unplugged with a depth > 1. If you were tracing a set of |
| 463 | events or functions at the time, the snapshot trace buffer would |
Carlos Garcia | c98be0c | 2014-04-04 22:31:00 -0400 | [diff] [blame] | 464 | capture those events when the trigger event occurred: |
Tom Zanussi | ac38fb8 | 2013-10-24 08:59:30 -0500 | [diff] [blame] | 465 | |
| 466 | # echo 'snapshot if nr_rq > 1' > \ |
| 467 | /sys/kernel/debug/tracing/events/block/block_unplug/trigger |
| 468 | |
| 469 | To only snapshot once: |
| 470 | |
| 471 | # echo 'snapshot:1 if nr_rq > 1' > \ |
| 472 | /sys/kernel/debug/tracing/events/block/block_unplug/trigger |
| 473 | |
| 474 | To remove the above commands: |
| 475 | |
| 476 | # echo '!snapshot if nr_rq > 1' > \ |
| 477 | /sys/kernel/debug/tracing/events/block/block_unplug/trigger |
| 478 | |
| 479 | # echo '!snapshot:1 if nr_rq > 1' > \ |
| 480 | /sys/kernel/debug/tracing/events/block/block_unplug/trigger |
| 481 | |
| 482 | Note that there can be only one snapshot trigger per triggering |
| 483 | event. |
| 484 | |
| 485 | - traceon/traceoff |
| 486 | |
| 487 | These commands turn tracing on and off when the specified events are |
| 488 | hit. The parameter determines how many times the tracing system is |
| 489 | turned on and off. If unspecified, there is no limit. |
| 490 | |
| 491 | The following command turns tracing off the first time a block |
| 492 | request queue is unplugged with a depth > 1. If you were tracing a |
| 493 | set of events or functions at the time, you could then examine the |
| 494 | trace buffer to see the sequence of events that led up to the |
| 495 | trigger event: |
| 496 | |
| 497 | # echo 'traceoff:1 if nr_rq > 1' > \ |
| 498 | /sys/kernel/debug/tracing/events/block/block_unplug/trigger |
| 499 | |
| 500 | To always disable tracing when nr_rq > 1 : |
| 501 | |
| 502 | # echo 'traceoff if nr_rq > 1' > \ |
| 503 | /sys/kernel/debug/tracing/events/block/block_unplug/trigger |
| 504 | |
| 505 | To remove the above commands: |
| 506 | |
| 507 | # echo '!traceoff:1 if nr_rq > 1' > \ |
| 508 | /sys/kernel/debug/tracing/events/block/block_unplug/trigger |
| 509 | |
| 510 | # echo '!traceoff if nr_rq > 1' > \ |
| 511 | /sys/kernel/debug/tracing/events/block/block_unplug/trigger |
| 512 | |
| 513 | Note that there can be only one traceon or traceoff trigger per |
| 514 | triggering event. |