Linux Kernel  3.7.1
 All Data Structures Namespaces Files Functions Variables Typedefs Enumerations Enumerator Macros Groups Pages
trace_functions_graph.c
Go to the documentation of this file.
1 /*
2  *
3  * Function graph tracer.
4  * Copyright (c) 2008-2009 Frederic Weisbecker <[email protected]>
5  * Mostly borrowed from function tracer which
6  * is Copyright (c) Steven Rostedt <[email protected]>
7  *
8  */
9 #include <linux/debugfs.h>
10 #include <linux/uaccess.h>
11 #include <linux/ftrace.h>
12 #include <linux/slab.h>
13 #include <linux/fs.h>
14 
15 #include "trace.h"
16 #include "trace_output.h"
17 
18 /* When set, irq functions will be ignored */
19 static int ftrace_graph_skip_irqs;
20 
23  int depth;
24  int depth_irq;
25  int ignore;
26  unsigned long enter_funcs[FTRACE_RETFUNC_DEPTH];
27 };
28 
29 struct fgraph_data {
31 
32  /* Place to preserve last processed entry. */
33  struct ftrace_graph_ent_entry ent;
34  struct ftrace_graph_ret_entry ret;
35  int failed;
36  int cpu;
37 };
38 
39 #define TRACE_GRAPH_INDENT 2
40 
41 /* Flag options */
42 #define TRACE_GRAPH_PRINT_OVERRUN 0x1
43 #define TRACE_GRAPH_PRINT_CPU 0x2
44 #define TRACE_GRAPH_PRINT_OVERHEAD 0x4
45 #define TRACE_GRAPH_PRINT_PROC 0x8
46 #define TRACE_GRAPH_PRINT_DURATION 0x10
47 #define TRACE_GRAPH_PRINT_ABS_TIME 0x20
48 #define TRACE_GRAPH_PRINT_IRQS 0x40
49 
50 static struct tracer_opt trace_opts[] = {
51  /* Display overruns? (for self-debug purpose) */
53  /* Display CPU ? */
54  { TRACER_OPT(funcgraph-cpu, TRACE_GRAPH_PRINT_CPU) },
55  /* Display Overhead ? */
56  { TRACER_OPT(funcgraph-overhead, TRACE_GRAPH_PRINT_OVERHEAD) },
57  /* Display proc name/pid */
58  { TRACER_OPT(funcgraph-proc, TRACE_GRAPH_PRINT_PROC) },
59  /* Display duration of execution */
61  /* Display absolute time of an entry */
62  { TRACER_OPT(funcgraph-abstime, TRACE_GRAPH_PRINT_ABS_TIME) },
63  /* Display interrupts */
64  { TRACER_OPT(funcgraph-irqs, TRACE_GRAPH_PRINT_IRQS) },
65  { } /* Empty entry */
66 };
67 
68 static struct tracer_flags tracer_flags = {
69  /* Don't display overruns and proc by default */
72  .opts = trace_opts
73 };
74 
75 static struct trace_array *graph_array;
76 
77 /*
78  * DURATION column is being also used to display IRQ signs,
79  * following values are used by print_graph_irq and others
80  * to fill in space into DURATION column.
81  */
82 enum {
86 };
87 
88 static enum print_line_t
89 print_graph_duration(unsigned long long duration, struct trace_seq *s,
90  u32 flags);
91 
92 /* Add a function return address to the trace stack on thread info.*/
93 int
94 ftrace_push_return_trace(unsigned long ret, unsigned long func, int *depth,
95  unsigned long frame_pointer)
96 {
97  unsigned long long calltime;
98  int index;
99 
100  if (!current->ret_stack)
101  return -EBUSY;
102 
103  /*
104  * We must make sure the ret_stack is tested before we read
105  * anything else.
106  */
107  smp_rmb();
108 
109  /* The return trace stack is full */
110  if (current->curr_ret_stack == FTRACE_RETFUNC_DEPTH - 1) {
111  atomic_inc(&current->trace_overrun);
112  return -EBUSY;
113  }
114 
115  calltime = trace_clock_local();
116 
117  index = ++current->curr_ret_stack;
118  barrier();
119  current->ret_stack[index].ret = ret;
120  current->ret_stack[index].func = func;
121  current->ret_stack[index].calltime = calltime;
122  current->ret_stack[index].subtime = 0;
123  current->ret_stack[index].fp = frame_pointer;
124  *depth = index;
125 
126  return 0;
127 }
128 
129 /* Retrieve a function return address to the trace stack on thread info.*/
130 static void
131 ftrace_pop_return_trace(struct ftrace_graph_ret *trace, unsigned long *ret,
132  unsigned long frame_pointer)
133 {
134  int index;
135 
136  index = current->curr_ret_stack;
137 
138  if (unlikely(index < 0)) {
139  ftrace_graph_stop();
140  WARN_ON(1);
141  /* Might as well panic, otherwise we have no where to go */
142  *ret = (unsigned long)panic;
143  return;
144  }
145 
146 #if defined(CONFIG_HAVE_FUNCTION_GRAPH_FP_TEST) && !defined(CC_USING_FENTRY)
147  /*
148  * The arch may choose to record the frame pointer used
149  * and check it here to make sure that it is what we expect it
150  * to be. If gcc does not set the place holder of the return
151  * address in the frame pointer, and does a copy instead, then
152  * the function graph trace will fail. This test detects this
153  * case.
154  *
155  * Currently, x86_32 with optimize for size (-Os) makes the latest
156  * gcc do the above.
157  *
158  * Note, -mfentry does not use frame pointers, and this test
159  * is not needed if CC_USING_FENTRY is set.
160  */
161  if (unlikely(current->ret_stack[index].fp != frame_pointer)) {
162  ftrace_graph_stop();
163  WARN(1, "Bad frame pointer: expected %lx, received %lx\n"
164  " from func %ps return to %lx\n",
165  current->ret_stack[index].fp,
166  frame_pointer,
167  (void *)current->ret_stack[index].func,
168  current->ret_stack[index].ret);
169  *ret = (unsigned long)panic;
170  return;
171  }
172 #endif
173 
174  *ret = current->ret_stack[index].ret;
175  trace->func = current->ret_stack[index].func;
176  trace->calltime = current->ret_stack[index].calltime;
177  trace->overrun = atomic_read(&current->trace_overrun);
178  trace->depth = index;
179 }
180 
181 /*
182  * Send the trace to the ring-buffer.
183  * @return the original return address.
184  */
185 unsigned long ftrace_return_to_handler(unsigned long frame_pointer)
186 {
187  struct ftrace_graph_ret trace;
188  unsigned long ret;
189 
190  ftrace_pop_return_trace(&trace, &ret, frame_pointer);
191  trace.rettime = trace_clock_local();
192  ftrace_graph_return(&trace);
193  barrier();
194  current->curr_ret_stack--;
195 
196  if (unlikely(!ret)) {
197  ftrace_graph_stop();
198  WARN_ON(1);
199  /* Might as well panic. What else to do? */
200  ret = (unsigned long)panic;
201  }
202 
203  return ret;
204 }
205 
207  struct ftrace_graph_ent *trace,
208  unsigned long flags,
209  int pc)
210 {
211  struct ftrace_event_call *call = &event_funcgraph_entry;
212  struct ring_buffer_event *event;
213  struct ring_buffer *buffer = tr->buffer;
214  struct ftrace_graph_ent_entry *entry;
215 
216  if (unlikely(__this_cpu_read(ftrace_cpu_disabled)))
217  return 0;
218 
220  sizeof(*entry), flags, pc);
221  if (!event)
222  return 0;
223  entry = ring_buffer_event_data(event);
224  entry->graph_ent = *trace;
225  if (!filter_current_check_discard(buffer, call, entry, event))
226  ring_buffer_unlock_commit(buffer, event);
227 
228  return 1;
229 }
230 
231 static inline int ftrace_graph_ignore_irqs(void)
232 {
233  if (!ftrace_graph_skip_irqs || trace_recursion_test(TRACE_IRQ_BIT))
234  return 0;
235 
236  return in_irq();
237 }
238 
240 {
241  struct trace_array *tr = graph_array;
242  struct trace_array_cpu *data;
243  unsigned long flags;
244  long disabled;
245  int ret;
246  int cpu;
247  int pc;
248 
249  if (!ftrace_trace_task(current))
250  return 0;
251 
252  /* trace it when it is-nested-in or is a function enabled. */
253  if (!(trace->depth || ftrace_graph_addr(trace->func)) ||
254  ftrace_graph_ignore_irqs())
255  return 0;
256 
257  local_irq_save(flags);
258  cpu = raw_smp_processor_id();
259  data = tr->data[cpu];
260  disabled = atomic_inc_return(&data->disabled);
261  if (likely(disabled == 1)) {
262  pc = preempt_count();
263  ret = __trace_graph_entry(tr, trace, flags, pc);
264  } else {
265  ret = 0;
266  }
267 
268  atomic_dec(&data->disabled);
269  local_irq_restore(flags);
270 
271  return ret;
272 }
273 
275 {
276  if (tracing_thresh)
277  return 1;
278  else
279  return trace_graph_entry(trace);
280 }
281 
282 static void
283 __trace_graph_function(struct trace_array *tr,
284  unsigned long ip, unsigned long flags, int pc)
285 {
287  struct ftrace_graph_ent ent = {
288  .func = ip,
289  .depth = 0,
290  };
291  struct ftrace_graph_ret ret = {
292  .func = ip,
293  .depth = 0,
294  .calltime = time,
295  .rettime = time,
296  };
297 
298  __trace_graph_entry(tr, &ent, flags, pc);
299  __trace_graph_return(tr, &ret, flags, pc);
300 }
301 
302 void
304  unsigned long ip, unsigned long parent_ip,
305  unsigned long flags, int pc)
306 {
307  __trace_graph_function(tr, ip, flags, pc);
308 }
309 
311  struct ftrace_graph_ret *trace,
312  unsigned long flags,
313  int pc)
314 {
315  struct ftrace_event_call *call = &event_funcgraph_exit;
316  struct ring_buffer_event *event;
317  struct ring_buffer *buffer = tr->buffer;
318  struct ftrace_graph_ret_entry *entry;
319 
320  if (unlikely(__this_cpu_read(ftrace_cpu_disabled)))
321  return;
322 
324  sizeof(*entry), flags, pc);
325  if (!event)
326  return;
327  entry = ring_buffer_event_data(event);
328  entry->ret = *trace;
329  if (!filter_current_check_discard(buffer, call, entry, event))
330  ring_buffer_unlock_commit(buffer, event);
331 }
332 
334 {
335  struct trace_array *tr = graph_array;
336  struct trace_array_cpu *data;
337  unsigned long flags;
338  long disabled;
339  int cpu;
340  int pc;
341 
342  local_irq_save(flags);
343  cpu = raw_smp_processor_id();
344  data = tr->data[cpu];
345  disabled = atomic_inc_return(&data->disabled);
346  if (likely(disabled == 1)) {
347  pc = preempt_count();
348  __trace_graph_return(tr, trace, flags, pc);
349  }
350  atomic_dec(&data->disabled);
351  local_irq_restore(flags);
352 }
353 
355 {
356  graph_array = tr;
357 
358  /* Make graph_array visible before we start tracing */
359 
360  smp_mb();
361 }
362 
364 {
365  if (tracing_thresh &&
366  (trace->rettime - trace->calltime < tracing_thresh))
367  return;
368  else
369  trace_graph_return(trace);
370 }
371 
372 static int graph_trace_init(struct trace_array *tr)
373 {
374  int ret;
375 
376  set_graph_array(tr);
377  if (tracing_thresh)
378  ret = register_ftrace_graph(&trace_graph_thresh_return,
380  else
381  ret = register_ftrace_graph(&trace_graph_return,
383  if (ret)
384  return ret;
386 
387  return 0;
388 }
389 
390 static void graph_trace_reset(struct trace_array *tr)
391 {
393  unregister_ftrace_graph();
394 }
395 
396 static int max_bytes_for_cpu;
397 
398 static enum print_line_t
399 print_graph_cpu(struct trace_seq *s, int cpu)
400 {
401  int ret;
402 
403  /*
404  * Start with a space character - to make it stand out
405  * to the right a bit when trace output is pasted into
406  * email:
407  */
408  ret = trace_seq_printf(s, " %*d) ", max_bytes_for_cpu, cpu);
409  if (!ret)
411 
412  return TRACE_TYPE_HANDLED;
413 }
414 
415 #define TRACE_GRAPH_PROCINFO_LENGTH 14
416 
417 static enum print_line_t
418 print_graph_proc(struct trace_seq *s, pid_t pid)
419 {
420  char comm[TASK_COMM_LEN];
421  /* sign + log10(MAX_INT) + '\0' */
422  char pid_str[11];
423  int spaces = 0;
424  int ret;
425  int len;
426  int i;
427 
428  trace_find_cmdline(pid, comm);
429  comm[7] = '\0';
430  sprintf(pid_str, "%d", pid);
431 
432  /* 1 stands for the "-" character */
433  len = strlen(comm) + strlen(pid_str) + 1;
434 
435  if (len < TRACE_GRAPH_PROCINFO_LENGTH)
436  spaces = TRACE_GRAPH_PROCINFO_LENGTH - len;
437 
438  /* First spaces to align center */
439  for (i = 0; i < spaces / 2; i++) {
440  ret = trace_seq_printf(s, " ");
441  if (!ret)
443  }
444 
445  ret = trace_seq_printf(s, "%s-%s", comm, pid_str);
446  if (!ret)
448 
449  /* Last spaces to align center */
450  for (i = 0; i < spaces - (spaces / 2); i++) {
451  ret = trace_seq_printf(s, " ");
452  if (!ret)
454  }
455  return TRACE_TYPE_HANDLED;
456 }
457 
458 
459 static enum print_line_t
460 print_graph_lat_fmt(struct trace_seq *s, struct trace_entry *entry)
461 {
462  if (!trace_seq_putc(s, ' '))
463  return 0;
464 
465  return trace_print_lat_fmt(s, entry);
466 }
467 
468 /* If the pid changed since the last trace, output this event */
469 static enum print_line_t
470 verif_pid(struct trace_seq *s, pid_t pid, int cpu, struct fgraph_data *data)
471 {
472  pid_t prev_pid;
473  pid_t *last_pid;
474  int ret;
475 
476  if (!data)
477  return TRACE_TYPE_HANDLED;
478 
479  last_pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid);
480 
481  if (*last_pid == pid)
482  return TRACE_TYPE_HANDLED;
483 
484  prev_pid = *last_pid;
485  *last_pid = pid;
486 
487  if (prev_pid == -1)
488  return TRACE_TYPE_HANDLED;
489 /*
490  * Context-switch trace line:
491 
492  ------------------------------------------
493  | 1) migration/0--1 => sshd-1755
494  ------------------------------------------
495 
496  */
497  ret = trace_seq_printf(s,
498  " ------------------------------------------\n");
499  if (!ret)
501 
502  ret = print_graph_cpu(s, cpu);
503  if (ret == TRACE_TYPE_PARTIAL_LINE)
505 
506  ret = print_graph_proc(s, prev_pid);
507  if (ret == TRACE_TYPE_PARTIAL_LINE)
509 
510  ret = trace_seq_printf(s, " => ");
511  if (!ret)
513 
514  ret = print_graph_proc(s, pid);
515  if (ret == TRACE_TYPE_PARTIAL_LINE)
517 
518  ret = trace_seq_printf(s,
519  "\n ------------------------------------------\n\n");
520  if (!ret)
522 
523  return TRACE_TYPE_HANDLED;
524 }
525 
526 static struct ftrace_graph_ret_entry *
527 get_return_for_leaf(struct trace_iterator *iter,
528  struct ftrace_graph_ent_entry *curr)
529 {
530  struct fgraph_data *data = iter->private;
531  struct ring_buffer_iter *ring_iter = NULL;
532  struct ring_buffer_event *event;
533  struct ftrace_graph_ret_entry *next;
534 
535  /*
536  * If the previous output failed to write to the seq buffer,
537  * then we just reuse the data from before.
538  */
539  if (data && data->failed) {
540  curr = &data->ent;
541  next = &data->ret;
542  } else {
543 
544  ring_iter = trace_buffer_iter(iter, iter->cpu);
545 
546  /* First peek to compare current entry and the next one */
547  if (ring_iter)
548  event = ring_buffer_iter_peek(ring_iter, NULL);
549  else {
550  /*
551  * We need to consume the current entry to see
552  * the next one.
553  */
554  ring_buffer_consume(iter->tr->buffer, iter->cpu,
555  NULL, NULL);
556  event = ring_buffer_peek(iter->tr->buffer, iter->cpu,
557  NULL, NULL);
558  }
559 
560  if (!event)
561  return NULL;
562 
563  next = ring_buffer_event_data(event);
564 
565  if (data) {
566  /*
567  * Save current and next entries for later reference
568  * if the output fails.
569  */
570  data->ent = *curr;
571  /*
572  * If the next event is not a return type, then
573  * we only care about what type it is. Otherwise we can
574  * safely copy the entire event.
575  */
576  if (next->ent.type == TRACE_GRAPH_RET)
577  data->ret = *next;
578  else
579  data->ret.ent.type = next->ent.type;
580  }
581  }
582 
583  if (next->ent.type != TRACE_GRAPH_RET)
584  return NULL;
585 
586  if (curr->ent.pid != next->ent.pid ||
587  curr->graph_ent.func != next->ret.func)
588  return NULL;
589 
590  /* this is a leaf, now advance the iterator */
591  if (ring_iter)
592  ring_buffer_read(ring_iter, NULL);
593 
594  return next;
595 }
596 
597 static int print_graph_abs_time(u64 t, struct trace_seq *s)
598 {
599  unsigned long usecs_rem;
600 
601  usecs_rem = do_div(t, NSEC_PER_SEC);
602  usecs_rem /= 1000;
603 
604  return trace_seq_printf(s, "%5lu.%06lu | ",
605  (unsigned long)t, usecs_rem);
606 }
607 
608 static enum print_line_t
609 print_graph_irq(struct trace_iterator *iter, unsigned long addr,
610  enum trace_type type, int cpu, pid_t pid, u32 flags)
611 {
612  int ret;
613  struct trace_seq *s = &iter->seq;
614 
615  if (addr < (unsigned long)__irqentry_text_start ||
616  addr >= (unsigned long)__irqentry_text_end)
617  return TRACE_TYPE_UNHANDLED;
618 
620  /* Absolute time */
621  if (flags & TRACE_GRAPH_PRINT_ABS_TIME) {
622  ret = print_graph_abs_time(iter->ts, s);
623  if (!ret)
625  }
626 
627  /* Cpu */
628  if (flags & TRACE_GRAPH_PRINT_CPU) {
629  ret = print_graph_cpu(s, cpu);
630  if (ret == TRACE_TYPE_PARTIAL_LINE)
632  }
633 
634  /* Proc */
635  if (flags & TRACE_GRAPH_PRINT_PROC) {
636  ret = print_graph_proc(s, pid);
637  if (ret == TRACE_TYPE_PARTIAL_LINE)
639  ret = trace_seq_printf(s, " | ");
640  if (!ret)
642  }
643  }
644 
645  /* No overhead */
646  ret = print_graph_duration(DURATION_FILL_START, s, flags);
647  if (ret != TRACE_TYPE_HANDLED)
648  return ret;
649 
650  if (type == TRACE_GRAPH_ENT)
651  ret = trace_seq_printf(s, "==========>");
652  else
653  ret = trace_seq_printf(s, "<==========");
654 
655  if (!ret)
657 
658  ret = print_graph_duration(DURATION_FILL_END, s, flags);
659  if (ret != TRACE_TYPE_HANDLED)
660  return ret;
661 
662  ret = trace_seq_printf(s, "\n");
663 
664  if (!ret)
666  return TRACE_TYPE_HANDLED;
667 }
668 
669 enum print_line_t
670 trace_print_graph_duration(unsigned long long duration, struct trace_seq *s)
671 {
672  unsigned long nsecs_rem = do_div(duration, 1000);
673  /* log10(ULONG_MAX) + '\0' */
674  char msecs_str[21];
675  char nsecs_str[5];
676  int ret, len;
677  int i;
678 
679  sprintf(msecs_str, "%lu", (unsigned long) duration);
680 
681  /* Print msecs */
682  ret = trace_seq_printf(s, "%s", msecs_str);
683  if (!ret)
685 
686  len = strlen(msecs_str);
687 
688  /* Print nsecs (we don't want to exceed 7 numbers) */
689  if (len < 7) {
690  size_t slen = min_t(size_t, sizeof(nsecs_str), 8UL - len);
691 
692  snprintf(nsecs_str, slen, "%03lu", nsecs_rem);
693  ret = trace_seq_printf(s, ".%s", nsecs_str);
694  if (!ret)
696  len += strlen(nsecs_str);
697  }
698 
699  ret = trace_seq_printf(s, " us ");
700  if (!ret)
702 
703  /* Print remaining spaces to fit the row's width */
704  for (i = len; i < 7; i++) {
705  ret = trace_seq_printf(s, " ");
706  if (!ret)
708  }
709  return TRACE_TYPE_HANDLED;
710 }
711 
712 static enum print_line_t
713 print_graph_duration(unsigned long long duration, struct trace_seq *s,
714  u32 flags)
715 {
716  int ret = -1;
717 
718  if (!(flags & TRACE_GRAPH_PRINT_DURATION) ||
719  !(trace_flags & TRACE_ITER_CONTEXT_INFO))
720  return TRACE_TYPE_HANDLED;
721 
722  /* No real adata, just filling the column with spaces */
723  switch (duration) {
724  case DURATION_FILL_FULL:
725  ret = trace_seq_printf(s, " | ");
727  case DURATION_FILL_START:
728  ret = trace_seq_printf(s, " ");
730  case DURATION_FILL_END:
731  ret = trace_seq_printf(s, " |");
733  }
734 
735  /* Signal a overhead of time execution to the output */
736  if (flags & TRACE_GRAPH_PRINT_OVERHEAD) {
737  /* Duration exceeded 100 msecs */
738  if (duration > 100000ULL)
739  ret = trace_seq_printf(s, "! ");
740  /* Duration exceeded 10 msecs */
741  else if (duration > 10000ULL)
742  ret = trace_seq_printf(s, "+ ");
743  }
744 
745  /*
746  * The -1 means we either did not exceed the duration tresholds
747  * or we dont want to print out the overhead. Either way we need
748  * to fill out the space.
749  */
750  if (ret == -1)
751  ret = trace_seq_printf(s, " ");
752 
753  /* Catching here any failure happenned above */
754  if (!ret)
756 
757  ret = trace_print_graph_duration(duration, s);
758  if (ret != TRACE_TYPE_HANDLED)
759  return ret;
760 
761  ret = trace_seq_printf(s, "| ");
762  if (!ret)
764 
765  return TRACE_TYPE_HANDLED;
766 }
767 
768 /* Case of a leaf function on its call entry */
769 static enum print_line_t
770 print_graph_entry_leaf(struct trace_iterator *iter,
771  struct ftrace_graph_ent_entry *entry,
772  struct ftrace_graph_ret_entry *ret_entry,
773  struct trace_seq *s, u32 flags)
774 {
775  struct fgraph_data *data = iter->private;
776  struct ftrace_graph_ret *graph_ret;
777  struct ftrace_graph_ent *call;
778  unsigned long long duration;
779  int ret;
780  int i;
781 
782  graph_ret = &ret_entry->ret;
783  call = &entry->graph_ent;
784  duration = graph_ret->rettime - graph_ret->calltime;
785 
786  if (data) {
787  struct fgraph_cpu_data *cpu_data;
788  int cpu = iter->cpu;
789 
790  cpu_data = per_cpu_ptr(data->cpu_data, cpu);
791 
792  /*
793  * Comments display at + 1 to depth. Since
794  * this is a leaf function, keep the comments
795  * equal to this depth.
796  */
797  cpu_data->depth = call->depth - 1;
798 
799  /* No need to keep this function around for this depth */
800  if (call->depth < FTRACE_RETFUNC_DEPTH)
801  cpu_data->enter_funcs[call->depth] = 0;
802  }
803 
804  /* Overhead and duration */
805  ret = print_graph_duration(duration, s, flags);
806  if (ret == TRACE_TYPE_PARTIAL_LINE)
808 
809  /* Function */
810  for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
811  ret = trace_seq_printf(s, " ");
812  if (!ret)
814  }
815 
816  ret = trace_seq_printf(s, "%ps();\n", (void *)call->func);
817  if (!ret)
819 
820  return TRACE_TYPE_HANDLED;
821 }
822 
823 static enum print_line_t
824 print_graph_entry_nested(struct trace_iterator *iter,
825  struct ftrace_graph_ent_entry *entry,
826  struct trace_seq *s, int cpu, u32 flags)
827 {
828  struct ftrace_graph_ent *call = &entry->graph_ent;
829  struct fgraph_data *data = iter->private;
830  int ret;
831  int i;
832 
833  if (data) {
834  struct fgraph_cpu_data *cpu_data;
835  int cpu = iter->cpu;
836 
837  cpu_data = per_cpu_ptr(data->cpu_data, cpu);
838  cpu_data->depth = call->depth;
839 
840  /* Save this function pointer to see if the exit matches */
841  if (call->depth < FTRACE_RETFUNC_DEPTH)
842  cpu_data->enter_funcs[call->depth] = call->func;
843  }
844 
845  /* No time */
846  ret = print_graph_duration(DURATION_FILL_FULL, s, flags);
847  if (ret != TRACE_TYPE_HANDLED)
848  return ret;
849 
850  /* Function */
851  for (i = 0; i < call->depth * TRACE_GRAPH_INDENT; i++) {
852  ret = trace_seq_printf(s, " ");
853  if (!ret)
855  }
856 
857  ret = trace_seq_printf(s, "%ps() {\n", (void *)call->func);
858  if (!ret)
860 
861  /*
862  * we already consumed the current entry to check the next one
863  * and see if this is a leaf.
864  */
865  return TRACE_TYPE_NO_CONSUME;
866 }
867 
868 static enum print_line_t
869 print_graph_prologue(struct trace_iterator *iter, struct trace_seq *s,
870  int type, unsigned long addr, u32 flags)
871 {
872  struct fgraph_data *data = iter->private;
873  struct trace_entry *ent = iter->ent;
874  int cpu = iter->cpu;
875  int ret;
876 
877  /* Pid */
878  if (verif_pid(s, ent->pid, cpu, data) == TRACE_TYPE_PARTIAL_LINE)
880 
881  if (type) {
882  /* Interrupt */
883  ret = print_graph_irq(iter, addr, type, cpu, ent->pid, flags);
884  if (ret == TRACE_TYPE_PARTIAL_LINE)
886  }
887 
888  if (!(trace_flags & TRACE_ITER_CONTEXT_INFO))
889  return 0;
890 
891  /* Absolute time */
892  if (flags & TRACE_GRAPH_PRINT_ABS_TIME) {
893  ret = print_graph_abs_time(iter->ts, s);
894  if (!ret)
896  }
897 
898  /* Cpu */
899  if (flags & TRACE_GRAPH_PRINT_CPU) {
900  ret = print_graph_cpu(s, cpu);
901  if (ret == TRACE_TYPE_PARTIAL_LINE)
903  }
904 
905  /* Proc */
906  if (flags & TRACE_GRAPH_PRINT_PROC) {
907  ret = print_graph_proc(s, ent->pid);
908  if (ret == TRACE_TYPE_PARTIAL_LINE)
910 
911  ret = trace_seq_printf(s, " | ");
912  if (!ret)
914  }
915 
916  /* Latency format */
918  ret = print_graph_lat_fmt(s, ent);
919  if (ret == TRACE_TYPE_PARTIAL_LINE)
921  }
922 
923  return 0;
924 }
925 
926 /*
927  * Entry check for irq code
928  *
929  * returns 1 if
930  * - we are inside irq code
931  * - we just entered irq code
932  *
933  * retunns 0 if
934  * - funcgraph-interrupts option is set
935  * - we are not inside irq code
936  */
937 static int
938 check_irq_entry(struct trace_iterator *iter, u32 flags,
939  unsigned long addr, int depth)
940 {
941  int cpu = iter->cpu;
942  int *depth_irq;
943  struct fgraph_data *data = iter->private;
944 
945  /*
946  * If we are either displaying irqs, or we got called as
947  * a graph event and private data does not exist,
948  * then we bypass the irq check.
949  */
950  if ((flags & TRACE_GRAPH_PRINT_IRQS) ||
951  (!data))
952  return 0;
953 
954  depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq);
955 
956  /*
957  * We are inside the irq code
958  */
959  if (*depth_irq >= 0)
960  return 1;
961 
962  if ((addr < (unsigned long)__irqentry_text_start) ||
963  (addr >= (unsigned long)__irqentry_text_end))
964  return 0;
965 
966  /*
967  * We are entering irq code.
968  */
969  *depth_irq = depth;
970  return 1;
971 }
972 
973 /*
974  * Return check for irq code
975  *
976  * returns 1 if
977  * - we are inside irq code
978  * - we just left irq code
979  *
980  * returns 0 if
981  * - funcgraph-interrupts option is set
982  * - we are not inside irq code
983  */
984 static int
985 check_irq_return(struct trace_iterator *iter, u32 flags, int depth)
986 {
987  int cpu = iter->cpu;
988  int *depth_irq;
989  struct fgraph_data *data = iter->private;
990 
991  /*
992  * If we are either displaying irqs, or we got called as
993  * a graph event and private data does not exist,
994  * then we bypass the irq check.
995  */
996  if ((flags & TRACE_GRAPH_PRINT_IRQS) ||
997  (!data))
998  return 0;
999 
1000  depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq);
1001 
1002  /*
1003  * We are not inside the irq code.
1004  */
1005  if (*depth_irq == -1)
1006  return 0;
1007 
1008  /*
1009  * We are inside the irq code, and this is returning entry.
1010  * Let's not trace it and clear the entry depth, since
1011  * we are out of irq code.
1012  *
1013  * This condition ensures that we 'leave the irq code' once
1014  * we are out of the entry depth. Thus protecting us from
1015  * the RETURN entry loss.
1016  */
1017  if (*depth_irq >= depth) {
1018  *depth_irq = -1;
1019  return 1;
1020  }
1021 
1022  /*
1023  * We are inside the irq code, and this is not the entry.
1024  */
1025  return 1;
1026 }
1027 
1028 static enum print_line_t
1029 print_graph_entry(struct ftrace_graph_ent_entry *field, struct trace_seq *s,
1030  struct trace_iterator *iter, u32 flags)
1031 {
1032  struct fgraph_data *data = iter->private;
1033  struct ftrace_graph_ent *call = &field->graph_ent;
1034  struct ftrace_graph_ret_entry *leaf_ret;
1035  static enum print_line_t ret;
1036  int cpu = iter->cpu;
1037 
1038  if (check_irq_entry(iter, flags, call->func, call->depth))
1039  return TRACE_TYPE_HANDLED;
1040 
1041  if (print_graph_prologue(iter, s, TRACE_GRAPH_ENT, call->func, flags))
1042  return TRACE_TYPE_PARTIAL_LINE;
1043 
1044  leaf_ret = get_return_for_leaf(iter, field);
1045  if (leaf_ret)
1046  ret = print_graph_entry_leaf(iter, field, leaf_ret, s, flags);
1047  else
1048  ret = print_graph_entry_nested(iter, field, s, cpu, flags);
1049 
1050  if (data) {
1051  /*
1052  * If we failed to write our output, then we need to make
1053  * note of it. Because we already consumed our entry.
1054  */
1055  if (s->full) {
1056  data->failed = 1;
1057  data->cpu = cpu;
1058  } else
1059  data->failed = 0;
1060  }
1061 
1062  return ret;
1063 }
1064 
1065 static enum print_line_t
1066 print_graph_return(struct ftrace_graph_ret *trace, struct trace_seq *s,
1067  struct trace_entry *ent, struct trace_iterator *iter,
1068  u32 flags)
1069 {
1070  unsigned long long duration = trace->rettime - trace->calltime;
1071  struct fgraph_data *data = iter->private;
1072  pid_t pid = ent->pid;
1073  int cpu = iter->cpu;
1074  int func_match = 1;
1075  int ret;
1076  int i;
1077 
1078  if (check_irq_return(iter, flags, trace->depth))
1079  return TRACE_TYPE_HANDLED;
1080 
1081  if (data) {
1082  struct fgraph_cpu_data *cpu_data;
1083  int cpu = iter->cpu;
1084 
1085  cpu_data = per_cpu_ptr(data->cpu_data, cpu);
1086 
1087  /*
1088  * Comments display at + 1 to depth. This is the
1089  * return from a function, we now want the comments
1090  * to display at the same level of the bracket.
1091  */
1092  cpu_data->depth = trace->depth - 1;
1093 
1094  if (trace->depth < FTRACE_RETFUNC_DEPTH) {
1095  if (cpu_data->enter_funcs[trace->depth] != trace->func)
1096  func_match = 0;
1097  cpu_data->enter_funcs[trace->depth] = 0;
1098  }
1099  }
1100 
1101  if (print_graph_prologue(iter, s, 0, 0, flags))
1102  return TRACE_TYPE_PARTIAL_LINE;
1103 
1104  /* Overhead and duration */
1105  ret = print_graph_duration(duration, s, flags);
1106  if (ret == TRACE_TYPE_PARTIAL_LINE)
1107  return TRACE_TYPE_PARTIAL_LINE;
1108 
1109  /* Closing brace */
1110  for (i = 0; i < trace->depth * TRACE_GRAPH_INDENT; i++) {
1111  ret = trace_seq_printf(s, " ");
1112  if (!ret)
1113  return TRACE_TYPE_PARTIAL_LINE;
1114  }
1115 
1116  /*
1117  * If the return function does not have a matching entry,
1118  * then the entry was lost. Instead of just printing
1119  * the '}' and letting the user guess what function this
1120  * belongs to, write out the function name.
1121  */
1122  if (func_match) {
1123  ret = trace_seq_printf(s, "}\n");
1124  if (!ret)
1125  return TRACE_TYPE_PARTIAL_LINE;
1126  } else {
1127  ret = trace_seq_printf(s, "} /* %ps */\n", (void *)trace->func);
1128  if (!ret)
1129  return TRACE_TYPE_PARTIAL_LINE;
1130  }
1131 
1132  /* Overrun */
1133  if (flags & TRACE_GRAPH_PRINT_OVERRUN) {
1134  ret = trace_seq_printf(s, " (Overruns: %lu)\n",
1135  trace->overrun);
1136  if (!ret)
1137  return TRACE_TYPE_PARTIAL_LINE;
1138  }
1139 
1140  ret = print_graph_irq(iter, trace->func, TRACE_GRAPH_RET,
1141  cpu, pid, flags);
1142  if (ret == TRACE_TYPE_PARTIAL_LINE)
1143  return TRACE_TYPE_PARTIAL_LINE;
1144 
1145  return TRACE_TYPE_HANDLED;
1146 }
1147 
1148 static enum print_line_t
1149 print_graph_comment(struct trace_seq *s, struct trace_entry *ent,
1150  struct trace_iterator *iter, u32 flags)
1151 {
1152  unsigned long sym_flags = (trace_flags & TRACE_ITER_SYM_MASK);
1153  struct fgraph_data *data = iter->private;
1154  struct trace_event *event;
1155  int depth = 0;
1156  int ret;
1157  int i;
1158 
1159  if (data)
1160  depth = per_cpu_ptr(data->cpu_data, iter->cpu)->depth;
1161 
1162  if (print_graph_prologue(iter, s, 0, 0, flags))
1163  return TRACE_TYPE_PARTIAL_LINE;
1164 
1165  /* No time */
1166  ret = print_graph_duration(DURATION_FILL_FULL, s, flags);
1167  if (ret != TRACE_TYPE_HANDLED)
1168  return ret;
1169 
1170  /* Indentation */
1171  if (depth > 0)
1172  for (i = 0; i < (depth + 1) * TRACE_GRAPH_INDENT; i++) {
1173  ret = trace_seq_printf(s, " ");
1174  if (!ret)
1175  return TRACE_TYPE_PARTIAL_LINE;
1176  }
1177 
1178  /* The comment */
1179  ret = trace_seq_printf(s, "/* ");
1180  if (!ret)
1181  return TRACE_TYPE_PARTIAL_LINE;
1182 
1183  switch (iter->ent->type) {
1184  case TRACE_BPRINT:
1185  ret = trace_print_bprintk_msg_only(iter);
1186  if (ret != TRACE_TYPE_HANDLED)
1187  return ret;
1188  break;
1189  case TRACE_PRINT:
1190  ret = trace_print_printk_msg_only(iter);
1191  if (ret != TRACE_TYPE_HANDLED)
1192  return ret;
1193  break;
1194  default:
1195  event = ftrace_find_event(ent->type);
1196  if (!event)
1197  return TRACE_TYPE_UNHANDLED;
1198 
1199  ret = event->funcs->trace(iter, sym_flags, event);
1200  if (ret != TRACE_TYPE_HANDLED)
1201  return ret;
1202  }
1203 
1204  /* Strip ending newline */
1205  if (s->buffer[s->len - 1] == '\n') {
1206  s->buffer[s->len - 1] = '\0';
1207  s->len--;
1208  }
1209 
1210  ret = trace_seq_printf(s, " */\n");
1211  if (!ret)
1212  return TRACE_TYPE_PARTIAL_LINE;
1213 
1214  return TRACE_TYPE_HANDLED;
1215 }
1216 
1217 
1218 enum print_line_t
1220 {
1221  struct ftrace_graph_ent_entry *field;
1222  struct fgraph_data *data = iter->private;
1223  struct trace_entry *entry = iter->ent;
1224  struct trace_seq *s = &iter->seq;
1225  int cpu = iter->cpu;
1226  int ret;
1227 
1228  if (data && per_cpu_ptr(data->cpu_data, cpu)->ignore) {
1229  per_cpu_ptr(data->cpu_data, cpu)->ignore = 0;
1230  return TRACE_TYPE_HANDLED;
1231  }
1232 
1233  /*
1234  * If the last output failed, there's a possibility we need
1235  * to print out the missing entry which would never go out.
1236  */
1237  if (data && data->failed) {
1238  field = &data->ent;
1239  iter->cpu = data->cpu;
1240  ret = print_graph_entry(field, s, iter, flags);
1241  if (ret == TRACE_TYPE_HANDLED && iter->cpu != cpu) {
1242  per_cpu_ptr(data->cpu_data, iter->cpu)->ignore = 1;
1243  ret = TRACE_TYPE_NO_CONSUME;
1244  }
1245  iter->cpu = cpu;
1246  return ret;
1247  }
1248 
1249  switch (entry->type) {
1250  case TRACE_GRAPH_ENT: {
1251  /*
1252  * print_graph_entry() may consume the current event,
1253  * thus @field may become invalid, so we need to save it.
1254  * sizeof(struct ftrace_graph_ent_entry) is very small,
1255  * it can be safely saved at the stack.
1256  */
1257  struct ftrace_graph_ent_entry saved;
1258  trace_assign_type(field, entry);
1259  saved = *field;
1260  return print_graph_entry(&saved, s, iter, flags);
1261  }
1262  case TRACE_GRAPH_RET: {
1263  struct ftrace_graph_ret_entry *field;
1264  trace_assign_type(field, entry);
1265  return print_graph_return(&field->ret, s, entry, iter, flags);
1266  }
1267  case TRACE_STACK:
1268  case TRACE_FN:
1269  /* dont trace stack and functions as comments */
1270  return TRACE_TYPE_UNHANDLED;
1271 
1272  default:
1273  return print_graph_comment(s, entry, iter, flags);
1274  }
1275 
1276  return TRACE_TYPE_HANDLED;
1277 }
1278 
1279 static enum print_line_t
1280 print_graph_function(struct trace_iterator *iter)
1281 {
1282  return print_graph_function_flags(iter, tracer_flags.val);
1283 }
1284 
1285 static enum print_line_t
1286 print_graph_function_event(struct trace_iterator *iter, int flags,
1287  struct trace_event *event)
1288 {
1289  return print_graph_function(iter);
1290 }
1291 
1292 static void print_lat_header(struct seq_file *s, u32 flags)
1293 {
1294  static const char spaces[] = " " /* 16 spaces */
1295  " " /* 4 spaces */
1296  " "; /* 17 spaces */
1297  int size = 0;
1298 
1299  if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
1300  size += 16;
1301  if (flags & TRACE_GRAPH_PRINT_CPU)
1302  size += 4;
1303  if (flags & TRACE_GRAPH_PRINT_PROC)
1304  size += 17;
1305 
1306  seq_printf(s, "#%.*s _-----=> irqs-off \n", size, spaces);
1307  seq_printf(s, "#%.*s / _----=> need-resched \n", size, spaces);
1308  seq_printf(s, "#%.*s| / _---=> hardirq/softirq \n", size, spaces);
1309  seq_printf(s, "#%.*s|| / _--=> preempt-depth \n", size, spaces);
1310  seq_printf(s, "#%.*s||| / \n", size, spaces);
1311 }
1312 
1313 static void __print_graph_headers_flags(struct seq_file *s, u32 flags)
1314 {
1315  int lat = trace_flags & TRACE_ITER_LATENCY_FMT;
1316 
1317  if (lat)
1318  print_lat_header(s, flags);
1319 
1320  /* 1st line */
1321  seq_printf(s, "#");
1322  if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
1323  seq_printf(s, " TIME ");
1324  if (flags & TRACE_GRAPH_PRINT_CPU)
1325  seq_printf(s, " CPU");
1326  if (flags & TRACE_GRAPH_PRINT_PROC)
1327  seq_printf(s, " TASK/PID ");
1328  if (lat)
1329  seq_printf(s, "||||");
1330  if (flags & TRACE_GRAPH_PRINT_DURATION)
1331  seq_printf(s, " DURATION ");
1332  seq_printf(s, " FUNCTION CALLS\n");
1333 
1334  /* 2nd line */
1335  seq_printf(s, "#");
1336  if (flags & TRACE_GRAPH_PRINT_ABS_TIME)
1337  seq_printf(s, " | ");
1338  if (flags & TRACE_GRAPH_PRINT_CPU)
1339  seq_printf(s, " | ");
1340  if (flags & TRACE_GRAPH_PRINT_PROC)
1341  seq_printf(s, " | | ");
1342  if (lat)
1343  seq_printf(s, "||||");
1344  if (flags & TRACE_GRAPH_PRINT_DURATION)
1345  seq_printf(s, " | | ");
1346  seq_printf(s, " | | | |\n");
1347 }
1348 
1350 {
1351  print_graph_headers_flags(s, tracer_flags.val);
1352 }
1353 
1355 {
1356  struct trace_iterator *iter = s->private;
1357 
1358  if (!(trace_flags & TRACE_ITER_CONTEXT_INFO))
1359  return;
1360 
1361  if (trace_flags & TRACE_ITER_LATENCY_FMT) {
1362  /* print nothing if the buffers are empty */
1363  if (trace_empty(iter))
1364  return;
1365 
1366  print_trace_header(s, iter);
1367  }
1368 
1369  __print_graph_headers_flags(s, flags);
1370 }
1371 
1373 {
1374  /* pid and depth on the last trace processed */
1375  struct fgraph_data *data;
1376  int cpu;
1377 
1378  iter->private = NULL;
1379 
1380  data = kzalloc(sizeof(*data), GFP_KERNEL);
1381  if (!data)
1382  goto out_err;
1383 
1384  data->cpu_data = alloc_percpu(struct fgraph_cpu_data);
1385  if (!data->cpu_data)
1386  goto out_err_free;
1387 
1388  for_each_possible_cpu(cpu) {
1389  pid_t *pid = &(per_cpu_ptr(data->cpu_data, cpu)->last_pid);
1390  int *depth = &(per_cpu_ptr(data->cpu_data, cpu)->depth);
1391  int *ignore = &(per_cpu_ptr(data->cpu_data, cpu)->ignore);
1392  int *depth_irq = &(per_cpu_ptr(data->cpu_data, cpu)->depth_irq);
1393 
1394  *pid = -1;
1395  *depth = 0;
1396  *ignore = 0;
1397  *depth_irq = -1;
1398  }
1399 
1400  iter->private = data;
1401 
1402  return;
1403 
1404  out_err_free:
1405  kfree(data);
1406  out_err:
1407  pr_warning("function graph tracer: not enough memory\n");
1408 }
1409 
1411 {
1412  struct fgraph_data *data = iter->private;
1413 
1414  if (data) {
1415  free_percpu(data->cpu_data);
1416  kfree(data);
1417  }
1418 }
1419 
1420 static int func_graph_set_flag(u32 old_flags, u32 bit, int set)
1421 {
1422  if (bit == TRACE_GRAPH_PRINT_IRQS)
1423  ftrace_graph_skip_irqs = !set;
1424 
1425  return 0;
1426 }
1427 
1428 static struct trace_event_functions graph_functions = {
1429  .trace = print_graph_function_event,
1430 };
1431 
1432 static struct trace_event graph_trace_entry_event = {
1433  .type = TRACE_GRAPH_ENT,
1434  .funcs = &graph_functions,
1435 };
1436 
1437 static struct trace_event graph_trace_ret_event = {
1438  .type = TRACE_GRAPH_RET,
1439  .funcs = &graph_functions
1440 };
1441 
1442 static struct tracer graph_trace __read_mostly = {
1443  .name = "function_graph",
1444  .open = graph_trace_open,
1445  .pipe_open = graph_trace_open,
1446  .close = graph_trace_close,
1447  .pipe_close = graph_trace_close,
1448  .wait_pipe = poll_wait_pipe,
1449  .init = graph_trace_init,
1450  .reset = graph_trace_reset,
1451  .print_line = print_graph_function,
1452  .print_header = print_graph_headers,
1453  .flags = &tracer_flags,
1454  .set_flag = func_graph_set_flag,
1455 #ifdef CONFIG_FTRACE_SELFTEST
1456  .selftest = trace_selftest_startup_function_graph,
1457 #endif
1458 };
1459 
1460 static __init int init_graph_trace(void)
1461 {
1462  max_bytes_for_cpu = snprintf(NULL, 0, "%d", nr_cpu_ids - 1);
1463 
1464  if (!register_ftrace_event(&graph_trace_entry_event)) {
1465  pr_warning("Warning: could not register graph trace events\n");
1466  return 1;
1467  }
1468 
1469  if (!register_ftrace_event(&graph_trace_ret_event)) {
1470  pr_warning("Warning: could not register graph trace events\n");
1471  return 1;
1472  }
1473 
1474  return register_tracer(&graph_trace);
1475 }
1476 
1477 device_initcall(init_graph_trace);