diff --git a/Documentation/trace/histogram.txt b/Documentation/trace/histogram.txt
index be612ca794550f82da7b3a974ccac08a79c0db2c..0aec2d8e166b2f6130de8d58383f26ae14386f53 100644
--- a/Documentation/trace/histogram.txt
+++ b/Documentation/trace/histogram.txt
@@ -188,6 +188,26 @@
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 32af523501bc56b5860f46f2eeb27a65b8d07fd8..8719b0ea672ffb6126e704bbff5c5d765bd2773c 100644
--- a/kernel/trace/trace_events_hist.c
+++ b/kernel/trace/trace_events_hist.c
@@ -351,6 +351,65 @@ struct action_data {
};
};
+
+static char last_hist_cmd[MAX_FILTER_STR_VAL];
+static char hist_err_str[MAX_FILTER_STR_VAL];
+
+static void last_cmd_set(char *str)
+{
+ if (!str)
+ return;
+
+ strncpy(last_hist_cmd, str, MAX_FILTER_STR_VAL - 1);
+}
+
+static void hist_err(char *str, char *var)
+{
+ int maxlen = MAX_FILTER_STR_VAL - 1;
+
+ if (!str)
+ return;
+
+ if (strlen(hist_err_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)
+ snprintf(err, MAX_FILTER_STR_VAL, "%s.%s.%s", system, event, var);
+ else if (system)
+ snprintf(err, MAX_FILTER_STR_VAL, "%s.%s", system, event);
+ else
+ strncpy(err, var, MAX_FILTER_STR_VAL);
+
+ hist_err(str, err);
+}
+
+static void hist_err_clear(void)
+{
+ hist_err_str[0] = '\0';
+}
+
+static bool have_hist_err(void)
+{
+ if (strlen(hist_err_str))
+ return true;
+
+ return false;
+}
+
static LIST_HEAD(synth_event_list);
static DEFINE_MUTEX(synth_event_mutex);
@@ -1448,8 +1507,10 @@ static struct trace_event_file *find_var_file(struct trace_array *tr,
continue;
if (find_var_field(var_hist_data, var_name)) {
- if (found)
+ if (found) {
+ hist_err_event("Variable name not unique, need to use fully qualified name (subsys.event.var) for variable: ", system, event_name, var_name);
return NULL;
+ }
found = file;
}
@@ -1498,6 +1559,7 @@ find_match_var(struct hist_trigger_data *hist_data, char *var_name)
hist_field = find_file_var(file, var_name);
if (hist_field) {
if (found) {
+ hist_err_event("Variable name not unique, need to use fully qualified name (subsys.event.var) for variable: ", system, event_name, var_name);
return ERR_PTR(-EINVAL);
}
@@ -1781,6 +1843,7 @@ static int parse_assignment(char *str, struct hist_trigger_attrs *attrs)
char *assignment;
if (attrs->n_assignments == TRACING_MAP_VARS_MAX) {
+ hist_err("Too many variables defined: ", str);
ret = -EINVAL;
goto out;
}
@@ -2335,6 +2398,10 @@ static struct hist_field *parse_var_ref(struct hist_trigger_data *hist_data,
if (var_field)
ref_field = create_var_ref(var_field, system, event_name);
+ if (!ref_field)
+ hist_err_event("Couldn't find variable: $",
+ system, event_name, var_name);
+
return ref_field;
}
@@ -2494,6 +2561,7 @@ static struct hist_field *parse_unary(struct hist_trigger_data *hist_data,
/* we support only -(xxx) i.e. explicit parens required */
if (level > 3) {
+ hist_err("Too many subexpressions (3 max): ", str);
ret = -EINVAL;
goto free;
}
@@ -2575,8 +2643,10 @@ static int check_expr_operands(struct hist_field *operand1,
}
if ((operand1_flags & HIST_FIELD_FL_TIMESTAMP_USECS) !=
- (operand2_flags & HIST_FIELD_FL_TIMESTAMP_USECS))
+ (operand2_flags & HIST_FIELD_FL_TIMESTAMP_USECS)) {
+ hist_err("Timestamp units in expression don't match", NULL);
return -EINVAL;
+ }
return 0;
}
@@ -2591,8 +2661,10 @@ static struct hist_field *parse_expr(struct hist_trigger_data *hist_data,
int field_op, ret = -EINVAL;
char *sep, *operand1_str;
- if (level > 3)
+ if (level > 3) {
+ hist_err("Too many subexpressions (3 max): ", str);
return ERR_PTR(-EINVAL);
+ }
field_op = contains_operator(str);
@@ -2826,12 +2898,17 @@ create_field_var_hist(struct hist_trigger_data *target_hist_data,
char *cmd;
int ret;
- if (target_hist_data->n_field_var_hists >= SYNTH_FIELDS_MAX)
+ if (target_hist_data->n_field_var_hists >= SYNTH_FIELDS_MAX) {
+ hist_err_event("onmatch: Too many field variables defined: ",
+ subsys_name, event_name, field_name);
return ERR_PTR(-EINVAL);
+ }
file = event_file(tr, subsys_name, event_name);
if (IS_ERR(file)) {
+ hist_err_event("onmatch: Event file not found: ",
+ subsys_name, event_name, field_name);
ret = PTR_ERR(file);
return ERR_PTR(ret);
}
@@ -2843,8 +2920,11 @@ create_field_var_hist(struct hist_trigger_data *target_hist_data,
* yet a registered histogram so we can't use that.
*/
hist_data = find_compatible_hist(target_hist_data, file);
- if (!hist_data)
+ if (!hist_data) {
+ hist_err_event("onmatch: Matching event histogram not found: ",
+ subsys_name, event_name, field_name);
return ERR_PTR(-EINVAL);
+ }
/* See if a synthetic field variable has already been created */
event_var = find_synthetic_field_var(target_hist_data, subsys_name,
@@ -2903,6 +2983,8 @@ create_field_var_hist(struct hist_trigger_data *target_hist_data,
kfree(cmd);
kfree(var_hist->cmd);
kfree(var_hist);
+ hist_err_event("onmatch: Couldn't create histogram for field: ",
+ subsys_name, event_name, field_name);
return ERR_PTR(ret);
}
@@ -2914,6 +2996,8 @@ create_field_var_hist(struct hist_trigger_data *target_hist_data,
if (IS_ERR_OR_NULL(event_var)) {
kfree(var_hist->cmd);
kfree(var_hist);
+ hist_err_event("onmatch: Couldn't find synthetic variable: ",
+ subsys_name, event_name, field_name);
return ERR_PTR(-EINVAL);
}
@@ -3050,18 +3134,21 @@ static struct field_var *create_field_var(struct hist_trigger_data *hist_data,
int ret = 0;
if (hist_data->n_field_vars >= SYNTH_FIELDS_MAX) {
+ hist_err("Too many field variables defined: ", field_name);
ret = -EINVAL;
goto err;
}
val = parse_atom(hist_data, file, field_name, &flags, NULL);
if (IS_ERR(val)) {
+ hist_err("Couldn't parse field variable: ", field_name);
ret = PTR_ERR(val);
goto err;
}
var = create_var(hist_data, file, field_name, val->size, val->type);
if (IS_ERR(var)) {
+ hist_err("Couldn't create or find variable: ", field_name);
kfree(val);
ret = PTR_ERR(var);
goto err;
@@ -3204,13 +3291,17 @@ static int onmax_create(struct hist_trigger_data *hist_data,
int ret = 0;
onmax_var_str = data->onmax.var_str;
- if (onmax_var_str[0] != '$')
+ if (onmax_var_str[0] != '$') {
+ hist_err("onmax: For onmax(x), x must be a variable: ", onmax_var_str);
return -EINVAL;
+ }
onmax_var_str++;
var_field = find_target_event_var(hist_data, NULL, NULL, onmax_var_str);
- if (!var_field)
+ if (!var_field) {
+ hist_err("onmax: Couldn't find onmax variable: ", onmax_var_str);
return -EINVAL;
+ }
flags = HIST_FIELD_FL_VAR_REF;
ref_field = create_hist_field(hist_data, NULL, flags, NULL);
@@ -3230,6 +3321,7 @@ static int onmax_create(struct hist_trigger_data *hist_data,
data->onmax.max_var_ref_idx = var_ref_idx;
max_var = create_var(hist_data, file, "max", sizeof(u64), "u64");
if (IS_ERR(max_var)) {
+ hist_err("onmax: Couldn't create onmax variable: ", "max");
ret = PTR_ERR(max_var);
goto out;
}
@@ -3244,6 +3336,7 @@ static int onmax_create(struct hist_trigger_data *hist_data,
field_var = create_target_field_var(hist_data, NULL, NULL, param);
if (IS_ERR(field_var)) {
+ hist_err("onmax: Couldn't create field variable: ", param);
ret = PTR_ERR(field_var);
kfree(param);
goto out;
@@ -3276,6 +3369,7 @@ static int parse_action_params(char *params, struct action_data *data)
param = strstrip(param);
if (strlen(param) < 2) {
+ hist_err("Invalid action param: ", param);
ret = -EINVAL;
goto out;
}
@@ -3451,6 +3545,9 @@ onmatch_find_var(struct hist_trigger_data *hist_data, struct action_data *data,
hist_field = find_event_var(hist_data, system, event, var);
}
+ if (!hist_field)
+ hist_err_event("onmatch: Couldn't find onmatch param: $", system, event, var);
+
return hist_field;
}
@@ -3518,6 +3615,7 @@ static int onmatch_create(struct hist_trigger_data *hist_data,
mutex_lock(&synth_event_mutex);
event = find_synth_event(data->onmatch.synth_event_name);
if (!event) {
+ hist_err("onmatch: Couldn't find synthetic event: ", data->onmatch.synth_event_name);
mutex_unlock(&synth_event_mutex);
return -EINVAL;
}
@@ -3577,12 +3675,15 @@ static int onmatch_create(struct hist_trigger_data *hist_data,
continue;
}
+ hist_err_event("onmatch: Param type doesn't match synthetic event field type: ",
+ system, event_name, param);
kfree(p);
ret = -EINVAL;
goto err;
}
if (field_pos != event->n_fields) {
+ hist_err("onmatch: Param count doesn't match synthetic event field count: ", event->name);
ret = -EINVAL;
goto err;
}
@@ -3612,15 +3713,22 @@ static struct action_data *onmatch_parse(struct trace_array *tr, char *str)
return ERR_PTR(-ENOMEM);
match_event = strsep(&str, ")");
- if (!match_event || !str)
+ if (!match_event || !str) {
+ hist_err("onmatch: Missing closing paren: ", match_event);
goto free;
+ }
match_event_system = strsep(&match_event, ".");
- if (!match_event)
+ if (!match_event) {
+ hist_err("onmatch: Missing subsystem for match event: ", match_event_system);
goto free;
+ }
- if (IS_ERR(event_file(tr, match_event_system, match_event)))
+ if (IS_ERR(event_file(tr, match_event_system, match_event))) {
+ hist_err_event("onmatch: Invalid subsystem or event name: ",
+ match_event_system, match_event, NULL);
goto free;
+ }
data->onmatch.match_event = kstrdup(match_event, GFP_KERNEL);
if (!data->onmatch.match_event) {
@@ -3635,12 +3743,16 @@ static struct action_data *onmatch_parse(struct trace_array *tr, char *str)
}
strsep(&str, ".");
- if (!str)
+ if (!str) {
+ hist_err("onmatch: Missing . after onmatch(): ", str);
goto free;
+ }
synth_event_name = strsep(&str, "(");
- if (!synth_event_name || !str)
+ if (!synth_event_name || !str) {
+ hist_err("onmatch: Missing opening paramlist paren: ", synth_event_name);
goto free;
+ }
data->onmatch.synth_event_name = kstrdup(synth_event_name, GFP_KERNEL);
if (!data->onmatch.synth_event_name) {
@@ -3649,8 +3761,10 @@ static struct action_data *onmatch_parse(struct trace_array *tr, char *str)
}
params = strsep(&str, ")");
- if (!params || !str || (str && strlen(str)))
+ if (!params || !str || (str && strlen(str))) {
+ hist_err("onmatch: Missing closing paramlist paren: ", params);
goto free;
+ }
ret = parse_action_params(params, data);
if (ret)
@@ -3725,7 +3839,9 @@ static int create_var_field(struct hist_trigger_data *hist_data,
if (WARN_ON(val_idx >= TRACING_MAP_VALS_MAX + TRACING_MAP_VARS_MAX))
return -EINVAL;
+
if (find_var(hist_data, file, var_name) && !hist_data->remove) {
+ hist_err("Variable already defined: ", var_name);
return -EINVAL;
}
@@ -3806,6 +3922,7 @@ static int create_key_field(struct hist_trigger_data *hist_data,
}
if (hist_field->flags & HIST_FIELD_FL_VAR_REF) {
+ hist_err("Using variable references as keys not supported: ", field_str);
destroy_hist_field(hist_field, 0);
ret = -EINVAL;
goto out;
@@ -3919,11 +4036,13 @@ static int parse_var_defs(struct hist_trigger_data *hist_data)
var_name = strsep(&field_str, "=");
if (!var_name || !field_str) {
+ hist_err("Malformed assignment: ", var_name);
ret = -EINVAL;
goto free;
}
if (n_vars == TRACING_MAP_VARS_MAX) {
+ hist_err("Too many variables defined: ", var_name);
ret = -EINVAL;
goto free;
}
@@ -4675,6 +4794,11 @@ static int hist_show(struct seq_file *m, void *v)
hist_trigger_show(m, data, n++);
}
+ if (have_hist_err()) {
+ seq_printf(m, "\nERROR: %s\n", hist_err_str);
+ seq_printf(m, " Last command: %s\n", last_hist_cmd);
+ }
+
out_unlock:
mutex_unlock(&event_mutex);
@@ -5039,6 +5163,7 @@ static int hist_register_trigger(char *glob, struct event_trigger_ops *ops,
if (named_data) {
if (!hist_trigger_match(data, named_data, named_data,
true)) {
+ hist_err("Named hist trigger doesn't match existing named trigger (includes variables): ", hist_data->attrs->name);
ret = -EINVAL;
goto out;
}
@@ -5058,13 +5183,16 @@ static int hist_register_trigger(char *glob, struct event_trigger_ops *ops,
test->paused = false;
else if (hist_data->attrs->clear)
hist_clear(test);
- else
+ else {
+ hist_err("Hist trigger already exists", NULL);
ret = -EEXIST;
+ }
goto out;
}
}
new:
if (hist_data->attrs->cont || hist_data->attrs->clear) {
+ hist_err("Can't clear or continue a nonexistent hist trigger", NULL);
ret = -ENOENT;
goto out;
}
@@ -5251,6 +5379,11 @@ static int event_hist_trigger_func(struct event_command *cmd_ops,
char *trigger, *p;
int ret = 0;
+ if (glob && strlen(glob)) {
+ last_cmd_set(param);
+ hist_err_clear();
+ }
+
if (!param)
return -EINVAL;
@@ -5389,6 +5522,9 @@ static int event_hist_trigger_func(struct event_command *cmd_ops,
/* Just return zero, not the number of registered triggers */
ret = 0;
out:
+ if (ret == 0)
+ hist_err_clear();
+
return ret;
out_unreg:
cmd_ops->unreg(glob+1, trigger_ops, trigger_data, file);