[PATCH] tracing: Don't log an error for the speculative field variable lookup

[Donggeun Yoo <donggeunyoo.kernel@gmail.com>]

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/
Signed-off-by: Donggeun Yoo <donggeunyoo.kernel@gmail.com>
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