Skip to content

Commit 8bcebc7

Browse files
committed
tracing: Fix histogram code when expression has same var as value
While working on a tool to convert SQL syntex into the histogram language of the kernel, I discovered the following bug: # echo 'first u64 start_time u64 end_time pid_t pid u64 delta' >> synthetic_events # echo 'hist:keys=pid:start=common_timestamp' > events/sched/sched_waking/trigger # echo 'hist:keys=next_pid:delta=common_timestamp-$start,start2=$start:onmatch(sched.sched_waking).trace(first,$start2,common_timestamp,next_pid,$delta)' > events/sched/sched_switch/trigger Would not display any histograms in the sched_switch histogram side. But if I were to swap the location of "delta=common_timestamp-$start" with "start2=$start" Such that the last line had: # echo 'hist:keys=next_pid:start2=$start,delta=common_timestamp-$start:onmatch(sched.sched_waking).trace(first,$start2,common_timestamp,next_pid,$delta)' > events/sched/sched_switch/trigger The histogram works as expected. What I found out is that the expressions clear out the value once it is resolved. As the variables are resolved in the order listed, when processing: delta=common_timestamp-$start The $start is cleared. When it gets to "start2=$start", it errors out with "unresolved symbol" (which is silent as this happens at the location of the trace), and the histogram is dropped. When processing the histogram for variable references, instead of adding a new reference for a variable used twice, use the same reference. That way, not only is it more efficient, but the order will no longer matter in processing of the variables. From Tom Zanussi: "Just to clarify some more about what the problem was is that without your patch, we would have two separate references to the same variable, and during resolve_var_refs(), they'd both want to be resolved separately, so in this case, since the first reference to start wasn't part of an expression, it wouldn't get the read-once flag set, so would be read normally, and then the second reference would do the read-once read and also be read but using read-once. So everything worked and you didn't see a problem: from: start2=$start,delta=common_timestamp-$start In the second case, when you switched them around, the first reference would be resolved by doing the read-once, and following that the second reference would try to resolve and see that the variable had already been read, so failed as unset, which caused it to short-circuit out and not do the trigger action to generate the synthetic event: to: delta=common_timestamp-$start,start2=$start With your patch, we only have the single resolution which happens correctly the one time it's resolved, so this can't happen." Link: https://lore.kernel.org/r/[email protected] Cc: [email protected] Fixes: 067fe03 ("tracing: Add variable reference handling to hist triggers") Reviewed-by: Tom Zanuss <[email protected]> Tested-by: Tom Zanussi <[email protected]> Signed-off-by: Steven Rostedt (VMware) <[email protected]>
1 parent aeed8aa commit 8bcebc7

File tree

1 file changed

+22
-0
lines changed

1 file changed

+22
-0
lines changed

kernel/trace/trace_events_hist.c

Lines changed: 22 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -116,6 +116,7 @@ struct hist_field {
116116
struct ftrace_event_field *field;
117117
unsigned long flags;
118118
hist_field_fn_t fn;
119+
unsigned int ref;
119120
unsigned int size;
120121
unsigned int offset;
121122
unsigned int is_signed;
@@ -2427,8 +2428,16 @@ static int contains_operator(char *str)
24272428
return field_op;
24282429
}
24292430

2431+
static void get_hist_field(struct hist_field *hist_field)
2432+
{
2433+
hist_field->ref++;
2434+
}
2435+
24302436
static void __destroy_hist_field(struct hist_field *hist_field)
24312437
{
2438+
if (--hist_field->ref > 1)
2439+
return;
2440+
24322441
kfree(hist_field->var.name);
24332442
kfree(hist_field->name);
24342443
kfree(hist_field->type);
@@ -2470,6 +2479,8 @@ static struct hist_field *create_hist_field(struct hist_trigger_data *hist_data,
24702479
if (!hist_field)
24712480
return NULL;
24722481

2482+
hist_field->ref = 1;
2483+
24732484
hist_field->hist_data = hist_data;
24742485

24752486
if (flags & HIST_FIELD_FL_EXPR || flags & HIST_FIELD_FL_ALIAS)
@@ -2665,6 +2676,17 @@ static struct hist_field *create_var_ref(struct hist_trigger_data *hist_data,
26652676
{
26662677
unsigned long flags = HIST_FIELD_FL_VAR_REF;
26672678
struct hist_field *ref_field;
2679+
int i;
2680+
2681+
/* Check if the variable already exists */
2682+
for (i = 0; i < hist_data->n_var_refs; i++) {
2683+
ref_field = hist_data->var_refs[i];
2684+
if (ref_field->var.idx == var_field->var.idx &&
2685+
ref_field->var.hist_data == var_field->hist_data) {
2686+
get_hist_field(ref_field);
2687+
return ref_field;
2688+
}
2689+
}
26682690

26692691
ref_field = create_hist_field(var_field->hist_data, NULL, flags, NULL);
26702692
if (ref_field) {

0 commit comments

Comments
 (0)