diff options
Diffstat (limited to 'Documentation/trace/events.txt')
-rw-r--r-- | Documentation/trace/events.txt | 210 |
1 files changed, 196 insertions, 14 deletions
diff --git a/Documentation/trace/events.txt b/Documentation/trace/events.txt index 2bcc8d4dea29..02ac6ed38b2d 100644 --- a/Documentation/trace/events.txt +++ b/Documentation/trace/events.txt | |||
@@ -1,7 +1,7 @@ | |||
1 | Event Tracing | 1 | Event Tracing |
2 | 2 | ||
3 | Documentation written by Theodore Ts'o | 3 | Documentation written by Theodore Ts'o |
4 | Updated by Li Zefan | 4 | Updated by Li Zefan and Tom Zanussi |
5 | 5 | ||
6 | 1. Introduction | 6 | 1. Introduction |
7 | =============== | 7 | =============== |
@@ -22,12 +22,12 @@ tracing information should be printed. | |||
22 | --------------------------------- | 22 | --------------------------------- |
23 | 23 | ||
24 | The events which are available for tracing can be found in the file | 24 | The events which are available for tracing can be found in the file |
25 | /debug/tracing/available_events. | 25 | /sys/kernel/debug/tracing/available_events. |
26 | 26 | ||
27 | To enable a particular event, such as 'sched_wakeup', simply echo it | 27 | To enable a particular event, such as 'sched_wakeup', simply echo it |
28 | to /debug/tracing/set_event. For example: | 28 | to /sys/kernel/debug/tracing/set_event. For example: |
29 | 29 | ||
30 | # echo sched_wakeup >> /debug/tracing/set_event | 30 | # echo sched_wakeup >> /sys/kernel/debug/tracing/set_event |
31 | 31 | ||
32 | [ Note: '>>' is necessary, otherwise it will firstly disable | 32 | [ Note: '>>' is necessary, otherwise it will firstly disable |
33 | all the events. ] | 33 | all the events. ] |
@@ -35,15 +35,15 @@ to /debug/tracing/set_event. For example: | |||
35 | To disable an event, echo the event name to the set_event file prefixed | 35 | To disable an event, echo the event name to the set_event file prefixed |
36 | with an exclamation point: | 36 | with an exclamation point: |
37 | 37 | ||
38 | # echo '!sched_wakeup' >> /debug/tracing/set_event | 38 | # echo '!sched_wakeup' >> /sys/kernel/debug/tracing/set_event |
39 | 39 | ||
40 | To disable all events, echo an empty line to the set_event file: | 40 | To disable all events, echo an empty line to the set_event file: |
41 | 41 | ||
42 | # echo > /debug/tracing/set_event | 42 | # echo > /sys/kernel/debug/tracing/set_event |
43 | 43 | ||
44 | To enable all events, echo '*:*' or '*:' to the set_event file: | 44 | To enable all events, echo '*:*' or '*:' to the set_event file: |
45 | 45 | ||
46 | # echo *:* > /debug/tracing/set_event | 46 | # echo *:* > /sys/kernel/debug/tracing/set_event |
47 | 47 | ||
48 | The events are organized into subsystems, such as ext4, irq, sched, | 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 | 49 | etc., and a full event name looks like this: <subsystem>:<event>. The |
@@ -52,29 +52,29 @@ 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 | 52 | "<subsystem>:*"; for example, to enable all irq events, you can use the |
53 | command: | 53 | command: |
54 | 54 | ||
55 | # echo 'irq:*' > /debug/tracing/set_event | 55 | # echo 'irq:*' > /sys/kernel/debug/tracing/set_event |
56 | 56 | ||
57 | 2.2 Via the 'enable' toggle | 57 | 2.2 Via the 'enable' toggle |
58 | --------------------------- | 58 | --------------------------- |
59 | 59 | ||
60 | The events available are also listed in /debug/tracing/events/ hierarchy | 60 | The events available are also listed in /sys/kernel/debug/tracing/events/ hierarchy |
61 | of directories. | 61 | of directories. |
62 | 62 | ||
63 | To enable event 'sched_wakeup': | 63 | To enable event 'sched_wakeup': |
64 | 64 | ||
65 | # echo 1 > /debug/tracing/events/sched/sched_wakeup/enable | 65 | # echo 1 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable |
66 | 66 | ||
67 | To disable it: | 67 | To disable it: |
68 | 68 | ||
69 | # echo 0 > /debug/tracing/events/sched/sched_wakeup/enable | 69 | # echo 0 > /sys/kernel/debug/tracing/events/sched/sched_wakeup/enable |
70 | 70 | ||
71 | To enable all events in sched subsystem: | 71 | To enable all events in sched subsystem: |
72 | 72 | ||
73 | # echo 1 > /debug/tracing/events/sched/enable | 73 | # echo 1 > /sys/kernel/debug/tracing/events/sched/enable |
74 | 74 | ||
75 | To eanble all events: | 75 | To enable all events: |
76 | 76 | ||
77 | # echo 1 > /debug/tracing/events/enable | 77 | # echo 1 > /sys/kernel/debug/tracing/events/enable |
78 | 78 | ||
79 | When reading one of these enable files, there are four results: | 79 | When reading one of these enable files, there are four results: |
80 | 80 | ||
@@ -97,3 +97,185 @@ The format of this boot option is the same as described in section 2.1. | |||
97 | 97 | ||
98 | See The example provided in samples/trace_events | 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 | ||