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