tracing/probes: Support function parameter access from return probe
Subsystems (3)
Masami Hiramatsu (Google)
maintainerv3 cover tracing/probes: Support function parameter access from return probe
Hi,
Here is version 3 series of patches to support accessing function entry data from function *return* probes (including kretprobe and fprobe-exit event). The previous version is here;
https://lore.kernel.org/all/170891987362.609861.6767830614537418260.stgit@devnote2/
In this version, [1/8] is a bugfix patch (but note that this is already pushed to probes-fixes-v6.8-rc5, just for reference), updated [4/8] changelog and build error, fixes selftests error [6/8], update document[8/8] and added Steve's reviewed-by.
This allows us to access the results of some functions, which returns the error code and its results are passed via function parameter, such as an structure-initialization function.
For example, vfs_open() will link the file structure to the inode and update mode. Thus we can trace that changes.
# echo 'f vfs_open mode=file->f_mode:x32 inode=file->f_inode:x64' >> dynamic_events
# echo 'f vfs_open%return mode=file->f_mode:x32 inode=file->f_inode:x64' >> dynamic_events
# echo 1 > events/fprobes/enable
# cat trace
sh-131 [006] ...1. 1945.714346: vfs_open__entry: (vfs_open+0x4/0x40) mode=0x2 inode=0x0
sh-131 [006] ...1. 1945.714358: vfs_open__exit: (do_open+0x274/0x3d0 <- vfs_open) mode=0x4d801e inode=0xffff888008470168
cat-143 [007] ...1. 1945.717949: vfs_open__entry: (vfs_open+0x4/0x40) mode=0x1 inode=0x0
cat-143 [007] ...1. 1945.717956: vfs_open__exit: (do_open+0x274/0x3d0 <- vfs_open) mode=0x4a801d inode=0xffff888005f78d28
cat-143 [007] ...1. 1945.720616: vfs_open__entry: (vfs_open+0x4/0x40) mode=0x1 inode=0x0
cat-143 [007] ...1. 1945.728263: vfs_open__exit: (do_open+0x274/0x3d0 <- vfs_open) mode=0xa800d inode=0xffff888004ada8d8So as you can see those fields are initialized at exit.
This series is based on v6.8-rc5 kernel or you can checkout from
https://git.kernel.org/pub/scm/linux/kernel/git/mhiramat/linux.git/log/?h=topic/entry-data
Thank you,
---
Masami Hiramatsu (Google) (8):
fprobe: Fix to allocate entry_data_size buffer with rethook instances tracing/fprobe-event: cleanup: Fix a wrong comment in fprobe event tracing/probes: Cleanup probe argument parser tracing/probes: cleanup: Set trace_probe::nr_args at trace_probe_init
tracing: Remove redundant #else block for BTF args from README tracing/probes: Support $argN in return probe (kprobe and fprobe) selftests/ftrace: Add test cases for entry args at function exit
Documentation: tracing: Add entry argument access at function exit
Documentation/trace/fprobetrace.rst | 31 + Documentation/trace/kprobetrace.rst | 9 kernel/trace/fprobe.c | 14 - kernel/trace/trace.c | 5 kernel/trace/trace_eprobe.c | 8 kernel/trace/trace_fprobe.c | 59 ++- kernel/trace/trace_kprobe.c | 58 ++- kernel/trace/trace_probe.c | 417 ++++++++++++++------ kernel/trace/trace_probe.h | 30 + kernel/trace/trace_probe_tmpl.h | 10 kernel/trace/trace_uprobe.c | 14 - .../ftrace/test.d/dynevent/fprobe_entry_arg.tc | 18 + .../ftrace/test.d/dynevent/fprobe_syntax_errors.tc | 4 .../ftrace/test.d/kprobe/kprobe_syntax_errors.tc | 2 .../ftrace/test.d/kprobe/kretprobe_entry_arg.tc | 18 + 15 files changed, 521 insertions(+), 176 deletions(-) create mode 100644 tools/testing/selftests/ftrace/test.d/dynevent/fprobe_entry_arg.tc create mode 100644 tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_entry_arg.tc
--
Masami Hiramatsu (Google) <[email protected]>
Masami Hiramatsu (Google)
maintainerPATCH v3 1/8 fprobe: Fix to allocate entry_data_size buffer with rethook instances
From: Masami Hiramatsu (Google) <[email protected]>
Fix to allocate fprobe::entry_data_size buffer with rethook instances. If fprobe doesn't allocate entry_data_size buffer for each rethook instance, fprobe entry handler can cause a buffer overrun when storing entry data in entry handler.
--- kernel/trace/fprobe.c | 14 ++++++-------- 1 file changed, 6 insertions(+), 8 deletions(-)
kernel/trace/fprobe.c +6 -8
@@ -189,9 +189,6 @@ static int fprobe_init_rethook(struct fprobe *fp, int num) {int size; -if (num <=0 ) -return -EINVAL ; -if (!fp->exit_handler) { fp->rethook =NULL ;return 0 ;
@@ -199,15 +196,16 @@ static int fprobe_init_rethook(struct fprobe *fp, int num)/* Initialize rethook if needed */ if (fp->nr_maxactive) - size = fp->nr_maxactive; + num = fp->nr_maxactive;else - size = num *num_possible_cpus () *2 ; -if (size <=0 ) + num *=num_possible_cpus () *2 ; +if (num <=0 )return -EINVAL ; + size =sizeof (struct fprobe_rethook_node ) + fp->entry_data_size; +/* Initialize rethook */ - fp->rethook =rethook_alloc ((void *)fp, fprobe_exit_handler, -sizeof (struct fprobe_rethook_node ), size); + fp->rethook =rethook_alloc ((void *)fp, fprobe_exit_handler, size, num);if (IS_ERR (fp->rethook))return PTR_ERR (fp->rethook);
Masami Hiramatsu (Google)
maintainerPATCH v3 2/8 tracing/fprobe-event: cleanup: Fix a wrong comment in fprobe event
In reply to Masami Hiramatsu (Google)From: Masami Hiramatsu (Google) <[email protected]>
Despite the fprobe event, "Kretprobe" was commented. So fix it.
--- kernel/trace/trace_fprobe.c | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-)
kernel/trace/trace_fprobe.c +1 -1
@@ -210,7 +210,7 @@ fentry_trace_func(struct trace_fprobe *tf, unsigned long entry_ip, }NOKPROBE_SYMBOL (fentry_trace_func); -/* Kretprobe handler */ +/* function exit handler */ static nokprobe_inline void __fexit_trace_func(struct trace_fprobe *tf, unsigned long entry_ip, unsigned long ret_ip, struct pt_regs *regs,
Masami Hiramatsu (Google)
maintainerPATCH v3 3/8 tracing/probes: Cleanup probe argument parser
In reply to Masami Hiramatsu (Google)From: Masami Hiramatsu (Google) <[email protected]>
Cleanup traceprobe_parse_probe_arg_body() to split out the type parser and post-processing part of fetch_insn. This makes no functional change.
--- kernel/trace/trace_probe.c | 230 ++++++++++++++++++++++++++------------------ 1 file changed, 137 insertions(+), 93 deletions(-)
kernel/trace/trace_probe.c +137 -93
@@ -1090,67 +1090,45 @@ static int __parse_bitfield_probe_arg(const char *bf,return (BYTES_TO_BITS (t->size) < (bw + bo)) ? -EINVAL :0 ; } -/* String length checking wrapper */ -static int traceprobe_parse_probe_arg_body (const char *argv,ssize_t *size, -struct probe_arg *parg, -struct traceprobe_parse_context *ctx) +/* Split type part from @arg and return it. */ +static char *parse_probe_arg_type (char *arg,struct probe_arg *parg, +struct traceprobe_parse_context *ctx) { -struct fetch_insn *code, *scode, *tmp =NULL ; -char *t, *t2, *t3; -int ret, len; -char *arg; +char *t =NULL , *t2, *t3; +int offs; - arg =kstrdup (argv,GFP_KERNEL ); -if (!arg) -return -ENOMEM ; - - ret = -EINVAL ; - len =strlen (arg); -if (len >MAX_ARGSTR_LEN ) { -trace_probe_log_err (ctx->offset,ARG_TOO_LONG ); - goto out; - }else if (len ==0 ) { -trace_probe_log_err (ctx->offset,NO_ARG_BODY ); - goto out; - } - - ret = -ENOMEM ; - parg->comm =kstrdup (arg,GFP_KERNEL ); -if (!parg->comm) - goto out; - - ret = -EINVAL ; t =strchr (arg,':' );if (t) { - *t ='\0' ; - t2 =strchr (++t,'[' ); + *t++ ='\0' ; + t2 =strchr (t,'[' );if (t2) { *t2++ ='\0' ; t3 =strchr (t2,']' );if (!t3) { -int offs = t2 +strlen (t2) - arg; + offs = t2 +strlen (t2) - arg;trace_probe_log_err (ctx->offset + offs,ARRAY_NO_CLOSE ); - goto out; +return ERR_PTR (-EINVAL ); }else if (t3[1 ] !='\0' ) {trace_probe_log_err (ctx->offset + t3 +1 - arg,BAD_ARRAY_SUFFIX ); - goto out; +return ERR_PTR (-EINVAL ); } *t3 ='\0' ;if (kstrtouint (t2,0 , &parg->count) || !parg->count) {trace_probe_log_err (ctx->offset + t2 - arg,BAD_ARRAY_NUM ); - goto out; +return ERR_PTR (-EINVAL ); }if (parg->count >MAX_ARRAY_LEN ) {trace_probe_log_err (ctx->offset + t2 - arg,ARRAY_TOO_BIG ); - goto out; +return ERR_PTR (-EINVAL ); } } } + offs = t ? t - arg :0 ;/* * Since $comm and immediate string can not be dereferenced,
@@ -1161,74 +1139,52 @@ static int traceprobe_parse_probe_arg_body(const char *argv, ssize_t *size, strncmp(arg, "\\\"", 2) == 0)) {/* The type of $comm must be "string", and not an array type. */ if (parg->count || (t &&strcmp (t,"string" ))) { -trace_probe_log_err (ctx->offset + (t ? (t - arg) :0 ), -NEED_STRING_TYPE ); - goto out; +trace_probe_log_err (ctx->offset + offs,NEED_STRING_TYPE ); +return ERR_PTR (-EINVAL ); } parg->type =find_fetch_type ("string" , ctx->flags); } else parg->type = find_fetch_type(t, ctx->flags); +if (!parg->type) { -trace_probe_log_err (ctx->offset + (t ? (t - arg) :0 ),BAD_TYPE ); - goto out; +trace_probe_log_err (ctx->offset + offs,BAD_TYPE ); +return ERR_PTR (-EINVAL ); } - code = tmp =kcalloc (FETCH_INSN_MAX ,sizeof (*code),GFP_KERNEL ); -if (!code) - goto out; - code[FETCH_INSN_MAX -1 ].op =FETCH_OP_END ; - - ctx->last_type =NULL ; - ret =parse_probe_arg (arg, parg->type, &code, &code[FETCH_INSN_MAX -1 ], - ctx); -if (ret) - goto fail; - -/* Update storing type if BTF is available */ -if (IS_ENABLED (CONFIG_PROBE_EVENTS_BTF_ARGS ) && - ctx->last_type) { -if (!t) { - parg->type =find_fetch_type_from_btf_type (ctx); - }else if (strstr (t,"string" )) { - ret =check_prepare_btf_string_fetch (t, &code, ctx); -if (ret) - goto fail; - } - } - parg->offset = *size; - *size += parg->type->size * (parg->count ?:1 ); +return t; +} -if (parg->count) { - len =strlen (parg->type->fmttype) +6 ; - parg->fmt =kmalloc (len,GFP_KERNEL ); -if (!parg->fmt) { - ret = -ENOMEM ; - goto out; - } -snprintf (parg->fmt, len,"%s[%d]" , parg->type->fmttype, - parg->count); - } +/* After parsing, adjust the fetch_insn according to the probe_arg */ +static int finalize_fetch_insn (struct fetch_insn *code, +struct probe_arg *parg, +char *type, +int type_offset, +struct traceprobe_parse_context *ctx) +{ +struct fetch_insn *scode; +int ret; - ret = -EINVAL ;/* Store operation */ if (parg->type->is_string) { +/* Check bad combination of the type and the last fetch_insn. */ if (!strcmp (parg->type->name,"symstr" )) {if (code->op !=FETCH_OP_REG && code->op !=FETCH_OP_STACK && code->op !=FETCH_OP_RETVAL && code->op !=FETCH_OP_ARG && code->op !=FETCH_OP_DEREF && code->op !=FETCH_OP_TP_ARG ) { -trace_probe_log_err (ctx->offset + (t ? (t - arg) :0 ), +trace_probe_log_err (ctx->offset + type_offset,BAD_SYMSTRING ); - goto fail; +return -EINVAL ; } }else {if (code->op !=FETCH_OP_DEREF && code->op !=FETCH_OP_UDEREF && code->op !=FETCH_OP_IMM && code->op !=FETCH_OP_COMM && code->op !=FETCH_OP_DATA && code->op !=FETCH_OP_TP_ARG ) { -trace_probe_log_err (ctx->offset + (t ? (t - arg) :0 ), +trace_probe_log_err (ctx->offset + type_offset,BAD_STRING ); - goto fail; +return -EINVAL ; } } + if (!strcmp(parg->type->name, "symstr") || (code->op == FETCH_OP_IMM || code->op == FETCH_OP_COMM || code->op == FETCH_OP_DATA) || code->op == FETCH_OP_TP_ARG ||
@@ -1244,9 +1200,10 @@ static int traceprobe_parse_probe_arg_body(const char *argv, ssize_t *size, code++;if (code->op !=FETCH_OP_NOP ) {trace_probe_log_err (ctx->offset,TOO_MANY_OPS ); - goto fail; +return -EINVAL ; } } +/* If op == DEREF, replace it with STRING */ if (!strcmp (parg->type->name,"ustring" ) || code->op ==FETCH_OP_UDEREF )
@@ -1267,47 +1224,134 @@ static int traceprobe_parse_probe_arg_body(const char *argv, ssize_t *size, code++;if (code->op !=FETCH_OP_NOP ) {trace_probe_log_err (ctx->offset,TOO_MANY_OPS ); - goto fail; +return -E2BIG ; } code->op =FETCH_OP_ST_RAW ; code->size = parg->type->size; } + +/* Save storing fetch_insn. */ scode = code; +/* Modify operation */ -if (t !=NULL ) { - ret =__parse_bitfield_probe_arg (t, parg->type, &code); +if (type !=NULL ) { +/* Bitfield needs a special fetch_insn. */ + ret =__parse_bitfield_probe_arg (type, parg->type, &code);if (ret) { -trace_probe_log_err (ctx->offset + t - arg,BAD_BITFIELD ); - goto fail; +trace_probe_log_err (ctx->offset + type_offset,BAD_BITFIELD ); +return ret; } }else if (IS_ENABLED (CONFIG_PROBE_EVENTS_BTF_ARGS ) && ctx->last_type) { +/* If user not specified the type, try parsing BTF bitfield. */ ret =parse_btf_bitfield (&code, ctx);if (ret) - goto fail; +return ret; } - ret = -EINVAL ; +/* Loop(Array) operation */ if (parg->count) {if (scode->op !=FETCH_OP_ST_MEM && scode->op !=FETCH_OP_ST_STRING && scode->op !=FETCH_OP_ST_USTRING ) { -trace_probe_log_err (ctx->offset + (t ? (t - arg) :0 ), -BAD_STRING ); - goto fail; +trace_probe_log_err (ctx->offset + type_offset,BAD_STRING ); +return -EINVAL ; } code++;if (code->op !=FETCH_OP_NOP ) {trace_probe_log_err (ctx->offset,TOO_MANY_OPS ); - goto fail; +return -E2BIG ; } code->op =FETCH_OP_LP_ARRAY ; code->param = parg->count; } + +/* Finalize the fetch_insn array. */ code++; code->op =FETCH_OP_END ; - ret =0 ; +return 0 ; +} + +/* String length checking wrapper */ +static int traceprobe_parse_probe_arg_body (const char *argv,ssize_t *size, +struct probe_arg *parg, +struct traceprobe_parse_context *ctx) +{ +struct fetch_insn *code, *tmp =NULL ; +char *type, *arg; +int ret, len; + + len =strlen (argv); +if (len >MAX_ARGSTR_LEN ) { +trace_probe_log_err (ctx->offset,ARG_TOO_LONG ); +return -E2BIG ; + }else if (len ==0 ) { +trace_probe_log_err (ctx->offset,NO_ARG_BODY ); +return -EINVAL ; + } + + arg =kstrdup (argv,GFP_KERNEL ); +if (!arg) +return -ENOMEM ; + + parg->comm =kstrdup (arg,GFP_KERNEL ); +if (!parg->comm) { + ret = -ENOMEM ; + goto out; + } + + type =parse_probe_arg_type (arg, parg, ctx); +if (IS_ERR (type)) { + ret =PTR_ERR (type); + goto out; + } + + code = tmp =kcalloc (FETCH_INSN_MAX ,sizeof (*code),GFP_KERNEL ); +if (!code) { + ret = -ENOMEM ; + goto out; + } + code[FETCH_INSN_MAX -1 ].op =FETCH_OP_END ; + + ctx->last_type =NULL ; + ret =parse_probe_arg (arg, parg->type, &code, &code[FETCH_INSN_MAX -1 ], + ctx); +if (ret <0 ) + goto fail; + +/* Update storing type if BTF is available */ +if (IS_ENABLED (CONFIG_PROBE_EVENTS_BTF_ARGS ) && + ctx->last_type) { +if (!type) { + parg->type =find_fetch_type_from_btf_type (ctx); + }else if (strstr (type,"string" )) { + ret =check_prepare_btf_string_fetch (type, &code, ctx); +if (ret) + goto fail; + } + } + parg->offset = *size; + *size += parg->type->size * (parg->count ?:1 ); + +if (parg->count) { + len =strlen (parg->type->fmttype) +6 ; + parg->fmt =kmalloc (len,GFP_KERNEL ); +if (!parg->fmt) { + ret = -ENOMEM ; + goto out; + } +snprintf (parg->fmt, len,"%s[%d]" , parg->type->fmttype, + parg->count); + } + + ret =finalize_fetch_insn (code, parg, type, type ? type - arg :0 , ctx); +if (ret <0 ) + goto fail; + +for (; code < tmp +FETCH_INSN_MAX ; code++) +if (code->op ==FETCH_OP_END ) +break ;/* Shrink down the code buffer */ parg->code =kcalloc (code - tmp +1 ,sizeof (*code),GFP_KERNEL );if (!parg->code)
@@ -1316,7 +1360,7 @@ static int traceprobe_parse_probe_arg_body(const char *argv, ssize_t *size,memcpy (parg->code, tmp,sizeof (*code) * (code - tmp +1 )); fail: -if (ret) { +if (ret <0 ) {for (code = tmp; code < tmp +FETCH_INSN_MAX ; code++)if (code->op ==FETCH_NOP_SYMBOL || code->op ==FETCH_OP_DATA )
Masami Hiramatsu (Google)
maintainerPATCH v3 4/8 tracing/probes: cleanup: Set trace_probe::nr_args at trace_probe_init
In reply to Masami Hiramatsu (Google)From: Masami Hiramatsu (Google) <[email protected]>
Instead of incrementing the trace_probe::nr_args, init it at trace_probe_init(). Without this change, there is no way to get the number of trace_probe arguments while parsing it.
This is a cleanup, so the behavior is not changed.
---
Changes in v3:
- Fix build error in trace_{kprobe,fprobe}.c.
- Update changelog.
--- kernel/trace/trace_eprobe.c | 2 +- kernel/trace/trace_fprobe.c | 2 +- kernel/trace/trace_kprobe.c | 2 +- kernel/trace/trace_probe.c | 10 ++++++---- kernel/trace/trace_probe.h | 2 +- kernel/trace/trace_uprobe.c | 2 +- 6 files changed, 11 insertions(+), 9 deletions(-)
kernel/trace/trace_eprobe.c +1 -1
@@ -220,7 +220,7 @@ static struct trace_eprobe *alloc_event_probe(const char *group,if (!ep->event_system) goto error; - ret =trace_probe_init (&ep->tp, this_event, group, false); + ret =trace_probe_init (&ep->tp, this_event, group, false, nargs);if (ret <0 ) goto error;
kernel/trace/trace_fprobe.c +1 -1
@@ -389,7 +389,7 @@ static struct trace_fprobe *alloc_trace_fprobe(const char *group, tf->tpoint = tpoint; tf->fp.nr_maxactive = maxactive; - ret =trace_probe_init (&tf->tp, event, group, false); + ret =trace_probe_init (&tf->tp, event, group, false, nargs);if (ret <0 ) goto error;
kernel/trace/trace_kprobe.c +1 -1
@@ -290,7 +290,7 @@ static struct trace_kprobe *alloc_trace_kprobe(const char *group,INIT_HLIST_NODE (&tk->rp.kp.hlist);INIT_LIST_HEAD (&tk->rp.kp.list); - ret =trace_probe_init (&tk->tp, event, group, false); + ret =trace_probe_init (&tk->tp, event, group, false, nargs);if (ret <0 ) goto error;
kernel/trace/trace_probe.c +6 -4
@@ -1423,9 +1423,6 @@ int traceprobe_parse_probe_arg(struct trace_probe *tp, int i, const char *arg,struct probe_arg *parg = &tp->args[i];const char *body; -/* Increment count for freeing args in error case */ - tp->nr_args++; - body =strchr (arg,'=' );if (body) {if (body - arg >MAX_ARG_NAME_LEN ) {
@@ -1810,7 +1807,7 @@ void trace_probe_cleanup(struct trace_probe *tp) }int trace_probe_init (struct trace_probe *tp,const char *event, -const char *group,bool alloc_filter) +const char *group,bool alloc_filter,int nargs) {struct trace_event_call *call;size_t size =sizeof (struct trace_probe_event );
@@ -1846,6 +1843,11 @@ int trace_probe_init(struct trace_probe *tp, const char *event, goto error; } + tp->nr_args = nargs; +/* Make sure pointers in args[] are NULL */ +if (nargs) +memset (tp->args,0 ,sizeof (tp->args[0 ]) * nargs); +return 0 ; error:
kernel/trace/trace_probe.h +1 -1
@@ -338,7 +338,7 @@ static inline bool trace_probe_has_single_file(struct trace_probe *tp) }int trace_probe_init (struct trace_probe *tp,const char *event, -const char *group,bool alloc_filter); +const char *group,bool alloc_filter,int nargs);void trace_probe_cleanup (struct trace_probe *tp);int trace_probe_append (struct trace_probe *tp,struct trace_probe *to);void trace_probe_unlink (struct trace_probe *tp);
kernel/trace/trace_uprobe.c +1 -1
@@ -337,7 +337,7 @@ alloc_trace_uprobe(const char *group, const char *event, int nargs, bool is_ret)if (!tu)return ERR_PTR (-ENOMEM ); - ret =trace_probe_init (&tu->tp, event, group, true); + ret =trace_probe_init (&tu->tp, event, group, true, nargs);if (ret <0 ) goto error;
Masami Hiramatsu (Google)
maintainerPATCH v3 5/8 tracing: Remove redundant #else block for BTF args from README
In reply to Masami Hiramatsu (Google)From: Masami Hiramatsu (Google) <[email protected]>
Remove redundant #else block for BTF args from README message. This is a cleanup, so no change on the message.
--- kernel/trace/trace.c | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-)
kernel/trace/trace.c +1 -3
@@ -5747,11 +5747,9 @@ static const char readme_msg[] = "\t args: <name>=fetcharg[:type]\n" "\t fetcharg: (%<register>|$<efield>), @<address>, @<symbol>[+|-<offset>],\n" #ifdef CONFIG_HAVE_FUNCTION_ARG_ACCESS_API -#ifdef CONFIG_PROBE_EVENTS_BTF_ARGS "\t $stack<index>, $stack, $retval, $comm, $arg<N>,\n" +#ifdef CONFIG_PROBE_EVENTS_BTF_ARGS "\t <argname>[->field[->field|.field...]],\n" -#else - "\t $stack<index>, $stack, $retval, $comm, $arg<N>,\n" #endif #else"\t $stack<index>, $stack, $retval, $comm,\n"
Masami Hiramatsu (Google)
maintainerPATCH v3 6/8 tracing/probes: Support $argN in return probe (kprobe and fprobe)
In reply to Masami Hiramatsu (Google)From: Masami Hiramatsu (Google) <[email protected]>
Support accessing $argN in the return probe events. This will help users to record entry data in function return (exit) event for simplfing the function entry/exit information in one event, and record the result values (e.g. allocated object/initialized object) at function exit.
For example, if we have a function int init_foo(struct foo *obj, int param) sometimes we want to check how obj is initialized. In such case, we can define a new return event like below;
# echo 'r init_foo retval=$retval param=$arg2 field1=+0($arg1)' >> kprobe_events
Thus it records the function parameter param and its result obj->field1 (the dereference will be done in the function exit timing) value at once.
This also support fprobe, BTF args and'$arg*'. So if CONFIG_DEBUG_INFO_BTF is enabled, we can trace both function parameters and the return value by following command.
# echo 'f target_function%return $arg* $retval' >> dynamic_events
---
Changes in v3:
- Fix syntax error check selftests because now some syntax error will not happen.
Changes in v2:
- Update README message
--- kernel/trace/trace.c | 1 kernel/trace/trace_eprobe.c | 6 - kernel/trace/trace_fprobe.c | 55 ++++-- kernel/trace/trace_kprobe.c | 56 +++++- kernel/trace/trace_probe.c | 177 ++++++++++++++++++-- kernel/trace/trace_probe.h | 28 +++ kernel/trace/trace_probe_tmpl.h | 10 + kernel/trace/trace_uprobe.c | 12 + .../ftrace/test.d/dynevent/fprobe_syntax_errors.tc | 4 .../ftrace/test.d/kprobe/kprobe_syntax_errors.tc | 2 10 files changed, 289 insertions(+), 62 deletions(-)
kernel/trace/trace.c +1 -0
@@ -5755,6 +5755,7 @@ static const char readme_msg[] = "\t $stack<index>, $stack, $retval, $comm,\n"#endif "\t +|-[u]<offset>(<fetcharg>), \\imm-value, \\\"imm-string\"\n" +"\t kernel return probes support: $retval, $arg<N>, $comm\n" "\t type: s8/16/32/64, u8/16/32/64, x8/16/32/64, char, string, symbol,\n" "\t b<bit-width>@<bit-offset>/<container-size>, ustring,\n" "\t symstr, <type>\\[<array-size>\\]\n"
kernel/trace/trace_eprobe.c +3 -3
@@ -390,8 +390,8 @@ static int get_eprobe_size(struct trace_probe *tp, void *rec)/* Note that we don't verify it, since the code does not come from user space */ static int -process_fetch_insn (struct fetch_insn *code,void *rec,void *dest, -void *base) +process_fetch_insn (struct fetch_insn *code,void *rec,void *edata, +void *dest,void *base) {unsigned long val;int ret;
@@ -438,7 +438,7 @@ __eprobe_trace_func(struct eprobe_data *edata, void *rec)return ; entry = fbuffer.entry =ring_buffer_event_data (fbuffer.event); -store_trace_args (&entry[1 ], &edata->ep->tp, rec,sizeof (*entry), dsize); +store_trace_args (&entry[1 ], &edata->ep->tp, rec,NULL ,sizeof (*entry), dsize);trace_event_buffer_commit (&fbuffer); }
kernel/trace/trace_fprobe.c +39 -16
160 lines not on this page · raw message
kernel/trace/trace_kprobe.c +46 -10
134 lines not on this page · raw message
kernel/trace/trace_probe.c +156 -21
238 lines not on this page · raw message
kernel/trace/trace_probe.h +27 -1
@@ -92,6 +92,7 @@ enum fetch_op {FETCH_OP_ARG ,/* Function argument : .param */ FETCH_OP_FOFFS ,/* File offset: .immediate */ FETCH_OP_DATA ,/* Allocated data: .data */ +FETCH_OP_EDATA ,/* Entry data: .offset */ // Stage 2 (dereference) op FETCH_OP_DEREF ,/* Dereference: .offset */ FETCH_OP_UDEREF, /* User-space Dereference: .offset */
@@ -102,6 +103,7 @@ enum fetch_op {FETCH_OP_ST_STRING ,/* String: .offset, .size */ FETCH_OP_ST_USTRING ,/* User String: .offset, .size */ FETCH_OP_ST_SYMSTR ,/* Kernel Symbol String: .offset, .size */ +FETCH_OP_ST_EDATA ,/* Store Entry Data: .offset */ // Stage 4 (modify) op FETCH_OP_MOD_BF, /* Bitfield: .basesize, .lshift, .rshift */// Stage 5 (loop) op
@@ -232,6 +234,11 @@ struct probe_arg {const struct fetch_type *type;/* Type of this argument */ }; +struct probe_entry_arg { +struct fetch_insn *code; +unsigned int size;/* The entry data size */ +}; +struct trace_uprobe_filter {rwlock_t rwlock;int nr_systemwide;
@@ -253,6 +260,7 @@ struct trace_probe {struct trace_probe_event *event;ssize_t size;/* trace entry size */ unsigned int nr_args; +struct probe_entry_arg *entry_arg;/* This is only for return probe */ struct probe_arg args[]; };
@@ -355,6 +363,18 @@ int trace_probe_create(const char *raw_command, int (*createfn)(int, const charint trace_probe_print_args (struct trace_seq *s,struct probe_arg *args,int nr_args,u8 *data,void *field); +#ifdef CONFIG_HAVE_FUNCTION_ARG_ACCESS_API +int traceprobe_get_entry_data_size (struct trace_probe *tp); +/* This is a runtime function to store entry data */ +void store_trace_entry_data (void *edata,struct trace_probe *tp,struct pt_regs *regs); +#else /* !CONFIG_HAVE_FUNCTION_ARG_ACCESS_API */ +static inline int traceprobe_get_entry_data_size (struct trace_probe *tp) +{ +return 0 ; +} +#define store_trace_entry_data (edata, tp, regs) do { } while (0) +#endif +#define trace_probe_for_each_link (pos, tp) \ list_for_each_entry(pos, &(tp)->event->files, list)#define trace_probe_for_each_link_rcu (pos, tp) \
@@ -381,6 +401,11 @@ static inline bool tparg_is_function_entry(unsigned int flags)return (flags &TPARG_FL_LOC_MASK ) == (TPARG_FL_KERNEL |TPARG_FL_FENTRY ); } +static inline bool tparg_is_function_return (unsigned int flags) +{ +return (flags &TPARG_FL_LOC_MASK ) == (TPARG_FL_KERNEL |TPARG_FL_RETURN ); +} +struct traceprobe_parse_context {struct trace_event_call *event;/* BTF related parameters */
@@ -392,6 +417,7 @@ struct traceprobe_parse_context {const struct btf_type *last_type;/* Saved type */ u32 last_bitoffs;/* Saved bitoffs */ u32 last_bitsize;/* Saved bitsize */ +struct trace_probe *tp;unsigned int flags;int offset; };
@@ -506,7 +532,7 @@ extern int traceprobe_define_arg_fields(struct trace_event_call *event_call,C (NO_BTFARG ,"This variable is not found at this probe point" ),\C (NO_BTF_ENTRY ,"No BTF entry for this probe point" ), \C (BAD_VAR_ARGS ,"$arg* must be an independent parameter without name etc." ),\ -C (NOFENTRY_ARGS ,"$arg* can be used only on function entry" ), \ +C (NOFENTRY_ARGS ,"$arg* can be used only on function entry or exit" ), \C (DOUBLE_ARGS ,"$arg* can be used only once in the parameters" ), \C (ARGS_2LONG ,"$arg* failed because the argument list is too long" ), \ C(ARGIDX_2BIG, "$argN index is too big"), \
kernel/trace/trace_probe_tmpl.h +5 -5
@@ -54,7 +54,7 @@ fetch_apply_bitfield(struct fetch_insn *code, void *buf)* If dest is NULL, don't store result and return required dynamic data size. */ static int -process_fetch_insn (struct fetch_insn *code,void *rec, +process_fetch_insn (struct fetch_insn *code,void *rec,void *edata,void *dest,void *base); static nokprobe_inline int fetch_store_strlen(unsigned long addr);static nokprobe_inline int
@@ -232,7 +232,7 @@ process_fetch_insn_bottom(struct fetch_insn *code, unsigned long val,/* Sum up total data length for dynamic arrays (strings) */ static nokprobe_inline int -__get_data_size (struct trace_probe *tp,struct pt_regs *regs) +__get_data_size (struct trace_probe *tp,struct pt_regs *regs,void *edata) {struct probe_arg *arg;int i, len, ret =0 ;
@@ -240,7 +240,7 @@ __get_data_size(struct trace_probe *tp, struct pt_regs *regs)for (i =0 ; i < tp->nr_args; i++) { arg = tp->args + i;if (unlikely (arg->dynamic)) { - len =process_fetch_insn (arg->code, regs,NULL ,NULL ); + len =process_fetch_insn (arg->code, regs, edata,NULL ,NULL );if (len >0 ) ret += len; }
@@ -251,7 +251,7 @@ __get_data_size(struct trace_probe *tp, struct pt_regs *regs)/* Store the value of each argument */ static nokprobe_inline void -store_trace_args (void *data,struct trace_probe *tp,void *rec, +store_trace_args (void *data,struct trace_probe *tp,void *rec,void *edata,int header_size,int maxlen) {struct probe_arg *arg;
@@ -266,7 +266,7 @@ store_trace_args(void *data, struct trace_probe *tp, void *rec,/* Point the dynamic data area if needed */ if (unlikely (arg->dynamic)) *dl =make_data_loc (maxlen, dyndata - base); - ret =process_fetch_insn (arg->code, rec, dl, base); + ret =process_fetch_insn (arg->code, rec, edata, dl, base);if (arg->dynamic &&likely (ret >0 )) { dyndata += ret; maxlen -= ret;
kernel/trace/trace_uprobe.c +6 -6
@@ -211,8 +211,8 @@ static unsigned long translate_user_vaddr(unsigned long file_offset)/* Note that we don't verify it, since the code does not come from user space */ static int -process_fetch_insn (struct fetch_insn *code,void *rec,void *dest, -void *base) +process_fetch_insn (struct fetch_insn *code,void *rec,void *edata, +void *dest,void *base) {struct pt_regs *regs = rec;unsigned long val;
@@ -1490,11 +1490,11 @@ static int uprobe_dispatcher(struct uprobe_consumer *con, struct pt_regs *regs)if (WARN_ON_ONCE (!uprobe_cpu_buffer))return 0 ; - dsize =__get_data_size (&tu->tp, regs); + dsize =__get_data_size (&tu->tp, regs,NULL ); esize =SIZEOF_TRACE_ENTRY (is_ret_probe (tu)); ucb =uprobe_buffer_get (); -store_trace_args (ucb->buf, &tu->tp, regs, esize, dsize); +store_trace_args (ucb->buf, &tu->tp, regs,NULL , esize, dsize);if (trace_probe_test_flag (&tu->tp,TP_FLAG_TRACE )) ret |=uprobe_trace_func (tu, regs, ucb, dsize);
@@ -1525,11 +1525,11 @@ static int uretprobe_dispatcher(struct uprobe_consumer *con,if (WARN_ON_ONCE (!uprobe_cpu_buffer))return 0 ; - dsize =__get_data_size (&tu->tp, regs); + dsize =__get_data_size (&tu->tp, regs,NULL ); esize =SIZEOF_TRACE_ENTRY (is_ret_probe (tu)); ucb =uprobe_buffer_get (); -store_trace_args (ucb->buf, &tu->tp, regs, esize, dsize); +store_trace_args (ucb->buf, &tu->tp, regs,NULL , esize, dsize);if (trace_probe_test_flag (&tu->tp,TP_FLAG_TRACE ))uretprobe_trace_func (tu, func, regs, ucb, dsize);
tools/testing/selftests/ftrace/test.d/dynevent/fprobe_syntax_errors.tc +4 -0
@@ -34,7 +34,9 @@ check_error 'f vfs_read ^$stack10000' # BAD_STACK_NUM check_error 'f vfs_read ^$arg10000' # BAD_ARG_NUM +if !grep -q 'kernel return probes support:' README; then check_error 'f vfs_read $retval ^$arg1' # BAD_VAR +fi check_error 'f vfs_read ^$none_var' # BAD_VAR check_error 'f vfs_read ^'$REG # BAD_VAR
@@ -99,7 +101,9 @@ if grep -q "<argname>" README; then check_error 'f vfs_read args=^$arg*' # BAD_VAR_ARGS check_error 'f vfs_read +0(^$arg*)' # BAD_VAR_ARGS check_error 'f vfs_read $arg* ^$arg*' # DOUBLE_ARGS +if !grep -q 'kernel return probes support:' README; then check_error 'f vfs_read%return ^$arg*' # NOFENTRY_ARGS +fi check_error 'f vfs_read ^hoge' # NO_BTFARG check_error 'f kfree ^$arg10' # NO_BTFARG (exceed the number of parameters) check_error 'f kfree%return ^$retval' # NO_RETVAL
tools/testing/selftests/ftrace/test.d/kprobe/kprobe_syntax_errors.tc +2 -0
@@ -108,7 +108,9 @@ if grep -q "<argname>" README; then check_error 'p vfs_read args=^$arg*' # BAD_VAR_ARGS check_error 'p vfs_read +0(^$arg*)' # BAD_VAR_ARGS check_error 'p vfs_read $arg* ^$arg*' # DOUBLE_ARGS +if !grep -q 'kernel return probes support:' README; then check_error 'r vfs_read ^$arg*' # NOFENTRY_ARGS +fi check_error 'p vfs_read+8 ^$arg*' # NOFENTRY_ARGS check_error 'p vfs_read ^hoge' # NO_BTFARG check_error 'p kfree ^$arg10' # NO_BTFARG (exceed the number of parameters)
Masami Hiramatsu (Google)
maintainerPATCH v3 7/8 selftests/ftrace: Add test cases for entry args at function exit
In reply to Masami Hiramatsu (Google)From: Masami Hiramatsu (Google) <[email protected]>
Add kretprobe and function exit probe test cases for checking whether those can access entry arguments at function exit correctly.
--- .../ftrace/test.d/dynevent/fprobe_entry_arg.tc | 18 ++++++++++++++++++ .../ftrace/test.d/kprobe/kretprobe_entry_arg.tc | 18 ++++++++++++++++++ 2 files changed, 36 insertions(+) create mode 100644 tools/testing/selftests/ftrace/test.d/dynevent/fprobe_entry_arg.tc create mode 100644 tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_entry_arg.tc
tools/testing/selftests/ftrace/test.d/dynevent/fprobe_entry_arg.tc new file +18 -0
@@ -0,0 +1,18 @@ +#!/bin/sh +# SPDX-License-Identifier: GPL-2.0 +# description: Function return probe entry argument access +# requires: dynamic_events 'f[:[<group>/][<event>]] <func-name>':README 'kernel return probes support:':README + +echo 'f:tests/myevent1 vfs_open arg=$arg1' >> dynamic_events +echo 'f:tests/myevent2 vfs_open%return arg=$arg1' >> dynamic_events + +echo 1 > events/tests/enable + +echo > trace +cat trace > /dev/null + +function streq() { + test $1 = $2 +} + +streq `grep -A 1 -m 1 myevent1 trace | sed -r 's/^.*(arg=.*)/\1/' `
tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_entry_arg.tc new file +18 -0
@@ -0,0 +1,18 @@ +#!/bin/sh +# SPDX-License-Identifier: GPL-2.0 +# description: Kretprobe entry argument access +# requires: kprobe_events 'kernel return probes support:':README + +echo 'p:myevent1 vfs_open arg=$arg1' >> kprobe_events +echo 'r:myevent2 vfs_open arg=$arg1' >> kprobe_events + +echo 1 > events/kprobes/enable + +echo > trace +cat trace > /dev/null + +function streq() { + test $1 = $2 +} + +streq `grep -A 1 -m 1 myevent1 trace | sed -r 's/^.*(arg=.*)/\1/' `
Masami Hiramatsu (Google)
maintainerPATCH v3 8/8 Documentation: tracing: Add entry argument access at function exit
In reply to Masami Hiramatsu (Google)From: Masami Hiramatsu (Google) <[email protected]>
Add a notes about the entry argument access at function exit probes for kprobes and fprobe trace event.
---
Changes in v3:
- Add usage example in fprobetrace.rst.
--- Documentation/trace/fprobetrace.rst | 31 +++++++++++++++++++++++++++++++ Documentation/trace/kprobetrace.rst | 9 +++++++++ 2 files changed, 40 insertions(+)
Documentation/trace/fprobetrace.rst +31 -0
@@ -70,6 +70,14 @@ Synopsis of fprobe-events For the details of TYPE, see :ref:`kprobetrace documentation <kprobetrace_types>`. +Function arguments at exit +-------------------------- +Function arguments can be accessed at exit probe using $arg<N> fetcharg. This +is useful to record the function parameter and return value at once, and +trace the difference of structure fields (for debuging a function whether it +correctly updates the given data structure or not) +See the :ref:`sample<fprobetrace_exit_args_sample>` below for how it works. + BTF arguments ------------- BTF (BPF Type Format) argument allows user to trace function and tracepoint
@@ -218,3 +226,26 @@ traceprobe event, you can trace that field as below. <idle>-0 [000] d..3. 5606.690317: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="kworker/0:1" usage=1 start_time=137000000 kworker/0:1-14 [000] d..3. 5606.690339: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="swapper/0" usage=2 start_time=0 <idle>-0 [000] d..3. 5606.692368: sched_switch: (__probestub_sched_switch+0x4/0x10) comm="kworker/0:1" usage=1 start_time=137000000 + +.. _fprobetrace_exit_args_sample: + +The return probe allows us to access the results of some functions, which returns +the error code and its results are passed via function parameter, such as an +structure-initialization function. + +For example, vfs_open() will link the file structure to the inode and update +mode. You can trace that changes with return probe. +:: + + # echo 'f vfs_open mode=file->f_mode:x32 inode=file->f_inode:x64' >> dynamic_events + # echo 'f vfs_open%%return mode=file->f_mode:x32 inode=file->f_inode:x64' >> dynamic_events + # echo 1 > events/fprobes/enable + # cat trace + sh-131 [006] ...1. 1945.714346: vfs_open__entry: (vfs_open+0x4/0x40) mode=0x2 inode=0x0 + sh-131 [006] ...1. 1945.714358: vfs_open__exit: (do_open+0x274/0x3d0 <- vfs_open) mode=0x4d801e inode=0xffff888008470168 + cat-143 [007] ...1. 1945.717949: vfs_open__entry: (vfs_open+0x4/0x40) mode=0x1 inode=0x0 + cat-143 [007] ...1. 1945.717956: vfs_open__exit: (do_open+0x274/0x3d0 <- vfs_open) mode=0x4a801d inode=0xffff888005f78d28 + cat-143 [007] ...1. 1945.720616: vfs_open__entry: (vfs_open+0x4/0x40) mode=0x1 inode=0x0 + cat-143 [007] ...1. 1945.728263: vfs_open__exit: (do_open+0x274/0x3d0 <- vfs_open) mode=0xa800d inode=0xffff888004ada8d8 + +You can see the `file::f_mode` and `file::f_inode` are upated in `vfs_open()`.
Documentation/trace/kprobetrace.rst +9 -0
@@ -70,6 +70,15 @@ Synopsis of kprobe_events (\*3) this is useful for fetching a field of data structures. (\*4) "u" means user-space dereference. See :ref:`user_mem_access`. +Function arguments at kretprobe +------------------------------- +Function arguments can be accessed at kretprobe using $arg<N> fetcharg. This +is useful to record the function parameter and return value at once, and +trace the difference of structure fields (for debuging a function whether it +correctly updates the given data structure or not). +See the :ref:`sample<fprobetrace_exit_args_sample>` in fprobe event for how +it works. + .. _kprobetrace_types: Types