Re: [PATCH -v4 9/9] tracing: add function graph tracer support for MIPS

[Steven Rostedt <rostedt@goodmis.org>]

On Wed, 2009-10-21 at 10:48 -0700, David Daney wrote:

> Although I am quite interested in ftrace for MIPS, I a haven't spent the 
> effort to try to figure out how many levels of backtrace we need to be 
> generating here.
> 
> If you only need the caller's address, that is passed in register 'at'. 
>   If you need more than that, then things get tricky.  I would do one of 
> two things:

Ftrace function tracer only needs the address passed in by AT. That
output looks like this (run on x86):

# tracer: function
#
#           TASK-PID    CPU#    TIMESTAMP  FUNCTION
#              | |       |          |         |
          <idle>-0     [000] 140973.465592: mwait_idle <-cpu_idle
          <idle>-0     [000] 140973.465592: need_resched <-mwait_idle
          <idle>-0     [000] 140973.465593: test_ti_thread_flag <-need_resched
          <idle>-0     [000] 140973.465593: T.389 <-mwait_idle
          <idle>-0     [000] 140973.465594: need_resched <-mwait_idle
          <idle>-0     [000] 140973.465594: test_ti_thread_flag <-need_resched
          <idle>-0     [000] 140973.465594: trace_power_end <-mwait_idle
          <idle>-0     [000] 140973.465595: test_ti_thread_flag <-cpu_idle
          <idle>-0     [000] 140973.465595: enter_idle <-cpu_idle
          <idle>-0     [000] 140973.465596: mwait_idle <-cpu_idle
          <idle>-0     [000] 140973.465596: need_resched <-mwait_idle
          <idle>-0     [000] 140973.465596: test_ti_thread_flag <-need_resched
          <idle>-0     [000] 140973.465597: T.389 <-mwait_idle

Which is very useful to have. But what we are trying to get is the
function graph tracer working. This is based off of ftrace's function
tracer. But it does a trick with the return address. Instead of just
reading it, it modifies it to call a hook (note kprobes does the same
thing). We replace the return address with a function that will also
trace the exit of the function. With this, we get a much nicer looking
trace, and also can record the time it took to execute the function
(note, graph tracing has overhead that skews this time).

Here's an example (again on x86):

# tracer: function_graph
#
# CPU  DURATION                  FUNCTION CALLS
# |     |   |                     |   |   |   |
 0)   0.535 us    |  find_vma();
 0)               |  handle_mm_fault() {
 0)               |    count_vm_event() {
 0)   0.333 us    |      test_ti_thread_flag();
 0)   1.029 us    |    }
 0)   0.336 us    |    pud_alloc();
 0)   0.333 us    |    pmd_alloc();
 0)   0.389 us    |    _spin_lock();
 0)               |    do_wp_page() {
 0)   0.322 us    |      vm_normal_page();
 0)   0.329 us    |      reuse_swap_page();
 0)               |      unlock_page() {
 0)               |        wake_up_page() {
 0)   0.352 us    |          page_waitqueue();
 0)   0.442 us    |          __wake_up_bit();
 0)   1.790 us    |        }
 0)   2.444 us    |      }
 0)               |      _spin_unlock() {
 0)   0.371 us    |        T.272();
 0)   1.089 us    |      }


> 
> 1) Use the mechanism used by the OOPS dump.
> 
> 2) Implement back traces based on DWARF2 unwinding data that is 
> generated by the compiler.


We're not doing back traces. We need to modify the return of the
function being called. Note, the above functions that end with ";" are
leaf functions. Non leaf functions show "{" and end with "}".

The trick here is to find a reliable way to modify the return address.

Thanks,

-- Steve