Search code examples
linuxdebugginglinux-kernelftrace

ftrace cannot trace some kernel functions


I'm using ftrace to trace ip_local_out() in kernel 5.4.20.

I'm sure ip_local_out() is available to trace:

/sys/kernel/debug/tracing # cat available_filter_functions |grep ip_local_out
__ip_local_out
ip_local_out

So I set up ftrace and start to trace as follows:

/sys/kernel/debug/tracing # echo ip_local_out > set_graph_function 
/sys/kernel/debug/tracing # echo function_graph > current_tracer 
/sys/kernel/debug/tracing # echo 3 > max_graph_depth 
/sys/kernel/debug/tracing # cat trace_pipe 

Then I communicate this kernel with ICMP ping. However, there is no output from ftrace.

I suspect ip_local_out() is not called at all, so I add printk() in ip_local_out() and recompile:


int ip_local_out(struct net *net, struct sock *sk, struct sk_buff *skb)
{
        int err;

        //crezov debug
        printk("<%s:%d> crezov debug: ip_local_out() is called!\n", __FUNCTION__, __LINE__);
        err = __ip_local_out(net, sk, skb);
        if (likely(err == 1))
                err = dst_output(net, sk, skb);

        return err;
}
EXPORT_SYMBOL_GPL(ip_local_out);

With same configuration and same ICMP ping, the recompiled kernel can output as follws, which can show that ip_local_out() is called, in addition, ip_local_out can be traced!

[   43.219817] <ip_local_out:127> crezov debug: ip_local_out() is called!
 0)               |  ip_local_out() {
 0)   ==========> |
 0)               |    smp_irq_work_interrupt() {
 0) + 44.167 us   |      irq_enter();
 0) + 98.824 us   |      __wake_up();
 0) + 11.717 us   |      irq_exit();
 0) ! 567.096 us  |    }
 0)   <========== |
 0)               |    printk() {
 0) # 9894.629 us |      vprintk_func();
 0) # 9941.234 us |    }
 0)               |    __ip_local_out() {
 0) + 52.389 us   |      ip_send_check();
 0) ! 135.433 us  |    }
 0)               |    ip_output() {
 0) ! 649.046 us  |      ip_finish_output();
 0) ! 716.535 us  |    }
 0) * 12446.31 us |  }

However, once I delete the printk() from ip_local_out and recompile, ip_local_out() can't be traced again.

What am I missing? Please help.


Solution

  • After a week's experiment, I finally find the reason: ip_local_out() was auto-inlined! When I use noinline attribute like this:

    noinline int ip_local_out(struct net *net, struct sock *sk, struct sk_buff *skb)
    {
            int err;
    
            err = __ip_local_out(net, sk, skb);
            if (likely(err == 1))
                    err = dst_output(net, sk, skb);
    
            return err;
    }
    EXPORT_SYMBOL_GPL(ip_local_out);
    

    ftrace can capture ip_local_out().