linux/kernel/trace
Steven Rostedt f1c7f517a5 ftrace: Add function names to dangling } in function graph tracer
The function graph tracer is currently the most invasive tracer
in the ftrace family. It can easily overflow the buffer even with
10megs per CPU. This means that events can often be lost.

On start up, or after events are lost, if the function return is
recorded but the function enter was lost, all we get to see is the
exiting '}'.

Here is how a typical trace output starts:

 [tracing] cat trace
 # tracer: function_graph
 #
 # CPU  DURATION                  FUNCTION CALLS
 # |     |   |                     |   |   |   |
  0) + 91.897 us   |                  }
  0) ! 567.961 us  |                }
  0)   <========== |
  0) ! 579.083 us  |                _raw_spin_lock_irqsave();
  0)   4.694 us    |                _raw_spin_unlock_irqrestore();
  0) ! 594.862 us  |              }
  0) ! 603.361 us  |            }
  0) ! 613.574 us  |          }
  0) ! 623.554 us  |        }
  0)   3.653 us    |        fget_light();
  0)               |        sock_poll() {

There are a series of '}' with no matching "func() {". There's no information
to what functions these ending brackets belong to.

This patch adds a stack on the per cpu structure used in outputting
the function graph tracer to keep track of what function was outputted.
Then on a function exit event, it checks the depth to see if the
function exit has a matching entry event. If it does, then it only
prints the '}', otherwise it adds the function name after the '}'.

This allows function exit events to show what function they belong to
at trace output startup, when the entry was lost due to ring buffer
overflow, or even after a new task is scheduled in.

Here is what the above trace will look like after this patch:

 [tracing] cat trace
 # tracer: function_graph
 #
 # CPU  DURATION                  FUNCTION CALLS
 # |     |   |                     |   |   |   |
  0) + 91.897 us   |                  } (irq_exit)
  0) ! 567.961 us  |                } (smp_apic_timer_interrupt)
  0)   <========== |
  0) ! 579.083 us  |                _raw_spin_lock_irqsave();
  0)   4.694 us    |                _raw_spin_unlock_irqrestore();
  0) ! 594.862 us  |              } (add_wait_queue)
  0) ! 603.361 us  |            } (__pollwait)
  0) ! 613.574 us  |          } (tcp_poll)
  0) ! 623.554 us  |        } (sock_poll)
  0)   3.653 us    |        fget_light();
  0)               |        sock_poll() {

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
2010-02-26 19:25:53 -05:00
..
blktrace.c Add a tracepoint for block request remapping 2009-10-01 21:19:34 +02:00
ftrace.c Merge commit 'v2.6.33' into tracing/core 2010-02-26 09:18:32 +01:00
Kconfig Merge branch 'tip/tracing/core' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace into tracing/core 2010-02-26 09:20:17 +01:00
kmemtrace.c kmemtrace: Fix up tracer registration 2009-10-01 11:53:44 +02:00
Makefile Merge branch 'tracing/hw-breakpoints' into perf/core 2009-11-21 14:07:23 +01:00
power-traces.c tracing/power: Remove two exports 2009-12-13 18:37:28 +01:00
ring_buffer_benchmark.c ring-buffer-benchmark: Add parameters to set produce/consumer priorities 2009-11-25 14:14:15 -05:00
ring_buffer.c ring-buffer: Check for end of page in iterator 2010-01-26 16:14:08 -05:00
trace_boot.c tracing: add filter event logic to special, mmiotrace and boot tracers 2009-09-12 23:34:04 -04:00
trace_branch.c tracing: Add correct/incorrect to sort keys for branch annotation output 2010-02-09 21:35:05 -05:00
trace_clock.c locking: Convert __raw_spin* functions to arch_spin* 2009-12-14 23:55:32 +01:00
trace_entries.h hw-breakpoints: Rewrite the hw-breakpoints layer on top of perf events 2009-11-08 15:34:42 +01:00
trace_event_profile.c tracing: Change event->profile_count to be int type 2009-12-13 18:37:28 +01:00
trace_events_filter.c tracing/filters: Add comment for match callbacks 2010-01-14 22:38:14 -05:00
trace_events.c tracing: Simplify memory recycle of trace_define_field 2010-02-25 10:42:55 -05:00
trace_export.c tracing: Remove show_format and related macros from TRACE_EVENT 2010-01-06 12:08:46 -05:00
trace_functions_graph.c ftrace: Add function names to dangling } in function graph tracer 2010-02-26 19:25:53 -05:00
trace_functions.c tracing: switch function prints from %pf to %ps 2009-09-17 15:53:40 -04:00
trace_hw_branches.c Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tj/percpu 2009-12-14 09:58:24 -08:00
trace_irqsoff.c tracing: Add stack trace to irqsoff tracer 2009-12-11 13:19:51 -05:00
trace_kprobe.c Merge branch 'tip/tracing/core' of git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-2.6-trace into tracing/core 2010-02-26 09:20:17 +01:00
trace_ksym.c ksym_tracer: Remove trace_stat 2009-12-30 07:50:50 +01:00
trace_mmiotrace.c tracing: add filter event logic to special, mmiotrace and boot tracers 2009-09-12 23:34:04 -04:00
trace_nop.c tracing/ftrace: make nop-tracer use polling wait for events on pipe 2009-03-23 09:22:15 +01:00
trace_output.c tracing: Add full state to trace_seq 2009-12-09 14:05:49 -05:00
trace_output.h tracing: consolidate code between trace_output.c and trace_function_graph.c 2009-09-11 14:24:13 -04:00
trace_printk.c tracing: Remove markers 2009-09-18 21:22:08 +02:00
trace_sched_switch.c tracing: pass around ring buffer instead of tracer 2009-09-04 18:59:39 -04:00
trace_sched_wakeup.c locking: Convert __raw_spin* functions to arch_spin* 2009-12-14 23:55:32 +01:00
trace_selftest_dynamic.c
trace_selftest.c locking: Convert __raw_spin* functions to arch_spin* 2009-12-14 23:55:32 +01:00
trace_stack.c tracing: Fix circular dead lock in stack trace 2010-02-02 10:20:18 -05:00
trace_stat.c trace_stat: Fix missing entry in stat file 2009-08-17 11:25:09 +02:00
trace_stat.h tracing/stat: Add stat_release() callback 2009-07-10 12:14:05 +02:00
trace_syscalls.c tracing: Fix typo in prof_sysexit_enable() 2010-02-25 10:35:55 -05:00
trace_sysprof.c perf events, x86/stacktrace: Make stack walking optional 2009-12-17 09:56:19 +01:00
trace_workqueue.c tracing/workqueues: Add refcnt to struct cpu_workqueue_stats 2009-07-10 12:14:07 +02:00
trace.c Merge commit 'v2.6.33' into tracing/core 2010-02-26 09:18:32 +01:00
trace.h tracing: Fix ftrace_event_call alignment for use with gcc 4.5 2010-02-25 09:38:11 -05:00