[PATCH] tracing: Warn when an event dereferences a pointer in TP_printk()

[PATCH] tracing: Warn when an event dereferences a pointer in TP_printk()

[Steven Rostedt]

From: Steven Rostedt <rostedt@goodmis.org>

Currently on boot up and when modules are loaded, the trace event
infrastructure will examine the TP_printk's of every event looking to see
if it dereferences pointers on the ring buffer via printk formats like
"%pB" and such. What it doesn't do is check if the arguments themselves
do a dereference from a pointer.

This was brought with a fix[1] to the fsl_edma event that had in the
arguments of the TP_printk(): "__entry->edma->membase"

The __entry->edma is a pointer saved in the ring buffer. The dereference
from TP_printk() happens when the user reads the "trace" file which can be
seconds, minutes, hours, days, weeks, or even months later! There is no
guarantee that the __entry->edma pointer will still be pointing to what it
was when it was recorded, and could crash the kernel when a user reads the
event.

Add logic to the test_event_printk() that also checks for this case and
warn if the event dereferences a pointer from the ring buffer.

[1] https://lore.kernel.org/all/20260630200022.1826420-1-martin@kaiser.cx/

Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
---
 kernel/trace/trace_events.c | 35 +++++++++++++++++++++++++++++------
 1 file changed, 29 insertions(+), 6 deletions(-)

diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
index c46e623e7e0d..3b52bfd8b300 100644
--- a/kernel/trace/trace_events.c
+++ b/kernel/trace/trace_events.c
@@ -400,6 +400,31 @@ static bool process_string(const char *fmt, int len, struct trace_event_call *ca
 	return true;
 }
 
+static void test_double_dereference(const char *str, int len,
+				    struct trace_event_call *call)
+{
+	const char *ptr;
+	const char *end = str + len;
+
+	ptr = strstr(str, "REC->");
+
+	while (ptr && ptr < end) {
+
+		ptr += 5;
+		for (; ptr < end; ptr++) {
+			if (ptr[0] == '-' && ptr[1] == '>') {
+				WARN_ONCE(1, "Event %s has double dereference in TP_printk: %.*s\n",
+					  trace_event_name(call), len, str);
+				return;
+			}
+			if (!isalnum(*ptr) && *ptr != '_')
+				break;
+		}
+
+		ptr = strstr(ptr, "REC->");
+	}
+}
+
 static void handle_dereference_arg(const char *arg_str, u64 string_flags, int len,
 				   u64 *dereference_flags, int arg,
 				   struct trace_event_call *call)
@@ -459,12 +484,6 @@ static void test_event_printk(struct trace_event_call *call)
 				if (in_quote) {
 					arg = 0;
 					first = false;
-					/*
-					 * If there was no %p* uses
-					 * the fmt is OK.
-					 */
-					if (!dereference_flags)
-						return;
 				}
 			}
 			if (in_quote) {
@@ -576,6 +595,8 @@ static void test_event_printk(struct trace_event_call *call)
 				continue;
 			}
 
+			test_double_dereference(fmt + start_arg, e - start_arg, call);
+
 			if (dereference_flags & (1ULL << arg)) {
 				handle_dereference_arg(fmt + start_arg, string_flags,
 						       e - start_arg,
@@ -589,6 +610,8 @@ static void test_event_printk(struct trace_event_call *call)
 		}
 	}
 
+	test_double_dereference(fmt + start_arg, i - start_arg, call);
+
 	if (dereference_flags & (1ULL << arg)) {
 		handle_dereference_arg(fmt + start_arg, string_flags,
 				       i - start_arg,
-- 
2.53.0

Re: [PATCH] tracing: Warn when an event dereferences a pointer in TP_printk()

[Martin Kaiser]

Thus wrote Steven Rostedt (rostedt@goodmis.org):

> From: Steven Rostedt <rostedt@goodmis.org>

> Currently on boot up and when modules are loaded, the trace event
> infrastructure will examine the TP_printk's of every event looking to see
> if it dereferences pointers on the ring buffer via printk formats like
> "%pB" and such. What it doesn't do is check if the arguments themselves
> do a dereference from a pointer.

> This was brought with a fix[1] to the fsl_edma event that had in the
> arguments of the TP_printk(): "__entry->edma->membase"

> The __entry->edma is a pointer saved in the ring buffer. The dereference
> from TP_printk() happens when the user reads the "trace" file which can be
> seconds, minutes, hours, days, weeks, or even months later! There is no
> guarantee that the __entry->edma pointer will still be pointing to what it
> was when it was recorded, and could crash the kernel when a user reads the
> event.

> Add logic to the test_event_printk() that also checks for this case and
> warn if the event dereferences a pointer from the ring buffer.

> [1] https://lore.kernel.org/all/20260630200022.1826420-1-martin@kaiser.cx/

> Signed-off-by: Steven Rostedt <rostedt@goodmis.org>
> ---
>  kernel/trace/trace_events.c | 35 +++++++++++++++++++++++++++++------
>  1 file changed, 29 insertions(+), 6 deletions(-)

> diff --git a/kernel/trace/trace_events.c b/kernel/trace/trace_events.c
> index c46e623e7e0d..3b52bfd8b300 100644
> --- a/kernel/trace/trace_events.c
> +++ b/kernel/trace/trace_events.c
> @@ -400,6 +400,31 @@ static bool process_string(const char *fmt, int len, struct trace_event_call *ca
>  	return true;
>  }

> +static void test_double_dereference(const char *str, int len,
> +				    struct trace_event_call *call)
> +{
> +	const char *ptr;
> +	const char *end = str + len;
> +
> +	ptr = strstr(str, "REC->");
> +
> +	while (ptr && ptr < end) {
> +
> +		ptr += 5;
> +		for (; ptr < end; ptr++) {
> +			if (ptr[0] == '-' && ptr[1] == '>') {
> +				WARN_ONCE(1, "Event %s has double dereference in TP_printk: %.*s\n",
> +					  trace_event_name(call), len, str);
> +				return;
> +			}
> +			if (!isalnum(*ptr) && *ptr != '_')
> +				break;
> +		}
> +
> +		ptr = strstr(ptr, "REC->");
> +	}
> +}
> +
>  static void handle_dereference_arg(const char *arg_str, u64 string_flags, int len,
>  				   u64 *dereference_flags, int arg,
>  				   struct trace_event_call *call)
> @@ -459,12 +484,6 @@ static void test_event_printk(struct trace_event_call *call)
>  				if (in_quote) {
>  					arg = 0;
>  					first = false;
> -					/*
> -					 * If there was no %p* uses
> -					 * the fmt is OK.
> -					 */
> -					if (!dereference_flags)
> -						return;
>  				}
>  			}
>  			if (in_quote) {
> @@ -576,6 +595,8 @@ static void test_event_printk(struct trace_event_call *call)
>  				continue;
>  			}

> +			test_double_dereference(fmt + start_arg, e - start_arg, call);
> +
>  			if (dereference_flags & (1ULL << arg)) {
>  				handle_dereference_arg(fmt + start_arg, string_flags,
>  						       e - start_arg,
> @@ -589,6 +610,8 @@ static void test_event_printk(struct trace_event_call *call)
>  		}
>  	}

> +	test_double_dereference(fmt + start_arg, i - start_arg, call);
> +
>  	if (dereference_flags & (1ULL << arg)) {
>  		handle_dereference_arg(fmt + start_arg, string_flags,
>  				       i - start_arg,
> -- 
> 2.53.0

Looks good to me.

Reviewed-by: Martin Kaiser <martin@kaiser.cx>

Re: [PATCH] tracing: Warn when an event dereferences a pointer in TP_printk()

[Vinod Koul]

On 30-06-26, 18:48, Steven Rostedt wrote:
> From: Steven Rostedt <rostedt@goodmis.org>
> 
> Currently on boot up and when modules are loaded, the trace event
> infrastructure will examine the TP_printk's of every event looking to see
> if it dereferences pointers on the ring buffer via printk formats like
> "%pB" and such. What it doesn't do is check if the arguments themselves
> do a dereference from a pointer.
> 
> This was brought with a fix[1] to the fsl_edma event that had in the
> arguments of the TP_printk(): "__entry->edma->membase"
> 
> The __entry->edma is a pointer saved in the ring buffer. The dereference
> from TP_printk() happens when the user reads the "trace" file which can be
> seconds, minutes, hours, days, weeks, or even months later! There is no
> guarantee that the __entry->edma pointer will still be pointing to what it
> was when it was recorded, and could crash the kernel when a user reads the
> event.
> 
> Add logic to the test_event_printk() that also checks for this case and
> warn if the event dereferences a pointer from the ring buffer.

Reviewed-by: Vinod Koul <vkoul@kernel.org>

-- 
~Vinod