Debugging Linux Kernel using Kretprobes - Measuring execution time of a kernel function

With KretProbes, you can measure the execution time taken by a function, without modifying the source code of the Kernel.

Kretprobes allows user to set an optional handler which will be called on function entry. This is achieved by setting the entry_handler field of kretprobe struct.

handler field is called when the return statement of the function executes.

Private data can be shared between entry and return handlers using kretprobe_instance object. data_size field of the kretprobe structure defines the maximum size of the private data structure

maxactive field of the kretprobe struct specifies the number of concurrent probed instances of the function.

Sample Code measuring execution time of _do_fork

#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/kprobes.h>

MODULE_LICENSE("GPL");
static struct kretprobe retprobe;

struct user_data {
        ktime_t time_stamp;
};

static int entry_handler(struct kretprobe_instance *ri, struct pt_regs *regs)
{
    struct user_data *user_data;
    if (!current->mm)
        return 1;   /* Skip kernel threads */
 
    user_data = (struct user_data *)ri->data;
    user_data->time_stamp = ktime_get();
    return 0;
}

static int ret_handler(struct kretprobe_instance *ri, struct pt_regs *regs)
{
    int retval = regs_return_value(regs);
    struct user_data *user_data = (struct user_data *)ri->data;
    s64 delta;
    ktime_t now;

    now = ktime_get();
    delta = ktime_to_ns(ktime_sub(now, user_data->time_stamp));
    printk(KERN_INFO "_do_fork returned %d and took %lld ns to execute\n",
                        retval, (long long)delta);
    return 0;
}

static int test_kretprobe_init(void)
{
    int retval = 0;
    printk(KERN_INFO"%s: In init\n", __func__);
    retprobe.entry_handler = entry_handler; 
    retprobe.kp.symbol_name = "_do_fork";
    retprobe.handler = ret_handler;
    retprobe.data_size = sizeof(struct user_data);
    retprobe.maxactive = 20;
    retval = register_kretprobe(&retprobe);
    if (retval < 0) {
        printk(KERN_INFO"register_kretprobe failed, returned:%d\n",
                retval);
    }
    return retval;
}

static void test_kretprobe_exit(void)
{
    unregister_kretprobe(&retprobe);
    printk(KERN_INFO"%s: In exit\n", __func__);
}
module_init(test_kretprobe_init);

module_exit(test_kretprobe_exit);

dmesg output: