Commit | Line | Data |
---|---|---|
b2441318 | 1 | // SPDX-License-Identifier: GPL-2.0 |
fb52607a FW |
2 | /* |
3 | * | |
4 | * Function graph tracer. | |
9005f3eb | 5 | * Copyright (c) 2008-2009 Frederic Weisbecker <fweisbec@gmail.com> |
fb52607a FW |
6 | * Mostly borrowed from function tracer which |
7 | * is Copyright (c) Steven Rostedt <srostedt@redhat.com> | |
8 | * | |
9 | */ | |
fb52607a FW |
10 | #include <linux/uaccess.h> |
11 | #include <linux/ftrace.h> | |
be7635e7 | 12 | #include <linux/interrupt.h> |
5a0e3ad6 | 13 | #include <linux/slab.h> |
fb52607a FW |
14 | #include <linux/fs.h> |
15 | ||
16 | #include "trace.h" | |
f0868d1e | 17 | #include "trace_output.h" |
fb52607a | 18 | |
b304d044 SR |
19 | /* When set, irq functions will be ignored */ |
20 | static int ftrace_graph_skip_irqs; | |
21 | ||
be1eca39 | 22 | struct fgraph_cpu_data { |
2fbcdb35 SR |
23 | pid_t last_pid; |
24 | int depth; | |
2bd16212 | 25 | int depth_irq; |
be1eca39 | 26 | int ignore; |
f1c7f517 | 27 | unsigned long enter_funcs[FTRACE_RETFUNC_DEPTH]; |
be1eca39 JO |
28 | }; |
29 | ||
30 | struct fgraph_data { | |
6016ee13 | 31 | struct fgraph_cpu_data __percpu *cpu_data; |
be1eca39 JO |
32 | |
33 | /* Place to preserve last processed entry. */ | |
34 | struct ftrace_graph_ent_entry ent; | |
35 | struct ftrace_graph_ret_entry ret; | |
36 | int failed; | |
37 | int cpu; | |
2fbcdb35 SR |
38 | }; |
39 | ||
287b6e68 | 40 | #define TRACE_GRAPH_INDENT 2 |
fb52607a | 41 | |
1a414428 | 42 | unsigned int fgraph_max_depth; |
8741db53 | 43 | |
fb52607a | 44 | static struct tracer_opt trace_opts[] = { |
9005f3eb | 45 | /* Display overruns? (for self-debug purpose) */ |
1a056155 FW |
46 | { TRACER_OPT(funcgraph-overrun, TRACE_GRAPH_PRINT_OVERRUN) }, |
47 | /* Display CPU ? */ | |
48 | { TRACER_OPT(funcgraph-cpu, TRACE_GRAPH_PRINT_CPU) }, | |
49 | /* Display Overhead ? */ | |
50 | { TRACER_OPT(funcgraph-overhead, TRACE_GRAPH_PRINT_OVERHEAD) }, | |
11e84acc FW |
51 | /* Display proc name/pid */ |
52 | { TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) }, | |
9005f3eb FW |
53 | /* Display duration of execution */ |
54 | { TRACER_OPT(funcgraph-duration, TRACE_GRAPH_PRINT_DURATION) }, | |
55 | /* Display absolute time of an entry */ | |
56 | { TRACER_OPT(funcgraph-abstime, TRACE_GRAPH_PRINT_ABS_TIME) }, | |
2bd16212 JO |
57 | /* Display interrupts */ |
58 | { TRACER_OPT(funcgraph-irqs, TRACE_GRAPH_PRINT_IRQS) }, | |
607e3a29 RE |
59 | /* Display function name after trailing } */ |
60 | { TRACER_OPT(funcgraph-tail, TRACE_GRAPH_PRINT_TAIL) }, | |
55577204 SRRH |
61 | /* Include sleep time (scheduled out) between entry and return */ |
62 | { TRACER_OPT(sleep-time, TRACE_GRAPH_SLEEP_TIME) }, | |
c8dd0f45 SRV |
63 | |
64 | #ifdef CONFIG_FUNCTION_PROFILER | |
55577204 SRRH |
65 | /* Include time within nested functions */ |
66 | { TRACER_OPT(graph-time, TRACE_GRAPH_GRAPH_TIME) }, | |
c8dd0f45 SRV |
67 | #endif |
68 | ||
fb52607a FW |
69 | { } /* Empty entry */ |
70 | }; | |
71 | ||
72 | static struct tracer_flags tracer_flags = { | |
607e3a29 | 73 | /* Don't display overruns, proc, or tail by default */ |
9005f3eb | 74 | .val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD | |
55577204 SRRH |
75 | TRACE_GRAPH_PRINT_DURATION | TRACE_GRAPH_PRINT_IRQS | |
76 | TRACE_GRAPH_SLEEP_TIME | TRACE_GRAPH_GRAPH_TIME, | |
fb52607a FW |
77 | .opts = trace_opts |
78 | }; | |
79 | ||
1a0799a8 | 80 | static struct trace_array *graph_array; |
9005f3eb | 81 | |
ffeb80fc JO |
82 | /* |
83 | * DURATION column is being also used to display IRQ signs, | |
84 | * following values are used by print_graph_irq and others | |
85 | * to fill in space into DURATION column. | |
86 | */ | |
87 | enum { | |
6fc84ea7 SRRH |
88 | FLAGS_FILL_FULL = 1 << TRACE_GRAPH_PRINT_FILL_SHIFT, |
89 | FLAGS_FILL_START = 2 << TRACE_GRAPH_PRINT_FILL_SHIFT, | |
90 | FLAGS_FILL_END = 3 << TRACE_GRAPH_PRINT_FILL_SHIFT, | |
ffeb80fc JO |
91 | }; |
92 | ||
9d9add34 | 93 | static void |
983f938a SRRH |
94 | print_graph_duration(struct trace_array *tr, unsigned long long duration, |
95 | struct trace_seq *s, u32 flags); | |
fb52607a | 96 | |
62b915f1 | 97 | int __trace_graph_entry(struct trace_array *tr, |
1a0799a8 FW |
98 | struct ftrace_graph_ent *trace, |
99 | unsigned long flags, | |
100 | int pc) | |
101 | { | |
2425bcb9 | 102 | struct trace_event_call *call = &event_funcgraph_entry; |
1a0799a8 | 103 | struct ring_buffer_event *event; |
12883efb | 104 | struct ring_buffer *buffer = tr->trace_buffer.buffer; |
1a0799a8 FW |
105 | struct ftrace_graph_ent_entry *entry; |
106 | ||
e77405ad | 107 | event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_ENT, |
1a0799a8 FW |
108 | sizeof(*entry), flags, pc); |
109 | if (!event) | |
110 | return 0; | |
111 | entry = ring_buffer_event_data(event); | |
112 | entry->graph_ent = *trace; | |
f306cc82 | 113 | if (!call_filter_check_discard(call, entry, buffer, event)) |
52ffabe3 | 114 | trace_buffer_unlock_commit_nostack(buffer, event); |
1a0799a8 FW |
115 | |
116 | return 1; | |
117 | } | |
118 | ||
b304d044 SR |
119 | static inline int ftrace_graph_ignore_irqs(void) |
120 | { | |
e4a3f541 | 121 | if (!ftrace_graph_skip_irqs || trace_recursion_test(TRACE_IRQ_BIT)) |
b304d044 SR |
122 | return 0; |
123 | ||
124 | return in_irq(); | |
125 | } | |
126 | ||
1a0799a8 FW |
127 | int trace_graph_entry(struct ftrace_graph_ent *trace) |
128 | { | |
129 | struct trace_array *tr = graph_array; | |
130 | struct trace_array_cpu *data; | |
131 | unsigned long flags; | |
132 | long disabled; | |
133 | int ret; | |
134 | int cpu; | |
135 | int pc; | |
136 | ||
9cd2992f SRV |
137 | if (trace_recursion_test(TRACE_GRAPH_NOTRACE_BIT)) |
138 | return 0; | |
139 | ||
140 | if (ftrace_graph_notrace_addr(trace->func)) { | |
141 | trace_recursion_set(TRACE_GRAPH_NOTRACE_BIT); | |
142 | /* | |
143 | * Need to return 1 to have the return called | |
144 | * that will clear the NOTRACE bit. | |
145 | */ | |
146 | return 1; | |
147 | } | |
148 | ||
345ddcc8 | 149 | if (!ftrace_trace_task(tr)) |
1a0799a8 FW |
150 | return 0; |
151 | ||
1a414428 SRRH |
152 | if (ftrace_graph_ignore_func(trace)) |
153 | return 0; | |
154 | ||
155 | if (ftrace_graph_ignore_irqs()) | |
1a0799a8 FW |
156 | return 0; |
157 | ||
29ad23b0 NK |
158 | /* |
159 | * Do not trace a function if it's filtered by set_graph_notrace. | |
160 | * Make the index of ret stack negative to indicate that it should | |
161 | * ignore further functions. But it needs its own ret stack entry | |
162 | * to recover the original index in order to continue tracing after | |
163 | * returning from the function. | |
164 | */ | |
165 | if (ftrace_graph_notrace_addr(trace->func)) | |
166 | return 1; | |
167 | ||
7fa8b717 JF |
168 | /* |
169 | * Stop here if tracing_threshold is set. We only write function return | |
170 | * events to the ring buffer. | |
171 | */ | |
172 | if (tracing_thresh) | |
173 | return 1; | |
174 | ||
1a0799a8 FW |
175 | local_irq_save(flags); |
176 | cpu = raw_smp_processor_id(); | |
12883efb | 177 | data = per_cpu_ptr(tr->trace_buffer.data, cpu); |
1a0799a8 FW |
178 | disabled = atomic_inc_return(&data->disabled); |
179 | if (likely(disabled == 1)) { | |
180 | pc = preempt_count(); | |
181 | ret = __trace_graph_entry(tr, trace, flags, pc); | |
182 | } else { | |
183 | ret = 0; | |
184 | } | |
1a0799a8 FW |
185 | |
186 | atomic_dec(&data->disabled); | |
187 | local_irq_restore(flags); | |
188 | ||
189 | return ret; | |
190 | } | |
191 | ||
0a772620 JO |
192 | static void |
193 | __trace_graph_function(struct trace_array *tr, | |
194 | unsigned long ip, unsigned long flags, int pc) | |
195 | { | |
196 | u64 time = trace_clock_local(); | |
197 | struct ftrace_graph_ent ent = { | |
198 | .func = ip, | |
199 | .depth = 0, | |
200 | }; | |
201 | struct ftrace_graph_ret ret = { | |
202 | .func = ip, | |
203 | .depth = 0, | |
204 | .calltime = time, | |
205 | .rettime = time, | |
206 | }; | |
207 | ||
208 | __trace_graph_entry(tr, &ent, flags, pc); | |
209 | __trace_graph_return(tr, &ret, flags, pc); | |
210 | } | |
211 | ||
212 | void | |
213 | trace_graph_function(struct trace_array *tr, | |
214 | unsigned long ip, unsigned long parent_ip, | |
215 | unsigned long flags, int pc) | |
216 | { | |
0a772620 JO |
217 | __trace_graph_function(tr, ip, flags, pc); |
218 | } | |
219 | ||
62b915f1 | 220 | void __trace_graph_return(struct trace_array *tr, |
1a0799a8 FW |
221 | struct ftrace_graph_ret *trace, |
222 | unsigned long flags, | |
223 | int pc) | |
224 | { | |
2425bcb9 | 225 | struct trace_event_call *call = &event_funcgraph_exit; |
1a0799a8 | 226 | struct ring_buffer_event *event; |
12883efb | 227 | struct ring_buffer *buffer = tr->trace_buffer.buffer; |
1a0799a8 FW |
228 | struct ftrace_graph_ret_entry *entry; |
229 | ||
e77405ad | 230 | event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_RET, |
1a0799a8 FW |
231 | sizeof(*entry), flags, pc); |
232 | if (!event) | |
233 | return; | |
234 | entry = ring_buffer_event_data(event); | |
235 | entry->ret = *trace; | |
f306cc82 | 236 | if (!call_filter_check_discard(call, entry, buffer, event)) |
52ffabe3 | 237 | trace_buffer_unlock_commit_nostack(buffer, event); |
1a0799a8 FW |
238 | } |
239 | ||
240 | void trace_graph_return(struct ftrace_graph_ret *trace) | |
241 | { | |
242 | struct trace_array *tr = graph_array; | |
243 | struct trace_array_cpu *data; | |
244 | unsigned long flags; | |
245 | long disabled; | |
246 | int cpu; | |
247 | int pc; | |
248 | ||
5cf99a0f SRV |
249 | ftrace_graph_addr_finish(trace); |
250 | ||
9cd2992f SRV |
251 | if (trace_recursion_test(TRACE_GRAPH_NOTRACE_BIT)) { |
252 | trace_recursion_clear(TRACE_GRAPH_NOTRACE_BIT); | |
253 | return; | |
254 | } | |
255 | ||
1a0799a8 FW |
256 | local_irq_save(flags); |
257 | cpu = raw_smp_processor_id(); | |
12883efb | 258 | data = per_cpu_ptr(tr->trace_buffer.data, cpu); |
1a0799a8 FW |
259 | disabled = atomic_inc_return(&data->disabled); |
260 | if (likely(disabled == 1)) { | |
261 | pc = preempt_count(); | |
262 | __trace_graph_return(tr, trace, flags, pc); | |
263 | } | |
1a0799a8 FW |
264 | atomic_dec(&data->disabled); |
265 | local_irq_restore(flags); | |
266 | } | |
267 | ||
24a53652 FW |
268 | void set_graph_array(struct trace_array *tr) |
269 | { | |
270 | graph_array = tr; | |
271 | ||
272 | /* Make graph_array visible before we start tracing */ | |
273 | ||
274 | smp_mb(); | |
275 | } | |
276 | ||
ba1afef6 | 277 | static void trace_graph_thresh_return(struct ftrace_graph_ret *trace) |
0e950173 | 278 | { |
5cf99a0f SRV |
279 | ftrace_graph_addr_finish(trace); |
280 | ||
9cd2992f SRV |
281 | if (trace_recursion_test(TRACE_GRAPH_NOTRACE_BIT)) { |
282 | trace_recursion_clear(TRACE_GRAPH_NOTRACE_BIT); | |
283 | return; | |
284 | } | |
285 | ||
0e950173 TB |
286 | if (tracing_thresh && |
287 | (trace->rettime - trace->calltime < tracing_thresh)) | |
288 | return; | |
289 | else | |
290 | trace_graph_return(trace); | |
291 | } | |
292 | ||
688f7089 SRV |
293 | static struct fgraph_ops funcgraph_thresh_ops = { |
294 | .entryfunc = &trace_graph_entry, | |
295 | .retfunc = &trace_graph_thresh_return, | |
296 | }; | |
297 | ||
298 | static struct fgraph_ops funcgraph_ops = { | |
299 | .entryfunc = &trace_graph_entry, | |
300 | .retfunc = &trace_graph_return, | |
301 | }; | |
302 | ||
fb52607a FW |
303 | static int graph_trace_init(struct trace_array *tr) |
304 | { | |
1a0799a8 FW |
305 | int ret; |
306 | ||
24a53652 | 307 | set_graph_array(tr); |
0e950173 | 308 | if (tracing_thresh) |
688f7089 | 309 | ret = register_ftrace_graph(&funcgraph_thresh_ops); |
0e950173 | 310 | else |
688f7089 | 311 | ret = register_ftrace_graph(&funcgraph_ops); |
660c7f9b SR |
312 | if (ret) |
313 | return ret; | |
314 | tracing_start_cmdline_record(); | |
315 | ||
316 | return 0; | |
fb52607a FW |
317 | } |
318 | ||
319 | static void graph_trace_reset(struct trace_array *tr) | |
320 | { | |
660c7f9b | 321 | tracing_stop_cmdline_record(); |
688f7089 SRV |
322 | if (tracing_thresh) |
323 | unregister_ftrace_graph(&funcgraph_thresh_ops); | |
324 | else | |
325 | unregister_ftrace_graph(&funcgraph_ops); | |
fb52607a FW |
326 | } |
327 | ||
ba1afef6 | 328 | static int graph_trace_update_thresh(struct trace_array *tr) |
6508fa76 SF |
329 | { |
330 | graph_trace_reset(tr); | |
331 | return graph_trace_init(tr); | |
332 | } | |
333 | ||
0c9e6f63 | 334 | static int max_bytes_for_cpu; |
1a056155 | 335 | |
9d9add34 | 336 | static void print_graph_cpu(struct trace_seq *s, int cpu) |
1a056155 | 337 | { |
d51090b3 IM |
338 | /* |
339 | * Start with a space character - to make it stand out | |
340 | * to the right a bit when trace output is pasted into | |
341 | * email: | |
342 | */ | |
9d9add34 | 343 | trace_seq_printf(s, " %*d) ", max_bytes_for_cpu, cpu); |
1a056155 FW |
344 | } |
345 | ||
11e84acc FW |
346 | #define TRACE_GRAPH_PROCINFO_LENGTH 14 |
347 | ||
9d9add34 | 348 | static void print_graph_proc(struct trace_seq *s, pid_t pid) |
11e84acc | 349 | { |
4ca53085 | 350 | char comm[TASK_COMM_LEN]; |
11e84acc FW |
351 | /* sign + log10(MAX_INT) + '\0' */ |
352 | char pid_str[11]; | |
4ca53085 | 353 | int spaces = 0; |
4ca53085 SR |
354 | int len; |
355 | int i; | |
11e84acc | 356 | |
4ca53085 | 357 | trace_find_cmdline(pid, comm); |
11e84acc FW |
358 | comm[7] = '\0'; |
359 | sprintf(pid_str, "%d", pid); | |
360 | ||
361 | /* 1 stands for the "-" character */ | |
362 | len = strlen(comm) + strlen(pid_str) + 1; | |
363 | ||
364 | if (len < TRACE_GRAPH_PROCINFO_LENGTH) | |
365 | spaces = TRACE_GRAPH_PROCINFO_LENGTH - len; | |
366 | ||
367 | /* First spaces to align center */ | |
9d9add34 SRRH |
368 | for (i = 0; i < spaces / 2; i++) |
369 | trace_seq_putc(s, ' '); | |
11e84acc | 370 | |
9d9add34 | 371 | trace_seq_printf(s, "%s-%s", comm, pid_str); |
11e84acc FW |
372 | |
373 | /* Last spaces to align center */ | |
9d9add34 SRRH |
374 | for (i = 0; i < spaces - (spaces / 2); i++) |
375 | trace_seq_putc(s, ' '); | |
11e84acc FW |
376 | } |
377 | ||
1a056155 | 378 | |
9d9add34 | 379 | static void print_graph_lat_fmt(struct trace_seq *s, struct trace_entry *entry) |
49ff5903 | 380 | { |
9d9add34 SRRH |
381 | trace_seq_putc(s, ' '); |
382 | trace_print_lat_fmt(s, entry); | |
afbab501 | 383 | trace_seq_puts(s, " | "); |
49ff5903 SR |
384 | } |
385 | ||
287b6e68 | 386 | /* If the pid changed since the last trace, output this event */ |
9d9add34 | 387 | static void |
2fbcdb35 | 388 | verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data) |
287b6e68 | 389 | { |
d51090b3 | 390 | pid_t prev_pid; |
9005f3eb | 391 | pid_t *last_pid; |
660c7f9b | 392 | |
2fbcdb35 | 393 | if (!data) |
9d9add34 | 394 | return; |
9005f3eb | 395 | |
be1eca39 | 396 | last_pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid); |
9005f3eb FW |
397 | |
398 | if (*last_pid == pid) | |
9d9add34 | 399 | return; |
fb52607a | 400 | |
9005f3eb FW |
401 | prev_pid = *last_pid; |
402 | *last_pid = pid; | |
d51090b3 | 403 | |
9005f3eb | 404 | if (prev_pid == -1) |
9d9add34 | 405 | return; |
d51090b3 IM |
406 | /* |
407 | * Context-switch trace line: | |
408 | ||
409 | ------------------------------------------ | |
410 | | 1) migration/0--1 => sshd-1755 | |
411 | ------------------------------------------ | |
412 | ||
413 | */ | |
9d9add34 SRRH |
414 | trace_seq_puts(s, " ------------------------------------------\n"); |
415 | print_graph_cpu(s, cpu); | |
416 | print_graph_proc(s, prev_pid); | |
417 | trace_seq_puts(s, " => "); | |
418 | print_graph_proc(s, pid); | |
419 | trace_seq_puts(s, "\n ------------------------------------------\n\n"); | |
287b6e68 FW |
420 | } |
421 | ||
b91facc3 FW |
422 | static struct ftrace_graph_ret_entry * |
423 | get_return_for_leaf(struct trace_iterator *iter, | |
83a8df61 FW |
424 | struct ftrace_graph_ent_entry *curr) |
425 | { | |
be1eca39 JO |
426 | struct fgraph_data *data = iter->private; |
427 | struct ring_buffer_iter *ring_iter = NULL; | |
83a8df61 FW |
428 | struct ring_buffer_event *event; |
429 | struct ftrace_graph_ret_entry *next; | |
430 | ||
be1eca39 JO |
431 | /* |
432 | * If the previous output failed to write to the seq buffer, | |
433 | * then we just reuse the data from before. | |
434 | */ | |
435 | if (data && data->failed) { | |
436 | curr = &data->ent; | |
437 | next = &data->ret; | |
438 | } else { | |
83a8df61 | 439 | |
6d158a81 | 440 | ring_iter = trace_buffer_iter(iter, iter->cpu); |
be1eca39 JO |
441 | |
442 | /* First peek to compare current entry and the next one */ | |
443 | if (ring_iter) | |
444 | event = ring_buffer_iter_peek(ring_iter, NULL); | |
445 | else { | |
446 | /* | |
447 | * We need to consume the current entry to see | |
448 | * the next one. | |
449 | */ | |
12883efb | 450 | ring_buffer_consume(iter->trace_buffer->buffer, iter->cpu, |
66a8cb95 | 451 | NULL, NULL); |
12883efb | 452 | event = ring_buffer_peek(iter->trace_buffer->buffer, iter->cpu, |
66a8cb95 | 453 | NULL, NULL); |
be1eca39 | 454 | } |
83a8df61 | 455 | |
be1eca39 JO |
456 | if (!event) |
457 | return NULL; | |
458 | ||
459 | next = ring_buffer_event_data(event); | |
83a8df61 | 460 | |
be1eca39 JO |
461 | if (data) { |
462 | /* | |
463 | * Save current and next entries for later reference | |
464 | * if the output fails. | |
465 | */ | |
466 | data->ent = *curr; | |
575570f0 SL |
467 | /* |
468 | * If the next event is not a return type, then | |
469 | * we only care about what type it is. Otherwise we can | |
470 | * safely copy the entire event. | |
471 | */ | |
472 | if (next->ent.type == TRACE_GRAPH_RET) | |
473 | data->ret = *next; | |
474 | else | |
475 | data->ret.ent.type = next->ent.type; | |
be1eca39 JO |
476 | } |
477 | } | |
83a8df61 FW |
478 | |
479 | if (next->ent.type != TRACE_GRAPH_RET) | |
b91facc3 | 480 | return NULL; |
83a8df61 FW |
481 | |
482 | if (curr->ent.pid != next->ent.pid || | |
483 | curr->graph_ent.func != next->ret.func) | |
b91facc3 | 484 | return NULL; |
83a8df61 | 485 | |
b91facc3 FW |
486 | /* this is a leaf, now advance the iterator */ |
487 | if (ring_iter) | |
488 | ring_buffer_read(ring_iter, NULL); | |
489 | ||
490 | return next; | |
83a8df61 FW |
491 | } |
492 | ||
9d9add34 | 493 | static void print_graph_abs_time(u64 t, struct trace_seq *s) |
d1f9cbd7 FW |
494 | { |
495 | unsigned long usecs_rem; | |
496 | ||
497 | usecs_rem = do_div(t, NSEC_PER_SEC); | |
498 | usecs_rem /= 1000; | |
499 | ||
9d9add34 SRRH |
500 | trace_seq_printf(s, "%5lu.%06lu | ", |
501 | (unsigned long)t, usecs_rem); | |
d1f9cbd7 FW |
502 | } |
503 | ||
9acd8de6 CD |
504 | static void |
505 | print_graph_rel_time(struct trace_iterator *iter, struct trace_seq *s) | |
506 | { | |
507 | unsigned long long usecs; | |
508 | ||
509 | usecs = iter->ts - iter->trace_buffer->time_start; | |
510 | do_div(usecs, NSEC_PER_USEC); | |
511 | ||
512 | trace_seq_printf(s, "%9llu us | ", usecs); | |
513 | } | |
514 | ||
9d9add34 | 515 | static void |
d1f9cbd7 | 516 | print_graph_irq(struct trace_iterator *iter, unsigned long addr, |
d7a8d9e9 | 517 | enum trace_type type, int cpu, pid_t pid, u32 flags) |
f8b755ac | 518 | { |
983f938a | 519 | struct trace_array *tr = iter->tr; |
d1f9cbd7 | 520 | struct trace_seq *s = &iter->seq; |
678f845e | 521 | struct trace_entry *ent = iter->ent; |
f8b755ac FW |
522 | |
523 | if (addr < (unsigned long)__irqentry_text_start || | |
524 | addr >= (unsigned long)__irqentry_text_end) | |
9d9add34 | 525 | return; |
f8b755ac | 526 | |
983f938a | 527 | if (tr->trace_flags & TRACE_ITER_CONTEXT_INFO) { |
749230b0 | 528 | /* Absolute time */ |
9d9add34 SRRH |
529 | if (flags & TRACE_GRAPH_PRINT_ABS_TIME) |
530 | print_graph_abs_time(iter->ts, s); | |
d1f9cbd7 | 531 | |
9acd8de6 CD |
532 | /* Relative time */ |
533 | if (flags & TRACE_GRAPH_PRINT_REL_TIME) | |
534 | print_graph_rel_time(iter, s); | |
535 | ||
749230b0 | 536 | /* Cpu */ |
9d9add34 SRRH |
537 | if (flags & TRACE_GRAPH_PRINT_CPU) |
538 | print_graph_cpu(s, cpu); | |
49ff5903 | 539 | |
749230b0 JO |
540 | /* Proc */ |
541 | if (flags & TRACE_GRAPH_PRINT_PROC) { | |
9d9add34 SRRH |
542 | print_graph_proc(s, pid); |
543 | trace_seq_puts(s, " | "); | |
749230b0 | 544 | } |
678f845e DBO |
545 | |
546 | /* Latency format */ | |
983f938a | 547 | if (tr->trace_flags & TRACE_ITER_LATENCY_FMT) |
9d9add34 | 548 | print_graph_lat_fmt(s, ent); |
9005f3eb | 549 | } |
f8b755ac | 550 | |
9005f3eb | 551 | /* No overhead */ |
983f938a | 552 | print_graph_duration(tr, 0, s, flags | FLAGS_FILL_START); |
f8b755ac | 553 | |
9005f3eb | 554 | if (type == TRACE_GRAPH_ENT) |
9d9add34 | 555 | trace_seq_puts(s, "==========>"); |
9005f3eb | 556 | else |
9d9add34 | 557 | trace_seq_puts(s, "<=========="); |
9005f3eb | 558 | |
983f938a | 559 | print_graph_duration(tr, 0, s, flags | FLAGS_FILL_END); |
9d9add34 | 560 | trace_seq_putc(s, '\n'); |
f8b755ac | 561 | } |
83a8df61 | 562 | |
9d9add34 | 563 | void |
0706f1c4 | 564 | trace_print_graph_duration(unsigned long long duration, struct trace_seq *s) |
83a8df61 FW |
565 | { |
566 | unsigned long nsecs_rem = do_div(duration, 1000); | |
166d3c79 | 567 | /* log10(ULONG_MAX) + '\0' */ |
4526d067 | 568 | char usecs_str[21]; |
166d3c79 | 569 | char nsecs_str[5]; |
9d9add34 | 570 | int len; |
166d3c79 FW |
571 | int i; |
572 | ||
4526d067 | 573 | sprintf(usecs_str, "%lu", (unsigned long) duration); |
166d3c79 FW |
574 | |
575 | /* Print msecs */ | |
9d9add34 | 576 | trace_seq_printf(s, "%s", usecs_str); |
166d3c79 | 577 | |
4526d067 | 578 | len = strlen(usecs_str); |
166d3c79 FW |
579 | |
580 | /* Print nsecs (we don't want to exceed 7 numbers) */ | |
581 | if (len < 7) { | |
14cae9bd BP |
582 | size_t slen = min_t(size_t, sizeof(nsecs_str), 8UL - len); |
583 | ||
584 | snprintf(nsecs_str, slen, "%03lu", nsecs_rem); | |
9d9add34 | 585 | trace_seq_printf(s, ".%s", nsecs_str); |
82c355e8 | 586 | len += strlen(nsecs_str) + 1; |
166d3c79 FW |
587 | } |
588 | ||
9d9add34 | 589 | trace_seq_puts(s, " us "); |
166d3c79 FW |
590 | |
591 | /* Print remaining spaces to fit the row's width */ | |
82c355e8 | 592 | for (i = len; i < 8; i++) |
9d9add34 | 593 | trace_seq_putc(s, ' '); |
0706f1c4 SR |
594 | } |
595 | ||
9d9add34 | 596 | static void |
983f938a SRRH |
597 | print_graph_duration(struct trace_array *tr, unsigned long long duration, |
598 | struct trace_seq *s, u32 flags) | |
0706f1c4 | 599 | { |
749230b0 | 600 | if (!(flags & TRACE_GRAPH_PRINT_DURATION) || |
983f938a | 601 | !(tr->trace_flags & TRACE_ITER_CONTEXT_INFO)) |
9d9add34 | 602 | return; |
ffeb80fc JO |
603 | |
604 | /* No real adata, just filling the column with spaces */ | |
6fc84ea7 SRRH |
605 | switch (flags & TRACE_GRAPH_PRINT_FILL_MASK) { |
606 | case FLAGS_FILL_FULL: | |
9d9add34 SRRH |
607 | trace_seq_puts(s, " | "); |
608 | return; | |
6fc84ea7 | 609 | case FLAGS_FILL_START: |
9d9add34 SRRH |
610 | trace_seq_puts(s, " "); |
611 | return; | |
6fc84ea7 | 612 | case FLAGS_FILL_END: |
9d9add34 SRRH |
613 | trace_seq_puts(s, " |"); |
614 | return; | |
ffeb80fc JO |
615 | } |
616 | ||
617 | /* Signal a overhead of time execution to the output */ | |
8e1e1df2 BP |
618 | if (flags & TRACE_GRAPH_PRINT_OVERHEAD) |
619 | trace_seq_printf(s, "%c ", trace_find_mark(duration)); | |
620 | else | |
9d9add34 | 621 | trace_seq_puts(s, " "); |
0706f1c4 | 622 | |
9d9add34 SRRH |
623 | trace_print_graph_duration(duration, s); |
624 | trace_seq_puts(s, "| "); | |
83a8df61 FW |
625 | } |
626 | ||
83a8df61 | 627 | /* Case of a leaf function on its call entry */ |
287b6e68 | 628 | static enum print_line_t |
83a8df61 | 629 | print_graph_entry_leaf(struct trace_iterator *iter, |
b91facc3 | 630 | struct ftrace_graph_ent_entry *entry, |
d7a8d9e9 JO |
631 | struct ftrace_graph_ret_entry *ret_entry, |
632 | struct trace_seq *s, u32 flags) | |
fb52607a | 633 | { |
2fbcdb35 | 634 | struct fgraph_data *data = iter->private; |
983f938a | 635 | struct trace_array *tr = iter->tr; |
83a8df61 | 636 | struct ftrace_graph_ret *graph_ret; |
83a8df61 FW |
637 | struct ftrace_graph_ent *call; |
638 | unsigned long long duration; | |
1fe4293f | 639 | int cpu = iter->cpu; |
1a056155 | 640 | int i; |
fb52607a | 641 | |
83a8df61 FW |
642 | graph_ret = &ret_entry->ret; |
643 | call = &entry->graph_ent; | |
644 | duration = graph_ret->rettime - graph_ret->calltime; | |
645 | ||
2fbcdb35 | 646 | if (data) { |
f1c7f517 | 647 | struct fgraph_cpu_data *cpu_data; |
f1c7f517 SR |
648 | |
649 | cpu_data = per_cpu_ptr(data->cpu_data, cpu); | |
2fbcdb35 SR |
650 | |
651 | /* | |
652 | * Comments display at + 1 to depth. Since | |
653 | * this is a leaf function, keep the comments | |
654 | * equal to this depth. | |
655 | */ | |
f1c7f517 SR |
656 | cpu_data->depth = call->depth - 1; |
657 | ||
658 | /* No need to keep this function around for this depth */ | |
794de08a SRRH |
659 | if (call->depth < FTRACE_RETFUNC_DEPTH && |
660 | !WARN_ON_ONCE(call->depth < 0)) | |
f1c7f517 | 661 | cpu_data->enter_funcs[call->depth] = 0; |
2fbcdb35 SR |
662 | } |
663 | ||
ffeb80fc | 664 | /* Overhead and duration */ |
983f938a | 665 | print_graph_duration(tr, duration, s, flags); |
1a056155 | 666 | |
83a8df61 | 667 | /* Function */ |
9d9add34 SRRH |
668 | for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) |
669 | trace_seq_putc(s, ' '); | |
83a8df61 | 670 | |
9d9add34 | 671 | trace_seq_printf(s, "%ps();\n", (void *)call->func); |
83a8df61 | 672 | |
1fe4293f CD |
673 | print_graph_irq(iter, graph_ret->func, TRACE_GRAPH_RET, |
674 | cpu, iter->ent->pid, flags); | |
675 | ||
9d9add34 | 676 | return trace_handle_return(s); |
83a8df61 FW |
677 | } |
678 | ||
679 | static enum print_line_t | |
2fbcdb35 SR |
680 | print_graph_entry_nested(struct trace_iterator *iter, |
681 | struct ftrace_graph_ent_entry *entry, | |
d7a8d9e9 | 682 | struct trace_seq *s, int cpu, u32 flags) |
83a8df61 | 683 | { |
83a8df61 | 684 | struct ftrace_graph_ent *call = &entry->graph_ent; |
2fbcdb35 | 685 | struct fgraph_data *data = iter->private; |
983f938a | 686 | struct trace_array *tr = iter->tr; |
2fbcdb35 SR |
687 | int i; |
688 | ||
689 | if (data) { | |
f1c7f517 | 690 | struct fgraph_cpu_data *cpu_data; |
2fbcdb35 | 691 | int cpu = iter->cpu; |
2fbcdb35 | 692 | |
f1c7f517 SR |
693 | cpu_data = per_cpu_ptr(data->cpu_data, cpu); |
694 | cpu_data->depth = call->depth; | |
695 | ||
696 | /* Save this function pointer to see if the exit matches */ | |
794de08a SRRH |
697 | if (call->depth < FTRACE_RETFUNC_DEPTH && |
698 | !WARN_ON_ONCE(call->depth < 0)) | |
f1c7f517 | 699 | cpu_data->enter_funcs[call->depth] = call->func; |
2fbcdb35 | 700 | } |
83a8df61 | 701 | |
9005f3eb | 702 | /* No time */ |
983f938a | 703 | print_graph_duration(tr, 0, s, flags | FLAGS_FILL_FULL); |
f8b755ac | 704 | |
83a8df61 | 705 | /* Function */ |
9d9add34 SRRH |
706 | for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) |
707 | trace_seq_putc(s, ' '); | |
708 | ||
709 | trace_seq_printf(s, "%ps() {\n", (void *)call->func); | |
287b6e68 | 710 | |
9d9add34 | 711 | if (trace_seq_has_overflowed(s)) |
83a8df61 FW |
712 | return TRACE_TYPE_PARTIAL_LINE; |
713 | ||
b91facc3 FW |
714 | /* |
715 | * we already consumed the current entry to check the next one | |
716 | * and see if this is a leaf. | |
717 | */ | |
718 | return TRACE_TYPE_NO_CONSUME; | |
287b6e68 FW |
719 | } |
720 | ||
9d9add34 | 721 | static void |
ac5f6c96 | 722 | print_graph_prologue(struct trace_iterator *iter, struct trace_seq *s, |
d7a8d9e9 | 723 | int type, unsigned long addr, u32 flags) |
83a8df61 | 724 | { |
2fbcdb35 | 725 | struct fgraph_data *data = iter->private; |
83a8df61 | 726 | struct trace_entry *ent = iter->ent; |
983f938a | 727 | struct trace_array *tr = iter->tr; |
ac5f6c96 | 728 | int cpu = iter->cpu; |
83a8df61 | 729 | |
1a056155 | 730 | /* Pid */ |
9d9add34 | 731 | verif_pid(s, ent->pid, cpu, data); |
9005f3eb | 732 | |
9d9add34 | 733 | if (type) |
ac5f6c96 | 734 | /* Interrupt */ |
9d9add34 | 735 | print_graph_irq(iter, addr, type, cpu, ent->pid, flags); |
83a8df61 | 736 | |
983f938a | 737 | if (!(tr->trace_flags & TRACE_ITER_CONTEXT_INFO)) |
9d9add34 | 738 | return; |
749230b0 | 739 | |
9005f3eb | 740 | /* Absolute time */ |
9d9add34 SRRH |
741 | if (flags & TRACE_GRAPH_PRINT_ABS_TIME) |
742 | print_graph_abs_time(iter->ts, s); | |
9005f3eb | 743 | |
9acd8de6 CD |
744 | /* Relative time */ |
745 | if (flags & TRACE_GRAPH_PRINT_REL_TIME) | |
746 | print_graph_rel_time(iter, s); | |
747 | ||
1a056155 | 748 | /* Cpu */ |
9d9add34 SRRH |
749 | if (flags & TRACE_GRAPH_PRINT_CPU) |
750 | print_graph_cpu(s, cpu); | |
11e84acc FW |
751 | |
752 | /* Proc */ | |
d7a8d9e9 | 753 | if (flags & TRACE_GRAPH_PRINT_PROC) { |
9d9add34 SRRH |
754 | print_graph_proc(s, ent->pid); |
755 | trace_seq_puts(s, " | "); | |
1a056155 | 756 | } |
83a8df61 | 757 | |
49ff5903 | 758 | /* Latency format */ |
983f938a | 759 | if (tr->trace_flags & TRACE_ITER_LATENCY_FMT) |
9d9add34 | 760 | print_graph_lat_fmt(s, ent); |
49ff5903 | 761 | |
9d9add34 | 762 | return; |
ac5f6c96 SR |
763 | } |
764 | ||
2bd16212 JO |
765 | /* |
766 | * Entry check for irq code | |
767 | * | |
768 | * returns 1 if | |
769 | * - we are inside irq code | |
25985edc | 770 | * - we just entered irq code |
2bd16212 JO |
771 | * |
772 | * retunns 0 if | |
773 | * - funcgraph-interrupts option is set | |
774 | * - we are not inside irq code | |
775 | */ | |
776 | static int | |
777 | check_irq_entry(struct trace_iterator *iter, u32 flags, | |
778 | unsigned long addr, int depth) | |
779 | { | |
780 | int cpu = iter->cpu; | |
a9d61173 | 781 | int *depth_irq; |
2bd16212 | 782 | struct fgraph_data *data = iter->private; |
2bd16212 | 783 | |
a9d61173 JO |
784 | /* |
785 | * If we are either displaying irqs, or we got called as | |
786 | * a graph event and private data does not exist, | |
787 | * then we bypass the irq check. | |
788 | */ | |
789 | if ((flags & TRACE_GRAPH_PRINT_IRQS) || | |
790 | (!data)) | |
2bd16212 JO |
791 | return 0; |
792 | ||
a9d61173 JO |
793 | depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq); |
794 | ||
2bd16212 JO |
795 | /* |
796 | * We are inside the irq code | |
797 | */ | |
798 | if (*depth_irq >= 0) | |
799 | return 1; | |
800 | ||
801 | if ((addr < (unsigned long)__irqentry_text_start) || | |
802 | (addr >= (unsigned long)__irqentry_text_end)) | |
803 | return 0; | |
804 | ||
805 | /* | |
806 | * We are entering irq code. | |
807 | */ | |
808 | *depth_irq = depth; | |
809 | return 1; | |
810 | } | |
811 | ||
812 | /* | |
813 | * Return check for irq code | |
814 | * | |
815 | * returns 1 if | |
816 | * - we are inside irq code | |
817 | * - we just left irq code | |
818 | * | |
819 | * returns 0 if | |
820 | * - funcgraph-interrupts option is set | |
821 | * - we are not inside irq code | |
822 | */ | |
823 | static int | |
824 | check_irq_return(struct trace_iterator *iter, u32 flags, int depth) | |
825 | { | |
826 | int cpu = iter->cpu; | |
a9d61173 | 827 | int *depth_irq; |
2bd16212 | 828 | struct fgraph_data *data = iter->private; |
2bd16212 | 829 | |
a9d61173 JO |
830 | /* |
831 | * If we are either displaying irqs, or we got called as | |
832 | * a graph event and private data does not exist, | |
833 | * then we bypass the irq check. | |
834 | */ | |
835 | if ((flags & TRACE_GRAPH_PRINT_IRQS) || | |
836 | (!data)) | |
2bd16212 JO |
837 | return 0; |
838 | ||
a9d61173 JO |
839 | depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq); |
840 | ||
2bd16212 JO |
841 | /* |
842 | * We are not inside the irq code. | |
843 | */ | |
844 | if (*depth_irq == -1) | |
845 | return 0; | |
846 | ||
847 | /* | |
848 | * We are inside the irq code, and this is returning entry. | |
849 | * Let's not trace it and clear the entry depth, since | |
850 | * we are out of irq code. | |
851 | * | |
852 | * This condition ensures that we 'leave the irq code' once | |
853 | * we are out of the entry depth. Thus protecting us from | |
854 | * the RETURN entry loss. | |
855 | */ | |
856 | if (*depth_irq >= depth) { | |
857 | *depth_irq = -1; | |
858 | return 1; | |
859 | } | |
860 | ||
861 | /* | |
862 | * We are inside the irq code, and this is not the entry. | |
863 | */ | |
864 | return 1; | |
865 | } | |
866 | ||
ac5f6c96 SR |
867 | static enum print_line_t |
868 | print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s, | |
d7a8d9e9 | 869 | struct trace_iterator *iter, u32 flags) |
ac5f6c96 | 870 | { |
be1eca39 | 871 | struct fgraph_data *data = iter->private; |
ac5f6c96 SR |
872 | struct ftrace_graph_ent *call = &field->graph_ent; |
873 | struct ftrace_graph_ret_entry *leaf_ret; | |
be1eca39 JO |
874 | static enum print_line_t ret; |
875 | int cpu = iter->cpu; | |
ac5f6c96 | 876 | |
2bd16212 JO |
877 | if (check_irq_entry(iter, flags, call->func, call->depth)) |
878 | return TRACE_TYPE_HANDLED; | |
879 | ||
9d9add34 | 880 | print_graph_prologue(iter, s, TRACE_GRAPH_ENT, call->func, flags); |
ac5f6c96 | 881 | |
b91facc3 FW |
882 | leaf_ret = get_return_for_leaf(iter, field); |
883 | if (leaf_ret) | |
d7a8d9e9 | 884 | ret = print_graph_entry_leaf(iter, field, leaf_ret, s, flags); |
83a8df61 | 885 | else |
d7a8d9e9 | 886 | ret = print_graph_entry_nested(iter, field, s, cpu, flags); |
83a8df61 | 887 | |
be1eca39 JO |
888 | if (data) { |
889 | /* | |
890 | * If we failed to write our output, then we need to make | |
891 | * note of it. Because we already consumed our entry. | |
892 | */ | |
893 | if (s->full) { | |
894 | data->failed = 1; | |
895 | data->cpu = cpu; | |
896 | } else | |
897 | data->failed = 0; | |
898 | } | |
899 | ||
900 | return ret; | |
83a8df61 FW |
901 | } |
902 | ||
287b6e68 FW |
903 | static enum print_line_t |
904 | print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s, | |
d7a8d9e9 JO |
905 | struct trace_entry *ent, struct trace_iterator *iter, |
906 | u32 flags) | |
287b6e68 | 907 | { |
83a8df61 | 908 | unsigned long long duration = trace->rettime - trace->calltime; |
2fbcdb35 | 909 | struct fgraph_data *data = iter->private; |
983f938a | 910 | struct trace_array *tr = iter->tr; |
2fbcdb35 SR |
911 | pid_t pid = ent->pid; |
912 | int cpu = iter->cpu; | |
f1c7f517 | 913 | int func_match = 1; |
2fbcdb35 SR |
914 | int i; |
915 | ||
2bd16212 JO |
916 | if (check_irq_return(iter, flags, trace->depth)) |
917 | return TRACE_TYPE_HANDLED; | |
918 | ||
2fbcdb35 | 919 | if (data) { |
f1c7f517 SR |
920 | struct fgraph_cpu_data *cpu_data; |
921 | int cpu = iter->cpu; | |
922 | ||
923 | cpu_data = per_cpu_ptr(data->cpu_data, cpu); | |
2fbcdb35 SR |
924 | |
925 | /* | |
926 | * Comments display at + 1 to depth. This is the | |
927 | * return from a function, we now want the comments | |
928 | * to display at the same level of the bracket. | |
929 | */ | |
f1c7f517 SR |
930 | cpu_data->depth = trace->depth - 1; |
931 | ||
794de08a SRRH |
932 | if (trace->depth < FTRACE_RETFUNC_DEPTH && |
933 | !WARN_ON_ONCE(trace->depth < 0)) { | |
f1c7f517 SR |
934 | if (cpu_data->enter_funcs[trace->depth] != trace->func) |
935 | func_match = 0; | |
936 | cpu_data->enter_funcs[trace->depth] = 0; | |
937 | } | |
2fbcdb35 | 938 | } |
287b6e68 | 939 | |
9d9add34 | 940 | print_graph_prologue(iter, s, 0, 0, flags); |
437f24fb | 941 | |
ffeb80fc | 942 | /* Overhead and duration */ |
983f938a | 943 | print_graph_duration(tr, duration, s, flags); |
1a056155 | 944 | |
83a8df61 | 945 | /* Closing brace */ |
9d9add34 SRRH |
946 | for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++) |
947 | trace_seq_putc(s, ' '); | |
287b6e68 | 948 | |
f1c7f517 SR |
949 | /* |
950 | * If the return function does not have a matching entry, | |
951 | * then the entry was lost. Instead of just printing | |
952 | * the '}' and letting the user guess what function this | |
607e3a29 RE |
953 | * belongs to, write out the function name. Always do |
954 | * that if the funcgraph-tail option is enabled. | |
f1c7f517 | 955 | */ |
9d9add34 SRRH |
956 | if (func_match && !(flags & TRACE_GRAPH_PRINT_TAIL)) |
957 | trace_seq_puts(s, "}\n"); | |
958 | else | |
959 | trace_seq_printf(s, "} /* %ps */\n", (void *)trace->func); | |
fb52607a | 960 | |
83a8df61 | 961 | /* Overrun */ |
9d9add34 SRRH |
962 | if (flags & TRACE_GRAPH_PRINT_OVERRUN) |
963 | trace_seq_printf(s, " (Overruns: %lu)\n", | |
964 | trace->overrun); | |
f8b755ac | 965 | |
9d9add34 SRRH |
966 | print_graph_irq(iter, trace->func, TRACE_GRAPH_RET, |
967 | cpu, pid, flags); | |
f8b755ac | 968 | |
9d9add34 | 969 | return trace_handle_return(s); |
287b6e68 FW |
970 | } |
971 | ||
1fd8f2a3 | 972 | static enum print_line_t |
d7a8d9e9 JO |
973 | print_graph_comment(struct trace_seq *s, struct trace_entry *ent, |
974 | struct trace_iterator *iter, u32 flags) | |
1fd8f2a3 | 975 | { |
983f938a SRRH |
976 | struct trace_array *tr = iter->tr; |
977 | unsigned long sym_flags = (tr->trace_flags & TRACE_ITER_SYM_MASK); | |
2fbcdb35 | 978 | struct fgraph_data *data = iter->private; |
5087f8d2 | 979 | struct trace_event *event; |
2fbcdb35 | 980 | int depth = 0; |
1fd8f2a3 | 981 | int ret; |
2fbcdb35 SR |
982 | int i; |
983 | ||
984 | if (data) | |
be1eca39 | 985 | depth = per_cpu_ptr(data->cpu_data, iter->cpu)->depth; |
9005f3eb | 986 | |
9d9add34 | 987 | print_graph_prologue(iter, s, 0, 0, flags); |
d1f9cbd7 | 988 | |
9005f3eb | 989 | /* No time */ |
983f938a | 990 | print_graph_duration(tr, 0, s, flags | FLAGS_FILL_FULL); |
1fd8f2a3 | 991 | |
1fd8f2a3 | 992 | /* Indentation */ |
2fbcdb35 | 993 | if (depth > 0) |
9d9add34 SRRH |
994 | for (i = 0; i < (depth + 1) * TRACE_GRAPH_INDENT; i++) |
995 | trace_seq_putc(s, ' '); | |
1fd8f2a3 FW |
996 | |
997 | /* The comment */ | |
9d9add34 | 998 | trace_seq_puts(s, "/* "); |
769b0441 | 999 | |
5087f8d2 | 1000 | switch (iter->ent->type) { |
613dccdf NK |
1001 | case TRACE_BPUTS: |
1002 | ret = trace_print_bputs_msg_only(iter); | |
1003 | if (ret != TRACE_TYPE_HANDLED) | |
1004 | return ret; | |
1005 | break; | |
5087f8d2 SR |
1006 | case TRACE_BPRINT: |
1007 | ret = trace_print_bprintk_msg_only(iter); | |
1008 | if (ret != TRACE_TYPE_HANDLED) | |
1009 | return ret; | |
1010 | break; | |
1011 | case TRACE_PRINT: | |
1012 | ret = trace_print_printk_msg_only(iter); | |
1013 | if (ret != TRACE_TYPE_HANDLED) | |
1014 | return ret; | |
1015 | break; | |
1016 | default: | |
1017 | event = ftrace_find_event(ent->type); | |
1018 | if (!event) | |
1019 | return TRACE_TYPE_UNHANDLED; | |
1020 | ||
a9a57763 | 1021 | ret = event->funcs->trace(iter, sym_flags, event); |
5087f8d2 SR |
1022 | if (ret != TRACE_TYPE_HANDLED) |
1023 | return ret; | |
1024 | } | |
1fd8f2a3 | 1025 | |
5ac48378 SRRH |
1026 | if (trace_seq_has_overflowed(s)) |
1027 | goto out; | |
1028 | ||
412d0bb5 | 1029 | /* Strip ending newline */ |
3a161d99 SRRH |
1030 | if (s->buffer[s->seq.len - 1] == '\n') { |
1031 | s->buffer[s->seq.len - 1] = '\0'; | |
1032 | s->seq.len--; | |
412d0bb5 FW |
1033 | } |
1034 | ||
9d9add34 | 1035 | trace_seq_puts(s, " */\n"); |
5ac48378 | 1036 | out: |
9d9add34 | 1037 | return trace_handle_return(s); |
1fd8f2a3 FW |
1038 | } |
1039 | ||
1040 | ||
287b6e68 | 1041 | enum print_line_t |
321e68b0 | 1042 | print_graph_function_flags(struct trace_iterator *iter, u32 flags) |
287b6e68 | 1043 | { |
be1eca39 JO |
1044 | struct ftrace_graph_ent_entry *field; |
1045 | struct fgraph_data *data = iter->private; | |
287b6e68 | 1046 | struct trace_entry *entry = iter->ent; |
5087f8d2 | 1047 | struct trace_seq *s = &iter->seq; |
be1eca39 JO |
1048 | int cpu = iter->cpu; |
1049 | int ret; | |
1050 | ||
1051 | if (data && per_cpu_ptr(data->cpu_data, cpu)->ignore) { | |
1052 | per_cpu_ptr(data->cpu_data, cpu)->ignore = 0; | |
1053 | return TRACE_TYPE_HANDLED; | |
1054 | } | |
1055 | ||
1056 | /* | |
1057 | * If the last output failed, there's a possibility we need | |
1058 | * to print out the missing entry which would never go out. | |
1059 | */ | |
1060 | if (data && data->failed) { | |
1061 | field = &data->ent; | |
1062 | iter->cpu = data->cpu; | |
d7a8d9e9 | 1063 | ret = print_graph_entry(field, s, iter, flags); |
be1eca39 JO |
1064 | if (ret == TRACE_TYPE_HANDLED && iter->cpu != cpu) { |
1065 | per_cpu_ptr(data->cpu_data, iter->cpu)->ignore = 1; | |
1066 | ret = TRACE_TYPE_NO_CONSUME; | |
1067 | } | |
1068 | iter->cpu = cpu; | |
1069 | return ret; | |
1070 | } | |
fb52607a | 1071 | |
287b6e68 FW |
1072 | switch (entry->type) { |
1073 | case TRACE_GRAPH_ENT: { | |
38ceb592 LJ |
1074 | /* |
1075 | * print_graph_entry() may consume the current event, | |
1076 | * thus @field may become invalid, so we need to save it. | |
1077 | * sizeof(struct ftrace_graph_ent_entry) is very small, | |
1078 | * it can be safely saved at the stack. | |
1079 | */ | |
be1eca39 | 1080 | struct ftrace_graph_ent_entry saved; |
287b6e68 | 1081 | trace_assign_type(field, entry); |
38ceb592 | 1082 | saved = *field; |
d7a8d9e9 | 1083 | return print_graph_entry(&saved, s, iter, flags); |
287b6e68 FW |
1084 | } |
1085 | case TRACE_GRAPH_RET: { | |
1086 | struct ftrace_graph_ret_entry *field; | |
1087 | trace_assign_type(field, entry); | |
d7a8d9e9 | 1088 | return print_graph_return(&field->ret, s, entry, iter, flags); |
287b6e68 | 1089 | } |
62b915f1 JO |
1090 | case TRACE_STACK: |
1091 | case TRACE_FN: | |
1092 | /* dont trace stack and functions as comments */ | |
1093 | return TRACE_TYPE_UNHANDLED; | |
1094 | ||
287b6e68 | 1095 | default: |
d7a8d9e9 | 1096 | return print_graph_comment(s, entry, iter, flags); |
fb52607a | 1097 | } |
5087f8d2 SR |
1098 | |
1099 | return TRACE_TYPE_HANDLED; | |
fb52607a FW |
1100 | } |
1101 | ||
d7a8d9e9 JO |
1102 | static enum print_line_t |
1103 | print_graph_function(struct trace_iterator *iter) | |
1104 | { | |
321e68b0 | 1105 | return print_graph_function_flags(iter, tracer_flags.val); |
d7a8d9e9 JO |
1106 | } |
1107 | ||
9106b693 | 1108 | static enum print_line_t |
a9a57763 SR |
1109 | print_graph_function_event(struct trace_iterator *iter, int flags, |
1110 | struct trace_event *event) | |
9106b693 JO |
1111 | { |
1112 | return print_graph_function(iter); | |
1113 | } | |
1114 | ||
d7a8d9e9 | 1115 | static void print_lat_header(struct seq_file *s, u32 flags) |
49ff5903 SR |
1116 | { |
1117 | static const char spaces[] = " " /* 16 spaces */ | |
1118 | " " /* 4 spaces */ | |
1119 | " "; /* 17 spaces */ | |
1120 | int size = 0; | |
1121 | ||
d7a8d9e9 | 1122 | if (flags & TRACE_GRAPH_PRINT_ABS_TIME) |
49ff5903 | 1123 | size += 16; |
9acd8de6 CD |
1124 | if (flags & TRACE_GRAPH_PRINT_REL_TIME) |
1125 | size += 16; | |
d7a8d9e9 | 1126 | if (flags & TRACE_GRAPH_PRINT_CPU) |
49ff5903 | 1127 | size += 4; |
d7a8d9e9 | 1128 | if (flags & TRACE_GRAPH_PRINT_PROC) |
49ff5903 SR |
1129 | size += 17; |
1130 | ||
1131 | seq_printf(s, "#%.*s _-----=> irqs-off \n", size, spaces); | |
1132 | seq_printf(s, "#%.*s / _----=> need-resched \n", size, spaces); | |
1133 | seq_printf(s, "#%.*s| / _---=> hardirq/softirq \n", size, spaces); | |
1134 | seq_printf(s, "#%.*s|| / _--=> preempt-depth \n", size, spaces); | |
199abfab | 1135 | seq_printf(s, "#%.*s||| / \n", size, spaces); |
49ff5903 SR |
1136 | } |
1137 | ||
983f938a SRRH |
1138 | static void __print_graph_headers_flags(struct trace_array *tr, |
1139 | struct seq_file *s, u32 flags) | |
decbec38 | 1140 | { |
983f938a | 1141 | int lat = tr->trace_flags & TRACE_ITER_LATENCY_FMT; |
49ff5903 SR |
1142 | |
1143 | if (lat) | |
d7a8d9e9 | 1144 | print_lat_header(s, flags); |
49ff5903 | 1145 | |
decbec38 | 1146 | /* 1st line */ |
1177e436 | 1147 | seq_putc(s, '#'); |
d7a8d9e9 | 1148 | if (flags & TRACE_GRAPH_PRINT_ABS_TIME) |
fa6f0cc7 | 1149 | seq_puts(s, " TIME "); |
9acd8de6 CD |
1150 | if (flags & TRACE_GRAPH_PRINT_REL_TIME) |
1151 | seq_puts(s, " REL TIME "); | |
d7a8d9e9 | 1152 | if (flags & TRACE_GRAPH_PRINT_CPU) |
fa6f0cc7 | 1153 | seq_puts(s, " CPU"); |
d7a8d9e9 | 1154 | if (flags & TRACE_GRAPH_PRINT_PROC) |
fa6f0cc7 | 1155 | seq_puts(s, " TASK/PID "); |
49ff5903 | 1156 | if (lat) |
afbab501 | 1157 | seq_puts(s, "|||| "); |
d7a8d9e9 | 1158 | if (flags & TRACE_GRAPH_PRINT_DURATION) |
fa6f0cc7 RV |
1159 | seq_puts(s, " DURATION "); |
1160 | seq_puts(s, " FUNCTION CALLS\n"); | |
decbec38 FW |
1161 | |
1162 | /* 2nd line */ | |
1177e436 | 1163 | seq_putc(s, '#'); |
d7a8d9e9 | 1164 | if (flags & TRACE_GRAPH_PRINT_ABS_TIME) |
fa6f0cc7 | 1165 | seq_puts(s, " | "); |
9acd8de6 CD |
1166 | if (flags & TRACE_GRAPH_PRINT_REL_TIME) |
1167 | seq_puts(s, " | "); | |
d7a8d9e9 | 1168 | if (flags & TRACE_GRAPH_PRINT_CPU) |
fa6f0cc7 | 1169 | seq_puts(s, " | "); |
d7a8d9e9 | 1170 | if (flags & TRACE_GRAPH_PRINT_PROC) |
fa6f0cc7 | 1171 | seq_puts(s, " | | "); |
49ff5903 | 1172 | if (lat) |
afbab501 | 1173 | seq_puts(s, "|||| "); |
d7a8d9e9 | 1174 | if (flags & TRACE_GRAPH_PRINT_DURATION) |
fa6f0cc7 RV |
1175 | seq_puts(s, " | | "); |
1176 | seq_puts(s, " | | | |\n"); | |
decbec38 | 1177 | } |
9005f3eb | 1178 | |
ba1afef6 | 1179 | static void print_graph_headers(struct seq_file *s) |
d7a8d9e9 JO |
1180 | { |
1181 | print_graph_headers_flags(s, tracer_flags.val); | |
1182 | } | |
1183 | ||
0a772620 JO |
1184 | void print_graph_headers_flags(struct seq_file *s, u32 flags) |
1185 | { | |
1186 | struct trace_iterator *iter = s->private; | |
983f938a | 1187 | struct trace_array *tr = iter->tr; |
0a772620 | 1188 | |
983f938a | 1189 | if (!(tr->trace_flags & TRACE_ITER_CONTEXT_INFO)) |
749230b0 JO |
1190 | return; |
1191 | ||
983f938a | 1192 | if (tr->trace_flags & TRACE_ITER_LATENCY_FMT) { |
0a772620 JO |
1193 | /* print nothing if the buffers are empty */ |
1194 | if (trace_empty(iter)) | |
1195 | return; | |
1196 | ||
1197 | print_trace_header(s, iter); | |
321e68b0 | 1198 | } |
0a772620 | 1199 | |
983f938a | 1200 | __print_graph_headers_flags(tr, s, flags); |
0a772620 JO |
1201 | } |
1202 | ||
62b915f1 | 1203 | void graph_trace_open(struct trace_iterator *iter) |
9005f3eb | 1204 | { |
2fbcdb35 | 1205 | /* pid and depth on the last trace processed */ |
be1eca39 | 1206 | struct fgraph_data *data; |
ef99b88b | 1207 | gfp_t gfpflags; |
9005f3eb FW |
1208 | int cpu; |
1209 | ||
be1eca39 JO |
1210 | iter->private = NULL; |
1211 | ||
ef99b88b RV |
1212 | /* We can be called in atomic context via ftrace_dump() */ |
1213 | gfpflags = (in_atomic() || irqs_disabled()) ? GFP_ATOMIC : GFP_KERNEL; | |
1214 | ||
1215 | data = kzalloc(sizeof(*data), gfpflags); | |
2fbcdb35 | 1216 | if (!data) |
be1eca39 JO |
1217 | goto out_err; |
1218 | ||
ef99b88b | 1219 | data->cpu_data = alloc_percpu_gfp(struct fgraph_cpu_data, gfpflags); |
be1eca39 JO |
1220 | if (!data->cpu_data) |
1221 | goto out_err_free; | |
1222 | ||
1223 | for_each_possible_cpu(cpu) { | |
1224 | pid_t *pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid); | |
1225 | int *depth = &(per_cpu_ptr(data->cpu_data, cpu)->depth); | |
1226 | int *ignore = &(per_cpu_ptr(data->cpu_data, cpu)->ignore); | |
2bd16212 JO |
1227 | int *depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq); |
1228 | ||
be1eca39 JO |
1229 | *pid = -1; |
1230 | *depth = 0; | |
1231 | *ignore = 0; | |
2bd16212 | 1232 | *depth_irq = -1; |
be1eca39 | 1233 | } |
9005f3eb | 1234 | |
2fbcdb35 | 1235 | iter->private = data; |
be1eca39 JO |
1236 | |
1237 | return; | |
1238 | ||
1239 | out_err_free: | |
1240 | kfree(data); | |
1241 | out_err: | |
a395d6a7 | 1242 | pr_warn("function graph tracer: not enough memory\n"); |
9005f3eb FW |
1243 | } |
1244 | ||
62b915f1 | 1245 | void graph_trace_close(struct trace_iterator *iter) |
9005f3eb | 1246 | { |
be1eca39 JO |
1247 | struct fgraph_data *data = iter->private; |
1248 | ||
1249 | if (data) { | |
1250 | free_percpu(data->cpu_data); | |
1251 | kfree(data); | |
1252 | } | |
9005f3eb FW |
1253 | } |
1254 | ||
8c1a49ae SRRH |
1255 | static int |
1256 | func_graph_set_flag(struct trace_array *tr, u32 old_flags, u32 bit, int set) | |
b304d044 SR |
1257 | { |
1258 | if (bit == TRACE_GRAPH_PRINT_IRQS) | |
1259 | ftrace_graph_skip_irqs = !set; | |
1260 | ||
55577204 SRRH |
1261 | if (bit == TRACE_GRAPH_SLEEP_TIME) |
1262 | ftrace_graph_sleep_time_control(set); | |
1263 | ||
1264 | if (bit == TRACE_GRAPH_GRAPH_TIME) | |
1265 | ftrace_graph_graph_time_control(set); | |
1266 | ||
b304d044 SR |
1267 | return 0; |
1268 | } | |
1269 | ||
a9a57763 SR |
1270 | static struct trace_event_functions graph_functions = { |
1271 | .trace = print_graph_function_event, | |
1272 | }; | |
1273 | ||
9106b693 JO |
1274 | static struct trace_event graph_trace_entry_event = { |
1275 | .type = TRACE_GRAPH_ENT, | |
a9a57763 | 1276 | .funcs = &graph_functions, |
9106b693 JO |
1277 | }; |
1278 | ||
1279 | static struct trace_event graph_trace_ret_event = { | |
1280 | .type = TRACE_GRAPH_RET, | |
a9a57763 | 1281 | .funcs = &graph_functions |
9106b693 JO |
1282 | }; |
1283 | ||
8f768993 | 1284 | static struct tracer graph_trace __tracer_data = { |
ef18012b | 1285 | .name = "function_graph", |
6508fa76 | 1286 | .update_thresh = graph_trace_update_thresh, |
9005f3eb | 1287 | .open = graph_trace_open, |
be1eca39 | 1288 | .pipe_open = graph_trace_open, |
9005f3eb | 1289 | .close = graph_trace_close, |
be1eca39 | 1290 | .pipe_close = graph_trace_close, |
ef18012b SR |
1291 | .init = graph_trace_init, |
1292 | .reset = graph_trace_reset, | |
decbec38 FW |
1293 | .print_line = print_graph_function, |
1294 | .print_header = print_graph_headers, | |
fb52607a | 1295 | .flags = &tracer_flags, |
b304d044 | 1296 | .set_flag = func_graph_set_flag, |
7447dce9 FW |
1297 | #ifdef CONFIG_FTRACE_SELFTEST |
1298 | .selftest = trace_selftest_startup_function_graph, | |
1299 | #endif | |
fb52607a FW |
1300 | }; |
1301 | ||
8741db53 SR |
1302 | |
1303 | static ssize_t | |
1304 | graph_depth_write(struct file *filp, const char __user *ubuf, size_t cnt, | |
1305 | loff_t *ppos) | |
1306 | { | |
1307 | unsigned long val; | |
1308 | int ret; | |
1309 | ||
1310 | ret = kstrtoul_from_user(ubuf, cnt, 10, &val); | |
1311 | if (ret) | |
1312 | return ret; | |
1313 | ||
1a414428 | 1314 | fgraph_max_depth = val; |
8741db53 SR |
1315 | |
1316 | *ppos += cnt; | |
1317 | ||
1318 | return cnt; | |
1319 | } | |
1320 | ||
1321 | static ssize_t | |
1322 | graph_depth_read(struct file *filp, char __user *ubuf, size_t cnt, | |
1323 | loff_t *ppos) | |
1324 | { | |
1325 | char buf[15]; /* More than enough to hold UINT_MAX + "\n"*/ | |
1326 | int n; | |
1327 | ||
1a414428 | 1328 | n = sprintf(buf, "%d\n", fgraph_max_depth); |
8741db53 SR |
1329 | |
1330 | return simple_read_from_buffer(ubuf, cnt, ppos, buf, n); | |
1331 | } | |
1332 | ||
1333 | static const struct file_operations graph_depth_fops = { | |
1334 | .open = tracing_open_generic, | |
1335 | .write = graph_depth_write, | |
1336 | .read = graph_depth_read, | |
1337 | .llseek = generic_file_llseek, | |
1338 | }; | |
1339 | ||
8434dc93 | 1340 | static __init int init_graph_tracefs(void) |
8741db53 SR |
1341 | { |
1342 | struct dentry *d_tracer; | |
1343 | ||
1344 | d_tracer = tracing_init_dentry(); | |
14a5ae40 | 1345 | if (IS_ERR(d_tracer)) |
8741db53 SR |
1346 | return 0; |
1347 | ||
1348 | trace_create_file("max_graph_depth", 0644, d_tracer, | |
1349 | NULL, &graph_depth_fops); | |
1350 | ||
1351 | return 0; | |
1352 | } | |
8434dc93 | 1353 | fs_initcall(init_graph_tracefs); |
8741db53 | 1354 | |
fb52607a FW |
1355 | static __init int init_graph_trace(void) |
1356 | { | |
9b130ad5 | 1357 | max_bytes_for_cpu = snprintf(NULL, 0, "%u", nr_cpu_ids - 1); |
0c9e6f63 | 1358 | |
9023c930 | 1359 | if (!register_trace_event(&graph_trace_entry_event)) { |
a395d6a7 | 1360 | pr_warn("Warning: could not register graph trace events\n"); |
9106b693 JO |
1361 | return 1; |
1362 | } | |
1363 | ||
9023c930 | 1364 | if (!register_trace_event(&graph_trace_ret_event)) { |
a395d6a7 | 1365 | pr_warn("Warning: could not register graph trace events\n"); |
9106b693 JO |
1366 | return 1; |
1367 | } | |
1368 | ||
fb52607a FW |
1369 | return register_tracer(&graph_trace); |
1370 | } | |
1371 | ||
6f415672 | 1372 | core_initcall(init_graph_trace); |