|
1 | 1 | Event Tracing
|
2 | 2 |
|
3 | 3 | Documentation written by Theodore Ts'o
|
4 |
| - Updated by Li Zefan |
| 4 | + Updated by Li Zefan and Tom Zanussi |
5 | 5 |
|
6 | 6 | 1. Introduction
|
7 | 7 | ===============
|
@@ -97,3 +97,185 @@ The format of this boot option is the same as described in section 2.1.
|
97 | 97 |
|
98 | 98 | See The example provided in samples/trace_events
|
99 | 99 |
|
| 100 | +4. Event formats |
| 101 | +================ |
| 102 | + |
| 103 | +Each trace event has a 'format' file associated with it that contains |
| 104 | +a description of each field in a logged event. This information can |
| 105 | +be used to parse the binary trace stream, and is also the place to |
| 106 | +find the field names that can be used in event filters (see section 5). |
| 107 | + |
| 108 | +It also displays the format string that will be used to print the |
| 109 | +event in text mode, along with the event name and ID used for |
| 110 | +profiling. |
| 111 | + |
| 112 | +Every event has a set of 'common' fields associated with it; these are |
| 113 | +the fields prefixed with 'common_'. The other fields vary between |
| 114 | +events and correspond to the fields defined in the TRACE_EVENT |
| 115 | +definition for that event. |
| 116 | + |
| 117 | +Each field in the format has the form: |
| 118 | + |
| 119 | + field:field-type field-name; offset:N; size:N; |
| 120 | + |
| 121 | +where offset is the offset of the field in the trace record and size |
| 122 | +is the size of the data item, in bytes. |
| 123 | + |
| 124 | +For example, here's the information displayed for the 'sched_wakeup' |
| 125 | +event: |
| 126 | + |
| 127 | +# cat /debug/tracing/events/sched/sched_wakeup/format |
| 128 | + |
| 129 | +name: sched_wakeup |
| 130 | +ID: 60 |
| 131 | +format: |
| 132 | + field:unsigned short common_type; offset:0; size:2; |
| 133 | + field:unsigned char common_flags; offset:2; size:1; |
| 134 | + field:unsigned char common_preempt_count; offset:3; size:1; |
| 135 | + field:int common_pid; offset:4; size:4; |
| 136 | + field:int common_tgid; offset:8; size:4; |
| 137 | + |
| 138 | + field:char comm[TASK_COMM_LEN]; offset:12; size:16; |
| 139 | + field:pid_t pid; offset:28; size:4; |
| 140 | + field:int prio; offset:32; size:4; |
| 141 | + field:int success; offset:36; size:4; |
| 142 | + field:int cpu; offset:40; size:4; |
| 143 | + |
| 144 | +print fmt: "task %s:%d [%d] success=%d [%03d]", REC->comm, REC->pid, |
| 145 | + REC->prio, REC->success, REC->cpu |
| 146 | + |
| 147 | +This event contains 10 fields, the first 5 common and the remaining 5 |
| 148 | +event-specific. All the fields for this event are numeric, except for |
| 149 | +'comm' which is a string, a distinction important for event filtering. |
| 150 | + |
| 151 | +5. Event filtering |
| 152 | +================== |
| 153 | + |
| 154 | +Trace events can be filtered in the kernel by associating boolean |
| 155 | +'filter expressions' with them. As soon as an event is logged into |
| 156 | +the trace buffer, its fields are checked against the filter expression |
| 157 | +associated with that event type. An event with field values that |
| 158 | +'match' the filter will appear in the trace output, and an event whose |
| 159 | +values don't match will be discarded. An event with no filter |
| 160 | +associated with it matches everything, and is the default when no |
| 161 | +filter has been set for an event. |
| 162 | + |
| 163 | +5.1 Expression syntax |
| 164 | +--------------------- |
| 165 | + |
| 166 | +A filter expression consists of one or more 'predicates' that can be |
| 167 | +combined using the logical operators '&&' and '||'. A predicate is |
| 168 | +simply a clause that compares the value of a field contained within a |
| 169 | +logged event with a constant value and returns either 0 or 1 depending |
| 170 | +on whether the field value matched (1) or didn't match (0): |
| 171 | + |
| 172 | + field-name relational-operator value |
| 173 | + |
| 174 | +Parentheses can be used to provide arbitrary logical groupings and |
| 175 | +double-quotes can be used to prevent the shell from interpreting |
| 176 | +operators as shell metacharacters. |
| 177 | + |
| 178 | +The field-names available for use in filters can be found in the |
| 179 | +'format' files for trace events (see section 4). |
| 180 | + |
| 181 | +The relational-operators depend on the type of the field being tested: |
| 182 | + |
| 183 | +The operators available for numeric fields are: |
| 184 | + |
| 185 | +==, !=, <, <=, >, >= |
| 186 | + |
| 187 | +And for string fields they are: |
| 188 | + |
| 189 | +==, != |
| 190 | + |
| 191 | +Currently, only exact string matches are supported. |
| 192 | + |
| 193 | +Currently, the maximum number of predicates in a filter is 16. |
| 194 | + |
| 195 | +5.2 Setting filters |
| 196 | +------------------- |
| 197 | + |
| 198 | +A filter for an individual event is set by writing a filter expression |
| 199 | +to the 'filter' file for the given event. |
| 200 | + |
| 201 | +For example: |
| 202 | + |
| 203 | +# cd /debug/tracing/events/sched/sched_wakeup |
| 204 | +# echo "common_preempt_count > 4" > filter |
| 205 | + |
| 206 | +A slightly more involved example: |
| 207 | + |
| 208 | +# cd /debug/tracing/events/sched/sched_signal_send |
| 209 | +# echo "((sig >= 10 && sig < 15) || sig == 17) && comm != bash" > filter |
| 210 | + |
| 211 | +If there is an error in the expression, you'll get an 'Invalid |
| 212 | +argument' error when setting it, and the erroneous string along with |
| 213 | +an error message can be seen by looking at the filter e.g.: |
| 214 | + |
| 215 | +# cd /debug/tracing/events/sched/sched_signal_send |
| 216 | +# echo "((sig >= 10 && sig < 15) || dsig == 17) && comm != bash" > filter |
| 217 | +-bash: echo: write error: Invalid argument |
| 218 | +# cat filter |
| 219 | +((sig >= 10 && sig < 15) || dsig == 17) && comm != bash |
| 220 | +^ |
| 221 | +parse_error: Field not found |
| 222 | + |
| 223 | +Currently the caret ('^') for an error always appears at the beginning of |
| 224 | +the filter string; the error message should still be useful though |
| 225 | +even without more accurate position info. |
| 226 | + |
| 227 | +5.3 Clearing filters |
| 228 | +-------------------- |
| 229 | + |
| 230 | +To clear the filter for an event, write a '0' to the event's filter |
| 231 | +file. |
| 232 | + |
| 233 | +To clear the filters for all events in a subsystem, write a '0' to the |
| 234 | +subsystem's filter file. |
| 235 | + |
| 236 | +5.3 Subsystem filters |
| 237 | +--------------------- |
| 238 | + |
| 239 | +For convenience, filters for every event in a subsystem can be set or |
| 240 | +cleared as a group by writing a filter expression into the filter file |
| 241 | +at the root of the subsytem. Note however, that if a filter for any |
| 242 | +event within the subsystem lacks a field specified in the subsystem |
| 243 | +filter, or if the filter can't be applied for any other reason, the |
| 244 | +filter for that event will retain its previous setting. This can |
| 245 | +result in an unintended mixture of filters which could lead to |
| 246 | +confusing (to the user who might think different filters are in |
| 247 | +effect) trace output. Only filters that reference just the common |
| 248 | +fields can be guaranteed to propagate successfully to all events. |
| 249 | + |
| 250 | +Here are a few subsystem filter examples that also illustrate the |
| 251 | +above points: |
| 252 | + |
| 253 | +Clear the filters on all events in the sched subsytem: |
| 254 | + |
| 255 | +# cd /sys/kernel/debug/tracing/events/sched |
| 256 | +# echo 0 > filter |
| 257 | +# cat sched_switch/filter |
| 258 | +none |
| 259 | +# cat sched_wakeup/filter |
| 260 | +none |
| 261 | + |
| 262 | +Set a filter using only common fields for all events in the sched |
| 263 | +subsytem (all events end up with the same filter): |
| 264 | + |
| 265 | +# cd /sys/kernel/debug/tracing/events/sched |
| 266 | +# echo common_pid == 0 > filter |
| 267 | +# cat sched_switch/filter |
| 268 | +common_pid == 0 |
| 269 | +# cat sched_wakeup/filter |
| 270 | +common_pid == 0 |
| 271 | + |
| 272 | +Attempt to set a filter using a non-common field for all events in the |
| 273 | +sched subsytem (all events but those that have a prev_pid field retain |
| 274 | +their old filters): |
| 275 | + |
| 276 | +# cd /sys/kernel/debug/tracing/events/sched |
| 277 | +# echo prev_pid == 0 > filter |
| 278 | +# cat sched_switch/filter |
| 279 | +prev_pid == 0 |
| 280 | +# cat sched_wakeup/filter |
| 281 | +common_pid == 0 |
0 commit comments