linux-kernelftrace

how to use ftrace to trace static functions for loadable kernel module


I'm wondering how I would go about tracing static functions from loadable modules. Let's say I wanted to record zram_init. If I do:

# echo zram_init > set_graph_function
bash: echo: write error: Invalid argument

it fails. There seem to be two causes -- first, zram_init is static, so it doesn't export a symbol, and second, the module isn't loaded, so the kernel wouldn't know about the symbol anyway. I'm more interested in the first, how to go about tracing static functions that are registered as interfaces for a particular kernel module (in particular, I want to see what zram is doing when various fs's call writepage), but I'm also curious about how you would record an init function as well...


Solution

  • One workaround is to trace do_one_initcall, which calls every module's __init function. It looks like the following for v6.14 kernel:

    int __init_or_module do_one_initcall(initcall_t fn)
    {
        ...
        do_trace_initcall_start(fn);
        ret = fn(); /* e.g. zram_init */
        do_trace_initcall_finish(fn, ret);
            ...
    }
    

    Especially for my kernel version the default trace buffer size is not enough to store the whole call-chain, so I did:

    # cd /sys/kernel/tracing
    # echo 16384 > buffer_size_kb
    

    Next make sure you're not loading any other kernel module (and make sure that zram.ko is not loaded yet), because then /sys/kernel/tracing/trace will have other init calls as well. Then do:

    # cd /sys/kernel/tracing
    # echo > set_graph_function
    # echo do_one_initcall > set_graph_function
    # echo > trace
    # modprobe zram
    

    Then, since /sys/kernel/tracing/trace will have large amount of calls, I'd prefer to store the trace into file and use vim to check it:

    # cat trace > /tmp/trace.log
    

    Then you should see something like this (this is especially true for my kernel):

    # tracer: function_graph
    #
    # CPU  DURATION                  FUNCTION CALLS
    # |     |   |                     |   |   |   |
      12)               |  do_one_initcall() {
      12)   0.600 us    |    initcall_blacklisted();
      12)               |    zram_init [zram]() {
      12)               |      __cpuhp_setup_state() {
      12)   0.250 us    |        cpus_read_lock();
      12)               |        __cpuhp_setup_state_cpuslocked() {
      12)   0.360 us    |          mutex_lock();
    
    ...
    

    As for,

    in particular, I want to see what zram is doing when various fs's call writepage

    I'm not sure what you mean by that, as far as I know zram is itself a block device that must have its own IO operations and in zram they are defined in zram_devops, especially for write and compression it seems that zram will use zram_write_page