2021-01-20 16:13:08

by Jianlin Lv

[permalink] [raw]
Subject: [PATCH v2] tracing: precise log info for kretprobe addr err

When trying to create kretprobe with the wrong function symbol in tracefs;
The error is triggered in the register_trace_kprobe() and recorded as
FAIL_REG_PROBE issue,

Example:
$ cd /sys/kernel/debug/tracing
$ echo 'r:myprobe ERROR_SYMBOL_XXX ret=%x0' >> kprobe_events
bash: echo: write error: Invalid argument
$ cat error_log
[142797.347877] trace_kprobe: error: Failed to register probe event
Command: r:myprobe ERROR_SYMBOL_XXX ret=%x0
^

This error can be detected in the parameter parsing stage, the effect of
applying this patch is as follows:

$ echo 'r:myprobe ERROR_SYMBOL_XXX ret=%x0' >> kprobe_events
bash: echo: write error: Invalid argument
$ cat error_log
[415.89]trace_kprobe: error: Retprobe address must be an function entry
Command: r:myprobe ERROR_SYMBOL_XXX ret=%x0
^

Signed-off-by: Jianlin Lv <[email protected]>

v2:add !strchr(symbol, ':') to check really bad symbol or not.
---
kernel/trace/trace_kprobe.c | 2 +-
1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/kernel/trace/trace_kprobe.c b/kernel/trace/trace_kprobe.c
index e6fba1798771..bce63d5ecaec 100644
--- a/kernel/trace/trace_kprobe.c
+++ b/kernel/trace/trace_kprobe.c
@@ -830,7 +830,7 @@ static int trace_kprobe_create(int argc, const char *argv[])
flags |= TPARG_FL_RETURN;
if (kprobe_on_func_entry(NULL, symbol, offset))
flags |= TPARG_FL_FENTRY;
- if (offset && is_return && !(flags & TPARG_FL_FENTRY)) {
+ if (!strchr(symbol, ':') && is_return && !(flags & TPARG_FL_FENTRY)) {
trace_probe_log_err(0, BAD_RETPROBE);
goto parse_error;
}
--
2.25.1


2021-01-20 16:27:01

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH v2] tracing: precise log info for kretprobe addr err


You forgot to include Masami on Cc again. Masami maintains kprobes. Please
include him on any updates, as he needs to review them, and give his
acknowledgment before acceptance.

I need to update MAINTAINERS files to include trace_kprobe under KPROBES.
And I also don't see any UPROBES section there. That needs to be done as
well.

On Wed, 20 Jan 2021 23:56:44 +0800
Jianlin Lv <[email protected]> wrote:

> When trying to create kretprobe with the wrong function symbol in tracefs;
> The error is triggered in the register_trace_kprobe() and recorded as
> FAIL_REG_PROBE issue,
>
> Example:
> $ cd /sys/kernel/debug/tracing
> $ echo 'r:myprobe ERROR_SYMBOL_XXX ret=%x0' >> kprobe_events
> bash: echo: write error: Invalid argument
> $ cat error_log
> [142797.347877] trace_kprobe: error: Failed to register probe event
> Command: r:myprobe ERROR_SYMBOL_XXX ret=%x0
> ^
>
> This error can be detected in the parameter parsing stage, the effect of
> applying this patch is as follows:
>
> $ echo 'r:myprobe ERROR_SYMBOL_XXX ret=%x0' >> kprobe_events
> bash: echo: write error: Invalid argument
> $ cat error_log
> [415.89]trace_kprobe: error: Retprobe address must be an function entry
> Command: r:myprobe ERROR_SYMBOL_XXX ret=%x0
> ^
>
> Signed-off-by: Jianlin Lv <[email protected]>
>
> v2:add !strchr(symbol, ':') to check really bad symbol or not.

Also, the "changes since" section should be below the "---" so that they
don't get pulled into the commit.

Thanks!

-- Steve


> ---
> kernel/trace/trace_kprobe.c | 2 +-
> 1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/kernel/trace/trace_kprobe.c b/kernel/trace/trace_kprobe.c
> index e6fba1798771..bce63d5ecaec 100644
> --- a/kernel/trace/trace_kprobe.c
> +++ b/kernel/trace/trace_kprobe.c
> @@ -830,7 +830,7 @@ static int trace_kprobe_create(int argc, const char *argv[])
> flags |= TPARG_FL_RETURN;
> if (kprobe_on_func_entry(NULL, symbol, offset))
> flags |= TPARG_FL_FENTRY;
> - if (offset && is_return && !(flags & TPARG_FL_FENTRY)) {
> + if (!strchr(symbol, ':') && is_return && !(flags & TPARG_FL_FENTRY)) {
> trace_probe_log_err(0, BAD_RETPROBE);
> goto parse_error;
> }

2021-01-21 03:29:59

by Masami Hiramatsu

[permalink] [raw]
Subject: Re: [PATCH v2] tracing: precise log info for kretprobe addr err

On Wed, 20 Jan 2021 11:20:04 -0500
Steven Rostedt <[email protected]> wrote:

>
> You forgot to include Masami on Cc again. Masami maintains kprobes. Please
> include him on any updates, as he needs to review them, and give his
> acknowledgment before acceptance.
>
> I need to update MAINTAINERS files to include trace_kprobe under KPROBES.
> And I also don't see any UPROBES section there. That needs to be done as
> well.

Uprobes is under kernel/events/, which seems to be handled by
performance event subsystem. Maybe we should ask them too.
Or, can I be a reviewer (R:) for tracing subsystem?

>
> On Wed, 20 Jan 2021 23:56:44 +0800
> Jianlin Lv <[email protected]> wrote:
>
> > When trying to create kretprobe with the wrong function symbol in tracefs;
> > The error is triggered in the register_trace_kprobe() and recorded as
> > FAIL_REG_PROBE issue,
> >
> > Example:
> > $ cd /sys/kernel/debug/tracing
> > $ echo 'r:myprobe ERROR_SYMBOL_XXX ret=%x0' >> kprobe_events
> > bash: echo: write error: Invalid argument
> > $ cat error_log
> > [142797.347877] trace_kprobe: error: Failed to register probe event
> > Command: r:myprobe ERROR_SYMBOL_XXX ret=%x0
> > ^
> >
> > This error can be detected in the parameter parsing stage, the effect of
> > applying this patch is as follows:
> >
> > $ echo 'r:myprobe ERROR_SYMBOL_XXX ret=%x0' >> kprobe_events
> > bash: echo: write error: Invalid argument
> > $ cat error_log
> > [415.89]trace_kprobe: error: Retprobe address must be an function entry
> > Command: r:myprobe ERROR_SYMBOL_XXX ret=%x0
> > ^
> >
> > Signed-off-by: Jianlin Lv <[email protected]>
> >
> > v2:add !strchr(symbol, ':') to check really bad symbol or not.
>
> Also, the "changes since" section should be below the "---" so that they
> don't get pulled into the commit.

Except that, this looks good to me.

Acked-by: Masami Hiramatsu <[email protected]>

Thank you,

>
> Thanks!
>
> -- Steve
>
>
> > ---
> > kernel/trace/trace_kprobe.c | 2 +-
> > 1 file changed, 1 insertion(+), 1 deletion(-)
> >
> > diff --git a/kernel/trace/trace_kprobe.c b/kernel/trace/trace_kprobe.c
> > index e6fba1798771..bce63d5ecaec 100644
> > --- a/kernel/trace/trace_kprobe.c
> > +++ b/kernel/trace/trace_kprobe.c
> > @@ -830,7 +830,7 @@ static int trace_kprobe_create(int argc, const char *argv[])
> > flags |= TPARG_FL_RETURN;
> > if (kprobe_on_func_entry(NULL, symbol, offset))
> > flags |= TPARG_FL_FENTRY;
> > - if (offset && is_return && !(flags & TPARG_FL_FENTRY)) {
> > + if (!strchr(symbol, ':') && is_return && !(flags & TPARG_FL_FENTRY)) {
> > trace_probe_log_err(0, BAD_RETPROBE);
> > goto parse_error;
> > }
>


--
Masami Hiramatsu <[email protected]>

2021-01-23 14:24:50

by Jianlin Lv

[permalink] [raw]
Subject: RE: [PATCH v2] tracing: precise log info for kretprobe addr err



> -----Original Message-----
> From: Masami Hiramatsu <[email protected]>
> Sent: Thursday, January 21, 2021 10:29 AM
> To: Steven Rostedt <[email protected]>
> Cc: Jianlin Lv <[email protected]>; [email protected]; linux-
> [email protected]; Masami Hiramatsu <[email protected]>;
> [email protected]
> Subject: Re: [PATCH v2] tracing: precise log info for kretprobe addr err
>
> On Wed, 20 Jan 2021 11:20:04 -0500
> Steven Rostedt <[email protected]> wrote:
>
> >
> > You forgot to include Masami on Cc again. Masami maintains kprobes.
> > Please include him on any updates, as he needs to review them, and
> > give his acknowledgment before acceptance.
> >
> > I need to update MAINTAINERS files to include trace_kprobe under
> KPROBES.
> > And I also don't see any UPROBES section there. That needs to be done
> > as well.

Regarding the UPROBES, I read the code of trace_uprobe_create() and found a place for improvement.

diff --git a/kernel/trace/trace_uprobe.c b/kernel/trace/trace_uprobe.c
index 3cf7128e1ad3..8c81f04d7755 100644
--- a/kernel/trace/trace_uprobe.c
+++ b/kernel/trace/trace_uprobe.c
@@ -567,16 +567,18 @@ static int trace_uprobe_create(int argc, const char **argv)
if (!filename)
return -ENOMEM;

+ trace_probe_log_init("trace_uprobe", argc, argv);
+ trace_probe_log_set_index(1); /* filename is the 2nd argument */
+
/* Find the last occurrence, in case the path contains ':' too. */
arg = strrchr(filename, ':');
if (!arg || !isdigit(arg[1])) {
+ trace_probe_log_err(arg + 1 - filename, BAD_UPROBE_OFFS);
kfree(filename);
- return -ECANCELED;
+ ret = -EINVAL;
+ goto out;
}

- trace_probe_log_init("trace_uprobe", argc, argv);
- trace_probe_log_set_index(1); /* filename is the 2nd argument */
-

Is there anything else that is missing?
Could you provide more detailed guidance?


>
> Uprobes is under kernel/events/, which seems to be handled by
> performance event subsystem. Maybe we should ask them too.
> Or, can I be a reviewer (R:) for tracing subsystem?
>
> >
> > On Wed, 20 Jan 2021 23:56:44 +0800
> > Jianlin Lv <[email protected]> wrote:
> >
> > > When trying to create kretprobe with the wrong function symbol in
> > > tracefs; The error is triggered in the register_trace_kprobe() and
> > > recorded as FAIL_REG_PROBE issue,
> > >
> > > Example:
> > > $ cd /sys/kernel/debug/tracing
> > > $ echo 'r:myprobe ERROR_SYMBOL_XXX ret=%x0' >> kprobe_events
> > > bash: echo: write error: Invalid argument
> > > $ cat error_log
> > > [142797.347877] trace_kprobe: error: Failed to register probe event
> > > Command: r:myprobe ERROR_SYMBOL_XXX ret=%x0
> > > ^
> > >
> > > This error can be detected in the parameter parsing stage, the
> > > effect of applying this patch is as follows:
> > >
> > > $ echo 'r:myprobe ERROR_SYMBOL_XXX ret=%x0' >> kprobe_events
> > > bash: echo: write error: Invalid argument
> > > $ cat error_log
> > > [415.89]trace_kprobe: error: Retprobe address must be an function
> entry
> > > Command: r:myprobe ERROR_SYMBOL_XXX ret=%x0
> > > ^
> > >
> > > Signed-off-by: Jianlin Lv <[email protected]>
> > >
> > > v2:add !strchr(symbol, ':') to check really bad symbol or not.
> >
> > Also, the "changes since" section should be below the "---" so that
> > they don't get pulled into the commit.
>
> Except that, this looks good to me.
>
> Acked-by: Masami Hiramatsu <[email protected]>
>
> Thank you,
>
> >
> > Thanks!
> >
> > -- Steve
> >
> >
> > > ---
> > > kernel/trace/trace_kprobe.c | 2 +-
> > > 1 file changed, 1 insertion(+), 1 deletion(-)
> > >
> > > diff --git a/kernel/trace/trace_kprobe.c
> > > b/kernel/trace/trace_kprobe.c index e6fba1798771..bce63d5ecaec
> > > 100644
> > > --- a/kernel/trace/trace_kprobe.c
> > > +++ b/kernel/trace/trace_kprobe.c
> > > @@ -830,7 +830,7 @@ static int trace_kprobe_create(int argc, const char
> *argv[])
> > > flags |= TPARG_FL_RETURN;
> > > if (kprobe_on_func_entry(NULL, symbol, offset))
> > > flags |= TPARG_FL_FENTRY;
> > > -if (offset && is_return && !(flags & TPARG_FL_FENTRY)) {
> > > +if (!strchr(symbol, ':') && is_return && !(flags &
> > > +TPARG_FL_FENTRY)) {
> > > trace_probe_log_err(0, BAD_RETPROBE);
> > > goto parse_error;
> > > }
> >
>
>
> --
> Masami Hiramatsu <[email protected]>
IMPORTANT NOTICE: The contents of this email and any attachments are confidential and may also be privileged. If you are not the intended recipient, please notify the sender immediately and do not disclose the contents to any other person, use it for any purpose, or store or copy the information in any medium. Thank you.

2021-01-24 08:55:33

by Masami Hiramatsu

[permalink] [raw]
Subject: Re: [PATCH v2] tracing: precise log info for kretprobe addr err

Hi Jianlin,

On Sat, 23 Jan 2021 14:21:48 +0000
Jianlin Lv <[email protected]> wrote:

> Regarding the UPROBES, I read the code of trace_uprobe_create() and found a place for improvement.
>
> diff --git a/kernel/trace/trace_uprobe.c b/kernel/trace/trace_uprobe.c
> index 3cf7128e1ad3..8c81f04d7755 100644
> --- a/kernel/trace/trace_uprobe.c
> +++ b/kernel/trace/trace_uprobe.c
> @@ -567,16 +567,18 @@ static int trace_uprobe_create(int argc, const char **argv)
> if (!filename)
> return -ENOMEM;
>
> + trace_probe_log_init("trace_uprobe", argc, argv);
> + trace_probe_log_set_index(1); /* filename is the 2nd argument */
> +
> /* Find the last occurrence, in case the path contains ':' too. */
> arg = strrchr(filename, ':');
> if (!arg || !isdigit(arg[1])) {
> + trace_probe_log_err(arg + 1 - filename, BAD_UPROBE_OFFS);
> kfree(filename);
> - return -ECANCELED;
> + ret = -EINVAL;
> + goto out;

Sorry, it's not a bug, but an expected behavior, because this is checking
routine which identify the passed command is mine (uprobe event definition)
or others (e.g. kprobe event definition).

Note that the dyn_event_operations::create operator will be used from
dyn_event, which passes the command string from TRACEFS/dynamic_events
to each create operator and check the return is -ECANCELED.
The -ECANCELED is not an error, it means "it is not mine, but maybe others."
See create_dyn_event(int argc, char **argv) in kernel/trace/trace_dynevent.c.

Thank you,

--
Masami Hiramatsu <[email protected]>

2021-01-25 03:19:07

by Jianlin Lv

[permalink] [raw]
Subject: RE: [PATCH v2] tracing: precise log info for kretprobe addr err

Hi Masami,
Thanks for your comments, it is very helpful to me.


Hi Steven,
Could you give me more detailed suggestions about the UPROBES section? I lack the knowledge of this part.
Can't fully understand your previous comments;


Thanks all for your patience.

Jianlin

> -----Original Message-----
> From: Masami Hiramatsu <[email protected]>
> Sent: Sunday, January 24, 2021 4:53 PM
> To: Jianlin Lv <[email protected]>
> Cc: Steven Rostedt <[email protected]>; [email protected]; linux-
> [email protected]; [email protected]
> Subject: Re: [PATCH v2] tracing: precise log info for kretprobe addr err
>
> Hi Jianlin,
>
> On Sat, 23 Jan 2021 14:21:48 +0000
> Jianlin Lv <[email protected]> wrote:
>
> > Regarding the UPROBES, I read the code of trace_uprobe_create() and
> found a place for improvement.
> >
> > diff --git a/kernel/trace/trace_uprobe.c b/kernel/trace/trace_uprobe.c
> > index 3cf7128e1ad3..8c81f04d7755 100644
> > --- a/kernel/trace/trace_uprobe.c
> > +++ b/kernel/trace/trace_uprobe.c
> > @@ -567,16 +567,18 @@ static int trace_uprobe_create(int argc, const
> char **argv)
> > if (!filename)
> > return -ENOMEM;
> >
> > + trace_probe_log_init("trace_uprobe", argc, argv);
> > + trace_probe_log_set_index(1); /* filename is the 2nd argument */
> > +
> > /* Find the last occurrence, in case the path contains ':' too. */
> > arg = strrchr(filename, ':');
> > if (!arg || !isdigit(arg[1])) {
> > + trace_probe_log_err(arg + 1 - filename,
> > + BAD_UPROBE_OFFS);
> > kfree(filename);
> > - return -ECANCELED;
> > + ret = -EINVAL;
> > + goto out;
>
> Sorry, it's not a bug, but an expected behavior, because this is checking
> routine which identify the passed command is mine (uprobe event definition)
> or others (e.g. kprobe event definition).
>
> Note that the dyn_event_operations::create operator will be used from
> dyn_event, which passes the command string from
> TRACEFS/dynamic_events to each create operator and check the return is -
> ECANCELED.
> The -ECANCELED is not an error, it means "it is not mine, but maybe others."
> See create_dyn_event(int argc, char **argv) in kernel/trace/trace_dynevent.c.
>
> Thank you,
>
> --
> Masami Hiramatsu <[email protected]>
IMPORTANT NOTICE: The contents of this email and any attachments are confidential and may also be privileged. If you are not the intended recipient, please notify the sender immediately and do not disclose the contents to any other person, use it for any purpose, or store or copy the information in any medium. Thank you.

2021-01-26 06:44:41

by Steven Rostedt

[permalink] [raw]
Subject: Re: [PATCH v2] tracing: precise log info for kretprobe addr err

On Mon, 25 Jan 2021 03:14:03 +0000
Jianlin Lv <[email protected]> wrote:

> Hi Steven,
> Could you give me more detailed suggestions about the UPROBES section? I lack the knowledge of this part.
> Can't fully understand your previous comments;

Sorry for the confusion. I was talking about the MAINTAINERS file. That
there's no "UPROBES" section in it.

-- Steve