[PATCH v3] tracing: precise log info for kretprobe addr err

[PATCH v3] tracing: precise log info for kretprobe addr err

[Jianlin Lv]

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 <Jianlin.Lv@arm.com>
---
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

Re: [PATCH v3] tracing: precise log info for kretprobe addr err

[Oleg Nesterov]

On 01/26, Jianlin Lv 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

IOW, the "offset != 0" check removed by this patch is obviously wrong, right?

Agreed, but...

> --- 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)) {

but why did you add the strchr(':') check instead?

I was really puzzled until I found the this email from Masami:
https://lore.kernel.org/lkml/20210120131406.5a992c1e434681750a0cd5d4@kernel.org/

So I leave this to you and Masami, but perhaps you can document this check at
least in the changelog?

Oleg.

Re: [PATCH v3] tracing: precise log info for kretprobe addr err

[Steven Rostedt]

On Mon, 25 Jan 2021 19:19:27 +0100
Oleg Nesterov <oleg@redhat.com> wrote:

> On 01/26, Jianlin Lv 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  
> 
> IOW, the "offset != 0" check removed by this patch is obviously wrong, right?
> 
> Agreed, but...
> 
> > --- 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)) {  
> 
> but why did you add the strchr(':') check instead?
> 
> I was really puzzled until I found the this email from Masami:
> https://lore.kernel.org/lkml/20210120131406.5a992c1e434681750a0cd5d4@kernel.org/
> 
> So I leave this to you and Masami, but perhaps you can document this check at
> least in the changelog?
> 

No, you are correct. That needs to be documented in the code.

I was about to comment that the check requires a comment ;-)

Jianlin,

Care to send a v4 of the patch with a comment to why we are checking the
symbol for ':'.

Thanks!

-- Steve

Re: [PATCH v3] tracing: precise log info for kretprobe addr err

[Masami Hiramatsu]

On Mon, 25 Jan 2021 13:38:40 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Mon, 25 Jan 2021 19:19:27 +0100
> Oleg Nesterov <oleg@redhat.com> wrote:
> 
> > On 01/26, Jianlin Lv 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  
> > 
> > IOW, the "offset != 0" check removed by this patch is obviously wrong, right?
> > 

No, not wrong. Even offset != 0, if the symbol exists in the kernel, 
kprobe_on_func_entry() will check it.

> > Agreed, but...
> > 
> > > --- 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)) {  
> > 
> > but why did you add the strchr(':') check instead?
> > 
> > I was really puzzled until I found the this email from Masami:
> > https://lore.kernel.org/lkml/20210120131406.5a992c1e434681750a0cd5d4@kernel.org/
> > 
> > So I leave this to you and Masami, but perhaps you can document this check at
> > least in the changelog?
> > 
> 
> No, you are correct. That needs to be documented in the code.

Agreed. There should be commented that is defered until the module is loaded.

> 
> I was about to comment that the check requires a comment ;-)
> 
> Jianlin,
> 
> Care to send a v4 of the patch with a comment to why we are checking the
> symbol for ':'.

Thank you!

> 
> Thanks!
> 
> -- Steve
> 


-- 
Masami Hiramatsu <mhiramat@kernel.org>

RE: [PATCH v3] tracing: precise log info for kretprobe addr err

[Jianlin Lv]

> -----Original Message-----
> From: Masami Hiramatsu <mhiramat@kernel.org>
> Sent: Tuesday, January 26, 2021 12:16 PM
> To: Steven Rostedt <rostedt@goodmis.org>
> Cc: Oleg Nesterov <oleg@redhat.com>; Jianlin Lv <Jianlin.Lv@arm.com>;
> mingo@redhat.com; mhiramat@kernel.org; linux-kernel@vger.kernel.org
> Subject: Re: [PATCH v3] tracing: precise log info for kretprobe addr err
>
> On Mon, 25 Jan 2021 13:38:40 -0500
> Steven Rostedt <rostedt@goodmis.org> wrote:
>
> > On Mon, 25 Jan 2021 19:19:27 +0100
> > Oleg Nesterov <oleg@redhat.com> wrote:
> >
> > > On 01/26, Jianlin Lv 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
> > >
> > > IOW, the "offset != 0" check removed by this patch is obviously wrong,
> right?
> > >
>
> No, not wrong. Even offset != 0, if the symbol exists in the kernel,
> kprobe_on_func_entry() will check it.
>
> > > Agreed, but...
> > >
> > > > --- 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)) {
> > >
> > > but why did you add the strchr(':') check instead?
> > >
> > > I was really puzzled until I found the this email from Masami:
> > >
> https://lore.kernel.org/lkml/20210120131406.5a992c1e434681750a0cd5d4
> > > @kernel.org/
> > >
> > > So I leave this to you and Masami, but perhaps you can document this
> > > check at least in the changelog?
> > >
> >
> > No, you are correct. That needs to be documented in the code.
>
> Agreed. There should be commented that is defered until the module is
> loaded.
>
> >
> > I was about to comment that the check requires a comment ;-)
> >
> > Jianlin,
> >
> > Care to send a v4 of the patch with a comment to why we are checking
> > the symbol for ':'.
>
> Thank you!
>
> >
> > Thanks!
> >
> > -- Steve
> >

Thanks for everyone's comments;  I will update this patch.
In addition, I have another question.

perf-probe can add a probe on a module which has not been loaded yet.
But I still get an error when I execute the following command:
# perf probe -m /lib/modules/5.11.0-rc2+/kernel/drivers/net/vxlan.ko
'vxlan_xmit%return $retval'
Failed to write event: Invalid argument
  Error: Failed to add events.

According to my investigation, __register_trace_kprobe will return -EINVAL,
because the vxlan module is not loaded;

__register_trace_kprobe
->register_kretprobe
->kprobe_on_func_entry
->return -EINVAL;

The following code snippet shows that the probe of the offline module can be
registered successfully only when the ret value is -ENOENT.

ret = __register_trace_kprobe(tk);
if (ret == -ENOENT && !trace_kprobe_module_exist(tk)) {
pr_warn("This probe might be able to register after target module is loaded. Continue.\n");
ret = 0;
}

kretprobe events not work with Offline Modules.
Is this a bug?

Jianlin

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

Re: [PATCH v3] tracing: precise log info for kretprobe addr err

[Oleg Nesterov]

On 01/26, Masami Hiramatsu wrote:
>
> > >
> > > IOW, the "offset != 0" check removed by this patch is obviously wrong, right?
> > >
>
> No, not wrong. Even offset != 0, if the symbol exists in the kernel,
> kprobe_on_func_entry() will check it.

Yes, but unless I am totally confused... if kprobe_on_func_entry() returns false,
then trace_kprobe_create() should fail with BAD_RETPROBE even if offset == 0 ?

Oleg.

Re: [PATCH v3] tracing: precise log info for kretprobe addr err

[Steven Rostedt]

On Tue, 26 Jan 2021 21:20:59 +0100
Oleg Nesterov <oleg@redhat.com> wrote:

> > No, not wrong. Even offset != 0, if the symbol exists in the kernel,
> > kprobe_on_func_entry() will check it.  
> 
> Yes, but unless I am totally confused... if kprobe_on_func_entry() returns false,
> then trace_kprobe_create() should fail with BAD_RETPROBE even if offset == 0 ?

From what I understand. kprobe_on_func_entry() can return false if you pass
in: "MOD:not_yet_loaded_module_func", but this is OK, because when the
module is loaded, and the "not_yet_loaded_module_func" exists, the
kretprobe will then be added.

The strchr(symbol,":") check is to see if "MOD:" (or some other ":" command)
is in the name, and we don't want it to fail if it is. Which is why we
should have that commented.

-- Steve

Re: [PATCH v3] tracing: precise log info for kretprobe addr err

[Oleg Nesterov]

On 01/26, Steven Rostedt wrote:
>
> On Tue, 26 Jan 2021 21:20:59 +0100
> Oleg Nesterov <oleg@redhat.com> wrote:
>
> > > No, not wrong. Even offset != 0, if the symbol exists in the kernel,
> > > kprobe_on_func_entry() will check it.
> >
> > Yes, but unless I am totally confused... if kprobe_on_func_entry() returns false,
> > then trace_kprobe_create() should fail with BAD_RETPROBE even if offset == 0 ?
>
> From what I understand. kprobe_on_func_entry() can return false if you pass
> in: "MOD:not_yet_loaded_module_func", but this is OK, because when the
> module is loaded, and the "not_yet_loaded_module_func" exists, the
> kretprobe will then be added.
>
> The strchr(symbol,":") check is to see if "MOD:" (or some other ":" command)
> is in the name, and we don't want it to fail if it is. Which is why we
> should have that commented.

Agreed, this matches my understanding.

But just in case... not sure I read this code correctly, but I think that
module_kallsyms_lookup_name("not_yet_loaded_module_func") should work even
without the "MOD:" prefix.

IOW, kprobe_on_func_entry("not_yet_loaded_module_func") can fail, and then
later succeed if you load the module which provides this symbol.

But even if I am right, I agree with the strchr(symbol,":") check.

Oleg.

Re: [PATCH v3] tracing: precise log info for kretprobe addr err

[Steven Rostedt]

On Tue, 26 Jan 2021 22:17:23 +0100
Oleg Nesterov <oleg@redhat.com> wrote:

> On 01/26, Steven Rostedt wrote:
> >
> > On Tue, 26 Jan 2021 21:20:59 +0100
> > Oleg Nesterov <oleg@redhat.com> wrote:
> >  
> > > > No, not wrong. Even offset != 0, if the symbol exists in the kernel,
> > > > kprobe_on_func_entry() will check it.  
> > >
> > > Yes, but unless I am totally confused... if kprobe_on_func_entry() returns false,
> > > then trace_kprobe_create() should fail with BAD_RETPROBE even if offset == 0 ?  
> >
> > From what I understand. kprobe_on_func_entry() can return false if you pass
> > in: "MOD:not_yet_loaded_module_func", but this is OK, because when the
> > module is loaded, and the "not_yet_loaded_module_func" exists, the
> > kretprobe will then be added.
> >
> > The strchr(symbol,":") check is to see if "MOD:" (or some other ":" command)
> > is in the name, and we don't want it to fail if it is. Which is why we
> > should have that commented.  
> 
> Agreed, this matches my understanding.
> 
> But just in case... not sure I read this code correctly, but I think that
> module_kallsyms_lookup_name("not_yet_loaded_module_func") should work even
> without the "MOD:" prefix.
> 
> IOW, kprobe_on_func_entry("not_yet_loaded_module_func") can fail, and then
> later succeed if you load the module which provides this symbol.
> 
> But even if I am right, I agree with the strchr(symbol,":") check.

I see what you are saying. If "MOD" is not loaded yet, the
kprobe_on_func_entry() should succeed.

kprobe_on_func_entry(name) {
	_kprobe_addr(name) {
		_kprobe_lookup_name(name) {
			kallsyms_lookup_name(name) {
				module_kallsyms_lookup_name(name) {

Which is:

unsigned long module_kallsyms_lookup_name(const char *name)
{
	struct module *mod;
	char *colon;
	unsigned long ret = 0;

	/* Don't lock: we're in enough trouble already. */
	preempt_disable();
	if ((colon = strnchr(name, MODULE_NAME_LEN, ':')) != NULL) {
		if ((mod = find_module_all(name, colon - name, false)) != NULL)
			ret = find_kallsyms_symbol_value(mod, colon+1);
	} else {
		list_for_each_entry_rcu(mod, &modules, list) {
			if (mod->state == MODULE_STATE_UNFORMED)
				continue;
			if ((ret = find_kallsyms_symbol_value(mod, name)) != 0)
				break;
		}
	}
	preempt_enable();
	return ret;
}


And if find_module_all() fails, ret isn't updated, and "return ret" will
return zero.

That is, the ":" check may not be needed, but its at least good to have?

-- Steve

Re: [PATCH v3] tracing: precise log info for kretprobe addr err

[Masami Hiramatsu]

On Tue, 26 Jan 2021 16:40:38 -0500
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Tue, 26 Jan 2021 22:17:23 +0100
> Oleg Nesterov <oleg@redhat.com> wrote:
> 
> > On 01/26, Steven Rostedt wrote:
> > >
> > > On Tue, 26 Jan 2021 21:20:59 +0100
> > > Oleg Nesterov <oleg@redhat.com> wrote:
> > >  
> > > > > No, not wrong. Even offset != 0, if the symbol exists in the kernel,
> > > > > kprobe_on_func_entry() will check it.  
> > > >
> > > > Yes, but unless I am totally confused... if kprobe_on_func_entry() returns false,
> > > > then trace_kprobe_create() should fail with BAD_RETPROBE even if offset == 0 ?  
> > >
> > > From what I understand. kprobe_on_func_entry() can return false if you pass
> > > in: "MOD:not_yet_loaded_module_func", but this is OK, because when the
> > > module is loaded, and the "not_yet_loaded_module_func" exists, the
> > > kretprobe will then be added.
> > >
> > > The strchr(symbol,":") check is to see if "MOD:" (or some other ":" command)
> > > is in the name, and we don't want it to fail if it is. Which is why we
> > > should have that commented.  
> > 
> > Agreed, this matches my understanding.
> > 
> > But just in case... not sure I read this code correctly, but I think that
> > module_kallsyms_lookup_name("not_yet_loaded_module_func") should work even
> > without the "MOD:" prefix.
> > 
> > IOW, kprobe_on_func_entry("not_yet_loaded_module_func") can fail, and then
> > later succeed if you load the module which provides this symbol.
> > 
> > But even if I am right, I agree with the strchr(symbol,":") check.
> 
> I see what you are saying. If "MOD" is not loaded yet, the
> kprobe_on_func_entry() should succeed.

No, that makes me more confused. kprobes_on_func_entry() returns true
only if it confirms the given address is on the function entry, because
it is used in the register_kretprobe() too.

OK, I will make a separate check which detects an error that the
module is loaded but the symbol does not exist.
(current code doesn't check the module is loaded or not)

That makes the code clearer.

Thank you,

-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [PATCH v3] tracing: precise log info for kretprobe addr err

[Masami Hiramatsu]

On Tue, 26 Jan 2021 21:20:59 +0100
Oleg Nesterov <oleg@redhat.com> wrote:

> On 01/26, Masami Hiramatsu wrote:
> >
> > > >
> > > > IOW, the "offset != 0" check removed by this patch is obviously wrong, right?
> > > >
> >
> > No, not wrong. Even offset != 0, if the symbol exists in the kernel,
> > kprobe_on_func_entry() will check it.
> 
> Yes, but unless I am totally confused... if kprobe_on_func_entry() returns false,
> then trace_kprobe_create() should fail with BAD_RETPROBE even if offset == 0 ?

Yes, if kprobe_on_func_entry() returns false, register_kretprobe() also returns
an error.

-----
int register_kretprobe(struct kretprobe *rp)
{
        int ret = 0;
        struct kretprobe_instance *inst;
        int i;
        void *addr;

        if (!kprobe_on_func_entry(rp->kp.addr, rp->kp.symbol_name, rp->kp.offset))
                return -EINVAL;

-----

Thank you,

-- 
Masami Hiramatsu <mhiramat@kernel.org>

RE: [PATCH v3] tracing: precise log info for kretprobe addr err

[Jianlin Lv]

> -----Original Message-----
> From: Masami Hiramatsu <mhiramat@kernel.org>
> Sent: Wednesday, January 27, 2021 10:02 AM
> To: Oleg Nesterov <oleg@redhat.com>
> Cc: Steven Rostedt <rostedt@goodmis.org>; Jianlin Lv <Jianlin.Lv@arm.com>;
> mingo@redhat.com; linux-kernel@vger.kernel.org
> Subject: Re: [PATCH v3] tracing: precise log info for kretprobe addr err
>
> On Tue, 26 Jan 2021 21:20:59 +0100
> Oleg Nesterov <oleg@redhat.com> wrote:
>
> > On 01/26, Masami Hiramatsu wrote:
> > >
> > > > >
> > > > > IOW, the "offset != 0" check removed by this patch is obviously wrong,
> right?
> > > > >
> > >
> > > No, not wrong. Even offset != 0, if the symbol exists in the kernel,
> > > kprobe_on_func_entry() will check it.
> >
> > Yes, but unless I am totally confused... if kprobe_on_func_entry()
> > returns false, then trace_kprobe_create() should fail with BAD_RETPROBE
> even if offset == 0 ?
>
> Yes, if kprobe_on_func_entry() returns false, register_kretprobe() also
> returns an error.
>
> -----
> int register_kretprobe(struct kretprobe *rp) {
>         int ret = 0;
>         struct kretprobe_instance *inst;
>         int i;
>         void *addr;
>
>         if (!kprobe_on_func_entry(rp->kp.addr, rp->kp.symbol_name, rp-
> >kp.offset))
>                 return -EINVAL;
>
> -----
>
> Thank you,
>
> --
> Masami Hiramatsu <mhiramat@kernel.org>


If register_kretprobe()returns an error -EINVAL.
This means that __register_trace_kprobe return -EINVAL,

---
ret = __register_trace_kprobe(tk);
if (ret == -ENOENT && !trace_kprobe_module_exist(tk)) {
pr_warn("This probe might be able to register after target module is loaded. Continue.\n");
ret = 0;
}
---
As code show, cannot enable kretprobe for an unloaded module.

This is consistent with my test results (no VXLAN module is loaded).

# perf probe -m /lib/modules/5.11.0-rc2+/kernel/drivers/net/vxlan.ko  \
'vxlan_xmit%return $retval'
Failed to write event: Invalid argument
  Error: Failed to add events.

Is this a bug?

Jianlin

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.

Re: [PATCH v3] tracing: precise log info for kretprobe addr err

[Masami Hiramatsu]

On Wed, 27 Jan 2021 02:46:10 +0000
Jianlin Lv <Jianlin.Lv@arm.com> wrote:

> 
> 
> > -----Original Message-----
> > From: Masami Hiramatsu <mhiramat@kernel.org>
> > Sent: Wednesday, January 27, 2021 10:02 AM
> > To: Oleg Nesterov <oleg@redhat.com>
> > Cc: Steven Rostedt <rostedt@goodmis.org>; Jianlin Lv <Jianlin.Lv@arm.com>;
> > mingo@redhat.com; linux-kernel@vger.kernel.org
> > Subject: Re: [PATCH v3] tracing: precise log info for kretprobe addr err
> >
> > On Tue, 26 Jan 2021 21:20:59 +0100
> > Oleg Nesterov <oleg@redhat.com> wrote:
> >
> > > On 01/26, Masami Hiramatsu wrote:
> > > >
> > > > > >
> > > > > > IOW, the "offset != 0" check removed by this patch is obviously wrong,
> > right?
> > > > > >
> > > >
> > > > No, not wrong. Even offset != 0, if the symbol exists in the kernel,
> > > > kprobe_on_func_entry() will check it.
> > >
> > > Yes, but unless I am totally confused... if kprobe_on_func_entry()
> > > returns false, then trace_kprobe_create() should fail with BAD_RETPROBE
> > even if offset == 0 ?
> >
> > Yes, if kprobe_on_func_entry() returns false, register_kretprobe() also
> > returns an error.
> >
> > -----
> > int register_kretprobe(struct kretprobe *rp) {
> >         int ret = 0;
> >         struct kretprobe_instance *inst;
> >         int i;
> >         void *addr;
> >
> >         if (!kprobe_on_func_entry(rp->kp.addr, rp->kp.symbol_name, rp-
> > >kp.offset))
> >                 return -EINVAL;
> >
> > -----
> >
> > Thank you,
> >
> > --
> > Masami Hiramatsu <mhiramat@kernel.org>
> 
> 
> If register_kretprobe()returns an error -EINVAL.
> This means that __register_trace_kprobe return -EINVAL,
> 
> ---
> ret = __register_trace_kprobe(tk);
> if (ret == -ENOENT && !trace_kprobe_module_exist(tk)) {
> pr_warn("This probe might be able to register after target module is loaded. Continue.\n");
> ret = 0;
> }
> ---
> As code show, cannot enable kretprobe for an unloaded module.
> 
> This is consistent with my test results (no VXLAN module is loaded).
> 
> # perf probe -m /lib/modules/5.11.0-rc2+/kernel/drivers/net/vxlan.ko  \
> 'vxlan_xmit%return $retval'
> Failed to write event: Invalid argument
>   Error: Failed to add events.
> 
> Is this a bug?

Oops, good catch!
It seems that the bug has been introduced when I added kprobe_on_func_entry() to register_Kretprobe.
Let me fix it.

Thank you!


-- 
Masami Hiramatsu <mhiramat@kernel.org>

RE: [PATCH v3] tracing: precise log info for kretprobe addr err

[Jianlin Lv]

> -----Original Message-----
> From: Masami Hiramatsu <mhiramat@kernel.org>
> Sent: Wednesday, January 27, 2021 9:28 PM
> To: Jianlin Lv <Jianlin.Lv@arm.com>
> Cc: Oleg Nesterov <oleg@redhat.com>; Steven Rostedt
> <rostedt@goodmis.org>; mingo@redhat.com; linux-kernel@vger.kernel.org
> Subject: Re: [PATCH v3] tracing: precise log info for kretprobe addr err
>
> On Wed, 27 Jan 2021 02:46:10 +0000
> Jianlin Lv <Jianlin.Lv@arm.com> wrote:
>
> >
> >
> > > -----Original Message-----
> > > From: Masami Hiramatsu <mhiramat@kernel.org>
> > > Sent: Wednesday, January 27, 2021 10:02 AM
> > > To: Oleg Nesterov <oleg@redhat.com>
> > > Cc: Steven Rostedt <rostedt@goodmis.org>; Jianlin Lv
> > > <Jianlin.Lv@arm.com>; mingo@redhat.com; linux-
> kernel@vger.kernel.org
> > > Subject: Re: [PATCH v3] tracing: precise log info for kretprobe addr
> > > err
> > >
> > > On Tue, 26 Jan 2021 21:20:59 +0100
> > > Oleg Nesterov <oleg@redhat.com> wrote:
> > >
> > > > On 01/26, Masami Hiramatsu wrote:
> > > > >
> > > > > > >
> > > > > > > IOW, the "offset != 0" check removed by this patch is
> > > > > > > obviously wrong,
> > > right?
> > > > > > >
> > > > >
> > > > > No, not wrong. Even offset != 0, if the symbol exists in the
> > > > > kernel,
> > > > > kprobe_on_func_entry() will check it.
> > > >
> > > > Yes, but unless I am totally confused... if kprobe_on_func_entry()
> > > > returns false, then trace_kprobe_create() should fail with
> > > > BAD_RETPROBE
> > > even if offset == 0 ?
> > >
> > > Yes, if kprobe_on_func_entry() returns false, register_kretprobe()
> > > also returns an error.
> > >
> > > -----
> > > int register_kretprobe(struct kretprobe *rp) {
> > >         int ret = 0;
> > >         struct kretprobe_instance *inst;
> > >         int i;
> > >         void *addr;
> > >
> > >         if (!kprobe_on_func_entry(rp->kp.addr, rp->kp.symbol_name,
> > > rp-
> > > >kp.offset))
> > >                 return -EINVAL;
> > >
> > > -----
> > >
> > > Thank you,
> > >
> > > --
> > > Masami Hiramatsu <mhiramat@kernel.org>
> >
> >
> > If register_kretprobe()returns an error -EINVAL.
> > This means that __register_trace_kprobe return -EINVAL,
> >
> > ---
> > ret = __register_trace_kprobe(tk);
> > if (ret == -ENOENT && !trace_kprobe_module_exist(tk)) { pr_warn("This
> > probe might be able to register after target module is loaded.
> > Continue.\n"); ret = 0; }
> > ---
> > As code show, cannot enable kretprobe for an unloaded module.
> >
> > This is consistent with my test results (no VXLAN module is loaded).
> >
> > # perf probe -m /lib/modules/5.11.0-rc2+/kernel/drivers/net/vxlan.ko
> > \ 'vxlan_xmit%return $retval'
> > Failed to write event: Invalid argument
> >   Error: Failed to add events.
> >
> > Is this a bug?
>
> Oops, good catch!
> It seems that the bug has been introduced when I added
> kprobe_on_func_entry() to register_Kretprobe.
> Let me fix it.
>
> Thank you!
>
>
> --
> Masami Hiramatsu <mhiramat@kernel.org>

After confirming this problem, my worries are eliminated,
and the current patch will be updated later.

I am also investigating this bug, and I think this process will deepen
my understanding of kernel probes.

Jianlin

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.