tracing/eprobe: Update cond flag before enabling trigger

That happens because enable_eprobe() will eventually trigger the kmem/mm_page_alloc trace event:

- enable_eprobe [trace_eprobe.c]
- trace_event_trigger_enable_disable [trace_events_trigger.c]
- trace_event_enable_disable [trace_events.c]
- __ftrace_event_enable_disable [trace_events.c]
- trace_buffered_event_enable [trace.c]
- alloc_pages_node [gfp.h]
...
- __alloc_pages [page_alloc.c]
- trace_mm_page_alloc // eprobe event file without TRIGGER_COND bit set

By the time kmem/mm_page_alloc trace event is hit, the eprobe event file does not have the TRIGGER_COND flag set yet, which causes the eprobe's trigger to be invoked (through the trace_trigger_soft_disabled() path) without a trace record, causing a NULL pointer dereference when fetching the event fields.

Fix this by setting the cond flag beforehand when enabling the eprobe's trigger.

Fixes 7491e2c44278 ("tracing: Add a probe that attaches to trace events")

Signed-off-by Rafael Mendonca <[email protected]>

---

Quoted 19 lines · On Wed, 16 Nov 2022 16:25:51 -0300 Rafael Mendonca <[email protected]>…

That happens because enable_eprobe() will eventually trigger the kmem/mm_page_alloc trace event:

- enable_eprobe [trace_eprobe.c]
- trace_event_trigger_enable_disable [trace_events_trigger.c]
- trace_event_enable_disable [trace_events.c]
- __ftrace_event_enable_disable [trace_events.c]
- trace_buffered_event_enable [trace.c]
- alloc_pages_node [gfp.h]
...
- __alloc_pages [page_alloc.c]
- trace_mm_page_alloc // eprobe event file without TRIGGER_COND bit set

By the time kmem/mm_page_alloc trace event is hit, the eprobe event file does not have the TRIGGER_COND flag set yet, which causes the eprobe's trigger to be invoked (through the trace_trigger_soft_disabled() path) without a trace record, causing a NULL pointer dereference when fetching the event fields.

Quoted 6 lines

Fix this by setting the cond flag beforehand when enabling the eprobe's trigger.

Fixes 7491e2c44278 ("tracing: Add a probe that attaches to trace events")

Signed-off-by Rafael Mendonca <[email protected]>

---

Thanks for the report, but I'm worried that this isn't enough because of how memory ordering can happen on different architectures. That is, just because you switch the order of updates, doesn't mean that the architecture will honor it.

I don't want to add memory barriers in the fast path, but instead we can simply check if rec is NULL in the handler.

So basically:

static void eprobe_trigger_func(struct event_trigger_data *data,
struct trace_buffer *buffer, void *rec, struct ring_buffer_event *rbe)

{
	struct eprobe_data *edata = data->private_data;

	if (!rec)
		return;

	__eprobe_trace_func(edata, rec);
}

And this should be documented.

Quoted 49 lines · On Thu, 17 Nov 2022 21:17:26 -0500 Steven Rostedt <[email protected]> wrote:

Quoted 19 lines · On Wed, 16 Nov 2022 16:25:51 -0300 Rafael Mendonca <[email protected]>…

That happens because enable_eprobe() will eventually trigger the kmem/mm_page_alloc trace event:

- enable_eprobe [trace_eprobe.c]
- trace_event_trigger_enable_disable [trace_events_trigger.c]
- trace_event_enable_disable [trace_events.c]
- __ftrace_event_enable_disable [trace_events.c]
- trace_buffered_event_enable [trace.c]
- alloc_pages_node [gfp.h]
...
- __alloc_pages [page_alloc.c]
- trace_mm_page_alloc // eprobe event file without TRIGGER_COND bit set

By the time kmem/mm_page_alloc trace event is hit, the eprobe event file does not have the TRIGGER_COND flag set yet, which causes the eprobe's trigger to be invoked (through the trace_trigger_soft_disabled() path) without a trace record, causing a NULL pointer dereference when fetching the event fields.

Quoted 6 lines

Fix this by setting the cond flag beforehand when enabling the eprobe's trigger.

Fixes 7491e2c44278 ("tracing: Add a probe that attaches to trace events")

Signed-off-by Rafael Mendonca <[email protected]>

---

Thanks for the report, but I'm worried that this isn't enough because of how memory ordering can happen on different architectures. That is, just because you switch the order of updates, doesn't mean that the architecture will honor it.

I don't want to add memory barriers in the fast path, but instead we can simply check if rec is NULL in the handler.

So basically:

static void eprobe_trigger_func(struct event_trigger_data *data,
struct trace_buffer *buffer, void *rec, struct ring_buffer_event *rbe)

{
	struct eprobe_data *edata = data->private_data;

	if (!rec)
		return;

Quoted 5 lines

	__eprobe_trace_func(edata, rec);
}

And this should be documented.

In fact, does this fix it for you?

I'm going to take this patch and reference you as a reported-by, as I have a lot of urgent code that needs to got upstream, and I need to start testing it.

Thanks!

-- Steve

kernel/trace/trace_eprobe.c +3 -0

index 5dd0617e5df6..6b31b74954d9 100644
@@ -563,6 +563,9 @@ static void eprobe_trigger_func(struct event_trigger_data *data,
 {
 	struct eprobe_data *edata = data->private_data;
 
+	if (!rec)
+		return;
+
 	__eprobe_trace_func(edata, rec);
 }
 

Quoted 55 lines · Steven Rostedt

Quoted 52 lines · On Thu, 17 Nov 2022 21:17:26 -0500 Steven Rostedt <[email protected]> wrote:

Quoted 19 lines · On Wed, 16 Nov 2022 16:25:51 -0300 Rafael Mendonca <[email protected]>…

That happens because enable_eprobe() will eventually trigger the kmem/mm_page_alloc trace event:

- enable_eprobe [trace_eprobe.c]
- trace_event_trigger_enable_disable [trace_events_trigger.c]
- trace_event_enable_disable [trace_events.c]
- __ftrace_event_enable_disable [trace_events.c]
- trace_buffered_event_enable [trace.c]
- alloc_pages_node [gfp.h]
...
- __alloc_pages [page_alloc.c]
- trace_mm_page_alloc // eprobe event file without TRIGGER_COND bit set

By the time kmem/mm_page_alloc trace event is hit, the eprobe event file does not have the TRIGGER_COND flag set yet, which causes the eprobe's trigger to be invoked (through the trace_trigger_soft_disabled() path) without a trace record, causing a NULL pointer dereference when fetching the event fields.

Quoted 6 lines

Fix this by setting the cond flag beforehand when enabling the eprobe's trigger.

Fixes 7491e2c44278 ("tracing: Add a probe that attaches to trace events")

Signed-off-by Rafael Mendonca <[email protected]>

---

Thanks for the report, but I'm worried that this isn't enough because of how memory ordering can happen on different architectures. That is, just because you switch the order of updates, doesn't mean that the architecture will honor it.

I don't want to add memory barriers in the fast path, but instead we can simply check if rec is NULL in the handler.

So basically:

static void eprobe_trigger_func(struct event_trigger_data *data,
struct trace_buffer *buffer, void *rec, struct ring_buffer_event *rbe)

{
	struct eprobe_data *edata = data->private_data;

	if (!rec)
		return;

	__eprobe_trace_func(edata, rec);
}

Quoted 4 lines

Quoted 2 lines

And this should be documented.

In fact, does this fix it for you?

It does. I found this while enabling eprobe for all events in my setup. Doing the same test wih the proposed patch it did not trigger any issue. Thanks.

Quoted 25 lines

I'm going to take this patch and reference you as a reported-by, as I have a lot of urgent code that needs to got upstream, and I need to start testing it.

Thanks!

-- Steve

kernel/trace/trace_eprobe.c +3 -0

index 5dd0617e5df6..6b31b74954d9 100644
@@ -563,6 +563,9 @@ static void eprobe_trigger_func(struct event_trigger_data *data,
 {
 	struct eprobe_data *edata = data->private_data;
 
+	if (!rec)
+		return;
+
 	__eprobe_trace_func(edata, rec);
 }
 

It did not trigger the NULL pointer issue to be more specific. When creating event probe for all events I was unable to create any event for the xhci-hcd system:

root@localhost:/sys/kernel/tracing# echo 'e xhci-hcd/xhci_add_endpoint' > dynamic_events 
-bash: echo: write error: Invalid argument

Debugging the issue it seems that the problem is in the is_good_name() check, which returns false for "xhci-hcd". Should we sanitize it by

converting '-' into '_'?

Quoted 4 lines · On Fri, 18 Nov 2022 10:34:40 -0300 Rafael Mendonca <[email protected]>…

It did not trigger the NULL pointer issue to be more specific. When creating event probe for all events I was unable to create any event for the xhci-hcd system:

Quoted 5 lines

root@localhost:/sys/kernel/tracing# echo 'e xhci-hcd/xhci_add_endpoint' > dynamic_events 
-bash: echo: write error: Invalid argument

Debugging the issue it seems that the problem is in the is_good_name() check, which returns false for "xhci-hcd". Should we sanitize it by

Ouch. I didn't realize that.

Quoted 2 lines

converting '-' into '_'?

Actually, it's just the system name that's an issue. I tested this patch and it appears to work.

-- Steve

kernel/trace/trace.h +16 -3

index 54ee5711c729..a16fb4c9642e 100644
@@ -1955,17 +1955,30 @@ static __always_inline void trace_iterator_reset(struct trace_iterator *iter)
 }
 
 /* Check the name is good for event/group/fields */
-static inline bool is_good_name(const char *name)
+static inline bool __is_good_name(const char *name, bool hash_ok)
 {
-	if (!isalpha(*name) && *name != '_')
+	if (!isalpha(*name) && *name != '_' && (!hash_ok || *name != '-'))
 		return false;
 	while (*++name != '\0') {
-		if (!isalpha(*name) && !isdigit(*name) && *name != '_')
+		if (!isalpha(*name) && !isdigit(*name) && *name != '_' &&
+		    (!hash_ok || *name != '-'))
 			return false;
 	}
 	return true;
 }
 
+/* Check the name is good for event/group/fields */
+static inline bool is_good_name(const char *name)
+{
+	return __is_good_name(name, false);
+}
+
+/* Check the name is good for system */
+static inline bool is_good_system_name(const char *name)
+{
+	return __is_good_name(name, true);
+}
+
 /* Convert certain expected symbols into '_' when generating event names */
 static inline void sanitize_event_name(char *name)
 {

kernel/trace/trace_probe.c +1 -1

index 36dff277de46..bb2f95d7175c 100644
@@ -246,7 +246,7 @@ int traceprobe_parse_event_name(const char **pevent, const char **pgroup,
 			return -EINVAL;
 		}
 		strlcpy(buf, event, slash - event + 1);
-		if (!is_good_name(buf)) {
+		if (!is_good_system_name(buf)) {
 			trace_probe_log_err(offset, BAD_GROUP_NAME);
 			return -EINVAL;
 		}

Quoted 7 lines · On Fri, 18 Nov 2022 11:19:40 -0500 Steven Rostedt <[email protected]> wrote:

Quoted 4 lines · On Fri, 18 Nov 2022 10:34:40 -0300 Rafael Mendonca <[email protected]>…

It did not trigger the NULL pointer issue to be more specific. When creating event probe for all events I was unable to create any event for the xhci-hcd system:

Quoted 7 lines

Quoted 5 lines

root@localhost:/sys/kernel/tracing# echo 'e xhci-hcd/xhci_add_endpoint' > dynamic_events 
-bash: echo: write error: Invalid argument

Debugging the issue it seems that the problem is in the is_good_name() check, which returns false for "xhci-hcd". Should we sanitize it by

Ouch. I didn't realize that.

Maybe we need better error message so that user can notice which character caused the error.

Quoted 3 lines

Quoted 2 lines

converting '-' into '_'?

Quoted 2 lines

Actually, it's just the system name that's an issue. I tested this patch and it appears to work.

Ah, the system name is more flexible than the event name because it has TRACE_SYSTEM_VAR.

Steve, can you send me the below patch?

BTW, TRACE_DEFINE_ENUM() and TRACE_DEFINE_SIZEOF() macros are using TRACE_SYSTEM instead of TRACE_SYSTEM_VAR. Should those use TRACE_SYSTEM_VAR for defining a variable?

Quoted 19 lines · On Wed, 16 Nov 2022 16:25:51 -0300 Rafael Mendonca <[email protected]>…

That happens because enable_eprobe() will eventually trigger the kmem/mm_page_alloc trace event:

- enable_eprobe [trace_eprobe.c]
- trace_event_trigger_enable_disable [trace_events_trigger.c]
- trace_event_enable_disable [trace_events.c]
- __ftrace_event_enable_disable [trace_events.c]
- trace_buffered_event_enable [trace.c]
- alloc_pages_node [gfp.h]
...
- __alloc_pages [page_alloc.c]
- trace_mm_page_alloc // eprobe event file without TRIGGER_COND bit set

By the time kmem/mm_page_alloc trace event is hit, the eprobe event file does not have the TRIGGER_COND flag set yet, which causes the eprobe's trigger to be invoked (through the trace_trigger_soft_disabled() path) without a trace record, causing a NULL pointer dereference when fetching the event fields.

Quoted 6 lines

Fix this by setting the cond flag beforehand when enabling the eprobe's trigger.

Fixes 7491e2c44278 ("tracing: Add a probe that attaches to trace events")

Signed-off-by Rafael Mendonca <[email protected]>

---

Thanks for the report, but I'm worried that this isn't enough because of how memory ordering can happen on different architectures. That is, just because you switch the order of updates, doesn't mean that the architecture will honor it.

I don't want to add memory barriers in the fast path, but instead we can simply check if rec is NULL in the handler.

So basically:

static void eprobe_trigger_func(struct event_trigger_data *data,
struct trace_buffer *buffer, void *rec, struct ring_buffer_event *rbe)

{
	struct eprobe_data *edata = data->private_data;

	if (!rec)
		return;

	__eprobe_trace_func(edata, rec);
}

And this should be documented.

-- Steve