3 * Function graph tracer.
4 * Copyright (c) 2008-2009 Frederic Weisbecker <fweisbec@gmail.com>
5 * Mostly borrowed from function tracer which
6 * is Copyright (c) Steven Rostedt <srostedt@redhat.com>
9 #include <linux/debugfs.h>
10 #include <linux/uaccess.h>
11 #include <linux/ftrace.h>
15 #include "trace_output.h"
17 struct fgraph_cpu_data
{
21 unsigned long enter_funcs
[FTRACE_RETFUNC_DEPTH
];
25 struct fgraph_cpu_data
*cpu_data
;
27 /* Place to preserve last processed entry. */
28 struct ftrace_graph_ent_entry ent
;
29 struct ftrace_graph_ret_entry ret
;
34 #define TRACE_GRAPH_INDENT 2
37 #define TRACE_GRAPH_PRINT_OVERRUN 0x1
38 #define TRACE_GRAPH_PRINT_CPU 0x2
39 #define TRACE_GRAPH_PRINT_OVERHEAD 0x4
40 #define TRACE_GRAPH_PRINT_PROC 0x8
41 #define TRACE_GRAPH_PRINT_DURATION 0x10
42 #define TRACE_GRAPH_PRINT_ABS_TIME 0X20
44 static struct tracer_opt trace_opts
[] = {
45 /* Display overruns? (for self-debug purpose) */
46 { TRACER_OPT(funcgraph
-overrun
, TRACE_GRAPH_PRINT_OVERRUN
) },
48 { TRACER_OPT(funcgraph
-cpu
, TRACE_GRAPH_PRINT_CPU
) },
49 /* Display Overhead ? */
50 { TRACER_OPT(funcgraph
-overhead
, TRACE_GRAPH_PRINT_OVERHEAD
) },
51 /* Display proc name/pid */
52 { TRACER_OPT(funcgraph
-proc
, TRACE_GRAPH_PRINT_PROC
) },
53 /* Display duration of execution */
54 { TRACER_OPT(funcgraph
-duration
, TRACE_GRAPH_PRINT_DURATION
) },
55 /* Display absolute time of an entry */
56 { TRACER_OPT(funcgraph
-abstime
, TRACE_GRAPH_PRINT_ABS_TIME
) },
60 static struct tracer_flags tracer_flags
= {
61 /* Don't display overruns and proc by default */
62 .val
= TRACE_GRAPH_PRINT_CPU
| TRACE_GRAPH_PRINT_OVERHEAD
|
63 TRACE_GRAPH_PRINT_DURATION
,
67 static struct trace_array
*graph_array
;
70 /* Add a function return address to the trace stack on thread info.*/
72 ftrace_push_return_trace(unsigned long ret
, unsigned long func
, int *depth
,
73 unsigned long frame_pointer
)
75 unsigned long long calltime
;
78 if (!current
->ret_stack
)
82 * We must make sure the ret_stack is tested before we read
87 /* The return trace stack is full */
88 if (current
->curr_ret_stack
== FTRACE_RETFUNC_DEPTH
- 1) {
89 atomic_inc(¤t
->trace_overrun
);
93 calltime
= trace_clock_local();
95 index
= ++current
->curr_ret_stack
;
97 current
->ret_stack
[index
].ret
= ret
;
98 current
->ret_stack
[index
].func
= func
;
99 current
->ret_stack
[index
].calltime
= calltime
;
100 current
->ret_stack
[index
].subtime
= 0;
101 current
->ret_stack
[index
].fp
= frame_pointer
;
107 /* Retrieve a function return address to the trace stack on thread info.*/
109 ftrace_pop_return_trace(struct ftrace_graph_ret
*trace
, unsigned long *ret
,
110 unsigned long frame_pointer
)
114 index
= current
->curr_ret_stack
;
116 if (unlikely(index
< 0)) {
119 /* Might as well panic, otherwise we have no where to go */
120 *ret
= (unsigned long)panic
;
124 #ifdef CONFIG_HAVE_FUNCTION_GRAPH_FP_TEST
126 * The arch may choose to record the frame pointer used
127 * and check it here to make sure that it is what we expect it
128 * to be. If gcc does not set the place holder of the return
129 * address in the frame pointer, and does a copy instead, then
130 * the function graph trace will fail. This test detects this
133 * Currently, x86_32 with optimize for size (-Os) makes the latest
136 if (unlikely(current
->ret_stack
[index
].fp
!= frame_pointer
)) {
138 WARN(1, "Bad frame pointer: expected %lx, received %lx\n"
139 " from func %ps return to %lx\n",
140 current
->ret_stack
[index
].fp
,
142 (void *)current
->ret_stack
[index
].func
,
143 current
->ret_stack
[index
].ret
);
144 *ret
= (unsigned long)panic
;
149 *ret
= current
->ret_stack
[index
].ret
;
150 trace
->func
= current
->ret_stack
[index
].func
;
151 trace
->calltime
= current
->ret_stack
[index
].calltime
;
152 trace
->overrun
= atomic_read(¤t
->trace_overrun
);
153 trace
->depth
= index
;
157 * Send the trace to the ring-buffer.
158 * @return the original return address.
160 unsigned long ftrace_return_to_handler(unsigned long frame_pointer
)
162 struct ftrace_graph_ret trace
;
165 ftrace_pop_return_trace(&trace
, &ret
, frame_pointer
);
166 trace
.rettime
= trace_clock_local();
167 ftrace_graph_return(&trace
);
169 current
->curr_ret_stack
--;
171 if (unlikely(!ret
)) {
174 /* Might as well panic. What else to do? */
175 ret
= (unsigned long)panic
;
181 static int __trace_graph_entry(struct trace_array
*tr
,
182 struct ftrace_graph_ent
*trace
,
186 struct ftrace_event_call
*call
= &event_funcgraph_entry
;
187 struct ring_buffer_event
*event
;
188 struct ring_buffer
*buffer
= tr
->buffer
;
189 struct ftrace_graph_ent_entry
*entry
;
191 if (unlikely(__this_cpu_read(per_cpu_var(ftrace_cpu_disabled
))))
194 event
= trace_buffer_lock_reserve(buffer
, TRACE_GRAPH_ENT
,
195 sizeof(*entry
), flags
, pc
);
198 entry
= ring_buffer_event_data(event
);
199 entry
->graph_ent
= *trace
;
200 if (!filter_current_check_discard(buffer
, call
, entry
, event
))
201 ring_buffer_unlock_commit(buffer
, event
);
206 int trace_graph_entry(struct ftrace_graph_ent
*trace
)
208 struct trace_array
*tr
= graph_array
;
209 struct trace_array_cpu
*data
;
216 if (!ftrace_trace_task(current
))
219 /* trace it when it is-nested-in or is a function enabled. */
220 if (!(trace
->depth
|| ftrace_graph_addr(trace
->func
)))
223 local_irq_save(flags
);
224 cpu
= raw_smp_processor_id();
225 data
= tr
->data
[cpu
];
226 disabled
= atomic_inc_return(&data
->disabled
);
227 if (likely(disabled
== 1)) {
228 pc
= preempt_count();
229 ret
= __trace_graph_entry(tr
, trace
, flags
, pc
);
234 atomic_dec(&data
->disabled
);
235 local_irq_restore(flags
);
240 static void __trace_graph_return(struct trace_array
*tr
,
241 struct ftrace_graph_ret
*trace
,
245 struct ftrace_event_call
*call
= &event_funcgraph_exit
;
246 struct ring_buffer_event
*event
;
247 struct ring_buffer
*buffer
= tr
->buffer
;
248 struct ftrace_graph_ret_entry
*entry
;
250 if (unlikely(__this_cpu_read(per_cpu_var(ftrace_cpu_disabled
))))
253 event
= trace_buffer_lock_reserve(buffer
, TRACE_GRAPH_RET
,
254 sizeof(*entry
), flags
, pc
);
257 entry
= ring_buffer_event_data(event
);
259 if (!filter_current_check_discard(buffer
, call
, entry
, event
))
260 ring_buffer_unlock_commit(buffer
, event
);
263 void trace_graph_return(struct ftrace_graph_ret
*trace
)
265 struct trace_array
*tr
= graph_array
;
266 struct trace_array_cpu
*data
;
272 local_irq_save(flags
);
273 cpu
= raw_smp_processor_id();
274 data
= tr
->data
[cpu
];
275 disabled
= atomic_inc_return(&data
->disabled
);
276 if (likely(disabled
== 1)) {
277 pc
= preempt_count();
278 __trace_graph_return(tr
, trace
, flags
, pc
);
280 atomic_dec(&data
->disabled
);
281 local_irq_restore(flags
);
284 void set_graph_array(struct trace_array
*tr
)
288 /* Make graph_array visible before we start tracing */
293 static int graph_trace_init(struct trace_array
*tr
)
298 ret
= register_ftrace_graph(&trace_graph_return
,
302 tracing_start_cmdline_record();
307 static void graph_trace_reset(struct trace_array
*tr
)
309 tracing_stop_cmdline_record();
310 unregister_ftrace_graph();
313 static int max_bytes_for_cpu
;
315 static enum print_line_t
316 print_graph_cpu(struct trace_seq
*s
, int cpu
)
321 * Start with a space character - to make it stand out
322 * to the right a bit when trace output is pasted into
325 ret
= trace_seq_printf(s
, " %*d) ", max_bytes_for_cpu
, cpu
);
327 return TRACE_TYPE_PARTIAL_LINE
;
329 return TRACE_TYPE_HANDLED
;
332 #define TRACE_GRAPH_PROCINFO_LENGTH 14
334 static enum print_line_t
335 print_graph_proc(struct trace_seq
*s
, pid_t pid
)
337 char comm
[TASK_COMM_LEN
];
338 /* sign + log10(MAX_INT) + '\0' */
345 trace_find_cmdline(pid
, comm
);
347 sprintf(pid_str
, "%d", pid
);
349 /* 1 stands for the "-" character */
350 len
= strlen(comm
) + strlen(pid_str
) + 1;
352 if (len
< TRACE_GRAPH_PROCINFO_LENGTH
)
353 spaces
= TRACE_GRAPH_PROCINFO_LENGTH
- len
;
355 /* First spaces to align center */
356 for (i
= 0; i
< spaces
/ 2; i
++) {
357 ret
= trace_seq_printf(s
, " ");
359 return TRACE_TYPE_PARTIAL_LINE
;
362 ret
= trace_seq_printf(s
, "%s-%s", comm
, pid_str
);
364 return TRACE_TYPE_PARTIAL_LINE
;
366 /* Last spaces to align center */
367 for (i
= 0; i
< spaces
- (spaces
/ 2); i
++) {
368 ret
= trace_seq_printf(s
, " ");
370 return TRACE_TYPE_PARTIAL_LINE
;
372 return TRACE_TYPE_HANDLED
;
376 static enum print_line_t
377 print_graph_lat_fmt(struct trace_seq
*s
, struct trace_entry
*entry
)
379 if (!trace_seq_putc(s
, ' '))
382 return trace_print_lat_fmt(s
, entry
);
385 /* If the pid changed since the last trace, output this event */
386 static enum print_line_t
387 verif_pid(struct trace_seq
*s
, pid_t pid
, int cpu
, struct fgraph_data
*data
)
394 return TRACE_TYPE_HANDLED
;
396 last_pid
= &(per_cpu_ptr(data
->cpu_data
, cpu
)->last_pid
);
398 if (*last_pid
== pid
)
399 return TRACE_TYPE_HANDLED
;
401 prev_pid
= *last_pid
;
405 return TRACE_TYPE_HANDLED
;
407 * Context-switch trace line:
409 ------------------------------------------
410 | 1) migration/0--1 => sshd-1755
411 ------------------------------------------
414 ret
= trace_seq_printf(s
,
415 " ------------------------------------------\n");
417 return TRACE_TYPE_PARTIAL_LINE
;
419 ret
= print_graph_cpu(s
, cpu
);
420 if (ret
== TRACE_TYPE_PARTIAL_LINE
)
421 return TRACE_TYPE_PARTIAL_LINE
;
423 ret
= print_graph_proc(s
, prev_pid
);
424 if (ret
== TRACE_TYPE_PARTIAL_LINE
)
425 return TRACE_TYPE_PARTIAL_LINE
;
427 ret
= trace_seq_printf(s
, " => ");
429 return TRACE_TYPE_PARTIAL_LINE
;
431 ret
= print_graph_proc(s
, pid
);
432 if (ret
== TRACE_TYPE_PARTIAL_LINE
)
433 return TRACE_TYPE_PARTIAL_LINE
;
435 ret
= trace_seq_printf(s
,
436 "\n ------------------------------------------\n\n");
438 return TRACE_TYPE_PARTIAL_LINE
;
440 return TRACE_TYPE_HANDLED
;
443 static struct ftrace_graph_ret_entry
*
444 get_return_for_leaf(struct trace_iterator
*iter
,
445 struct ftrace_graph_ent_entry
*curr
)
447 struct fgraph_data
*data
= iter
->private;
448 struct ring_buffer_iter
*ring_iter
= NULL
;
449 struct ring_buffer_event
*event
;
450 struct ftrace_graph_ret_entry
*next
;
453 * If the previous output failed to write to the seq buffer,
454 * then we just reuse the data from before.
456 if (data
&& data
->failed
) {
461 ring_iter
= iter
->buffer_iter
[iter
->cpu
];
463 /* First peek to compare current entry and the next one */
465 event
= ring_buffer_iter_peek(ring_iter
, NULL
);
468 * We need to consume the current entry to see
471 ring_buffer_consume(iter
->tr
->buffer
, iter
->cpu
, NULL
);
472 event
= ring_buffer_peek(iter
->tr
->buffer
, iter
->cpu
,
479 next
= ring_buffer_event_data(event
);
483 * Save current and next entries for later reference
484 * if the output fails.
491 if (next
->ent
.type
!= TRACE_GRAPH_RET
)
494 if (curr
->ent
.pid
!= next
->ent
.pid
||
495 curr
->graph_ent
.func
!= next
->ret
.func
)
498 /* this is a leaf, now advance the iterator */
500 ring_buffer_read(ring_iter
, NULL
);
505 /* Signal a overhead of time execution to the output */
507 print_graph_overhead(unsigned long long duration
, struct trace_seq
*s
)
509 /* If duration disappear, we don't need anything */
510 if (!(tracer_flags
.val
& TRACE_GRAPH_PRINT_DURATION
))
513 /* Non nested entry or return */
515 return trace_seq_printf(s
, " ");
517 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_OVERHEAD
) {
518 /* Duration exceeded 100 msecs */
519 if (duration
> 100000ULL)
520 return trace_seq_printf(s
, "! ");
522 /* Duration exceeded 10 msecs */
523 if (duration
> 10000ULL)
524 return trace_seq_printf(s
, "+ ");
527 return trace_seq_printf(s
, " ");
530 static int print_graph_abs_time(u64 t
, struct trace_seq
*s
)
532 unsigned long usecs_rem
;
534 usecs_rem
= do_div(t
, NSEC_PER_SEC
);
537 return trace_seq_printf(s
, "%5lu.%06lu | ",
538 (unsigned long)t
, usecs_rem
);
541 static enum print_line_t
542 print_graph_irq(struct trace_iterator
*iter
, unsigned long addr
,
543 enum trace_type type
, int cpu
, pid_t pid
)
546 struct trace_seq
*s
= &iter
->seq
;
548 if (addr
< (unsigned long)__irqentry_text_start
||
549 addr
>= (unsigned long)__irqentry_text_end
)
550 return TRACE_TYPE_UNHANDLED
;
553 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_ABS_TIME
) {
554 ret
= print_graph_abs_time(iter
->ts
, s
);
556 return TRACE_TYPE_PARTIAL_LINE
;
560 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_CPU
) {
561 ret
= print_graph_cpu(s
, cpu
);
562 if (ret
== TRACE_TYPE_PARTIAL_LINE
)
563 return TRACE_TYPE_PARTIAL_LINE
;
567 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_PROC
) {
568 ret
= print_graph_proc(s
, pid
);
569 if (ret
== TRACE_TYPE_PARTIAL_LINE
)
570 return TRACE_TYPE_PARTIAL_LINE
;
571 ret
= trace_seq_printf(s
, " | ");
573 return TRACE_TYPE_PARTIAL_LINE
;
577 ret
= print_graph_overhead(-1, s
);
579 return TRACE_TYPE_PARTIAL_LINE
;
581 if (type
== TRACE_GRAPH_ENT
)
582 ret
= trace_seq_printf(s
, "==========>");
584 ret
= trace_seq_printf(s
, "<==========");
587 return TRACE_TYPE_PARTIAL_LINE
;
589 /* Don't close the duration column if haven't one */
590 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_DURATION
)
591 trace_seq_printf(s
, " |");
592 ret
= trace_seq_printf(s
, "\n");
595 return TRACE_TYPE_PARTIAL_LINE
;
596 return TRACE_TYPE_HANDLED
;
600 trace_print_graph_duration(unsigned long long duration
, struct trace_seq
*s
)
602 unsigned long nsecs_rem
= do_div(duration
, 1000);
603 /* log10(ULONG_MAX) + '\0' */
609 sprintf(msecs_str
, "%lu", (unsigned long) duration
);
612 ret
= trace_seq_printf(s
, "%s", msecs_str
);
614 return TRACE_TYPE_PARTIAL_LINE
;
616 len
= strlen(msecs_str
);
618 /* Print nsecs (we don't want to exceed 7 numbers) */
620 snprintf(nsecs_str
, 8 - len
, "%03lu", nsecs_rem
);
621 ret
= trace_seq_printf(s
, ".%s", nsecs_str
);
623 return TRACE_TYPE_PARTIAL_LINE
;
624 len
+= strlen(nsecs_str
);
627 ret
= trace_seq_printf(s
, " us ");
629 return TRACE_TYPE_PARTIAL_LINE
;
631 /* Print remaining spaces to fit the row's width */
632 for (i
= len
; i
< 7; i
++) {
633 ret
= trace_seq_printf(s
, " ");
635 return TRACE_TYPE_PARTIAL_LINE
;
637 return TRACE_TYPE_HANDLED
;
640 static enum print_line_t
641 print_graph_duration(unsigned long long duration
, struct trace_seq
*s
)
645 ret
= trace_print_graph_duration(duration
, s
);
646 if (ret
!= TRACE_TYPE_HANDLED
)
649 ret
= trace_seq_printf(s
, "| ");
651 return TRACE_TYPE_PARTIAL_LINE
;
653 return TRACE_TYPE_HANDLED
;
656 /* Case of a leaf function on its call entry */
657 static enum print_line_t
658 print_graph_entry_leaf(struct trace_iterator
*iter
,
659 struct ftrace_graph_ent_entry
*entry
,
660 struct ftrace_graph_ret_entry
*ret_entry
, struct trace_seq
*s
)
662 struct fgraph_data
*data
= iter
->private;
663 struct ftrace_graph_ret
*graph_ret
;
664 struct ftrace_graph_ent
*call
;
665 unsigned long long duration
;
669 graph_ret
= &ret_entry
->ret
;
670 call
= &entry
->graph_ent
;
671 duration
= graph_ret
->rettime
- graph_ret
->calltime
;
674 struct fgraph_cpu_data
*cpu_data
;
677 cpu_data
= per_cpu_ptr(data
->cpu_data
, cpu
);
680 * Comments display at + 1 to depth. Since
681 * this is a leaf function, keep the comments
682 * equal to this depth.
684 cpu_data
->depth
= call
->depth
- 1;
686 /* No need to keep this function around for this depth */
687 if (call
->depth
< FTRACE_RETFUNC_DEPTH
)
688 cpu_data
->enter_funcs
[call
->depth
] = 0;
692 ret
= print_graph_overhead(duration
, s
);
694 return TRACE_TYPE_PARTIAL_LINE
;
697 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_DURATION
) {
698 ret
= print_graph_duration(duration
, s
);
699 if (ret
== TRACE_TYPE_PARTIAL_LINE
)
700 return TRACE_TYPE_PARTIAL_LINE
;
704 for (i
= 0; i
< call
->depth
* TRACE_GRAPH_INDENT
; i
++) {
705 ret
= trace_seq_printf(s
, " ");
707 return TRACE_TYPE_PARTIAL_LINE
;
710 ret
= trace_seq_printf(s
, "%ps();\n", (void *)call
->func
);
712 return TRACE_TYPE_PARTIAL_LINE
;
714 return TRACE_TYPE_HANDLED
;
717 static enum print_line_t
718 print_graph_entry_nested(struct trace_iterator
*iter
,
719 struct ftrace_graph_ent_entry
*entry
,
720 struct trace_seq
*s
, int cpu
)
722 struct ftrace_graph_ent
*call
= &entry
->graph_ent
;
723 struct fgraph_data
*data
= iter
->private;
728 struct fgraph_cpu_data
*cpu_data
;
731 cpu_data
= per_cpu_ptr(data
->cpu_data
, cpu
);
732 cpu_data
->depth
= call
->depth
;
734 /* Save this function pointer to see if the exit matches */
735 if (call
->depth
< FTRACE_RETFUNC_DEPTH
)
736 cpu_data
->enter_funcs
[call
->depth
] = call
->func
;
740 ret
= print_graph_overhead(-1, s
);
742 return TRACE_TYPE_PARTIAL_LINE
;
745 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_DURATION
) {
746 ret
= trace_seq_printf(s
, " | ");
748 return TRACE_TYPE_PARTIAL_LINE
;
752 for (i
= 0; i
< call
->depth
* TRACE_GRAPH_INDENT
; i
++) {
753 ret
= trace_seq_printf(s
, " ");
755 return TRACE_TYPE_PARTIAL_LINE
;
758 ret
= trace_seq_printf(s
, "%ps() {\n", (void *)call
->func
);
760 return TRACE_TYPE_PARTIAL_LINE
;
763 * we already consumed the current entry to check the next one
764 * and see if this is a leaf.
766 return TRACE_TYPE_NO_CONSUME
;
769 static enum print_line_t
770 print_graph_prologue(struct trace_iterator
*iter
, struct trace_seq
*s
,
771 int type
, unsigned long addr
)
773 struct fgraph_data
*data
= iter
->private;
774 struct trace_entry
*ent
= iter
->ent
;
779 if (verif_pid(s
, ent
->pid
, cpu
, data
) == TRACE_TYPE_PARTIAL_LINE
)
780 return TRACE_TYPE_PARTIAL_LINE
;
784 ret
= print_graph_irq(iter
, addr
, type
, cpu
, ent
->pid
);
785 if (ret
== TRACE_TYPE_PARTIAL_LINE
)
786 return TRACE_TYPE_PARTIAL_LINE
;
790 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_ABS_TIME
) {
791 ret
= print_graph_abs_time(iter
->ts
, s
);
793 return TRACE_TYPE_PARTIAL_LINE
;
797 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_CPU
) {
798 ret
= print_graph_cpu(s
, cpu
);
799 if (ret
== TRACE_TYPE_PARTIAL_LINE
)
800 return TRACE_TYPE_PARTIAL_LINE
;
804 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_PROC
) {
805 ret
= print_graph_proc(s
, ent
->pid
);
806 if (ret
== TRACE_TYPE_PARTIAL_LINE
)
807 return TRACE_TYPE_PARTIAL_LINE
;
809 ret
= trace_seq_printf(s
, " | ");
811 return TRACE_TYPE_PARTIAL_LINE
;
815 if (trace_flags
& TRACE_ITER_LATENCY_FMT
) {
816 ret
= print_graph_lat_fmt(s
, ent
);
817 if (ret
== TRACE_TYPE_PARTIAL_LINE
)
818 return TRACE_TYPE_PARTIAL_LINE
;
824 static enum print_line_t
825 print_graph_entry(struct ftrace_graph_ent_entry
*field
, struct trace_seq
*s
,
826 struct trace_iterator
*iter
)
828 struct fgraph_data
*data
= iter
->private;
829 struct ftrace_graph_ent
*call
= &field
->graph_ent
;
830 struct ftrace_graph_ret_entry
*leaf_ret
;
831 static enum print_line_t ret
;
834 if (print_graph_prologue(iter
, s
, TRACE_GRAPH_ENT
, call
->func
))
835 return TRACE_TYPE_PARTIAL_LINE
;
837 leaf_ret
= get_return_for_leaf(iter
, field
);
839 ret
= print_graph_entry_leaf(iter
, field
, leaf_ret
, s
);
841 ret
= print_graph_entry_nested(iter
, field
, s
, cpu
);
845 * If we failed to write our output, then we need to make
846 * note of it. Because we already consumed our entry.
858 static enum print_line_t
859 print_graph_return(struct ftrace_graph_ret
*trace
, struct trace_seq
*s
,
860 struct trace_entry
*ent
, struct trace_iterator
*iter
)
862 unsigned long long duration
= trace
->rettime
- trace
->calltime
;
863 struct fgraph_data
*data
= iter
->private;
864 pid_t pid
= ent
->pid
;
871 struct fgraph_cpu_data
*cpu_data
;
874 cpu_data
= per_cpu_ptr(data
->cpu_data
, cpu
);
877 * Comments display at + 1 to depth. This is the
878 * return from a function, we now want the comments
879 * to display at the same level of the bracket.
881 cpu_data
->depth
= trace
->depth
- 1;
883 if (trace
->depth
< FTRACE_RETFUNC_DEPTH
) {
884 if (cpu_data
->enter_funcs
[trace
->depth
] != trace
->func
)
886 cpu_data
->enter_funcs
[trace
->depth
] = 0;
890 if (print_graph_prologue(iter
, s
, 0, 0))
891 return TRACE_TYPE_PARTIAL_LINE
;
894 ret
= print_graph_overhead(duration
, s
);
896 return TRACE_TYPE_PARTIAL_LINE
;
899 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_DURATION
) {
900 ret
= print_graph_duration(duration
, s
);
901 if (ret
== TRACE_TYPE_PARTIAL_LINE
)
902 return TRACE_TYPE_PARTIAL_LINE
;
906 for (i
= 0; i
< trace
->depth
* TRACE_GRAPH_INDENT
; i
++) {
907 ret
= trace_seq_printf(s
, " ");
909 return TRACE_TYPE_PARTIAL_LINE
;
913 * If the return function does not have a matching entry,
914 * then the entry was lost. Instead of just printing
915 * the '}' and letting the user guess what function this
916 * belongs to, write out the function name.
919 ret
= trace_seq_printf(s
, "}\n");
921 return TRACE_TYPE_PARTIAL_LINE
;
923 ret
= trace_seq_printf(s
, "} (%ps)\n", (void *)trace
->func
);
925 return TRACE_TYPE_PARTIAL_LINE
;
929 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_OVERRUN
) {
930 ret
= trace_seq_printf(s
, " (Overruns: %lu)\n",
933 return TRACE_TYPE_PARTIAL_LINE
;
936 ret
= print_graph_irq(iter
, trace
->func
, TRACE_GRAPH_RET
, cpu
, pid
);
937 if (ret
== TRACE_TYPE_PARTIAL_LINE
)
938 return TRACE_TYPE_PARTIAL_LINE
;
940 return TRACE_TYPE_HANDLED
;
943 static enum print_line_t
944 print_graph_comment(struct trace_seq
*s
, struct trace_entry
*ent
,
945 struct trace_iterator
*iter
)
947 unsigned long sym_flags
= (trace_flags
& TRACE_ITER_SYM_MASK
);
948 struct fgraph_data
*data
= iter
->private;
949 struct trace_event
*event
;
955 depth
= per_cpu_ptr(data
->cpu_data
, iter
->cpu
)->depth
;
957 if (print_graph_prologue(iter
, s
, 0, 0))
958 return TRACE_TYPE_PARTIAL_LINE
;
961 ret
= print_graph_overhead(-1, s
);
963 return TRACE_TYPE_PARTIAL_LINE
;
966 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_DURATION
) {
967 ret
= trace_seq_printf(s
, " | ");
969 return TRACE_TYPE_PARTIAL_LINE
;
974 for (i
= 0; i
< (depth
+ 1) * TRACE_GRAPH_INDENT
; i
++) {
975 ret
= trace_seq_printf(s
, " ");
977 return TRACE_TYPE_PARTIAL_LINE
;
981 ret
= trace_seq_printf(s
, "/* ");
983 return TRACE_TYPE_PARTIAL_LINE
;
985 switch (iter
->ent
->type
) {
987 ret
= trace_print_bprintk_msg_only(iter
);
988 if (ret
!= TRACE_TYPE_HANDLED
)
992 ret
= trace_print_printk_msg_only(iter
);
993 if (ret
!= TRACE_TYPE_HANDLED
)
997 event
= ftrace_find_event(ent
->type
);
999 return TRACE_TYPE_UNHANDLED
;
1001 ret
= event
->trace(iter
, sym_flags
);
1002 if (ret
!= TRACE_TYPE_HANDLED
)
1006 /* Strip ending newline */
1007 if (s
->buffer
[s
->len
- 1] == '\n') {
1008 s
->buffer
[s
->len
- 1] = '\0';
1012 ret
= trace_seq_printf(s
, " */\n");
1014 return TRACE_TYPE_PARTIAL_LINE
;
1016 return TRACE_TYPE_HANDLED
;
1021 print_graph_function(struct trace_iterator
*iter
)
1023 struct ftrace_graph_ent_entry
*field
;
1024 struct fgraph_data
*data
= iter
->private;
1025 struct trace_entry
*entry
= iter
->ent
;
1026 struct trace_seq
*s
= &iter
->seq
;
1027 int cpu
= iter
->cpu
;
1030 if (data
&& per_cpu_ptr(data
->cpu_data
, cpu
)->ignore
) {
1031 per_cpu_ptr(data
->cpu_data
, cpu
)->ignore
= 0;
1032 return TRACE_TYPE_HANDLED
;
1036 * If the last output failed, there's a possibility we need
1037 * to print out the missing entry which would never go out.
1039 if (data
&& data
->failed
) {
1041 iter
->cpu
= data
->cpu
;
1042 ret
= print_graph_entry(field
, s
, iter
);
1043 if (ret
== TRACE_TYPE_HANDLED
&& iter
->cpu
!= cpu
) {
1044 per_cpu_ptr(data
->cpu_data
, iter
->cpu
)->ignore
= 1;
1045 ret
= TRACE_TYPE_NO_CONSUME
;
1051 switch (entry
->type
) {
1052 case TRACE_GRAPH_ENT
: {
1054 * print_graph_entry() may consume the current event,
1055 * thus @field may become invalid, so we need to save it.
1056 * sizeof(struct ftrace_graph_ent_entry) is very small,
1057 * it can be safely saved at the stack.
1059 struct ftrace_graph_ent_entry saved
;
1060 trace_assign_type(field
, entry
);
1062 return print_graph_entry(&saved
, s
, iter
);
1064 case TRACE_GRAPH_RET
: {
1065 struct ftrace_graph_ret_entry
*field
;
1066 trace_assign_type(field
, entry
);
1067 return print_graph_return(&field
->ret
, s
, entry
, iter
);
1070 return print_graph_comment(s
, entry
, iter
);
1073 return TRACE_TYPE_HANDLED
;
1076 static void print_lat_header(struct seq_file
*s
)
1078 static const char spaces
[] = " " /* 16 spaces */
1080 " "; /* 17 spaces */
1083 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_ABS_TIME
)
1085 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_CPU
)
1087 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_PROC
)
1090 seq_printf(s
, "#%.*s _-----=> irqs-off \n", size
, spaces
);
1091 seq_printf(s
, "#%.*s / _----=> need-resched \n", size
, spaces
);
1092 seq_printf(s
, "#%.*s| / _---=> hardirq/softirq \n", size
, spaces
);
1093 seq_printf(s
, "#%.*s|| / _--=> preempt-depth \n", size
, spaces
);
1094 seq_printf(s
, "#%.*s||| / _-=> lock-depth \n", size
, spaces
);
1095 seq_printf(s
, "#%.*s|||| / \n", size
, spaces
);
1098 static void print_graph_headers(struct seq_file
*s
)
1100 int lat
= trace_flags
& TRACE_ITER_LATENCY_FMT
;
1103 print_lat_header(s
);
1107 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_ABS_TIME
)
1108 seq_printf(s
, " TIME ");
1109 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_CPU
)
1110 seq_printf(s
, " CPU");
1111 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_PROC
)
1112 seq_printf(s
, " TASK/PID ");
1114 seq_printf(s
, "|||||");
1115 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_DURATION
)
1116 seq_printf(s
, " DURATION ");
1117 seq_printf(s
, " FUNCTION CALLS\n");
1121 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_ABS_TIME
)
1122 seq_printf(s
, " | ");
1123 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_CPU
)
1124 seq_printf(s
, " | ");
1125 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_PROC
)
1126 seq_printf(s
, " | | ");
1128 seq_printf(s
, "|||||");
1129 if (tracer_flags
.val
& TRACE_GRAPH_PRINT_DURATION
)
1130 seq_printf(s
, " | | ");
1131 seq_printf(s
, " | | | |\n");
1134 static void graph_trace_open(struct trace_iterator
*iter
)
1136 /* pid and depth on the last trace processed */
1137 struct fgraph_data
*data
;
1140 iter
->private = NULL
;
1142 data
= kzalloc(sizeof(*data
), GFP_KERNEL
);
1146 data
->cpu_data
= alloc_percpu(struct fgraph_cpu_data
);
1147 if (!data
->cpu_data
)
1150 for_each_possible_cpu(cpu
) {
1151 pid_t
*pid
= &(per_cpu_ptr(data
->cpu_data
, cpu
)->last_pid
);
1152 int *depth
= &(per_cpu_ptr(data
->cpu_data
, cpu
)->depth
);
1153 int *ignore
= &(per_cpu_ptr(data
->cpu_data
, cpu
)->ignore
);
1159 iter
->private = data
;
1166 pr_warning("function graph tracer: not enough memory\n");
1169 static void graph_trace_close(struct trace_iterator
*iter
)
1171 struct fgraph_data
*data
= iter
->private;
1174 free_percpu(data
->cpu_data
);
1179 static struct tracer graph_trace __read_mostly
= {
1180 .name
= "function_graph",
1181 .open
= graph_trace_open
,
1182 .pipe_open
= graph_trace_open
,
1183 .close
= graph_trace_close
,
1184 .pipe_close
= graph_trace_close
,
1185 .wait_pipe
= poll_wait_pipe
,
1186 .init
= graph_trace_init
,
1187 .reset
= graph_trace_reset
,
1188 .print_line
= print_graph_function
,
1189 .print_header
= print_graph_headers
,
1190 .flags
= &tracer_flags
,
1191 #ifdef CONFIG_FTRACE_SELFTEST
1192 .selftest
= trace_selftest_startup_function_graph
,
1196 static __init
int init_graph_trace(void)
1198 max_bytes_for_cpu
= snprintf(NULL
, 0, "%d", nr_cpu_ids
- 1);
1200 return register_tracer(&graph_trace
);
1203 device_initcall(init_graph_trace
);