ftrace function graph with static ftrace does not work on MIPS

Hi,

I am trying to understand why ftrace function graph doesn't work when using static ftrace on MIPS. So, what happens when I do 'echo function_graph > current_tracer' is that the ftrace_graph_caller from mcount.S is executed once. The function that called it is 'core_kernel_data()' from __register_ftrace_function in kernel/trace/ftrace.c

However, this is the only function that is reported in the trace file

# cat trace
# tracer: function_graph
#
# CPU  DURATION                  FUNCTION CALLS
# |     |   |                     |   |   |   |
 0)               |  core_kernel_data() {
 0)   0.000 us    |  } /* core_kernel_data */

The reason that the ftrace_graph_caller is never executed after that is that the following as far as I understand:

NESTED(_mcount, PT_SIZE, ra)

        PTR_LA  t1, ftrace_stub
        PTR_L   t2, ftrace_trace_function /* Prepare t2 for (1) */
        bne     t1, t2, static_trace

nop

#ifdef CONFIG_FUNCTION_GRAPH_TRACER
PTR_L t3, ftrace_graph_return
bne t1, t3, ftrace_graph_caller
nop
PTR_LA t1, ftrace_graph_entry_stub
PTR_L t3, ftrace_graph_entry
bne t1, t3, ftrace_graph_caller
nop
#endif

The previous 3 conditionals exists in arch/mips/kernel/mcount.S. Originally, ftrace_trace_function == ftrace_stub, so the first conditional is not taken and we end up executed the ftrace_graph_caller. All good.
However, later on, ftrace_trace_function is set to 'ftrace_ops_no_ops', so the first 'bne' is taken and the ftrace_graph_caller is never executed after that. It is not clear to me if this behaviour is expected so I used QEMU to get a backtrace when ftrace_trace_function is set to ftrace_ops_no_ops.

Old value = (ftrace_func_t) 0x8010fa90 <ftrace_stub>
New value = (ftrace_func_t) 0x801a32f0 <ftrace_ops_no_ops> 0x801a2578 in update_ftrace_function () at kernel/trace/ftrace.c:318 (gdb) bt
#0 0x801a2578 in update_ftrace_function () at kernel/trace/ftrace.c:318 #1 0x801a2ae8 in __register_ftrace_function (ops=0x806fbcb4 <global_ops>)
at kernel/trace/ftrace.c:414
#2 0x801a39ec in register_ftrace_graph (retfunc=0x801b6ab8 <trace_graph_return>,

    entryfunc=0x801b67b4 <trace_graph_entry>) at kernel/trace/ftrace.c:5438
#3  0x801b63d0 in graph_trace_init (tr=<optimized out>)
    at kernel/trace/trace_functions_graph.c:463
#4  0x801b0b84 in tracer_init (tr=<optimized out>, t=<optimized out>)
    at kernel/trace/trace.c:3916
#5  tracing_set_tracer (tr=0x8093e1d8 <global_trace>,
    buf=0x8 <error: Cannot access memory at address 0x8>) at
kernel/trace/trace.c:4171
#6  0x801b103c in tracing_set_trace_write (filp=<optimized out>,
ubuf=<optimized out>,
    cnt=<optimized out>, ppos=0x82147f00) at kernel/trace/trace.c:4209
#7  0x80212944 in vfs_write (file=0x821fa100,
    buf=0x806fbc8c <graph_ops> "\220\372\020\200h0o\200", <incomplete
sequence \340>,
    count=<optimized out>, pos=0x82147f00) at fs/read_write.c:532
#8  0x80213164 in SYSC_write (count=<optimized out>, buf=<optimized out>,
    fd=<optimized out>) at fs/read_write.c:583

#9 SyS_write (fd=<optimized out>, buf=0x4bdf38, count=0xf) at fs/read_write.c:575
#10 0x80112f48 in handle_sys () at arch/mips/kernel/scall32-o32.S:99

So, now that the ftrace_trace_function has been set to 'ftrace_ops_no_ops', the previous branch (as I explained before) is taken and the function graph related functions are not being executed anymore.

Dynamic tracing is working (or seems it does) because the code does a 'jal ftrace_call' and the returns back and does a 'j ftrace_graph_caller'. In other words, it always executes the ftrace_graph_caller no matter what the ftrace_trace_function is.

So any ideas? Do I do something wrong?

markos

Looks like the static tracing code in wrong. The function graph code should be tested every time.

-- Steve

Hi Steven,

I had a look on

https://www.kernel.org/doc/Documentation/trace/ftrace-design.txt

and section "HAVE_FUNCTION_GRAPH_TRACER"

According to the sample code, first we check "ftrace_trace_function != ftrace_stub" and if that's true, then we never check the ftrace_graph_* functions which is exactly what MIPS does. So the graph functions are not always checked. x86 seems to do something similar in mcount_64.S

markos

Thanks, I need to update that file.

I don't test static tracing much as I feel it's overhead makes it almost not worth keeping. I've been even thinking of nuking it, but I keep it in because it's good for archs adding function tracing to get a basic test working, as dynamic function tracing is a bit more difficult to implement.

But yeah, don't go too much by that document. It is out of date, and when I get time, I'll have to update it. I'll probably do that when I bring powerpc up to speed with x86 (except for the fentry part).

I want dynamic trampolines for powerpc and such, and when I do that, it will make all the changes fresh in my mind to go back and tackle the design documentation.

-- Steve