Kretprobes
使用Kretprobes 监控内涵函数运行时间和返回值.
一个简单的例子
文件名: myretprobe.c
#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/kprobes.h>
#include <linux/ktime.h>
#include <linux/limits.h>
#include <linux/sched.h>
static char func_name[NAME_MAX] = "ksys_read";
module_param_string(func, func_name, NAME_MAX, S_IRUGO);
MODULE_PARM_DESC(func, "Function to kretprobe; this module will report the"
" function's execution time");
/* per-instance private data */
struct my_data {
ktime_t entry_stamp;
};
/* Here we use the entry_hanlder to timestamp function entry */
static int entry_handler(struct kretprobe_instance *ri, struct pt_regs *regs)
{
struct my_data *data;
if (!current->mm)
return 1; /* Skip kernel threads */
data = (struct my_data *)ri->data;
data->entry_stamp = ktime_get();
return 0;
}
/*
* Return-probe handler: Log the return value and duration. Duration may turn
* out to be zero consistently, depending upon the granularity of time
* accounting on the platform.
*/
static int ret_handler(struct kretprobe_instance *ri, struct pt_regs *regs)
{
int retval = regs_return_value(regs);
struct my_data *data = (struct my_data *)ri->data;
s64 delta;
ktime_t now;
now = ktime_get();
delta = ktime_to_ns(ktime_sub(now, data->entry_stamp));
printk(KERN_INFO "%s returned %d and took %lld ns to execute\n",
func_name, retval, (long long)delta);
return 0;
}
static struct kretprobe my_kretprobe = {
.handler = ret_handler,
.entry_handler = entry_handler,
.data_size = sizeof(struct my_data),
/* Probe up to 20 instances concurrently. */
.maxactive = 20,
};
static int __init kretprobe_init(void)
{
int ret;
my_kretprobe.kp.symbol_name = func_name;
ret = register_kretprobe(&my_kretprobe);
if (ret < 0) {
printk(KERN_INFO "register_kretprobe failed, returned %d\n",
ret);
return -1;
}
printk(KERN_INFO "Planted return probe at %s: %p\n",
my_kretprobe.kp.symbol_name, my_kretprobe.kp.addr);
return 0;
}
static void __exit kretprobe_exit(void)
{
unregister_kretprobe(&my_kretprobe);
printk(KERN_INFO "kretprobe at %p unregistered\n",
my_kretprobe.kp.addr);
/* nmissed > 0 suggests that maxactive was set too low. */
printk(KERN_INFO "Missed probing %d instances of %s\n",
my_kretprobe.nmissed, my_kretprobe.kp.symbol_name);
}
module_init(kretprobe_init)
module_exit(kretprobe_exit)
MODULE_LICENSE("GPL");
Makefile
obj-m += myretprobe.o
tag ?= `uname -r`
KDIR := /lib/modules/${tag}/build/
all:
make -C $(KDIR) M=$(PWD) modules
clean:
make -C $(KDIR) M=$(PWD) clean
运行并查看结果
$ make all
$ sudo insmod myretprobe.ko
$ sudo rmmod myretprobe
$ tail -n 10 /var/log/syslog
Jul 13 00:27:54 supra kernel: [ 2367.855060] ksys_read returned -32 and took 234 ns to execute
Jul 13 00:27:54 supra kernel: [ 2367.855063] ksys_read returned -32 and took 190 ns to execute
Jul 13 00:27:54 supra kernel: [ 2367.855066] ksys_read returned -32 and took 191 ns to execute
Jul 13 00:27:54 supra kernel: [ 2367.855068] ksys_read returned -32 and took 189 ns to execute
统计返回值 histogram 的例子
#include <linux/kernel.h>
#include <linux/module.h>
#include <linux/kprobes.h>
#include <linux/ktime.h>
#include <linux/limits.h>
#include <linux/sched.h>
#include <linux/init.h>
#define MY_ARRAY_SIZE 10
static uint my_array[MY_ARRAY_SIZE];
static char func_name[NAME_MAX] = "ksys_read";
module_param_string(func, func_name, NAME_MAX, S_IRUGO);
MODULE_PARM_DESC(func, "Function to kretprobe; this module will report the"
" function's execution time");
static int ret_handler(struct kretprobe_instance *ri, struct pt_regs *regs)
{
int retval = regs_return_value(regs);
if (retval < 0) {
my_array[0]++;
} else if (0 == retval) {
my_array[1]++;
} else if (retval < 20) {
my_array[2]++;
} else if (retval < 40) {
my_array[3]++;
} else if (retval < 80) {
my_array[4]++;
} else if (retval < 160) {
my_array[5]++;
} else if (retval < 320) {
my_array[6]++;
} else if (retval < 640) {
my_array[7]++;
} else if (retval < 1280) {
my_array[8]++;
} else {
my_array[9]++;
}
//printk(KERN_INFO "%s returned %d \n", func_name, retval);
return 0;
}
static struct kretprobe my_kretprobe = {
.handler = ret_handler,
.maxactive = 3,
};
static int __init kretprobe_init(void)
{
int ret;
memset(my_array, 0, sizeof(uint) * MY_ARRAY_SIZE);
my_kretprobe.kp.symbol_name = func_name;
ret = register_kretprobe(&my_kretprobe);
if (ret < 0) {
printk(KERN_INFO "register_kretprobe failed, returned %d\n",
ret);
return -1;
}
printk(KERN_INFO "Planted return probe at %s: %p\n",
my_kretprobe.kp.symbol_name, my_kretprobe.kp.addr);
return 0;
}
static void __exit kretprobe_exit(void)
{
int i;
unregister_kretprobe(&my_kretprobe);
printk(KERN_INFO "kretprobe at %p unregistered\n",
my_kretprobe.kp.addr);
printk(KERN_INFO "my_array values:\n");
for (i = 0; i < MY_ARRAY_SIZE; i++) {
printk(KERN_INFO "my_array[%d]: %u\n", i, my_array[i]);
}
/* nmissed > 0 suggests that maxactive was set too low. */
printk(KERN_INFO "Missed probing %d instances of %s\n",
my_kretprobe.nmissed, my_kretprobe.kp.symbol_name);
}
module_init(kretprobe_init)
module_exit(kretprobe_exit)
MODULE_LICENSE("GPL");