Re: [PATCH 29/32] tracing: Add 'last error' error facility for hist triggers

Namhyung Kim
2017-07-26T04:39:07Z

On Mon, Jun 26, 2017 at 05:49:30PM -0500, Tom Zanussi wrote:
> With the addition of variables and actions, it's become necessary to
> provide more detailed error information to users about syntax errors.
>
> Add a 'last error' facility accessible via the erroring event's 'hist'
> file. Reading the hist file after an error will display more detailed
> information about what went wrong, if information is available. This
> extended error information will be available until the next hist
> trigger command for that event.
>
> # echo xxx > /sys/kernel/debug/tracing/events/sched/sched_wakeup/trigger
> echo: write error: Invalid argument
>
> # cat /sys/kernel/debug/tracing/events/sched/sched_wakeup/hist
>
> ERROR: Couldn't yyy: zzz
> Last command: xxx
>
> Also add specific error messages for variable and action errors.
>
> Signed-off-by: Tom Zanussi <tom.zanussi@linux.intel.com>
> ---
> Documentation/trace/events.txt | 19 ++++
> kernel/trace/trace_events_hist.c | 181 ++++++++++++++++++++++++++++++++++++---
> 2 files changed, 188 insertions(+), 12 deletions(-)
>
> diff --git a/Documentation/trace/events.txt b/Documentation/trace/events.txt
> index 9717688..f271d87 100644
> --- a/Documentation/trace/events.txt
> +++ b/Documentation/trace/events.txt
> @@ -686,6 +686,25 @@ The following commands are supported:
> interpreted as microseconds.
> cpu int - the cpu on which the event occurred.
>
> + Extended error information
> + --------------------------
> +
> + For some error conditions encountered when invoking a hist trigger
> + command, extended error information is available via the
> + corresponding event's 'hist' file. Reading the hist file after an
> + error will display more detailed information about what went wrong,
> + if information is available. This extended error information will
> + be available until the next hist trigger command for that event.
> +
> + If available for a given error condition, the extended error
> + information and usage takes the following form:
> +
> + # echo xxx > /sys/kernel/debug/tracing/events/sched/sched_wakeup/trigger
> + echo: write error: Invalid argument
> +
> + # cat /sys/kernel/debug/tracing/events/sched/sched_wakeup/hist
> + ERROR: Couldn't yyy: zzz
> + Last command: xxx
>
> 6.2 'hist' trigger examples
> ---------------------------
> diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c
> index 799b95e..06049f8 100644
> --- a/kernel/trace/trace_events_hist.c
> +++ b/kernel/trace/trace_events_hist.c
> @@ -288,6 +288,7 @@ struct hist_trigger_data {
> struct field_var *max_vars[SYNTH_FIELDS_MAX];
> unsigned int n_max_vars;
> unsigned int n_max_var_str;
> + char *last_err;

I couldn't find where it's used.

> };
>
> struct synth_field {
> @@ -332,6 +333,83 @@ struct action_data {
> struct hist_field *onmax_var;
> };
>
> +
> +static char *hist_err_str;
> +static char *last_hist_cmd;
> +
> +static int hist_err_alloc(void)
> +{
> + int ret = 0;
> +
> + last_hist_cmd = kzalloc(MAX_FILTER_STR_VAL, GFP_KERNEL);
> + hist_err_str = kzalloc(MAX_FILTER_STR_VAL, GFP_KERNEL);
> + if (!last_hist_cmd || !hist_err_str)
> + ret = -ENOMEM;

This makes me uncomfortable..

> +
> + return ret;
> +}
> +
> +static void last_cmd_set(char *str)
> +{
> + if (!last_hist_cmd || !str)
> + return;
> +
> + if (strlen(last_hist_cmd) > MAX_FILTER_STR_VAL - 1)
> + return;

Hmm.. why does it check 'last_hist_cmd' rather than 'str'?

> +
> + strcpy(last_hist_cmd, str);
> +}
> +
> +static void hist_err(char *str, char *var)
> +{
> + int maxlen = MAX_FILTER_STR_VAL - 1;
> +
> + if (strlen(hist_err_str))
> + return;

Shouldn't it move to after the NULL check below?

Thanks,
Namhyung

> +
> + if (!hist_err_str || !str)
> + return;
> +
> + if (!var)
> + var = "";
> +
> + if (strlen(hist_err_str) + strlen(str) + strlen(var) > maxlen)
> + return;
> +
> + strcat(hist_err_str, str);
> + strcat(hist_err_str, var);
> +}
> +
> +static void hist_err_event(char *str, char *system, char *event, char *var)
> +{
> + char err[MAX_FILTER_STR_VAL];
> +
> + if (system && var)
> + sprintf(err, "%s.%s.%s", system, event, var);
> + else if (system)
> + sprintf(err, "%s.%s", system, event);
> + else
> + strcpy(err, var);
> +
> + hist_err(str, err);
> +}
> +
> +static void hist_err_clear(void)
> +{
> + if (!hist_err_str)
> + return;
> +
> + hist_err_str[0] = '\0';
> +}
> +
> +static bool have_hist_err(void)
> +{
> + if (hist_err_str && strlen(hist_err_str))
> + return true;
> +
> + return false;
> +}