2022-05-13 08:34:47

by Jeff Xie

[permalink] [raw]
Subject: [PATCH v10 0/4] trace: Introduce objtrace trigger to trace the kernel object

Introduce a method based on function tracer to trace any object and get
the value of the object dynamically. the object can be obtained from the
dynamic event (kprobe_event/uprobe_event) or the static event(tracepoint).

Usage:
When using the kprobe event, only need to set the objtrace(a new trigger),
we can get the value of the object. The object is from the setting of the
kprobe event.

For example:
For the function bio_add_page():

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

Firstly, we can set the base of the object, thus the first string "arg1"
stands for the value of the first parameter of this function bio_add_gage(),

# echo 'p bio_add_page arg1=$arg1' > ./kprobe_events

Secondly, we can get the value dynamically based on above object.

find the offset of the bi_size in struct bio:
$ gdb vmlinux
(gdb) p &(((struct bio *)0)->bi_iter.bi_size)
$1 = (unsigned int *) 0x28

# echo 'objtrace:add:arg1,0x28:u32:1 if comm == "cat"' > ./events/kprobes/ \
p_bio_add_page_0/trigger

# cd /sys/kernel/debug/tracing/
# echo 'p bio_add_page arg1=$arg1' > ./kprobe_events
# echo 'objtrace:add:arg1,0x28:u32:1 if comm == "cat"' > ./events/kprobes/p_bio_add_page_0/trigger

# du -sh /test.txt
12.0K /test.txt

# cat /test.txt > /dev/null
# cat ./trace
# tracer: nop
#
# entries-in-buffer/entries-written: 128/128 #P:4
#
# _-----=> irqs-off/BH-disabled
# / _----=> need-resched
# | / _---=> hardirq/softirq
# || / _--=> preempt-depth
# ||| / _-=> migrate-disable
# |||| / delay
# TASK-PID CPU# ||||| TIMESTAMP FUNCTION
# | | | ||||| | |
cat-117 [002] ...1. 1.602243: __bio_try_merge_page <-bio_add_page object:0xffff88811bee4000 value:0x0
cat-117 [002] ...1. 1.602244: __bio_add_page <-bio_add_page object:0xffff88811bee4000 value:0x0
cat-117 [002] ...2. 1.602244: bio_add_page <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x1000
cat-117 [002] ...1. 1.602245: __bio_try_merge_page <-bio_add_page object:0xffff88811bee4000 value:0x1000
cat-117 [002] ...1. 1.602245: __bio_add_page <-bio_add_page object:0xffff88811bee4000 value:0x1000
cat-117 [002] ...2. 1.602245: bio_add_page <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x2000
cat-117 [002] ...1. 1.602245: __bio_try_merge_page <-bio_add_page object:0xffff88811bee4000 value:0x2000
cat-117 [002] ...1. 1.602245: __bio_add_page <-bio_add_page object:0xffff88811bee4000 value:0x2000
cat-117 [002] ...1. 1.602245: submit_bio <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x3000
cat-117 [002] ...1. 1.602245: submit_bio_noacct <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x3000
cat-117 [002] ...1. 1.602246: __submit_bio <-submit_bio_noacct object:0xffff88811bee4000 value:0x3000
cat-117 [002] ...1. 1.602246: submit_bio_checks <-__submit_bio object:0xffff88811bee4000 value:0x3000
cat-117 [002] ...1. 1.602246: __cond_resched <-submit_bio_checks object:0xffff88811bee4000 value:0x3000
cat-117 [002] ...1. 1.602246: should_fail_bio <-submit_bio_checks object:0xffff88811bee4000 value:0x3000
cat-117 [002] ...1. 1.602246: blk_mq_submit_bio <-submit_bio_noacct object:0xffff88811bee4000 value:0x3000
cat-117 [002] ...1. 1.602246: blk_attempt_plug_merge <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
cat-117 [002] ...1. 1.602246: blk_mq_sched_bio_merge <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
cat-117 [002] ...1. 1.602247: __rcu_read_lock <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
cat-117 [002] ...1. 1.602247: __rcu_read_unlock <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
cat-117 [002] ...1. 1.602247: __blk_mq_alloc_requests <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
<idle>-0 [002] d..3. 1.602298: bio_endio <-blk_update_request object:0xffff88811bee4000 value:0x0
<idle>-0 [002] d..3. 1.602298: mpage_end_io <-blk_update_request object:0xffff88811bee4000 value:0x0
<idle>-0 [002] d..3. 1.602298: __read_end_io <-blk_update_request object:0xffff88811bee4000 value:0x0
<idle>-0 [002] d..3. 1.602300: bio_put <-blk_update_request object:0xffff88811bee4000 value:0x0
<idle>-0 [002] d..3. 1.602300: bio_free <-blk_update_request object:0xffff88811bee4000 value:0x0
<idle>-0 [002] d..3. 1.602300: mempool_free <-blk_update_request object:0xffff88811bee4000 value:0x0
<idle>-0 [002] d..3. 1.602300: mempool_free_slab <-blk_update_request object:0xffff88811bee4000 value:0x0
<idle>-0 [002] d..3. 1.602300: kmem_cache_free <-blk_update_request object:0xffff88811bee4000 value:0x0
...

Almost all changelogs were suggested by Masami([email protected])
and steve([email protected]), thank you all so much.

v10:
- support ftrace instances
- use trace_buffer_lock_reserve instead of trace_event_buffer_lock_reserve
- a lot of cleanup work has been done mainly for event_object_trigger_parse

v9:
- fix objtrace trigger output was incomplete
- fix the objtrace trigger was removed when using the existed parameter on
event.
- add testcase for the second fix above.

v8:
- revert to use per-cpu recursion for the function trace_object_events_call
- recover the filter when getting the value of the object
- simplify the implementation for the function get_object_value
- fix the build error

v7:
- use fixed-size array for object pool instead of list structure
- use ftrace_test_recursion_trylock for function trace hook function
- fix trace_object_ref reference count in the init_trace_object
- invoke exit_trace_object no matter whether data->ops->free is null
in the unregister_object_trigger
- release private_data of event_trigger_data in the trace_object_trigger_free
- remove [RFC] tag

v6:
- change the objtrace trigger syntax.
- add patchset description
- add <tracefs>/README

v5:
- add testcasts
- add check the field->size
- add lockless to search object
- describe the object trace more clearly in Kconfig

v4:
- please ignore the v4 which is the same as v3

v3:
- change the objfilter to objtrace
- add a command to the objfilter syntax
- change to get the value of the object
- use trace_find_event_field to find the field instead of using argN
- get data from @rec in the event trigger callback funciton

v2:
- adding a "objfilter" trigger to update object

Jeff Xie (4):
trace: Add trace any kernel object
trace/objtrace: Get the value of the object
trace/objtrace: Add testcases for objtrace
trace/objtrace: Add documentation for objtrace

Documentation/trace/events.rst | 83 +++
include/linux/trace_events.h | 1 +
kernel/trace/Kconfig | 10 +
kernel/trace/Makefile | 1 +
kernel/trace/trace.c | 11 +
kernel/trace/trace.h | 21 +
kernel/trace/trace_entries.h | 18 +
kernel/trace/trace_events_trigger.c | 5 +-
kernel/trace/trace_object.c | 611 ++++++++++++++++++
kernel/trace/trace_output.c | 40 ++
.../ftrace/test.d/trigger/trigger-objtrace.tc | 41 ++
11 files changed, 840 insertions(+), 2 deletions(-)
create mode 100644 kernel/trace/trace_object.c
create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/trigger-objtrace.tc

--
2.25.1



2022-05-14 00:37:41

by Jeff Xie

[permalink] [raw]
Subject: [PATCH v10 1/4] trace: Add trace any kernel object

Introduce objtrace trigger to get the call flow by tracing any kernel
object in the function parameter.

The objtrace trigger makes a list of the target object address from
the given event parameter, and records all kernel function calls
which has the object address in its parameter.

Syntax:
objtrace:add:obj[:count][if <filter>]

Usage:
# echo 'p bio_add_page arg1=$arg1' > kprobe_events
# cd events/kprobes/p_bio_add_page_0
# echo 'objtrace:add:arg1:1 if comm == "cat"' > ./trigger
# cat /test.txt

Signed-off-by: Jeff Xie <[email protected]>
---
include/linux/trace_events.h | 1 +
kernel/trace/Kconfig | 10 +
kernel/trace/Makefile | 1 +
kernel/trace/trace.c | 11 +
kernel/trace/trace.h | 21 ++
kernel/trace/trace_entries.h | 17 ++
kernel/trace/trace_events_trigger.c | 5 +-
kernel/trace/trace_object.c | 449 ++++++++++++++++++++++++++++
kernel/trace/trace_output.c | 40 +++
9 files changed, 553 insertions(+), 2 deletions(-)
create mode 100644 kernel/trace/trace_object.c

diff --git a/include/linux/trace_events.h b/include/linux/trace_events.h
index e6e95a9f07a5..f3645166b724 100644
--- a/include/linux/trace_events.h
+++ b/include/linux/trace_events.h
@@ -693,6 +693,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);
diff --git a/kernel/trace/Kconfig b/kernel/trace/Kconfig
index 2c43e327a619..30c34d43dc3f 100644
--- a/kernel/trace/Kconfig
+++ b/kernel/trace/Kconfig
@@ -276,6 +276,16 @@ config FUNCTION_PROFILER

If in doubt, say N.

+config TRACE_OBJECT
+ bool "Trace kernel object in function parameter"
+ depends on FUNCTION_TRACER
+ depends on HAVE_FUNCTION_ARG_ACCESS_API
+ select TRACING
+ default y
+ help
+ You can trace the kernel object in the kernel function parameter.
+ The kernel object is dynamically specified via event trigger.
+
config STACK_TRACER
bool "Trace max stack"
depends on HAVE_FUNCTION_TRACER
diff --git a/kernel/trace/Makefile b/kernel/trace/Makefile
index d77cd8032213..8380e01432b5 100644
--- a/kernel/trace/Makefile
+++ b/kernel/trace/Makefile
@@ -67,6 +67,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
diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 087740f63d92..60d57b0b2be4 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -5627,6 +5627,9 @@ static const char readme_msg[] =
"\t enable_hist:<system>:<event>\n"
"\t disable_hist:<system>:<event>\n"
#endif
+#ifdef CONFIG_TRACE_OBJECT
+ "\t objtrace:add:obj[:count][if <filter>]\n"
+#endif
#ifdef CONFIG_STACKTRACE
"\t\t stacktrace\n"
#endif
@@ -9274,6 +9277,9 @@ static struct trace_array *trace_array_create(const char *name)
if (ftrace_allocate_ftrace_ops(tr) < 0)
goto out_free_tr;

+ if (allocate_objtrace_data(tr) < 0)
+ goto out_free_tr;
+
ftrace_init_trace_array(tr);

init_trace_flags_index(tr);
@@ -9293,6 +9299,7 @@ static struct trace_array *trace_array_create(const char *name)

out_free_tr:
ftrace_free_ftrace_ops(tr);
+ free_objtrace_data(tr);
free_trace_buffers(tr);
free_cpumask_var(tr->tracing_cpumask);
kfree(tr->name);
@@ -9386,6 +9393,7 @@ static int __remove_instance(struct trace_array *tr)
event_trace_del_tracer(tr);
ftrace_clear_pids(tr);
ftrace_destroy_function_files(tr);
+ free_objtrace_data(tr);
tracefs_remove(tr->dir);
free_percpu(tr->last_func_repeats);
free_trace_buffers(tr);
@@ -10120,6 +10128,9 @@ __init static int tracer_alloc_buffers(void)
goto out_free_savedcmd;
}

+ if (allocate_objtrace_data(&global_trace))
+ goto out_free_savedcmd;
+
if (global_trace.buffer_disabled)
tracing_off();

diff --git a/kernel/trace/trace.h b/kernel/trace/trace.h
index ff816fb41e48..18220b659555 100644
--- a/kernel/trace/trace.h
+++ b/kernel/trace/trace.h
@@ -54,6 +54,7 @@ enum trace_type {
TRACE_TIMERLAT,
TRACE_RAW_DATA,
TRACE_FUNC_REPEATS,
+ TRACE_OBJECT,

__TRACE_LAST_TYPE,
};
@@ -363,6 +364,9 @@ struct trace_array {
cpumask_var_t tracing_cpumask; /* only trace on set CPUs */
int ref;
int trace_ref;
+#ifdef CONFIG_TRACE_OBJECT
+ struct objtrace_data *obj_data;
+#endif
#ifdef CONFIG_FUNCTION_TRACER
struct ftrace_ops *ops;
struct trace_pid_list __rcu *function_pids;
@@ -471,6 +475,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)

@@ -1536,6 +1541,16 @@ static inline int register_trigger_hist_cmd(void) { return 0; }
static inline int register_trigger_hist_enable_disable_cmds(void) { return 0; }
#endif

+#ifdef CONFIG_TRACE_OBJECT
+extern int register_trigger_object_cmd(void);
+extern int allocate_objtrace_data(struct trace_array *tr);
+extern void free_objtrace_data(struct trace_array *tr);
+#else
+static inline int register_trigger_object_cmd(void) { return 0; }
+static inline int allocate_objtrace_data(struct trace_array *tr) { return 0; }
+static inline void free_objtrace_data(struct trace_array *tr) { };
+#endif
+
extern int register_trigger_cmds(void);
extern void clear_event_triggers(struct trace_array *tr);

@@ -1611,6 +1626,12 @@ extern bool event_trigger_check_remove(const char *glob);
extern bool event_trigger_empty_param(const char *param);
extern int event_trigger_separate_filter(char *param_and_filter, char **param,
char **filter, bool param_required);
+extern int register_trigger(char *glob,
+ struct event_trigger_data *data,
+ struct trace_event_file *file);
+extern void unregister_trigger(char *glob,
+ struct event_trigger_data *test,
+ struct trace_event_file *file);
extern struct event_trigger_data *
event_trigger_alloc(struct event_command *cmd_ops,
char *cmd,
diff --git a/kernel/trace/trace_entries.h b/kernel/trace/trace_entries.h
index cd41e863b51c..bb120d9498a9 100644
--- a/kernel/trace/trace_entries.h
+++ b/kernel/trace/trace_entries.h
@@ -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)
+);
diff --git a/kernel/trace/trace_events_trigger.c b/kernel/trace/trace_events_trigger.c
index 21592bed2e89..cbb8a692a81f 100644
--- a/kernel/trace/trace_events_trigger.c
+++ b/kernel/trace/trace_events_trigger.c
@@ -560,7 +560,7 @@ void update_cond_flag(struct trace_event_file *file)
*
* Return: 0 on success, errno otherwise
*/
-static int register_trigger(char *glob,
+int register_trigger(char *glob,
struct event_trigger_data *data,
struct trace_event_file *file)
{
@@ -605,7 +605,7 @@ static int register_trigger(char *glob,
* Usually used directly as the @unreg method in event command
* implementations.
*/
-static void unregister_trigger(char *glob,
+void unregister_trigger(char *glob,
struct event_trigger_data *test,
struct trace_event_file *file)
{
@@ -1976,6 +1976,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;
}
diff --git a/kernel/trace/trace_object.c b/kernel/trace/trace_object.c
new file mode 100644
index 000000000000..9f9c42a9b37a
--- /dev/null
+++ b/kernel/trace/trace_object.c
@@ -0,0 +1,449 @@
+// SPDX-License-Identifier: GPL-2.0
+/*
+ * trace the kernel object in the kernel function parameter
+ * Copyright (C) 2021 Jeff Xie <[email protected]>
+ */
+
+#define pr_fmt(fmt) "trace_object: " fmt
+
+#include "trace_output.h"
+
+#define MAX_TRACED_OBJECT 5
+#define OBJTRACE_CMD_LEN 16
+static LIST_HEAD(obj_data_head);
+static const int max_args_num = 6;
+static void exit_trace_object(struct trace_array *tr);
+static int init_trace_object(struct trace_array *tr);
+
+struct object_instance {
+ void *obj;
+ struct trace_array *tr;
+};
+
+/* objtrace private data */
+struct objtrace_trigger_data {
+ struct ftrace_event_field *field;
+ char objtrace_cmd[OBJTRACE_CMD_LEN];
+ struct trace_array *tr;
+};
+
+/* objtrace data with fops and objtrace_instances */
+struct objtrace_data {
+ struct list_head head;
+ struct trace_array *tr;
+ struct ftrace_ops fops;
+ atomic_t num_traced_obj;
+ struct object_instance traced_obj[MAX_TRACED_OBJECT];
+ raw_spinlock_t obj_data_lock;
+};
+
+static struct objtrace_data *get_obj_data(struct trace_array *tr)
+{
+ struct objtrace_data *obj_data = NULL;
+
+ list_for_each_entry(obj_data, &obj_data_head, head) {
+ if (obj_data->tr == tr)
+ break;
+ }
+ return obj_data;
+}
+
+static bool object_exist(void *obj, struct trace_array *tr)
+{
+ int i, max;
+ struct objtrace_data *obj_data;
+
+ obj_data = get_obj_data(tr);
+ if (!obj_data)
+ return false;
+
+ max = atomic_read(&obj_data->num_traced_obj);
+ smp_rmb();
+ for (i = 0; i < max; i++) {
+ if (obj_data->traced_obj[i].obj == obj)
+ return true;
+ }
+ return false;
+}
+
+static bool object_empty(struct trace_array *tr)
+{
+ struct objtrace_data *obj_data;
+
+ obj_data = get_obj_data(tr);
+ if (!obj_data)
+ return false;
+
+ return !atomic_read(&obj_data->num_traced_obj);
+}
+
+static void set_trace_object(void *obj, struct trace_array *tr)
+{
+ unsigned long flags;
+ struct object_instance *obj_ins;
+ struct objtrace_data *obj_data;
+
+ if (in_nmi())
+ return;
+
+ if (!obj && object_exist(obj, tr))
+ return;
+
+ obj_data = get_obj_data(tr);
+ if (!obj_data)
+ return;
+
+ /* only this place has write operations */
+ raw_spin_lock_irqsave(&obj_data->obj_data_lock, flags);
+ if (atomic_read(&obj_data->num_traced_obj) == MAX_TRACED_OBJECT) {
+ trace_array_printk_buf(tr->array_buffer.buffer, _THIS_IP_,
+ "object_pool is full, can't trace object:0x%px\n", obj);
+ goto out;
+ }
+ obj_ins = &obj_data->traced_obj[atomic_read(&obj_data->num_traced_obj)];
+ obj_ins->obj = obj;
+ obj_ins->tr = tr;
+ /* make sure the num_traced_obj update always appears after traced_obj update */
+ smp_wmb();
+ atomic_inc(&obj_data->num_traced_obj);
+out:
+ raw_spin_unlock_irqrestore(&obj_data->obj_data_lock, flags);
+}
+
+static void submit_trace_object(unsigned long ip, unsigned long parent_ip,
+ unsigned long object, struct trace_array *tr)
+{
+
+ struct trace_buffer *buffer = tr->array_buffer.buffer;
+ struct ring_buffer_event *event;
+ struct trace_object_entry *entry;
+ unsigned int trace_ctx = 0;
+
+ trace_ctx = tracing_gen_ctx();
+ event = trace_buffer_lock_reserve(buffer, TRACE_OBJECT,
+ sizeof(*entry), trace_ctx);
+ if (!event)
+ return;
+ entry = ring_buffer_event_data(event);
+ entry->ip = ip;
+ entry->parent_ip = parent_ip;
+ entry->object = object;
+
+ trace_buffer_unlock_commit(tr, buffer, event, trace_ctx);
+}
+
+static void
+trace_object_events_call(unsigned long ip, unsigned long parent_ip,
+ struct ftrace_ops *op, struct ftrace_regs *fregs)
+{
+ struct pt_regs *pt_regs = ftrace_get_regs(fregs);
+ struct trace_array *tr = op->private;
+ struct trace_array_cpu *data;
+ unsigned long obj;
+ long disabled;
+ int cpu, n;
+
+ preempt_disable_notrace();
+
+ cpu = raw_smp_processor_id();
+ data = per_cpu_ptr(tr->array_buffer.data, cpu);
+ disabled = atomic_inc_return(&data->disabled);
+ if (likely(disabled == 1)) {
+ if (object_empty(tr))
+ goto out;
+ for (n = 0; n < max_args_num; n++) {
+ obj = regs_get_kernel_argument(pt_regs, n);
+ if (object_exist((void *)obj, tr))
+ submit_trace_object(ip, parent_ip, obj, tr);
+ /* The parameters of a function may match multiple objects */
+ }
+ }
+out:
+ atomic_dec(&data->disabled);
+ preempt_enable_notrace();
+}
+
+static void
+trace_object_trigger(struct event_trigger_data *data,
+ struct trace_buffer *buffer, void *rec,
+ struct ring_buffer_event *event)
+{
+ struct objtrace_trigger_data *obj_data = data->private_data;
+ struct trace_array *tr = obj_data->tr;
+ struct ftrace_event_field *field;
+ void *obj = NULL;
+
+ field = obj_data->field;
+ memcpy(&obj, rec + field->offset, sizeof(obj));
+ set_trace_object(obj, tr);
+}
+
+static void
+trace_object_trigger_free(struct event_trigger_data *data)
+{
+ struct objtrace_trigger_data *obj_data = data->private_data;
+
+ if (WARN_ON_ONCE(data->ref <= 0))
+ return;
+
+ data->ref--;
+ if (!data->ref) {
+ exit_trace_object(obj_data->tr);
+ kfree(data->private_data);
+ trigger_data_free(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
+event_trigger_print(const char *name, struct seq_file *m,
+ void *data, char *filter_str, void *objtrace_data)
+{
+ long count = (long)data;
+ struct objtrace_trigger_data *obj_data = objtrace_data;
+
+ seq_puts(m, name);
+
+ seq_printf(m, ":%s", obj_data->objtrace_cmd);
+ seq_printf(m, ":%s", obj_data->field->name);
+
+ if (count == -1)
+ seq_puts(m, ":unlimited");
+ else
+ seq_printf(m, ":count=%ld", count);
+
+ if (filter_str)
+ seq_printf(m, " if %s\n", filter_str);
+ else
+ seq_putc(m, '\n');
+
+ return 0;
+}
+
+static int event_object_trigger_init(struct event_trigger_data *data)
+{
+ struct objtrace_trigger_data *obj_data = data->private_data;
+ int ret;
+
+ if (!data->ref) {
+ ret = init_trace_object(obj_data->tr);
+ if (ret)
+ return ret;
+ }
+ data->ref++;
+ return 0;
+}
+
+static int
+trace_object_trigger_print(struct seq_file *m, struct event_trigger_data *data)
+{
+ return event_trigger_print("objtrace", m, (void *)data->count,
+ data->filter_str, data->private_data);
+}
+
+static struct event_trigger_ops objecttrace_trigger_ops = {
+ .trigger = trace_object_trigger,
+ .print = trace_object_trigger_print,
+ .init = event_object_trigger_init,
+ .free = trace_object_trigger_free,
+};
+
+static struct event_trigger_ops objecttrace_count_trigger_ops = {
+ .trigger = trace_object_count_trigger,
+ .print = trace_object_trigger_print,
+ .init = event_object_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 bool field_exist(struct trace_event_file *file,
+ struct event_command *cmd_ops,
+ const char *field_name)
+{
+ struct event_trigger_data *data;
+ struct objtrace_trigger_data *obj_data;
+
+ lockdep_assert_held(&event_mutex);
+
+ list_for_each_entry(data, &file->triggers, list) {
+ if (data->cmd_ops->trigger_type == cmd_ops->trigger_type) {
+ obj_data = data->private_data;
+ if (!strcmp(obj_data->field->name, field_name))
+ return true;
+ }
+ }
+
+ return false;
+}
+
+static int
+event_object_trigger_parse(struct event_command *cmd_ops,
+ struct trace_event_file *file,
+ char *glob, char *cmd, char *param_and_filter)
+{
+ struct event_trigger_data *trigger_data;
+ struct objtrace_trigger_data *obj_data;
+ struct ftrace_event_field *field;
+ char *objtrace_cmd, *arg;
+ char *param, *filter;
+ int ret;
+ bool remove;
+
+ remove = event_trigger_check_remove(glob);
+
+ /*
+ * separate the param and the filter:
+ * objtrace:add:OBJ[:COUNT] [if filter]
+ */
+ ret = event_trigger_separate_filter(param_and_filter, &param, &filter, true);
+ if (ret)
+ return ret;
+
+ objtrace_cmd = strsep(&param, ":");
+ if (!objtrace_cmd || strcmp(objtrace_cmd, "add")) {
+ pr_err("error objtrace command\n");
+ return -EINVAL;
+ }
+
+ arg = strsep(&param, ":");
+ if (!arg)
+ return -EINVAL;
+
+ field = trace_find_event_field(file->event_call, arg);
+ if (!field)
+ return -EINVAL;
+
+ if (field->size != sizeof(void *)) {
+ pr_err("the size of the %s should be:%ld\n", field->name, sizeof(void *));
+ return -EINVAL;
+ }
+
+ if (remove && !field_exist(file, cmd_ops, field->name))
+ return -EINVAL;
+
+ obj_data = kzalloc(sizeof(*obj_data), GFP_KERNEL);
+ if (!obj_data)
+ return -ENOMEM;
+
+ obj_data->field = field;
+ obj_data->tr = file->tr;
+ snprintf(obj_data->objtrace_cmd, OBJTRACE_CMD_LEN, objtrace_cmd);
+
+ trigger_data = event_trigger_alloc(cmd_ops, cmd, param, obj_data);
+ if (!trigger_data) {
+ kfree(obj_data);
+ return -ENOMEM;
+ }
+ if (remove) {
+ event_trigger_unregister(cmd_ops, file, glob+1, trigger_data);
+ kfree(obj_data);
+ kfree(trigger_data);
+ return 0;
+ }
+
+ ret = event_trigger_parse_num(param, trigger_data);
+ if (ret)
+ goto out_free;
+
+ ret = event_trigger_set_filter(cmd_ops, file, filter, trigger_data);
+ if (ret < 0)
+ goto out_free;
+
+ ret = event_trigger_register(cmd_ops, file, glob, trigger_data);
+ if (ret)
+ goto out_free;
+
+ return ret;
+
+ out_free:
+ event_trigger_reset_filter(cmd_ops, trigger_data);
+ kfree(obj_data);
+ kfree(trigger_data);
+ return ret;
+}
+
+static struct event_command trigger_object_cmd = {
+ .name = "objtrace",
+ .trigger_type = ETT_TRACE_OBJECT,
+ .flags = EVENT_CMD_FL_NEEDS_REC,
+ .parse = event_object_trigger_parse,
+ .reg = register_trigger,
+ .unreg = unregister_trigger,
+ .get_trigger_ops = objecttrace_get_trigger_ops,
+ .set_filter = set_trigger_filter,
+};
+
+__init int register_trigger_object_cmd(void)
+{
+ int ret;
+
+ ret = register_event_command(&trigger_object_cmd);
+ WARN_ON(ret < 0);
+
+ return ret;
+}
+
+int allocate_objtrace_data(struct trace_array *tr)
+{
+ struct objtrace_data *obj_data;
+ struct ftrace_ops *fops;
+
+ obj_data = kzalloc(sizeof(*obj_data), GFP_KERNEL);
+ if (!obj_data)
+ return -ENOMEM;
+
+ tr->obj_data = obj_data;
+ obj_data->tr = tr;
+ fops = &obj_data->fops;
+ fops->func = trace_object_events_call;
+ fops->flags = FTRACE_OPS_FL_SAVE_REGS;
+ fops->private = tr;
+
+ raw_spin_lock(&obj_data->obj_data_lock);
+ list_add(&obj_data->head, &obj_data_head);
+ raw_spin_unlock(&obj_data->obj_data_lock);
+ return 0;
+}
+
+static int init_trace_object(struct trace_array *tr)
+{
+ int ret;
+
+ ret = register_ftrace_function(&tr->obj_data->fops);
+ WARN_ON(ret < 0);
+
+ return ret;
+}
+
+void free_objtrace_data(struct trace_array *tr)
+{
+ kfree(tr->obj_data);
+ tr->obj_data = NULL;
+}
+
+static void exit_trace_object(struct trace_array *tr)
+{
+ struct objtrace_data *obj_data = tr->obj_data;
+
+ atomic_set(&obj_data->num_traced_obj, 0);
+ WARN_ONCE(unregister_ftrace_function(&obj_data->fops),
+ "can't unregister ftrace for trace object\n");
+}
diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index 67f47ea27921..34ff7b4dc521 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -1551,6 +1551,45 @@ static struct trace_event trace_func_repeats_event = {
.funcs = &trace_func_repeats_funcs,
};

+/* TRACE_OBJECT */
+static enum print_line_t trace_object_print(struct trace_iterator *iter, int flags,
+ struct trace_event *event)
+{
+ struct trace_object_entry *field;
+ struct trace_seq *s = &iter->seq;
+
+ trace_assign_type(field, iter->ent);
+ print_fn_trace(s, field->ip, field->parent_ip, flags);
+ trace_seq_printf(s, " object:0x%lx", field->object);
+ trace_seq_putc(s, '\n');
+
+ return trace_handle_return(s);
+}
+
+static enum print_line_t trace_object_raw(struct trace_iterator *iter, int flags,
+ struct trace_event *event)
+{
+ struct trace_object_entry *field;
+
+ trace_assign_type(field, iter->ent);
+
+ trace_seq_printf(&iter->seq, "%lx %lx\n",
+ field->ip,
+ field->parent_ip);
+
+ return trace_handle_return(&iter->seq);
+}
+
+static struct trace_event_functions trace_object_funcs = {
+ .trace = trace_object_print,
+ .raw = trace_object_raw,
+};
+
+static struct trace_event trace_object_event = {
+ .type = TRACE_OBJECT,
+ .funcs = &trace_object_funcs,
+};
+
static struct trace_event *events[] __initdata = {
&trace_fn_event,
&trace_ctx_event,
@@ -1565,6 +1604,7 @@ static struct trace_event *events[] __initdata = {
&trace_timerlat_event,
&trace_raw_data_event,
&trace_func_repeats_event,
+ &trace_object_event,
NULL
};

--
2.25.1


2022-05-14 01:17:14

by Jeff Xie

[permalink] [raw]
Subject: [PATCH v10 4/4] trace/objtrace: Add documentation for objtrace

Added documentation explaining how to use objtrace trigger to get the value
of the object.

Signed-off-by: Jeff Xie <[email protected]>
---
Documentation/trace/events.rst | 83 ++++++++++++++++++++++++++++++++++
1 file changed, 83 insertions(+)

diff --git a/Documentation/trace/events.rst b/Documentation/trace/events.rst
index c47f381d0c00..0dc475160133 100644
--- a/Documentation/trace/events.rst
+++ b/Documentation/trace/events.rst
@@ -546,6 +546,89 @@ The following commands are supported:

See Documentation/trace/histogram.rst for details and examples.

+- objtrace
+
+ This command provides a way to get the value of any object, The object
+ can be obtained from the dynamic event(kprobe_event/uprobe_event) or the
+ static event(tracepoint).
+
+ Usage:
+ When using the kprobe event, only need to set the objtrace(a new trigger),
+ we can get the value of the object. The object is from the setting of the
+ kprobe event.
+
+ For example:
+ For the function bio_add_page():
+
+ int bio_add_page(struct bio *bio, struct page *page,
+ unsigned int len, unsigned int offset)
+
+ Firstly, we can set the base of the object, thus the first string "arg1"
+ stands for the value of the first parameter of this function bio_add_gage(),
+
+ # echo 'p bio_add_page arg1=$arg1' > ./kprobe_events
+
+ Secondly, we can get the value dynamically based on above object.
+
+ find the offset of the bi_size in struct bio:
+ $ gdb vmlinux
+ (gdb) p &(((struct bio *)0)->bi_iter.bi_size)
+ $1 = (unsigned int *) 0x28
+
+ # echo 'objtrace:add:arg1,0x28:u32:1 if comm == "cat"' > ./events/kprobes/ \
+ p_bio_add_page_0/trigger
+
+ # cd /sys/kernel/debug/tracing/
+ # echo 'p bio_add_page arg1=$arg1' > ./kprobe_events
+ # echo 'objtrace:add:arg1,0x28:u32:1 if comm == "cat"' > ./events/kprobes/p_bio_add_page_0/trigger
+
+ # du -sh /test.txt
+ 12.0K /test.txt
+
+ # cat /test.txt > /dev/null
+ # cat ./trace
+ # tracer: nop
+ #
+ # entries-in-buffer/entries-written: 128/128 #P:4
+ #
+ # _-----=> irqs-off/BH-disabled
+ # / _----=> need-resched
+ # | / _---=> hardirq/softirq
+ # || / _--=> preempt-depth
+ # ||| / _-=> migrate-disable
+ # |||| / delay
+ # TASK-PID CPU# ||||| TIMESTAMP FUNCTION
+ # | | | ||||| | |
+ cat-117 [002] ...1. 1.602243: __bio_try_merge_page <-bio_add_page object:0xffff88811bee4000 value:0x0
+ cat-117 [002] ...1. 1.602244: __bio_add_page <-bio_add_page object:0xffff88811bee4000 value:0x0
+ cat-117 [002] ...2. 1.602244: bio_add_page <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x1000
+ cat-117 [002] ...1. 1.602245: __bio_try_merge_page <-bio_add_page object:0xffff88811bee4000 value:0x1000
+ cat-117 [002] ...1. 1.602245: __bio_add_page <-bio_add_page object:0xffff88811bee4000 value:0x1000
+ cat-117 [002] ...2. 1.602245: bio_add_page <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x2000
+ cat-117 [002] ...1. 1.602245: __bio_try_merge_page <-bio_add_page object:0xffff88811bee4000 value:0x2000
+ cat-117 [002] ...1. 1.602245: __bio_add_page <-bio_add_page object:0xffff88811bee4000 value:0x2000
+ cat-117 [002] ...1. 1.602245: submit_bio <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x3000
+ cat-117 [002] ...1. 1.602245: submit_bio_noacct <-ext4_mpage_readpages object:0xffff88811bee4000 value:0x3000
+ cat-117 [002] ...1. 1.602246: __submit_bio <-submit_bio_noacct object:0xffff88811bee4000 value:0x3000
+ cat-117 [002] ...1. 1.602246: submit_bio_checks <-__submit_bio object:0xffff88811bee4000 value:0x3000
+ cat-117 [002] ...1. 1.602246: __cond_resched <-submit_bio_checks object:0xffff88811bee4000 value:0x3000
+ cat-117 [002] ...1. 1.602246: should_fail_bio <-submit_bio_checks object:0xffff88811bee4000 value:0x3000
+ cat-117 [002] ...1. 1.602246: blk_mq_submit_bio <-submit_bio_noacct object:0xffff88811bee4000 value:0x3000
+ cat-117 [002] ...1. 1.602246: blk_attempt_plug_merge <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
+ cat-117 [002] ...1. 1.602246: blk_mq_sched_bio_merge <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
+ cat-117 [002] ...1. 1.602247: __rcu_read_lock <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
+ cat-117 [002] ...1. 1.602247: __rcu_read_unlock <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
+ cat-117 [002] ...1. 1.602247: __blk_mq_alloc_requests <-blk_mq_submit_bio object:0xffff88811bee4000 value:0x3000
+ <idle>-0 [002] d..3. 1.602298: bio_endio <-blk_update_request object:0xffff88811bee4000 value:0x0
+ <idle>-0 [002] d..3. 1.602298: mpage_end_io <-blk_update_request object:0xffff88811bee4000 value:0x0
+ <idle>-0 [002] d..3. 1.602298: __read_end_io <-blk_update_request object:0xffff88811bee4000 value:0x0
+ <idle>-0 [002] d..3. 1.602300: bio_put <-blk_update_request object:0xffff88811bee4000 value:0x0
+ <idle>-0 [002] d..3. 1.602300: bio_free <-blk_update_request object:0xffff88811bee4000 value:0x0
+ <idle>-0 [002] d..3. 1.602300: mempool_free <-blk_update_request object:0xffff88811bee4000 value:0x0
+ <idle>-0 [002] d..3. 1.602300: mempool_free_slab <-blk_update_request object:0xffff88811bee4000 value:0x0
+ <idle>-0 [002] d..3. 1.602300: kmem_cache_free <-blk_update_request object:0xffff88811bee4000 value:0x0
+ ...
+
7. In-kernel trace event API
============================

--
2.25.1


2022-05-14 02:11:44

by Jeff Xie

[permalink] [raw]
Subject: [PATCH v10 3/4] trace/objtrace: Add testcases for objtrace

Add a series of testcases to illustrate correct and incorrect usage of
objtrace trigger.

Signed-off-by: Jeff Xie <[email protected]>
---
.../ftrace/test.d/trigger/trigger-objtrace.tc | 41 +++++++++++++++++++
1 file changed, 41 insertions(+)
create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/trigger-objtrace.tc

diff --git a/tools/testing/selftests/ftrace/test.d/trigger/trigger-objtrace.tc b/tools/testing/selftests/ftrace/test.d/trigger/trigger-objtrace.tc
new file mode 100644
index 000000000000..d894442b6a30
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/trigger/trigger-objtrace.tc
@@ -0,0 +1,41 @@
+#!/bin/sh
+# SPDX-License-Identifier: GPL-2.0
+# description: event trigger - test objtrace-trigger
+# requires: kprobe_events "objtrace":README
+
+fail() { #msg
+ echo $1
+ exit_fail
+}
+
+echo 'p bio_add_page arg1=$arg1 arg2=$arg2' > kprobe_events
+
+FEATURE=`grep objtrace events/kprobes/p_bio_add_page_0/trigger`
+if [ -z "$FEATURE" ]; then
+ echo "objtrace trigger is not supported"
+ exit_unsupported
+fi
+
+echo "Test objtrace trigger"
+echo 'objtrace:add:arg1,0x28:u32:1 if comm == "cat"' > \
+ events/kprobes/p_bio_add_page_0/trigger
+if [ -z $? ]; then
+ fail "objtrace trigger syntax error"
+fi
+
+echo "Test objtrace semantic errors"
+
+# Being lack of objtrace command
+! echo 'objtrace:arg1,0x28:u32:1' > events/kprobes/p_bio_add_page_0/trigger
+# Bad parameter name
+! echo 'objtrace:add:argx:u32:1' > events/kprobes/p_bio_add_page_0/trigger
+# The parameter existed on event
+! echo 'objtrace:add:arg2:u32:1' > events/kprobes/p_bio_add_page_0/trigger
+
+echo "reset objtrace trigger"
+
+echo '!objtrace:add:arg1,0x28:u32' > \
+ events/kprobes/p_bio_add_page_0/trigger
+echo '-:p_bio_add_page_0' >> ./kprobe_events
+
+exit 0
--
2.25.1


2022-05-14 02:49:03

by Jeff Xie

[permalink] [raw]
Subject: [PATCH v10 2/4] trace/objtrace: Get the value of the object

Using objtrace trigger to get the value of the object which from the kernel
function parameter.

Syntax:
objtrace:add:obj[,offset][:type][:count][if <filter>]

Usage:
# echo 'p bio_add_page arg1=$arg1' > ./kprobe_events
# gdb vmlinux
(gdb) p &(((struct bio *)0)->bi_iter.bi_size)
$1 = (unsigned int *) 0x28
# echo 'objtrace:add:arg1,0x28:u32:1 if comm == "cat"' > ./events/kprobes/ \
p_bio_add_page_0/trigger
# cat /test.txt

Signed-off-by: Jeff Xie <[email protected]>
---
kernel/trace/trace.c | 2 +-
kernel/trace/trace_entries.h | 5 +-
kernel/trace/trace_object.c | 188 ++++++++++++++++++++++++++++++++---
kernel/trace/trace_output.c | 6 +-
4 files changed, 182 insertions(+), 19 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 60d57b0b2be4..7a5c0ac03942 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -5628,7 +5628,7 @@ static const char readme_msg[] =
"\t disable_hist:<system>:<event>\n"
#endif
#ifdef CONFIG_TRACE_OBJECT
- "\t objtrace:add:obj[:count][if <filter>]\n"
+ "\t objtrace:add:obj[,offset][:type][:count][if <filter>]\n"
#endif
#ifdef CONFIG_STACKTRACE
"\t\t stacktrace\n"
diff --git a/kernel/trace/trace_entries.h b/kernel/trace/trace_entries.h
index bb120d9498a9..2407c45a568c 100644
--- a/kernel/trace/trace_entries.h
+++ b/kernel/trace/trace_entries.h
@@ -413,8 +413,9 @@ FTRACE_ENTRY(object, trace_object_entry,
__field( unsigned long, ip )
__field( unsigned long, parent_ip )
__field( unsigned long, object )
+ __field( unsigned long, value )
),

- F_printk(" %ps <-- %ps object:%lx\n",
- (void *)__entry->ip, (void *)__entry->parent_ip, __entry->object)
+ F_printk(" %ps <-- %ps object:%lx value:%lx\n", (void *)__entry->ip,
+ (void *)__entry->parent_ip, __entry->object, __entry->value)
);
diff --git a/kernel/trace/trace_object.c b/kernel/trace/trace_object.c
index 9f9c42a9b37a..6e1bd496f67f 100644
--- a/kernel/trace/trace_object.c
+++ b/kernel/trace/trace_object.c
@@ -15,8 +15,14 @@ static const int max_args_num = 6;
static void exit_trace_object(struct trace_array *tr);
static int init_trace_object(struct trace_array *tr);

+/*
+ * get the offset from the special object and
+ * the type size of the value
+ */
struct object_instance {
void *obj;
+ int obj_offset;
+ int obj_value_type_size;
struct trace_array *tr;
};

@@ -24,9 +30,23 @@ struct object_instance {
struct objtrace_trigger_data {
struct ftrace_event_field *field;
char objtrace_cmd[OBJTRACE_CMD_LEN];
+ int obj_offset;
+ int obj_value_type_size;
struct trace_array *tr;
};

+/* get the type size for the special object */
+struct objtrace_fetch_type {
+ char *name;
+ int type_size;
+};
+
+enum objattr {
+ OBJ_OFFSET,
+ OBJ_VAL_TYPE_SIZE,
+ MAX_OBJ_ATTR
+};
+
/* objtrace data with fops and objtrace_instances */
struct objtrace_data {
struct list_head head;
@@ -66,6 +86,35 @@ static bool object_exist(void *obj, struct trace_array *tr)
return false;
}

+static int get_object_attr(void *obj, int objattr,
+ struct trace_array *tr, int *result)
+{
+ int i, max;
+ struct objtrace_data *obj_data;
+
+ obj_data = get_obj_data(tr);
+ if (!obj_data)
+ return -EINVAL;
+
+ max = atomic_read(&obj_data->num_traced_obj);
+ smp_rmb();
+ for (i = 0; i < max; i++) {
+ if (obj_data->traced_obj[i].obj == obj) {
+ switch (objattr) {
+ case OBJ_OFFSET:
+ *result = obj_data->traced_obj[i].obj_offset;
+ return 0;
+ case OBJ_VAL_TYPE_SIZE:
+ *result = obj_data->traced_obj[i].obj_value_type_size;
+ return 0;
+ default:
+ return -EINVAL;
+ }
+ }
+ }
+ return -EINVAL;
+}
+
static bool object_empty(struct trace_array *tr)
{
struct objtrace_data *obj_data;
@@ -77,7 +126,8 @@ static bool object_empty(struct trace_array *tr)
return !atomic_read(&obj_data->num_traced_obj);
}

-static void set_trace_object(void *obj, struct trace_array *tr)
+static void set_trace_object(void *obj, int obj_offset,
+ int obj_value_type_size, struct trace_array *tr)
{
unsigned long flags;
struct object_instance *obj_ins;
@@ -102,6 +152,8 @@ static void set_trace_object(void *obj, struct trace_array *tr)
}
obj_ins = &obj_data->traced_obj[atomic_read(&obj_data->num_traced_obj)];
obj_ins->obj = obj;
+ obj_ins->obj_value_type_size = obj_value_type_size;
+ obj_ins->obj_offset = obj_offset;
obj_ins->tr = tr;
/* make sure the num_traced_obj update always appears after traced_obj update */
smp_wmb();
@@ -111,7 +163,7 @@ static void set_trace_object(void *obj, struct trace_array *tr)
}

static void submit_trace_object(unsigned long ip, unsigned long parent_ip,
- unsigned long object, struct trace_array *tr)
+ unsigned long object, unsigned long value, struct trace_array *tr)
{

struct trace_buffer *buffer = tr->array_buffer.buffer;
@@ -128,10 +180,43 @@ static void submit_trace_object(unsigned long ip, unsigned long parent_ip,
entry->ip = ip;
entry->parent_ip = parent_ip;
entry->object = object;
+ entry->value = value;

trace_buffer_unlock_commit(tr, buffer, event, trace_ctx);
}

+static inline long get_object_value(unsigned long *val, void *obj, int type_size)
+{
+ char tmp[sizeof(u64)];
+ long ret = 0;
+
+ ret = copy_from_kernel_nofault(tmp, obj, sizeof(tmp));
+ if (ret)
+ return ret;
+ switch (type_size) {
+ case 1: {
+ *val = (unsigned long)*(u8 *)tmp;
+ break;
+ }
+ case 2: {
+ *val = (unsigned long)*(u16 *)tmp;
+ break;
+ }
+ case 4: {
+ *val = (unsigned long)*(u32 *)tmp;
+ break;
+ }
+ case 8: {
+ *val = (unsigned long)*(u64 *)tmp;
+ break;
+ }
+ default:
+ return -EINVAL;
+ }
+
+ return 0;
+}
+
static void
trace_object_events_call(unsigned long ip, unsigned long parent_ip,
struct ftrace_ops *op, struct ftrace_regs *fregs)
@@ -139,7 +224,8 @@ trace_object_events_call(unsigned long ip, unsigned long parent_ip,
struct pt_regs *pt_regs = ftrace_get_regs(fregs);
struct trace_array *tr = op->private;
struct trace_array_cpu *data;
- unsigned long obj;
+ int ret, val_type_size, obj_offset;
+ unsigned long obj, val;
long disabled;
int cpu, n;

@@ -153,8 +239,18 @@ trace_object_events_call(unsigned long ip, unsigned long parent_ip,
goto out;
for (n = 0; n < max_args_num; n++) {
obj = regs_get_kernel_argument(pt_regs, n);
- if (object_exist((void *)obj, tr))
- submit_trace_object(ip, parent_ip, obj, tr);
+ if (object_exist((void *)obj, tr)) {
+ ret = get_object_attr((void *)obj, OBJ_OFFSET, tr, &obj_offset);
+ if (unlikely(ret) < 0)
+ goto out;
+ ret = get_object_attr((void *)obj, OBJ_VAL_TYPE_SIZE, tr, &val_type_size);
+ if (unlikely(ret) < 0)
+ goto out;
+ if (get_object_value(&val, (void *)(obj + obj_offset), val_type_size))
+ continue;
+
+ submit_trace_object(ip, parent_ip, obj, val, tr);
+ }
/* The parameters of a function may match multiple objects */
}
}
@@ -175,9 +271,27 @@ trace_object_trigger(struct event_trigger_data *data,

field = obj_data->field;
memcpy(&obj, rec + field->offset, sizeof(obj));
- set_trace_object(obj, tr);
+ /* set the offset from the special object and the type size of the value*/
+ set_trace_object(obj, obj_data->obj_offset,
+ obj_data->obj_value_type_size, tr);
}

+static const struct objtrace_fetch_type objtrace_fetch_types[] = {
+ {"u8", 1},
+ {"s8", 1},
+ {"x8", 1},
+ {"u16", 2},
+ {"s16", 2},
+ {"x16", 2},
+ {"u32", 4},
+ {"s32", 4},
+ {"x32", 4},
+ {"u64", 8},
+ {"s64", 8},
+ {"x64", 8},
+ {}
+};
+
static void
trace_object_trigger_free(struct event_trigger_data *data)
{
@@ -212,14 +326,25 @@ static int
event_trigger_print(const char *name, struct seq_file *m,
void *data, char *filter_str, void *objtrace_data)
{
+ int i;
long count = (long)data;
struct objtrace_trigger_data *obj_data = objtrace_data;
+ const char *value_type_name;

seq_puts(m, name);

seq_printf(m, ":%s", obj_data->objtrace_cmd);
seq_printf(m, ":%s", obj_data->field->name);
+ if (obj_data->obj_offset)
+ seq_printf(m, ",0x%x", obj_data->obj_offset);

+ for (i = 0; objtrace_fetch_types[i].name; i++) {
+ if (objtrace_fetch_types[i].type_size == obj_data->obj_value_type_size) {
+ value_type_name = objtrace_fetch_types[i].name;
+ break;
+ }
+ }
+ seq_printf(m, ":%s", value_type_name);
if (count == -1)
seq_puts(m, ":unlimited");
else
@@ -302,16 +427,18 @@ event_object_trigger_parse(struct event_command *cmd_ops,
struct event_trigger_data *trigger_data;
struct objtrace_trigger_data *obj_data;
struct ftrace_event_field *field;
- char *objtrace_cmd, *arg;
- char *param, *filter;
- int ret;
+ char *objtrace_cmd, *obj;
+ char *param, *filter, *str, *type;
+ int ret, i, def_type_size, obj_value_type_size = 0;
+ char *tmp_saved_param;
+ long offset = 0;
bool remove;

remove = event_trigger_check_remove(glob);

/*
* separate the param and the filter:
- * objtrace:add:OBJ[:COUNT] [if filter]
+ * objtrace:add:OBJ[,OFFS][:TYPE][:COUNT] [if filter]
*/
ret = event_trigger_separate_filter(param_and_filter, &param, &filter, true);
if (ret)
@@ -323,11 +450,44 @@ event_object_trigger_parse(struct event_command *cmd_ops,
return -EINVAL;
}

- arg = strsep(&param, ":");
- if (!arg)
+ obj = strsep(&param, ":");
+ if (!obj)
return -EINVAL;

- field = trace_find_event_field(file->event_call, arg);
+ str = strchr(obj, ',');
+ if (!str)
+ offset = 0;
+ else {
+ *str++ = '\0';
+ ret = kstrtol(str, 0, &offset);
+ if (ret)
+ return -EINVAL;
+ }
+ def_type_size = sizeof(void *);
+ if (!param) {
+ obj_value_type_size = def_type_size;
+ goto skip_get_type;
+ }
+ tmp_saved_param = param;
+ type = strsep(&param, ":");
+ if (!type)
+ obj_value_type_size = def_type_size;
+ /* if this is the trigger count */
+ else if (isdigit(type[0])) {
+ obj_value_type_size = def_type_size;
+ param = tmp_saved_param;
+ } else {
+ for (i = 0; objtrace_fetch_types[i].name; i++) {
+ if (strcmp(objtrace_fetch_types[i].name, type) == 0) {
+ obj_value_type_size = objtrace_fetch_types[i].type_size;
+ break;
+ }
+ }
+ }
+ if (!obj_value_type_size)
+ return -EINVAL;
+skip_get_type:
+ field = trace_find_event_field(file->event_call, obj);
if (!field)
return -EINVAL;

@@ -344,6 +504,8 @@ event_object_trigger_parse(struct event_command *cmd_ops,
return -ENOMEM;

obj_data->field = field;
+ obj_data->obj_offset = offset;
+ obj_data->obj_value_type_size = obj_value_type_size;
obj_data->tr = file->tr;
snprintf(obj_data->objtrace_cmd, OBJTRACE_CMD_LEN, objtrace_cmd);

diff --git a/kernel/trace/trace_output.c b/kernel/trace/trace_output.c
index 34ff7b4dc521..a45871b52dcc 100644
--- a/kernel/trace/trace_output.c
+++ b/kernel/trace/trace_output.c
@@ -1561,6 +1561,7 @@ static enum print_line_t trace_object_print(struct trace_iterator *iter, int fla
trace_assign_type(field, iter->ent);
print_fn_trace(s, field->ip, field->parent_ip, flags);
trace_seq_printf(s, " object:0x%lx", field->object);
+ trace_seq_printf(s, " value:0x%lx", field->value);
trace_seq_putc(s, '\n');

return trace_handle_return(s);
@@ -1573,9 +1574,8 @@ static enum print_line_t trace_object_raw(struct trace_iterator *iter, int flags

trace_assign_type(field, iter->ent);

- trace_seq_printf(&iter->seq, "%lx %lx\n",
- field->ip,
- field->parent_ip);
+ trace_seq_printf(&iter->seq, "%lx %lx %lx %lx\n", field->ip,
+ field->parent_ip, field->object, field->value);

return trace_handle_return(&iter->seq);
}
--
2.25.1


2022-05-14 04:11:11

by kernel test robot

[permalink] [raw]
Subject: Re: [PATCH v10 1/4] trace: Add trace any kernel object

Hi Jeff,

Thank you for the patch! Perhaps something to improve:

[auto build test WARNING on rostedt-trace/for-next]
[also build test WARNING on v5.18-rc6 next-20220512]
[If your patch is applied to the wrong git tree, kindly drop us a note.
And when submitting patch, we suggest to use '--base' as documented in
https://git-scm.com/docs/git-format-patch]

url: https://github.com/intel-lab-lkp/linux/commits/Jeff-Xie/trace-Introduce-objtrace-trigger-to-trace-the-kernel-object/20220513-010820
base: https://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git for-next
config: i386-randconfig-c001 (https://download.01.org/0day-ci/archive/20220513/[email protected]/config)
compiler: clang version 15.0.0 (https://github.com/llvm/llvm-project 9519dacab7b8afd537811fc2abaceb4d14f4e16a)
reproduce (this is a W=1 build):
wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross
chmod +x ~/bin/make.cross
# https://github.com/intel-lab-lkp/linux/commit/3c91aa291a0fe8b28b02a14827b0c4ca3ebda601
git remote add linux-review https://github.com/intel-lab-lkp/linux
git fetch --no-tags linux-review Jeff-Xie/trace-Introduce-objtrace-trigger-to-trace-the-kernel-object/20220513-010820
git checkout 3c91aa291a0fe8b28b02a14827b0c4ca3ebda601
# save the config file
mkdir build_dir && cp config build_dir/.config
COMPILER_INSTALL_PATH=$HOME/0day COMPILER=clang make.cross W=1 O=build_dir ARCH=i386 SHELL=/bin/bash kernel/trace/

If you fix the issue, kindly add following tag as appropriate
Reported-by: kernel test robot <[email protected]>

All warnings (new ones prefixed by >>):

kernel/trace/trace_object.c:259:13: error: incompatible function pointer types initializing 'int (*)(struct seq_file *, struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct seq_file *, struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
.print = trace_object_trigger_print,
^~~~~~~~~~~~~~~~~~~~~~~~~~
kernel/trace/trace_object.c:260:12: error: incompatible function pointer types initializing 'int (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
.init = event_object_trigger_init,
^~~~~~~~~~~~~~~~~~~~~~~~~
kernel/trace/trace_object.c:261:12: error: incompatible function pointer types initializing 'void (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'void (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
.free = trace_object_trigger_free,
^~~~~~~~~~~~~~~~~~~~~~~~~
kernel/trace/trace_object.c:266:13: error: incompatible function pointer types initializing 'int (*)(struct seq_file *, struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct seq_file *, struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
.print = trace_object_trigger_print,
^~~~~~~~~~~~~~~~~~~~~~~~~~
kernel/trace/trace_object.c:267:12: error: incompatible function pointer types initializing 'int (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
.init = event_object_trigger_init,
^~~~~~~~~~~~~~~~~~~~~~~~~
kernel/trace/trace_object.c:268:12: error: incompatible function pointer types initializing 'void (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'void (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
.free = trace_object_trigger_free,
^~~~~~~~~~~~~~~~~~~~~~~~~
>> kernel/trace/trace_object.c:335:61: warning: format specifies type 'long' but the argument has type 'unsigned int' [-Wformat]
pr_err("the size of the %s should be:%ld\n", field->name, sizeof(void *));
~~~ ^~~~~~~~~~~~~~
%u
include/linux/printk.h:489:33: note: expanded from macro 'pr_err'
printk(KERN_ERR pr_fmt(fmt), ##__VA_ARGS__)
~~~ ^~~~~~~~~~~
include/linux/printk.h:446:60: note: expanded from macro 'printk'
#define printk(fmt, ...) printk_index_wrap(_printk, fmt, ##__VA_ARGS__)
~~~ ^~~~~~~~~~~
include/linux/printk.h:418:19: note: expanded from macro 'printk_index_wrap'
_p_func(_fmt, ##__VA_ARGS__); \
~~~~ ^~~~~~~~~~~
kernel/trace/trace_object.c:356:3: error: implicit declaration of function 'event_trigger_unregister' [-Werror,-Wimplicit-function-declaration]
event_trigger_unregister(cmd_ops, file, glob+1, trigger_data);
^
kernel/trace/trace_object.c:356:3: note: did you mean 'event_trigger_register'?
kernel/trace/trace.h:1650:12: note: 'event_trigger_register' declared here
extern int event_trigger_register(struct event_command *cmd_ops,
^
kernel/trace/trace_object.c:370:64: error: too few arguments to function call, expected 7, have 4
ret = event_trigger_register(cmd_ops, file, glob, trigger_data);
~~~~~~~~~~~~~~~~~~~~~~ ^
kernel/trace/trace.h:1650:12: note: 'event_trigger_register' declared here
extern int event_trigger_register(struct event_command *cmd_ops,
^
1 warning and 8 errors generated.


vim +335 kernel/trace/trace_object.c

296
297 static int
298 event_object_trigger_parse(struct event_command *cmd_ops,
299 struct trace_event_file *file,
300 char *glob, char *cmd, char *param_and_filter)
301 {
302 struct event_trigger_data *trigger_data;
303 struct objtrace_trigger_data *obj_data;
304 struct ftrace_event_field *field;
305 char *objtrace_cmd, *arg;
306 char *param, *filter;
307 int ret;
308 bool remove;
309
310 remove = event_trigger_check_remove(glob);
311
312 /*
313 * separate the param and the filter:
314 * objtrace:add:OBJ[:COUNT] [if filter]
315 */
316 ret = event_trigger_separate_filter(param_and_filter, &param, &filter, true);
317 if (ret)
318 return ret;
319
320 objtrace_cmd = strsep(&param, ":");
321 if (!objtrace_cmd || strcmp(objtrace_cmd, "add")) {
322 pr_err("error objtrace command\n");
323 return -EINVAL;
324 }
325
326 arg = strsep(&param, ":");
327 if (!arg)
328 return -EINVAL;
329
330 field = trace_find_event_field(file->event_call, arg);
331 if (!field)
332 return -EINVAL;
333
334 if (field->size != sizeof(void *)) {
> 335 pr_err("the size of the %s should be:%ld\n", field->name, sizeof(void *));
336 return -EINVAL;
337 }
338
339 if (remove && !field_exist(file, cmd_ops, field->name))
340 return -EINVAL;
341
342 obj_data = kzalloc(sizeof(*obj_data), GFP_KERNEL);
343 if (!obj_data)
344 return -ENOMEM;
345
346 obj_data->field = field;
347 obj_data->tr = file->tr;
348 snprintf(obj_data->objtrace_cmd, OBJTRACE_CMD_LEN, objtrace_cmd);
349
350 trigger_data = event_trigger_alloc(cmd_ops, cmd, param, obj_data);
351 if (!trigger_data) {
352 kfree(obj_data);
353 return -ENOMEM;
354 }
355 if (remove) {
356 event_trigger_unregister(cmd_ops, file, glob+1, trigger_data);
357 kfree(obj_data);
358 kfree(trigger_data);
359 return 0;
360 }
361
362 ret = event_trigger_parse_num(param, trigger_data);
363 if (ret)
364 goto out_free;
365
366 ret = event_trigger_set_filter(cmd_ops, file, filter, trigger_data);
367 if (ret < 0)
368 goto out_free;
369
370 ret = event_trigger_register(cmd_ops, file, glob, trigger_data);
371 if (ret)
372 goto out_free;
373
374 return ret;
375
376 out_free:
377 event_trigger_reset_filter(cmd_ops, trigger_data);
378 kfree(obj_data);
379 kfree(trigger_data);
380 return ret;
381 }
382

--
0-DAY CI Kernel Test Service
https://01.org/lkp

2022-05-18 13:50:09

by Masami Hiramatsu

[permalink] [raw]
Subject: Re: [PATCH v10 1/4] trace: Add trace any kernel object

Hi Jeff,

Can you fix these errors, since these looks real bugs.

Thank you,

On Fri, 13 May 2022 10:01:48 +0800
kernel test robot <[email protected]> wrote:

> Hi Jeff,
>
> Thank you for the patch! Perhaps something to improve:
>
> [auto build test WARNING on rostedt-trace/for-next]
> [also build test WARNING on v5.18-rc6 next-20220512]
> [If your patch is applied to the wrong git tree, kindly drop us a note.
> And when submitting patch, we suggest to use '--base' as documented in
> https://git-scm.com/docs/git-format-patch]
>
> url: https://github.com/intel-lab-lkp/linux/commits/Jeff-Xie/trace-Introduce-objtrace-trigger-to-trace-the-kernel-object/20220513-010820
> base: https://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git for-next
> config: i386-randconfig-c001 (https://download.01.org/0day-ci/archive/20220513/[email protected]/config)
> compiler: clang version 15.0.0 (https://github.com/llvm/llvm-project 9519dacab7b8afd537811fc2abaceb4d14f4e16a)
> reproduce (this is a W=1 build):
> wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross
> chmod +x ~/bin/make.cross
> # https://github.com/intel-lab-lkp/linux/commit/3c91aa291a0fe8b28b02a14827b0c4ca3ebda601
> git remote add linux-review https://github.com/intel-lab-lkp/linux
> git fetch --no-tags linux-review Jeff-Xie/trace-Introduce-objtrace-trigger-to-trace-the-kernel-object/20220513-010820
> git checkout 3c91aa291a0fe8b28b02a14827b0c4ca3ebda601
> # save the config file
> mkdir build_dir && cp config build_dir/.config
> COMPILER_INSTALL_PATH=$HOME/0day COMPILER=clang make.cross W=1 O=build_dir ARCH=i386 SHELL=/bin/bash kernel/trace/
>
> If you fix the issue, kindly add following tag as appropriate
> Reported-by: kernel test robot <[email protected]>
>
> All warnings (new ones prefixed by >>):
>
> kernel/trace/trace_object.c:259:13: error: incompatible function pointer types initializing 'int (*)(struct seq_file *, struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct seq_file *, struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> .print = trace_object_trigger_print,
> ^~~~~~~~~~~~~~~~~~~~~~~~~~
> kernel/trace/trace_object.c:260:12: error: incompatible function pointer types initializing 'int (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> .init = event_object_trigger_init,
> ^~~~~~~~~~~~~~~~~~~~~~~~~
> kernel/trace/trace_object.c:261:12: error: incompatible function pointer types initializing 'void (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'void (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> .free = trace_object_trigger_free,
> ^~~~~~~~~~~~~~~~~~~~~~~~~
> kernel/trace/trace_object.c:266:13: error: incompatible function pointer types initializing 'int (*)(struct seq_file *, struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct seq_file *, struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> .print = trace_object_trigger_print,
> ^~~~~~~~~~~~~~~~~~~~~~~~~~
> kernel/trace/trace_object.c:267:12: error: incompatible function pointer types initializing 'int (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> .init = event_object_trigger_init,
> ^~~~~~~~~~~~~~~~~~~~~~~~~
> kernel/trace/trace_object.c:268:12: error: incompatible function pointer types initializing 'void (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'void (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> .free = trace_object_trigger_free,
> ^~~~~~~~~~~~~~~~~~~~~~~~~
> >> kernel/trace/trace_object.c:335:61: warning: format specifies type 'long' but the argument has type 'unsigned int' [-Wformat]
> pr_err("the size of the %s should be:%ld\n", field->name, sizeof(void *));
> ~~~ ^~~~~~~~~~~~~~
> %u
> include/linux/printk.h:489:33: note: expanded from macro 'pr_err'
> printk(KERN_ERR pr_fmt(fmt), ##__VA_ARGS__)
> ~~~ ^~~~~~~~~~~
> include/linux/printk.h:446:60: note: expanded from macro 'printk'
> #define printk(fmt, ...) printk_index_wrap(_printk, fmt, ##__VA_ARGS__)
> ~~~ ^~~~~~~~~~~
> include/linux/printk.h:418:19: note: expanded from macro 'printk_index_wrap'
> _p_func(_fmt, ##__VA_ARGS__); \
> ~~~~ ^~~~~~~~~~~
> kernel/trace/trace_object.c:356:3: error: implicit declaration of function 'event_trigger_unregister' [-Werror,-Wimplicit-function-declaration]
> event_trigger_unregister(cmd_ops, file, glob+1, trigger_data);
> ^
> kernel/trace/trace_object.c:356:3: note: did you mean 'event_trigger_register'?
> kernel/trace/trace.h:1650:12: note: 'event_trigger_register' declared here
> extern int event_trigger_register(struct event_command *cmd_ops,
> ^
> kernel/trace/trace_object.c:370:64: error: too few arguments to function call, expected 7, have 4
> ret = event_trigger_register(cmd_ops, file, glob, trigger_data);
> ~~~~~~~~~~~~~~~~~~~~~~ ^
> kernel/trace/trace.h:1650:12: note: 'event_trigger_register' declared here
> extern int event_trigger_register(struct event_command *cmd_ops,
> ^
> 1 warning and 8 errors generated.
>
>
> vim +335 kernel/trace/trace_object.c
>
> 296
> 297 static int
> 298 event_object_trigger_parse(struct event_command *cmd_ops,
> 299 struct trace_event_file *file,
> 300 char *glob, char *cmd, char *param_and_filter)
> 301 {
> 302 struct event_trigger_data *trigger_data;
> 303 struct objtrace_trigger_data *obj_data;
> 304 struct ftrace_event_field *field;
> 305 char *objtrace_cmd, *arg;
> 306 char *param, *filter;
> 307 int ret;
> 308 bool remove;
> 309
> 310 remove = event_trigger_check_remove(glob);
> 311
> 312 /*
> 313 * separate the param and the filter:
> 314 * objtrace:add:OBJ[:COUNT] [if filter]
> 315 */
> 316 ret = event_trigger_separate_filter(param_and_filter, &param, &filter, true);
> 317 if (ret)
> 318 return ret;
> 319
> 320 objtrace_cmd = strsep(&param, ":");
> 321 if (!objtrace_cmd || strcmp(objtrace_cmd, "add")) {
> 322 pr_err("error objtrace command\n");
> 323 return -EINVAL;
> 324 }
> 325
> 326 arg = strsep(&param, ":");
> 327 if (!arg)
> 328 return -EINVAL;
> 329
> 330 field = trace_find_event_field(file->event_call, arg);
> 331 if (!field)
> 332 return -EINVAL;
> 333
> 334 if (field->size != sizeof(void *)) {
> > 335 pr_err("the size of the %s should be:%ld\n", field->name, sizeof(void *));
> 336 return -EINVAL;
> 337 }
> 338
> 339 if (remove && !field_exist(file, cmd_ops, field->name))
> 340 return -EINVAL;
> 341
> 342 obj_data = kzalloc(sizeof(*obj_data), GFP_KERNEL);
> 343 if (!obj_data)
> 344 return -ENOMEM;
> 345
> 346 obj_data->field = field;
> 347 obj_data->tr = file->tr;
> 348 snprintf(obj_data->objtrace_cmd, OBJTRACE_CMD_LEN, objtrace_cmd);
> 349
> 350 trigger_data = event_trigger_alloc(cmd_ops, cmd, param, obj_data);
> 351 if (!trigger_data) {
> 352 kfree(obj_data);
> 353 return -ENOMEM;
> 354 }
> 355 if (remove) {
> 356 event_trigger_unregister(cmd_ops, file, glob+1, trigger_data);
> 357 kfree(obj_data);
> 358 kfree(trigger_data);
> 359 return 0;
> 360 }
> 361
> 362 ret = event_trigger_parse_num(param, trigger_data);
> 363 if (ret)
> 364 goto out_free;
> 365
> 366 ret = event_trigger_set_filter(cmd_ops, file, filter, trigger_data);
> 367 if (ret < 0)
> 368 goto out_free;
> 369
> 370 ret = event_trigger_register(cmd_ops, file, glob, trigger_data);
> 371 if (ret)
> 372 goto out_free;
> 373
> 374 return ret;
> 375
> 376 out_free:
> 377 event_trigger_reset_filter(cmd_ops, trigger_data);
> 378 kfree(obj_data);
> 379 kfree(trigger_data);
> 380 return ret;
> 381 }
> 382
>
> --
> 0-DAY CI Kernel Test Service
> https://01.org/lkp


--
Masami Hiramatsu <[email protected]>

2022-05-18 14:23:41

by Jeff Xie

[permalink] [raw]
Subject: Re: [PATCH v10 1/4] trace: Add trace any kernel object

Hi Masami,

Thank you for your reminder, I feel very strange, this patch series
was always based on:
https://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
ftrace/core

These compile errors may be because other branches have not merged
into Tom's patches.
Steve told me before that this patch series should rely on Tom's patch.


On Wed, May 18, 2022 at 9:48 PM Masami Hiramatsu <[email protected]> wrote:
>
> Hi Jeff,
>
> Can you fix these errors, since these looks real bugs.
>
> Thank you,
>
> On Fri, 13 May 2022 10:01:48 +0800
> kernel test robot <[email protected]> wrote:
>
> > Hi Jeff,
> >
> > Thank you for the patch! Perhaps something to improve:
> >
> > [auto build test WARNING on rostedt-trace/for-next]
> > [also build test WARNING on v5.18-rc6 next-20220512]
> > [If your patch is applied to the wrong git tree, kindly drop us a note.
> > And when submitting patch, we suggest to use '--base' as documented in
> > https://git-scm.com/docs/git-format-patch]
> >
> > url: https://github.com/intel-lab-lkp/linux/commits/Jeff-Xie/trace-Introduce-objtrace-trigger-to-trace-the-kernel-object/20220513-010820
> > base: https://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git for-next
> > config: i386-randconfig-c001 (https://download.01.org/0day-ci/archive/20220513/[email protected]/config)
> > compiler: clang version 15.0.0 (https://github.com/llvm/llvm-project 9519dacab7b8afd537811fc2abaceb4d14f4e16a)
> > reproduce (this is a W=1 build):
> > wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross
> > chmod +x ~/bin/make.cross
> > # https://github.com/intel-lab-lkp/linux/commit/3c91aa291a0fe8b28b02a14827b0c4ca3ebda601
> > git remote add linux-review https://github.com/intel-lab-lkp/linux
> > git fetch --no-tags linux-review Jeff-Xie/trace-Introduce-objtrace-trigger-to-trace-the-kernel-object/20220513-010820
> > git checkout 3c91aa291a0fe8b28b02a14827b0c4ca3ebda601
> > # save the config file
> > mkdir build_dir && cp config build_dir/.config
> > COMPILER_INSTALL_PATH=$HOME/0day COMPILER=clang make.cross W=1 O=build_dir ARCH=i386 SHELL=/bin/bash kernel/trace/
> >
> > If you fix the issue, kindly add following tag as appropriate
> > Reported-by: kernel test robot <[email protected]>
> >
> > All warnings (new ones prefixed by >>):
> >
> > kernel/trace/trace_object.c:259:13: error: incompatible function pointer types initializing 'int (*)(struct seq_file *, struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct seq_file *, struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > .print = trace_object_trigger_print,
> > ^~~~~~~~~~~~~~~~~~~~~~~~~~
> > kernel/trace/trace_object.c:260:12: error: incompatible function pointer types initializing 'int (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > .init = event_object_trigger_init,
> > ^~~~~~~~~~~~~~~~~~~~~~~~~
> > kernel/trace/trace_object.c:261:12: error: incompatible function pointer types initializing 'void (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'void (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > .free = trace_object_trigger_free,
> > ^~~~~~~~~~~~~~~~~~~~~~~~~
> > kernel/trace/trace_object.c:266:13: error: incompatible function pointer types initializing 'int (*)(struct seq_file *, struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct seq_file *, struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > .print = trace_object_trigger_print,
> > ^~~~~~~~~~~~~~~~~~~~~~~~~~
> > kernel/trace/trace_object.c:267:12: error: incompatible function pointer types initializing 'int (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > .init = event_object_trigger_init,
> > ^~~~~~~~~~~~~~~~~~~~~~~~~
> > kernel/trace/trace_object.c:268:12: error: incompatible function pointer types initializing 'void (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'void (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > .free = trace_object_trigger_free,
> > ^~~~~~~~~~~~~~~~~~~~~~~~~
> > >> kernel/trace/trace_object.c:335:61: warning: format specifies type 'long' but the argument has type 'unsigned int' [-Wformat]
> > pr_err("the size of the %s should be:%ld\n", field->name, sizeof(void *));
> > ~~~ ^~~~~~~~~~~~~~
> > %u
> > include/linux/printk.h:489:33: note: expanded from macro 'pr_err'
> > printk(KERN_ERR pr_fmt(fmt), ##__VA_ARGS__)
> > ~~~ ^~~~~~~~~~~
> > include/linux/printk.h:446:60: note: expanded from macro 'printk'
> > #define printk(fmt, ...) printk_index_wrap(_printk, fmt, ##__VA_ARGS__)
> > ~~~ ^~~~~~~~~~~
> > include/linux/printk.h:418:19: note: expanded from macro 'printk_index_wrap'
> > _p_func(_fmt, ##__VA_ARGS__); \
> > ~~~~ ^~~~~~~~~~~
> > kernel/trace/trace_object.c:356:3: error: implicit declaration of function 'event_trigger_unregister' [-Werror,-Wimplicit-function-declaration]
> > event_trigger_unregister(cmd_ops, file, glob+1, trigger_data);
> > ^
> > kernel/trace/trace_object.c:356:3: note: did you mean 'event_trigger_register'?
> > kernel/trace/trace.h:1650:12: note: 'event_trigger_register' declared here
> > extern int event_trigger_register(struct event_command *cmd_ops,
> > ^
> > kernel/trace/trace_object.c:370:64: error: too few arguments to function call, expected 7, have 4
> > ret = event_trigger_register(cmd_ops, file, glob, trigger_data);
> > ~~~~~~~~~~~~~~~~~~~~~~ ^
> > kernel/trace/trace.h:1650:12: note: 'event_trigger_register' declared here
> > extern int event_trigger_register(struct event_command *cmd_ops,
> > ^
> > 1 warning and 8 errors generated.
> >
> >
> > vim +335 kernel/trace/trace_object.c
> >
> > 296
> > 297 static int
> > 298 event_object_trigger_parse(struct event_command *cmd_ops,
> > 299 struct trace_event_file *file,
> > 300 char *glob, char *cmd, char *param_and_filter)
> > 301 {
> > 302 struct event_trigger_data *trigger_data;
> > 303 struct objtrace_trigger_data *obj_data;
> > 304 struct ftrace_event_field *field;
> > 305 char *objtrace_cmd, *arg;
> > 306 char *param, *filter;
> > 307 int ret;
> > 308 bool remove;
> > 309
> > 310 remove = event_trigger_check_remove(glob);
> > 311
> > 312 /*
> > 313 * separate the param and the filter:
> > 314 * objtrace:add:OBJ[:COUNT] [if filter]
> > 315 */
> > 316 ret = event_trigger_separate_filter(param_and_filter, &param, &filter, true);
> > 317 if (ret)
> > 318 return ret;
> > 319
> > 320 objtrace_cmd = strsep(&param, ":");
> > 321 if (!objtrace_cmd || strcmp(objtrace_cmd, "add")) {
> > 322 pr_err("error objtrace command\n");
> > 323 return -EINVAL;
> > 324 }
> > 325
> > 326 arg = strsep(&param, ":");
> > 327 if (!arg)
> > 328 return -EINVAL;
> > 329
> > 330 field = trace_find_event_field(file->event_call, arg);
> > 331 if (!field)
> > 332 return -EINVAL;
> > 333
> > 334 if (field->size != sizeof(void *)) {
> > > 335 pr_err("the size of the %s should be:%ld\n", field->name, sizeof(void *));
> > 336 return -EINVAL;
> > 337 }
> > 338
> > 339 if (remove && !field_exist(file, cmd_ops, field->name))
> > 340 return -EINVAL;
> > 341
> > 342 obj_data = kzalloc(sizeof(*obj_data), GFP_KERNEL);
> > 343 if (!obj_data)
> > 344 return -ENOMEM;
> > 345
> > 346 obj_data->field = field;
> > 347 obj_data->tr = file->tr;
> > 348 snprintf(obj_data->objtrace_cmd, OBJTRACE_CMD_LEN, objtrace_cmd);
> > 349
> > 350 trigger_data = event_trigger_alloc(cmd_ops, cmd, param, obj_data);
> > 351 if (!trigger_data) {
> > 352 kfree(obj_data);
> > 353 return -ENOMEM;
> > 354 }
> > 355 if (remove) {
> > 356 event_trigger_unregister(cmd_ops, file, glob+1, trigger_data);
> > 357 kfree(obj_data);
> > 358 kfree(trigger_data);
> > 359 return 0;
> > 360 }
> > 361
> > 362 ret = event_trigger_parse_num(param, trigger_data);
> > 363 if (ret)
> > 364 goto out_free;
> > 365
> > 366 ret = event_trigger_set_filter(cmd_ops, file, filter, trigger_data);
> > 367 if (ret < 0)
> > 368 goto out_free;
> > 369
> > 370 ret = event_trigger_register(cmd_ops, file, glob, trigger_data);
> > 371 if (ret)
> > 372 goto out_free;
> > 373
> > 374 return ret;
> > 375
> > 376 out_free:
> > 377 event_trigger_reset_filter(cmd_ops, trigger_data);
> > 378 kfree(obj_data);
> > 379 kfree(trigger_data);
> > 380 return ret;
> > 381 }
> > 382
> >
> > --
> > 0-DAY CI Kernel Test Service
> > https://01.org/lkp
>
>
> --
> Masami Hiramatsu <[email protected]>

Thanks,
JeffXie

2022-05-23 06:32:05

by Jeff Xie

[permalink] [raw]
Subject: Re: [PATCH v10 2/4] trace/objtrace: Get the value of the object

Hi Masami,

On Sun, May 22, 2022 at 10:22 PM Masami Hiramatsu <[email protected]> wrote:
>
> Hi Jeff,
>
> On Fri, 13 May 2022 01:00:06 +0800
> Jeff Xie <[email protected]> wrote:
>
> [...]
> > @@ -175,9 +271,27 @@ trace_object_trigger(struct event_trigger_data *data,
> >
> > field = obj_data->field;
> > memcpy(&obj, rec + field->offset, sizeof(obj));
> > - set_trace_object(obj, tr);
> > + /* set the offset from the special object and the type size of the value*/
> > + set_trace_object(obj, obj_data->obj_offset,
> > + obj_data->obj_value_type_size, tr);
> > }
> >
> > +static const struct objtrace_fetch_type objtrace_fetch_types[] = {
> > + {"u8", 1},
> > + {"s8", 1},
> > + {"x8", 1},
> > + {"u16", 2},
> > + {"s16", 2},
> > + {"x16", 2},
> > + {"u32", 4},
> > + {"s32", 4},
> > + {"x32", 4},
> > + {"u64", 8},
> > + {"s64", 8},
> > + {"x64", 8},
>
> Hmm, as far as I can see, you don't distinguish the prefix 'u','s','x'.
> If so, please support only 'x' at this moment. kprobe events supports
> those types, and it distinguishes the types when printing the logged
> data. E.g. 's16' shows '-1' for 0xffff, but 'x16' shows '0xffff'.
> You can add another patch to support such different types afterwards.

Thanks, I will add another patch to support it .

> > + {}
>
> If this array is null terminated, please explictly do that, like
>
> {NULL, 0},
>
> for readability.

Thank you for your reminder.

> Thank you,
>
> --
> Masami Hiramatsu (Google) <[email protected]>

Thanks,
JeffXie

2022-05-23 06:57:25

by Jeff Xie

[permalink] [raw]
Subject: Re: [PATCH v10 1/4] trace: Add trace any kernel object

Hi Masami,

Thanks for your detailed review.

On Sat, May 21, 2022 at 11:25 PM Masami Hiramatsu <[email protected]> wrote:
>
> Hi Jeff,
>
> On Fri, 13 May 2022 01:00:05 +0800
> Jeff Xie <[email protected]> wrote:
>
> > Introduce objtrace trigger to get the call flow by tracing any kernel
> > object in the function parameter.
> >
> > The objtrace trigger makes a list of the target object address from
> > the given event parameter, and records all kernel function calls
> > which has the object address in its parameter.
>
> Thank you for updating this. Please read my comments below
>
> [...]
> > +
> > +static bool object_exist(void *obj, struct trace_array *tr)
> > +{
> > + int i, max;
> > + struct objtrace_data *obj_data;
> > +
> > + obj_data = get_obj_data(tr);
> > + if (!obj_data)
> > + return false;
> > +
> > + max = atomic_read(&obj_data->num_traced_obj);
>
> max = READ_ONCE(&obj_data->num_traced_obj);
> (see below)

Thanks, it is indeed more appropriate to use READ_ONCE in places like this ;-)

>
> > + smp_rmb();
> > + for (i = 0; i < max; i++) {
> > + if (obj_data->traced_obj[i].obj == obj)
> > + return true;
> > + }
> > + return false;
> > +}
> > +
> > +static bool object_empty(struct trace_array *tr)
> > +{
> > + struct objtrace_data *obj_data;
> > +
> > + obj_data = get_obj_data(tr);
> > + if (!obj_data)
> > + return false;
> > +
> > + return !atomic_read(&obj_data->num_traced_obj);
>
> return !READ_ONCE(&obj_data->num_traced_obj);
> (see below)
>
> > +}
> > +
> > +static void set_trace_object(void *obj, struct trace_array *tr)
> > +{
> > + unsigned long flags;
> > + struct object_instance *obj_ins;
> > + struct objtrace_data *obj_data;
> > +
> > + if (in_nmi())
> > + return;
> > +
> > + if (!obj && object_exist(obj, tr))
> > + return;
> > +
> > + obj_data = get_obj_data(tr);
> > + if (!obj_data)
> > + return;
> > +
> > + /* only this place has write operations */
> > + raw_spin_lock_irqsave(&obj_data->obj_data_lock, flags);
> > + if (atomic_read(&obj_data->num_traced_obj) == MAX_TRACED_OBJECT) {
>
> Since obj_data->num_traced_obj update is protected by obj_data->obj_data_lock,
> you don't need atomic operation. What you need is using READ_ONCE() to
> access the num_traced_obj outside of this protected area.

Thank you for your reminder, this atomic operation is indeed redundant.

> > + trace_array_printk_buf(tr->array_buffer.buffer, _THIS_IP_,
> > + "object_pool is full, can't trace object:0x%px\n", obj);
> > + goto out;
> > + }
> > + obj_ins = &obj_data->traced_obj[atomic_read(&obj_data->num_traced_obj)];
> > + obj_ins->obj = obj;
> > + obj_ins->tr = tr;
> > + /* make sure the num_traced_obj update always appears after traced_obj update */
> > + smp_wmb();
> > + atomic_inc(&obj_data->num_traced_obj);
> > +out:
> > + raw_spin_unlock_irqrestore(&obj_data->obj_data_lock, flags);
> > +}
> > +
> [...]
> > +
> > +static int
> > +event_object_trigger_parse(struct event_command *cmd_ops,
> > + struct trace_event_file *file,
> > + char *glob, char *cmd, char *param_and_filter)
> > +{
> > + struct event_trigger_data *trigger_data;
> > + struct objtrace_trigger_data *obj_data;
> > + struct ftrace_event_field *field;
> > + char *objtrace_cmd, *arg;
> > + char *param, *filter;
> > + int ret;
> > + bool remove;
> > +
> > + remove = event_trigger_check_remove(glob);
> > +
> > + /*
> > + * separate the param and the filter:
> > + * objtrace:add:OBJ[:COUNT] [if filter]
> > + */
> > + ret = event_trigger_separate_filter(param_and_filter, &param, &filter, true);
> > + if (ret)
> > + return ret;
> > +
> > + objtrace_cmd = strsep(&param, ":");
> > + if (!objtrace_cmd || strcmp(objtrace_cmd, "add")) {
> > + pr_err("error objtrace command\n");
> > + return -EINVAL;
> > + }
> > +
> > + arg = strsep(&param, ":");
> > + if (!arg)
> > + return -EINVAL;
> > +
> > + field = trace_find_event_field(file->event_call, arg);
> > + if (!field)
> > + return -EINVAL;
> > +
> > + if (field->size != sizeof(void *)) {
> > + pr_err("the size of the %s should be:%ld\n", field->name, sizeof(void *));
> > + return -EINVAL;
> > + }
> > +
> > + if (remove && !field_exist(file, cmd_ops, field->name))
> > + return -EINVAL;
>
> This may return -ENOENT.

It would be better indeed to use -ENOENT ;-)

> > +
> > + obj_data = kzalloc(sizeof(*obj_data), GFP_KERNEL);
> > + if (!obj_data)
> > + return -ENOMEM;
> > +
> > + obj_data->field = field;
> > + obj_data->tr = file->tr;
> > + snprintf(obj_data->objtrace_cmd, OBJTRACE_CMD_LEN, objtrace_cmd);
>
> If objtrace_cmd is fixed command string, can you make this a flag, like
> OBJTRACE_CMD_ADD.

Yes I can use a macro to define the "add" OBJTRACE_CMD:
#define OBJTRACE_CMD_ADD "add"

> > +
> > + trigger_data = event_trigger_alloc(cmd_ops, cmd, param, obj_data);
> > + if (!trigger_data) {
> > + kfree(obj_data);
> > + return -ENOMEM;
> > + }
> > + if (remove) {
> > + event_trigger_unregister(cmd_ops, file, glob+1, trigger_data);
> > + kfree(obj_data);
> > + kfree(trigger_data);
> > + return 0;
> > + }
> > +
> > + ret = event_trigger_parse_num(param, trigger_data);
> > + if (ret)
> > + goto out_free;
> > +
> > + ret = event_trigger_set_filter(cmd_ops, file, filter, trigger_data);
> > + if (ret < 0)
> > + goto out_free;
> > +
> > + ret = event_trigger_register(cmd_ops, file, glob, trigger_data);
> > + if (ret)
> > + goto out_free;
> > +
> > + return ret;
> > +
> > + out_free:
> > + event_trigger_reset_filter(cmd_ops, trigger_data);
> > + kfree(obj_data);
> > + kfree(trigger_data);
> > + return ret;
> > +}
> > +
> > +static struct event_command trigger_object_cmd = {
> > + .name = "objtrace",
> > + .trigger_type = ETT_TRACE_OBJECT,
> > + .flags = EVENT_CMD_FL_NEEDS_REC,
> > + .parse = event_object_trigger_parse,
> > + .reg = register_trigger,
> > + .unreg = unregister_trigger,
> > + .get_trigger_ops = objecttrace_get_trigger_ops,
> > + .set_filter = set_trigger_filter,
> > +};
> > +
> > +__init int register_trigger_object_cmd(void)
> > +{
> > + int ret;
> > +
> > + ret = register_event_command(&trigger_object_cmd);
> > + WARN_ON(ret < 0);
> > +
> > + return ret;
> > +}
> > +
> > +int allocate_objtrace_data(struct trace_array *tr)
> > +{
> > + struct objtrace_data *obj_data;
> > + struct ftrace_ops *fops;
> > +
> > + obj_data = kzalloc(sizeof(*obj_data), GFP_KERNEL);
> > + if (!obj_data)
> > + return -ENOMEM;
> > +
> > + tr->obj_data = obj_data;
>
> I suggest to move this line after initializing all field in
> the obj_data.

Thanks ,Indeed it is better to move it after initializing all fields
in the obj_data ;-)

> > + obj_data->tr = tr;
> > + fops = &obj_data->fops;
> > + fops->func = trace_object_events_call;
> > + fops->flags = FTRACE_OPS_FL_SAVE_REGS;
> > + fops->private = tr;
> > +
> > + raw_spin_lock(&obj_data->obj_data_lock);
>
> You don't need to lock this spinlock becuase this data structure
> is not used yet. Also, you need to initialize the lock with
> __RAW_SPIN_LOCK_UNLOCKED() macro.

Thanks, I will remove the spinlock from here,
maybe it is better to use raw_spin_lock_init(&obj_data->obj_data_lock)
instead of
__RAW_SPIN_LOCK_UNLOCKED(obj_data->obj_data_lock)

The compiler will report warning if we use the __RAW_SPIN_LOCK_UNLOCKED

<compile warning>
kernel/trace/trace_object.c: In function ‘allocate_objtrace_data’:
./include/linux/spinlock_types_raw.h:69:2: warning: value computed is
not used [-Wunused-value]
69 | (raw_spinlock_t) __RAW_SPIN_LOCK_INITIALIZER(lockname)
| ^
kernel/trace/trace_object.c:422:2: note: in expansion of macro
‘__RAW_SPIN_LOCK_UNLOCKED’
422 | __RAW_SPIN_LOCK_UNLOCKED(obj_data->obj_data_lock);
</compile warning>

> > + list_add(&obj_data->head, &obj_data_head);
> > + raw_spin_unlock(&obj_data->obj_data_lock);
> > + return 0;
> > +}
>
>
> Thank you,
>
>
> --
> Masami Hiramatsu <[email protected]>

Thanks,
JeffXie

2022-05-23 07:29:26

by Masami Hiramatsu

[permalink] [raw]
Subject: Re: [PATCH v10 1/4] trace: Add trace any kernel object

Hi Jeff,

On Fri, 13 May 2022 01:00:05 +0800
Jeff Xie <[email protected]> wrote:

> Introduce objtrace trigger to get the call flow by tracing any kernel
> object in the function parameter.
>
> The objtrace trigger makes a list of the target object address from
> the given event parameter, and records all kernel function calls
> which has the object address in its parameter.

Thank you for updating this. Please read my comments below

[...]
> +
> +static bool object_exist(void *obj, struct trace_array *tr)
> +{
> + int i, max;
> + struct objtrace_data *obj_data;
> +
> + obj_data = get_obj_data(tr);
> + if (!obj_data)
> + return false;
> +
> + max = atomic_read(&obj_data->num_traced_obj);

max = READ_ONCE(&obj_data->num_traced_obj);
(see below)

> + smp_rmb();
> + for (i = 0; i < max; i++) {
> + if (obj_data->traced_obj[i].obj == obj)
> + return true;
> + }
> + return false;
> +}
> +
> +static bool object_empty(struct trace_array *tr)
> +{
> + struct objtrace_data *obj_data;
> +
> + obj_data = get_obj_data(tr);
> + if (!obj_data)
> + return false;
> +
> + return !atomic_read(&obj_data->num_traced_obj);

return !READ_ONCE(&obj_data->num_traced_obj);
(see below)

> +}
> +
> +static void set_trace_object(void *obj, struct trace_array *tr)
> +{
> + unsigned long flags;
> + struct object_instance *obj_ins;
> + struct objtrace_data *obj_data;
> +
> + if (in_nmi())
> + return;
> +
> + if (!obj && object_exist(obj, tr))
> + return;
> +
> + obj_data = get_obj_data(tr);
> + if (!obj_data)
> + return;
> +
> + /* only this place has write operations */
> + raw_spin_lock_irqsave(&obj_data->obj_data_lock, flags);
> + if (atomic_read(&obj_data->num_traced_obj) == MAX_TRACED_OBJECT) {

Since obj_data->num_traced_obj update is protected by obj_data->obj_data_lock,
you don't need atomic operation. What you need is using READ_ONCE() to
access the num_traced_obj outside of this protected area.

> + trace_array_printk_buf(tr->array_buffer.buffer, _THIS_IP_,
> + "object_pool is full, can't trace object:0x%px\n", obj);
> + goto out;
> + }
> + obj_ins = &obj_data->traced_obj[atomic_read(&obj_data->num_traced_obj)];
> + obj_ins->obj = obj;
> + obj_ins->tr = tr;
> + /* make sure the num_traced_obj update always appears after traced_obj update */
> + smp_wmb();
> + atomic_inc(&obj_data->num_traced_obj);
> +out:
> + raw_spin_unlock_irqrestore(&obj_data->obj_data_lock, flags);
> +}
> +
[...]
> +
> +static int
> +event_object_trigger_parse(struct event_command *cmd_ops,
> + struct trace_event_file *file,
> + char *glob, char *cmd, char *param_and_filter)
> +{
> + struct event_trigger_data *trigger_data;
> + struct objtrace_trigger_data *obj_data;
> + struct ftrace_event_field *field;
> + char *objtrace_cmd, *arg;
> + char *param, *filter;
> + int ret;
> + bool remove;
> +
> + remove = event_trigger_check_remove(glob);
> +
> + /*
> + * separate the param and the filter:
> + * objtrace:add:OBJ[:COUNT] [if filter]
> + */
> + ret = event_trigger_separate_filter(param_and_filter, &param, &filter, true);
> + if (ret)
> + return ret;
> +
> + objtrace_cmd = strsep(&param, ":");
> + if (!objtrace_cmd || strcmp(objtrace_cmd, "add")) {
> + pr_err("error objtrace command\n");
> + return -EINVAL;
> + }
> +
> + arg = strsep(&param, ":");
> + if (!arg)
> + return -EINVAL;
> +
> + field = trace_find_event_field(file->event_call, arg);
> + if (!field)
> + return -EINVAL;
> +
> + if (field->size != sizeof(void *)) {
> + pr_err("the size of the %s should be:%ld\n", field->name, sizeof(void *));
> + return -EINVAL;
> + }
> +
> + if (remove && !field_exist(file, cmd_ops, field->name))
> + return -EINVAL;

This may return -ENOENT.

> +
> + obj_data = kzalloc(sizeof(*obj_data), GFP_KERNEL);
> + if (!obj_data)
> + return -ENOMEM;
> +
> + obj_data->field = field;
> + obj_data->tr = file->tr;
> + snprintf(obj_data->objtrace_cmd, OBJTRACE_CMD_LEN, objtrace_cmd);

If objtrace_cmd is fixed command string, can you make this a flag, like
OBJTRACE_CMD_ADD.

> +
> + trigger_data = event_trigger_alloc(cmd_ops, cmd, param, obj_data);
> + if (!trigger_data) {
> + kfree(obj_data);
> + return -ENOMEM;
> + }
> + if (remove) {
> + event_trigger_unregister(cmd_ops, file, glob+1, trigger_data);
> + kfree(obj_data);
> + kfree(trigger_data);
> + return 0;
> + }
> +
> + ret = event_trigger_parse_num(param, trigger_data);
> + if (ret)
> + goto out_free;
> +
> + ret = event_trigger_set_filter(cmd_ops, file, filter, trigger_data);
> + if (ret < 0)
> + goto out_free;
> +
> + ret = event_trigger_register(cmd_ops, file, glob, trigger_data);
> + if (ret)
> + goto out_free;
> +
> + return ret;
> +
> + out_free:
> + event_trigger_reset_filter(cmd_ops, trigger_data);
> + kfree(obj_data);
> + kfree(trigger_data);
> + return ret;
> +}
> +
> +static struct event_command trigger_object_cmd = {
> + .name = "objtrace",
> + .trigger_type = ETT_TRACE_OBJECT,
> + .flags = EVENT_CMD_FL_NEEDS_REC,
> + .parse = event_object_trigger_parse,
> + .reg = register_trigger,
> + .unreg = unregister_trigger,
> + .get_trigger_ops = objecttrace_get_trigger_ops,
> + .set_filter = set_trigger_filter,
> +};
> +
> +__init int register_trigger_object_cmd(void)
> +{
> + int ret;
> +
> + ret = register_event_command(&trigger_object_cmd);
> + WARN_ON(ret < 0);
> +
> + return ret;
> +}
> +
> +int allocate_objtrace_data(struct trace_array *tr)
> +{
> + struct objtrace_data *obj_data;
> + struct ftrace_ops *fops;
> +
> + obj_data = kzalloc(sizeof(*obj_data), GFP_KERNEL);
> + if (!obj_data)
> + return -ENOMEM;
> +
> + tr->obj_data = obj_data;

I suggest to move this line after initializing all field in
the obj_data.

> + obj_data->tr = tr;
> + fops = &obj_data->fops;
> + fops->func = trace_object_events_call;
> + fops->flags = FTRACE_OPS_FL_SAVE_REGS;
> + fops->private = tr;
> +
> + raw_spin_lock(&obj_data->obj_data_lock);

You don't need to lock this spinlock becuase this data structure
is not used yet. Also, you need to initialize the lock with
__RAW_SPIN_LOCK_UNLOCKED() macro.

> + list_add(&obj_data->head, &obj_data_head);
> + raw_spin_unlock(&obj_data->obj_data_lock);
> + return 0;
> +}


Thank you,


--
Masami Hiramatsu <[email protected]>

2022-05-23 07:52:05

by Masami Hiramatsu

[permalink] [raw]
Subject: Re: [PATCH v10 2/4] trace/objtrace: Get the value of the object

Hi Jeff,

On Fri, 13 May 2022 01:00:06 +0800
Jeff Xie <[email protected]> wrote:

[...]
> @@ -175,9 +271,27 @@ trace_object_trigger(struct event_trigger_data *data,
>
> field = obj_data->field;
> memcpy(&obj, rec + field->offset, sizeof(obj));
> - set_trace_object(obj, tr);
> + /* set the offset from the special object and the type size of the value*/
> + set_trace_object(obj, obj_data->obj_offset,
> + obj_data->obj_value_type_size, tr);
> }
>
> +static const struct objtrace_fetch_type objtrace_fetch_types[] = {
> + {"u8", 1},
> + {"s8", 1},
> + {"x8", 1},
> + {"u16", 2},
> + {"s16", 2},
> + {"x16", 2},
> + {"u32", 4},
> + {"s32", 4},
> + {"x32", 4},
> + {"u64", 8},
> + {"s64", 8},
> + {"x64", 8},

Hmm, as far as I can see, you don't distinguish the prefix 'u','s','x'.
If so, please support only 'x' at this moment. kprobe events supports
those types, and it distinguishes the types when printing the logged
data. E.g. 's16' shows '-1' for 0xffff, but 'x16' shows '0xffff'.
You can add another patch to support such different types afterwards.

> + {}

If this array is null terminated, please explictly do that, like

{NULL, 0},

for readability.

Thank you,

--
Masami Hiramatsu (Google) <[email protected]>

2022-05-28 12:54:07

by Jeff Xie

[permalink] [raw]
Subject: Re: [PATCH v10 1/4] trace: Add trace any kernel object

Hi Masami,

On Fri, May 27, 2022 at 7:42 AM Masami Hiramatsu <[email protected]> wrote:
>
> Hi Jeff,
>
> On Wed, 18 May 2022 22:17:50 +0800
> Jeff Xie <[email protected]> wrote:
>
> > Hi Masami,
> >
> > Thank you for your reminder, I feel very strange, this patch series
> > was always based on:
> > https://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
> > ftrace/core
> >
> > These compile errors may be because other branches have not merged
> > into Tom's patches.
> > Steve told me before that this patch series should rely on Tom's patch.
>
> OK, when you send the next version, please describe this in the cover
> mail and point Tom's series if it is not merged yet.

Ok, thanks for the reminder.

> Thank you,
>
> >
> >
> > On Wed, May 18, 2022 at 9:48 PM Masami Hiramatsu <[email protected]> wrote:
> > >
> > > Hi Jeff,
> > >
> > > Can you fix these errors, since these looks real bugs.
> > >
> > > Thank you,
> > >
> > > On Fri, 13 May 2022 10:01:48 +0800
> > > kernel test robot <[email protected]> wrote:
> > >
> > > > Hi Jeff,
> > > >
> > > > Thank you for the patch! Perhaps something to improve:
> > > >
> > > > [auto build test WARNING on rostedt-trace/for-next]
> > > > [also build test WARNING on v5.18-rc6 next-20220512]
> > > > [If your patch is applied to the wrong git tree, kindly drop us a note.
> > > > And when submitting patch, we suggest to use '--base' as documented in
> > > > https://git-scm.com/docs/git-format-patch]
> > > >
> > > > url: https://github.com/intel-lab-lkp/linux/commits/Jeff-Xie/trace-Introduce-objtrace-trigger-to-trace-the-kernel-object/20220513-010820
> > > > base: https://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git for-next
> > > > config: i386-randconfig-c001 (https://download.01.org/0day-ci/archive/20220513/[email protected]/config)
> > > > compiler: clang version 15.0.0 (https://github.com/llvm/llvm-project 9519dacab7b8afd537811fc2abaceb4d14f4e16a)
> > > > reproduce (this is a W=1 build):
> > > > wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross
> > > > chmod +x ~/bin/make.cross
> > > > # https://github.com/intel-lab-lkp/linux/commit/3c91aa291a0fe8b28b02a14827b0c4ca3ebda601
> > > > git remote add linux-review https://github.com/intel-lab-lkp/linux
> > > > git fetch --no-tags linux-review Jeff-Xie/trace-Introduce-objtrace-trigger-to-trace-the-kernel-object/20220513-010820
> > > > git checkout 3c91aa291a0fe8b28b02a14827b0c4ca3ebda601
> > > > # save the config file
> > > > mkdir build_dir && cp config build_dir/.config
> > > > COMPILER_INSTALL_PATH=$HOME/0day COMPILER=clang make.cross W=1 O=build_dir ARCH=i386 SHELL=/bin/bash kernel/trace/
> > > >
> > > > If you fix the issue, kindly add following tag as appropriate
> > > > Reported-by: kernel test robot <[email protected]>
> > > >
> > > > All warnings (new ones prefixed by >>):
> > > >
> > > > kernel/trace/trace_object.c:259:13: error: incompatible function pointer types initializing 'int (*)(struct seq_file *, struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct seq_file *, struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > > > .print = trace_object_trigger_print,
> > > > ^~~~~~~~~~~~~~~~~~~~~~~~~~
> > > > kernel/trace/trace_object.c:260:12: error: incompatible function pointer types initializing 'int (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > > > .init = event_object_trigger_init,
> > > > ^~~~~~~~~~~~~~~~~~~~~~~~~
> > > > kernel/trace/trace_object.c:261:12: error: incompatible function pointer types initializing 'void (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'void (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > > > .free = trace_object_trigger_free,
> > > > ^~~~~~~~~~~~~~~~~~~~~~~~~
> > > > kernel/trace/trace_object.c:266:13: error: incompatible function pointer types initializing 'int (*)(struct seq_file *, struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct seq_file *, struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > > > .print = trace_object_trigger_print,
> > > > ^~~~~~~~~~~~~~~~~~~~~~~~~~
> > > > kernel/trace/trace_object.c:267:12: error: incompatible function pointer types initializing 'int (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > > > .init = event_object_trigger_init,
> > > > ^~~~~~~~~~~~~~~~~~~~~~~~~
> > > > kernel/trace/trace_object.c:268:12: error: incompatible function pointer types initializing 'void (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'void (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > > > .free = trace_object_trigger_free,
> > > > ^~~~~~~~~~~~~~~~~~~~~~~~~
> > > > >> kernel/trace/trace_object.c:335:61: warning: format specifies type 'long' but the argument has type 'unsigned int' [-Wformat]
> > > > pr_err("the size of the %s should be:%ld\n", field->name, sizeof(void *));
> > > > ~~~ ^~~~~~~~~~~~~~
> > > > %u
> > > > include/linux/printk.h:489:33: note: expanded from macro 'pr_err'
> > > > printk(KERN_ERR pr_fmt(fmt), ##__VA_ARGS__)
> > > > ~~~ ^~~~~~~~~~~
> > > > include/linux/printk.h:446:60: note: expanded from macro 'printk'
> > > > #define printk(fmt, ...) printk_index_wrap(_printk, fmt, ##__VA_ARGS__)
> > > > ~~~ ^~~~~~~~~~~
> > > > include/linux/printk.h:418:19: note: expanded from macro 'printk_index_wrap'
> > > > _p_func(_fmt, ##__VA_ARGS__); \
> > > > ~~~~ ^~~~~~~~~~~
> > > > kernel/trace/trace_object.c:356:3: error: implicit declaration of function 'event_trigger_unregister' [-Werror,-Wimplicit-function-declaration]
> > > > event_trigger_unregister(cmd_ops, file, glob+1, trigger_data);
> > > > ^
> > > > kernel/trace/trace_object.c:356:3: note: did you mean 'event_trigger_register'?
> > > > kernel/trace/trace.h:1650:12: note: 'event_trigger_register' declared here
> > > > extern int event_trigger_register(struct event_command *cmd_ops,
> > > > ^
> > > > kernel/trace/trace_object.c:370:64: error: too few arguments to function call, expected 7, have 4
> > > > ret = event_trigger_register(cmd_ops, file, glob, trigger_data);
> > > > ~~~~~~~~~~~~~~~~~~~~~~ ^
> > > > kernel/trace/trace.h:1650:12: note: 'event_trigger_register' declared here
> > > > extern int event_trigger_register(struct event_command *cmd_ops,
> > > > ^
> > > > 1 warning and 8 errors generated.
> > > >
> > > >
> > > > vim +335 kernel/trace/trace_object.c
> > > >
> > > > 296
> > > > 297 static int
> > > > 298 event_object_trigger_parse(struct event_command *cmd_ops,
> > > > 299 struct trace_event_file *file,
> > > > 300 char *glob, char *cmd, char *param_and_filter)
> > > > 301 {
> > > > 302 struct event_trigger_data *trigger_data;
> > > > 303 struct objtrace_trigger_data *obj_data;
> > > > 304 struct ftrace_event_field *field;
> > > > 305 char *objtrace_cmd, *arg;
> > > > 306 char *param, *filter;
> > > > 307 int ret;
> > > > 308 bool remove;
> > > > 309
> > > > 310 remove = event_trigger_check_remove(glob);
> > > > 311
> > > > 312 /*
> > > > 313 * separate the param and the filter:
> > > > 314 * objtrace:add:OBJ[:COUNT] [if filter]
> > > > 315 */
> > > > 316 ret = event_trigger_separate_filter(param_and_filter, &param, &filter, true);
> > > > 317 if (ret)
> > > > 318 return ret;
> > > > 319
> > > > 320 objtrace_cmd = strsep(&param, ":");
> > > > 321 if (!objtrace_cmd || strcmp(objtrace_cmd, "add")) {
> > > > 322 pr_err("error objtrace command\n");
> > > > 323 return -EINVAL;
> > > > 324 }
> > > > 325
> > > > 326 arg = strsep(&param, ":");
> > > > 327 if (!arg)
> > > > 328 return -EINVAL;
> > > > 329
> > > > 330 field = trace_find_event_field(file->event_call, arg);
> > > > 331 if (!field)
> > > > 332 return -EINVAL;
> > > > 333
> > > > 334 if (field->size != sizeof(void *)) {
> > > > > 335 pr_err("the size of the %s should be:%ld\n", field->name, sizeof(void *));
> > > > 336 return -EINVAL;
> > > > 337 }
> > > > 338
> > > > 339 if (remove && !field_exist(file, cmd_ops, field->name))
> > > > 340 return -EINVAL;
> > > > 341
> > > > 342 obj_data = kzalloc(sizeof(*obj_data), GFP_KERNEL);
> > > > 343 if (!obj_data)
> > > > 344 return -ENOMEM;
> > > > 345
> > > > 346 obj_data->field = field;
> > > > 347 obj_data->tr = file->tr;
> > > > 348 snprintf(obj_data->objtrace_cmd, OBJTRACE_CMD_LEN, objtrace_cmd);
> > > > 349
> > > > 350 trigger_data = event_trigger_alloc(cmd_ops, cmd, param, obj_data);
> > > > 351 if (!trigger_data) {
> > > > 352 kfree(obj_data);
> > > > 353 return -ENOMEM;
> > > > 354 }
> > > > 355 if (remove) {
> > > > 356 event_trigger_unregister(cmd_ops, file, glob+1, trigger_data);
> > > > 357 kfree(obj_data);
> > > > 358 kfree(trigger_data);
> > > > 359 return 0;
> > > > 360 }
> > > > 361
> > > > 362 ret = event_trigger_parse_num(param, trigger_data);
> > > > 363 if (ret)
> > > > 364 goto out_free;
> > > > 365
> > > > 366 ret = event_trigger_set_filter(cmd_ops, file, filter, trigger_data);
> > > > 367 if (ret < 0)
> > > > 368 goto out_free;
> > > > 369
> > > > 370 ret = event_trigger_register(cmd_ops, file, glob, trigger_data);
> > > > 371 if (ret)
> > > > 372 goto out_free;
> > > > 373
> > > > 374 return ret;
> > > > 375
> > > > 376 out_free:
> > > > 377 event_trigger_reset_filter(cmd_ops, trigger_data);
> > > > 378 kfree(obj_data);
> > > > 379 kfree(trigger_data);
> > > > 380 return ret;
> > > > 381 }
> > > > 382
> > > >
> > > > --
> > > > 0-DAY CI Kernel Test Service
> > > > https://01.org/lkp
> > >
> > >
> > > --
> > > Masami Hiramatsu <[email protected]>
> >
> > Thanks,
> > JeffXie
>
>
> --
> Masami Hiramatsu (Google) <[email protected]>

Thanks,
JeffXie

2022-05-28 19:52:11

by Masami Hiramatsu

[permalink] [raw]
Subject: Re: [PATCH v10 1/4] trace: Add trace any kernel object

Hi Jeff,

On Wed, 18 May 2022 22:17:50 +0800
Jeff Xie <[email protected]> wrote:

> Hi Masami,
>
> Thank you for your reminder, I feel very strange, this patch series
> was always based on:
> https://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
> ftrace/core
>
> These compile errors may be because other branches have not merged
> into Tom's patches.
> Steve told me before that this patch series should rely on Tom's patch.

OK, when you send the next version, please describe this in the cover
mail and point Tom's series if it is not merged yet.

Thank you,

>
>
> On Wed, May 18, 2022 at 9:48 PM Masami Hiramatsu <[email protected]> wrote:
> >
> > Hi Jeff,
> >
> > Can you fix these errors, since these looks real bugs.
> >
> > Thank you,
> >
> > On Fri, 13 May 2022 10:01:48 +0800
> > kernel test robot <[email protected]> wrote:
> >
> > > Hi Jeff,
> > >
> > > Thank you for the patch! Perhaps something to improve:
> > >
> > > [auto build test WARNING on rostedt-trace/for-next]
> > > [also build test WARNING on v5.18-rc6 next-20220512]
> > > [If your patch is applied to the wrong git tree, kindly drop us a note.
> > > And when submitting patch, we suggest to use '--base' as documented in
> > > https://git-scm.com/docs/git-format-patch]
> > >
> > > url: https://github.com/intel-lab-lkp/linux/commits/Jeff-Xie/trace-Introduce-objtrace-trigger-to-trace-the-kernel-object/20220513-010820
> > > base: https://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git for-next
> > > config: i386-randconfig-c001 (https://download.01.org/0day-ci/archive/20220513/[email protected]/config)
> > > compiler: clang version 15.0.0 (https://github.com/llvm/llvm-project 9519dacab7b8afd537811fc2abaceb4d14f4e16a)
> > > reproduce (this is a W=1 build):
> > > wget https://raw.githubusercontent.com/intel/lkp-tests/master/sbin/make.cross -O ~/bin/make.cross
> > > chmod +x ~/bin/make.cross
> > > # https://github.com/intel-lab-lkp/linux/commit/3c91aa291a0fe8b28b02a14827b0c4ca3ebda601
> > > git remote add linux-review https://github.com/intel-lab-lkp/linux
> > > git fetch --no-tags linux-review Jeff-Xie/trace-Introduce-objtrace-trigger-to-trace-the-kernel-object/20220513-010820
> > > git checkout 3c91aa291a0fe8b28b02a14827b0c4ca3ebda601
> > > # save the config file
> > > mkdir build_dir && cp config build_dir/.config
> > > COMPILER_INSTALL_PATH=$HOME/0day COMPILER=clang make.cross W=1 O=build_dir ARCH=i386 SHELL=/bin/bash kernel/trace/
> > >
> > > If you fix the issue, kindly add following tag as appropriate
> > > Reported-by: kernel test robot <[email protected]>
> > >
> > > All warnings (new ones prefixed by >>):
> > >
> > > kernel/trace/trace_object.c:259:13: error: incompatible function pointer types initializing 'int (*)(struct seq_file *, struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct seq_file *, struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > > .print = trace_object_trigger_print,
> > > ^~~~~~~~~~~~~~~~~~~~~~~~~~
> > > kernel/trace/trace_object.c:260:12: error: incompatible function pointer types initializing 'int (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > > .init = event_object_trigger_init,
> > > ^~~~~~~~~~~~~~~~~~~~~~~~~
> > > kernel/trace/trace_object.c:261:12: error: incompatible function pointer types initializing 'void (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'void (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > > .free = trace_object_trigger_free,
> > > ^~~~~~~~~~~~~~~~~~~~~~~~~
> > > kernel/trace/trace_object.c:266:13: error: incompatible function pointer types initializing 'int (*)(struct seq_file *, struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct seq_file *, struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > > .print = trace_object_trigger_print,
> > > ^~~~~~~~~~~~~~~~~~~~~~~~~~
> > > kernel/trace/trace_object.c:267:12: error: incompatible function pointer types initializing 'int (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'int (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > > .init = event_object_trigger_init,
> > > ^~~~~~~~~~~~~~~~~~~~~~~~~
> > > kernel/trace/trace_object.c:268:12: error: incompatible function pointer types initializing 'void (*)(struct event_trigger_ops *, struct event_trigger_data *)' with an expression of type 'void (struct event_trigger_data *)' [-Werror,-Wincompatible-function-pointer-types]
> > > .free = trace_object_trigger_free,
> > > ^~~~~~~~~~~~~~~~~~~~~~~~~
> > > >> kernel/trace/trace_object.c:335:61: warning: format specifies type 'long' but the argument has type 'unsigned int' [-Wformat]
> > > pr_err("the size of the %s should be:%ld\n", field->name, sizeof(void *));
> > > ~~~ ^~~~~~~~~~~~~~
> > > %u
> > > include/linux/printk.h:489:33: note: expanded from macro 'pr_err'
> > > printk(KERN_ERR pr_fmt(fmt), ##__VA_ARGS__)
> > > ~~~ ^~~~~~~~~~~
> > > include/linux/printk.h:446:60: note: expanded from macro 'printk'
> > > #define printk(fmt, ...) printk_index_wrap(_printk, fmt, ##__VA_ARGS__)
> > > ~~~ ^~~~~~~~~~~
> > > include/linux/printk.h:418:19: note: expanded from macro 'printk_index_wrap'
> > > _p_func(_fmt, ##__VA_ARGS__); \
> > > ~~~~ ^~~~~~~~~~~
> > > kernel/trace/trace_object.c:356:3: error: implicit declaration of function 'event_trigger_unregister' [-Werror,-Wimplicit-function-declaration]
> > > event_trigger_unregister(cmd_ops, file, glob+1, trigger_data);
> > > ^
> > > kernel/trace/trace_object.c:356:3: note: did you mean 'event_trigger_register'?
> > > kernel/trace/trace.h:1650:12: note: 'event_trigger_register' declared here
> > > extern int event_trigger_register(struct event_command *cmd_ops,
> > > ^
> > > kernel/trace/trace_object.c:370:64: error: too few arguments to function call, expected 7, have 4
> > > ret = event_trigger_register(cmd_ops, file, glob, trigger_data);
> > > ~~~~~~~~~~~~~~~~~~~~~~ ^
> > > kernel/trace/trace.h:1650:12: note: 'event_trigger_register' declared here
> > > extern int event_trigger_register(struct event_command *cmd_ops,
> > > ^
> > > 1 warning and 8 errors generated.
> > >
> > >
> > > vim +335 kernel/trace/trace_object.c
> > >
> > > 296
> > > 297 static int
> > > 298 event_object_trigger_parse(struct event_command *cmd_ops,
> > > 299 struct trace_event_file *file,
> > > 300 char *glob, char *cmd, char *param_and_filter)
> > > 301 {
> > > 302 struct event_trigger_data *trigger_data;
> > > 303 struct objtrace_trigger_data *obj_data;
> > > 304 struct ftrace_event_field *field;
> > > 305 char *objtrace_cmd, *arg;
> > > 306 char *param, *filter;
> > > 307 int ret;
> > > 308 bool remove;
> > > 309
> > > 310 remove = event_trigger_check_remove(glob);
> > > 311
> > > 312 /*
> > > 313 * separate the param and the filter:
> > > 314 * objtrace:add:OBJ[:COUNT] [if filter]
> > > 315 */
> > > 316 ret = event_trigger_separate_filter(param_and_filter, &param, &filter, true);
> > > 317 if (ret)
> > > 318 return ret;
> > > 319
> > > 320 objtrace_cmd = strsep(&param, ":");
> > > 321 if (!objtrace_cmd || strcmp(objtrace_cmd, "add")) {
> > > 322 pr_err("error objtrace command\n");
> > > 323 return -EINVAL;
> > > 324 }
> > > 325
> > > 326 arg = strsep(&param, ":");
> > > 327 if (!arg)
> > > 328 return -EINVAL;
> > > 329
> > > 330 field = trace_find_event_field(file->event_call, arg);
> > > 331 if (!field)
> > > 332 return -EINVAL;
> > > 333
> > > 334 if (field->size != sizeof(void *)) {
> > > > 335 pr_err("the size of the %s should be:%ld\n", field->name, sizeof(void *));
> > > 336 return -EINVAL;
> > > 337 }
> > > 338
> > > 339 if (remove && !field_exist(file, cmd_ops, field->name))
> > > 340 return -EINVAL;
> > > 341
> > > 342 obj_data = kzalloc(sizeof(*obj_data), GFP_KERNEL);
> > > 343 if (!obj_data)
> > > 344 return -ENOMEM;
> > > 345
> > > 346 obj_data->field = field;
> > > 347 obj_data->tr = file->tr;
> > > 348 snprintf(obj_data->objtrace_cmd, OBJTRACE_CMD_LEN, objtrace_cmd);
> > > 349
> > > 350 trigger_data = event_trigger_alloc(cmd_ops, cmd, param, obj_data);
> > > 351 if (!trigger_data) {
> > > 352 kfree(obj_data);
> > > 353 return -ENOMEM;
> > > 354 }
> > > 355 if (remove) {
> > > 356 event_trigger_unregister(cmd_ops, file, glob+1, trigger_data);
> > > 357 kfree(obj_data);
> > > 358 kfree(trigger_data);
> > > 359 return 0;
> > > 360 }
> > > 361
> > > 362 ret = event_trigger_parse_num(param, trigger_data);
> > > 363 if (ret)
> > > 364 goto out_free;
> > > 365
> > > 366 ret = event_trigger_set_filter(cmd_ops, file, filter, trigger_data);
> > > 367 if (ret < 0)
> > > 368 goto out_free;
> > > 369
> > > 370 ret = event_trigger_register(cmd_ops, file, glob, trigger_data);
> > > 371 if (ret)
> > > 372 goto out_free;
> > > 373
> > > 374 return ret;
> > > 375
> > > 376 out_free:
> > > 377 event_trigger_reset_filter(cmd_ops, trigger_data);
> > > 378 kfree(obj_data);
> > > 379 kfree(trigger_data);
> > > 380 return ret;
> > > 381 }
> > > 382
> > >
> > > --
> > > 0-DAY CI Kernel Test Service
> > > https://01.org/lkp
> >
> >
> > --
> > Masami Hiramatsu <[email protected]>
>
> Thanks,
> JeffXie


--
Masami Hiramatsu (Google) <[email protected]>

2022-06-01 14:17:58

by Jeff Xie

[permalink] [raw]
Subject: Re: [PATCH v10 2/4] trace/objtrace: Get the value of the object

Hi Masami and steve,

On Sun, May 22, 2022 at 10:22 PM Masami Hiramatsu <[email protected]> wrote:
>
> Hi Jeff,
>
> On Fri, 13 May 2022 01:00:06 +0800
> Jeff Xie <[email protected]> wrote:
>
> [...]
> > @@ -175,9 +271,27 @@ trace_object_trigger(struct event_trigger_data *data,
> >
> > field = obj_data->field;
> > memcpy(&obj, rec + field->offset, sizeof(obj));
> > - set_trace_object(obj, tr);
> > + /* set the offset from the special object and the type size of the value*/
> > + set_trace_object(obj, obj_data->obj_offset,
> > + obj_data->obj_value_type_size, tr);
> > }
> >
> > +static const struct objtrace_fetch_type objtrace_fetch_types[] = {
> > + {"u8", 1},
> > + {"s8", 1},
> > + {"x8", 1},
> > + {"u16", 2},
> > + {"s16", 2},
> > + {"x16", 2},
> > + {"u32", 4},
> > + {"s32", 4},
> > + {"x32", 4},
> > + {"u64", 8},
> > + {"s64", 8},
> > + {"x64", 8},
>
> Hmm, as far as I can see, you don't distinguish the prefix 'u','s','x'.
> If so, please support only 'x' at this moment. kprobe events supports
> those types, and it distinguishes the types when printing the logged
> data. E.g. 's16' shows '-1' for 0xffff, but 'x16' shows '0xffff'.
> You can add another patch to support such different types afterwards.

I feel to let the objtrace trigger to distinguish the prefix 'u', 's',
'x', It seems a very challenging work ;-)
I spent a lot of time thinking, I would like to add a callback
function(print function) in the struct trace_object_entry for each
data type.
Not sure if this is possible or allowed, as I haven't seen any example
like this to add function in the struct *_entry ;-)

The following is part of the code I have prepared. I don't know if you
can give any suggestions or wait until I submit the next version to
discuss.

<snip>
diff --git a/kernel/trace/trace_entries.h b/kernel/trace/trace_entries.h
index 2407c45a568c..5f8289e26f91 100644
--- a/kernel/trace/trace_entries.h
+++ b/kernel/trace/trace_entries.h
@@ -414,6 +414,7 @@ FTRACE_ENTRY(object, trace_object_entry,
__field( unsigned long, parent_ip )
__field( unsigned long, object )
__field( unsigned long, value )
+ __field( unsigned long, print )
),

+/* get the type size for the special object */
+struct objtrace_fetch_type {
+ char *name;
+ int type_size;
+ int is_signed;
+ print_type_func_t print;
+};
+

static const struct objtrace_fetch_type objtrace_fetch_types[] = {
- {"x8", 1},
- {"x16", 2},
- {"x32", 4},
- {"x64", 8},
- {NULL, 0}
+ {"u8", 1, 0, PRINT_TYPE_FUNC_NAME(u8)},
+ {"s8", 1, 1, PRINT_TYPE_FUNC_NAME(s8)},
+ {"x8", 1, 0, PRINT_TYPE_FUNC_NAME(x8)},
+ {"u16", 2, 0, PRINT_TYPE_FUNC_NAME(u16)},
+ {"s16", 2, 1, PRINT_TYPE_FUNC_NAME(s16)},
+ {"x16", 2, 0, PRINT_TYPE_FUNC_NAME(x16)},
+ {"u32", 4, 0, PRINT_TYPE_FUNC_NAME(u32)},
+ {"s32", 4, 1, PRINT_TYPE_FUNC_NAME(s32)},
+ {"x32", 4, 0, PRINT_TYPE_FUNC_NAME(x32)},
+ {"u64", 8, 0, PRINT_TYPE_FUNC_NAME(u64)},
+ {"s64", 8, 1, PRINT_TYPE_FUNC_NAME(s64)},
+ {"x64", 8, 1, PRINT_TYPE_FUNC_NAME(x64)},
+ {NULL, 0, 0, NULL}
};
</snip>

> > + {}
>
> If this array is null terminated, please explictly do that, like
>
> {NULL, 0},
>
> for readability.
>
> Thank you,
>
> --
> Masami Hiramatsu (Google) <[email protected]>

Thanks,
JeffXie

2022-06-01 20:20:30

by Masami Hiramatsu

[permalink] [raw]
Subject: Re: [PATCH v10 2/4] trace/objtrace: Get the value of the object

On Tue, 31 May 2022 15:13:24 +0800
Jeff Xie <[email protected]> wrote:

> Hi Masami and steve,
>
> On Sun, May 22, 2022 at 10:22 PM Masami Hiramatsu <[email protected]> wrote:
> >
> > Hi Jeff,
> >
> > On Fri, 13 May 2022 01:00:06 +0800
> > Jeff Xie <[email protected]> wrote:
> >
> > [...]
> > > @@ -175,9 +271,27 @@ trace_object_trigger(struct event_trigger_data *data,
> > >
> > > field = obj_data->field;
> > > memcpy(&obj, rec + field->offset, sizeof(obj));
> > > - set_trace_object(obj, tr);
> > > + /* set the offset from the special object and the type size of the value*/
> > > + set_trace_object(obj, obj_data->obj_offset,
> > > + obj_data->obj_value_type_size, tr);
> > > }
> > >
> > > +static const struct objtrace_fetch_type objtrace_fetch_types[] = {
> > > + {"u8", 1},
> > > + {"s8", 1},
> > > + {"x8", 1},
> > > + {"u16", 2},
> > > + {"s16", 2},
> > > + {"x16", 2},
> > > + {"u32", 4},
> > > + {"s32", 4},
> > > + {"x32", 4},
> > > + {"u64", 8},
> > > + {"s64", 8},
> > > + {"x64", 8},
> >
> > Hmm, as far as I can see, you don't distinguish the prefix 'u','s','x'.
> > If so, please support only 'x' at this moment. kprobe events supports
> > those types, and it distinguishes the types when printing the logged
> > data. E.g. 's16' shows '-1' for 0xffff, but 'x16' shows '0xffff'.
> > You can add another patch to support such different types afterwards.
>
> I feel to let the objtrace trigger to distinguish the prefix 'u', 's',
> 'x', It seems a very challenging work ;-)
> I spent a lot of time thinking, I would like to add a callback
> function(print function) in the struct trace_object_entry for each
> data type.
> Not sure if this is possible or allowed, as I haven't seen any example
> like this to add function in the struct *_entry ;-)

Hmm, I don't recommend this, becuase this event record can be exposed
to user space as binary data. So please do not put such a function
pointer which will be used in the ftrace directly.
Instead, add a new event type of the object-trace for each type-prefix,
since each of them has different print-fmt.

Anyway I would like to ask you is to share the next version of the
series without that improvement. You can improve it after merging the
basic feature. No need to stop the series until all possible feature
set are implemented (unless it will change the user-exposed interface
much.)

>
> The following is part of the code I have prepared. I don't know if you
> can give any suggestions or wait until I submit the next version to
> discuss.

But thanks for sharing the code. This helps me to understand what you
are trying :)

Thank you,



>
> <snip>
> diff --git a/kernel/trace/trace_entries.h b/kernel/trace/trace_entries.h
> index 2407c45a568c..5f8289e26f91 100644
> --- a/kernel/trace/trace_entries.h
> +++ b/kernel/trace/trace_entries.h
> @@ -414,6 +414,7 @@ FTRACE_ENTRY(object, trace_object_entry,
> __field( unsigned long, parent_ip )
> __field( unsigned long, object )
> __field( unsigned long, value )
> + __field( unsigned long, print )
> ),
>
> +/* get the type size for the special object */
> +struct objtrace_fetch_type {
> + char *name;
> + int type_size;
> + int is_signed;
> + print_type_func_t print;
> +};
> +
>
> static const struct objtrace_fetch_type objtrace_fetch_types[] = {
> - {"x8", 1},
> - {"x16", 2},
> - {"x32", 4},
> - {"x64", 8},
> - {NULL, 0}
> + {"u8", 1, 0, PRINT_TYPE_FUNC_NAME(u8)},
> + {"s8", 1, 1, PRINT_TYPE_FUNC_NAME(s8)},
> + {"x8", 1, 0, PRINT_TYPE_FUNC_NAME(x8)},
> + {"u16", 2, 0, PRINT_TYPE_FUNC_NAME(u16)},
> + {"s16", 2, 1, PRINT_TYPE_FUNC_NAME(s16)},
> + {"x16", 2, 0, PRINT_TYPE_FUNC_NAME(x16)},
> + {"u32", 4, 0, PRINT_TYPE_FUNC_NAME(u32)},
> + {"s32", 4, 1, PRINT_TYPE_FUNC_NAME(s32)},
> + {"x32", 4, 0, PRINT_TYPE_FUNC_NAME(x32)},
> + {"u64", 8, 0, PRINT_TYPE_FUNC_NAME(u64)},
> + {"s64", 8, 1, PRINT_TYPE_FUNC_NAME(s64)},
> + {"x64", 8, 1, PRINT_TYPE_FUNC_NAME(x64)},
> + {NULL, 0, 0, NULL}
> };
> </snip>
>
> > > + {}
> >
> > If this array is null terminated, please explictly do that, like
> >
> > {NULL, 0},
> >
> > for readability.
> >
> > Thank you,
> >
> > --
> > Masami Hiramatsu (Google) <[email protected]>
>
> Thanks,
> JeffXie


--
Masami Hiramatsu (Google) <[email protected]>

2022-06-03 00:13:00

by Jeff Xie

[permalink] [raw]
Subject: Re: [PATCH v10 2/4] trace/objtrace: Get the value of the object

Hi Masami,

On Wed, Jun 1, 2022 at 11:13 PM Masami Hiramatsu <[email protected]> wrote:
>
> On Tue, 31 May 2022 15:13:24 +0800
> Jeff Xie <[email protected]> wrote:
>
> > Hi Masami and steve,
> >
> > On Sun, May 22, 2022 at 10:22 PM Masami Hiramatsu <[email protected]> wrote:
> > >
> > > Hi Jeff,
> > >
> > > On Fri, 13 May 2022 01:00:06 +0800
> > > Jeff Xie <[email protected]> wrote:
> > >
> > > [...]
> > > > @@ -175,9 +271,27 @@ trace_object_trigger(struct event_trigger_data *data,
> > > >
> > > > field = obj_data->field;
> > > > memcpy(&obj, rec + field->offset, sizeof(obj));
> > > > - set_trace_object(obj, tr);
> > > > + /* set the offset from the special object and the type size of the value*/
> > > > + set_trace_object(obj, obj_data->obj_offset,
> > > > + obj_data->obj_value_type_size, tr);
> > > > }
> > > >
> > > > +static const struct objtrace_fetch_type objtrace_fetch_types[] = {
> > > > + {"u8", 1},
> > > > + {"s8", 1},
> > > > + {"x8", 1},
> > > > + {"u16", 2},
> > > > + {"s16", 2},
> > > > + {"x16", 2},
> > > > + {"u32", 4},
> > > > + {"s32", 4},
> > > > + {"x32", 4},
> > > > + {"u64", 8},
> > > > + {"s64", 8},
> > > > + {"x64", 8},
> > >
> > > Hmm, as far as I can see, you don't distinguish the prefix 'u','s','x'.
> > > If so, please support only 'x' at this moment. kprobe events supports
> > > those types, and it distinguishes the types when printing the logged
> > > data. E.g. 's16' shows '-1' for 0xffff, but 'x16' shows '0xffff'.
> > > You can add another patch to support such different types afterwards.
> >
> > I feel to let the objtrace trigger to distinguish the prefix 'u', 's',
> > 'x', It seems a very challenging work ;-)
> > I spent a lot of time thinking, I would like to add a callback
> > function(print function) in the struct trace_object_entry for each
> > data type.
> > Not sure if this is possible or allowed, as I haven't seen any example
> > like this to add function in the struct *_entry ;-)
>
> Hmm, I don't recommend this, becuase this event record can be exposed
> to user space as binary data. So please do not put such a function
> pointer which will be used in the ftrace directly.
> Instead, add a new event type of the object-trace for each type-prefix,
> since each of them has different print-fmt.

This place is still a difficult point for me ;-)

> Anyway I would like to ask you is to share the next version of the
> series without that improvement. You can improve it after merging the
> basic feature. No need to stop the series until all possible feature
> set are implemented (unless it will change the user-exposed interface
> much.)

Thanks for your suggestion, I will submit the next version.

>
> >
> > The following is part of the code I have prepared. I don't know if you
> > can give any suggestions or wait until I submit the next version to
> > discuss.
>
> But thanks for sharing the code. This helps me to understand what you
> are trying :)
>
> Thank you,
>
>
>
> >
> > <snip>
> > diff --git a/kernel/trace/trace_entries.h b/kernel/trace/trace_entries.h
> > index 2407c45a568c..5f8289e26f91 100644
> > --- a/kernel/trace/trace_entries.h
> > +++ b/kernel/trace/trace_entries.h
> > @@ -414,6 +414,7 @@ FTRACE_ENTRY(object, trace_object_entry,
> > __field( unsigned long, parent_ip )
> > __field( unsigned long, object )
> > __field( unsigned long, value )
> > + __field( unsigned long, print )
> > ),
> >
> > +/* get the type size for the special object */
> > +struct objtrace_fetch_type {
> > + char *name;
> > + int type_size;
> > + int is_signed;
> > + print_type_func_t print;
> > +};
> > +
> >
> > static const struct objtrace_fetch_type objtrace_fetch_types[] = {
> > - {"x8", 1},
> > - {"x16", 2},
> > - {"x32", 4},
> > - {"x64", 8},
> > - {NULL, 0}
> > + {"u8", 1, 0, PRINT_TYPE_FUNC_NAME(u8)},
> > + {"s8", 1, 1, PRINT_TYPE_FUNC_NAME(s8)},
> > + {"x8", 1, 0, PRINT_TYPE_FUNC_NAME(x8)},
> > + {"u16", 2, 0, PRINT_TYPE_FUNC_NAME(u16)},
> > + {"s16", 2, 1, PRINT_TYPE_FUNC_NAME(s16)},
> > + {"x16", 2, 0, PRINT_TYPE_FUNC_NAME(x16)},
> > + {"u32", 4, 0, PRINT_TYPE_FUNC_NAME(u32)},
> > + {"s32", 4, 1, PRINT_TYPE_FUNC_NAME(s32)},
> > + {"x32", 4, 0, PRINT_TYPE_FUNC_NAME(x32)},
> > + {"u64", 8, 0, PRINT_TYPE_FUNC_NAME(u64)},
> > + {"s64", 8, 1, PRINT_TYPE_FUNC_NAME(s64)},
> > + {"x64", 8, 1, PRINT_TYPE_FUNC_NAME(x64)},
> > + {NULL, 0, 0, NULL}
> > };
> > </snip>
> >
> > > > + {}
> > >
> > > If this array is null terminated, please explictly do that, like
> > >
> > > {NULL, 0},
> > >
> > > for readability.
> > >
> > > Thank you,
> > >
> > > --
> > > Masami Hiramatsu (Google) <[email protected]>
> >
> > Thanks,
> > JeffXie
>
>
> --
> Masami Hiramatsu (Google) <[email protected]>

Thanks,
JeffXie