Skip to content
Permalink
Browse files
trace: Add trace any kernel object
Introduce a method based on function tracer and kprobe/uprobe/trace_event/
to trace any object in the linux kernel.

Usage:
When using kprobe/uprobe/trace_event/ we can use a new trigger(objfilter)
to set object and tigger object trace.

For example:

For the function bio_add_page, we can trace the first argument:

int bio_add_page(struct bio *bio, struct page *page,
				unsigned int len, unsigned int offset)

[root@JeffXie ]# cd /sys/kernel/debug/tracing/
[root@JeffXie tracing]# echo 'p bio_add_page arg1=$arg1' > kprobe_events
[root@JeffXie tracing]# cd events/kprobes/p_bio_add_page_0/
[root@JeffXie p_bio_add_page_0]# echo 'objfilter:arg1 if comm == "cat"' > ./trigger
[root@JeffXie p_bio_add_page_0]# cat /test.txt
[root@JeffXie p_bio_add_page_0]# cd /sys/kernel/debug/tracing/
[root@JeffXie tracing]# cat ./trace
# tracer: nop
#
# entries-in-buffer/entries-written: 81/81   #P:4
#
#                                _-----=> irqs-off
#                               / _----=> need-resched
#                              | / _---=> hardirq/softirq
#                              || / _--=> preempt-depth
#                              ||| / _-=> migrate-disable
#                              |||| /     delay
#           TASK-PID     CPU#  |||||  TIMESTAMP  FUNCTION
#              | |         |   |||||     |         |
             cat-122     [001] .....   111.193997: bio_add_page <-ext4_mpage_readpages object:0xffff888102a4b900
             cat-122     [001] .....   111.193998: __bio_try_merge_page <-bio_add_page object:0xffff888102a4b900
             cat-122     [001] .....   111.193998: __bio_add_page <-bio_add_page object:0xffff888102a4b900
             cat-122     [001] .....   111.193998: submit_bio <-ext4_mpage_readpages object:0xffff888102a4b900
             cat-122     [001] .....   111.193998: submit_bio_noacct <-ext4_mpage_readpages object:0xffff888102a4b900
             cat-122     [001] .....   111.193999: __submit_bio <-submit_bio_noacct object:0xffff888102a4b900
             cat-122     [001] .....   111.193999: submit_bio_checks <-__submit_bio object:0xffff888102a4b900
             cat-122     [001] .....   111.193999: __cond_resched <-submit_bio_checks object:0xffff888102a4b900
             cat-122     [001] .....   111.193999: rcu_all_qs <-__cond_resched object:0xffff888102a4b900
             cat-122     [001] .....   111.194000: should_fail_bio <-submit_bio_checks object:0xffff888102a4b900
             cat-122     [001] .....   111.194001: blk_mq_submit_bio <-__submit_bio object:0xffff888102a4b900
             cat-122     [001] .....   111.194001: blk_attempt_plug_merge <-blk_mq_submit_bio object:0xffff888102a4b900
             cat-122     [001] .....   111.194001: __blk_mq_sched_bio_merge <-blk_mq_submit_bio object:0xffff888102a4b900
             cat-122     [001] .....   111.194002: __blk_mq_alloc_request <-blk_mq_submit_bio object:0xffff888102a4b900
             cat-122     [001] .....   111.194002: blk_mq_get_tag <-__blk_mq_alloc_request object:0xffff888102a4b900
             cat-122     [001] .....   111.194003: blk_account_io_start <-blk_mq_submit_bio object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194212: bio_advance <-blk_update_request object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194213: bio_endio <-blk_update_request object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194213: mpage_end_io <-blk_update_request object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194213: __read_end_io <-blk_update_request object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194218: bio_put <-blk_update_request object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194218: bio_free <-blk_update_request object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194218: bio_free <-blk_update_request object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194218: bvec_free <-bio_free object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194219: mempool_free <-blk_update_request object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194219: mempool_free <-blk_update_request object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194219: mempool_free_slab <-blk_update_request object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194219: mempool_free_slab <-blk_update_request object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194219: kmem_cache_free <-blk_update_request object:0xffff888102a4b900
          <idle>-0       [001] d....   111.194219: kmem_cache_free <-blk_update_request object:0xffff888102a4b900

Signed-off-by: Jeff Xie <xiehuan09@gmail.com>
  • Loading branch information
Jeff Xie authored and intel-lab-lkp committed Oct 21, 2021
1 parent 519d819 commit 215d03dac45677f4ea859542fc2c2fe524e29fa1
Show file tree
Hide file tree
Showing 12 changed files with 405 additions and 0 deletions.
@@ -1078,4 +1078,20 @@ unsigned long arch_syscall_addr(int nr);

#endif /* CONFIG_FTRACE_SYSCALLS */

struct trace_event_file;

#ifdef CONFIG_TRACE_OBJECT
int init_trace_object(void);
int exit_trace_object(void);
void set_trace_object(void *obj);
void record_trace_object(struct trace_event_file *trace_file,
struct pt_regs *regs);
#else
static inline int init_trace_object(void) { return 0; }
static inline int exit_trace_object(void) { return 0; }
static inline void set_trace_object(void *obj) { }
static inline void record_trace_object(struct trace_event_file *trace_file,
struct pt_regs *regs) { }
#endif /* CONFIG_TRACE_OBJECT */

#endif /* _LINUX_FTRACE_H */
@@ -684,6 +684,7 @@ enum event_trigger_type {
ETT_EVENT_HIST = (1 << 4),
ETT_HIST_ENABLE = (1 << 5),
ETT_EVENT_EPROBE = (1 << 6),
ETT_TRACE_OBJECT = (1 << 7),
};

extern int filter_match_preds(struct event_filter *filter, void *rec);
@@ -237,6 +237,13 @@ config FUNCTION_PROFILER

If in doubt, say N.

config TRACE_OBJECT
bool "Trace kernel object"
depends on FUNCTION_TRACER
default y
help
This help kernel developer to trace any kernel object.

config STACK_TRACER
bool "Trace max stack"
depends on HAVE_FUNCTION_TRACER
@@ -66,6 +66,7 @@ obj-$(CONFIG_FUNCTION_GRAPH_TRACER) += trace_functions_graph.o
obj-$(CONFIG_TRACE_BRANCH_PROFILING) += trace_branch.o
obj-$(CONFIG_BLK_DEV_IO_TRACE) += blktrace.o
obj-$(CONFIG_FUNCTION_GRAPH_TRACER) += fgraph.o
obj-$(CONFIG_TRACE_OBJECT) += trace_object.o
ifeq ($(CONFIG_BLOCK),y)
obj-$(CONFIG_EVENT_TRACING) += blktrace.o
endif
@@ -49,6 +49,7 @@ enum trace_type {
TRACE_TIMERLAT,
TRACE_RAW_DATA,
TRACE_FUNC_REPEATS,
TRACE_OBJECT,

__TRACE_LAST_TYPE,
};
@@ -460,6 +461,7 @@ extern void __ftrace_bad_type(void);
TRACE_GRAPH_RET); \
IF_ASSIGN(var, ent, struct func_repeats_entry, \
TRACE_FUNC_REPEATS); \
IF_ASSIGN(var, ent, struct trace_object_entry, TRACE_OBJECT);\
__ftrace_bad_type(); \
} while (0)

@@ -1950,6 +1952,11 @@ struct trace_min_max_param {
u64 *max;
};

struct object_trigger_param {
struct pt_regs *regs;
int param;
};

#define U64_STR_SIZE 24 /* 20 digits max */

extern const struct file_operations trace_min_max_fops;
@@ -401,3 +401,20 @@ FTRACE_ENTRY(timerlat, timerlat_entry,
__entry->context,
__entry->timer_latency)
);

/*
* trace object entry:
*/
FTRACE_ENTRY(object, trace_object_entry,

TRACE_OBJECT,

F_STRUCT(
__field( unsigned long, ip )
__field( unsigned long, parent_ip )
__field( unsigned long, object )
),

F_printk(" %ps <-- %ps object:%lx\n",
(void *)__entry->ip, (void *)__entry->parent_ip, __entry->object)
);
@@ -756,12 +756,36 @@ int set_trigger_filter(char *filter_str,
struct event_filter *filter = NULL, *tmp;
int ret = -EINVAL;
char *s;
unsigned long param;
struct object_trigger_param *obj_param;
int len;

if (!filter_str) /* clear the current filter */
goto assign;

s = strsep(&filter_str, " \t");

if (data->cmd_ops->trigger_type == ETT_TRACE_OBJECT) {
obj_param = data->private_data;
len = str_has_prefix(s, "arg");
if (!len)
goto out;
ret = kstrtoul(s + len, 10, &param);
if (ret || param == 0)
goto out;
obj_param = kmalloc(sizeof(*obj_param), GFP_KERNEL);
if (!obj_param) {
ret = -ENOMEM;
goto out;
}
data->private_data = obj_param;
obj_param->param = param;
init_trace_object();
}
if (!strlen(s) || !filter_str)
goto out;

s = strsep(&filter_str, " \t");
if (!strlen(s) || strcmp(s, "if") != 0)
goto out;

@@ -1679,6 +1703,103 @@ static __init int register_trigger_traceon_traceoff_cmds(void)
return ret;
}

#ifdef CONFIG_TRACE_OBJECT

static void
trace_object_trigger(struct event_trigger_data *data,
struct trace_buffer *buffer, void *rec,
struct ring_buffer_event *event)
{

struct object_trigger_param *obj_param = data->private_data;
unsigned long param;

param = regs_get_kernel_argument(obj_param->regs, obj_param->param - 1);
set_trace_object((void *)param);
}

static void
trace_object_trigger_free(struct event_trigger_ops *ops,
struct event_trigger_data *data)
{
if (WARN_ON_ONCE(data->ref <= 0))
return;

data->ref--;
if (!data->ref) {
exit_trace_object();
trigger_data_free(data);
kfree(data->private_data);
}
}

static void
trace_object_count_trigger(struct event_trigger_data *data,
struct trace_buffer *buffer, void *rec,
struct ring_buffer_event *event)
{
if (!data->count)
return;

if (data->count != -1)
(data->count)--;

trace_object_trigger(data, buffer, rec, event);
}

static int
trace_object_trigger_print(struct seq_file *m, struct event_trigger_ops *ops,
struct event_trigger_data *data)
{
return event_trigger_print("objfilter", m, (void *)data->count,
data->filter_str);
}

static struct event_trigger_ops objecttrace_trigger_ops = {
.func = trace_object_trigger,
.print = trace_object_trigger_print,
.init = event_trigger_init,
.free = trace_object_trigger_free,
};

static struct event_trigger_ops objecttrace_count_trigger_ops = {
.func = trace_object_count_trigger,
.print = trace_object_trigger_print,
.init = event_trigger_init,
.free = trace_object_trigger_free,
};

static struct event_trigger_ops *
objecttrace_get_trigger_ops(char *cmd, char *param)
{
return param ? &objecttrace_count_trigger_ops : &objecttrace_trigger_ops;
}

static struct event_command trigger_object_cmd = {
.name = "objfilter",
.trigger_type = ETT_TRACE_OBJECT,
.flags = EVENT_CMD_FL_NEEDS_REC,
.func = event_trigger_callback,
.reg = register_trigger,
.unreg = unregister_trigger,
.get_trigger_ops = objecttrace_get_trigger_ops,
.set_filter = set_trigger_filter,
};

static __init int register_trigger_object_cmd(void)
{
int ret;

ret = register_event_command(&trigger_object_cmd);
WARN_ON(ret < 0);

return ret;
}

#else
static __init int register_trigger_object_cmd(void) { return 0; }
#endif

__init int register_trigger_cmds(void)
{
register_trigger_traceon_traceoff_cmds();
@@ -1687,6 +1808,7 @@ __init int register_trigger_cmds(void)
register_trigger_enable_disable_cmds();
register_trigger_hist_enable_disable_cmds();
register_trigger_hist_cmd();
register_trigger_object_cmd();

return 0;
}
@@ -1380,6 +1380,7 @@ __kprobe_trace_func(struct trace_kprobe *tk, struct pt_regs *regs,

WARN_ON(call != trace_file->event_call);

record_trace_object(trace_file, regs);
if (trace_trigger_soft_disabled(trace_file))
return;

0 comments on commit 215d03d

Please sign in to comment.