[PATCH] tracing: Don't log an error for the speculative field variable lookup
From: Donggeun Yoo <hidden>
Date: 2026-09-13 20:32:03
Also in:
lkml
Subsystem:
the rest, tracing · Maintainers:
Linus Torvalds, Steven Rostedt, Masami Hiramatsu
A hist trigger that installs and works leaves two errors behind:
# echo 'hist:keys=pid:ts0=common_timestamp.usecs' > \
events/sched/sched_waking/trigger
# echo 'my_synth u64 lat; int prio' > synthetic_events
# echo 'hist:keys=next_pid:wakeup_lat=common_timestamp.usecs-$ts0:\
onmatch(sched.sched_waking).my_synth($wakeup_lat,prio)' > \
events/sched/sched_switch/trigger
# cat error_log
hist:sched:sched_switch: error: Couldn't find field
hist:sched:sched_switch: error: Couldn't parse field variable
prio is a sched_waking field, so the trigger installs and my_synth
fires.
trace_action_create_field_var() tries the target event first -- "First
try to create a field var on the target event", as its own comment says
-- and falls back to the onmatch() event, which is how a parameter taken
from the matched event resolves. The failed first attempt logs through
hist_err() and nothing clears it.
Silence hist_err() while that attempt runs. A name on neither event
still reports, from the fallback, and the write still fails.
Fixes: c282a386a397 ("tracing: Add 'onmatch' hist trigger action support")
Reported-by: Steven Rostedt <rostedt@goodmis.org>
Closes: https://lore.kernel.org/linux-trace-kernel/20260913122523.30f487d9@robin/ (local)
Signed-off-by: Donggeun Yoo <redacted>
Assisted-by: Claude:claude-fable-5
---
x86_64 under QEMU, CONFIG_KASAN=y, 4 CPUs, base 2f0c1cf72f46. A histogram
on sched_waking keyed on pid, an onmatch() target on sched_switch keyed on
next_pid, my_synth($wakeup_lat,ARG).
ARG where it lives unpatched patched
next_prio target event rc=0, 0 errors rc=0, 0 errors
prio match event only rc=0, 2 errors rc=0, 0 errors
nosuchfld neither rc=1, 4 errors rc=1, 2 errors
kernel/trace/trace_events_hist.c | 7 ++++++-
1 file changed, 6 insertions(+), 1 deletion(-)
diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c
index 963e0d6b61fd..4676dc6d9146 100644
--- a/kernel/trace/trace_events_hist.c
+++ b/kernel/trace/trace_events_hist.c@@ -806,9 +806,12 @@ static void last_cmd_set(struct trace_event_file *file, char *str) snprintf(last_cmd_loc, MAX_FILTER_STR_VAL, HIST_PREFIX "%s:%s", system, name); } +/* Set while a field lookup may fail silently; the parse path is serialized. */ +static bool hist_err_silent; + static void hist_err(struct trace_array *tr, u8 err_type, u16 err_pos) { - if (!last_cmd) + if (!last_cmd || hist_err_silent) return; tracing_log_err(tr, last_cmd_loc, last_cmd, err_text,
@@ -4003,7 +4006,9 @@ trace_action_create_field_var(struct hist_trigger_data *hist_data, * unqualified fields on the target event, or if qualified, * target fields that have qualified names matching the target. */ + hist_err_silent = true; field_var = create_target_field_var(hist_data, system, event, var); + hist_err_silent = false; if (field_var && !IS_ERR(field_var)) { save_field_var(hist_data, field_var);
--
2.53.0