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

[Martin Kaiser <martin@kaiser.cx>]

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>