[PATCH 0/4] tracing: Improve error messages for histogram sorting

[PATCH 0/4] tracing: Improve error messages for histogram sorting

[Tom Zanussi]

Hi,

These patches add some improvements for histogram sorting, addressing
some shortcomings pointed out by Masami.

In order to address the specific problem pointed out by Masami, as
well as add additional related error messages, the first patch
does some simplification of assignment parsing.

The second patch actually adds the new error messages.

The fourth patch adds a new testcase for hist trigger parsing, similar
to the same kind of tests for kprobes and uprobes.  Additional tests
covering all possible hist trigger errors should/will be added here in
the future.

The third patch just adds a missing hist: prefix to the error log so
that the testcases work properly, and which should have been there
anyway.

Thanks,

Tom

The following changes since commit a124692b698b00026a58d89831ceda2331b2e1d0:

  ftrace: Enable trampoline when rec count returns back to one (2019-05-25 23:04:43 -0400)

are available in the git repository at:

  git://git.kernel.org/pub/scm/linux/kernel/git/zanussi/linux-trace.git ftrace-hist-sort-err-msgs-v1

Tom Zanussi (4):
  tracing: Simplify assignment parsing for hist triggers
  tracing: Add hist trigger error messages for sort specification
  tracing: Add 'hist:' to hist trigger error log error string
  tracing: Add new testcases for hist trigger parsing errors

 kernel/trace/trace_events_hist.c                   | 94 +++++++++++-----------
 .../test.d/trigger/trigger-hist-syntax-errors.tc   | 32 ++++++++
 2 files changed, 78 insertions(+), 48 deletions(-)
 create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-syntax-errors.tc

-- 
2.14.1

[PATCH 1/4] tracing: Simplify assignment parsing for hist triggers

[Tom Zanussi]

In the process of adding better error messages for sorting, I realized
that strsep was being used incorrectly and some of the error paths I
was expecting to be hit weren't and just fell through to the common
invalid key error case.

It also became obvious that for keyword assignments, it wasn't
necessary to save the full assignment and reparse it later, and having
a common empty-assignment check would also make more sense in terms of
error processing.

Change the code to fix these problems and simplify it for new error
message changes in a subsequent patch.

Signed-off-by: Tom Zanussi <zanussi@kernel.org>
---
 kernel/trace/trace_events_hist.c | 70 ++++++++++++++++------------------------
 1 file changed, 27 insertions(+), 43 deletions(-)

diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c
index ca6b0dff60c5..964d032f51c6 100644
--- a/kernel/trace/trace_events_hist.c
+++ b/kernel/trace/trace_events_hist.c
@@ -1985,12 +1985,6 @@ static int parse_map_size(char *str)
 	unsigned long size, map_bits;
 	int ret;
 
-	strsep(&str, "=");
-	if (!str) {
-		ret = -EINVAL;
-		goto out;
-	}
-
 	ret = kstrtoul(str, 0, &size);
 	if (ret)
 		goto out;
@@ -2050,25 +2044,25 @@ static int parse_action(char *str, struct hist_trigger_attrs *attrs)
 static int parse_assignment(struct trace_array *tr,
 			    char *str, struct hist_trigger_attrs *attrs)
 {
-	int ret = 0;
+	int len, ret = 0;
 
-	if ((str_has_prefix(str, "key=")) ||
-	    (str_has_prefix(str, "keys="))) {
-		attrs->keys_str = kstrdup(str, GFP_KERNEL);
+	if ((len = str_has_prefix(str, "key=")) ||
+	    (len = str_has_prefix(str, "keys="))) {
+		attrs->keys_str = kstrdup(str + len, GFP_KERNEL);
 		if (!attrs->keys_str) {
 			ret = -ENOMEM;
 			goto out;
 		}
-	} else if ((str_has_prefix(str, "val=")) ||
-		   (str_has_prefix(str, "vals=")) ||
-		   (str_has_prefix(str, "values="))) {
-		attrs->vals_str = kstrdup(str, GFP_KERNEL);
+	} else if ((len = str_has_prefix(str, "val=")) ||
+		   (len = str_has_prefix(str, "vals=")) ||
+		   (len = str_has_prefix(str, "values="))) {
+		attrs->vals_str = kstrdup(str + len, GFP_KERNEL);
 		if (!attrs->vals_str) {
 			ret = -ENOMEM;
 			goto out;
 		}
-	} else if (str_has_prefix(str, "sort=")) {
-		attrs->sort_key_str = kstrdup(str, GFP_KERNEL);
+	} else if ((len = str_has_prefix(str, "sort="))) {
+		attrs->sort_key_str = kstrdup(str + len, GFP_KERNEL);
 		if (!attrs->sort_key_str) {
 			ret = -ENOMEM;
 			goto out;
@@ -2079,12 +2073,8 @@ static int parse_assignment(struct trace_array *tr,
 			ret = -ENOMEM;
 			goto out;
 		}
-	} else if (str_has_prefix(str, "clock=")) {
-		strsep(&str, "=");
-		if (!str) {
-			ret = -EINVAL;
-			goto out;
-		}
+	} else if ((len = str_has_prefix(str, "clock="))) {
+		str += len;
 
 		str = strstrip(str);
 		attrs->clock = kstrdup(str, GFP_KERNEL);
@@ -2092,8 +2082,8 @@ static int parse_assignment(struct trace_array *tr,
 			ret = -ENOMEM;
 			goto out;
 		}
-	} else if (str_has_prefix(str, "size=")) {
-		int map_bits = parse_map_size(str);
+	} else if ((len = str_has_prefix(str, "size="))) {
+		int map_bits = parse_map_size(str + len);
 
 		if (map_bits < 0) {
 			ret = map_bits;
@@ -2133,8 +2123,14 @@ parse_hist_trigger_attrs(struct trace_array *tr, char *trigger_str)
 
 	while (trigger_str) {
 		char *str = strsep(&trigger_str, ":");
+		char *rhs;
 
-		if (strchr(str, '=')) {
+		rhs = strchr(str, '=');
+		if (rhs) {
+			if (!strlen(++rhs)) {
+				ret = -EINVAL;
+				goto free;
+			}
 			ret = parse_assignment(tr, str, attrs);
 			if (ret)
 				goto free;
@@ -4459,10 +4455,6 @@ static int create_val_fields(struct hist_trigger_data *hist_data,
 	if (!fields_str)
 		goto out;
 
-	strsep(&fields_str, "=");
-	if (!fields_str)
-		goto out;
-
 	for (i = 0, j = 1; i < TRACING_MAP_VALS_MAX &&
 		     j < TRACING_MAP_VALS_MAX; i++) {
 		field_str = strsep(&fields_str, ",");
@@ -4557,10 +4549,6 @@ static int create_key_fields(struct hist_trigger_data *hist_data,
 	if (!fields_str)
 		goto out;
 
-	strsep(&fields_str, "=");
-	if (!fields_str)
-		goto out;
-
 	for (i = n_vals; i < n_vals + TRACING_MAP_KEYS_MAX; i++) {
 		field_str = strsep(&fields_str, ",");
 		if (!field_str)
@@ -4718,12 +4706,6 @@ static int create_sort_keys(struct hist_trigger_data *hist_data)
 	if (!fields_str)
 		goto out;
 
-	strsep(&fields_str, "=");
-	if (!fields_str) {
-		ret = -EINVAL;
-		goto out;
-	}
-
 	for (i = 0; i < TRACING_MAP_SORT_KEYS_MAX; i++) {
 		struct hist_field *hist_field;
 		char *field_str, *field_name;
@@ -4732,9 +4714,11 @@ static int create_sort_keys(struct hist_trigger_data *hist_data)
 		sort_key = &hist_data->sort_keys[i];
 
 		field_str = strsep(&fields_str, ",");
-		if (!field_str) {
-			if (i == 0)
-				ret = -EINVAL;
+		if (!field_str)
+			break;
+
+		if (!*field_str) {
+			ret = -EINVAL;
 			break;
 		}
 
@@ -4744,7 +4728,7 @@ static int create_sort_keys(struct hist_trigger_data *hist_data)
 		}
 
 		field_name = strsep(&field_str, ".");
-		if (!field_name) {
+		if (!field_name || !*field_name) {
 			ret = -EINVAL;
 			break;
 		}
-- 
2.14.1

Re: [PATCH 1/4] tracing: Simplify assignment parsing for hist triggers

[Masami Hiramatsu]

On Thu, 27 Jun 2019 10:35:16 -0500
Tom Zanussi <zanussi@kernel.org> wrote:

> In the process of adding better error messages for sorting, I realized
> that strsep was being used incorrectly and some of the error paths I
> was expecting to be hit weren't and just fell through to the common
> invalid key error case.

Would you mean this includes a bugfix too?

> 
> It also became obvious that for keyword assignments, it wasn't
> necessary to save the full assignment and reparse it later, and having
> a common empty-assignment check would also make more sense in terms of
> error processing.
> 
> Change the code to fix these problems and simplify it for new error
> message changes in a subsequent patch.
> 
> Signed-off-by: Tom Zanussi <zanussi@kernel.org>

Anyway looks good to me.

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

Thanks,

> ---
>  kernel/trace/trace_events_hist.c | 70 ++++++++++++++++------------------------
>  1 file changed, 27 insertions(+), 43 deletions(-)
> 
> diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c
> index ca6b0dff60c5..964d032f51c6 100644
> --- a/kernel/trace/trace_events_hist.c
> +++ b/kernel/trace/trace_events_hist.c
> @@ -1985,12 +1985,6 @@ static int parse_map_size(char *str)
>  	unsigned long size, map_bits;
>  	int ret;
>  
> -	strsep(&str, "=");
> -	if (!str) {
> -		ret = -EINVAL;
> -		goto out;
> -	}
> -
>  	ret = kstrtoul(str, 0, &size);
>  	if (ret)
>  		goto out;
> @@ -2050,25 +2044,25 @@ static int parse_action(char *str, struct hist_trigger_attrs *attrs)
>  static int parse_assignment(struct trace_array *tr,
>  			    char *str, struct hist_trigger_attrs *attrs)
>  {
> -	int ret = 0;
> +	int len, ret = 0;
>  
> -	if ((str_has_prefix(str, "key=")) ||
> -	    (str_has_prefix(str, "keys="))) {
> -		attrs->keys_str = kstrdup(str, GFP_KERNEL);
> +	if ((len = str_has_prefix(str, "key=")) ||
> +	    (len = str_has_prefix(str, "keys="))) {
> +		attrs->keys_str = kstrdup(str + len, GFP_KERNEL);
>  		if (!attrs->keys_str) {
>  			ret = -ENOMEM;
>  			goto out;
>  		}
> -	} else if ((str_has_prefix(str, "val=")) ||
> -		   (str_has_prefix(str, "vals=")) ||
> -		   (str_has_prefix(str, "values="))) {
> -		attrs->vals_str = kstrdup(str, GFP_KERNEL);
> +	} else if ((len = str_has_prefix(str, "val=")) ||
> +		   (len = str_has_prefix(str, "vals=")) ||
> +		   (len = str_has_prefix(str, "values="))) {
> +		attrs->vals_str = kstrdup(str + len, GFP_KERNEL);
>  		if (!attrs->vals_str) {
>  			ret = -ENOMEM;
>  			goto out;
>  		}
> -	} else if (str_has_prefix(str, "sort=")) {
> -		attrs->sort_key_str = kstrdup(str, GFP_KERNEL);
> +	} else if ((len = str_has_prefix(str, "sort="))) {
> +		attrs->sort_key_str = kstrdup(str + len, GFP_KERNEL);
>  		if (!attrs->sort_key_str) {
>  			ret = -ENOMEM;
>  			goto out;
> @@ -2079,12 +2073,8 @@ static int parse_assignment(struct trace_array *tr,
>  			ret = -ENOMEM;
>  			goto out;
>  		}
> -	} else if (str_has_prefix(str, "clock=")) {
> -		strsep(&str, "=");
> -		if (!str) {
> -			ret = -EINVAL;
> -			goto out;
> -		}
> +	} else if ((len = str_has_prefix(str, "clock="))) {
> +		str += len;
>  
>  		str = strstrip(str);
>  		attrs->clock = kstrdup(str, GFP_KERNEL);
> @@ -2092,8 +2082,8 @@ static int parse_assignment(struct trace_array *tr,
>  			ret = -ENOMEM;
>  			goto out;
>  		}
> -	} else if (str_has_prefix(str, "size=")) {
> -		int map_bits = parse_map_size(str);
> +	} else if ((len = str_has_prefix(str, "size="))) {
> +		int map_bits = parse_map_size(str + len);
>  
>  		if (map_bits < 0) {
>  			ret = map_bits;
> @@ -2133,8 +2123,14 @@ parse_hist_trigger_attrs(struct trace_array *tr, char *trigger_str)
>  
>  	while (trigger_str) {
>  		char *str = strsep(&trigger_str, ":");
> +		char *rhs;
>  
> -		if (strchr(str, '=')) {
> +		rhs = strchr(str, '=');
> +		if (rhs) {
> +			if (!strlen(++rhs)) {
> +				ret = -EINVAL;
> +				goto free;
> +			}
>  			ret = parse_assignment(tr, str, attrs);
>  			if (ret)
>  				goto free;
> @@ -4459,10 +4455,6 @@ static int create_val_fields(struct hist_trigger_data *hist_data,
>  	if (!fields_str)
>  		goto out;
>  
> -	strsep(&fields_str, "=");
> -	if (!fields_str)
> -		goto out;
> -
>  	for (i = 0, j = 1; i < TRACING_MAP_VALS_MAX &&
>  		     j < TRACING_MAP_VALS_MAX; i++) {
>  		field_str = strsep(&fields_str, ",");
> @@ -4557,10 +4549,6 @@ static int create_key_fields(struct hist_trigger_data *hist_data,
>  	if (!fields_str)
>  		goto out;
>  
> -	strsep(&fields_str, "=");
> -	if (!fields_str)
> -		goto out;
> -
>  	for (i = n_vals; i < n_vals + TRACING_MAP_KEYS_MAX; i++) {
>  		field_str = strsep(&fields_str, ",");
>  		if (!field_str)
> @@ -4718,12 +4706,6 @@ static int create_sort_keys(struct hist_trigger_data *hist_data)
>  	if (!fields_str)
>  		goto out;
>  
> -	strsep(&fields_str, "=");
> -	if (!fields_str) {
> -		ret = -EINVAL;
> -		goto out;
> -	}
> -
>  	for (i = 0; i < TRACING_MAP_SORT_KEYS_MAX; i++) {
>  		struct hist_field *hist_field;
>  		char *field_str, *field_name;
> @@ -4732,9 +4714,11 @@ static int create_sort_keys(struct hist_trigger_data *hist_data)
>  		sort_key = &hist_data->sort_keys[i];
>  
>  		field_str = strsep(&fields_str, ",");
> -		if (!field_str) {
> -			if (i == 0)
> -				ret = -EINVAL;
> +		if (!field_str)
> +			break;
> +
> +		if (!*field_str) {
> +			ret = -EINVAL;
>  			break;
>  		}
>  
> @@ -4744,7 +4728,7 @@ static int create_sort_keys(struct hist_trigger_data *hist_data)
>  		}
>  
>  		field_name = strsep(&field_str, ".");
> -		if (!field_name) {
> +		if (!field_name || !*field_name) {
>  			ret = -EINVAL;
>  			break;
>  		}
> -- 
> 2.14.1
> 


-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [PATCH 1/4] tracing: Simplify assignment parsing for hist triggers

[Tom Zanussi]

Hi Masami,

On Fri, 2019-06-28 at 14:39 +0900, Masami Hiramatsu wrote:
> On Thu, 27 Jun 2019 10:35:16 -0500
> Tom Zanussi <zanussi@kernel.org> wrote:
> 
> > In the process of adding better error messages for sorting, I
> > realized
> > that strsep was being used incorrectly and some of the error paths
> > I
> > was expecting to be hit weren't and just fell through to the common
> > invalid key error case.
> 
> Would you mean this includes a bugfix too?
> 

Yes, though not actually a problem or visible to the user.  This
basically cleans things up so that the next patch adding the error
messages works as expected.

Tom

> > 
> > It also became obvious that for keyword assignments, it wasn't
> > necessary to save the full assignment and reparse it later, and
> > having
> > a common empty-assignment check would also make more sense in terms
> > of
> > error processing.
> > 
> > Change the code to fix these problems and simplify it for new error
> > message changes in a subsequent patch.
> > 
> > Signed-off-by: Tom Zanussi <zanussi@kernel.org>
> 
> Anyway looks good to me.
> 
> Reviewed-by: Masami Hiramatsu <mhiramat@kernel.org>
> 
> Thanks,
> 
> > ---
> >  kernel/trace/trace_events_hist.c | 70 ++++++++++++++++----------
> > --------------
> >  1 file changed, 27 insertions(+), 43 deletions(-)
> > 
> > diff --git a/kernel/trace/trace_events_hist.c
> > b/kernel/trace/trace_events_hist.c
> > index ca6b0dff60c5..964d032f51c6 100644
> > --- a/kernel/trace/trace_events_hist.c
> > +++ b/kernel/trace/trace_events_hist.c
> > @@ -1985,12 +1985,6 @@ static int parse_map_size(char *str)
> >  	unsigned long size, map_bits;
> >  	int ret;
> >  
> > -	strsep(&str, "=");
> > -	if (!str) {
> > -		ret = -EINVAL;
> > -		goto out;
> > -	}
> > -
> >  	ret = kstrtoul(str, 0, &size);
> >  	if (ret)
> >  		goto out;
> > @@ -2050,25 +2044,25 @@ static int parse_action(char *str, struct
> > hist_trigger_attrs *attrs)
> >  static int parse_assignment(struct trace_array *tr,
> >  			    char *str, struct hist_trigger_attrs
> > *attrs)
> >  {
> > -	int ret = 0;
> > +	int len, ret = 0;
> >  
> > -	if ((str_has_prefix(str, "key=")) ||
> > -	    (str_has_prefix(str, "keys="))) {
> > -		attrs->keys_str = kstrdup(str, GFP_KERNEL);
> > +	if ((len = str_has_prefix(str, "key=")) ||
> > +	    (len = str_has_prefix(str, "keys="))) {
> > +		attrs->keys_str = kstrdup(str + len, GFP_KERNEL);
> >  		if (!attrs->keys_str) {
> >  			ret = -ENOMEM;
> >  			goto out;
> >  		}
> > -	} else if ((str_has_prefix(str, "val=")) ||
> > -		   (str_has_prefix(str, "vals=")) ||
> > -		   (str_has_prefix(str, "values="))) {
> > -		attrs->vals_str = kstrdup(str, GFP_KERNEL);
> > +	} else if ((len = str_has_prefix(str, "val=")) ||
> > +		   (len = str_has_prefix(str, "vals=")) ||
> > +		   (len = str_has_prefix(str, "values="))) {
> > +		attrs->vals_str = kstrdup(str + len, GFP_KERNEL);
> >  		if (!attrs->vals_str) {
> >  			ret = -ENOMEM;
> >  			goto out;
> >  		}
> > -	} else if (str_has_prefix(str, "sort=")) {
> > -		attrs->sort_key_str = kstrdup(str, GFP_KERNEL);
> > +	} else if ((len = str_has_prefix(str, "sort="))) {
> > +		attrs->sort_key_str = kstrdup(str + len,
> > GFP_KERNEL);
> >  		if (!attrs->sort_key_str) {
> >  			ret = -ENOMEM;
> >  			goto out;
> > @@ -2079,12 +2073,8 @@ static int parse_assignment(struct
> > trace_array *tr,
> >  			ret = -ENOMEM;
> >  			goto out;
> >  		}
> > -	} else if (str_has_prefix(str, "clock=")) {
> > -		strsep(&str, "=");
> > -		if (!str) {
> > -			ret = -EINVAL;
> > -			goto out;
> > -		}
> > +	} else if ((len = str_has_prefix(str, "clock="))) {
> > +		str += len;
> >  
> >  		str = strstrip(str);
> >  		attrs->clock = kstrdup(str, GFP_KERNEL);
> > @@ -2092,8 +2082,8 @@ static int parse_assignment(struct
> > trace_array *tr,
> >  			ret = -ENOMEM;
> >  			goto out;
> >  		}
> > -	} else if (str_has_prefix(str, "size=")) {
> > -		int map_bits = parse_map_size(str);
> > +	} else if ((len = str_has_prefix(str, "size="))) {
> > +		int map_bits = parse_map_size(str + len);
> >  
> >  		if (map_bits < 0) {
> >  			ret = map_bits;
> > @@ -2133,8 +2123,14 @@ parse_hist_trigger_attrs(struct trace_array
> > *tr, char *trigger_str)
> >  
> >  	while (trigger_str) {
> >  		char *str = strsep(&trigger_str, ":");
> > +		char *rhs;
> >  
> > -		if (strchr(str, '=')) {
> > +		rhs = strchr(str, '=');
> > +		if (rhs) {
> > +			if (!strlen(++rhs)) {
> > +				ret = -EINVAL;
> > +				goto free;
> > +			}
> >  			ret = parse_assignment(tr, str, attrs);
> >  			if (ret)
> >  				goto free;
> > @@ -4459,10 +4455,6 @@ static int create_val_fields(struct
> > hist_trigger_data *hist_data,
> >  	if (!fields_str)
> >  		goto out;
> >  
> > -	strsep(&fields_str, "=");
> > -	if (!fields_str)
> > -		goto out;
> > -
> >  	for (i = 0, j = 1; i < TRACING_MAP_VALS_MAX &&
> >  		     j < TRACING_MAP_VALS_MAX; i++) {
> >  		field_str = strsep(&fields_str, ",");
> > @@ -4557,10 +4549,6 @@ static int create_key_fields(struct
> > hist_trigger_data *hist_data,
> >  	if (!fields_str)
> >  		goto out;
> >  
> > -	strsep(&fields_str, "=");
> > -	if (!fields_str)
> > -		goto out;
> > -
> >  	for (i = n_vals; i < n_vals + TRACING_MAP_KEYS_MAX; i++) {
> >  		field_str = strsep(&fields_str, ",");
> >  		if (!field_str)
> > @@ -4718,12 +4706,6 @@ static int create_sort_keys(struct
> > hist_trigger_data *hist_data)
> >  	if (!fields_str)
> >  		goto out;
> >  
> > -	strsep(&fields_str, "=");
> > -	if (!fields_str) {
> > -		ret = -EINVAL;
> > -		goto out;
> > -	}
> > -
> >  	for (i = 0; i < TRACING_MAP_SORT_KEYS_MAX; i++) {
> >  		struct hist_field *hist_field;
> >  		char *field_str, *field_name;
> > @@ -4732,9 +4714,11 @@ static int create_sort_keys(struct
> > hist_trigger_data *hist_data)
> >  		sort_key = &hist_data->sort_keys[i];
> >  
> >  		field_str = strsep(&fields_str, ",");
> > -		if (!field_str) {
> > -			if (i == 0)
> > -				ret = -EINVAL;
> > +		if (!field_str)
> > +			break;
> > +
> > +		if (!*field_str) {
> > +			ret = -EINVAL;
> >  			break;
> >  		}
> >  
> > @@ -4744,7 +4728,7 @@ static int create_sort_keys(struct
> > hist_trigger_data *hist_data)
> >  		}
> >  
> >  		field_name = strsep(&field_str, ".");
> > -		if (!field_name) {
> > +		if (!field_name || !*field_name) {
> >  			ret = -EINVAL;
> >  			break;
> >  		}
> > -- 
> > 2.14.1
> > 
> 
> 

[PATCH 2/4] tracing: Add hist trigger error messages for sort specification

[Tom Zanussi]

Add error codes and messages for all the error paths leading to sort
specification parsing errors.

Signed-off-by: Tom Zanussi <zanussi@kernel.org>
---
 kernel/trace/trace_events_hist.c | 21 +++++++++++++++++----
 1 file changed, 17 insertions(+), 4 deletions(-)

diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c
index 964d032f51c6..d33c94a1cfa9 100644
--- a/kernel/trace/trace_events_hist.c
+++ b/kernel/trace/trace_events_hist.c
@@ -61,7 +61,12 @@
 	C(INVALID_SUBSYS_EVENT,	"Invalid subsystem or event name"),	\
 	C(INVALID_REF_KEY,	"Using variable references in keys not supported"), \
 	C(VAR_NOT_FOUND,	"Couldn't find variable"),		\
-	C(FIELD_NOT_FOUND,	"Couldn't find field"),
+	C(FIELD_NOT_FOUND,	"Couldn't find field"),			\
+	C(EMPTY_ASSIGNMENT,	"Empty assignment"),			\
+	C(INVALID_SORT_MODIFIER,"Invalid sort modifier"),		\
+	C(EMPTY_SORT_FIELD,	"Empty sort field"),			\
+	C(TOO_MANY_SORT_FIELDS,	"Too many sort fields (Max = 2)"),	\
+	C(INVALID_SORT_FIELD,	"Sort field must be a key or a val"),
 
 #undef C
 #define C(a, b)		HIST_ERR_##a
@@ -2129,6 +2134,7 @@ parse_hist_trigger_attrs(struct trace_array *tr, char *trigger_str)
 		if (rhs) {
 			if (!strlen(++rhs)) {
 				ret = -EINVAL;
+				hist_err(tr, HIST_ERR_EMPTY_ASSIGNMENT, errpos(str));
 				goto free;
 			}
 			ret = parse_assignment(tr, str, attrs);
@@ -4680,7 +4686,7 @@ static int create_hist_fields(struct hist_trigger_data *hist_data,
 	return ret;
 }
 
-static int is_descending(const char *str)
+static int is_descending(struct trace_array *tr, const char *str)
 {
 	if (!str)
 		return 0;
@@ -4691,11 +4697,14 @@ static int is_descending(const char *str)
 	if (strcmp(str, "ascending") == 0)
 		return 0;
 
+	hist_err(tr, HIST_ERR_INVALID_SORT_MODIFIER, errpos((char *)str));
+
 	return -EINVAL;
 }
 
 static int create_sort_keys(struct hist_trigger_data *hist_data)
 {
+	struct trace_array *tr = hist_data->event_file->tr;
 	char *fields_str = hist_data->attrs->sort_key_str;
 	struct tracing_map_sort_key *sort_key;
 	int descending, ret = 0;
@@ -4719,10 +4728,12 @@ static int create_sort_keys(struct hist_trigger_data *hist_data)
 
 		if (!*field_str) {
 			ret = -EINVAL;
+			hist_err(tr, HIST_ERR_EMPTY_SORT_FIELD, errpos("sort="));
 			break;
 		}
 
 		if ((i == TRACING_MAP_SORT_KEYS_MAX - 1) && fields_str) {
+			hist_err(tr, HIST_ERR_TOO_MANY_SORT_FIELDS, errpos("sort="));
 			ret = -EINVAL;
 			break;
 		}
@@ -4730,11 +4741,12 @@ static int create_sort_keys(struct hist_trigger_data *hist_data)
 		field_name = strsep(&field_str, ".");
 		if (!field_name || !*field_name) {
 			ret = -EINVAL;
+			hist_err(tr, HIST_ERR_EMPTY_SORT_FIELD, errpos("sort="));
 			break;
 		}
 
 		if (strcmp(field_name, "hitcount") == 0) {
-			descending = is_descending(field_str);
+			descending = is_descending(tr, field_str);
 			if (descending < 0) {
 				ret = descending;
 				break;
@@ -4756,7 +4768,7 @@ static int create_sort_keys(struct hist_trigger_data *hist_data)
 
 			if (strcmp(field_name, test_name) == 0) {
 				sort_key->field_idx = idx;
-				descending = is_descending(field_str);
+				descending = is_descending(tr, field_str);
 				if (descending < 0) {
 					ret = descending;
 					goto out;
@@ -4767,6 +4779,7 @@ static int create_sort_keys(struct hist_trigger_data *hist_data)
 		}
 		if (j == hist_data->n_fields) {
 			ret = -EINVAL;
+			hist_err(tr, HIST_ERR_INVALID_SORT_FIELD, errpos(field_name));
 			break;
 		}
 	}
-- 
2.14.1

[PATCH 3/4] tracing: Add 'hist:' to hist trigger error log error string

[Tom Zanussi]

The 'hist:' prefix gets stripped from the command text during command
processing, but should be added back when displaying the command
during error processing.

Not only because it's what should be displayed but also because not
having it means the test cases fail because the caret is miscalculated
by the length of the prefix string.

Signed-off-by: Tom Zanussi <zanussi@kernel.org>
---
 kernel/trace/trace_events_hist.c | 3 ++-
 1 file changed, 2 insertions(+), 1 deletion(-)

diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c
index d33c94a1cfa9..79768f22d5c5 100644
--- a/kernel/trace/trace_events_hist.c
+++ b/kernel/trace/trace_events_hist.c
@@ -607,7 +607,8 @@ static void last_cmd_set(struct trace_event_file *file, char *str)
 	if (!str)
 		return;
 
-	strncpy(last_cmd, str, MAX_FILTER_STR_VAL - 1);
+	strcpy(last_cmd, "hist:");
+	strncat(last_cmd, str, MAX_FILTER_STR_VAL - 1 - sizeof("hist:"));
 
 	if (file) {
 		call = file->event_call;
-- 
2.14.1

[PATCH 4/4] tracing: Add new testcases for hist trigger parsing errors

[Tom Zanussi]

Add a testcase ensuring that the tracing error_log correctly displays
hist trigger parsing errors.

Signed-off-by: Tom Zanussi <zanussi@kernel.org>
---
 .../test.d/trigger/trigger-hist-syntax-errors.tc   | 32 ++++++++++++++++++++++
 1 file changed, 32 insertions(+)
 create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-syntax-errors.tc

diff --git a/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-syntax-errors.tc b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-syntax-errors.tc
new file mode 100644
index 000000000000..d44087a2f3d1
--- /dev/null
+++ b/tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-syntax-errors.tc
@@ -0,0 +1,32 @@
+#!/bin/sh
+# SPDX-License-Identifier: GPL-2.0
+# description: event trigger - test histogram parser errors
+
+if [ ! -f set_event -o ! -d events/kmem ]; then
+    echo "event tracing is not supported"
+    exit_unsupported
+fi
+
+if [ ! -f events/kmem/kmalloc/trigger ]; then
+    echo "event trigger is not supported"
+    exit_unsupported
+fi
+
+if [ ! -f events/kmem/kmalloc/hist ]; then
+    echo "hist trigger is not supported"
+    exit_unsupported
+fi
+
+[ -f error_log ] || exit_unsupported
+
+check_error() { # command-with-error-pos-by-^
+    ftrace_errlog_check 'hist:kmem:kmalloc' "$1" 'events/kmem/kmalloc/trigger'
+}
+
+check_error 'hist:keys=common_pid:vals=bytes_req:sort=common_pid,^junk'	# INVALID_SORT_FIELD
+check_error 'hist:keys=common_pid:vals=bytes_req:^sort='		# EMPTY_ASSIGNMENT
+check_error 'hist:keys=common_pid:vals=bytes_req:^sort=common_pid,'	# EMPTY_SORT_FIELD
+check_error 'hist:keys=common_pid:vals=bytes_req:sort=common_pid.^junk'	# INVALID_SORT_MODIFIER
+check_error 'hist:keys=common_pid:vals=bytes_req,bytes_alloc:^sort=common_pid,bytes_req,bytes_alloc'	# TOO_MANY_SORT_FIELDS
+
+exit 0
-- 
2.14.1

Re: [PATCH 0/4] tracing: Improve error messages for histogram sorting

[Masami Hiramatsu]

On Thu, 27 Jun 2019 10:35:15 -0500
Tom Zanussi <zanussi@kernel.org> wrote:

> Hi,
> 
> These patches add some improvements for histogram sorting, addressing
> some shortcomings pointed out by Masami.
> 
> In order to address the specific problem pointed out by Masami, as
> well as add additional related error messages, the first patch
> does some simplification of assignment parsing.
> 
> The second patch actually adds the new error messages.
> 
> The fourth patch adds a new testcase for hist trigger parsing, similar
> to the same kind of tests for kprobes and uprobes.  Additional tests
> covering all possible hist trigger errors should/will be added here in
> the future.
> 
> The third patch just adds a missing hist: prefix to the error log so
> that the testcases work properly, and which should have been there
> anyway.
> 
> Thanks,


Hi Tom,

These patches look good to me :)

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

for all patches. BTW, if you think there is a bug and the 1st one fixes it,
please add Fixes: tag.

Thank you,
> 
> Tom
> 
> The following changes since commit a124692b698b00026a58d89831ceda2331b2e1d0:
> 
>   ftrace: Enable trampoline when rec count returns back to one (2019-05-25 23:04:43 -0400)
> 
> are available in the git repository at:
> 
>   git://git.kernel.org/pub/scm/linux/kernel/git/zanussi/linux-trace.git ftrace-hist-sort-err-msgs-v1
> 
> Tom Zanussi (4):
>   tracing: Simplify assignment parsing for hist triggers
>   tracing: Add hist trigger error messages for sort specification
>   tracing: Add 'hist:' to hist trigger error log error string
>   tracing: Add new testcases for hist trigger parsing errors
> 
>  kernel/trace/trace_events_hist.c                   | 94 +++++++++++-----------
>  .../test.d/trigger/trigger-hist-syntax-errors.tc   | 32 ++++++++
>  2 files changed, 78 insertions(+), 48 deletions(-)
>  create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-syntax-errors.tc
> 
> -- 
> 2.14.1
> 


-- 
Masami Hiramatsu <mhiramat@kernel.org>

Re: [PATCH 0/4] tracing: Improve error messages for histogram sorting

[Tom Zanussi]

Hi Masami,

On Fri, 2019-06-28 at 15:16 +0900, Masami Hiramatsu wrote:
> On Thu, 27 Jun 2019 10:35:15 -0500
> Tom Zanussi <zanussi@kernel.org> wrote:
> 
> > Hi,
> > 
> > These patches add some improvements for histogram sorting,
> > addressing
> > some shortcomings pointed out by Masami.
> > 
> > In order to address the specific problem pointed out by Masami, as
> > well as add additional related error messages, the first patch
> > does some simplification of assignment parsing.
> > 
> > The second patch actually adds the new error messages.
> > 
> > The fourth patch adds a new testcase for hist trigger parsing,
> > similar
> > to the same kind of tests for kprobes and uprobes.  Additional
> > tests
> > covering all possible hist trigger errors should/will be added here
> > in
> > the future.
> > 
> > The third patch just adds a missing hist: prefix to the error log
> > so
> > that the testcases work properly, and which should have been there
> > anyway.
> > 
> > Thanks,
> 
> 
> Hi Tom,
> 
> These patches look good to me :)
> 
> Reviewed-by: Masami Hiramatsu <mhiramat@kernel.org>
> 
> for all patches. BTW, if you think there is a bug and the 1st one
> fixes it,
> please add Fixes: tag.
> 

Yeah, I'll submit a v2 that adds that.

Thanks for the review,

Tom


> Thank you,
> > 
> > Tom
> > 
> > The following changes since commit
> > a124692b698b00026a58d89831ceda2331b2e1d0:
> > 
> >   ftrace: Enable trampoline when rec count returns back to one
> > (2019-05-25 23:04:43 -0400)
> > 
> > are available in the git repository at:
> > 
> >   git://git.kernel.org/pub/scm/linux/kernel/git/zanussi/linux-
> > trace.git ftrace-hist-sort-err-msgs-v1
> > 
> > Tom Zanussi (4):
> >   tracing: Simplify assignment parsing for hist triggers
> >   tracing: Add hist trigger error messages for sort specification
> >   tracing: Add 'hist:' to hist trigger error log error string
> >   tracing: Add new testcases for hist trigger parsing errors
> > 
> >  kernel/trace/trace_events_hist.c                   | 94
> > +++++++++++-----------
> >  .../test.d/trigger/trigger-hist-syntax-errors.tc   | 32 ++++++++
> >  2 files changed, 78 insertions(+), 48 deletions(-)
> >  create mode 100644
> > tools/testing/selftests/ftrace/test.d/trigger/trigger-hist-syntax-
> > errors.tc
> > 
> > -- 
> > 2.14.1
> > 
> 
>