[PATCH] tracing/boottime: Fix kprobe multiple events

[PATCH] tracing/boottime: Fix kprobe multiple events

[Sascha Ortmann]

Fix boottime kprobe events to add multiple events even if one fails
and report probe generation failures.

As an example, when we try to set multiprobe kprobe events in
bootconfig like this:

ftrace.event.kprobes.vfsevents {
	probes = "vfs_read $arg1 $arg2,,
                 !error! not reported;?", // leads to error
		 "vfs_write $arg1 $arg2"
}

this will not work like expected. After commit
da0f1f4167e3af69e1d8b32d6d65195ddd2bfb64 ("tracing/boottime:
Fix kprobe event API usage"), the function
trace_boot_add_kprobe_event will not produce any error message,
aborting the function and stopping subsequent probes from getting
installed when adding a probe fails at kprobe_event_gen_cmd_start.
Furthermore, probes continue when kprobe_event_gen_cmd_end fails
(and kprobe_event_gen_cmd_start did not fail). In this case the
function even returns successfully when the last call to
kprobe_event_gen_cmd_end is successful.

The behaviour of reporting and aborting after failures is not
consistent.

The function trace_boot_add_kprobe_event now continues even when
one of the multiple events fails. Each failure is now reported
individually. Since the function can only return one result to the
caller, the function returns now the last failure (or none, if
nothing fails).

Cc: linux-kernel@i4.cs.fau.de
Signed-off-by: Maximilian Werner <maximilian.werner96@gmail.com>
Signed-off-by: Sascha Ortmann <sascha.ortmann@stud.uni-hannover.de>
---
 kernel/trace/trace_boot.c | 16 +++++++++++-----
 1 file changed, 11 insertions(+), 5 deletions(-)

diff --git a/kernel/trace/trace_boot.c b/kernel/trace/trace_boot.c
index 9de29bb45a27..dbb50184e060 100644
--- a/kernel/trace/trace_boot.c
+++ b/kernel/trace/trace_boot.c
@@ -95,18 +95,24 @@ trace_boot_add_kprobe_event(struct xbc_node *node, const char *event)
 	struct xbc_node *anode;
 	char buf[MAX_BUF_LEN];
 	const char *val;
+	int error = 0;
 	int ret = 0;
 
 	xbc_node_for_each_array_value(node, "probes", anode, val) {
 		kprobe_event_cmd_init(&cmd, buf, MAX_BUF_LEN);
 
-		ret = kprobe_event_gen_cmd_start(&cmd, event, val);
-		if (ret)
-			break;
+		error = kprobe_event_gen_cmd_start(&cmd, event, val);
+		if (error) {
+			pr_err("Failed to generate probe: %s\n", buf);
+			ret = error;
+			continue;
+		}
 
-		ret = kprobe_event_gen_cmd_end(&cmd);
-		if (ret)
+		error = kprobe_event_gen_cmd_end(&cmd);
+		if (error) {
 			pr_err("Failed to add probe: %s\n", buf);
+			ret = error;
+		}
 	}
 
 	return ret;
-- 
2.17.1

Re: [PATCH] tracing/boottime: Fix kprobe multiple events

[Steven Rostedt]

On Wed, 17 Jun 2020 16:08:17 +0200
Sascha Ortmann <sascha.ortmann@stud.uni-hannover.de> wrote:

> Fix boottime kprobe events to add multiple events even if one fails
> and report probe generation failures.
> 
> As an example, when we try to set multiprobe kprobe events in
> bootconfig like this:
> 
> ftrace.event.kprobes.vfsevents {
> 	probes = "vfs_read $arg1 $arg2,,
>                  !error! not reported;?", // leads to error
> 		 "vfs_write $arg1 $arg2"
> }
> 
> this will not work like expected. After commit
> da0f1f4167e3af69e1d8b32d6d65195ddd2bfb64 ("tracing/boottime:
> Fix kprobe event API usage"), the function
> trace_boot_add_kprobe_event will not produce any error message,
> aborting the function and stopping subsequent probes from getting
> installed when adding a probe fails at kprobe_event_gen_cmd_start.
> Furthermore, probes continue when kprobe_event_gen_cmd_end fails
> (and kprobe_event_gen_cmd_start did not fail). In this case the
> function even returns successfully when the last call to
> kprobe_event_gen_cmd_end is successful.
> 
> The behaviour of reporting and aborting after failures is not
> consistent.
> 
> The function trace_boot_add_kprobe_event now continues even when
> one of the multiple events fails. Each failure is now reported
> individually. Since the function can only return one result to the
> caller, the function returns now the last failure (or none, if
> nothing fails).
> 
> Cc: linux-kernel@i4.cs.fau.de
> Signed-off-by: Maximilian Werner <maximilian.werner96@gmail.com>
> Signed-off-by: Sascha Ortmann <sascha.ortmann@stud.uni-hannover.de>

Why the double signed off by?

Masami, I'm fine with this, but needs your review.

-- Steve

> ---
>  kernel/trace/trace_boot.c | 16 +++++++++++-----
>  1 file changed, 11 insertions(+), 5 deletions(-)
> 
> diff --git a/kernel/trace/trace_boot.c b/kernel/trace/trace_boot.c
> index 9de29bb45a27..dbb50184e060 100644
> --- a/kernel/trace/trace_boot.c
> +++ b/kernel/trace/trace_boot.c
> @@ -95,18 +95,24 @@ trace_boot_add_kprobe_event(struct xbc_node *node, const char *event)
>  	struct xbc_node *anode;
>  	char buf[MAX_BUF_LEN];
>  	const char *val;
> +	int error = 0;
>  	int ret = 0;
>  
>  	xbc_node_for_each_array_value(node, "probes", anode, val) {
>  		kprobe_event_cmd_init(&cmd, buf, MAX_BUF_LEN);
>  
> -		ret = kprobe_event_gen_cmd_start(&cmd, event, val);
> -		if (ret)
> -			break;
> +		error = kprobe_event_gen_cmd_start(&cmd, event, val);
> +		if (error) {
> +			pr_err("Failed to generate probe: %s\n", buf);
> +			ret = error;
> +			continue;
> +		}
>  
> -		ret = kprobe_event_gen_cmd_end(&cmd);
> -		if (ret)
> +		error = kprobe_event_gen_cmd_end(&cmd);
> +		if (error) {
>  			pr_err("Failed to add probe: %s\n", buf);
> +			ret = error;
> +		}
>  	}
>  
>  	return ret;

Re: [PATCH] tracing/boottime: Fix kprobe multiple events

[Steven Rostedt]

On Wed, 17 Jun 2020 11:05:21 -0400
Steven Rostedt <rostedt@goodmis.org> wrote:

> On Wed, 17 Jun 2020 16:08:17 +0200
> Sascha Ortmann <sascha.ortmann@stud.uni-hannover.de> wrote:
> 
> > Fix boottime kprobe events to add multiple events even if one fails
> > and report probe generation failures.
> > 
> > As an example, when we try to set multiprobe kprobe events in
> > bootconfig like this:
> > 
> > ftrace.event.kprobes.vfsevents {
> > 	probes = "vfs_read $arg1 $arg2,,
> >                  !error! not reported;?", // leads to error
> > 		 "vfs_write $arg1 $arg2"
> > }
> > 
> > this will not work like expected. After commit
> > da0f1f4167e3af69e1d8b32d6d65195ddd2bfb64 ("tracing/boottime:
> > Fix kprobe event API usage"), the function
> > trace_boot_add_kprobe_event will not produce any error message,
> > aborting the function and stopping subsequent probes from getting
> > installed when adding a probe fails at kprobe_event_gen_cmd_start.
> > Furthermore, probes continue when kprobe_event_gen_cmd_end fails
> > (and kprobe_event_gen_cmd_start did not fail). In this case the
> > function even returns successfully when the last call to
> > kprobe_event_gen_cmd_end is successful.
> > 
> > The behaviour of reporting and aborting after failures is not
> > consistent.
> > 
> > The function trace_boot_add_kprobe_event now continues even when
> > one of the multiple events fails. Each failure is now reported
> > individually. Since the function can only return one result to the
> > caller, the function returns now the last failure (or none, if
> > nothing fails).
> > 
> > Cc: linux-kernel@i4.cs.fau.de
> > Signed-off-by: Maximilian Werner <maximilian.werner96@gmail.com>
> > Signed-off-by: Sascha Ortmann <sascha.ortmann@stud.uni-hannover.de>  
> 
> Why the double signed off by?
> 
> Masami, I'm fine with this, but needs your review.

[ It appears that Masami wasn't in the Cc ]


> 
> -- Steve
> 
> > ---
> >  kernel/trace/trace_boot.c | 16 +++++++++++-----
> >  1 file changed, 11 insertions(+), 5 deletions(-)
> > 
> > diff --git a/kernel/trace/trace_boot.c b/kernel/trace/trace_boot.c
> > index 9de29bb45a27..dbb50184e060 100644
> > --- a/kernel/trace/trace_boot.c
> > +++ b/kernel/trace/trace_boot.c
> > @@ -95,18 +95,24 @@ trace_boot_add_kprobe_event(struct xbc_node *node, const char *event)
> >  	struct xbc_node *anode;
> >  	char buf[MAX_BUF_LEN];
> >  	const char *val;
> > +	int error = 0;
> >  	int ret = 0;
> >  
> >  	xbc_node_for_each_array_value(node, "probes", anode, val) {
> >  		kprobe_event_cmd_init(&cmd, buf, MAX_BUF_LEN);
> >  
> > -		ret = kprobe_event_gen_cmd_start(&cmd, event, val);
> > -		if (ret)
> > -			break;
> > +		error = kprobe_event_gen_cmd_start(&cmd, event, val);
> > +		if (error) {
> > +			pr_err("Failed to generate probe: %s\n", buf);
> > +			ret = error;
> > +			continue;
> > +		}
> >  
> > -		ret = kprobe_event_gen_cmd_end(&cmd);
> > -		if (ret)
> > +		error = kprobe_event_gen_cmd_end(&cmd);
> > +		if (error) {
> >  			pr_err("Failed to add probe: %s\n", buf);
> > +			ret = error;
> > +		}
> >  	}
> >  
> >  	return ret;  
> 

Re: [PATCH] tracing/boottime: Fix kprobe multiple events

[Maximilian Werner]

We are a group of students from Leibniz University Hannover and
this patch is part of a project of ours. That's why both of us
signed this off.

Should we have added Masami to Cc? He didn't appear in the
get_maintainer script.

-- Maximilian & Sascha

On 17.06.20 17:06, Steven Rostedt wrote:
> On Wed, 17 Jun 2020 11:05:21 -0400
> Steven Rostedt <rostedt@goodmis.org> wrote:
> 
>> On Wed, 17 Jun 2020 16:08:17 +0200
>> Sascha Ortmann <sascha.ortmann@stud.uni-hannover.de> wrote:
>>
>>> Fix boottime kprobe events to add multiple events even if one fails
>>> and report probe generation failures.
>>>
>>> As an example, when we try to set multiprobe kprobe events in
>>> bootconfig like this:
>>>
>>> ftrace.event.kprobes.vfsevents {
>>> 	probes = "vfs_read $arg1 $arg2,,
>>>                   !error! not reported;?", // leads to error
>>> 		 "vfs_write $arg1 $arg2"
>>> }
>>>
>>> this will not work like expected. After commit
>>> da0f1f4167e3af69e1d8b32d6d65195ddd2bfb64 ("tracing/boottime:
>>> Fix kprobe event API usage"), the function
>>> trace_boot_add_kprobe_event will not produce any error message,
>>> aborting the function and stopping subsequent probes from getting
>>> installed when adding a probe fails at kprobe_event_gen_cmd_start.
>>> Furthermore, probes continue when kprobe_event_gen_cmd_end fails
>>> (and kprobe_event_gen_cmd_start did not fail). In this case the
>>> function even returns successfully when the last call to
>>> kprobe_event_gen_cmd_end is successful.
>>>
>>> The behaviour of reporting and aborting after failures is not
>>> consistent.
>>>
>>> The function trace_boot_add_kprobe_event now continues even when
>>> one of the multiple events fails. Each failure is now reported
>>> individually. Since the function can only return one result to the
>>> caller, the function returns now the last failure (or none, if
>>> nothing fails).
>>>
>>> Cc: linux-kernel@i4.cs.fau.de
>>> Signed-off-by: Maximilian Werner <maximilian.werner96@gmail.com>
>>> Signed-off-by: Sascha Ortmann <sascha.ortmann@stud.uni-hannover.de>
>>
>> Why the double signed off by?
>>
>> Masami, I'm fine with this, but needs your review.
> 
> [ It appears that Masami wasn't in the Cc ]
> 
> 
>>
>> -- Steve
>>
>>> ---
>>>   kernel/trace/trace_boot.c | 16 +++++++++++-----
>>>   1 file changed, 11 insertions(+), 5 deletions(-)
>>>
>>> diff --git a/kernel/trace/trace_boot.c b/kernel/trace/trace_boot.c
>>> index 9de29bb45a27..dbb50184e060 100644
>>> --- a/kernel/trace/trace_boot.c
>>> +++ b/kernel/trace/trace_boot.c
>>> @@ -95,18 +95,24 @@ trace_boot_add_kprobe_event(struct xbc_node *node, const char *event)
>>>   	struct xbc_node *anode;
>>>   	char buf[MAX_BUF_LEN];
>>>   	const char *val;
>>> +	int error = 0;
>>>   	int ret = 0;
>>>   
>>>   	xbc_node_for_each_array_value(node, "probes", anode, val) {
>>>   		kprobe_event_cmd_init(&cmd, buf, MAX_BUF_LEN);
>>>   
>>> -		ret = kprobe_event_gen_cmd_start(&cmd, event, val);
>>> -		if (ret)
>>> -			break;
>>> +		error = kprobe_event_gen_cmd_start(&cmd, event, val);
>>> +		if (error) {
>>> +			pr_err("Failed to generate probe: %s\n", buf);
>>> +			ret = error;
>>> +			continue;
>>> +		}
>>>   
>>> -		ret = kprobe_event_gen_cmd_end(&cmd);
>>> -		if (ret)
>>> +		error = kprobe_event_gen_cmd_end(&cmd);
>>> +		if (error) {
>>>   			pr_err("Failed to add probe: %s\n", buf);
>>> +			ret = error;
>>> +		}
>>>   	}
>>>   
>>>   	return ret;
>>
> 

Re: [PATCH] tracing/boottime: Fix kprobe multiple events

[Steven Rostedt]

On Wed, 17 Jun 2020 17:57:13 +0200
Maximilian Werner <maximilian.werner96@gmail.com> wrote:

> We are a group of students from Leibniz University Hannover and
> this patch is part of a project of ours. That's why both of us
> signed this off.

Usually, if there's two people signed off, there's a comment in the
change log that states the other person worked on the patch as well.

> 
> Should we have added Masami to Cc? He didn't appear in the
> get_maintainer script.
> 

Yeah, we need to update the MAINTAINER's file to fix that. Not your
fault.

-- Steve

Re: [PATCH] tracing/boottime: Fix kprobe multiple events

[Masami Hiramatsu]

Hi,

On Wed, 17 Jun 2020 16:08:17 +0200
Sascha Ortmann <sascha.ortmann@stud.uni-hannover.de> wrote:

> Fix boottime kprobe events to add multiple events even if one fails
> and report probe generation failures.
> 
> As an example, when we try to set multiprobe kprobe events in
> bootconfig like this:
> 
> ftrace.event.kprobes.vfsevents {
> 	probes = "vfs_read $arg1 $arg2,,
>                  !error! not reported;?", // leads to error
> 		 "vfs_write $arg1 $arg2"
> }
> 
> this will not work like expected. After commit
> da0f1f4167e3af69e1d8b32d6d65195ddd2bfb64 ("tracing/boottime:
> Fix kprobe event API usage"), the function
> trace_boot_add_kprobe_event will not produce any error message,
> aborting the function and stopping subsequent probes from getting
> installed when adding a probe fails at kprobe_event_gen_cmd_start.

Ah, good catch!
Indeed, I missed the error message.

> Furthermore, probes continue when kprobe_event_gen_cmd_end fails
> (and kprobe_event_gen_cmd_start did not fail). In this case the
> function even returns successfully when the last call to
> kprobe_event_gen_cmd_end is successful.
> 
> The behaviour of reporting and aborting after failures is not
> consistent.

OK. And for more consistency, we should abort the loop if we hit any
error instead of continuing, because if trace_boot_add_kprobe_event()
returns an error code, the rest of event settings are skipped.
(See trace_boot_init_one_event())

> 
> The function trace_boot_add_kprobe_event now continues even when
> one of the multiple events fails. Each failure is now reported
> individually. Since the function can only return one result to the
> caller, the function returns now the last failure (or none, if
> nothing fails).
> 
> Cc: linux-kernel@i4.cs.fau.de
> Signed-off-by: Maximilian Werner <maximilian.werner96@gmail.com>
> Signed-off-by: Sascha Ortmann <sascha.ortmann@stud.uni-hannover.de>
> ---
>  kernel/trace/trace_boot.c | 16 +++++++++++-----
>  1 file changed, 11 insertions(+), 5 deletions(-)
> 
> diff --git a/kernel/trace/trace_boot.c b/kernel/trace/trace_boot.c
> index 9de29bb45a27..dbb50184e060 100644
> --- a/kernel/trace/trace_boot.c
> +++ b/kernel/trace/trace_boot.c
> @@ -95,18 +95,24 @@ trace_boot_add_kprobe_event(struct xbc_node *node, const char *event)
>  	struct xbc_node *anode;
>  	char buf[MAX_BUF_LEN];
>  	const char *val;
> +	int error = 0;
>  	int ret = 0;
>  
>  	xbc_node_for_each_array_value(node, "probes", anode, val) {
>  		kprobe_event_cmd_init(&cmd, buf, MAX_BUF_LEN);
>  
> -		ret = kprobe_event_gen_cmd_start(&cmd, event, val);
> -		if (ret)
> -			break;
> +		error = kprobe_event_gen_cmd_start(&cmd, event, val);
> +		if (error) {
> +			pr_err("Failed to generate probe: %s\n", buf);
> +			ret = error;
> +			continue;

so, could you break here?

> +		}
>  
> -		ret = kprobe_event_gen_cmd_end(&cmd);
> -		if (ret)
> +		error = kprobe_event_gen_cmd_end(&cmd);
> +		if (error) {
>  			pr_err("Failed to add probe: %s\n", buf);
> +			ret = error;

And here.

> +		}
>  	}
>  
>  	return ret;
> -- 
> 2.17.1
> 

Thank you!


-- 
Masami Hiramatsu <mhiramat@kernel.org>

[PATCH v2] tracing/boottime: Fix kprobe multiple events

[Sascha Ortmann]

Fix boottime kprobe events to report and abort after each failure when
adding probes.

As an example, when we try to set multiprobe kprobe events in
bootconfig like this:

ftrace.event.kprobes.vfsevents {
        probes = "vfs_read $arg1 $arg2,,
                 !error! not reported;?", // leads to error
                 "vfs_write $arg1 $arg2"
}

This will not work as expected. After 
commit da0f1f4167e3af69e ("tracing/boottime: Fix kprobe event API usage"), 
the function trace_boot_add_kprobe_event will not produce any error 
message when adding a probe fails at kprobe_event_gen_cmd_start. 
Furthermore, we continue to add probes when kprobe_event_gen_cmd_end fails
(and kprobe_event_gen_cmd_start did not fail). In this case the function 
even returns successfully when the last call to kprobe_event_gen_cmd_end
is successful.

The behaviour of reporting and aborting after failures is not
consistent.

The function trace_boot_add_kprobe_event now reports each failure and
stops adding probes immediately.

Cc: linux-kernel@i4.cs.fau.de
Co-developed-by: Maximilian Werner <maximilian.werner96@gmail.com>
Signed-off-by: Maximilian Werner <maximilian.werner96@gmail.com>
Signed-off-by: Sascha Ortmann <sascha.ortmann@stud.uni-hannover.de>
---
 kernel/trace/trace_boot.c | 8 ++++++--
 1 file changed, 6 insertions(+), 2 deletions(-)

diff --git a/kernel/trace/trace_boot.c b/kernel/trace/trace_boot.c
index 9de29bb45a27..be893eb22071 100644
--- a/kernel/trace/trace_boot.c
+++ b/kernel/trace/trace_boot.c
@@ -101,12 +101,16 @@ trace_boot_add_kprobe_event(struct xbc_node *node, const char *event)
 		kprobe_event_cmd_init(&cmd, buf, MAX_BUF_LEN);
 
 		ret = kprobe_event_gen_cmd_start(&cmd, event, val);
-		if (ret)
+		if (ret) {
+			pr_err("Failed to generate probe: %s\n", buf);
 			break;
+		}
 
 		ret = kprobe_event_gen_cmd_end(&cmd);
-		if (ret)
+		if (ret) {
 			pr_err("Failed to add probe: %s\n", buf);
+			break;
+		}
 	}
 
 	return ret;
-- 
2.17.1

Re: [PATCH v2] tracing/boottime: Fix kprobe multiple events

[Masami Hiramatsu]

On Thu, 18 Jun 2020 18:33:01 +0200
Sascha Ortmann <sascha.ortmann@stud.uni-hannover.de> wrote:

> Fix boottime kprobe events to report and abort after each failure when
> adding probes.
> 
> As an example, when we try to set multiprobe kprobe events in
> bootconfig like this:
> 
> ftrace.event.kprobes.vfsevents {
>         probes = "vfs_read $arg1 $arg2,,
>                  !error! not reported;?", // leads to error
>                  "vfs_write $arg1 $arg2"
> }
> 
> This will not work as expected. After 
> commit da0f1f4167e3af69e ("tracing/boottime: Fix kprobe event API usage"), 
> the function trace_boot_add_kprobe_event will not produce any error 
> message when adding a probe fails at kprobe_event_gen_cmd_start. 
> Furthermore, we continue to add probes when kprobe_event_gen_cmd_end fails
> (and kprobe_event_gen_cmd_start did not fail). In this case the function 
> even returns successfully when the last call to kprobe_event_gen_cmd_end
> is successful.
> 
> The behaviour of reporting and aborting after failures is not
> consistent.
> 
> The function trace_boot_add_kprobe_event now reports each failure and
> stops adding probes immediately.

Thanks for updating. This looks good to me. 

Acked-by: Masami Hiramatsu <mhiramat@kernel.org>

and 

Fixes: da0f1f4167e3 ("tracing/boottime: Fix kprobe event API usage")

Thank you!

> 
> Cc: linux-kernel@i4.cs.fau.de
> Co-developed-by: Maximilian Werner <maximilian.werner96@gmail.com>
> Signed-off-by: Maximilian Werner <maximilian.werner96@gmail.com>
> Signed-off-by: Sascha Ortmann <sascha.ortmann@stud.uni-hannover.de>
> ---
>  kernel/trace/trace_boot.c | 8 ++++++--
>  1 file changed, 6 insertions(+), 2 deletions(-)
> 
> diff --git a/kernel/trace/trace_boot.c b/kernel/trace/trace_boot.c
> index 9de29bb45a27..be893eb22071 100644
> --- a/kernel/trace/trace_boot.c
> +++ b/kernel/trace/trace_boot.c
> @@ -101,12 +101,16 @@ trace_boot_add_kprobe_event(struct xbc_node *node, const char *event)
>  		kprobe_event_cmd_init(&cmd, buf, MAX_BUF_LEN);
>  
>  		ret = kprobe_event_gen_cmd_start(&cmd, event, val);
> -		if (ret)
> +		if (ret) {
> +			pr_err("Failed to generate probe: %s\n", buf);
>  			break;
> +		}
>  
>  		ret = kprobe_event_gen_cmd_end(&cmd);
> -		if (ret)
> +		if (ret) {
>  			pr_err("Failed to add probe: %s\n", buf);
> +			break;
> +		}
>  	}
>  
>  	return ret;
> -- 
> 2.17.1
> 


-- 
Masami Hiramatsu <mhiramat@kernel.org>