tracing/probes: Support function parameter access from return probe
Subsystems (3)
Masami Hiramatsu (Google)
maintainerv2 cover tracing/probes: Support function parameter access from return probe
Hi,
Here is version 2 series of patches to support accessing function entry data from function *return* probes (including kretprobe and fprobe-exit event).
In this version, I added another cleanup [4/7], updated README[5/7], added testcases[6/7] and updated document[7/7].
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) (7):
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 | 7 Documentation/trace/kprobetrace.rst | 7 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/kprobe/kretprobe_entry_arg.tc | 18 + 12 files changed, 483 insertions(+), 168 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 v2 1/7 tracing/fprobe-event: cleanup: Fix a wrong comment in fprobe event
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,
Re: [PATCH v2 1/7] tracing/fprobe-event: cleanup: Fix a wrong comment in fprobe event
Quoted 5 lines · On Mon, 26 Feb 2024 12:58:03 +0900 "Masami Hiramatsu (Google)"…
From: Masami Hiramatsu (Google) <[email protected]>
Despite the fprobe event, "Kretprobe" was commented. So fix it.
Signed-off-by Masami Hiramatsu (Google) <[email protected]>
-- Steve
Quoted 17 lines
--- 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 v2 2/7 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 )
Re: [PATCH v2 2/7] tracing/probes: Cleanup probe argument parser
Quoted 7 lines · On Mon, 26 Feb 2024 12:58:13 +0900 "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 offetch_insn. This makes no functional change.Signed-off-by Masami Hiramatsu (Google) <[email protected]>
-- Steve
Quoted 3 lines
--- kernel/trace/trace_probe.c | 230 ++++++++++++++++++++++++++------------------ 1 file changed, 137 insertions(+), 93 deletions(-)
Masami Hiramatsu (Google)
maintainerPATCH v2 3/7 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(). This is a cleanup, so the behavior is not changed.
--- kernel/trace/trace_eprobe.c | 2 +- kernel/trace/trace_probe.c | 10 ++++++---- kernel/trace/trace_probe.h | 2 +- kernel/trace/trace_uprobe.c | 2 +- 4 files changed, 9 insertions(+), 7 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_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;
Re: [PATCH v2 3/7] tracing/probes: cleanup: Set trace_probe::nr_args at trace_probe_init
Quoted 4 lines · On Mon, 26 Feb 2024 12:58:23 +0900 "Masami Hiramatsu (Google)"…
From: Masami Hiramatsu (Google) <[email protected]>
Instead of incrementing the
trace_probe::nr_args, init it attrace_probe_init(). This is a cleanup, so the behavior is not changed.
The change is fine, but the change log does not say why this was done.
-- Steve
Quoted 3 lines
Signed-off-by Masami Hiramatsu (Google) <[email protected]>---
Masami Hiramatsu (Google)
maintainerRe: [PATCH v2 3/7] tracing/probes: cleanup: Set trace_probe::nr_args at trace_probe_init
Quoted 9 lines · On Thu, 29 Feb 2024 22:37:53 -0500 Steven Rostedt <[email protected]> wrote:
Quoted 4 lines · On Mon, 26 Feb 2024 12:58:23 +0900 "Masami Hiramatsu (Google)"…
From: Masami Hiramatsu (Google) <[email protected]>
Instead of incrementing the
trace_probe::nr_args, init it attrace_probe_init(). This is a cleanup, so the behavior is not changed.The change is fine, but the change log does not say why this was done.
This change is to get the number of trace_probe arguments while parsing the argument strings.
Thank you,
Quoted 9 lines
Reviewed-by Steven Rostedt (Google) <[email protected]>-- Steve
Quoted 3 lines
Signed-off-by Masami Hiramatsu (Google) <[email protected]>---
Signature · 1 line
Masami Hiramatsu (Google) <[email protected]>
Masami Hiramatsu (Google)
maintainerPATCH v2 4/7 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"
Re: [PATCH v2 4/7] tracing: Remove redundant #else block for BTF args from README
Quoted 4 lines · On Mon, 26 Feb 2024 12:58:33 +0900 "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.
-- Steve
Quoted 3 lines
Signed-off-by Masami Hiramatsu (Google) <[email protected]>---
Masami Hiramatsu (Google)
maintainerPATCH v2 5/7 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 v2:
- Update README message
--- kernel/trace/trace.c | 1 kernel/trace/trace_eprobe.c | 6 + kernel/trace/trace_fprobe.c | 57 +++++++++---- kernel/trace/trace_kprobe.c | 58 ++++++++++--- 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 +-- 8 files changed, 285 insertions(+), 64 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 +40 -17
168 lines not on this page · raw message
kernel/trace/trace_kprobe.c +47 -11
142 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);
Masami Hiramatsu (Google)
maintainerPATCH v2 6/7 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 v2 7/7 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.
--- Documentation/trace/fprobetrace.rst | 7 +++++++ Documentation/trace/kprobetrace.rst | 7 +++++++ 2 files changed, 14 insertions(+)
Documentation/trace/fprobetrace.rst +7 -0
@@ -70,6 +70,13 @@ 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) + BTF arguments ------------- BTF (BPF Type Format) argument allows user to trace function and tracepoint
Documentation/trace/kprobetrace.rst +7 -0
@@ -70,6 +70,13 @@ 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) + .. _kprobetrace_types: Types
Quoted 15 lines · Masami Hiramatsu (Google)
Hi,
Here is version 2 series of patches to support accessing function entry data from function *return* probes (including kretprobe and fprobe-exit event).
In this version, I added another cleanup [4/7], updated README[5/7], added testcases[6/7] and updated document[7/7].
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.
Quoted 10 lines
# 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=0xffff888004ada8d8hi,
I hit a crash while playing with this, by runnning:
# echo 'f vfs_read%return $arg*' >> dynamic_events # echo 1 > events/fprobes/enable
jirka
---
[ 86.805519][ T712] general protection fault, probably for non-canonical address 0xef01a20a8bd21200: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC NOPTI [ 86.807259][ T712] CPU: 0 PID: 712 Comm: cat Not tainted 6.8.0-rc5+ #432 b8184d32457f2dd20b7178757a1fce97b3f847e2 [ 86.808417][ T712] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-1.fc38 04/01/2014 [ 86.809294][ T712] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.809930][ T712] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.811727][ T712] RSP: 0018:ffffc90001e0bdf8 EFLAGS: 00010286 [ 86.812316][ T712] RAX: ffffc90001e0bef0 RBX: ffff8881775999a0 RCX: ffffc90001e0be40 [ 86.813106][ T712] RDX: ffffffff81545129 RSI: 0000000000000000 RDI: ffff888177599990 [ 86.813881][ T712] RBP: ffff8881775999a0 R08: 0000000000000000 R09: ffff88810246af00 [ 86.814626][ T712] R10: 0000000000000001 R11: 0000000000000000 R12: ffffffff81545129 [ 86.815357][ T712] R13: ef01a20a8bd21200 R14: ffffc90001e0bee8 R15: ffffc90001e0be40 [ 86.816114][ T712] FS: 00007f22d7c1f740(0000) GS:ffff88846ce00000(0000) knlGS:0000000000000000 [ 86.816885][ T712] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.817455][ T712] CR2: 00007f22d7b9c000 CR3: 0000000176918001 CR4: 0000000000770ef0 [ 86.818221][ T712] PKRU: 55555554 [ 86.818579][ T712] Call Trace: [ 86.818900][ T712] <TASK> [ 86.819194][ T712] ? die_addr+0x32/0x80 [ 86.819583][ T712] ? exc_general_protection+0x276/0x4d0 [ 86.820079][ T712] ? asm_exc_general_protection+0x22/0x30 [ 86.820600][ T712] ? ksys_read+0x69/0xf0 [ 86.821022][ T712] ? ksys_read+0x69/0xf0 [ 86.821422][ T712] ? rethook_trampoline_handler+0x8e/0x200 [ 86.821984][ T712] ? rethook_trampoline_handler+0x91/0x200 [ 86.822539][ T712] arch_rethook_trampoline_callback+0x36/0x50 [ 86.823097][ T712] arch_rethook_trampoline+0x2c/0x60 [ 86.823584][ T712] ? ksys_read+0x69/0xf0 [ 86.823962][ T712] osnoise_arch_unregister+0x210/0x210 [ 86.824463][ T712] do_syscall_64+0x87/0x1b0 [ 86.824910][ T712] entry_SYSCALL_64_after_hwframe+0x6e/0x76 [ 86.825418][ T712] RIP: 0033:0x7f22d7d230b1 [ 86.825859][ T712] Code: d5 fe ff ff 55 48 8d 3d 25 47 0a 00 48 89 e5 e8 b5 18 02 00 0f 1f 44 00 00 f3 0f 1e fa 80 3d 2d b5 0d 00 00 74 13 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 4f c3 66 0f 1f 44 00 00 55 48 89 e5 48 83 ec [ 86.827635][ T712] RSP: 002b:00007fffdaaef668 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 86.828355][ T712] RAX: ffffffffffffffda RBX: 0000000000020000 RCX: 00007f22d7d230b1 [ 86.829017][ T712] RDX: 0000000000020000 RSI: 00007f22d7b9c000 RDI: 0000000000000003 [ 86.829710][ T712] RBP: 00007fffdaaef690 R08: 00000000ffffffff R09: 0000000000000000 [ 86.831165][ T712] R10: 0000000000000022 R11: 0000000000000246 R12: 0000000000020000 [ 86.831910][ T712] R13: 00007f22d7b9c000 R14: 0000000000000003 R15: 0000000000000000 [ 86.832691][ T712] </TASK> [ 86.833016][ T712] Modules linked in: intel_rapl_msr intel_rapl_common crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel kvm_intel rapl iTCO_wdt iTCO_vendor_support i2c_i801 i2c_smbus lpc_ich drm loop drm_panel_orientation_quirks zram [ 86.835078][ T634] general protection fault, probably for non-canonical address 0x440038d965baf00: 0000 [#2] PREEMPT SMP DEBUG_PAGEALLOC NOPTI [ 86.835196][ T712] ---[ end trace 0000000000000000 ]--- [ 86.835943][ T634] CPU: 3 PID: 634 Comm: sshd Tainted: G D 6.8.0-rc5+ #432 b8184d32457f2dd20b7178757a1fce97b3f847e2 [ 86.835946][ T634] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-1.fc38 04/01/2014 [ 86.835947][ T634] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.835952][ T634] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.836363][ T712] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.837090][ T634] RSP: 0018:ffffc90001d3bdf8 EFLAGS: 00010206 [ 86.837776][ T712] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.838205][ T634] [ 86.839488][ T712] RSP: 0018:ffffc90001e0bdf8 EFLAGS: 00010286 [ 86.839890][ T634] RAX: ffffc90001d3bef0 RBX: ffff888176cbbaa0 RCX: ffffc90001d3be40 [ 86.840239][ T712] [ 86.840240][ T712] RAX: ffffc90001e0bef0 RBX: ffff8881775999a0 RCX: ffffc90001e0be40 [ 86.841309][ T634] RDX: ffffffff81545129 RSI: 0000000000000000 RDI: ffff888176cbba90 [ 86.841311][ T634] RBP: ffff888176cbbaa0 R08: 0000000000000001 R09: 0000000000000000 [ 86.841312][ T634] R10: 0000000000000001 R11: 0000000000000001 R12: ffffffff81545129 [ 86.841313][ T634] R13: 0440038d965baf00 R14: ffffc90001d3bee8 R15: ffffc90001d3be40 [ 86.841314][ T634] FS: 00007f1ddf838940(0000) GS:ffff88846da00000(0000) knlGS:0000000000000000 [ 86.841316][ T634] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.841477][ T712] RDX: ffffffff81545129 RSI: 0000000000000000 RDI: ffff888177599990 [ 86.841800][ T634] CR2: 0000559fb5f9f000 CR3: 0000000176e2e004 CR4: 0000000000770ef0 [ 86.842308][ T712] RBP: ffff8881775999a0 R08: 0000000000000000 R09: ffff88810246af00 [ 86.842456][ T634] PKRU: 55555554 [ 86.842458][ T634] Call Trace: [ 86.842459][ T634] <TASK> [ 86.842462][ T634] ? die_addr+0x32/0x80 [ 86.842978][ T712] R10: 0000000000000001 R11: 0000000000000000 R12: ffffffff81545129 [ 86.843508][ T634] ? exc_general_protection+0x276/0x4d0 [ 86.843516][ T634] ? asm_exc_general_protection+0x22/0x30 [ 86.844002][ T712] R13: ef01a20a8bd21200 R14: ffffc90001e0bee8 R15: ffffc90001e0be40 [ 86.844004][ T712] FS: 00007f22d7c1f740(0000) GS:ffff88846ce00000(0000) knlGS:0000000000000000 [ 86.844503][ T634] ? ksys_read+0x69/0xf0 [ 86.844507][ T634] ? ksys_read+0x69/0xf0 [ 86.844510][ T634] ? rethook_trampoline_handler+0x8e/0x200 [ 86.845033][ T712] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.845677][ T634] ? rethook_trampoline_handler+0x91/0x200 [ 86.845680][ T634] arch_rethook_trampoline_callback+0x36/0x50 [ 86.845684][ T634] arch_rethook_trampoline+0x2c/0x60 [ 86.846111][ T712] CR2: 00007f22d7b9c000 CR3: 0000000176918001 CR4: 0000000000770ef0 [ 86.846674][ T634] ? ksys_read+0x69/0xf0 [ 86.846679][ T634] osnoise_arch_unregister+0x210/0x210 [ 86.847213][ T712] PKRU: 55555554 [ 86.847648][ T634] do_syscall_64+0x87/0x1b0 [ 86.847653][ T634] entry_SYSCALL_64_after_hwframe+0x6e/0x76 [ 86.847868][ T712] note: cat[712] exited with preempt_count 1 [ 86.848096][ T634] RIP: 0033:0x7f1ddfc4a0b1 [ 86.869351][ T634] Code: d5 fe ff ff 55 48 8d 3d 25 47 0a 00 48 89 e5 e8 b5 18 02 00 0f 1f 44 00 00 f3 0f 1e fa 80 3d 2d b5 0d 00 00 74 13 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 4f c3 66 0f 1f 44 00 00 55 48 89 e5 48 83 ec [ 86.871186][ T634] RSP: 002b:00007fffdd061ae8 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 86.871995][ T634] RAX: ffffffffffffffda RBX: 0000000000008000 RCX: 00007f1ddfc4a0b1 [ 86.872785][ T634] RDX: 0000000000008000 RSI: 000055bbb41e37b0 RDI: 000000000000000c [ 86.873553][ T634] RBP: 00007fffdd061b50 R08: 0000000000000000 R09: 0000000000000000 [ 86.874320][ T634] R10: 0000000000000001 R11: 0000000000000246 R12: 0000000000000000 [ 86.874960][ T634] R13: 0000000000000000 R14: 000055bbb4172840 R15: 000000000000000c [ 86.875670][ T634] </TASK> [ 86.875964][ T634] Modules linked in: intel_rapl_msr intel_rapl_common crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel kvm_intel rapl iTCO_wdt iTCO_vendor_support i2c_i801 i2c_smbus lpc_ich drm loop drm_panel_orientation_quirks zram [ 86.877814][ T634] ---[ end trace 0000000000000000 ]--- [ 86.877991][ T450] kernel tried to execute NX-protected page - exploit attempt? (uid: 0) [ 86.878210][ T634] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.878217][ T634] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.878219][ T634] RSP: 0018:ffffc90001e0bdf8 EFLAGS: 00010286 [ 86.878221][ T634] RAX: ffffc90001e0bef0 RBX: ffff8881775999a0 RCX: ffffc90001e0be40 [ 86.878222][ T634] RDX: ffffffff81545129 RSI: 0000000000000000 RDI: ffff888177599990 [ 86.878224][ T634] RBP: ffff8881775999a0 R08: 0000000000000000 R09: ffff88810246af00 [ 86.878225][ T634] R10: 0000000000000001 R11: 0000000000000000 R12: ffffffff81545129 [ 86.878226][ T634] R13: ef01a20a8bd21200 R14: ffffc90001e0bee8 R15: ffffc90001e0be40 [ 86.878227][ T634] FS: 00007f1ddf838940(0000) GS:ffff88846da00000(0000) knlGS:0000000000000000 [ 86.878228][ T634] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.878230][ T634] CR2: 0000559fb5f9f000 CR3: 0000000176e2e004 CR4: 0000000000770ef0 [ 86.878233][ T634] PKRU: 55555554 [ 86.878235][ T634] note: sshd[634] exited with preempt_count 1 [ 86.888492][ T450] BUG: unable to handle page fault for address: ffffc90001cdff58 [ 86.889266][ T450] #PF: supervisor instruction fetch in kernel mode [ 86.889914][ T450] #PF: error_code(0x0011) - permissions violation [ 86.891248][ T450] PGD 100000067 P4D 100000067 PUD 102a49067 PMD 10b3ee067 PTE 8000000109295163 [ 86.892032][ T450] Oops: 0011 [#3] PREEMPT SMP DEBUG_PAGEALLOC NOPTI [ 86.892560][ T450] CPU: 1 PID: 450 Comm: systemd-journal Tainted: G D 6.8.0-rc5+ #432 b8184d32457f2dd20b7178757a1fce97b3f847e2 [ 86.893758][ T450] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-1.fc38 04/01/2014 [ 86.894542][ T450] RIP: 0010:0xffffc90001cdff58 [ 86.894964][ T450] Code: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 e6 00 60 82 ff ff ff ff <00> 00 00 00 00 00 00 00 03 00 00 00 00 00 00 00 00 00 00 00 00 00 [ 86.896519][ T450] RSP: 0018:ffffc90000b13df0 EFLAGS: 00010282 [ 86.897004][ T450] RAX: ffffc90001cdfef0 RBX: ffff88817759a8a0 RCX: ffffc90000b13e40 [ 86.897672][ T450] RDX: ffffffff81545129 RSI: ffffffffffffffff RDI: ffff88817759a890 [ 86.898341][ T450] RBP: ffff88817759a8a0 R08: 0000000000000001 R09: ffff888102b2c470 [ 86.899143][ T450] R10: ffffc90000b13e58 R11: ffffffff83976548 R12: ffffffff81545129 [ 86.899871][ T450] R13: ffffc90001cdff58 R14: ffffc90000b13ee8 R15: ffffc90000b13e40 [ 86.900547][ T450] FS: 00007f20a7635940(0000) GS:ffff88846d200000(0000) knlGS:0000000000000000 [ 86.901259][ T450] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.901773][ T450] CR2: ffffc90001cdff58 CR3: 0000000176a7a003 CR4: 0000000000770ef0 [ 86.902411][ T450] PKRU: 55555554 [ 86.902722][ T450] Call Trace: [ 86.903009][ T450] <TASK> [ 86.903271][ T450] ? __die+0x1f/0x70 [ 86.903613][ T450] ? page_fault_oops+0x176/0x4d0 [ 86.904126][ T450] ? exc_page_fault+0x16c/0x250 [ 86.904614][ T450] ? asm_exc_page_fault+0x22/0x30 [ 86.905140][ T450] ? ksys_read+0x69/0xf0 [ 86.905615][ T450] ? ksys_read+0x69/0xf0 [ 86.906053][ T450] ? rethook_trampoline_handler+0x91/0x200 [ 86.906643][ T450] ? arch_rethook_trampoline_callback+0x36/0x50 [ 86.907271][ T450] ? arch_rethook_trampoline+0x2c/0x60 [ 86.907845][ T450] ? ksys_read+0x69/0xf0 [ 86.908300][ T450] ? osnoise_arch_unregister+0x210/0x210 [ 86.908781][ T450] ? do_syscall_64+0x87/0x1b0 [ 86.909186][ T450] ? entry_SYSCALL_64_after_hwframe+0x6e/0x76 [ 86.909681][ T450] </TASK> [ 86.909959][ T450] Modules linked in: intel_rapl_msr intel_rapl_common crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel kvm_intel rapl iTCO_wdt iTCO_vendor_support i2c_i801 i2c_smbus lpc_ich drm loop drm_panel_orientation_quirks zram [ 86.911681][ T450] CR2: ffffc90001cdff58 [ 86.912108][ T450] ---[ end trace 0000000000000000 ]--- [ 86.912674][ T450] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.913232][ T450] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.914702][ T450] RSP: 0018:ffffc90001e0bdf8 EFLAGS: 00010286 [ 86.915196][ T450] RAX: ffffc90001e0bef0 RBX: ffff8881775999a0 RCX: ffffc90001e0be40 [ 86.915853][ T450] RDX: ffffffff81545129 RSI: 0000000000000000 RDI: ffff888177599990 [ 86.916644][ T450] RBP: ffff8881775999a0 R08: 0000000000000000 R09: ffff88810246af00 [ 86.917449][ T450] R10: 0000000000000001 R11: 0000000000000000 R12: ffffffff81545129 [ 86.918238][ T450] R13: ef01a20a8bd21200 R14: ffffc90001e0bee8 R15: ffffc90001e0be40 [ 86.919043][ T450] FS: 00007f20a7635940(0000) GS:ffff88846d200000(0000) knlGS:0000000000000000 [ 86.919906][ T450] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.921265][ T450] CR2: ffffc90001cdff58 CR3: 0000000176a7a003 CR4: 0000000000770ef0 [ 86.921972][ T450] PKRU: 55555554 [ 86.922365][ T450] note: systemd-journal[450] exited with irqs disabled [ 86.923076][ T450] note: systemd-journal[450] exited with preempt_count 1 [ 86.927597][ T47] audit: type=1106 audit(1709132147.391:266): pid=619 uid=0 auid=1000 ses=1 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=PAM:session_close grantors=pam_selinux,pam_loginuid,pam_selinux,pam_namespace,pam_keyinit,pam_keyinit,pam_limits,pam_systemd,pam_unix,pam_umask,pam_lastlog acct="jolsa" exe="/usr/sbin/sshd" hostname=192.168.122.1 addr=192.168.122.1 terminal=ssh res=success' [ 86.928777][ T450] systemd-journal (450) used greatest stack depth: 11424 bytes left [ 86.929578][ T1] general protection fault, probably for non-canonical address 0xd4f06e07d9d64800: 0000 [#4] PREEMPT SMP DEBUG_PAGEALLOC NOPTI [ 86.929582][ T1] CPU: 2 PID: 1 Comm: systemd Tainted: G D 6.8.0-rc5+ #432 b8184d32457f2dd20b7178757a1fce97b3f847e2 [ 86.929584][ T1] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-1.fc38 04/01/2014 [ 86.929586][ T1] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.929591][ T1] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.929592][ T1] RSP: 0018:ffffc90000013df8 EFLAGS: 00010286 [ 86.929594][ T1] RAX: ffffc90000013ef0 RBX: ffff888177598aa0 RCX: ffffc90000013e40 [ 86.929595][ T1] RDX: ffffffff81545129 RSI: 0000000000000010 RDI: ffff888177598a90 [ 86.929596][ T1] RBP: ffff888177598aa0 R08: 0000000000000010 R09: ffff888175005750 [ 86.929597][ T1] R10: 0000000000000000 R11: ffffc90000013dd8 R12: ffffffff81545129 [ 86.929598][ T1] R13: d4f06e07d9d64800 R14: ffffc90000013ee8 R15: ffffc90000013e40 [ 86.929599][ T1] FS: 00007f0ec5012940(0000) GS:ffff88846d600000(0000) knlGS:0000000000000000 [ 86.929600][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.929601][ T1] CR2: 00005595e83bf5b0 CR3: 000000010805e001 CR4: 0000000000770ef0 [ 86.929604][ T1] PKRU: 55555554 [ 86.929605][ T1] Call Trace: [ 86.929606][ T1] <TASK> [ 86.929606][ T1] ? die_addr+0x32/0x80 [ 86.929610][ T1] ? exc_general_protection+0x276/0x4d0 [ 86.929616][ T1] ? asm_exc_general_protection+0x22/0x30 [ 86.929621][ T1] ? ksys_read+0x69/0xf0 [ 86.929624][ T1] ? ksys_read+0x69/0xf0 [ 86.929627][ T1] ? rethook_trampoline_handler+0x8e/0x200 [ 86.929629][ T1] ? rethook_trampoline_handler+0x91/0x200 [ 86.929631][ T1] arch_rethook_trampoline_callback+0x36/0x50 [ 86.929635][ T1] arch_rethook_trampoline+0x2c/0x60 [ 86.929639][ T1] ? ksys_read+0x69/0xf0 [ 86.929640][ T1] osnoise_arch_unregister+0x210/0x210 [ 86.929643][ T1] do_syscall_64+0x87/0x1b0 [ 86.929645][ T1] entry_SYSCALL_64_after_hwframe+0x6e/0x76 [ 86.929647][ T1] RIP: 0033:0x7f0ec49230ea [ 86.929653][ T1] Code: 55 48 89 e5 48 83 ec 20 48 89 55 e8 48 89 75 f0 89 7d f8 e8 e8 79 f8 ff 48 8b 55 e8 48 8b 75 f0 41 89 c0 8b 7d f8 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 2e 44 89 c7 48 89 45 f8 e8 42 7a f8 ff 48 8b [ 86.929655][ T1] RSP: 002b:00007ffead1dc7a0 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 86.929656][ T1] RAX: ffffffffffffffda RBX: 00005625bff4efe0 RCX: 00007f0ec49230ea [ 86.929657][ T1] RDX: 0000000000000400 RSI: 00005625bfeda010 RDI: 0000000000000019 [ 86.929658][ T1] RBP: 00007ffead1dc7c0 R08: 0000000000000000 R09: 0000000000000001 [ 86.929659][ T1] R10: 0000000000001000 R11: 0000000000000246 R12: 00007f0ec49f3660 [ 86.929659][ T1] R13: 00007f0ec50127d0 R14: 0000000000000a68 R15: 00007f0ec49f2d60 [ 86.929663][ T1] </TASK> [ 86.929663][ T1] Modules linked in: intel_rapl_msr intel_rapl_common crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel kvm_intel rapl iTCO_wdt iTCO_vendor_support i2c_i801 i2c_smbus lpc_ich drm loop drm_panel_orientation_quirks zram [ 86.929676][ T1] ---[ end trace 0000000000000000 ]--- [ 86.929677][ T1] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.929679][ T1] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.929680][ T1] RSP: 0018:ffffc90001e0bdf8 EFLAGS: 00010286 [ 86.929681][ T1] RAX: ffffc90001e0bef0 RBX: ffff8881775999a0 RCX: ffffc90001e0be40 [ 86.929682][ T1] RDX: ffffffff81545129 RSI: 0000000000000000 RDI: ffff888177599990 [ 86.929683][ T1] RBP: ffff8881775999a0 R08: 0000000000000000 R09: ffff88810246af00 [ 86.929684][ T1] R10: 0000000000000001 R11: 0000000000000000 R12: ffffffff81545129 [ 86.929685][ T1] R13: ef01a20a8bd21200 R14: ffffc90001e0bee8 R15: ffffc90001e0be40 [ 86.929686][ T1] FS: 00007f0ec5012940(0000) GS:ffff88846d600000(0000) knlGS:0000000000000000 [ 86.929687][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.929688][ T1] CR2: 00005595e83bf5b0 CR3: 000000010805e001 CR4: 0000000000770ef0 [ 86.929688][ T1] PKRU: 55555554 [ 86.929689][ T1] note: systemd[1] exited with preempt_count 1 [ 86.929692][ T1] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b [ 86.929992][ T1] Kernel Offset: disabled
Masami Hiramatsu (Google)
maintainerQuoted 27 lines · On Wed, 28 Feb 2024 17:23:34 +0100 Jiri Olsa <[email protected]> wrote:
Quoted 15 lines · Masami Hiramatsu (Google)
Hi,
Here is version 2 series of patches to support accessing function entry data from function *return* probes (including kretprobe and fprobe-exit event).
In this version, I added another cleanup [4/7], updated README[5/7], added testcases[6/7] and updated document[7/7].
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.Quoted 10 lines
# 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
Quoted 5 lines
hi,
I hit a crash while playing with this, by runnning:# echo 'f vfs_read%return $arg*' >> dynamic_events # echo 1 > events/fprobes/enable
Thanks for reporting! But I can not reproduce it.
Can you share your kconfig?
Quoted 226 lines
jirka
---
[ 86.805519][ T712] general protection fault, probably for non-canonical address 0xef01a20a8bd21200: 0000 [#1] PREEMPT SMP DEBUG_PAGEALLOC NOPTI [ 86.807259][ T712] CPU: 0 PID: 712 Comm: cat Not tainted 6.8.0-rc5+ #432 b8184d32457f2dd20b7178757a1fce97b3f847e2 [ 86.808417][ T712] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-1.fc38 04/01/2014 [ 86.809294][ T712] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.809930][ T712] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.811727][ T712] RSP: 0018:ffffc90001e0bdf8 EFLAGS: 00010286 [ 86.812316][ T712] RAX: ffffc90001e0bef0 RBX: ffff8881775999a0 RCX: ffffc90001e0be40 [ 86.813106][ T712] RDX: ffffffff81545129 RSI: 0000000000000000 RDI: ffff888177599990 [ 86.813881][ T712] RBP: ffff8881775999a0 R08: 0000000000000000 R09: ffff88810246af00 [ 86.814626][ T712] R10: 0000000000000001 R11: 0000000000000000 R12: ffffffff81545129 [ 86.815357][ T712] R13: ef01a20a8bd21200 R14: ffffc90001e0bee8 R15: ffffc90001e0be40 [ 86.816114][ T712] FS: 00007f22d7c1f740(0000) GS:ffff88846ce00000(0000) knlGS:0000000000000000 [ 86.816885][ T712] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.817455][ T712] CR2: 00007f22d7b9c000 CR3: 0000000176918001 CR4: 0000000000770ef0 [ 86.818221][ T712] PKRU: 55555554 [ 86.818579][ T712] Call Trace: [ 86.818900][ T712] <TASK> [ 86.819194][ T712] ? die_addr+0x32/0x80 [ 86.819583][ T712] ? exc_general_protection+0x276/0x4d0 [ 86.820079][ T712] ? asm_exc_general_protection+0x22/0x30 [ 86.820600][ T712] ? ksys_read+0x69/0xf0 [ 86.821022][ T712] ? ksys_read+0x69/0xf0 [ 86.821422][ T712] ? rethook_trampoline_handler+0x8e/0x200 [ 86.821984][ T712] ? rethook_trampoline_handler+0x91/0x200 [ 86.822539][ T712] arch_rethook_trampoline_callback+0x36/0x50 [ 86.823097][ T712] arch_rethook_trampoline+0x2c/0x60 [ 86.823584][ T712] ? ksys_read+0x69/0xf0 [ 86.823962][ T712] osnoise_arch_unregister+0x210/0x210 [ 86.824463][ T712] do_syscall_64+0x87/0x1b0 [ 86.824910][ T712] entry_SYSCALL_64_after_hwframe+0x6e/0x76 [ 86.825418][ T712] RIP: 0033:0x7f22d7d230b1 [ 86.825859][ T712] Code: d5 fe ff ff 55 48 8d 3d 25 47 0a 00 48 89 e5 e8 b5 18 02 00 0f 1f 44 00 00 f3 0f 1e fa 80 3d 2d b5 0d 00 00 74 13 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 4f c3 66 0f 1f 44 00 00 55 48 89 e5 48 83 ec [ 86.827635][ T712] RSP: 002b:00007fffdaaef668 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 86.828355][ T712] RAX: ffffffffffffffda RBX: 0000000000020000 RCX: 00007f22d7d230b1 [ 86.829017][ T712] RDX: 0000000000020000 RSI: 00007f22d7b9c000 RDI: 0000000000000003 [ 86.829710][ T712] RBP: 00007fffdaaef690 R08: 00000000ffffffff R09: 0000000000000000 [ 86.831165][ T712] R10: 0000000000000022 R11: 0000000000000246 R12: 0000000000020000 [ 86.831910][ T712] R13: 00007f22d7b9c000 R14: 0000000000000003 R15: 0000000000000000 [ 86.832691][ T712] </TASK> [ 86.833016][ T712] Modules linked in: intel_rapl_msr intel_rapl_common crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel kvm_intel rapl iTCO_wdt iTCO_vendor_support i2c_i801 i2c_smbus lpc_ich drm loop drm_panel_orientation_quirks zram [ 86.835078][ T634] general protection fault, probably for non-canonical address 0x440038d965baf00: 0000 [#2] PREEMPT SMP DEBUG_PAGEALLOC NOPTI [ 86.835196][ T712] ---[ end trace 0000000000000000 ]--- [ 86.835943][ T634] CPU: 3 PID: 634 Comm: sshd Tainted: G D 6.8.0-rc5+ #432 b8184d32457f2dd20b7178757a1fce97b3f847e2 [ 86.835946][ T634] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-1.fc38 04/01/2014 [ 86.835947][ T634] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.835952][ T634] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.836363][ T712] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.837090][ T634] RSP: 0018:ffffc90001d3bdf8 EFLAGS: 00010206 [ 86.837776][ T712] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.838205][ T634] [ 86.839488][ T712] RSP: 0018:ffffc90001e0bdf8 EFLAGS: 00010286 [ 86.839890][ T634] RAX: ffffc90001d3bef0 RBX: ffff888176cbbaa0 RCX: ffffc90001d3be40 [ 86.840239][ T712] [ 86.840240][ T712] RAX: ffffc90001e0bef0 RBX: ffff8881775999a0 RCX: ffffc90001e0be40 [ 86.841309][ T634] RDX: ffffffff81545129 RSI: 0000000000000000 RDI: ffff888176cbba90 [ 86.841311][ T634] RBP: ffff888176cbbaa0 R08: 0000000000000001 R09: 0000000000000000 [ 86.841312][ T634] R10: 0000000000000001 R11: 0000000000000001 R12: ffffffff81545129 [ 86.841313][ T634] R13: 0440038d965baf00 R14: ffffc90001d3bee8 R15: ffffc90001d3be40 [ 86.841314][ T634] FS: 00007f1ddf838940(0000) GS:ffff88846da00000(0000) knlGS:0000000000000000 [ 86.841316][ T634] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.841477][ T712] RDX: ffffffff81545129 RSI: 0000000000000000 RDI: ffff888177599990 [ 86.841800][ T634] CR2: 0000559fb5f9f000 CR3: 0000000176e2e004 CR4: 0000000000770ef0 [ 86.842308][ T712] RBP: ffff8881775999a0 R08: 0000000000000000 R09: ffff88810246af00 [ 86.842456][ T634] PKRU: 55555554 [ 86.842458][ T634] Call Trace: [ 86.842459][ T634] <TASK> [ 86.842462][ T634] ? die_addr+0x32/0x80 [ 86.842978][ T712] R10: 0000000000000001 R11: 0000000000000000 R12: ffffffff81545129 [ 86.843508][ T634] ? exc_general_protection+0x276/0x4d0 [ 86.843516][ T634] ? asm_exc_general_protection+0x22/0x30 [ 86.844002][ T712] R13: ef01a20a8bd21200 R14: ffffc90001e0bee8 R15: ffffc90001e0be40 [ 86.844004][ T712] FS: 00007f22d7c1f740(0000) GS:ffff88846ce00000(0000) knlGS:0000000000000000 [ 86.844503][ T634] ? ksys_read+0x69/0xf0 [ 86.844507][ T634] ? ksys_read+0x69/0xf0 [ 86.844510][ T634] ? rethook_trampoline_handler+0x8e/0x200 [ 86.845033][ T712] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.845677][ T634] ? rethook_trampoline_handler+0x91/0x200 [ 86.845680][ T634] arch_rethook_trampoline_callback+0x36/0x50 [ 86.845684][ T634] arch_rethook_trampoline+0x2c/0x60 [ 86.846111][ T712] CR2: 00007f22d7b9c000 CR3: 0000000176918001 CR4: 0000000000770ef0 [ 86.846674][ T634] ? ksys_read+0x69/0xf0 [ 86.846679][ T634] osnoise_arch_unregister+0x210/0x210 [ 86.847213][ T712] PKRU: 55555554 [ 86.847648][ T634] do_syscall_64+0x87/0x1b0 [ 86.847653][ T634] entry_SYSCALL_64_after_hwframe+0x6e/0x76 [ 86.847868][ T712] note: cat[712] exited with preempt_count 1 [ 86.848096][ T634] RIP: 0033:0x7f1ddfc4a0b1 [ 86.869351][ T634] Code: d5 fe ff ff 55 48 8d 3d 25 47 0a 00 48 89 e5 e8 b5 18 02 00 0f 1f 44 00 00 f3 0f 1e fa 80 3d 2d b5 0d 00 00 74 13 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 4f c3 66 0f 1f 44 00 00 55 48 89 e5 48 83 ec [ 86.871186][ T634] RSP: 002b:00007fffdd061ae8 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 86.871995][ T634] RAX: ffffffffffffffda RBX: 0000000000008000 RCX: 00007f1ddfc4a0b1 [ 86.872785][ T634] RDX: 0000000000008000 RSI: 000055bbb41e37b0 RDI: 000000000000000c [ 86.873553][ T634] RBP: 00007fffdd061b50 R08: 0000000000000000 R09: 0000000000000000 [ 86.874320][ T634] R10: 0000000000000001 R11: 0000000000000246 R12: 0000000000000000 [ 86.874960][ T634] R13: 0000000000000000 R14: 000055bbb4172840 R15: 000000000000000c [ 86.875670][ T634] </TASK> [ 86.875964][ T634] Modules linked in: intel_rapl_msr intel_rapl_common crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel kvm_intel rapl iTCO_wdt iTCO_vendor_support i2c_i801 i2c_smbus lpc_ich drm loop drm_panel_orientation_quirks zram [ 86.877814][ T634] ---[ end trace 0000000000000000 ]--- [ 86.877991][ T450] kernel tried to execute NX-protected page - exploit attempt? (uid: 0) [ 86.878210][ T634] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.878217][ T634] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.878219][ T634] RSP: 0018:ffffc90001e0bdf8 EFLAGS: 00010286 [ 86.878221][ T634] RAX: ffffc90001e0bef0 RBX: ffff8881775999a0 RCX: ffffc90001e0be40 [ 86.878222][ T634] RDX: ffffffff81545129 RSI: 0000000000000000 RDI: ffff888177599990 [ 86.878224][ T634] RBP: ffff8881775999a0 R08: 0000000000000000 R09: ffff88810246af00 [ 86.878225][ T634] R10: 0000000000000001 R11: 0000000000000000 R12: ffffffff81545129 [ 86.878226][ T634] R13: ef01a20a8bd21200 R14: ffffc90001e0bee8 R15: ffffc90001e0be40 [ 86.878227][ T634] FS: 00007f1ddf838940(0000) GS:ffff88846da00000(0000) knlGS:0000000000000000 [ 86.878228][ T634] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.878230][ T634] CR2: 0000559fb5f9f000 CR3: 0000000176e2e004 CR4: 0000000000770ef0 [ 86.878233][ T634] PKRU: 55555554 [ 86.878235][ T634] note: sshd[634] exited with preempt_count 1 [ 86.888492][ T450] BUG: unable to handle page fault for address: ffffc90001cdff58 [ 86.889266][ T450] #PF: supervisor instruction fetch in kernel mode [ 86.889914][ T450] #PF: error_code(0x0011) - permissions violation [ 86.891248][ T450] PGD 100000067 P4D 100000067 PUD 102a49067 PMD 10b3ee067 PTE 8000000109295163 [ 86.892032][ T450] Oops: 0011 [#3] PREEMPT SMP DEBUG_PAGEALLOC NOPTI [ 86.892560][ T450] CPU: 1 PID: 450 Comm: systemd-journal Tainted: G D 6.8.0-rc5+ #432 b8184d32457f2dd20b7178757a1fce97b3f847e2 [ 86.893758][ T450] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-1.fc38 04/01/2014 [ 86.894542][ T450] RIP: 0010:0xffffc90001cdff58 [ 86.894964][ T450] Code: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 e6 00 60 82 ff ff ff ff <00> 00 00 00 00 00 00 00 03 00 00 00 00 00 00 00 00 00 00 00 00 00 [ 86.896519][ T450] RSP: 0018:ffffc90000b13df0 EFLAGS: 00010282 [ 86.897004][ T450] RAX: ffffc90001cdfef0 RBX: ffff88817759a8a0 RCX: ffffc90000b13e40 [ 86.897672][ T450] RDX: ffffffff81545129 RSI: ffffffffffffffff RDI: ffff88817759a890 [ 86.898341][ T450] RBP: ffff88817759a8a0 R08: 0000000000000001 R09: ffff888102b2c470 [ 86.899143][ T450] R10: ffffc90000b13e58 R11: ffffffff83976548 R12: ffffffff81545129 [ 86.899871][ T450] R13: ffffc90001cdff58 R14: ffffc90000b13ee8 R15: ffffc90000b13e40 [ 86.900547][ T450] FS: 00007f20a7635940(0000) GS:ffff88846d200000(0000) knlGS:0000000000000000 [ 86.901259][ T450] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.901773][ T450] CR2: ffffc90001cdff58 CR3: 0000000176a7a003 CR4: 0000000000770ef0 [ 86.902411][ T450] PKRU: 55555554 [ 86.902722][ T450] Call Trace: [ 86.903009][ T450] <TASK> [ 86.903271][ T450] ? __die+0x1f/0x70 [ 86.903613][ T450] ? page_fault_oops+0x176/0x4d0 [ 86.904126][ T450] ? exc_page_fault+0x16c/0x250 [ 86.904614][ T450] ? asm_exc_page_fault+0x22/0x30 [ 86.905140][ T450] ? ksys_read+0x69/0xf0 [ 86.905615][ T450] ? ksys_read+0x69/0xf0 [ 86.906053][ T450] ? rethook_trampoline_handler+0x91/0x200 [ 86.906643][ T450] ? arch_rethook_trampoline_callback+0x36/0x50 [ 86.907271][ T450] ? arch_rethook_trampoline+0x2c/0x60 [ 86.907845][ T450] ? ksys_read+0x69/0xf0 [ 86.908300][ T450] ? osnoise_arch_unregister+0x210/0x210 [ 86.908781][ T450] ? do_syscall_64+0x87/0x1b0 [ 86.909186][ T450] ? entry_SYSCALL_64_after_hwframe+0x6e/0x76 [ 86.909681][ T450] </TASK> [ 86.909959][ T450] Modules linked in: intel_rapl_msr intel_rapl_common crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel kvm_intel rapl iTCO_wdt iTCO_vendor_support i2c_i801 i2c_smbus lpc_ich drm loop drm_panel_orientation_quirks zram [ 86.911681][ T450] CR2: ffffc90001cdff58 [ 86.912108][ T450] ---[ end trace 0000000000000000 ]--- [ 86.912674][ T450] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.913232][ T450] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.914702][ T450] RSP: 0018:ffffc90001e0bdf8 EFLAGS: 00010286 [ 86.915196][ T450] RAX: ffffc90001e0bef0 RBX: ffff8881775999a0 RCX: ffffc90001e0be40 [ 86.915853][ T450] RDX: ffffffff81545129 RSI: 0000000000000000 RDI: ffff888177599990 [ 86.916644][ T450] RBP: ffff8881775999a0 R08: 0000000000000000 R09: ffff88810246af00 [ 86.917449][ T450] R10: 0000000000000001 R11: 0000000000000000 R12: ffffffff81545129 [ 86.918238][ T450] R13: ef01a20a8bd21200 R14: ffffc90001e0bee8 R15: ffffc90001e0be40 [ 86.919043][ T450] FS: 00007f20a7635940(0000) GS:ffff88846d200000(0000) knlGS:0000000000000000 [ 86.919906][ T450] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.921265][ T450] CR2: ffffc90001cdff58 CR3: 0000000176a7a003 CR4: 0000000000770ef0 [ 86.921972][ T450] PKRU: 55555554 [ 86.922365][ T450] note: systemd-journal[450] exited with irqs disabled [ 86.923076][ T450] note: systemd-journal[450] exited with preempt_count 1 [ 86.927597][ T47] audit: type=1106 audit(1709132147.391:266): pid=619 uid=0 auid=1000 ses=1 subj=system_u:system_r:sshd_t:s0-s0:c0.c1023 msg='op=PAM:session_close grantors=pam_selinux,pam_loginuid,pam_selinux,pam_namespace,pam_keyinit,pam_keyinit,pam_limits,pam_systemd,pam_unix,pam_umask,pam_lastlog acct="jolsa" exe="/usr/sbin/sshd" hostname=192.168.122.1 addr=192.168.122.1 terminal=ssh res=success' [ 86.928777][ T450] systemd-journal (450) used greatest stack depth: 11424 bytes left [ 86.929578][ T1] general protection fault, probably for non-canonical address 0xd4f06e07d9d64800: 0000 [#4] PREEMPT SMP DEBUG_PAGEALLOC NOPTI [ 86.929582][ T1] CPU: 2 PID: 1 Comm: systemd Tainted: G D 6.8.0-rc5+ #432 b8184d32457f2dd20b7178757a1fce97b3f847e2 [ 86.929584][ T1] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS 1.16.2-1.fc38 04/01/2014 [ 86.929586][ T1] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.929591][ T1] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.929592][ T1] RSP: 0018:ffffc90000013df8 EFLAGS: 00010286 [ 86.929594][ T1] RAX: ffffc90000013ef0 RBX: ffff888177598aa0 RCX: ffffc90000013e40 [ 86.929595][ T1] RDX: ffffffff81545129 RSI: 0000000000000010 RDI: ffff888177598a90 [ 86.929596][ T1] RBP: ffff888177598aa0 R08: 0000000000000010 R09: ffff888175005750 [ 86.929597][ T1] R10: 0000000000000000 R11: ffffc90000013dd8 R12: ffffffff81545129 [ 86.929598][ T1] R13: d4f06e07d9d64800 R14: ffffc90000013ee8 R15: ffffc90000013e40 [ 86.929599][ T1] FS: 00007f0ec5012940(0000) GS:ffff88846d600000(0000) knlGS:0000000000000000 [ 86.929600][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.929601][ T1] CR2: 00005595e83bf5b0 CR3: 000000010805e001 CR4: 0000000000770ef0 [ 86.929604][ T1] PKRU: 55555554 [ 86.929605][ T1] Call Trace: [ 86.929606][ T1] <TASK> [ 86.929606][ T1] ? die_addr+0x32/0x80 [ 86.929610][ T1] ? exc_general_protection+0x276/0x4d0 [ 86.929616][ T1] ? asm_exc_general_protection+0x22/0x30 [ 86.929621][ T1] ? ksys_read+0x69/0xf0 [ 86.929624][ T1] ? ksys_read+0x69/0xf0 [ 86.929627][ T1] ? rethook_trampoline_handler+0x8e/0x200 [ 86.929629][ T1] ? rethook_trampoline_handler+0x91/0x200 [ 86.929631][ T1] arch_rethook_trampoline_callback+0x36/0x50 [ 86.929635][ T1] arch_rethook_trampoline+0x2c/0x60 [ 86.929639][ T1] ? ksys_read+0x69/0xf0 [ 86.929640][ T1] osnoise_arch_unregister+0x210/0x210 [ 86.929643][ T1] do_syscall_64+0x87/0x1b0 [ 86.929645][ T1] entry_SYSCALL_64_after_hwframe+0x6e/0x76 [ 86.929647][ T1] RIP: 0033:0x7f0ec49230ea [ 86.929653][ T1] Code: 55 48 89 e5 48 83 ec 20 48 89 55 e8 48 89 75 f0 89 7d f8 e8 e8 79 f8 ff 48 8b 55 e8 48 8b 75 f0 41 89 c0 8b 7d f8 31 c0 0f 05 <48> 3d 00 f0 ff ff 77 2e 44 89 c7 48 89 45 f8 e8 42 7a f8 ff 48 8b [ 86.929655][ T1] RSP: 002b:00007ffead1dc7a0 EFLAGS: 00000246 ORIG_RAX: 0000000000000000 [ 86.929656][ T1] RAX: ffffffffffffffda RBX: 00005625bff4efe0 RCX: 00007f0ec49230ea [ 86.929657][ T1] RDX: 0000000000000400 RSI: 00005625bfeda010 RDI: 0000000000000019 [ 86.929658][ T1] RBP: 00007ffead1dc7c0 R08: 0000000000000000 R09: 0000000000000001 [ 86.929659][ T1] R10: 0000000000001000 R11: 0000000000000246 R12: 00007f0ec49f3660 [ 86.929659][ T1] R13: 00007f0ec50127d0 R14: 0000000000000a68 R15: 00007f0ec49f2d60 [ 86.929663][ T1] </TASK> [ 86.929663][ T1] Modules linked in: intel_rapl_msr intel_rapl_common crct10dif_pclmul crc32_pclmul crc32c_intel ghash_clmulni_intel kvm_intel rapl iTCO_wdt iTCO_vendor_support i2c_i801 i2c_smbus lpc_ich drm loop drm_panel_orientation_quirks zram [ 86.929676][ T1] ---[ end trace 0000000000000000 ]--- [ 86.929677][ T1] RIP: 0010:rethook_trampoline_handler+0x8e/0x200 [ 86.929679][ T1] Code: 5e 20 00 48 8b a8 c8 2a 00 00 48 85 ed 75 2f e9 8b 00 00 00 4d 85 ed 74 17 48 8b 45 08 48 8d 7d f0 4c 89 f9 4c 89 e2 48 8b 30 <41> ff d5 0f 1f 00 48 39 dd 74 6a 48 8b 6d 00 48 85 ed 74 61 4c 39 [ 86.929680][ T1] RSP: 0018:ffffc90001e0bdf8 EFLAGS: 00010286 [ 86.929681][ T1] RAX: ffffc90001e0bef0 RBX: ffff8881775999a0 RCX: ffffc90001e0be40 [ 86.929682][ T1] RDX: ffffffff81545129 RSI: 0000000000000000 RDI: ffff888177599990 [ 86.929683][ T1] RBP: ffff8881775999a0 R08: 0000000000000000 R09: ffff88810246af00 [ 86.929684][ T1] R10: 0000000000000001 R11: 0000000000000000 R12: ffffffff81545129 [ 86.929685][ T1] R13: ef01a20a8bd21200 R14: ffffc90001e0bee8 R15: ffffc90001e0be40 [ 86.929686][ T1] FS: 00007f0ec5012940(0000) GS:ffff88846d600000(0000) knlGS:0000000000000000 [ 86.929687][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 86.929688][ T1] CR2: 00005595e83bf5b0 CR3: 000000010805e001 CR4: 0000000000770ef0 [ 86.929688][ T1] PKRU: 55555554 [ 86.929689][ T1] note: systemd[1] exited with preempt_count 1 [ 86.929692][ T1] Kernel panic - not syncing: Attempted to kill init! exitcode=0x0000000b [ 86.929992][ T1] Kernel Offset: disabled
Signature · 1 line
Masami Hiramatsu (Google) <[email protected]>
Masami Hiramatsu (Google)
maintainerQuoted 30 lines · On Thu, 29 Feb 2024 14:51:39 +0900 Masami Hiramatsu (Google)…
Quoted 27 lines · On Wed, 28 Feb 2024 17:23:34 +0100 Jiri Olsa <[email protected]> wrote:
Quoted 25 lines · Masami Hiramatsu (Google)
Hi,
Here is version 2 series of patches to support accessing function entry data from function *return* probes (including kretprobe and fprobe-exit event).
In this version, I added another cleanup [4/7], updated README[5/7], added testcases[6/7] and updated document[7/7].
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=0xffff888004ada8d8
Quoted 8 lines
Quoted 5 lines
hi,
I hit a crash while playing with this, by runnning:# echo 'f vfs_read%return $arg*' >> dynamic_events # echo 1 > events/fprobes/enableThanks for reporting! But I can not reproduce it.
Can you share your kconfig?
No problem, I could reproduce it.
/sys/kernel/tracing # echo 'f vfs_read%return $arg* $retval' >> dynamic_events /sys/kernel/tracing # echo 1 > events/fprobes/enable /sys/kernel/tracing #/sys/kernel/tracing # [ 67.709725] general protection fault, maybe for address 0xffffc9000047bef8: 0000 [#1] PREEMPT SMP PTI
[ 67.714672] CPU: 5 PID: 132 Comm: sh Tainted: G N 6.8.0-rc5-00007-gd5e41e4cee7e #149 [ 67.716491] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.15.0-1 04/01/2014 [ 67.718036] RIP: 0010:__x86_indirect_thunk_r13+0xa/0x20 [ 67.719087] Code: e8 01 00 00 00 cc 4c 89 24 24 c3 cc cc cc cc 66 66 2e 0f 1f 84 00 00 00 00 00 66 0f 1f 44 00 00 e8 01 00 00 00 cc 4c 89 2c 24 <c3> cc cc cc cc 66 66 2e 0f 1f 84 00 00 00 00 00 66 0f 1f 44 00 00 [ 67.722314] RSP: 0018:ffffc9000047bdf0 EFLAGS: 00010286 [ 67.723251] RAX: ffffc9000047bef8 RBX: ffff8880073258e0 RCX: ffffc9000047be48 [ 67.724704] RDX: ffffffff813aba09 RSI: 0000000000000000 RDI: ffff8880073258d0 [ 67.725840] RBP: ffff8880073258e0 R08: 0000000000000000 R09: ffff888005053648 [ 67.727017] R10: ffff888008452388 R11: 0000000000000001 R12: ffffffff813aba09 [ 67.728107] R13: 9c73d7ba3660c600 R14: ffffc9000047bef0 R15: ffffc9000047be48 [ 67.729630] FS: 000000000115d8c0(0000) GS:ffff88807d940000(0000) knlGS:0000000000000000 [ 67.731231] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 67.732285] CR2: 00000000005a2319 CR3: 0000000005ad6000 CR4: 00000000000006b0 [ 67.733502] Call Trace: [ 67.734013] <TASK> [ 67.734504] ? die_addr+0x37/0x90 [ 67.735307] ? exc_general_protection+0x1ac/0x3f0 [ 67.736158] ? asm_exc_general_protection+0x26/0x30 [ 67.736984] ? ksys_read+0x69/0xf0 [ 67.737559] ? ksys_read+0x69/0xf0 [ 67.738142] ? __x86_indirect_thunk_r13+0xa/0x20 [ 67.739160] ? rethook_trampoline_handler+0x95/0x200 [ 67.739919] ? arch_rethook_trampoline_callback+0x3a/0x50 [ 67.740665] ? arch_rethook_trampoline+0x2c/0x60 [ 67.741362] ? ksys_read+0x69/0xf0 [ 67.741980] ? trace_clock_x86_tsc+0x20/0x20 [ 67.742662] ? do_syscall_64+0xcc/0x1e0 [ 67.743289] ? entry_SYSCALL_64_after_hwframe+0x6f/0x77 [ 67.744620] </TASK> [ 67.745044] Modules linked in: [ 67.745559] ---[ end trace 0000000000000000 ]--- [ 67.746221] RIP: 0010:__x86_indirect_thunk_r13+0xa/0x20 [ 67.746927] Code: e8 01 00 00 00 cc 4c 89 24 24 c3 cc cc cc cc 66 66 2e 0f 1f 84 00 00 00 00 00 66 0f 1f 44 00 00 e8 01 00 00 00 cc 4c 89 2c 24 <c3> cc cc cc cc 66 66 2e 0f 1f 84 00 00 00 00 00 66 0f 1f 44 00 00 [ 67.749176] RSP: 0018:ffffc9000047bdf0 EFLAGS: 00010286 [ 67.749835] RAX: ffffc9000047bef8 RBX: ffff8880073258e0 RCX: ffffc9000047be48 [ 67.750687] RDX: ffffffff813aba09 RSI: 0000000000000000 RDI: ffff8880073258d0 [ 67.751880] RBP: ffff8880073258e0 R08: 0000000000000000 R09: ffff888005053648 [ 67.752810] R10: ffff888008452388 R11: 0000000000000001 R12: ffffffff813aba09 [ 67.753721] R13: 9c73d7ba3660c600 R14: ffffc9000047bef0 R15: ffffc9000047be48 [ 67.754554] FS: 000000000115d8c0(0000) GS:ffff88807d940000(0000) knlGS:0000000000000000 [ 67.755568] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 67.756278] CR2: 00000000005a2319 CR3: 0000000005ad6000 CR4: 00000000000006b0 [ 67.757089] Kernel panic - not syncing: Fatal exception [ 67.757917] Kernel Offset: disabled [ 67.758404] ---[ end Kernel panic - not syncing: Fatal exception ]---
Hmm, this seems arch_rethook_trampoline caused the issue.
And curiously, it depends on the number of stored data.
OK:/sys/kernel/tracing # echo 'f vfs_read%return $arg1 $arg2 $arg3' >> dynamic_events /sys/kernel/tracing # echo 1 > events/fprobes/enable
NG:/sys/kernel/tracing # echo 'f vfs_read%return $arg1 $arg2 $arg3 $arg4' >> dynamic_events /sys/kernel/tracing # echo 1 > events/fprobes/enable
I also confirmed that on 'vfs_write' caused the same result. 3 arguments(24 bytes) is OK, but 4 arguments (32bytes) is NG.
Thank you,
Signature · 1 line
Masami Hiramatsu (Google) <[email protected]>
Masami Hiramatsu (Google)
maintainerQuoted 8 lines · On Thu, 29 Feb 2024 15:38:55 +0900 Masami Hiramatsu (Google)…
Hmm, this seems
arch_rethook_trampolinecaused the issue.And curiously, it depends on the number of stored data.
OK:
/sys/kernel/tracing# echo 'f vfs_read%return $arg1 $arg2 $arg3' >>dynamic_events/sys/kernel/tracing# echo 1 > events/fprobes/enable
Quoted 6 lines
NG:
/sys/kernel/tracing# echo 'f vfs_read%return $arg1 $arg2 $arg3 $arg4' >>dynamic_events/sys/kernel/tracing# echo 1 > events/fprobes/enableI also confirmed that on '
vfs_write' caused the same result. 3 arguments(24 bytes) is OK, but 4 arguments (32bytes) is NG.
And this may be the fprobe bug. kretprobe events doesn't show this issue.
OK:/sys/kernel/tracing # echo 'r vfs_read $arg*' >> kprobe_events /sys/kernel/tracing # echo 1 > events/kprobes/enable
But this is strange because both uses same rethook...
Thank you,
Signature · 1 line
Masami Hiramatsu (Google) <[email protected]>
Masami Hiramatsu (Google)
maintainerQuoted 18 lines · On Thu, 29 Feb 2024 16:13:20 +0900 Masami Hiramatsu (Google)…
Quoted 8 lines · On Thu, 29 Feb 2024 15:38:55 +0900 Masami Hiramatsu (Google)…
Hmm, this seems
arch_rethook_trampolinecaused the issue.And curiously, it depends on the number of stored data.
OK:
/sys/kernel/tracing# echo 'f vfs_read%return $arg1 $arg2 $arg3' >>dynamic_events/sys/kernel/tracing# echo 1 > events/fprobes/enableQuoted 6 lines
NG:
/sys/kernel/tracing# echo 'f vfs_read%return $arg1 $arg2 $arg3 $arg4' >>dynamic_events/sys/kernel/tracing# echo 1 > events/fprobes/enableI also confirmed that on '
vfs_write' caused the same result. 3 arguments(24 bytes) is OK, but 4 arguments (32bytes) is NG.
Quoted 7 lines
And this may be the fprobe bug. kretprobe events doesn't show this issue.
OK:
/sys/kernel/tracing# echo 'rvfs_read$arg*' >>kprobe_events/sys/kernel/tracing# echo 1 > events/kprobes/enableBut this is strange because both uses same rethook...
Lol, I haven't allocate the entry data size when initialize rethook. That's a bug.
Please try below.
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);
Signature · 1 line
Masami Hiramatsu (Google) <[email protected]>
Steven Rostedt
maintainerQuoted 3 lines · On Thu, 29 Feb 2024 17:52:16 +0900 Masami Hiramatsu (Google)…
Lol, I haven't allocate the entry data size when initialize rethook. That's a bug.
Please try below.
I'll wait to review patches 5,6,7 as I'm guessing this will have a v3?
-- Steve
Masami Hiramatsu (Google)
maintainerQuoted 8 lines · On Thu, 29 Feb 2024 22:41:34 -0500 Steven Rostedt <[email protected]> wrote:
Quoted 3 lines · On Thu, 29 Feb 2024 17:52:16 +0900 Masami Hiramatsu (Google)…
Lol, I haven't allocate the entry data size when initialize rethook. That's a bug.
Please try below.I'll wait to review patches 5,6,7 as I'm guessing this will have a v3?
Ah, actually I pushed this fix separately because it is an actual bug and may silently cause an issue in the selftest. I pushed it in probes-fixes-v6.8-rc5.
Anyway, let me send v3 it with that fix.
Thank you,
Quoted 3 lines
-- Steve
Signature · 1 line
Masami Hiramatsu (Google) <[email protected]>