tracing: Final updates for 7.1

Small cleanups fixes and updates for 7.1

git://git.kernel.org/pub/scm/linux/kernel/git/trace/linux-trace.git
trace/for-next

Head SHA1: 621a59d8fc678762abc12ad8ad6bf616496fa4d2

CaoRuichuang (1):
tracing: Report ipi_raise target CPUs as cpumask

David Carlier (1):
tracepoint: balance regfunc() on func_add() failure in tracepoint_add_func()

Pengpeng Hou (1):
tracing: Rebuild full_name on each hist_field_name() call

Tom Zanussi (2):
tracing: Fix fully-qualified variable reference printing in histograms selftests/ftrace: Add test case for fully-qualified variable references

----

 include/trace/events/ipi.h                         |  6 ++--
 kernel/trace/trace_events_hist.c                   | 25 ++++++++++------
 kernel/tracepoint.c                                |  2 ++
 .../inter-event/trigger-fully-qualified-var-ref.tc | 34 ++++++++++++++++++++++
 4 files changed, 55 insertions(+), 12 deletions(-)
 create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-fully-qualified-var-ref.tc

From: CaoRuichuang <[email protected]>

Bugzilla 217447 points out that ftrace bitmask fields still use the legacy dynamic-array format, which makes trace consumers treat them as unsigned long arrays instead of bitmaps.

This is visible in the ipi events today: ipi_send_cpumask already reports its CPU mask as '__data_loc cpumask_t', but ipi_raise still exposes target_cpus as '__data_loc unsigned long[]'.

Switch ipi_raise to __cpumask() and the matching helpers so its tracefs format matches the existing cpumask representation used by the other ipi event. The underlying storage size stays the same, but trace data consumers can now recognize the field as a cpumask directly.

---
 include/trace/events/ipi.h | 6 +++---
 1 file changed, 3 insertions(+), 3 deletions(-)

index 9912f0ded81d..fae4f8eac411 100644
@@ -68,16 +68,16 @@ TRACE_EVENT(ipi_raise,
 	TP_ARGS(mask, reason),
 
 	TP_STRUCT__entry(
-		__bitmask(target_cpus, nr_cpumask_bits)
+		__cpumask(target_cpus)
 		__field(const char *, reason)
 	),
 
 	TP_fast_assign(
-		__assign_bitmask(target_cpus, cpumask_bits(mask), nr_cpumask_bits);
+		__assign_cpumask(target_cpus, cpumask_bits(mask));
 		__entry->reason = reason;
 	),
 
-	TP_printk("target_mask=%s (%s)", __get_bitmask(target_cpus), __entry->reason)
+	TP_printk("target_mask=%s (%s)", __get_cpumask(target_cpus), __entry->reason)
 );
 
 DECLARE_EVENT_CLASS(ipi_handler,

2.51.0

From: Pengpeng Hou <[email protected]>

hist_field_name() uses a static MAX_FILTER_STR_VAL buffer for fully qualified variable-reference names, but it currently appends into that buffer with strcat() without rebuilding it first. As a result, repeated calls append a new "system.event.field" name onto the previous one, which can eventually run past the end of full_name.

Build the name with snprintf() on each call and return NULL if the fully qualified name does not fit in MAX_FILTER_STR_VAL.

---
 kernel/trace/trace_events_hist.c | 12 +++++++-----
 1 file changed, 7 insertions(+), 5 deletions(-)

index 67cb92310864..b2b675c7d663 100644
@@ -1361,12 +1361,14 @@ static const char *hist_field_name(struct hist_field *field,
 		 field->flags & HIST_FIELD_FL_VAR_REF) {
 		if (field->system) {
 			static char full_name[MAX_FILTER_STR_VAL];
+			int len;
+
+			len = snprintf(full_name, sizeof(full_name), "%s.%s.%s",
+				       field->system, field->event_name,
+				       field->name);
+			if (len >= sizeof(full_name))
+				return NULL;
 
-			strcat(full_name, field->system);
-			strcat(full_name, ".");
-			strcat(full_name, field->event_name);
-			strcat(full_name, ".");
-			strcat(full_name, field->name);
 			field_name = full_name;
 		} else
 			field_name = field->name;

2.51.0

From: David Carlier <[email protected]>

When a tracepoint goes through the 0 -> 1 transition, tracepoint_add_func() invokes the subsystem's ext->regfunc() before attempting to install the new probe via func_add(). If func_add() then fails (for example, when allocate_probes() cannot allocate a new probe array under memory pressure and returns -ENOMEM), the function returns the error without calling the matching ext->unregfunc(), leaving the side effects of regfunc() behind with no installed probe to justify them.

For syscall tracepoints this is particularly unpleasant: syscall_regfunc() bumps sys_tracepoint_refcount and sets SYSCALL_TRACEPOINT on every task. After a leaked failure, the refcount is stuck at a non-zero value with no consumer, and every task continues paying the syscall trace entry/exit overhead until reboot. Other subsystems providing regfunc()/unregfunc() pairs exhibit similarly scoped persistent state.

Mirror the existing 1 -> 0 cleanup and call ext->unregfunc() in the func_add() error path, gated on the same condition used there so the unwind is symmetric with the registration.

---
 kernel/tracepoint.c | 2 ++
 1 file changed, 2 insertions(+)

index 91905aa19294..dffef52a807b 100644
@@ -300,6 +300,8 @@ static int tracepoint_add_func(struct tracepoint *tp,
 			lockdep_is_held(&tracepoints_mutex));
 	old = func_add(&tp_funcs, func, prio);
 	if (IS_ERR(old)) {
+		if (tp->ext && tp->ext->unregfunc && !static_key_enabled(&tp->key))
+			tp->ext->unregfunc();
 		WARN_ON_ONCE(warn && PTR_ERR(old) != -ENOMEM);
 		return PTR_ERR(old);
 	}

2.51.0

From: Tom Zanussi <[email protected]>

The syntax for fully-qualified variable references in histograms is subsys.event.$var, which is parsed correctly, but not displayed correctly when printing a histogram spec. The current code puts the $ reference at the beginning of the fully-qualified variable name i.e. $subsys.event.var, which is incorrect.

Before:

trigger info: hist:keys=next_comm:vals=hitcount:wakeup_lat=common_timestamp.usecs-$sched.sched_wakeup.ts0: ...

After:

trigger info: hist:keys=next_comm:vals=hitcount:wakeup_lat=common_timestamp.usecs-sched.sched_wakeup.$ts0: ...

---
 kernel/trace/trace_events_hist.c | 15 ++++++++++-----
 1 file changed, 10 insertions(+), 5 deletions(-)

index b2b675c7d663..0dbbf6cca9bc 100644
@@ -1361,9 +1361,12 @@ static const char *hist_field_name(struct hist_field *field,
 		 field->flags & HIST_FIELD_FL_VAR_REF) {
 		if (field->system) {
 			static char full_name[MAX_FILTER_STR_VAL];
+			static char *fmt;
 			int len;
 
-			len = snprintf(full_name, sizeof(full_name), "%s.%s.%s",
+			fmt = field->flags & HIST_FIELD_FL_VAR_REF ? "%s.%s.$%s" : "%s.%s.%s";
+
+			len = snprintf(full_name, sizeof(full_name), fmt,
 				       field->system, field->event_name,
 				       field->name);
 			if (len >= sizeof(full_name))

@@ -1742,9 +1745,10 @@ static const char *get_hist_field_flags(struct hist_field *hist_field)
 
 static void expr_field_str(struct hist_field *field, char *expr)
 {
-	if (field->flags & HIST_FIELD_FL_VAR_REF)
-		strcat(expr, "$");
-	else if (field->flags & HIST_FIELD_FL_CONST) {
+	if (field->flags & HIST_FIELD_FL_VAR_REF) {
+		if (!field->system)
+			strcat(expr, "$");
+	} else if (field->flags & HIST_FIELD_FL_CONST) {
 		char str[HIST_CONST_DIGITS_MAX];
 
 		snprintf(str, HIST_CONST_DIGITS_MAX, "%llu", field->constant);

@@ -6156,7 +6160,8 @@ static void hist_field_print(struct seq_file *m, struct hist_field *hist_field)
 	else if (field_name) {
 		if (hist_field->flags & HIST_FIELD_FL_VAR_REF ||
 		    hist_field->flags & HIST_FIELD_FL_ALIAS)
-			seq_putc(m, '$');
+			if (!hist_field->system)
+				seq_putc(m, '$');
 		seq_printf(m, "%s", field_name);
 	} else if (hist_field->flags & HIST_FIELD_FL_TIMESTAMP)
 		seq_puts(m, "common_timestamp");

2.51.0

From: Tom Zanussi <[email protected]>

This test adds a variable (ts0) to two events (sched_waking and sched_wakeup) and uses a fully-qualified variable reference to expicitly choose a particular one (sched_wakeup.$ts0) when calculating the wakeup latency.

---
 .../trigger-fully-qualified-var-ref.tc        | 34 +++++++++++++++++++
 1 file changed, 34 insertions(+)
 create mode 100644 tools/testing/selftests/ftrace/test.d/trigger/inter-event/trigger-fully-qualified-var-ref.tc

new file mode 100644
index 000000000000..8d12cdd06f1d
@@ -0,0 +1,34 @@
+#!/bin/sh
+# SPDX-License-Identifier: GPL-2.0
+# description: event trigger - test fully-qualified variable reference support
+# requires: set_event synthetic_events events/sched/sched_process_fork/hist ping:program
+
+fail() { #msg
+    echo $1
+    exit_fail
+}
+
+echo "Test fully-qualified variable reference support"
+
+echo 'wakeup_latency u64 lat; pid_t pid; int prio; char comm[16]' > synthetic_events
+echo 'hist:keys=comm:ts0=common_timestamp.usecs if comm=="ping"' > events/sched/sched_waking/trigger
+echo 'hist:keys=comm:ts0=common_timestamp.usecs if comm=="ping"' > events/sched/sched_wakeup/trigger
+echo 'hist:keys=next_comm:wakeup_lat=common_timestamp.usecs-sched.sched_wakeup.$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,sched.sched_waking.prio,next_comm) if next_comm=="ping"' > events/sched/sched_switch/trigger
+echo 'hist:keys=pid,prio,comm:vals=lat:sort=pid,prio' > events/synthetic/wakeup_latency/trigger
+
+ping $LOCALHOST -c 3
+if ! grep -q "ping" events/synthetic/wakeup_latency/hist; then
+    fail "Failed to create inter-event histogram"
+fi
+
+if ! grep -q "synthetic_prio=prio" events/sched/sched_waking/hist; then
+    fail "Failed to create histogram with fully-qualified variable reference"
+fi
+
+echo '!hist:keys=next_comm:wakeup_lat=common_timestamp.usecs-sched.sched_wakeup.$ts0:onmatch(sched.sched_waking).wakeup_latency($wakeup_lat,next_pid,sched.sched_waking.prio,next_comm) if next_comm=="ping"' >> events/sched/sched_switch/trigger
+
+if grep -q "synthetic_prio=prio" events/sched/sched_waking/hist; then
+    fail "Failed to remove histogram with fully-qualified variable reference"
+fi
+
+exit 0

2.51.0