Re: [RFC][PATCH 11/21] tracing: Add variable support to hist triggers

From: Tom Zanussi
Date: Tue Feb 14 2017 - 10:25:42 EST

Next message: Lee Jones: "Re: [PATCH v2 3/4] rtc: cros-ec: add cros-ec-rtc driver."
Previous message: Zhi Li: "Re: [PATCH 1/2] Fix mmdc_pmu_write_accesses event definition"
In reply to: Namhyung Kim: "Re: [RFC][PATCH 11/21] tracing: Add variable support to hist triggers"
Next in thread: Tom Zanussi: "[RFC][PATCH 21/21] tracing: Add inter-event hist trigger Documentation"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Hi Namhyung,

On Mon, 2017-02-13 at 15:03 +0900, Namhyung Kim wrote:
> On Wed, Feb 08, 2017 at 11:25:07AM -0600, Tom Zanussi wrote:
> > Add support for saving the value of a current event's event field by
> > assigning it to a variable that can be read by a subsequent event.
> >
> > The basic syntax for saving a variable is to simply prefix a unique
> > variable name not corresponding to any keyword along with an '=' sign
> > to any event field.
> >
> > Both keys and values can be saved and retrieved in this way:
> >
> > # echo 'hist:keys=next_pid:vals=ts0=common_timestamp ...
> > # echo 'hist:key=timer_pid=common_pid ...'
> >
> > If a variable isn't a key variable or prefixed with 'vals=', the
> > associated event field will be saved in a variable but won't be summed
> > as a value:
> >
> > # echo 'hist:keys=next_pid:ts1=common_timestamp:...
> >
> > Multiple variables can be assigned at the same time:
> >
> > # echo 'hist:keys=pid:vals=ts0=common_timestamp,b=field1,field2 ...
> >
> > Variables set as above can be used by being referenced from another
> > event, as described in a subsequent patch.
> >
> > Signed-off-by: Tom Zanussi <tom.zanussi@xxxxxxxxxxxxxxx>
> > ---
> > kernel/trace/trace_events_hist.c | 160 ++++++++++++++++++++++++++++++++-------
> > 1 file changed, 131 insertions(+), 29 deletions(-)
> >
> > diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c
> > index 8d7f7dd..e707577 100644
> > --- a/kernel/trace/trace_events_hist.c
> > +++ b/kernel/trace/trace_events_hist.c
> > @@ -29,6 +29,7 @@ typedef u64 (*hist_field_fn_t) (struct hist_field *field, void *event,
> > struct ring_buffer_event *rbe);
> >
> > #define HIST_FIELD_OPERANDS_MAX 2
> > +#define HIST_ASSIGNMENT_MAX 4
> >
> > struct hist_field {
> > struct ftrace_event_field *field;
> > @@ -36,8 +37,10 @@ struct hist_field {
> > hist_field_fn_t fn;
> > unsigned int size;
> > unsigned int offset;
> > - unsigned int is_signed;
> > + unsigned int is_signed;
>
> It seems like an unnecessary change.
>

Yes, it is.

> > struct hist_field *operands[HIST_FIELD_OPERANDS_MAX];
> > + u64 var_val;
> > + char *var_name;
> > };
> >
> > static u64 hist_field_none(struct hist_field *field, void *event,
> > @@ -140,12 +143,16 @@ enum hist_field_flags {
> > HIST_FIELD_FL_SYSCALL = 128,
> > HIST_FIELD_FL_STACKTRACE = 256,
> > HIST_FIELD_FL_LOG2 = 512,
> > - HIST_FIELD_FL_TIMESTAMP = 1024,
> > + HIST_FIELD_FL_VAR = 1024,
> > + HIST_FIELD_FL_VAR_ONLY = 2048,
> > + HIST_FIELD_FL_TIMESTAMP = 4096,
>
> Why did you move the timestamp?
>

No good reason, just happened to be how some refactoring factored out.

> > };
> >
> > struct hist_trigger_attrs {
> > char *keys_str;
> > char *vals_str;
> > + char *assignment_str[HIST_ASSIGNMENT_MAX];
> > + unsigned int n_assignments;
> > char *sort_key_str;
> > char *name;
> > bool pause;
> > @@ -241,9 +248,14 @@ static int parse_map_size(char *str)
> >
> > static void destroy_hist_trigger_attrs(struct hist_trigger_attrs *attrs)
> > {
> > + unsigned int i;
> > +
> > if (!attrs)
> > return;
> >
> > + for (i = 0; i < attrs->n_assignments; i++)
> > + kfree(attrs->assignment_str[i]);
> > +
> > kfree(attrs->name);
> > kfree(attrs->sort_key_str);
> > kfree(attrs->keys_str);
> > @@ -258,9 +270,9 @@ static int parse_assignment(char *str, struct hist_trigger_attrs *attrs)
> > if ((strncmp(str, "key=", strlen("key=")) == 0) ||
> > (strncmp(str, "keys=", strlen("keys=")) == 0))
> > attrs->keys_str = kstrdup(str, GFP_KERNEL);
> > - else if ((strncmp(str, "val=", strlen("val=")) == 0) ||
> > - (strncmp(str, "vals=", strlen("vals=")) == 0) ||
> > - (strncmp(str, "values=", strlen("values=")) == 0))
> > + else if (((strncmp(str, "val=", strlen("val=")) == 0) ||
> > + (strncmp(str, "vals=", strlen("vals=")) == 0) ||
> > + (strncmp(str, "values=", strlen("values=")) == 0)))
>
> Looks unnecessary too.
>

Yep.

> > attrs->vals_str = kstrdup(str, GFP_KERNEL);
> > else if (strncmp(str, "sort=", strlen("sort=")) == 0)
> > attrs->sort_key_str = kstrdup(str, GFP_KERNEL);
> > @@ -274,8 +286,22 @@ static int parse_assignment(char *str, struct hist_trigger_attrs *attrs)
> > goto out;
> > }
> > attrs->map_bits = map_bits;
> > - } else
> > - ret = -EINVAL;
> > + } else {
> > + char *assignment;
> > +
> > + if (attrs->n_assignments == HIST_ASSIGNMENT_MAX) {
> > + ret = -EINVAL;
> > + goto out;
> > + }
> > +
> > + assignment = kstrdup(str, GFP_KERNEL);
> > + if (!assignment) {
> > + ret = -ENOMEM;
> > + goto out;
> > + }
> > +
> > + attrs->assignment_str[attrs->n_assignments++] = assignment;
> > + }
> > out:
> > return ret;
> > }
>
> [SNIP]
> > @@ -839,8 +913,7 @@ static int create_tracing_map_fields(struct hist_trigger_data *hist_data)
> > idx = tracing_map_add_key_field(map,
> > hist_field->offset,
> > cmp_fn);
> > -
> > - } else
> > + } else if (!(hist_field->flags & HIST_FIELD_FL_VAR))
> > idx = tracing_map_add_sum_field(map);
> >
> > if (idx < 0)
> > @@ -931,6 +1004,11 @@ static void hist_trigger_elt_update(struct hist_trigger_data *hist_data,
> > for_each_hist_val_field(i, hist_data) {
> > hist_field = hist_data->fields[i];
> > hist_val = hist_field->fn(hist_field, rec, rbe);
> > + if (hist_field->flags & HIST_FIELD_FL_VAR) {
> > + hist_field->var_val = hist_val;
> > + if (hist_field->flags & HIST_FIELD_FL_VAR_ONLY)
> > + continue;
> > + }
> > tracing_map_update_sum(elt, i, hist_val);
>
> Hmm.. you didn't add a field for HIST_FIELD_FL_VAR but it attempts to
> update it, no?
>

There's a little confusion regarding VAR_ONLY, and the whole thing needs
to be cleaned up wrt that. Originally, for simplicity I implemented it
such that you could only either have variables or values, not both.
Later when I added the assignment code, I changed that and some of the
old related code remained. Anyway, suffice it to say that this whole
area will be cleaned up...

>
> > }
> > }
> > @@ -996,17 +1074,21 @@ static void event_hist_trigger(struct event_trigger_data *data, void *rec,
> > } else
> > key = (void *)&field_contents;
> > }
> > -
> > if (use_compound_key)
> > add_to_key(compound_key, key, key_field, rec);
> > +
> > + if (key_field->flags & HIST_FIELD_FL_VAR)
> > + key_field->var_val = (u64)key;
> > }
> >
> > if (use_compound_key)
> > key = compound_key;
> >
> > elt = tracing_map_insert(hist_data->map, key);
> > - if (elt)
> > - hist_trigger_elt_update(hist_data, elt, rec, rbe);
> > + if (!elt)
> > + return;
> > +
> > + hist_trigger_elt_update(hist_data, elt, rec, rbe);
> > }
> >
> > static void hist_trigger_stacktrace_print(struct seq_file *m,
> > @@ -1228,7 +1310,12 @@ static void hist_field_print(struct seq_file *m, struct hist_field *hist_field)
> > {
> > const char *field_name = hist_field_name(hist_field);
> >
> > - seq_printf(m, "%s", field_name);
> > + if (hist_field->var_name)
> > + seq_printf(m, "%s=", hist_field->var_name);
> > +
> > + if (field_name)
> > + seq_printf(m, "%s", field_name);
> > +
> > if (hist_field->flags) {
> > const char *flags_str = get_hist_field_flags(hist_field);
> >
> > @@ -1237,6 +1324,16 @@ static void hist_field_print(struct seq_file *m, struct hist_field *hist_field)
> > }
> > }
> >
> > +static bool var_only(struct hist_trigger_data *hist_data)
> > +{
> > + unsigned int i;
> > +
> > + for_each_hist_val_field(i, hist_data)
> > + if (hist_data->fields[i]->flags & HIST_FIELD_FL_VAR_ONLY)
> > + return true;
> > + return false;
> > +}
>
> This means if there's a var-only field, the whole hist will be treated
> as var-only, right? What if it has normal fields and var-only fields
> at the same time? Didn't it have "hitcount"? Please see below..
>

As mentioned, this is a holdover that no longer makes sense, will clean
the whole thing up in the next version.

> > +
> > static int event_hist_trigger_print(struct seq_file *m,
> > struct event_trigger_ops *ops,
> > struct event_trigger_data *data)
> > @@ -1266,15 +1363,19 @@ static int event_hist_trigger_print(struct seq_file *m,
> > hist_field_print(m, key_field);
> > }
> >
> > - seq_puts(m, ":vals=");
> > + if (!var_only(hist_data))
> > + seq_puts(m, ":vals=");
> > + else
> > + seq_puts(m, ":");
> >
> > for_each_hist_val_field(i, hist_data) {
> > - if (i == HITCOUNT_IDX)
> > + if (i == HITCOUNT_IDX && !var_only(hist_data))
> > seq_puts(m, "hitcount");
>
> Looks like var-only hist cannot have hitcount, right?
>
> > else if (hist_data->fields[i]->flags & HIST_FIELD_FL_TIMESTAMP)
> > seq_puts(m, "common_timestamp");
> > else {
> > - seq_puts(m, ",");
> > + if (!var_only(hist_data))
> > + seq_puts(m, ",");
>
> If a var-only hist hist can have multiple fields, it should print ","
> as well IMHO. Also it seems "common_timestamp" also needs it.
>

Yep, some missing commas in the output, thanks for pointing them out.

Thanks,

Tom

Next message: Lee Jones: "Re: [PATCH v2 3/4] rtc: cros-ec: add cros-ec-rtc driver."
Previous message: Zhi Li: "Re: [PATCH 1/2] Fix mmdc_pmu_write_accesses event definition"
In reply to: Namhyung Kim: "Re: [RFC][PATCH 11/21] tracing: Add variable support to hist triggers"
Next in thread: Tom Zanussi: "[RFC][PATCH 21/21] tracing: Add inter-event hist trigger Documentation"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]