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

Subsystems: the rest, tracing

COLD26d

3 messages, 2 authors, 26d ago · open the first message on its own page

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

From: Donggeun Yoo <hidden>
Date: 2026-09-13 20:32:03

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 <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

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

From: sashiko-bot@kernel.org
Date: 2026-09-13 20:45:54

Thank you for your contribution! Sashiko AI review found 1 potential issue(s) to consider:

Pre-existing issues:
- [High] Memory leak of VAR_REF hist_field objects when a variable is referenced 3 or more times.
--

commit de921069f4d7b51b3167c82eacf22c1d74694b83
Author: Donggeun Yoo [off-list ref]

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

This commit prevents a spurious error log during speculative field variable
lookups in trace events. It silences hist_err() while initially attempting
to create a field variable on the target event, avoiding persistent errors
for fallback matches.

Closes: https://lore.kernel.org/linux-trace-kernel/20260913122523.30f487d9@robin/
quoted hunk
diff --git a/kernel/trace/trace_events_hist.c b/kernel/trace/trace_events_hist.c
index 963e0d6b61fdf..4676dc6d91465 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,
[ ... ]

[Severity: High]
This isn't a bug introduced by this patch, but while reviewing
trace_events_hist.c, I noticed a potential memory leak of var_ref
hist_field objects when a variable is referenced 3 or more times.

Looking at how variables are referenced:

kernel/trace/trace_events_hist.c:create_var_ref() {
    ...
	for (i = 0; i < hist_data->n_var_refs; i++) {
		ref_field = hist_data->var_refs[i];
		if (ref_field->var.idx == var_field->var.idx &&
		    ref_field->var.hist_data == var_field->hist_data) {
			get_hist_field(ref_field);
			return ref_field;
		}
	}
    ...
}

This increments the reference count for each additional use of the variable.

During trigger destruction, the teardown logic iterates over the unique
var_ref objects in the hist_data->var_refs array and calls
__destroy_hist_field() exactly once for each. However, looking at the
refcount check:

kernel/trace/trace_events_hist.c:__destroy_hist_field() {
	if (--hist_field->ref > 1)
		return;

	kfree(hist_field->var.name);
    ...
}

If a variable is referenced 3 or more times, its ref count becomes >= 3.
Since the single teardown call only decrements the ref count by 1 (leaving
it >= 2), the condition > 1 evaluates to true, and the function returns
early without freeing the structure. 

Does this permanently leak the var_ref object and its dynamically allocated
strings, since __destroy_hist_field() is never called again for that object?

Could this allow a privileged user to reliably exhaust kernel memory by
creating and destroying a tracefs histogram trigger that references the same
variable 3 or more times (e.g., using a variable multiple times in a
synthetic event or an arithmetic expression)?

-- 
Sashiko AI review · https://sashiko.dev/#/patchset/20260913203156.941433-1-donggeunyoo.kernel@gmail.com?part=1

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

From: Donggeun Yoo <hidden>
Date: 2026-09-14 03:45:24

On Sun, 13 Sep 2026 20:45:54 +0000, Sashiko AI review wrote:
This isn't a bug introduced by this patch, but while reviewing
trace_events_hist.c, I noticed a potential memory leak of var_ref
hist_field objects when a variable is referenced 3 or more times.
Already fixed in mainline, by 4bddcb346a6c ("tracing: Free histogram var
refs regardless of how often they are referenced"). It removed both halves
of this: the get_hist_field(ref_field) in create_var_ref(), and the
refcount test in __destroy_hist_field() that the quoted code relies on.
At 22098763a10d, __destroy_hist_field() has no refcount left at all.

That commit merged the same day as this review, so the baseline predates
it.
Keyboard shortcuts
hback out one level
jnext message in thread
kprevious message in thread
ldrill in
Escclose help / fold thread tree
?toggle this help