1 // SPDX-License-Identifier: GPL-2.0
2 /*
3 *
4 * Function graph tracer.
5 * Copyright (c) 2008-2009 Frederic Weisbecker <fweisbec@gmail.com>
6 * Mostly borrowed from function tracer which
7 * is Copyright (c) Steven Rostedt <srostedt@redhat.com>
8 *
9 */
10 #include <linux/uaccess.h>
11 #include <linux/ftrace.h>
12 #include <linux/interrupt.h>
13 #include <linux/slab.h>
14 #include <linux/fs.h>
15
16 #include "trace.h"
17 #include "trace_output.h"
18
19 /* When set, irq functions might be ignored */
20 static int ftrace_graph_skip_irqs;
21
22 /* Do not record function time when task is sleeping */
23 int fgraph_no_sleep_time;
24
25 struct fgraph_cpu_data {
26 pid_t last_pid;
27 int depth;
28 int depth_irq;
29 int ignore;
30 unsigned long enter_funcs[FTRACE_RETFUNC_DEPTH];
31 };
32
33 struct fgraph_ent_args {
34 struct ftrace_graph_ent_entry ent;
35 /* Force the sizeof of args[] to have FTRACE_REGS_MAX_ARGS entries */
36 unsigned long args[FTRACE_REGS_MAX_ARGS];
37 };
38
39 struct fgraph_retaddr_ent_args {
40 struct fgraph_retaddr_ent_entry ent;
41 /* Force the sizeof of args[] to have FTRACE_REGS_MAX_ARGS entries */
42 unsigned long args[FTRACE_REGS_MAX_ARGS];
43 };
44
45 struct fgraph_data {
46 struct fgraph_cpu_data __percpu *cpu_data;
47
48 /* Place to preserve last processed entry. */
49 union {
50 struct fgraph_ent_args ent;
51 struct fgraph_retaddr_ent_args rent;
52 };
53 struct ftrace_graph_ret_entry ret;
54 int failed;
55 int cpu;
56 };
57
58 #define TRACE_GRAPH_INDENT 2
59
60 unsigned int fgraph_max_depth;
61
62 static struct tracer_opt trace_opts[] = {
63 /* Display overruns? (for self-debug purpose) */
64 { TRACER_OPT(funcgraph-overrun, TRACE_GRAPH_PRINT_OVERRUN) },
65 /* Display CPU ? */
66 { TRACER_OPT(funcgraph-cpu, TRACE_GRAPH_PRINT_CPU) },
67 /* Display Overhead ? */
68 { TRACER_OPT(funcgraph-overhead, TRACE_GRAPH_PRINT_OVERHEAD) },
69 /* Display proc name/pid */
70 { TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) },
71 /* Display duration of execution */
72 { TRACER_OPT(funcgraph-duration, TRACE_GRAPH_PRINT_DURATION) },
73 /* Display absolute time of an entry */
74 { TRACER_OPT(funcgraph-abstime, TRACE_GRAPH_PRINT_ABS_TIME) },
75 /* Display interrupts */
76 { TRACER_OPT(funcgraph-irqs, TRACE_GRAPH_PRINT_IRQS) },
77 /* Display function name after trailing } */
78 { TRACER_OPT(funcgraph-tail, TRACE_GRAPH_PRINT_TAIL) },
79 #ifdef CONFIG_FUNCTION_GRAPH_RETVAL
80 /* Display function return value ? */
81 { TRACER_OPT(funcgraph-retval, TRACE_GRAPH_PRINT_RETVAL) },
82 /* Display function return value in hexadecimal format ? */
83 { TRACER_OPT(funcgraph-retval-hex, TRACE_GRAPH_PRINT_RETVAL_HEX) },
84 #endif
85 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
86 /* Display function return address ? */
87 { TRACER_OPT(funcgraph-retaddr, TRACE_GRAPH_PRINT_RETADDR) },
88 #endif
89 #ifdef CONFIG_FUNCTION_TRACE_ARGS
90 /* Display function arguments ? */
91 { TRACER_OPT(funcgraph-args, TRACE_GRAPH_ARGS) },
92 #endif
93 /* Include sleep time (scheduled out) between entry and return */
94 { TRACER_OPT(sleep-time, TRACE_GRAPH_SLEEP_TIME) },
95
96 { } /* Empty entry */
97 };
98
99 static struct tracer_flags tracer_flags = {
100 /* Don't display overruns, proc, or tail by default */
101 .val = TRACE_GRAPH_PRINT_CPU | TRACE_GRAPH_PRINT_OVERHEAD |
102 TRACE_GRAPH_PRINT_DURATION | TRACE_GRAPH_PRINT_IRQS |
103 TRACE_GRAPH_SLEEP_TIME,
104 .opts = trace_opts
105 };
106
tracer_flags_is_set(struct trace_array * tr,u32 flags)107 static bool tracer_flags_is_set(struct trace_array *tr, u32 flags)
108 {
109 return (tr->current_trace_flags->val & flags) == flags;
110 }
111
112 /*
113 * DURATION column is being also used to display IRQ signs,
114 * following values are used by print_graph_irq and others
115 * to fill in space into DURATION column.
116 */
117 enum {
118 FLAGS_FILL_FULL = 1 << TRACE_GRAPH_PRINT_FILL_SHIFT,
119 FLAGS_FILL_START = 2 << TRACE_GRAPH_PRINT_FILL_SHIFT,
120 FLAGS_FILL_END = 3 << TRACE_GRAPH_PRINT_FILL_SHIFT,
121 };
122
123 static void
124 print_graph_duration(struct trace_array *tr, unsigned long long duration,
125 struct trace_seq *s, u32 flags);
126
__graph_entry(struct trace_array * tr,struct ftrace_graph_ent * trace,unsigned int trace_ctx,struct ftrace_regs * fregs)127 static int __graph_entry(struct trace_array *tr, struct ftrace_graph_ent *trace,
128 unsigned int trace_ctx, struct ftrace_regs *fregs)
129 {
130 struct ring_buffer_event *event;
131 struct trace_buffer *buffer = tr->array_buffer.buffer;
132 struct ftrace_graph_ent_entry *entry;
133 int size;
134
135 /* If fregs is defined, add FTRACE_REGS_MAX_ARGS long size words */
136 size = sizeof(*entry) + (FTRACE_REGS_MAX_ARGS * !!fregs * sizeof(long));
137
138 event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_ENT, size, trace_ctx);
139 if (!event)
140 return 0;
141
142 entry = ring_buffer_event_data(event);
143 entry->graph_ent = *trace;
144
145 #ifdef CONFIG_HAVE_FUNCTION_ARG_ACCESS_API
146 if (fregs) {
147 for (int i = 0; i < FTRACE_REGS_MAX_ARGS; i++)
148 entry->args[i] = ftrace_regs_get_argument(fregs, i);
149 }
150 #endif
151
152 trace_buffer_unlock_commit_nostack(buffer, event);
153
154 return 1;
155 }
156
__trace_graph_entry(struct trace_array * tr,struct ftrace_graph_ent * trace,unsigned int trace_ctx)157 int __trace_graph_entry(struct trace_array *tr,
158 struct ftrace_graph_ent *trace,
159 unsigned int trace_ctx)
160 {
161 return __graph_entry(tr, trace, trace_ctx, NULL);
162 }
163
164 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
__trace_graph_retaddr_entry(struct trace_array * tr,struct ftrace_graph_ent * trace,unsigned int trace_ctx,unsigned long retaddr,struct ftrace_regs * fregs)165 int __trace_graph_retaddr_entry(struct trace_array *tr,
166 struct ftrace_graph_ent *trace,
167 unsigned int trace_ctx,
168 unsigned long retaddr,
169 struct ftrace_regs *fregs)
170 {
171 struct ring_buffer_event *event;
172 struct trace_buffer *buffer = tr->array_buffer.buffer;
173 struct fgraph_retaddr_ent_entry *entry;
174 int size;
175
176 /* If fregs is defined, add FTRACE_REGS_MAX_ARGS long size words */
177 size = sizeof(*entry) + (FTRACE_REGS_MAX_ARGS * !!fregs * sizeof(long));
178
179 event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_RETADDR_ENT,
180 size, trace_ctx);
181 if (!event)
182 return 0;
183 entry = ring_buffer_event_data(event);
184 entry->graph_rent.ent = *trace;
185 entry->graph_rent.retaddr = retaddr;
186
187 #ifdef CONFIG_HAVE_FUNCTION_ARG_ACCESS_API
188 if (fregs) {
189 for (int i = 0; i < FTRACE_REGS_MAX_ARGS; i++)
190 entry->args[i] = ftrace_regs_get_argument(fregs, i);
191 }
192 #endif
193
194 trace_buffer_unlock_commit_nostack(buffer, event);
195
196 return 1;
197 }
198 #else
__trace_graph_retaddr_entry(struct trace_array * tr,struct ftrace_graph_ent * trace,unsigned int trace_ctx,unsigned long retaddr,struct ftrace_regs * fregs)199 int __trace_graph_retaddr_entry(struct trace_array *tr,
200 struct ftrace_graph_ent *trace,
201 unsigned int trace_ctx,
202 unsigned long retaddr,
203 struct ftrace_regs *fregs)
204 {
205 return 1;
206 }
207 #endif
208
ftrace_graph_ignore_irqs(struct trace_array * tr)209 static inline int ftrace_graph_ignore_irqs(struct trace_array *tr)
210 {
211 if (!ftrace_graph_skip_irqs || trace_recursion_test(TRACE_IRQ_BIT))
212 return 0;
213
214 if (tracer_flags_is_set(tr, TRACE_GRAPH_PRINT_IRQS))
215 return 0;
216
217 return in_hardirq();
218 }
219
220 struct fgraph_times {
221 unsigned long long calltime;
222 unsigned long long sleeptime; /* may be optional! */
223 };
224
graph_entry(struct ftrace_graph_ent * trace,struct fgraph_ops * gops,struct ftrace_regs * fregs)225 static int graph_entry(struct ftrace_graph_ent *trace,
226 struct fgraph_ops *gops,
227 struct ftrace_regs *fregs)
228 {
229 unsigned long *task_var = fgraph_get_task_var(gops);
230 struct trace_array *tr = gops->private;
231 struct fgraph_times *ftimes;
232 unsigned int trace_ctx;
233 int ret = 0;
234
235 if (*task_var & TRACE_GRAPH_NOTRACE)
236 return 0;
237
238 /*
239 * Do not trace a function if it's filtered by set_graph_notrace.
240 * Make the index of ret stack negative to indicate that it should
241 * ignore further functions. But it needs its own ret stack entry
242 * to recover the original index in order to continue tracing after
243 * returning from the function.
244 */
245 if (ftrace_graph_notrace_addr(trace->func)) {
246 *task_var |= TRACE_GRAPH_NOTRACE;
247 /*
248 * Need to return 1 to have the return called
249 * that will clear the NOTRACE bit.
250 */
251 return 1;
252 }
253
254 if (ftrace_graph_ignore_func(gops, trace))
255 return 0;
256
257 if (ftrace_graph_ignore_irqs(tr))
258 return 0;
259
260 if (fgraph_no_sleep_time &&
261 !tracer_flags_is_set(tr, TRACE_GRAPH_SLEEP_TIME)) {
262 ftimes = fgraph_reserve_data(gops->idx, sizeof(*ftimes));
263 if (ftimes)
264 ftimes->sleeptime = current->ftrace_sleeptime;
265 } else {
266 /* Only need to record the calltime */
267 ftimes = fgraph_reserve_data(gops->idx, sizeof(ftimes->calltime));
268 }
269 if (!ftimes)
270 return 0;
271
272 ftimes->calltime = trace_clock_local();
273
274 /*
275 * Stop here if tracing_threshold is set. We only write function return
276 * events to the ring buffer.
277 */
278 if (tracing_thresh)
279 return 1;
280
281 trace_ctx = tracing_gen_ctx();
282 if (IS_ENABLED(CONFIG_FUNCTION_GRAPH_RETADDR) &&
283 tracer_flags_is_set(tr, TRACE_GRAPH_PRINT_RETADDR)) {
284 unsigned long retaddr = ftrace_graph_top_ret_addr(current);
285 ret = __trace_graph_retaddr_entry(tr, trace, trace_ctx,
286 retaddr, fregs);
287 } else {
288 ret = __graph_entry(tr, trace, trace_ctx, fregs);
289 }
290
291 return ret;
292 }
293
trace_graph_entry(struct ftrace_graph_ent * trace,struct fgraph_ops * gops,struct ftrace_regs * fregs)294 int trace_graph_entry(struct ftrace_graph_ent *trace,
295 struct fgraph_ops *gops,
296 struct ftrace_regs *fregs)
297 {
298 return graph_entry(trace, gops, NULL);
299 }
300
trace_graph_entry_args(struct ftrace_graph_ent * trace,struct fgraph_ops * gops,struct ftrace_regs * fregs)301 static int trace_graph_entry_args(struct ftrace_graph_ent *trace,
302 struct fgraph_ops *gops,
303 struct ftrace_regs *fregs)
304 {
305 return graph_entry(trace, gops, fregs);
306 }
307
308 static void
__trace_graph_function(struct trace_array * tr,unsigned long ip,unsigned int trace_ctx)309 __trace_graph_function(struct trace_array *tr,
310 unsigned long ip, unsigned int trace_ctx)
311 {
312 u64 time = trace_clock_local();
313 struct ftrace_graph_ent ent = {
314 .func = ip,
315 .depth = 0,
316 };
317 struct ftrace_graph_ret ret = {
318 .func = ip,
319 .depth = 0,
320 };
321
322 __trace_graph_entry(tr, &ent, trace_ctx);
323 __trace_graph_return(tr, &ret, trace_ctx, time, time);
324 }
325
326 void
trace_graph_function(struct trace_array * tr,unsigned long ip,unsigned long parent_ip,unsigned int trace_ctx)327 trace_graph_function(struct trace_array *tr,
328 unsigned long ip, unsigned long parent_ip,
329 unsigned int trace_ctx)
330 {
331 __trace_graph_function(tr, ip, trace_ctx);
332 }
333
__trace_graph_return(struct trace_array * tr,struct ftrace_graph_ret * trace,unsigned int trace_ctx,u64 calltime,u64 rettime)334 void __trace_graph_return(struct trace_array *tr,
335 struct ftrace_graph_ret *trace,
336 unsigned int trace_ctx,
337 u64 calltime, u64 rettime)
338 {
339 struct ring_buffer_event *event;
340 struct trace_buffer *buffer = tr->array_buffer.buffer;
341 struct ftrace_graph_ret_entry *entry;
342
343 event = trace_buffer_lock_reserve(buffer, TRACE_GRAPH_RET,
344 sizeof(*entry), trace_ctx);
345 if (!event)
346 return;
347 entry = ring_buffer_event_data(event);
348 entry->ret = *trace;
349 entry->calltime = calltime;
350 entry->rettime = rettime;
351 trace_buffer_unlock_commit_nostack(buffer, event);
352 }
353
handle_nosleeptime(struct trace_array * tr,struct ftrace_graph_ret * trace,struct fgraph_times * ftimes,int size)354 static void handle_nosleeptime(struct trace_array *tr,
355 struct ftrace_graph_ret *trace,
356 struct fgraph_times *ftimes,
357 int size)
358 {
359 if (size < sizeof(*ftimes))
360 return;
361
362 if (!fgraph_no_sleep_time || tracer_flags_is_set(tr, TRACE_GRAPH_SLEEP_TIME))
363 return;
364
365 ftimes->calltime += current->ftrace_sleeptime - ftimes->sleeptime;
366 }
367
trace_graph_return(struct ftrace_graph_ret * trace,struct fgraph_ops * gops,struct ftrace_regs * fregs)368 void trace_graph_return(struct ftrace_graph_ret *trace,
369 struct fgraph_ops *gops, struct ftrace_regs *fregs)
370 {
371 unsigned long *task_var = fgraph_get_task_var(gops);
372 struct trace_array *tr = gops->private;
373 struct fgraph_times *ftimes;
374 unsigned int trace_ctx;
375 u64 calltime, rettime;
376 int size;
377
378 rettime = trace_clock_local();
379
380 ftrace_graph_addr_finish(gops, trace);
381
382 if (*task_var & TRACE_GRAPH_NOTRACE) {
383 *task_var &= ~TRACE_GRAPH_NOTRACE;
384 return;
385 }
386
387 ftimes = fgraph_retrieve_data(gops->idx, &size);
388 if (!ftimes)
389 return;
390
391 handle_nosleeptime(tr, trace, ftimes, size);
392
393 calltime = ftimes->calltime;
394
395 trace_ctx = tracing_gen_ctx();
396 __trace_graph_return(tr, trace, trace_ctx, calltime, rettime);
397 }
398
trace_graph_thresh_return(struct ftrace_graph_ret * trace,struct fgraph_ops * gops,struct ftrace_regs * fregs)399 static void trace_graph_thresh_return(struct ftrace_graph_ret *trace,
400 struct fgraph_ops *gops,
401 struct ftrace_regs *fregs)
402 {
403 unsigned long *task_var = fgraph_get_task_var(gops);
404 struct fgraph_times *ftimes;
405 struct trace_array *tr;
406 unsigned int trace_ctx;
407 u64 calltime, rettime;
408 int size;
409
410 rettime = trace_clock_local();
411
412 ftrace_graph_addr_finish(gops, trace);
413
414 if (*task_var & TRACE_GRAPH_NOTRACE) {
415 *task_var &= ~TRACE_GRAPH_NOTRACE;
416 return;
417 }
418
419 ftimes = fgraph_retrieve_data(gops->idx, &size);
420 if (!ftimes)
421 return;
422
423 tr = gops->private;
424 handle_nosleeptime(tr, trace, ftimes, size);
425
426 calltime = ftimes->calltime;
427
428 if (tracing_thresh && (rettime - calltime < tracing_thresh))
429 return;
430
431 trace_ctx = tracing_gen_ctx();
432 __trace_graph_return(tr, trace, trace_ctx, calltime, rettime);
433 }
434
435 static struct fgraph_ops funcgraph_ops = {
436 .entryfunc = &trace_graph_entry,
437 .retfunc = &trace_graph_return,
438 };
439
allocate_fgraph_ops(struct trace_array * tr,struct ftrace_ops * ops)440 int allocate_fgraph_ops(struct trace_array *tr, struct ftrace_ops *ops)
441 {
442 struct fgraph_ops *gops;
443
444 gops = kzalloc_obj(*gops);
445 if (!gops)
446 return -ENOMEM;
447
448 gops->entryfunc = &trace_graph_entry;
449 gops->retfunc = &trace_graph_return;
450
451 tr->gops = gops;
452 gops->private = tr;
453
454 fgraph_init_ops(&gops->ops, ops);
455
456 return 0;
457 }
458
free_fgraph_ops(struct trace_array * tr)459 void free_fgraph_ops(struct trace_array *tr)
460 {
461 kfree(tr->gops);
462 }
463
init_array_fgraph_ops(struct trace_array * tr,struct ftrace_ops * ops)464 __init void init_array_fgraph_ops(struct trace_array *tr, struct ftrace_ops *ops)
465 {
466 tr->gops = &funcgraph_ops;
467 funcgraph_ops.private = tr;
468 fgraph_init_ops(&tr->gops->ops, ops);
469 }
470
graph_trace_init(struct trace_array * tr)471 static int graph_trace_init(struct trace_array *tr)
472 {
473 int ret;
474
475 if (tracer_flags_is_set(tr, TRACE_GRAPH_ARGS))
476 tr->gops->entryfunc = trace_graph_entry_args;
477 else
478 tr->gops->entryfunc = trace_graph_entry;
479
480 if (tracing_thresh)
481 tr->gops->retfunc = trace_graph_thresh_return;
482 else
483 tr->gops->retfunc = trace_graph_return;
484
485 if (!tracer_flags_is_set(tr, TRACE_GRAPH_PRINT_IRQS))
486 ftrace_graph_skip_irqs++;
487
488 if (!tracer_flags_is_set(tr, TRACE_GRAPH_SLEEP_TIME))
489 fgraph_no_sleep_time++;
490
491 /* Make gops functions visible before we start tracing */
492 smp_mb();
493
494 ret = register_ftrace_graph(tr->gops);
495 if (ret)
496 return ret;
497 tracing_start_cmdline_record();
498
499 return 0;
500 }
501
502 static struct tracer graph_trace;
503
ftrace_graph_trace_args(struct trace_array * tr,int set)504 static int ftrace_graph_trace_args(struct trace_array *tr, int set)
505 {
506 trace_func_graph_ent_t entry;
507
508 if (set)
509 entry = trace_graph_entry_args;
510 else
511 entry = trace_graph_entry;
512
513 /* See if there's any changes */
514 if (tr->gops->entryfunc == entry)
515 return 0;
516
517 unregister_ftrace_graph(tr->gops);
518
519 tr->gops->entryfunc = entry;
520
521 /* Make gops functions visible before we start tracing */
522 smp_mb();
523 return register_ftrace_graph(tr->gops);
524 }
525
graph_trace_reset(struct trace_array * tr)526 static void graph_trace_reset(struct trace_array *tr)
527 {
528 if (!tracer_flags_is_set(tr, TRACE_GRAPH_PRINT_IRQS))
529 ftrace_graph_skip_irqs--;
530 if (WARN_ON_ONCE(ftrace_graph_skip_irqs < 0))
531 ftrace_graph_skip_irqs = 0;
532
533 if (!tracer_flags_is_set(tr, TRACE_GRAPH_SLEEP_TIME))
534 fgraph_no_sleep_time--;
535 if (WARN_ON_ONCE(fgraph_no_sleep_time < 0))
536 fgraph_no_sleep_time = 0;
537
538 tracing_stop_cmdline_record();
539 unregister_ftrace_graph(tr->gops);
540 }
541
graph_trace_update_thresh(struct trace_array * tr)542 static int graph_trace_update_thresh(struct trace_array *tr)
543 {
544 graph_trace_reset(tr);
545 return graph_trace_init(tr);
546 }
547
548 static int max_bytes_for_cpu;
549
print_graph_cpu(struct trace_seq * s,int cpu)550 static void print_graph_cpu(struct trace_seq *s, int cpu)
551 {
552 /*
553 * Start with a space character - to make it stand out
554 * to the right a bit when trace output is pasted into
555 * email:
556 */
557 trace_seq_printf(s, " %*d) ", max_bytes_for_cpu, cpu);
558 }
559
560 #define TRACE_GRAPH_PROCINFO_LENGTH 14
561
print_graph_proc(struct trace_seq * s,pid_t pid)562 static void print_graph_proc(struct trace_seq *s, pid_t pid)
563 {
564 char comm[TASK_COMM_LEN];
565 /* sign + log10(MAX_INT) + '\0' */
566 char pid_str[12];
567 int spaces = 0;
568 int len;
569 int i;
570
571 trace_find_cmdline(pid, comm);
572 comm[7] = '\0';
573 sprintf(pid_str, "%d", pid);
574
575 /* 1 stands for the "-" character */
576 len = strlen(comm) + strlen(pid_str) + 1;
577
578 if (len < TRACE_GRAPH_PROCINFO_LENGTH)
579 spaces = TRACE_GRAPH_PROCINFO_LENGTH - len;
580
581 /* First spaces to align center */
582 for (i = 0; i < spaces / 2; i++)
583 trace_seq_putc(s, ' ');
584
585 trace_seq_printf(s, "%s-%s", comm, pid_str);
586
587 /* Last spaces to align center */
588 for (i = 0; i < spaces - (spaces / 2); i++)
589 trace_seq_putc(s, ' ');
590 }
591
592
print_graph_lat_fmt(struct trace_seq * s,struct trace_entry * entry)593 static void print_graph_lat_fmt(struct trace_seq *s, struct trace_entry *entry)
594 {
595 trace_seq_putc(s, ' ');
596 trace_print_lat_fmt(s, entry);
597 trace_seq_puts(s, " | ");
598 }
599
600 /* If the pid changed since the last trace, output this event */
601 static void
verif_pid(struct trace_seq * s,pid_t pid,int cpu,struct fgraph_data * data)602 verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data)
603 {
604 pid_t prev_pid;
605 pid_t *last_pid;
606
607 if (!data)
608 return;
609
610 last_pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid);
611
612 if (*last_pid == pid)
613 return;
614
615 prev_pid = *last_pid;
616 *last_pid = pid;
617
618 if (prev_pid == -1)
619 return;
620 /*
621 * Context-switch trace line:
622
623 ------------------------------------------
624 | 1) migration/0--1 => sshd-1755
625 ------------------------------------------
626
627 */
628 trace_seq_puts(s, " ------------------------------------------\n");
629 print_graph_cpu(s, cpu);
630 print_graph_proc(s, prev_pid);
631 trace_seq_puts(s, " => ");
632 print_graph_proc(s, pid);
633 trace_seq_puts(s, "\n ------------------------------------------\n\n");
634 }
635
636 static struct ftrace_graph_ret_entry *
get_return_for_leaf(struct trace_iterator * iter,struct ftrace_graph_ent_entry * curr)637 get_return_for_leaf(struct trace_iterator *iter,
638 struct ftrace_graph_ent_entry *curr)
639 {
640 struct fgraph_data *data = iter->private;
641 struct ring_buffer_iter *ring_iter = NULL;
642 struct ring_buffer_event *event;
643 struct ftrace_graph_ret_entry *next;
644
645 /*
646 * If the previous output failed to write to the seq buffer,
647 * then we just reuse the data from before.
648 */
649 if (data && data->failed) {
650 curr = &data->ent.ent;
651 next = &data->ret;
652 } else {
653
654 ring_iter = trace_buffer_iter(iter, iter->cpu);
655
656 /* First peek to compare current entry and the next one */
657 if (ring_iter)
658 event = ring_buffer_iter_peek(ring_iter, NULL);
659 else {
660 /*
661 * We need to consume the current entry to see
662 * the next one.
663 */
664 ring_buffer_consume(iter->array_buffer->buffer, iter->cpu,
665 NULL, NULL);
666 event = ring_buffer_peek(iter->array_buffer->buffer, iter->cpu,
667 NULL, NULL);
668 }
669
670 if (!event)
671 return NULL;
672
673 next = ring_buffer_event_data(event);
674
675 if (data) {
676 /*
677 * Save current and next entries for later reference
678 * if the output fails.
679 */
680 int size = min_t(int, sizeof(data->rent), iter->ent_size);
681
682 memcpy(&data->rent, curr, size);
683 /*
684 * If the next event is not a return type, then
685 * we only care about what type it is. Otherwise we can
686 * safely copy the entire event.
687 */
688 if (next->ent.type == TRACE_GRAPH_RET)
689 data->ret = *next;
690 else
691 data->ret.ent.type = next->ent.type;
692 }
693 }
694
695 if (next->ent.type != TRACE_GRAPH_RET)
696 return NULL;
697
698 if (curr->ent.pid != next->ent.pid ||
699 curr->graph_ent.func != next->ret.func)
700 return NULL;
701
702 /* this is a leaf, now advance the iterator */
703 if (ring_iter)
704 ring_buffer_iter_advance(ring_iter);
705
706 return next;
707 }
708
print_graph_abs_time(u64 t,struct trace_seq * s)709 static void print_graph_abs_time(u64 t, struct trace_seq *s)
710 {
711 unsigned long usecs_rem;
712
713 usecs_rem = do_div(t, NSEC_PER_SEC);
714 usecs_rem /= 1000;
715
716 trace_seq_printf(s, "%5lu.%06lu | ",
717 (unsigned long)t, usecs_rem);
718 }
719
720 static void
print_graph_rel_time(struct trace_iterator * iter,struct trace_seq * s)721 print_graph_rel_time(struct trace_iterator *iter, struct trace_seq *s)
722 {
723 unsigned long long usecs;
724
725 usecs = iter->ts - iter->array_buffer->time_start;
726 do_div(usecs, NSEC_PER_USEC);
727
728 trace_seq_printf(s, "%9llu us | ", usecs);
729 }
730
731 static void
print_graph_irq(struct trace_iterator * iter,unsigned long addr,enum trace_type type,int cpu,pid_t pid,u32 flags)732 print_graph_irq(struct trace_iterator *iter, unsigned long addr,
733 enum trace_type type, int cpu, pid_t pid, u32 flags)
734 {
735 struct trace_array *tr = iter->tr;
736 struct trace_seq *s = &iter->seq;
737 struct trace_entry *ent = iter->ent;
738
739 addr += iter->tr->text_delta;
740
741 if (addr < (unsigned long)__irqentry_text_start ||
742 addr >= (unsigned long)__irqentry_text_end)
743 return;
744
745 if (tr->trace_flags & TRACE_ITER(CONTEXT_INFO)) {
746 /* Absolute time */
747 if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
748 print_graph_abs_time(iter->ts, s);
749
750 /* Relative time */
751 if (flags & TRACE_GRAPH_PRINT_REL_TIME)
752 print_graph_rel_time(iter, s);
753
754 /* Cpu */
755 if (flags & TRACE_GRAPH_PRINT_CPU)
756 print_graph_cpu(s, cpu);
757
758 /* Proc */
759 if (flags & TRACE_GRAPH_PRINT_PROC) {
760 print_graph_proc(s, pid);
761 trace_seq_puts(s, " | ");
762 }
763
764 /* Latency format */
765 if (tr->trace_flags & TRACE_ITER(LATENCY_FMT))
766 print_graph_lat_fmt(s, ent);
767 }
768
769 /* No overhead */
770 print_graph_duration(tr, 0, s, flags | FLAGS_FILL_START);
771
772 if (type == TRACE_GRAPH_ENT)
773 trace_seq_puts(s, "==========>");
774 else
775 trace_seq_puts(s, "<==========");
776
777 print_graph_duration(tr, 0, s, flags | FLAGS_FILL_END);
778 trace_seq_putc(s, '\n');
779 }
780
781 void
trace_print_graph_duration(unsigned long long duration,struct trace_seq * s)782 trace_print_graph_duration(unsigned long long duration, struct trace_seq *s)
783 {
784 unsigned long nsecs_rem = do_div(duration, 1000);
785 /* log10(ULONG_MAX) + '\0' */
786 char usecs_str[21];
787 char nsecs_str[5];
788 int len;
789 int i;
790
791 sprintf(usecs_str, "%lu", (unsigned long) duration);
792
793 /* Print msecs */
794 trace_seq_printf(s, "%s", usecs_str);
795
796 len = strlen(usecs_str);
797
798 /* Print nsecs (we don't want to exceed 7 numbers) */
799 if (len < 7) {
800 size_t slen = min_t(size_t, sizeof(nsecs_str), 8UL - len);
801
802 snprintf(nsecs_str, slen, "%03lu", nsecs_rem);
803 trace_seq_printf(s, ".%s", nsecs_str);
804 len += strlen(nsecs_str) + 1;
805 }
806
807 trace_seq_puts(s, " us ");
808
809 /* Print remaining spaces to fit the row's width */
810 for (i = len; i < 8; i++)
811 trace_seq_putc(s, ' ');
812 }
813
814 static void
print_graph_duration(struct trace_array * tr,unsigned long long duration,struct trace_seq * s,u32 flags)815 print_graph_duration(struct trace_array *tr, unsigned long long duration,
816 struct trace_seq *s, u32 flags)
817 {
818 if (!(flags & TRACE_GRAPH_PRINT_DURATION) ||
819 !(tr->trace_flags & TRACE_ITER(CONTEXT_INFO)))
820 return;
821
822 /* No real adata, just filling the column with spaces */
823 switch (flags & TRACE_GRAPH_PRINT_FILL_MASK) {
824 case FLAGS_FILL_FULL:
825 trace_seq_puts(s, " | ");
826 return;
827 case FLAGS_FILL_START:
828 trace_seq_puts(s, " ");
829 return;
830 case FLAGS_FILL_END:
831 trace_seq_puts(s, " |");
832 return;
833 }
834
835 /* Signal a overhead of time execution to the output */
836 if (flags & TRACE_GRAPH_PRINT_OVERHEAD)
837 trace_seq_printf(s, "%c ", trace_find_mark(duration));
838 else
839 trace_seq_puts(s, " ");
840
841 trace_print_graph_duration(duration, s);
842 trace_seq_puts(s, "| ");
843 }
844
845 #ifdef CONFIG_FUNCTION_GRAPH_RETVAL
846 #define __TRACE_GRAPH_PRINT_RETVAL TRACE_GRAPH_PRINT_RETVAL
847 #else
848 #define __TRACE_GRAPH_PRINT_RETVAL 0
849 #endif
850
851 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
852 #define __TRACE_GRAPH_PRINT_RETADDR TRACE_GRAPH_PRINT_RETADDR
print_graph_retaddr(struct trace_seq * s,struct fgraph_retaddr_ent_entry * entry,u32 trace_flags,bool comment)853 static void print_graph_retaddr(struct trace_seq *s, struct fgraph_retaddr_ent_entry *entry,
854 u32 trace_flags, bool comment)
855 {
856 if (comment)
857 trace_seq_puts(s, " /*");
858
859 trace_seq_puts(s, " <-");
860 seq_print_ip_sym_offset(s, entry->graph_rent.retaddr, trace_flags);
861
862 if (comment)
863 trace_seq_puts(s, " */");
864 }
865 #else
866 #define __TRACE_GRAPH_PRINT_RETADDR 0
867 #define print_graph_retaddr(_seq, _entry, _tflags, _comment) do { } while (0)
868 #endif
869
870 #if defined(CONFIG_FUNCTION_GRAPH_RETVAL) || defined(CONFIG_FUNCTION_GRAPH_RETADDR)
871
print_graph_retval(struct trace_seq * s,struct ftrace_graph_ent_entry * entry,struct ftrace_graph_ret * graph_ret,void * func,u32 opt_flags,u32 trace_flags,int args_size)872 static void print_graph_retval(struct trace_seq *s, struct ftrace_graph_ent_entry *entry,
873 struct ftrace_graph_ret *graph_ret, void *func,
874 u32 opt_flags, u32 trace_flags, int args_size)
875 {
876 unsigned long err_code = 0;
877 unsigned long retval = 0;
878 bool print_retaddr = false;
879 bool print_retval = false;
880 bool hex_format = !!(opt_flags & TRACE_GRAPH_PRINT_RETVAL_HEX);
881
882 #ifdef CONFIG_FUNCTION_GRAPH_RETVAL
883 retval = graph_ret->retval;
884 print_retval = !!(opt_flags & TRACE_GRAPH_PRINT_RETVAL);
885 #endif
886
887 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
888 print_retaddr = !!(opt_flags & TRACE_GRAPH_PRINT_RETADDR);
889 #endif
890
891 if (print_retval && retval && !hex_format) {
892 /* Check if the return value matches the negative format */
893 if (IS_ENABLED(CONFIG_64BIT) && (retval & BIT(31)) &&
894 (((u64)retval) >> 32) == 0) {
895 err_code = sign_extend64(retval, 31);
896 } else {
897 err_code = retval;
898 }
899
900 if (!IS_ERR_VALUE(err_code))
901 err_code = 0;
902 }
903
904 if (entry) {
905 if (entry->ent.type != TRACE_GRAPH_RETADDR_ENT)
906 print_retaddr = false;
907
908 trace_seq_printf(s, "%ps", func);
909
910 if (args_size >= FTRACE_REGS_MAX_ARGS * sizeof(long)) {
911 print_function_args(s, FGRAPH_ENTRY_ARGS(entry), (unsigned long)func);
912 trace_seq_putc(s, ';');
913 } else
914 trace_seq_puts(s, "();");
915
916 if (print_retval || print_retaddr)
917 trace_seq_puts(s, " /*");
918 } else {
919 print_retaddr = false;
920 trace_seq_printf(s, "} /* %ps", func);
921 }
922
923 if (print_retaddr)
924 print_graph_retaddr(s, (struct fgraph_retaddr_ent_entry *)entry,
925 trace_flags, false);
926
927 if (print_retval) {
928 if (hex_format || (err_code == 0))
929 trace_seq_printf(s, " ret=0x%lx", retval);
930 else
931 trace_seq_printf(s, " ret=%ld", err_code);
932 }
933
934 if (!entry || print_retval || print_retaddr)
935 trace_seq_puts(s, " */");
936 }
937
938 #else
939
940 #define print_graph_retval(_seq, _ent, _ret, _func, _opt_flags, _trace_flags, args_size) \
941 do {} while (0)
942
943 #endif
944
945 /* Case of a leaf function on its call entry */
946 static enum print_line_t
print_graph_entry_leaf(struct trace_iterator * iter,struct ftrace_graph_ent_entry * entry,struct ftrace_graph_ret_entry * ret_entry,struct trace_seq * s,u32 flags)947 print_graph_entry_leaf(struct trace_iterator *iter,
948 struct ftrace_graph_ent_entry *entry,
949 struct ftrace_graph_ret_entry *ret_entry,
950 struct trace_seq *s, u32 flags)
951 {
952 struct fgraph_data *data = iter->private;
953 struct trace_array *tr = iter->tr;
954 struct ftrace_graph_ret *graph_ret;
955 struct ftrace_graph_ent *call;
956 unsigned long long duration;
957 unsigned long ret_func;
958 int args_size;
959 int cpu = iter->cpu;
960 int i;
961
962 args_size = iter->ent_size - offsetof(struct ftrace_graph_ent_entry, args);
963
964 graph_ret = &ret_entry->ret;
965 call = &entry->graph_ent;
966 duration = ret_entry->rettime - ret_entry->calltime;
967
968 if (data) {
969 struct fgraph_cpu_data *cpu_data;
970
971 cpu_data = per_cpu_ptr(data->cpu_data, cpu);
972
973 /*
974 * Comments display at + 1 to depth. Since
975 * this is a leaf function, keep the comments
976 * equal to this depth.
977 */
978 cpu_data->depth = call->depth - 1;
979
980 /* No need to keep this function around for this depth */
981 if (call->depth < FTRACE_RETFUNC_DEPTH &&
982 !WARN_ON_ONCE(call->depth < 0))
983 cpu_data->enter_funcs[call->depth] = 0;
984 }
985
986 /* Overhead and duration */
987 print_graph_duration(tr, duration, s, flags);
988
989 /* Function */
990 for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
991 trace_seq_putc(s, ' ');
992
993 ret_func = graph_ret->func + iter->tr->text_delta;
994
995 /*
996 * Write out the function return value or return address
997 */
998 if (flags & (__TRACE_GRAPH_PRINT_RETVAL | __TRACE_GRAPH_PRINT_RETADDR)) {
999 print_graph_retval(s, entry, graph_ret,
1000 (void *)graph_ret->func + iter->tr->text_delta,
1001 flags, tr->trace_flags, args_size);
1002 } else {
1003 trace_seq_printf(s, "%ps", (void *)ret_func);
1004
1005 if (args_size >= FTRACE_REGS_MAX_ARGS * sizeof(long)) {
1006 print_function_args(s, FGRAPH_ENTRY_ARGS(entry), ret_func);
1007 trace_seq_putc(s, ';');
1008 } else
1009 trace_seq_puts(s, "();");
1010 }
1011 trace_seq_putc(s, '\n');
1012
1013 print_graph_irq(iter, graph_ret->func, TRACE_GRAPH_RET,
1014 cpu, iter->ent->pid, flags);
1015
1016 return trace_handle_return(s);
1017 }
1018
1019 static enum print_line_t
print_graph_entry_nested(struct trace_iterator * iter,struct ftrace_graph_ent_entry * entry,struct trace_seq * s,int cpu,u32 flags)1020 print_graph_entry_nested(struct trace_iterator *iter,
1021 struct ftrace_graph_ent_entry *entry,
1022 struct trace_seq *s, int cpu, u32 flags)
1023 {
1024 struct ftrace_graph_ent *call = &entry->graph_ent;
1025 struct fgraph_data *data = iter->private;
1026 struct trace_array *tr = iter->tr;
1027 unsigned long func;
1028 int args_size;
1029 int i;
1030
1031 if (data) {
1032 struct fgraph_cpu_data *cpu_data;
1033 int cpu = iter->cpu;
1034
1035 cpu_data = per_cpu_ptr(data->cpu_data, cpu);
1036 cpu_data->depth = call->depth;
1037
1038 /* Save this function pointer to see if the exit matches */
1039 if (call->depth < FTRACE_RETFUNC_DEPTH &&
1040 !WARN_ON_ONCE(call->depth < 0))
1041 cpu_data->enter_funcs[call->depth] = call->func;
1042 }
1043
1044 /* No time */
1045 print_graph_duration(tr, 0, s, flags | FLAGS_FILL_FULL);
1046
1047 /* Function */
1048 for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++)
1049 trace_seq_putc(s, ' ');
1050
1051 func = call->func + iter->tr->text_delta;
1052
1053 trace_seq_printf(s, "%ps", (void *)func);
1054
1055 args_size = iter->ent_size - offsetof(struct ftrace_graph_ent_entry, args);
1056
1057 if (args_size >= FTRACE_REGS_MAX_ARGS * sizeof(long))
1058 print_function_args(s, FGRAPH_ENTRY_ARGS(entry), func);
1059 else
1060 trace_seq_puts(s, "()");
1061
1062 trace_seq_puts(s, " {");
1063
1064 if (flags & __TRACE_GRAPH_PRINT_RETADDR &&
1065 entry->ent.type == TRACE_GRAPH_RETADDR_ENT)
1066 print_graph_retaddr(s, (struct fgraph_retaddr_ent_entry *)entry,
1067 tr->trace_flags, true);
1068 trace_seq_putc(s, '\n');
1069
1070 if (trace_seq_has_overflowed(s))
1071 return TRACE_TYPE_PARTIAL_LINE;
1072
1073 /*
1074 * we already consumed the current entry to check the next one
1075 * and see if this is a leaf.
1076 */
1077 return TRACE_TYPE_NO_CONSUME;
1078 }
1079
1080 static void
print_graph_prologue(struct trace_iterator * iter,struct trace_seq * s,int type,unsigned long addr,u32 flags)1081 print_graph_prologue(struct trace_iterator *iter, struct trace_seq *s,
1082 int type, unsigned long addr, u32 flags)
1083 {
1084 struct fgraph_data *data = iter->private;
1085 struct trace_entry *ent = iter->ent;
1086 struct trace_array *tr = iter->tr;
1087 int cpu = iter->cpu;
1088
1089 /* Pid */
1090 verif_pid(s, ent->pid, cpu, data);
1091
1092 if (type)
1093 /* Interrupt */
1094 print_graph_irq(iter, addr, type, cpu, ent->pid, flags);
1095
1096 if (!(tr->trace_flags & TRACE_ITER(CONTEXT_INFO)))
1097 return;
1098
1099 /* Absolute time */
1100 if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
1101 print_graph_abs_time(iter->ts, s);
1102
1103 /* Relative time */
1104 if (flags & TRACE_GRAPH_PRINT_REL_TIME)
1105 print_graph_rel_time(iter, s);
1106
1107 /* Cpu */
1108 if (flags & TRACE_GRAPH_PRINT_CPU)
1109 print_graph_cpu(s, cpu);
1110
1111 /* Proc */
1112 if (flags & TRACE_GRAPH_PRINT_PROC) {
1113 print_graph_proc(s, ent->pid);
1114 trace_seq_puts(s, " | ");
1115 }
1116
1117 /* Latency format */
1118 if (tr->trace_flags & TRACE_ITER(LATENCY_FMT))
1119 print_graph_lat_fmt(s, ent);
1120
1121 return;
1122 }
1123
1124 /*
1125 * Entry check for irq code
1126 *
1127 * returns 1 if
1128 * - we are inside irq code
1129 * - we just entered irq code
1130 *
1131 * returns 0 if
1132 * - funcgraph-interrupts option is set
1133 * - we are not inside irq code
1134 */
1135 static int
check_irq_entry(struct trace_iterator * iter,u32 flags,unsigned long addr,int depth)1136 check_irq_entry(struct trace_iterator *iter, u32 flags,
1137 unsigned long addr, int depth)
1138 {
1139 int cpu = iter->cpu;
1140 int *depth_irq;
1141 struct fgraph_data *data = iter->private;
1142
1143 addr += iter->tr->text_delta;
1144
1145 /*
1146 * If we are either displaying irqs, or we got called as
1147 * a graph event and private data does not exist,
1148 * then we bypass the irq check.
1149 */
1150 if ((flags & TRACE_GRAPH_PRINT_IRQS) ||
1151 (!data))
1152 return 0;
1153
1154 depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq);
1155
1156 /*
1157 * We are inside the irq code
1158 */
1159 if (*depth_irq >= 0)
1160 return 1;
1161
1162 if ((addr < (unsigned long)__irqentry_text_start) ||
1163 (addr >= (unsigned long)__irqentry_text_end))
1164 return 0;
1165
1166 /*
1167 * We are entering irq code.
1168 */
1169 *depth_irq = depth;
1170 return 1;
1171 }
1172
1173 /*
1174 * Return check for irq code
1175 *
1176 * returns 1 if
1177 * - we are inside irq code
1178 * - we just left irq code
1179 *
1180 * returns 0 if
1181 * - funcgraph-interrupts option is set
1182 * - we are not inside irq code
1183 */
1184 static int
check_irq_return(struct trace_iterator * iter,u32 flags,int depth)1185 check_irq_return(struct trace_iterator *iter, u32 flags, int depth)
1186 {
1187 int cpu = iter->cpu;
1188 int *depth_irq;
1189 struct fgraph_data *data = iter->private;
1190
1191 /*
1192 * If we are either displaying irqs, or we got called as
1193 * a graph event and private data does not exist,
1194 * then we bypass the irq check.
1195 */
1196 if ((flags & TRACE_GRAPH_PRINT_IRQS) ||
1197 (!data))
1198 return 0;
1199
1200 depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq);
1201
1202 /*
1203 * We are not inside the irq code.
1204 */
1205 if (*depth_irq == -1)
1206 return 0;
1207
1208 /*
1209 * We are inside the irq code, and this is returning entry.
1210 * Let's not trace it and clear the entry depth, since
1211 * we are out of irq code.
1212 *
1213 * This condition ensures that we 'leave the irq code' once
1214 * we are out of the entry depth. Thus protecting us from
1215 * the RETURN entry loss.
1216 */
1217 if (*depth_irq >= depth) {
1218 *depth_irq = -1;
1219 return 1;
1220 }
1221
1222 /*
1223 * We are inside the irq code, and this is not the entry.
1224 */
1225 return 1;
1226 }
1227
1228 static enum print_line_t
print_graph_entry(struct ftrace_graph_ent_entry * field,struct trace_seq * s,struct trace_iterator * iter,u32 flags)1229 print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
1230 struct trace_iterator *iter, u32 flags)
1231 {
1232 struct fgraph_data *data = iter->private;
1233 struct ftrace_graph_ent *call;
1234 struct ftrace_graph_ret_entry *leaf_ret;
1235 static enum print_line_t ret;
1236 int cpu = iter->cpu;
1237 /*
1238 * print_graph_entry() may consume the current event,
1239 * thus @field may become invalid, so we need to save it.
1240 * This function is shared by ftrace_graph_ent_entry and
1241 * fgraph_retaddr_ent_entry, the size of the latter one
1242 * is larger, but it is very small and can be safely saved
1243 * at the stack.
1244 */
1245 struct ftrace_graph_ent_entry *entry;
1246 struct fgraph_retaddr_ent_entry *rentry;
1247 u8 save_buf[sizeof(*rentry) + FTRACE_REGS_MAX_ARGS * sizeof(long)];
1248
1249 /* The ent_size is expected to be as big as the entry */
1250 if (iter->ent_size > sizeof(save_buf))
1251 iter->ent_size = sizeof(save_buf);
1252
1253 entry = (void *)save_buf;
1254 memcpy(entry, field, iter->ent_size);
1255
1256 call = &entry->graph_ent;
1257
1258 if (check_irq_entry(iter, flags, call->func, call->depth))
1259 return TRACE_TYPE_HANDLED;
1260
1261 print_graph_prologue(iter, s, TRACE_GRAPH_ENT, call->func, flags);
1262
1263 leaf_ret = get_return_for_leaf(iter, entry);
1264 if (leaf_ret)
1265 ret = print_graph_entry_leaf(iter, entry, leaf_ret, s, flags);
1266 else
1267 ret = print_graph_entry_nested(iter, entry, s, cpu, flags);
1268
1269 if (data) {
1270 /*
1271 * If we failed to write our output, then we need to make
1272 * note of it. Because we already consumed our entry.
1273 */
1274 if (s->full) {
1275 data->failed = 1;
1276 data->cpu = cpu;
1277 } else
1278 data->failed = 0;
1279 }
1280
1281 return ret;
1282 }
1283
1284 static enum print_line_t
print_graph_return(struct ftrace_graph_ret_entry * retentry,struct trace_seq * s,struct trace_entry * ent,struct trace_iterator * iter,u32 flags)1285 print_graph_return(struct ftrace_graph_ret_entry *retentry, struct trace_seq *s,
1286 struct trace_entry *ent, struct trace_iterator *iter,
1287 u32 flags)
1288 {
1289 struct ftrace_graph_ret *trace = &retentry->ret;
1290 u64 calltime = retentry->calltime;
1291 u64 rettime = retentry->rettime;
1292 unsigned long long duration = rettime - calltime;
1293 struct fgraph_data *data = iter->private;
1294 struct trace_array *tr = iter->tr;
1295 unsigned long func;
1296 pid_t pid = ent->pid;
1297 int cpu = iter->cpu;
1298 int func_match = 1;
1299 int i;
1300
1301 func = trace->func + iter->tr->text_delta;
1302
1303 if (check_irq_return(iter, flags, trace->depth))
1304 return TRACE_TYPE_HANDLED;
1305
1306 if (data) {
1307 struct fgraph_cpu_data *cpu_data;
1308 int cpu = iter->cpu;
1309
1310 cpu_data = per_cpu_ptr(data->cpu_data, cpu);
1311
1312 /*
1313 * Comments display at + 1 to depth. This is the
1314 * return from a function, we now want the comments
1315 * to display at the same level of the bracket.
1316 */
1317 cpu_data->depth = trace->depth - 1;
1318
1319 if (trace->depth < FTRACE_RETFUNC_DEPTH &&
1320 !WARN_ON_ONCE(trace->depth < 0)) {
1321 if (cpu_data->enter_funcs[trace->depth] != trace->func)
1322 func_match = 0;
1323 cpu_data->enter_funcs[trace->depth] = 0;
1324 }
1325 }
1326
1327 print_graph_prologue(iter, s, 0, 0, flags);
1328
1329 /* Overhead and duration */
1330 print_graph_duration(tr, duration, s, flags);
1331
1332 /* Closing brace */
1333 for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++)
1334 trace_seq_putc(s, ' ');
1335
1336 /*
1337 * Always write out the function name and its return value if the
1338 * funcgraph-retval option is enabled.
1339 */
1340 if (flags & __TRACE_GRAPH_PRINT_RETVAL) {
1341 print_graph_retval(s, NULL, trace, (void *)func, flags,
1342 tr->trace_flags, 0);
1343 } else {
1344 /*
1345 * If the return function does not have a matching entry,
1346 * then the entry was lost. Instead of just printing
1347 * the '}' and letting the user guess what function this
1348 * belongs to, write out the function name. Always do
1349 * that if the funcgraph-tail option is enabled.
1350 */
1351 if (func_match && !(flags & TRACE_GRAPH_PRINT_TAIL))
1352 trace_seq_puts(s, "}");
1353 else
1354 trace_seq_printf(s, "} /* %ps */", (void *)func);
1355 }
1356 trace_seq_putc(s, '\n');
1357
1358 /* Overrun */
1359 if (flags & TRACE_GRAPH_PRINT_OVERRUN)
1360 trace_seq_printf(s, " (Overruns: %u)\n",
1361 trace->overrun);
1362
1363 print_graph_irq(iter, trace->func, TRACE_GRAPH_RET,
1364 cpu, pid, flags);
1365
1366 return trace_handle_return(s);
1367 }
1368
1369 static enum print_line_t
print_graph_comment(struct trace_seq * s,struct trace_entry * ent,struct trace_iterator * iter,u32 flags)1370 print_graph_comment(struct trace_seq *s, struct trace_entry *ent,
1371 struct trace_iterator *iter, u32 flags)
1372 {
1373 struct trace_array *tr = iter->tr;
1374 unsigned long sym_flags = (tr->trace_flags & TRACE_ITER_SYM_MASK);
1375 struct fgraph_data *data = iter->private;
1376 struct trace_event *event;
1377 int depth = 0;
1378 int ret;
1379 int i;
1380
1381 if (data)
1382 depth = per_cpu_ptr(data->cpu_data, iter->cpu)->depth;
1383
1384 print_graph_prologue(iter, s, 0, 0, flags);
1385
1386 /* No time */
1387 print_graph_duration(tr, 0, s, flags | FLAGS_FILL_FULL);
1388
1389 /* Indentation */
1390 if (depth > 0)
1391 for (i = 0; i < (depth + 1) * TRACE_GRAPH_INDENT; i++)
1392 trace_seq_putc(s, ' ');
1393
1394 /* The comment */
1395 trace_seq_puts(s, "/* ");
1396
1397 switch (iter->ent->type) {
1398 case TRACE_BPUTS:
1399 ret = trace_print_bputs_msg_only(iter);
1400 if (ret != TRACE_TYPE_HANDLED)
1401 return ret;
1402 break;
1403 case TRACE_BPRINT:
1404 ret = trace_print_bprintk_msg_only(iter);
1405 if (ret != TRACE_TYPE_HANDLED)
1406 return ret;
1407 break;
1408 case TRACE_PRINT:
1409 ret = trace_print_printk_msg_only(iter);
1410 if (ret != TRACE_TYPE_HANDLED)
1411 return ret;
1412 break;
1413 default:
1414 event = ftrace_find_event(ent->type);
1415 if (!event)
1416 return TRACE_TYPE_UNHANDLED;
1417
1418 ret = event->funcs->trace(iter, sym_flags, event);
1419 if (ret != TRACE_TYPE_HANDLED)
1420 return ret;
1421 }
1422
1423 if (trace_seq_has_overflowed(s))
1424 goto out;
1425
1426 /* Strip ending newline */
1427 if (s->buffer[s->seq.len - 1] == '\n') {
1428 s->buffer[s->seq.len - 1] = '\0';
1429 s->seq.len--;
1430 }
1431
1432 trace_seq_puts(s, " */\n");
1433 out:
1434 return trace_handle_return(s);
1435 }
1436
1437
1438 enum print_line_t
print_graph_function_flags(struct trace_iterator * iter,u32 flags)1439 print_graph_function_flags(struct trace_iterator *iter, u32 flags)
1440 {
1441 struct ftrace_graph_ent_entry *field;
1442 struct fgraph_data *data = iter->private;
1443 struct trace_entry *entry = iter->ent;
1444 struct trace_seq *s = &iter->seq;
1445 int cpu = iter->cpu;
1446 int ret;
1447
1448 if (data && per_cpu_ptr(data->cpu_data, cpu)->ignore) {
1449 per_cpu_ptr(data->cpu_data, cpu)->ignore = 0;
1450 return TRACE_TYPE_HANDLED;
1451 }
1452
1453 /*
1454 * If the last output failed, there's a possibility we need
1455 * to print out the missing entry which would never go out.
1456 */
1457 if (data && data->failed) {
1458 field = &data->ent.ent;
1459 iter->cpu = data->cpu;
1460 ret = print_graph_entry(field, s, iter, flags);
1461 if (ret == TRACE_TYPE_HANDLED && iter->cpu != cpu) {
1462 per_cpu_ptr(data->cpu_data, iter->cpu)->ignore = 1;
1463 ret = TRACE_TYPE_NO_CONSUME;
1464 }
1465 iter->cpu = cpu;
1466 return ret;
1467 }
1468
1469 switch (entry->type) {
1470 case TRACE_GRAPH_ENT: {
1471 trace_assign_type(field, entry);
1472 return print_graph_entry(field, s, iter, flags);
1473 }
1474 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
1475 case TRACE_GRAPH_RETADDR_ENT: {
1476 /*
1477 * ftrace_graph_ent_entry and fgraph_retaddr_ent_entry have
1478 * similar functions and memory layouts. The only difference
1479 * is that the latter one has an extra retaddr member, so
1480 * they can share most of the logic.
1481 */
1482 struct fgraph_retaddr_ent_entry *rfield;
1483
1484 trace_assign_type(rfield, entry);
1485 return print_graph_entry((struct ftrace_graph_ent_entry *)rfield,
1486 s, iter, flags);
1487 }
1488 #endif
1489 case TRACE_GRAPH_RET: {
1490 struct ftrace_graph_ret_entry *field;
1491 trace_assign_type(field, entry);
1492 return print_graph_return(field, s, entry, iter, flags);
1493 }
1494 case TRACE_STACK:
1495 case TRACE_FN:
1496 /* dont trace stack and functions as comments */
1497 return TRACE_TYPE_UNHANDLED;
1498
1499 default:
1500 return print_graph_comment(s, entry, iter, flags);
1501 }
1502
1503 return TRACE_TYPE_HANDLED;
1504 }
1505
1506 static enum print_line_t
print_graph_function(struct trace_iterator * iter)1507 print_graph_function(struct trace_iterator *iter)
1508 {
1509 struct trace_array *tr = iter->tr;
1510 return print_graph_function_flags(iter, tr->current_trace_flags->val);
1511 }
1512
1513 static enum print_line_t
print_graph_function_event(struct trace_iterator * iter,int flags,struct trace_event * event)1514 print_graph_function_event(struct trace_iterator *iter, int flags,
1515 struct trace_event *event)
1516 {
1517 return print_graph_function(iter);
1518 }
1519
print_lat_header(struct seq_file * s,u32 flags)1520 static void print_lat_header(struct seq_file *s, u32 flags)
1521 {
1522 static const char spaces[] = " " /* 16 spaces */
1523 " " /* 4 spaces */
1524 " "; /* 17 spaces */
1525 int size = 0;
1526
1527 if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
1528 size += 16;
1529 if (flags & TRACE_GRAPH_PRINT_REL_TIME)
1530 size += 16;
1531 if (flags & TRACE_GRAPH_PRINT_CPU)
1532 size += 4;
1533 if (flags & TRACE_GRAPH_PRINT_PROC)
1534 size += 17;
1535
1536 seq_printf(s, "#%.*s _-----=> irqs-off \n", size, spaces);
1537 seq_printf(s, "#%.*s / _----=> need-resched \n", size, spaces);
1538 seq_printf(s, "#%.*s| / _---=> hardirq/softirq \n", size, spaces);
1539 seq_printf(s, "#%.*s|| / _--=> preempt-depth \n", size, spaces);
1540 seq_printf(s, "#%.*s||| / \n", size, spaces);
1541 }
1542
__print_graph_headers_flags(struct trace_array * tr,struct seq_file * s,u32 flags)1543 static void __print_graph_headers_flags(struct trace_array *tr,
1544 struct seq_file *s, u32 flags)
1545 {
1546 int lat = tr->trace_flags & TRACE_ITER(LATENCY_FMT);
1547
1548 if (lat)
1549 print_lat_header(s, flags);
1550
1551 /* 1st line */
1552 seq_putc(s, '#');
1553 if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
1554 seq_puts(s, " TIME ");
1555 if (flags & TRACE_GRAPH_PRINT_REL_TIME)
1556 seq_puts(s, " REL TIME ");
1557 if (flags & TRACE_GRAPH_PRINT_CPU)
1558 seq_puts(s, " CPU");
1559 if (flags & TRACE_GRAPH_PRINT_PROC)
1560 seq_puts(s, " TASK/PID ");
1561 if (lat)
1562 seq_puts(s, "|||| ");
1563 if (flags & TRACE_GRAPH_PRINT_DURATION)
1564 seq_puts(s, " DURATION ");
1565 seq_puts(s, " FUNCTION CALLS\n");
1566
1567 /* 2nd line */
1568 seq_putc(s, '#');
1569 if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
1570 seq_puts(s, " | ");
1571 if (flags & TRACE_GRAPH_PRINT_REL_TIME)
1572 seq_puts(s, " | ");
1573 if (flags & TRACE_GRAPH_PRINT_CPU)
1574 seq_puts(s, " | ");
1575 if (flags & TRACE_GRAPH_PRINT_PROC)
1576 seq_puts(s, " | | ");
1577 if (lat)
1578 seq_puts(s, "|||| ");
1579 if (flags & TRACE_GRAPH_PRINT_DURATION)
1580 seq_puts(s, " | | ");
1581 seq_puts(s, " | | | |\n");
1582 }
1583
print_graph_headers(struct seq_file * s)1584 static void print_graph_headers(struct seq_file *s)
1585 {
1586 struct trace_iterator *iter = s->private;
1587 struct trace_array *tr = iter->tr;
1588
1589 print_graph_headers_flags(s, tr->current_trace_flags->val);
1590 }
1591
print_graph_headers_flags(struct seq_file * s,u32 flags)1592 void print_graph_headers_flags(struct seq_file *s, u32 flags)
1593 {
1594 struct trace_iterator *iter = s->private;
1595 struct trace_array *tr = iter->tr;
1596
1597 if (!(tr->trace_flags & TRACE_ITER(CONTEXT_INFO)))
1598 return;
1599
1600 if (tr->trace_flags & TRACE_ITER(LATENCY_FMT)) {
1601 /* print nothing if the buffers are empty */
1602 if (trace_empty(iter))
1603 return;
1604
1605 print_trace_header(s, iter);
1606 }
1607
1608 __print_graph_headers_flags(tr, s, flags);
1609 }
1610
graph_trace_open(struct trace_iterator * iter)1611 void graph_trace_open(struct trace_iterator *iter)
1612 {
1613 /* pid and depth on the last trace processed */
1614 struct fgraph_data *data;
1615 gfp_t gfpflags;
1616 int cpu;
1617
1618 iter->private = NULL;
1619
1620 /* We can be called in atomic context via ftrace_dump() */
1621 gfpflags = (in_atomic() || irqs_disabled()) ? GFP_ATOMIC : GFP_KERNEL;
1622
1623 data = kzalloc_obj(*data, gfpflags);
1624 if (!data)
1625 goto out_err;
1626
1627 data->cpu_data = alloc_percpu_gfp(struct fgraph_cpu_data, gfpflags);
1628 if (!data->cpu_data)
1629 goto out_err_free;
1630
1631 for_each_possible_cpu(cpu) {
1632 pid_t *pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid);
1633 int *depth = &(per_cpu_ptr(data->cpu_data, cpu)->depth);
1634 int *ignore = &(per_cpu_ptr(data->cpu_data, cpu)->ignore);
1635 int *depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq);
1636
1637 *pid = -1;
1638 *depth = 0;
1639 *ignore = 0;
1640 *depth_irq = -1;
1641 }
1642
1643 iter->private = data;
1644
1645 return;
1646
1647 out_err_free:
1648 kfree(data);
1649 out_err:
1650 pr_warn("function graph tracer: not enough memory\n");
1651 }
1652
graph_trace_close(struct trace_iterator * iter)1653 void graph_trace_close(struct trace_iterator *iter)
1654 {
1655 struct fgraph_data *data = iter->private;
1656
1657 if (data) {
1658 free_percpu(data->cpu_data);
1659 kfree(data);
1660 iter->private = NULL;
1661 }
1662 }
1663
1664 static int
func_graph_set_flag(struct trace_array * tr,u32 old_flags,u32 bit,int set)1665 func_graph_set_flag(struct trace_array *tr, u32 old_flags, u32 bit, int set)
1666 {
1667 /*
1668 * The function profiler gets updated even if function graph
1669 * isn't the current tracer. Handle it separately.
1670 */
1671 #ifdef CONFIG_FUNCTION_PROFILER
1672 if (bit == TRACE_GRAPH_SLEEP_TIME && (tr->flags & TRACE_ARRAY_FL_GLOBAL) &&
1673 !!set == fprofile_no_sleep_time) {
1674 if (set) {
1675 fgraph_no_sleep_time--;
1676 if (WARN_ON_ONCE(fgraph_no_sleep_time < 0))
1677 fgraph_no_sleep_time = 0;
1678 fprofile_no_sleep_time = false;
1679 } else {
1680 fgraph_no_sleep_time++;
1681 fprofile_no_sleep_time = true;
1682 }
1683 }
1684 #endif
1685
1686 /* Do nothing if the current tracer is not this tracer */
1687 if (tr->current_trace != &graph_trace)
1688 return 0;
1689
1690 /* Do nothing if already set. */
1691 if (!!set == !!(tr->current_trace_flags->val & bit))
1692 return 0;
1693
1694 switch (bit) {
1695 case TRACE_GRAPH_SLEEP_TIME:
1696 if (set) {
1697 fgraph_no_sleep_time--;
1698 if (WARN_ON_ONCE(fgraph_no_sleep_time < 0))
1699 fgraph_no_sleep_time = 0;
1700 } else {
1701 fgraph_no_sleep_time++;
1702 }
1703 break;
1704
1705 case TRACE_GRAPH_PRINT_IRQS:
1706 if (set)
1707 ftrace_graph_skip_irqs--;
1708 else
1709 ftrace_graph_skip_irqs++;
1710 if (WARN_ON_ONCE(ftrace_graph_skip_irqs < 0))
1711 ftrace_graph_skip_irqs = 0;
1712 break;
1713
1714 case TRACE_GRAPH_ARGS:
1715 return ftrace_graph_trace_args(tr, set);
1716 }
1717
1718 return 0;
1719 }
1720
1721 static struct trace_event_functions graph_functions = {
1722 .trace = print_graph_function_event,
1723 };
1724
1725 static struct trace_event graph_trace_entry_event = {
1726 .type = TRACE_GRAPH_ENT,
1727 .funcs = &graph_functions,
1728 };
1729
1730 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
1731 static struct trace_event graph_trace_retaddr_entry_event = {
1732 .type = TRACE_GRAPH_RETADDR_ENT,
1733 .funcs = &graph_functions,
1734 };
1735 #endif
1736
1737 static struct trace_event graph_trace_ret_event = {
1738 .type = TRACE_GRAPH_RET,
1739 .funcs = &graph_functions
1740 };
1741
1742 static struct tracer graph_trace __tracer_data = {
1743 .name = "function_graph",
1744 .update_thresh = graph_trace_update_thresh,
1745 .open = graph_trace_open,
1746 .pipe_open = graph_trace_open,
1747 .close = graph_trace_close,
1748 .pipe_close = graph_trace_close,
1749 .init = graph_trace_init,
1750 .reset = graph_trace_reset,
1751 .print_line = print_graph_function,
1752 .print_header = print_graph_headers,
1753 .default_flags = &tracer_flags,
1754 .set_flag = func_graph_set_flag,
1755 .allow_instances = true,
1756 #ifdef CONFIG_FTRACE_SELFTEST
1757 .selftest = trace_selftest_startup_function_graph,
1758 #endif
1759 };
1760
1761
1762 static ssize_t
graph_depth_write(struct file * filp,const char __user * ubuf,size_t cnt,loff_t * ppos)1763 graph_depth_write(struct file *filp, const char __user *ubuf, size_t cnt,
1764 loff_t *ppos)
1765 {
1766 unsigned long val;
1767 int ret;
1768
1769 ret = kstrtoul_from_user(ubuf, cnt, 10, &val);
1770 if (ret)
1771 return ret;
1772
1773 fgraph_max_depth = val;
1774
1775 *ppos += cnt;
1776
1777 return cnt;
1778 }
1779
1780 static ssize_t
graph_depth_read(struct file * filp,char __user * ubuf,size_t cnt,loff_t * ppos)1781 graph_depth_read(struct file *filp, char __user *ubuf, size_t cnt,
1782 loff_t *ppos)
1783 {
1784 char buf[15]; /* More than enough to hold UINT_MAX + "\n"*/
1785 int n;
1786
1787 n = sprintf(buf, "%d\n", fgraph_max_depth);
1788
1789 return simple_read_from_buffer(ubuf, cnt, ppos, buf, n);
1790 }
1791
1792 static const struct file_operations graph_depth_fops = {
1793 .open = tracing_open_generic,
1794 .write = graph_depth_write,
1795 .read = graph_depth_read,
1796 .llseek = generic_file_llseek,
1797 };
1798
init_graph_tracefs(void)1799 static __init int init_graph_tracefs(void)
1800 {
1801 int ret;
1802
1803 ret = tracing_init_dentry();
1804 if (ret)
1805 return 0;
1806
1807 trace_create_file("max_graph_depth", TRACE_MODE_WRITE, NULL,
1808 NULL, &graph_depth_fops);
1809
1810 return 0;
1811 }
1812 fs_initcall(init_graph_tracefs);
1813
init_graph_trace(void)1814 static __init int init_graph_trace(void)
1815 {
1816 max_bytes_for_cpu = snprintf(NULL, 0, "%u", nr_cpu_ids - 1);
1817
1818 if (!register_trace_event(&graph_trace_entry_event)) {
1819 pr_warn("Warning: could not register graph trace events\n");
1820 return 1;
1821 }
1822
1823 #ifdef CONFIG_FUNCTION_GRAPH_RETADDR
1824 if (!register_trace_event(&graph_trace_retaddr_entry_event)) {
1825 pr_warn("Warning: could not register graph trace retaddr events\n");
1826 return 1;
1827 }
1828 #endif
1829
1830 if (!register_trace_event(&graph_trace_ret_event)) {
1831 pr_warn("Warning: could not register graph trace events\n");
1832 return 1;
1833 }
1834
1835 return register_tracer(&graph_trace);
1836 }
1837
1838 core_initcall(init_graph_trace);
1839