[GIT PULL] tracing: Have filter check for balanced ops

[GIT PULL] tracing: Have filter check for balanced ops

[Steven Rostedt]

Linus,

Vince Weaver reported a warning when he added perf event filters
into his fuzzer tests. There's a missing check of balanced
operations when parenthesis are used, and this triggers a WARN_ON()
and when reading the failure, the filter reports no failure occurred.

The operands were not being checked if they match, this adds that.

Please pull the latest trace-fix-filter-4.1-rc8 tree, which can be found at:


  git://git.kernel.org/pub/scm/linux/kernel/git/rostedt/linux-trace.git
trace-fix-filter-4.1-rc8

Tag SHA1: 34bcfc82862ee15a76b98c54126f64abf52191c3
Head SHA1: 2cf30dc180cea808077f003c5116388183e54f9e


Steven Rostedt (1):
      tracing: Have filter check for balanced ops

----
 kernel/trace/trace_events_filter.c | 11 +++++++++--
 1 file changed, 9 insertions(+), 2 deletions(-)
---------------------------
commit 2cf30dc180cea808077f003c5116388183e54f9e
Author: Steven Rostedt <rostedt@goodmis.org>
Date:   Mon Jun 15 17:50:25 2015 -0400

    tracing: Have filter check for balanced ops
    
    When the following filter is used it causes a warning to trigger:
    
     # cd /sys/kernel/debug/tracing
     # echo "((dev==1)blocks==2)" > events/ext4/ext4_truncate_exit/filter
    -bash: echo: write error: Invalid argument
     # cat events/ext4/ext4_truncate_exit/filter
    ((dev==1)blocks==2)
    ^
    parse_error: No error
    
     ------------[ cut here ]------------
     WARNING: CPU: 2 PID: 1223 at kernel/trace/trace_events_filter.c:1640 replace_preds+0x3c5/0x990()
     Modules linked in: bnep lockd grace bluetooth  ...
     CPU: 3 PID: 1223 Comm: bash Tainted: G        W       4.1.0-rc3-test+ #450
     Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v02.05 05/07/2012
      0000000000000668 ffff8800c106bc98 ffffffff816ed4f9 ffff88011ead0cf0
      0000000000000000 ffff8800c106bcd8 ffffffff8107fb07 ffffffff8136b46c
      ffff8800c7d81d48 ffff8800d4c2bc00 ffff8800d4d4f920 00000000ffffffea
     Call Trace:
      [<ffffffff816ed4f9>] dump_stack+0x4c/0x6e
      [<ffffffff8107fb07>] warn_slowpath_common+0x97/0xe0
      [<ffffffff8136b46c>] ? _kstrtoull+0x2c/0x80
      [<ffffffff8107fb6a>] warn_slowpath_null+0x1a/0x20
      [<ffffffff81159065>] replace_preds+0x3c5/0x990
      [<ffffffff811596b2>] create_filter+0x82/0xb0
      [<ffffffff81159944>] apply_event_filter+0xd4/0x180
      [<ffffffff81152bbf>] event_filter_write+0x8f/0x120
      [<ffffffff811db2a8>] __vfs_write+0x28/0xe0
      [<ffffffff811dda43>] ? __sb_start_write+0x53/0xf0
      [<ffffffff812e51e0>] ? security_file_permission+0x30/0xc0
      [<ffffffff811dc408>] vfs_write+0xb8/0x1b0
      [<ffffffff811dc72f>] SyS_write+0x4f/0xb0
      [<ffffffff816f5217>] system_call_fastpath+0x12/0x6a
     ---[ end trace e11028bd95818dcd ]---
    
    Worse yet, reading the error message (the filter again) it says that
    there was no error, when there clearly was. The issue is that the
    code that checks the input does not check for balanced ops. That is,
    having an op between a closed parenthesis and the next token.
    
    This would only cause a warning, and fail out before doing any real
    harm, but it should still not caues a warning, and the error reported
    should work:
    
     # cd /sys/kernel/debug/tracing
     # echo "((dev==1)blocks==2)" > events/ext4/ext4_truncate_exit/filter
    -bash: echo: write error: Invalid argument
     # cat events/ext4/ext4_truncate_exit/filter
    ((dev==1)blocks==2)
    ^
    parse_error: Meaningless filter expression
    
    And give no kernel warning.
    
    Link: http://lkml.kernel.org/r/20150615175025.7e809215@gandalf.local.home
    
    Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
    Cc: Ingo Molnar <mingo@redhat.com>
    Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
    Cc: stable@vger.kernel.org # 2.6.31+
    Reported-by: Vince Weaver <vincent.weaver@maine.edu>
    Tested-by: Vince Weaver <vincent.weaver@maine.edu>
    Signed-off-by: Steven Rostedt <rostedt@goodmis.org>

diff --git a/kernel/trace/trace_events_filter.c b/kernel/trace/trace_events_filter.c
index ced69da0ff55..7f2e97ce71a7 100644
--- a/kernel/trace/trace_events_filter.c
+++ b/kernel/trace/trace_events_filter.c
@@ -1369,19 +1369,26 @@ static int check_preds(struct filter_parse_state *ps)
 {
 	int n_normal_preds = 0, n_logical_preds = 0;
 	struct postfix_elt *elt;
+	int cnt = 0;
 
 	list_for_each_entry(elt, &ps->postfix, list) {
-		if (elt->op == OP_NONE)
+		if (elt->op == OP_NONE) {
+			cnt++;
 			continue;
+		}
 
 		if (elt->op == OP_AND || elt->op == OP_OR) {
 			n_logical_preds++;
+			cnt--;
 			continue;
 		}
+		if (elt->op != OP_NOT)
+			cnt--;
 		n_normal_preds++;
+		WARN_ON_ONCE(cnt < 0);
 	}
 
-	if (!n_normal_preds || n_logical_preds >= n_normal_preds) {
+	if (cnt != 1 || !n_normal_preds || n_logical_preds >= n_normal_preds) {
 		parse_error(ps, FILT_ERR_INVALID_FILTER, 0);
 		return -EINVAL;
 	}

Re: [GIT PULL] tracing: Have filter check for balanced ops

[Luis Henriques]

Hi Steven,

On Wed, Jun 17, 2015 at 08:36:38AM -0400, Steven Rostedt wrote:
...
> diff --git a/kernel/trace/trace_events_filter.c b/kernel/trace/trace_events_filter.c
> index ced69da0ff55..7f2e97ce71a7 100644
> --- a/kernel/trace/trace_events_filter.c
> +++ b/kernel/trace/trace_events_filter.c
> @@ -1369,19 +1369,26 @@ static int check_preds(struct filter_parse_state *ps)
>  {
>  	int n_normal_preds = 0, n_logical_preds = 0;
>  	struct postfix_elt *elt;
> +	int cnt = 0;
>  
>  	list_for_each_entry(elt, &ps->postfix, list) {
> -		if (elt->op == OP_NONE)
> +		if (elt->op == OP_NONE) {
> +			cnt++;
>  			continue;
> +		}
>  
>  		if (elt->op == OP_AND || elt->op == OP_OR) {
>  			n_logical_preds++;
> +			cnt--;
>  			continue;
>  		}
> +		if (elt->op != OP_NOT)
> +			cnt--;

Since the OP_NOT was introduced only with e12c09cf3087 ("tracing: Add
NOT to filtering logic"), how would stable kernels backport this fix?
Do you think that just dropping the 'if' and do the 'cnt--'
unconditionally would be ok?

Cheers,
--
Luís

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
Please read the FAQ at  http://www.tux.org/lkml/

Re: [GIT PULL] tracing: Have filter check for balanced ops

[Luis Henriques]

On Mon, Jun 22, 2015 at 02:53:17PM +0100, Luis Henriques wrote:
> Hi Steven,
> 
> On Wed, Jun 17, 2015 at 08:36:38AM -0400, Steven Rostedt wrote:
> ...
> > diff --git a/kernel/trace/trace_events_filter.c b/kernel/trace/trace_events_filter.c
> > index ced69da0ff55..7f2e97ce71a7 100644
> > --- a/kernel/trace/trace_events_filter.c
> > +++ b/kernel/trace/trace_events_filter.c
> > @@ -1369,19 +1369,26 @@ static int check_preds(struct filter_parse_state *ps)
> >  {
> >  	int n_normal_preds = 0, n_logical_preds = 0;
> >  	struct postfix_elt *elt;
> > +	int cnt = 0;
> >  
> >  	list_for_each_entry(elt, &ps->postfix, list) {
> > -		if (elt->op == OP_NONE)
> > +		if (elt->op == OP_NONE) {
> > +			cnt++;
> >  			continue;
> > +		}
> >  
> >  		if (elt->op == OP_AND || elt->op == OP_OR) {
> >  			n_logical_preds++;
> > +			cnt--;
> >  			continue;
> >  		}
> > +		if (elt->op != OP_NOT)
> > +			cnt--;
> 
> Since the OP_NOT was introduced only with e12c09cf3087 ("tracing: Add
> NOT to filtering logic"), how would stable kernels backport this fix?
> Do you think that just dropping the 'if' and do the 'cnt--'
> unconditionally would be ok?

Something like the patch below (only compile-tested).

Cheers,
--
Luís

>From db7ac73e73dd0ef0259d5d2871b7b9402b12e4d3 Mon Sep 17 00:00:00 2001
From: Steven Rostedt <rostedt@goodmis.org>
Date: Mon, 15 Jun 2015 17:50:25 -0400
Subject: [PATCH] tracing: Have filter check for balanced ops

commit 2cf30dc180cea808077f003c5116388183e54f9e upstream.

When the following filter is used it causes a warning to trigger:

 # cd /sys/kernel/debug/tracing
 # echo "((dev==1)blocks==2)" > events/ext4/ext4_truncate_exit/filter
-bash: echo: write error: Invalid argument
 # cat events/ext4/ext4_truncate_exit/filter
((dev==1)blocks==2)
^
parse_error: No error

 ------------[ cut here ]------------
 WARNING: CPU: 2 PID: 1223 at kernel/trace/trace_events_filter.c:1640 replace_preds+0x3c5/0x990()
 Modules linked in: bnep lockd grace bluetooth  ...
 CPU: 3 PID: 1223 Comm: bash Tainted: G        W       4.1.0-rc3-test+ #450
 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v02.05 05/07/2012
  0000000000000668 ffff8800c106bc98 ffffffff816ed4f9 ffff88011ead0cf0
  0000000000000000 ffff8800c106bcd8 ffffffff8107fb07 ffffffff8136b46c
  ffff8800c7d81d48 ffff8800d4c2bc00 ffff8800d4d4f920 00000000ffffffea
 Call Trace:
  [<ffffffff816ed4f9>] dump_stack+0x4c/0x6e
  [<ffffffff8107fb07>] warn_slowpath_common+0x97/0xe0
  [<ffffffff8136b46c>] ? _kstrtoull+0x2c/0x80
  [<ffffffff8107fb6a>] warn_slowpath_null+0x1a/0x20
  [<ffffffff81159065>] replace_preds+0x3c5/0x990
  [<ffffffff811596b2>] create_filter+0x82/0xb0
  [<ffffffff81159944>] apply_event_filter+0xd4/0x180
  [<ffffffff81152bbf>] event_filter_write+0x8f/0x120
  [<ffffffff811db2a8>] __vfs_write+0x28/0xe0
  [<ffffffff811dda43>] ? __sb_start_write+0x53/0xf0
  [<ffffffff812e51e0>] ? security_file_permission+0x30/0xc0
  [<ffffffff811dc408>] vfs_write+0xb8/0x1b0
  [<ffffffff811dc72f>] SyS_write+0x4f/0xb0
  [<ffffffff816f5217>] system_call_fastpath+0x12/0x6a
 ---[ end trace e11028bd95818dcd ]---

Worse yet, reading the error message (the filter again) it says that
there was no error, when there clearly was. The issue is that the
code that checks the input does not check for balanced ops. That is,
having an op between a closed parenthesis and the next token.

This would only cause a warning, and fail out before doing any real
harm, but it should still not caues a warning, and the error reported
should work:

 # cd /sys/kernel/debug/tracing
 # echo "((dev==1)blocks==2)" > events/ext4/ext4_truncate_exit/filter
-bash: echo: write error: Invalid argument
 # cat events/ext4/ext4_truncate_exit/filter
((dev==1)blocks==2)
^
parse_error: Meaningless filter expression

And give no kernel warning.

Link: http://lkml.kernel.org/r/20150615175025.7e809215@gandalf.local.home

Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
Reported-by: Vince Weaver <vincent.weaver@maine.edu>
Tested-by: Vince Weaver <vincent.weaver@maine.edu>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
[ luis: backported to 3.16:
  - unconditionally decrement cnt as the OP_NOT logic was introduced only
    by e12c09cf3087 ("tracing: Add NOT to filtering logic") ]
Signed-off-by: Luis Henriques <luis.henriques@canonical.com>
---
 kernel/trace/trace_events_filter.c | 10 ++++++++--
 1 file changed, 8 insertions(+), 2 deletions(-)

diff --git a/kernel/trace/trace_events_filter.c b/kernel/trace/trace_events_filter.c
index 8a8631926a07..cc1cdaff9e9f 100644
--- a/kernel/trace/trace_events_filter.c
+++ b/kernel/trace/trace_events_filter.c
@@ -1399,19 +1399,25 @@ static int check_preds(struct filter_parse_state *ps)
 {
 	int n_normal_preds = 0, n_logical_preds = 0;
 	struct postfix_elt *elt;
+	int cnt = 0;
 
 	list_for_each_entry(elt, &ps->postfix, list) {
-		if (elt->op == OP_NONE)
+		if (elt->op == OP_NONE) {
+			cnt++;
 			continue;
+		}
 
 		if (elt->op == OP_AND || elt->op == OP_OR) {
 			n_logical_preds++;
+			cnt--;
 			continue;
 		}
+		cnt--;
 		n_normal_preds++;
+		WARN_ON_ONCE(cnt < 0);
 	}
 
-	if (!n_normal_preds || n_logical_preds >= n_normal_preds) {
+	if (cnt != 1 || !n_normal_preds || n_logical_preds >= n_normal_preds) {
 		parse_error(ps, FILT_ERR_INVALID_FILTER, 0);
 		return -EINVAL;
 	}
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
Please read the FAQ at  http://www.tux.org/lkml/

Re: [GIT PULL] tracing: Have filter check for balanced ops

[Steven Rostedt]

On Mon, 22 Jun 2015 15:03:14 +0100
Luis Henriques <luis.henriques@canonical.com> wrote:

> On Mon, Jun 22, 2015 at 02:53:17PM +0100, Luis Henriques wrote:
> > Hi Steven,
> > 
> > On Wed, Jun 17, 2015 at 08:36:38AM -0400, Steven Rostedt wrote:
> > ...
> > > diff --git a/kernel/trace/trace_events_filter.c b/kernel/trace/trace_events_filter.c
> > > index ced69da0ff55..7f2e97ce71a7 100644
> > > --- a/kernel/trace/trace_events_filter.c
> > > +++ b/kernel/trace/trace_events_filter.c
> > > @@ -1369,19 +1369,26 @@ static int check_preds(struct filter_parse_state *ps)
> > >  {
> > >  	int n_normal_preds = 0, n_logical_preds = 0;
> > >  	struct postfix_elt *elt;
> > > +	int cnt = 0;
> > >  
> > >  	list_for_each_entry(elt, &ps->postfix, list) {
> > > -		if (elt->op == OP_NONE)
> > > +		if (elt->op == OP_NONE) {
> > > +			cnt++;
> > >  			continue;
> > > +		}
> > >  
> > >  		if (elt->op == OP_AND || elt->op == OP_OR) {
> > >  			n_logical_preds++;
> > > +			cnt--;
> > >  			continue;
> > >  		}
> > > +		if (elt->op != OP_NOT)
> > > +			cnt--;
> > 
> > Since the OP_NOT was introduced only with e12c09cf3087 ("tracing: Add
> > NOT to filtering logic"), how would stable kernels backport this fix?
> > Do you think that just dropping the 'if' and do the 'cnt--'
> > unconditionally would be ok?
> 
> Something like the patch below (only compile-tested).
> 
> Cheers,
> --
> Luís
> 
> >From db7ac73e73dd0ef0259d5d2871b7b9402b12e4d3 Mon Sep 17 00:00:00 2001
> From: Steven Rostedt <rostedt@goodmis.org>
> Date: Mon, 15 Jun 2015 17:50:25 -0400
> Subject: [PATCH] tracing: Have filter check for balanced ops
> 
> commit 2cf30dc180cea808077f003c5116388183e54f9e upstream.
> 
> When the following filter is used it causes a warning to trigger:
> 
>  # cd /sys/kernel/debug/tracing
>  # echo "((dev==1)blocks==2)" > events/ext4/ext4_truncate_exit/filter
> -bash: echo: write error: Invalid argument
>  # cat events/ext4/ext4_truncate_exit/filter
> ((dev==1)blocks==2)
> ^
> parse_error: No error
> 
>  ------------[ cut here ]------------
>  WARNING: CPU: 2 PID: 1223 at kernel/trace/trace_events_filter.c:1640 replace_preds+0x3c5/0x990()
>  Modules linked in: bnep lockd grace bluetooth  ...
>  CPU: 3 PID: 1223 Comm: bash Tainted: G        W       4.1.0-rc3-test+ #450
>  Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v02.05 05/07/2012
>   0000000000000668 ffff8800c106bc98 ffffffff816ed4f9 ffff88011ead0cf0
>   0000000000000000 ffff8800c106bcd8 ffffffff8107fb07 ffffffff8136b46c
>   ffff8800c7d81d48 ffff8800d4c2bc00 ffff8800d4d4f920 00000000ffffffea
>  Call Trace:
>   [<ffffffff816ed4f9>] dump_stack+0x4c/0x6e
>   [<ffffffff8107fb07>] warn_slowpath_common+0x97/0xe0
>   [<ffffffff8136b46c>] ? _kstrtoull+0x2c/0x80
>   [<ffffffff8107fb6a>] warn_slowpath_null+0x1a/0x20
>   [<ffffffff81159065>] replace_preds+0x3c5/0x990
>   [<ffffffff811596b2>] create_filter+0x82/0xb0
>   [<ffffffff81159944>] apply_event_filter+0xd4/0x180
>   [<ffffffff81152bbf>] event_filter_write+0x8f/0x120
>   [<ffffffff811db2a8>] __vfs_write+0x28/0xe0
>   [<ffffffff811dda43>] ? __sb_start_write+0x53/0xf0
>   [<ffffffff812e51e0>] ? security_file_permission+0x30/0xc0
>   [<ffffffff811dc408>] vfs_write+0xb8/0x1b0
>   [<ffffffff811dc72f>] SyS_write+0x4f/0xb0
>   [<ffffffff816f5217>] system_call_fastpath+0x12/0x6a
>  ---[ end trace e11028bd95818dcd ]---
> 
> Worse yet, reading the error message (the filter again) it says that
> there was no error, when there clearly was. The issue is that the
> code that checks the input does not check for balanced ops. That is,
> having an op between a closed parenthesis and the next token.
> 
> This would only cause a warning, and fail out before doing any real
> harm, but it should still not caues a warning, and the error reported
> should work:
> 
>  # cd /sys/kernel/debug/tracing
>  # echo "((dev==1)blocks==2)" > events/ext4/ext4_truncate_exit/filter
> -bash: echo: write error: Invalid argument
>  # cat events/ext4/ext4_truncate_exit/filter
> ((dev==1)blocks==2)
> ^
> parse_error: Meaningless filter expression
> 
> And give no kernel warning.
> 
> Link: http://lkml.kernel.org/r/20150615175025.7e809215@gandalf.local.home
> 
> Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
> Cc: Ingo Molnar <mingo@redhat.com>
> Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
> Reported-by: Vince Weaver <vincent.weaver@maine.edu>
> Tested-by: Vince Weaver <vincent.weaver@maine.edu>
> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> [ luis: backported to 3.16:
>   - unconditionally decrement cnt as the OP_NOT logic was introduced only
>     by e12c09cf3087 ("tracing: Add NOT to filtering logic") ]
> Signed-off-by: Luis Henriques <luis.henriques@canonical.com>
> ---
>  kernel/trace/trace_events_filter.c | 10 ++++++++--
>  1 file changed, 8 insertions(+), 2 deletions(-)
> 
> diff --git a/kernel/trace/trace_events_filter.c b/kernel/trace/trace_events_filter.c
> index 8a8631926a07..cc1cdaff9e9f 100644
> --- a/kernel/trace/trace_events_filter.c
> +++ b/kernel/trace/trace_events_filter.c
> @@ -1399,19 +1399,25 @@ static int check_preds(struct filter_parse_state *ps)
>  {
>  	int n_normal_preds = 0, n_logical_preds = 0;
>  	struct postfix_elt *elt;
> +	int cnt = 0;
>  
>  	list_for_each_entry(elt, &ps->postfix, list) {
> -		if (elt->op == OP_NONE)
> +		if (elt->op == OP_NONE) {
> +			cnt++;
>  			continue;
> +		}
>  
>  		if (elt->op == OP_AND || elt->op == OP_OR) {
>  			n_logical_preds++;
> +			cnt--;
>  			continue;
>  		}
> +		cnt--;

To make this patch simpler, just move the "cnt--;" above the OP_AND and
OP_OR check and remove the "cnt--;" from that if statement.

But yeah, this looks fine. You can test it with the example in the
change log.

  echo "((dev==1)blocks==2)" > events/ext4/ext4_truncate_exit/filter

And see if it gives an error other than "parse_error: No error".

-- Steve


>  		n_normal_preds++;
> +		WARN_ON_ONCE(cnt < 0);
>  	}
>  
> -	if (!n_normal_preds || n_logical_preds >= n_normal_preds) {
> +	if (cnt != 1 || !n_normal_preds || n_logical_preds >= n_normal_preds) {
>  		parse_error(ps, FILT_ERR_INVALID_FILTER, 0);
>  		return -EINVAL;
>  	}

--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
Please read the FAQ at  http://www.tux.org/lkml/

Re: [GIT PULL] tracing: Have filter check for balanced ops

[Luis Henriques]

On Mon, Jun 22, 2015 at 10:17:28AM -0400, Steven Rostedt wrote:
...
> To make this patch simpler, just move the "cnt--;" above the OP_AND and
> OP_OR check and remove the "cnt--;" from that if statement.
> 
> But yeah, this looks fine. You can test it with the example in the
> change log.
> 
>   echo "((dev==1)blocks==2)" > events/ext4/ext4_truncate_exit/filter
> 
> And see if it gives an error other than "parse_error: No error".
> 
> -- Steve

Thanks Steven, I've done a quick test with a 3.16-ckt kernel and I can
confirm that the modified patch (i.e. including your suggestion) fixes
the problem.

I'm attaching the patch below and CC'ing stable mailing-list.

Cheers,
--
Luís

>From 19305c2d68fbb43ba219881082b95da2e4e82db5 Mon Sep 17 00:00:00 2001
From: Steven Rostedt <rostedt@goodmis.org>
Date: Mon, 15 Jun 2015 17:50:25 -0400
Subject: [PATCH] tracing: Have filter check for balanced ops

commit 2cf30dc180cea808077f003c5116388183e54f9e upstream.

When the following filter is used it causes a warning to trigger:

 # cd /sys/kernel/debug/tracing
 # echo "((dev==1)blocks==2)" > events/ext4/ext4_truncate_exit/filter
-bash: echo: write error: Invalid argument
 # cat events/ext4/ext4_truncate_exit/filter
((dev==1)blocks==2)
^
parse_error: No error

 ------------[ cut here ]------------
 WARNING: CPU: 2 PID: 1223 at kernel/trace/trace_events_filter.c:1640 replace_preds+0x3c5/0x990()
 Modules linked in: bnep lockd grace bluetooth  ...
 CPU: 3 PID: 1223 Comm: bash Tainted: G        W       4.1.0-rc3-test+ #450
 Hardware name: Hewlett-Packard HP Compaq Pro 6300 SFF/339A, BIOS K01 v02.05 05/07/2012
  0000000000000668 ffff8800c106bc98 ffffffff816ed4f9 ffff88011ead0cf0
  0000000000000000 ffff8800c106bcd8 ffffffff8107fb07 ffffffff8136b46c
  ffff8800c7d81d48 ffff8800d4c2bc00 ffff8800d4d4f920 00000000ffffffea
 Call Trace:
  [<ffffffff816ed4f9>] dump_stack+0x4c/0x6e
  [<ffffffff8107fb07>] warn_slowpath_common+0x97/0xe0
  [<ffffffff8136b46c>] ? _kstrtoull+0x2c/0x80
  [<ffffffff8107fb6a>] warn_slowpath_null+0x1a/0x20
  [<ffffffff81159065>] replace_preds+0x3c5/0x990
  [<ffffffff811596b2>] create_filter+0x82/0xb0
  [<ffffffff81159944>] apply_event_filter+0xd4/0x180
  [<ffffffff81152bbf>] event_filter_write+0x8f/0x120
  [<ffffffff811db2a8>] __vfs_write+0x28/0xe0
  [<ffffffff811dda43>] ? __sb_start_write+0x53/0xf0
  [<ffffffff812e51e0>] ? security_file_permission+0x30/0xc0
  [<ffffffff811dc408>] vfs_write+0xb8/0x1b0
  [<ffffffff811dc72f>] SyS_write+0x4f/0xb0
  [<ffffffff816f5217>] system_call_fastpath+0x12/0x6a
 ---[ end trace e11028bd95818dcd ]---

Worse yet, reading the error message (the filter again) it says that
there was no error, when there clearly was. The issue is that the
code that checks the input does not check for balanced ops. That is,
having an op between a closed parenthesis and the next token.

This would only cause a warning, and fail out before doing any real
harm, but it should still not caues a warning, and the error reported
should work:

 # cd /sys/kernel/debug/tracing
 # echo "((dev==1)blocks==2)" > events/ext4/ext4_truncate_exit/filter
-bash: echo: write error: Invalid argument
 # cat events/ext4/ext4_truncate_exit/filter
((dev==1)blocks==2)
^
parse_error: Meaningless filter expression

And give no kernel warning.

Link: http://lkml.kernel.org/r/20150615175025.7e809215@gandalf.local.home

Cc: Peter Zijlstra <a.p.zijlstra@chello.nl>
Cc: Ingo Molnar <mingo@redhat.com>
Cc: Arnaldo Carvalho de Melo <acme@kernel.org>
Reported-by: Vince Weaver <vincent.weaver@maine.edu>
Tested-by: Vince Weaver <vincent.weaver@maine.edu>
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
[ luis: backported to 3.16:
  - unconditionally decrement cnt as the OP_NOT logic was introduced only
    by e12c09cf3087 ("tracing: Add NOT to filtering logic") ]
Signed-off-by: Luis Henriques <luis.henriques@canonical.com>
---
 kernel/trace/trace_events_filter.c | 9 +++++++--
 1 file changed, 7 insertions(+), 2 deletions(-)

diff --git a/kernel/trace/trace_events_filter.c b/kernel/trace/trace_events_filter.c
index 8a8631926a07..cb347e85f75e 100644
--- a/kernel/trace/trace_events_filter.c
+++ b/kernel/trace/trace_events_filter.c
@@ -1399,19 +1399,24 @@ static int check_preds(struct filter_parse_state *ps)
 {
 	int n_normal_preds = 0, n_logical_preds = 0;
 	struct postfix_elt *elt;
+	int cnt = 0;
 
 	list_for_each_entry(elt, &ps->postfix, list) {
-		if (elt->op == OP_NONE)
+		if (elt->op == OP_NONE) {
+			cnt++;
 			continue;
+		}
 
+		cnt--;
 		if (elt->op == OP_AND || elt->op == OP_OR) {
 			n_logical_preds++;
 			continue;
 		}
 		n_normal_preds++;
+		WARN_ON_ONCE(cnt < 0);
 	}
 
-	if (!n_normal_preds || n_logical_preds >= n_normal_preds) {
+	if (cnt != 1 || !n_normal_preds || n_logical_preds >= n_normal_preds) {
 		parse_error(ps, FILT_ERR_INVALID_FILTER, 0);
 		return -EINVAL;
 	}
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
Please read the FAQ at  http://www.tux.org/lkml/

Re: [GIT PULL] tracing: Have filter check for balanced ops

[Greg KH]

On Mon, Jun 22, 2015 at 03:49:40PM +0100, Luis Henriques wrote:
> On Mon, Jun 22, 2015 at 10:17:28AM -0400, Steven Rostedt wrote:
> ...
> > To make this patch simpler, just move the "cnt--;" above the OP_AND and
> > OP_OR check and remove the "cnt--;" from that if statement.
> > 
> > But yeah, this looks fine. You can test it with the example in the
> > change log.
> > 
> >   echo "((dev==1)blocks==2)" > events/ext4/ext4_truncate_exit/filter
> > 
> > And see if it gives an error other than "parse_error: No error".
> > 
> > -- Steve
> 
> Thanks Steven, I've done a quick test with a 3.16-ckt kernel and I can
> confirm that the modified patch (i.e. including your suggestion) fixes
> the problem.
> 
> I'm attaching the patch below and CC'ing stable mailing-list.
> 
> Cheers,
> --
> Luís

Thanks, I've used this patch for 3.10 and 3.14.

greg k-h

Re: [GIT PULL] tracing: Have filter check for balanced ops

[Sasha Levin]

On 06/17/2015 08:36 AM, Steven Rostedt wrote:
> Linus,
> 
> Vince Weaver reported a warning when he added perf event filters
> into his fuzzer tests. There's a missing check of balanced
> operations when parenthesis are used, and this triggers a WARN_ON()
> and when reading the failure, the filter reports no failure occurred.

Hey Steven,

My fuzzings are hitting the warning added by this patch:

[2175114.187536] WARNING: CPU: 16 PID: 10388 at kernel/trace/trace_events_filter.c:1388 replace_preds+0x814/0x2140()
[2175114.190213] Modules linked in:
[2175114.191111] CPU: 16 PID: 10388 Comm: trinity-c48 Not tainted 4.1.0-next-20150623-sasha-00039-ga1eb83a-dirty #2280
[2175114.194463]  ffff880a23350000 000000006a8e22d4 ffff880a2335f878 ffffffffabc8cfa3
[2175114.196547]  0000000000000000 0000000000000000 ffff880a2335f8c8 ffffffffa21ebd36
[2175114.198604]  ffff880e60fe09e0 ffffffffa24608f4 ffff880e61b14830 ffff880e60fe09d8
[2175114.200666] Call Trace:
[2175114.201377]  [<ffffffffabc8cfa3>] dump_stack+0x4f/0x7b
[2175114.202793]  [<ffffffffa21ebd36>] warn_slowpath_common+0xc6/0x120
[2175114.206235]  [<ffffffffa21ebf7a>] warn_slowpath_null+0x1a/0x20
[2175114.207819]  [<ffffffffa24608f4>] replace_preds+0x814/0x2140
[2175114.216433]  [<ffffffffa24638aa>] create_filter+0x15a/0x210
[2175114.231529]  [<ffffffffa246406b>] apply_event_filter+0x28b/0x780
[2175114.241196]  [<ffffffffa2450306>] event_filter_write+0x106/0x1c0
[2175114.242823]  [<ffffffffa260dd48>] do_loop_readv_writev+0x128/0x1e0
[2175114.248901]  [<ffffffffa261051e>] do_readv_writev+0x5ae/0x6c0
[2175114.256760]  [<ffffffffa2610742>] vfs_writev+0x72/0xb0
[2175114.258134]  [<ffffffffa2613bb4>] SyS_pwritev+0x1b4/0x220
[2175114.261291]  [<ffffffffabcf9962>] tracesys_phase2+0x88/0x8d


Thanks,
Sasha

Re: [GIT PULL] tracing: Have filter check for balanced ops

[Steven Rostedt]

On Thu, 25 Jun 2015 00:03:02 -0400
Sasha Levin <sasha.levin@oracle.com> wrote:

> On 06/17/2015 08:36 AM, Steven Rostedt wrote:
> > Linus,
> > 
> > Vince Weaver reported a warning when he added perf event filters
> > into his fuzzer tests. There's a missing check of balanced
> > operations when parenthesis are used, and this triggers a WARN_ON()
> > and when reading the failure, the filter reports no failure occurred.
> 
> Hey Steven,
> 
> My fuzzings are hitting the warning added by this patch:

Yes, Vince said he was able to hit it as well. But the warning itself
is useless if you don't supply what filter was used to trigger it.

-- Steve


> 
> [2175114.187536] WARNING: CPU: 16 PID: 10388 at kernel/trace/trace_events_filter.c:1388 replace_preds+0x814/0x2140()
> [2175114.190213] Modules linked in:
> [2175114.191111] CPU: 16 PID: 10388 Comm: trinity-c48 Not tainted 4.1.0-next-20150623-sasha-00039-ga1eb83a-dirty #2280
> [2175114.194463]  ffff880a23350000 000000006a8e22d4 ffff880a2335f878 ffffffffabc8cfa3
> [2175114.196547]  0000000000000000 0000000000000000 ffff880a2335f8c8 ffffffffa21ebd36
> [2175114.198604]  ffff880e60fe09e0 ffffffffa24608f4 ffff880e61b14830 ffff880e60fe09d8
> [2175114.200666] Call Trace:
> [2175114.201377]  [<ffffffffabc8cfa3>] dump_stack+0x4f/0x7b
> [2175114.202793]  [<ffffffffa21ebd36>] warn_slowpath_common+0xc6/0x120
> [2175114.206235]  [<ffffffffa21ebf7a>] warn_slowpath_null+0x1a/0x20
> [2175114.207819]  [<ffffffffa24608f4>] replace_preds+0x814/0x2140
> [2175114.216433]  [<ffffffffa24638aa>] create_filter+0x15a/0x210
> [2175114.231529]  [<ffffffffa246406b>] apply_event_filter+0x28b/0x780
> [2175114.241196]  [<ffffffffa2450306>] event_filter_write+0x106/0x1c0
> [2175114.242823]  [<ffffffffa260dd48>] do_loop_readv_writev+0x128/0x1e0
> [2175114.248901]  [<ffffffffa261051e>] do_readv_writev+0x5ae/0x6c0
> [2175114.256760]  [<ffffffffa2610742>] vfs_writev+0x72/0xb0
> [2175114.258134]  [<ffffffffa2613bb4>] SyS_pwritev+0x1b4/0x220
> [2175114.261291]  [<ffffffffabcf9962>] tracesys_phase2+0x88/0x8d
> 
> 
> Thanks,
> Sasha

Re: [GIT PULL] tracing: Have filter check for balanced ops

[Sasha Levin]

On 06/25/2015 12:35 AM, Steven Rostedt wrote:
> On Thu, 25 Jun 2015 00:03:02 -0400
> Sasha Levin <sasha.levin@oracle.com> wrote:
> 
>> On 06/17/2015 08:36 AM, Steven Rostedt wrote:
>>> Linus,
>>>
>>> Vince Weaver reported a warning when he added perf event filters
>>> into his fuzzer tests. There's a missing check of balanced
>>> operations when parenthesis are used, and this triggers a WARN_ON()
>>> and when reading the failure, the filter reports no failure occurred.
>>
>> Hey Steven,
>>
>> My fuzzings are hitting the warning added by this patch:
> 
> Yes, Vince said he was able to hit it as well. But the warning itself
> is useless if you don't supply what filter was used to trigger it.

# echo ">" > events/ext4/ext4_truncate_exit/filter


Thanks,
Sasha

Re: [GIT PULL] tracing: Have filter check for balanced ops

[Steven Rostedt]

On Thu, 25 Jun 2015 16:11:46 -0400
Sasha Levin <sasha.levin@oracle.com> wrote:


> # echo ">" > events/ext4/ext4_truncate_exit/filter

Thanks. Seems that the WARN_ON is frivolous. We should just handle 
cnt < 0 as a bad filter.

Can you run you tests with this patch. Thanks!

-- Steve

>From b4875bbe7e68f139bd3383828ae8e994a0df6d28 Mon Sep 17 00:00:00 2001
From: "Steven Rostedt (Red Hat)" <rostedt@goodmis.org>
Date: Thu, 25 Jun 2015 18:02:29 -0400
Subject: [PATCH] tracing/filter: Do not WARN on operand count going below zero

When testing the fix for the trace filter, I could not come up with
a scenario where the operand count goes below zero, so I added a
WARN_ON_ONCE(cnt < 0) to the logic. But there is legitimate case
that it can happen (although the filter would be wrong).

 # echo '>' > /sys/kernel/debug/events/ext4/ext4_truncate_exit/filter

That is, a single operation without any operands will hit the path
where the WARN_ON_ONCE() can trigger. Although this is harmless,
and the filter is reported as a error. But instead of spitting out
a warning to the kernel dmesg, just fail nicely and report it via
the proper channels.

Link: http://lkml.kernel.org/r/558C6082.90608@oracle.com

Reported-by: Vince Weaver <vincent.weaver@maine.edu>
Reported-by: Sasha Levin <sasha.levin@oracle.com>
Cc: stable@vger.kernel.org # 2.6.33+
Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace_events_filter.c | 4 +++-
 1 file changed, 3 insertions(+), 1 deletion(-)

diff --git a/kernel/trace/trace_events_filter.c b/kernel/trace/trace_events_filter.c
index 7f2e97ce71a7..2900d7723d97 100644
--- a/kernel/trace/trace_events_filter.c
+++ b/kernel/trace/trace_events_filter.c
@@ -1385,7 +1385,9 @@ static int check_preds(struct filter_parse_state *ps)
 		if (elt->op != OP_NOT)
 			cnt--;
 		n_normal_preds++;
-		WARN_ON_ONCE(cnt < 0);
+		/* all ops should have operands */
+		if (cnt < 0)
+			break;
 	}
 
 	if (cnt != 1 || !n_normal_preds || n_logical_preds >= n_normal_preds) {
-- 
2.1.4