[PATCH v2 0/7] tracing/probes: Support function parameter access from return probe

[PATCH v2 0/7] tracing/probes: Support function parameter access from return probe

[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

So 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) <mhiramat@kernel.org>

[PATCH v2 1/7] tracing/fprobe-event: cleanup: Fix a wrong comment in fprobe event

[Masami Hiramatsu (Google)]

From: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Despite the fprobe event,  "Kretprobe" was commented. So fix it.

Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
 kernel/trace/trace_fprobe.c |    2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/kernel/trace/trace_fprobe.c b/kernel/trace/trace_fprobe.c
index 7d2ddbcfa377..3ccef4d82235 100644
--- a/kernel/trace/trace_fprobe.c
+++ b/kernel/trace/trace_fprobe.c
@@ -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

[Steven Rostedt]

On Mon, 26 Feb 2024 12:58:03 +0900
"Masami Hiramatsu (Google)" <mhiramat@kernel.org> wrote:

> From: Masami Hiramatsu (Google) <mhiramat@kernel.org>
> 
> Despite the fprobe event,  "Kretprobe" was commented. So fix it.
> 
> Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Reviewed-by: Steven Rostedt (Google) <rostedt@goodmis.org>

-- Steve

> ---
>  kernel/trace/trace_fprobe.c |    2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/kernel/trace/trace_fprobe.c b/kernel/trace/trace_fprobe.c
> index 7d2ddbcfa377..3ccef4d82235 100644
> --- a/kernel/trace/trace_fprobe.c
> +++ b/kernel/trace/trace_fprobe.c
> @@ -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,

[PATCH v2 2/7] tracing/probes: Cleanup probe argument parser

[Masami Hiramatsu (Google)]

From: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Cleanup traceprobe_parse_probe_arg_body() to split out the
type parser and post-processing part of fetch_insn.
This makes no functional change.

Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
 kernel/trace/trace_probe.c |  230 ++++++++++++++++++++++++++------------------
 1 file changed, 137 insertions(+), 93 deletions(-)

diff --git a/kernel/trace/trace_probe.c b/kernel/trace/trace_probe.c
index 34289f9c6707..67a0b9cbb648 100644
--- a/kernel/trace/trace_probe.c
+++ b/kernel/trace/trace_probe.c
@@ -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

[Steven Rostedt]

On Mon, 26 Feb 2024 12:58:13 +0900
"Masami Hiramatsu (Google)" <mhiramat@kernel.org> wrote:

> From: Masami Hiramatsu (Google) <mhiramat@kernel.org>
> 
> Cleanup traceprobe_parse_probe_arg_body() to split out the
> type parser and post-processing part of fetch_insn.
> This makes no functional change.
> 
> Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Reviewed-by: Steven Rostedt (Google) <rostedt@goodmis.org>

-- Steve

> ---
>  kernel/trace/trace_probe.c |  230 ++++++++++++++++++++++++++------------------
>  1 file changed, 137 insertions(+), 93 deletions(-)

[PATCH v2 3/7] tracing/probes: cleanup: Set trace_probe::nr_args at trace_probe_init

[Masami Hiramatsu (Google)]

From: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Instead of incrementing the trace_probe::nr_args, init it at trace_probe_init().
This is a cleanup, so the behavior is not changed.

Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
 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(-)

diff --git a/kernel/trace/trace_eprobe.c b/kernel/trace/trace_eprobe.c
index 03c851f57969..eb72def7410f 100644
--- a/kernel/trace/trace_eprobe.c
+++ b/kernel/trace/trace_eprobe.c
@@ -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;
 
diff --git a/kernel/trace/trace_probe.c b/kernel/trace/trace_probe.c
index 67a0b9cbb648..93f36f8a108e 100644
--- a/kernel/trace/trace_probe.c
+++ b/kernel/trace/trace_probe.c
@@ -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:
diff --git a/kernel/trace/trace_probe.h b/kernel/trace/trace_probe.h
index c1877d018269..ed8d1052f8a7 100644
--- a/kernel/trace/trace_probe.h
+++ b/kernel/trace/trace_probe.h
@@ -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);
diff --git a/kernel/trace/trace_uprobe.c b/kernel/trace/trace_uprobe.c
index a84b85d8aac1..796ebcae9b38 100644
--- a/kernel/trace/trace_uprobe.c
+++ b/kernel/trace/trace_uprobe.c
@@ -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

[Steven Rostedt]

On Mon, 26 Feb 2024 12:58:23 +0900
"Masami Hiramatsu (Google)" <mhiramat@kernel.org> wrote:

> From: Masami Hiramatsu (Google) <mhiramat@kernel.org>
> 
> Instead of incrementing the trace_probe::nr_args, init it at trace_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.

Reviewed-by: Steven Rostedt (Google) <rostedt@goodmis.org>

-- Steve


> 
> Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
> ---

Re: [PATCH v2 3/7] tracing/probes: cleanup: Set trace_probe::nr_args at trace_probe_init

[Masami Hiramatsu]

On Thu, 29 Feb 2024 22:37:53 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Mon, 26 Feb 2024 12:58:23 +0900
> "Masami Hiramatsu (Google)" <mhiramat@kernel.org> wrote:
> 
> > From: Masami Hiramatsu (Google) <mhiramat@kernel.org>
> > 
> > Instead of incrementing the trace_probe::nr_args, init it at trace_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,

> 
> Reviewed-by: Steven Rostedt (Google) <rostedt@goodmis.org>
> 
> -- Steve
> 
> 
> > 
> > Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
> > ---


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>

[PATCH v2 4/7] tracing: Remove redundant #else block for BTF args from README

[Masami Hiramatsu (Google)]

From: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Remove redundant #else block for BTF args from README message.
This is a cleanup, so no change on the message.

Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
 kernel/trace/trace.c |    4 +---
 1 file changed, 1 insertion(+), 3 deletions(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 8198bfc54b58..516c585f5879 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -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

[Steven Rostedt]

On Mon, 26 Feb 2024 12:58:33 +0900
"Masami Hiramatsu (Google)" <mhiramat@kernel.org> wrote:

> From: Masami Hiramatsu (Google) <mhiramat@kernel.org>
> 
> Remove redundant #else block for BTF args from README message.
> This is a cleanup, so no change on the message.

Reviewed-by: Steven Rostedt (Google) <rostedt@goodmis.org>

-- Steve

> 
> Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
> ---

[PATCH v2 5/7] tracing/probes: Support $argN in return probe (kprobe and fprobe)

[Masami Hiramatsu (Google)]

From: Masami Hiramatsu (Google) <mhiramat@kernel.org>

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

Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
 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(-)

diff --git a/kernel/trace/trace.c b/kernel/trace/trace.c
index 516c585f5879..71a96decc276 100644
--- a/kernel/trace/trace.c
+++ b/kernel/trace/trace.c
@@ -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"
diff --git a/kernel/trace/trace_eprobe.c b/kernel/trace/trace_eprobe.c
index eb72def7410f..b0e0ec85912e 100644
--- a/kernel/trace/trace_eprobe.c
+++ b/kernel/trace/trace_eprobe.c
@@ -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);
 }
diff --git a/kernel/trace/trace_fprobe.c b/kernel/trace/trace_fprobe.c
index 3ccef4d82235..4f4280815522 100644
--- a/kernel/trace/trace_fprobe.c
+++ b/kernel/trace/trace_fprobe.c
@@ -4,6 +4,7 @@
  * Copyright (C) 2022 Google LLC.
  */
 #define pr_fmt(fmt)	"trace_fprobe: " fmt
+#include <asm/ptrace.h>
 
 #include <linux/fprobe.h>
 #include <linux/module.h>
@@ -129,8 +130,8 @@ static bool trace_fprobe_is_registered(struct trace_fprobe *tf)
  * 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;
@@ -152,6 +153,9 @@ process_fetch_insn(struct fetch_insn *code, void *rec, void *dest,
 	case FETCH_OP_ARG:
 		val = regs_get_kernel_argument(regs, code->param);
 		break;
+	case FETCH_OP_EDATA:
+		val = *(unsigned long *)((unsigned long)edata + code->offset);
+		break;
 #endif
 	case FETCH_NOP_SYMBOL:	/* Ignore a place holder */
 		code++;
@@ -184,7 +188,7 @@ __fentry_trace_func(struct trace_fprobe *tf, unsigned long entry_ip,
 	if (trace_trigger_soft_disabled(trace_file))
 		return;
 
-	dsize = __get_data_size(&tf->tp, regs);
+	dsize = __get_data_size(&tf->tp, regs, NULL);
 
 	entry = trace_event_buffer_reserve(&fbuffer, trace_file,
 					   sizeof(*entry) + tf->tp.size + dsize);
@@ -194,7 +198,7 @@ __fentry_trace_func(struct trace_fprobe *tf, unsigned long entry_ip,
 	fbuffer.regs = regs;
 	entry = fbuffer.entry = ring_buffer_event_data(fbuffer.event);
 	entry->ip = entry_ip;
-	store_trace_args(&entry[1], &tf->tp, regs, sizeof(*entry), dsize);
+	store_trace_args(&entry[1], &tf->tp, regs, NULL, sizeof(*entry), dsize);
 
 	trace_event_buffer_commit(&fbuffer);
 }
@@ -211,10 +215,23 @@ fentry_trace_func(struct trace_fprobe *tf, unsigned long entry_ip,
 NOKPROBE_SYMBOL(fentry_trace_func);
 
 /* function exit handler */
+static int trace_fprobe_entry_handler(struct fprobe *fp, unsigned long entry_ip,
+				unsigned long ret_ip, struct pt_regs *regs,
+				void *entry_data)
+{
+	struct trace_fprobe *tf = container_of(fp, struct trace_fprobe, fp);
+
+	if (tf->tp.entry_arg)
+		store_trace_entry_data(entry_data, &tf->tp, regs);
+
+	return 0;
+}
+NOKPROBE_SYMBOL(trace_fprobe_entry_handler)
+
 static nokprobe_inline void
 __fexit_trace_func(struct trace_fprobe *tf, unsigned long entry_ip,
 		   unsigned long ret_ip, struct pt_regs *regs,
-		   struct trace_event_file *trace_file)
+		   void *entry_data, struct trace_event_file *trace_file)
 {
 	struct fexit_trace_entry_head *entry;
 	struct trace_event_buffer fbuffer;
@@ -227,7 +244,7 @@ __fexit_trace_func(struct trace_fprobe *tf, unsigned long entry_ip,
 	if (trace_trigger_soft_disabled(trace_file))
 		return;
 
-	dsize = __get_data_size(&tf->tp, regs);
+	dsize = __get_data_size(&tf->tp, regs, entry_data);
 
 	entry = trace_event_buffer_reserve(&fbuffer, trace_file,
 					   sizeof(*entry) + tf->tp.size + dsize);
@@ -238,19 +255,19 @@ __fexit_trace_func(struct trace_fprobe *tf, unsigned long entry_ip,
 	entry = fbuffer.entry = ring_buffer_event_data(fbuffer.event);
 	entry->func = entry_ip;
 	entry->ret_ip = ret_ip;
-	store_trace_args(&entry[1], &tf->tp, regs, sizeof(*entry), dsize);
+	store_trace_args(&entry[1], &tf->tp, regs, entry_data, sizeof(*entry), dsize);
 
 	trace_event_buffer_commit(&fbuffer);
 }
 
 static void
 fexit_trace_func(struct trace_fprobe *tf, unsigned long entry_ip,
-		 unsigned long ret_ip, struct pt_regs *regs)
+		 unsigned long ret_ip, struct pt_regs *regs, void *entry_data)
 {
 	struct event_file_link *link;
 
 	trace_probe_for_each_link_rcu(link, &tf->tp)
-		__fexit_trace_func(tf, entry_ip, ret_ip, regs, link->file);
+		__fexit_trace_func(tf, entry_ip, ret_ip, regs, entry_data, link->file);
 }
 NOKPROBE_SYMBOL(fexit_trace_func);
 
@@ -269,7 +286,7 @@ static int fentry_perf_func(struct trace_fprobe *tf, unsigned long entry_ip,
 	if (hlist_empty(head))
 		return 0;
 
-	dsize = __get_data_size(&tf->tp, regs);
+	dsize = __get_data_size(&tf->tp, regs, NULL);
 	__size = sizeof(*entry) + tf->tp.size + dsize;
 	size = ALIGN(__size + sizeof(u32), sizeof(u64));
 	size -= sizeof(u32);
@@ -280,7 +297,7 @@ static int fentry_perf_func(struct trace_fprobe *tf, unsigned long entry_ip,
 
 	entry->ip = entry_ip;
 	memset(&entry[1], 0, dsize);
-	store_trace_args(&entry[1], &tf->tp, regs, sizeof(*entry), dsize);
+	store_trace_args(&entry[1], &tf->tp, regs, NULL, sizeof(*entry), dsize);
 	perf_trace_buf_submit(entry, size, rctx, call->event.type, 1, regs,
 			      head, NULL);
 	return 0;
@@ -289,7 +306,8 @@ NOKPROBE_SYMBOL(fentry_perf_func);
 
 static void
 fexit_perf_func(struct trace_fprobe *tf, unsigned long entry_ip,
-		unsigned long ret_ip, struct pt_regs *regs)
+		unsigned long ret_ip, struct pt_regs *regs,
+		void *entry_data)
 {
 	struct trace_event_call *call = trace_probe_event_call(&tf->tp);
 	struct fexit_trace_entry_head *entry;
@@ -301,7 +319,7 @@ fexit_perf_func(struct trace_fprobe *tf, unsigned long entry_ip,
 	if (hlist_empty(head))
 		return;
 
-	dsize = __get_data_size(&tf->tp, regs);
+	dsize = __get_data_size(&tf->tp, regs, entry_data);
 	__size = sizeof(*entry) + tf->tp.size + dsize;
 	size = ALIGN(__size + sizeof(u32), sizeof(u64));
 	size -= sizeof(u32);
@@ -312,7 +330,7 @@ fexit_perf_func(struct trace_fprobe *tf, unsigned long entry_ip,
 
 	entry->func = entry_ip;
 	entry->ret_ip = ret_ip;
-	store_trace_args(&entry[1], &tf->tp, regs, sizeof(*entry), dsize);
+	store_trace_args(&entry[1], &tf->tp, regs, entry_data, sizeof(*entry), dsize);
 	perf_trace_buf_submit(entry, size, rctx, call->event.type, 1, regs,
 			      head, NULL);
 }
@@ -343,10 +361,10 @@ static void fexit_dispatcher(struct fprobe *fp, unsigned long entry_ip,
 	struct trace_fprobe *tf = container_of(fp, struct trace_fprobe, fp);
 
 	if (trace_probe_test_flag(&tf->tp, TP_FLAG_TRACE))
-		fexit_trace_func(tf, entry_ip, ret_ip, regs);
+		fexit_trace_func(tf, entry_ip, ret_ip, regs, entry_data);
 #ifdef CONFIG_PERF_EVENTS
 	if (trace_probe_test_flag(&tf->tp, TP_FLAG_PROFILE))
-		fexit_perf_func(tf, entry_ip, ret_ip, regs);
+		fexit_perf_func(tf, entry_ip, ret_ip, regs, entry_data);
 #endif
 }
 NOKPROBE_SYMBOL(fexit_dispatcher);
@@ -389,7 +407,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;
 
@@ -1109,6 +1127,11 @@ static int __trace_fprobe_create(int argc, const char *argv[])
 			goto error;	/* This can be -ENOMEM */
 	}
 
+	if (is_return && tf->tp.entry_arg) {
+		tf->fp.entry_handler = trace_fprobe_entry_handler;
+		tf->fp.entry_data_size = traceprobe_get_entry_data_size(&tf->tp);
+	}
+
 	ret = traceprobe_set_print_fmt(&tf->tp,
 			is_return ? PROBE_PRINT_RETURN : PROBE_PRINT_NORMAL);
 	if (ret < 0)
diff --git a/kernel/trace/trace_kprobe.c b/kernel/trace/trace_kprobe.c
index c4c6e0e0068b..14099cc17fc9 100644
--- a/kernel/trace/trace_kprobe.c
+++ b/kernel/trace/trace_kprobe.c
@@ -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;
 
@@ -740,6 +740,9 @@ static unsigned int number_of_same_symbols(char *func_name)
 	return ctx.count;
 }
 
+static int trace_kprobe_entry_handler(struct kretprobe_instance *ri,
+				      struct pt_regs *regs);
+
 static int __trace_kprobe_create(int argc, const char *argv[])
 {
 	/*
@@ -948,6 +951,11 @@ static int __trace_kprobe_create(int argc, const char *argv[])
 		if (ret)
 			goto error;	/* This can be -ENOMEM */
 	}
+	/* entry handler for kretprobe */
+	if (is_return && tk->tp.entry_arg) {
+		tk->rp.entry_handler = trace_kprobe_entry_handler;
+		tk->rp.data_size = traceprobe_get_entry_data_size(&tk->tp);
+	}
 
 	ptype = is_return ? PROBE_PRINT_RETURN : PROBE_PRINT_NORMAL;
 	ret = traceprobe_set_print_fmt(&tk->tp, ptype);
@@ -1303,8 +1311,8 @@ static const struct file_operations kprobe_profile_ops = {
 
 /* 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;
@@ -1329,6 +1337,9 @@ process_fetch_insn(struct fetch_insn *code, void *rec, void *dest,
 	case FETCH_OP_ARG:
 		val = regs_get_kernel_argument(regs, code->param);
 		break;
+	case FETCH_OP_EDATA:
+		val = *(unsigned long *)((unsigned long)edata + code->offset);
+		break;
 #endif
 	case FETCH_NOP_SYMBOL:	/* Ignore a place holder */
 		code++;
@@ -1359,7 +1370,7 @@ __kprobe_trace_func(struct trace_kprobe *tk, struct pt_regs *regs,
 	if (trace_trigger_soft_disabled(trace_file))
 		return;
 
-	dsize = __get_data_size(&tk->tp, regs);
+	dsize = __get_data_size(&tk->tp, regs, NULL);
 
 	entry = trace_event_buffer_reserve(&fbuffer, trace_file,
 					   sizeof(*entry) + tk->tp.size + dsize);
@@ -1368,7 +1379,7 @@ __kprobe_trace_func(struct trace_kprobe *tk, struct pt_regs *regs,
 
 	fbuffer.regs = regs;
 	entry->ip = (unsigned long)tk->rp.kp.addr;
-	store_trace_args(&entry[1], &tk->tp, regs, sizeof(*entry), dsize);
+	store_trace_args(&entry[1], &tk->tp, regs, NULL, sizeof(*entry), dsize);
 
 	trace_event_buffer_commit(&fbuffer);
 }
@@ -1384,6 +1395,31 @@ kprobe_trace_func(struct trace_kprobe *tk, struct pt_regs *regs)
 NOKPROBE_SYMBOL(kprobe_trace_func);
 
 /* Kretprobe handler */
+
+static int trace_kprobe_entry_handler(struct kretprobe_instance *ri,
+				      struct pt_regs *regs)
+{
+	struct kretprobe *rp = get_kretprobe(ri);
+	struct trace_kprobe *tk;
+
+	/*
+	 * There is a small chance that get_kretprobe(ri) returns NULL when
+	 * the kretprobe is unregister on another CPU between kretprobe's
+	 * trampoline_handler and this function.
+	 */
+	if (unlikely(!rp))
+		return -ENOENT;
+
+	tk = container_of(rp, struct trace_kprobe, rp);
+
+	/* store argument values into ri->data as entry data */
+	if (tk->tp.entry_arg)
+		store_trace_entry_data(ri->data, &tk->tp, regs);
+
+	return 0;
+}
+
+
 static nokprobe_inline void
 __kretprobe_trace_func(struct trace_kprobe *tk, struct kretprobe_instance *ri,
 		       struct pt_regs *regs,
@@ -1399,7 +1435,7 @@ __kretprobe_trace_func(struct trace_kprobe *tk, struct kretprobe_instance *ri,
 	if (trace_trigger_soft_disabled(trace_file))
 		return;
 
-	dsize = __get_data_size(&tk->tp, regs);
+	dsize = __get_data_size(&tk->tp, regs, ri->data);
 
 	entry = trace_event_buffer_reserve(&fbuffer, trace_file,
 					   sizeof(*entry) + tk->tp.size + dsize);
@@ -1409,7 +1445,7 @@ __kretprobe_trace_func(struct trace_kprobe *tk, struct kretprobe_instance *ri,
 	fbuffer.regs = regs;
 	entry->func = (unsigned long)tk->rp.kp.addr;
 	entry->ret_ip = get_kretprobe_retaddr(ri);
-	store_trace_args(&entry[1], &tk->tp, regs, sizeof(*entry), dsize);
+	store_trace_args(&entry[1], &tk->tp, regs, ri->data, sizeof(*entry), dsize);
 
 	trace_event_buffer_commit(&fbuffer);
 }
@@ -1557,7 +1593,7 @@ kprobe_perf_func(struct trace_kprobe *tk, struct pt_regs *regs)
 	if (hlist_empty(head))
 		return 0;
 
-	dsize = __get_data_size(&tk->tp, regs);
+	dsize = __get_data_size(&tk->tp, regs, NULL);
 	__size = sizeof(*entry) + tk->tp.size + dsize;
 	size = ALIGN(__size + sizeof(u32), sizeof(u64));
 	size -= sizeof(u32);
@@ -1568,7 +1604,7 @@ kprobe_perf_func(struct trace_kprobe *tk, struct pt_regs *regs)
 
 	entry->ip = (unsigned long)tk->rp.kp.addr;
 	memset(&entry[1], 0, dsize);
-	store_trace_args(&entry[1], &tk->tp, regs, sizeof(*entry), dsize);
+	store_trace_args(&entry[1], &tk->tp, regs, NULL, sizeof(*entry), dsize);
 	perf_trace_buf_submit(entry, size, rctx, call->event.type, 1, regs,
 			      head, NULL);
 	return 0;
@@ -1593,7 +1629,7 @@ kretprobe_perf_func(struct trace_kprobe *tk, struct kretprobe_instance *ri,
 	if (hlist_empty(head))
 		return;
 
-	dsize = __get_data_size(&tk->tp, regs);
+	dsize = __get_data_size(&tk->tp, regs, ri->data);
 	__size = sizeof(*entry) + tk->tp.size + dsize;
 	size = ALIGN(__size + sizeof(u32), sizeof(u64));
 	size -= sizeof(u32);
@@ -1604,7 +1640,7 @@ kretprobe_perf_func(struct trace_kprobe *tk, struct kretprobe_instance *ri,
 
 	entry->func = (unsigned long)tk->rp.kp.addr;
 	entry->ret_ip = get_kretprobe_retaddr(ri);
-	store_trace_args(&entry[1], &tk->tp, regs, sizeof(*entry), dsize);
+	store_trace_args(&entry[1], &tk->tp, regs, ri->data, sizeof(*entry), dsize);
 	perf_trace_buf_submit(entry, size, rctx, call->event.type, 1, regs,
 			      head, NULL);
 }
diff --git a/kernel/trace/trace_probe.c b/kernel/trace/trace_probe.c
index 93f36f8a108e..217169de0920 100644
--- a/kernel/trace/trace_probe.c
+++ b/kernel/trace/trace_probe.c
@@ -594,6 +594,8 @@ static int parse_btf_field(char *fieldname, const struct btf_type *type,
 	return 0;
 }
 
+static int __store_entry_arg(struct trace_probe *tp, int argnum);
+
 static int parse_btf_arg(char *varname,
 			 struct fetch_insn **pcode, struct fetch_insn *end,
 			 struct traceprobe_parse_context *ctx)
@@ -618,11 +620,7 @@ static int parse_btf_arg(char *varname,
 		return -EOPNOTSUPP;
 	}
 
-	if (ctx->flags & TPARG_FL_RETURN) {
-		if (strcmp(varname, "$retval") != 0) {
-			trace_probe_log_err(ctx->offset, NO_BTFARG);
-			return -ENOENT;
-		}
+	if (ctx->flags & TPARG_FL_RETURN && !strcmp(varname, "$retval")) {
 		code->op = FETCH_OP_RETVAL;
 		/* Check whether the function return type is not void */
 		if (query_btf_context(ctx) == 0) {
@@ -654,11 +652,21 @@ static int parse_btf_arg(char *varname,
 		const char *name = btf_name_by_offset(ctx->btf, params[i].name_off);
 
 		if (name && !strcmp(name, varname)) {
-			code->op = FETCH_OP_ARG;
-			if (ctx->flags & TPARG_FL_TPOINT)
-				code->param = i + 1;
-			else
-				code->param = i;
+			if (tparg_is_function_entry(ctx->flags)) {
+				code->op = FETCH_OP_ARG;
+				if (ctx->flags & TPARG_FL_TPOINT)
+					code->param = i + 1;
+				else
+					code->param = i;
+			} else if (tparg_is_function_return(ctx->flags)) {
+				code->op = FETCH_OP_EDATA;
+				ret = __store_entry_arg(ctx->tp, i);
+				if (ret < 0) {
+					/* internal error */
+					return ret;
+				}
+				code->offset = ret;
+			}
 			tid = params[i].type;
 			goto found;
 		}
@@ -755,6 +763,110 @@ static int check_prepare_btf_string_fetch(char *typename,
 
 #endif
 
+#ifdef CONFIG_HAVE_FUNCTION_ARG_ACCESS_API
+
+static int __store_entry_arg(struct trace_probe *tp, int argnum)
+{
+	struct probe_entry_arg *earg = tp->entry_arg;
+	bool match = false;
+	int i, offset;
+
+	if (!earg) {
+		earg = kzalloc(sizeof(*tp->entry_arg), GFP_KERNEL);
+		if (!earg)
+			return -ENOMEM;
+		earg->size = 2 * tp->nr_args + 1;
+		earg->code = kcalloc(earg->size, sizeof(struct fetch_insn),
+				     GFP_KERNEL);
+		if (!earg->code) {
+			kfree(earg);
+			return -ENOMEM;
+		}
+		/* Fill the code buffer with 'end' to simplify it */
+		for (i = 0; i < earg->size; i++)
+			earg->code[i].op = FETCH_OP_END;
+		tp->entry_arg = earg;
+	}
+
+	offset = 0;
+	for (i = 0; i < earg->size - 1; i++) {
+		switch (earg->code[i].op) {
+		case FETCH_OP_END:
+			earg->code[i].op = FETCH_OP_ARG;
+			earg->code[i].param = argnum;
+			earg->code[i + 1].op = FETCH_OP_ST_EDATA;
+			earg->code[i + 1].offset = offset;
+			return offset;
+		case FETCH_OP_ARG:
+			match = (earg->code[i].param == argnum);
+			break;
+		case FETCH_OP_ST_EDATA:
+			offset = earg->code[i].offset;
+			if (match)
+				return offset;
+			offset += sizeof(unsigned long);
+			break;
+		default:
+			break;
+		}
+	}
+	return -ENOSPC;
+}
+
+int traceprobe_get_entry_data_size(struct trace_probe *tp)
+{
+	struct probe_entry_arg *earg = tp->entry_arg;
+	int i, size = 0;
+
+	if (!earg)
+		return 0;
+
+	for (i = 0; i < earg->size; i++) {
+		switch (earg->code[i].op) {
+		case FETCH_OP_END:
+			goto out;
+		case FETCH_OP_ST_EDATA:
+			size = earg->code[i].offset + sizeof(unsigned long);
+			break;
+		default:
+			break;
+		}
+	}
+out:
+	return size;
+}
+
+void store_trace_entry_data(void *edata, struct trace_probe *tp, struct pt_regs *regs)
+{
+	struct probe_entry_arg *earg = tp->entry_arg;
+	unsigned long val;
+	int i;
+
+	if (!earg)
+		return;
+
+	for (i = 0; i < earg->size; i++) {
+		struct fetch_insn *code = &earg->code[i];
+
+		switch (code->op) {
+		case FETCH_OP_ARG:
+			val = regs_get_kernel_argument(regs, code->param);
+			break;
+		case FETCH_OP_ST_EDATA:
+			*(unsigned long *)((unsigned long)edata + code->offset) = val;
+			break;
+		case FETCH_OP_END:
+			goto end;
+		default:
+			break;
+		}
+	}
+end:
+	return;
+}
+NOKPROBE_SYMBOL(store_trace_entry_data)
+#endif
+
 #define PARAM_MAX_STACK (THREAD_SIZE / sizeof(unsigned long))
 
 /* Parse $vars. @orig_arg points '$', which syncs to @ctx->offset */
@@ -830,7 +942,7 @@ static int parse_probe_vars(char *orig_arg, const struct fetch_type *t,
 
 #ifdef CONFIG_HAVE_FUNCTION_ARG_ACCESS_API
 	len = str_has_prefix(arg, "arg");
-	if (len && tparg_is_function_entry(ctx->flags)) {
+	if (len) {
 		ret = kstrtoul(arg + len, 10, &param);
 		if (ret)
 			goto inval;
@@ -839,15 +951,29 @@ static int parse_probe_vars(char *orig_arg, const struct fetch_type *t,
 			err = TP_ERR_BAD_ARG_NUM;
 			goto inval;
 		}
+		param--; /* argN starts from 1, but internal arg[N] starts from 0 */
 
-		code->op = FETCH_OP_ARG;
-		code->param = (unsigned int)param - 1;
-		/*
-		 * The tracepoint probe will probe a stub function, and the
-		 * first parameter of the stub is a dummy and should be ignored.
-		 */
-		if (ctx->flags & TPARG_FL_TPOINT)
-			code->param++;
+		if (tparg_is_function_entry(ctx->flags)) {
+			code->op = FETCH_OP_ARG;
+			code->param = (unsigned int)param;
+			/*
+			 * The tracepoint probe will probe a stub function, and the
+			 * first parameter of the stub is a dummy and should be ignored.
+			 */
+			if (ctx->flags & TPARG_FL_TPOINT)
+				code->param++;
+		} else if (tparg_is_function_return(ctx->flags)) {
+			/* function entry argument access from return probe */
+			ret = __store_entry_arg(ctx->tp, param);
+			if (ret < 0)	/* This error should be an internal error */
+				return ret;
+
+			code->op = FETCH_OP_EDATA;
+			code->offset = ret;
+		} else {
+			err = TP_ERR_NOFENTRY_ARGS;
+			goto inval;
+		}
 		return 0;
 	}
 #endif
@@ -1037,7 +1163,8 @@ parse_probe_arg(char *arg, const struct fetch_type *type,
 		break;
 	default:
 		if (isalpha(arg[0]) || arg[0] == '_') {	/* BTF variable */
-			if (!tparg_is_function_entry(ctx->flags)) {
+			if (!tparg_is_function_entry(ctx->flags) &&
+			    !tparg_is_function_return(ctx->flags)) {
 				trace_probe_log_err(ctx->offset, NOSUP_BTFARG);
 				return -EINVAL;
 			}
@@ -1423,6 +1550,7 @@ int traceprobe_parse_probe_arg(struct trace_probe *tp, int i, const char *arg,
 	struct probe_arg *parg = &tp->args[i];
 	const char *body;
 
+	ctx->tp = tp;
 	body = strchr(arg, '=');
 	if (body) {
 		if (body - arg > MAX_ARG_NAME_LEN) {
@@ -1479,7 +1607,8 @@ static int argv_has_var_arg(int argc, const char *argv[], int *args_idx,
 		if (str_has_prefix(argv[i], "$arg")) {
 			trace_probe_log_set_index(i + 2);
 
-			if (!tparg_is_function_entry(ctx->flags)) {
+			if (!tparg_is_function_entry(ctx->flags) &&
+			    !tparg_is_function_return(ctx->flags)) {
 				trace_probe_log_err(0, NOFENTRY_ARGS);
 				return -EINVAL;
 			}
@@ -1802,6 +1931,12 @@ void trace_probe_cleanup(struct trace_probe *tp)
 	for (i = 0; i < tp->nr_args; i++)
 		traceprobe_free_probe_arg(&tp->args[i]);
 
+	if (tp->entry_arg) {
+		kfree(tp->entry_arg->code);
+		kfree(tp->entry_arg);
+		tp->entry_arg = NULL;
+	}
+
 	if (tp->event)
 		trace_probe_unlink(tp);
 }
diff --git a/kernel/trace/trace_probe.h b/kernel/trace/trace_probe.h
index ed8d1052f8a7..cef3a50628a3 100644
--- a/kernel/trace/trace_probe.h
+++ b/kernel/trace/trace_probe.h
@@ -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 char
 int 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"),		\
diff --git a/kernel/trace/trace_probe_tmpl.h b/kernel/trace/trace_probe_tmpl.h
index 3935b347f874..2caf0d2afb32 100644
--- a/kernel/trace/trace_probe_tmpl.h
+++ b/kernel/trace/trace_probe_tmpl.h
@@ -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;
diff --git a/kernel/trace/trace_uprobe.c b/kernel/trace/trace_uprobe.c
index 796ebcae9b38..9e461362450a 100644
--- a/kernel/trace/trace_uprobe.c
+++ b/kernel/trace/trace_uprobe.c
@@ -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);

[PATCH v2 6/7] selftests/ftrace: Add test cases for entry args at function exit

[Masami Hiramatsu (Google)]

From: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Add kretprobe and function exit probe test cases for checking whether
those can access entry arguments at function exit correctly.

Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
 .../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

diff --git a/tools/testing/selftests/ftrace/test.d/dynevent/fprobe_entry_arg.tc b/tools/testing/selftests/ftrace/test.d/dynevent/fprobe_entry_arg.tc
new file mode 100644
index 000000000000..d183b8a8ecf8
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/dynevent/fprobe_entry_arg.tc
@@ -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/' `
diff --git a/tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_entry_arg.tc b/tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_entry_arg.tc
new file mode 100644
index 000000000000..53b82f36a1d0
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/kprobe/kretprobe_entry_arg.tc
@@ -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/' `

[PATCH v2 7/7] Documentation: tracing: Add entry argument access at function exit

[Masami Hiramatsu (Google)]

From: Masami Hiramatsu (Google) <mhiramat@kernel.org>

Add a notes about the entry argument access at function exit probes for
kprobes and fprobe trace event.

Signed-off-by: Masami Hiramatsu (Google) <mhiramat@kernel.org>
---
 Documentation/trace/fprobetrace.rst |    7 +++++++
 Documentation/trace/kprobetrace.rst |    7 +++++++
 2 files changed, 14 insertions(+)

diff --git a/Documentation/trace/fprobetrace.rst b/Documentation/trace/fprobetrace.rst
index e35e6b18df40..ab71ebf178cb 100644
--- a/Documentation/trace/fprobetrace.rst
+++ b/Documentation/trace/fprobetrace.rst
@@ -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
diff --git a/Documentation/trace/kprobetrace.rst b/Documentation/trace/kprobetrace.rst
index bf9cecb69fc9..35a383f95746 100644
--- a/Documentation/trace/kprobetrace.rst
+++ b/Documentation/trace/kprobetrace.rst
@@ -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

Re: [PATCH v2 0/7] tracing/probes: Support function parameter access from return probe

[Jiri Olsa]

On Mon, Feb 26, 2024 at 12:57:53PM +0900, Masami Hiramatsu (Google) wrote:
> 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

hi,
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

Re: [PATCH v2 0/7] tracing/probes: Support function parameter access from return probe

[Masami Hiramatsu]

On Wed, 28 Feb 2024 17:23:34 +0100
Jiri Olsa <olsajiri@gmail.com> wrote:

> On Mon, Feb 26, 2024 at 12:57:53PM +0900, Masami Hiramatsu (Google) wrote:
> > 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
> 
> 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?

> 
> 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) <mhiramat@kernel.org>

Re: [PATCH v2 0/7] tracing/probes: Support function parameter access from return probe

[Masami Hiramatsu]

On Thu, 29 Feb 2024 14:51:39 +0900
Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:

> On Wed, 28 Feb 2024 17:23:34 +0100
> Jiri Olsa <olsajiri@gmail.com> wrote:
> 
> > On Mon, Feb 26, 2024 at 12:57:53PM +0900, Masami Hiramatsu (Google) wrote:
> > > 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
> > 
> > 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?

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,


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>

Re: [PATCH v2 0/7] tracing/probes: Support function parameter access from return probe

[Masami Hiramatsu]

On Thu, 29 Feb 2024 15:38:55 +0900
Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:

> 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.

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,

-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>

Re: [PATCH v2 0/7] tracing/probes: Support function parameter access from return probe

[Masami Hiramatsu]

On Thu, 29 Feb 2024 16:13:20 +0900
Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:

> On Thu, 29 Feb 2024 15:38:55 +0900
> Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:
> 
> > 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.
> 
> 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...

Lol, I haven't allocate the entry data size when initialize rethook.
That's a bug.
Please try below.

diff --git a/kernel/trace/fprobe.c b/kernel/trace/fprobe.c
index 6cd2a4e3afb8..9ff018245840 100644
--- a/kernel/trace/fprobe.c
+++ b/kernel/trace/fprobe.c
@@ -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) <mhiramat@kernel.org>

Re: [PATCH v2 0/7] tracing/probes: Support function parameter access from return probe

[Steven Rostedt]

On Thu, 29 Feb 2024 17:52:16 +0900
Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:

> 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

Re: [PATCH v2 0/7] tracing/probes: Support function parameter access from return probe

[Masami Hiramatsu]

On Thu, 29 Feb 2024 22:41:34 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Thu, 29 Feb 2024 17:52:16 +0900
> Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:
> 
> > 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,

> 
> -- Steve
> 


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>