[PATCH v2 0/2] tracing: fix race when creating trace probe log error message

[PATCH v2 0/2] tracing: fix race when creating trace probe log error message

[Paul Cacheux via B4 Relay]

Hello,

As reported in [1] a race exists in the shared trace probe log
used to build error messages. This can cause kernel crashes
when building the actual error message, but the race happens
even for non-error tracefs uses, it's just not visible.

Reproducer first reported that is still crashing:

  # 'p4' is invalid command which make kernel run into trace_probe_log_err()
  cd /sys/kernel/debug/tracing
  while true; do
    echo 'p4:myprobe1 do_sys_openat2 dfd=%ax filename=%dx flags=%cx mode=+4($stack)' >> kprobe_events &
    echo 'p4:myprobe2 do_sys_openat2' >> kprobe_events &
    echo 'p4:myprobe3 do_sys_openat2 dfd=%ax filename=%dx' >> kprobe_events &
  done;

The original email suggested to use a mutex or to allocate the
trace_probe_log on the stack. This patch implements a simpler
solution suggest during the review of the v1 where we only protect
access to the shared trace_probe_log with a mutex. This will prevent
any crash from happening.

[1] https://lore.kernel.org/all/20221121081103.3070449-1-zhengyejian1@huawei.com/T/

Signed-off-by: Paul Cacheux <paulcacheux@gmail.com>
---
Changes in v2:
- change approach, and use the mutex based solution suggested during
  review
- Link to v1: https://lore.kernel.org/r/20250422-fix-trace-probe-log-race-v1-1-d2728d42cacb@gmail.com

---
Paul Cacheux (2):
      tracing: add missing trace_probe_log_clear for eprobes
      tracing: protect trace_probe_log with mutex

 kernel/trace/trace_eprobe.c | 3 +++
 kernel/trace/trace_probe.c  | 6 ++++++
 2 files changed, 9 insertions(+)
---
base-commit: ebd297a2affadb6f6f4d2e5d975c1eda18ac762d
change-id: 20250420-fix-trace-probe-log-race-cc89d8e5fb15

Best regards,
-- 
Paul Cacheux <paulcacheux@gmail.com>

[PATCH v2 1/2] tracing: add missing trace_probe_log_clear for eprobes

[Paul Cacheux via B4 Relay]

From: Paul Cacheux <paulcacheux@gmail.com>

Make sure trace_probe_log_clear is called in the tracing
eprobe code path, matching the trace_probe_log_init call.

Signed-off-by: Paul Cacheux <paulcacheux@gmail.com>
---
 kernel/trace/trace_eprobe.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/kernel/trace/trace_eprobe.c b/kernel/trace/trace_eprobe.c
index c08355c3ef32b4124ac944d7e3a03efb66492269..916555f0de811f03feed9d923c63078b0e4c993b 100644
--- a/kernel/trace/trace_eprobe.c
+++ b/kernel/trace/trace_eprobe.c
@@ -969,10 +969,13 @@ static int __trace_eprobe_create(int argc, const char *argv[])
 			goto error;
 		}
 	}
+	trace_probe_log_clear();
 	return ret;
+
 parse_error:
 	ret = -EINVAL;
 error:
+	trace_probe_log_clear();
 	trace_event_probe_cleanup(ep);
 	return ret;
 }

-- 
2.49.0

Re: [PATCH v2 1/2] tracing: add missing trace_probe_log_clear for eprobes

[Masami Hiramatsu]

On Fri, 02 May 2025 15:15:52 +0200
Paul Cacheux via B4 Relay <devnull+paulcacheux.gmail.com@kernel.org> wrote:

> From: Paul Cacheux <paulcacheux@gmail.com>
> 
> Make sure trace_probe_log_clear is called in the tracing
> eprobe code path, matching the trace_probe_log_init call.
> 
> Signed-off-by: Paul Cacheux <paulcacheux@gmail.com>

Looks good to me.

Fixes: 7491e2c44278 ("tracing: Add a probe that attaches to trace events")
Cc: stable@vger.kernel.org

Thank you,

> ---
>  kernel/trace/trace_eprobe.c | 3 +++
>  1 file changed, 3 insertions(+)
> 
> diff --git a/kernel/trace/trace_eprobe.c b/kernel/trace/trace_eprobe.c
> index c08355c3ef32b4124ac944d7e3a03efb66492269..916555f0de811f03feed9d923c63078b0e4c993b 100644
> --- a/kernel/trace/trace_eprobe.c
> +++ b/kernel/trace/trace_eprobe.c
> @@ -969,10 +969,13 @@ static int __trace_eprobe_create(int argc, const char *argv[])
>  			goto error;
>  		}
>  	}
> +	trace_probe_log_clear();
>  	return ret;
> +
>  parse_error:
>  	ret = -EINVAL;
>  error:
> +	trace_probe_log_clear();
>  	trace_event_probe_cleanup(ep);
>  	return ret;
>  }
> 
> -- 
> 2.49.0
> 
> 


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>

[PATCH v2 2/2] tracing: protect trace_probe_log with mutex

[Paul Cacheux via B4 Relay]

From: Paul Cacheux <paulcacheux@gmail.com>

The shared trace_probe_log variable can be accessed and modified
by multiple processes using tracefs at the same time, this new
mutex will guarantee it's always in a coherent state.

There is no guarantee that multiple errors happening at the same
time will each have the correct error message, but at least this
won't crash.

Fixes: ab105a4fb894 ("tracing: Use tracing error_log with probe events")

Signed-off-by: Paul Cacheux <paulcacheux@gmail.com>
---
 kernel/trace/trace_probe.c | 6 ++++++
 1 file changed, 6 insertions(+)

diff --git a/kernel/trace/trace_probe.c b/kernel/trace/trace_probe.c
index 2eeecb6c95eea55502b83af6775b7b6f0cc5ab94..14a7a0b59cd20a8bc43e3e7c653e986081f924c8 100644
--- a/kernel/trace/trace_probe.c
+++ b/kernel/trace/trace_probe.c
@@ -154,9 +154,11 @@ static const struct fetch_type *find_fetch_type(const char *type, unsigned long
 }
 
 static struct trace_probe_log trace_probe_log;
+static DEFINE_MUTEX(trace_probe_log_lock);
 
 void trace_probe_log_init(const char *subsystem, int argc, const char **argv)
 {
+	guard(mutex)(&trace_probe_log_lock);
 	trace_probe_log.subsystem = subsystem;
 	trace_probe_log.argc = argc;
 	trace_probe_log.argv = argv;
@@ -165,11 +167,13 @@ void trace_probe_log_init(const char *subsystem, int argc, const char **argv)
 
 void trace_probe_log_clear(void)
 {
+	guard(mutex)(&trace_probe_log_lock);
 	memset(&trace_probe_log, 0, sizeof(trace_probe_log));
 }
 
 void trace_probe_log_set_index(int index)
 {
+	guard(mutex)(&trace_probe_log_lock);
 	trace_probe_log.index = index;
 }
 
@@ -178,6 +182,8 @@ void __trace_probe_log_err(int offset, int err_type)
 	char *command, *p;
 	int i, len = 0, pos = 0;
 
+	guard(mutex)(&trace_probe_log_lock);
+
 	if (!trace_probe_log.argv)
 		return;
 

-- 
2.49.0

Re: [PATCH v2 2/2] tracing: protect trace_probe_log with mutex

[Steven Rostedt]

On Fri, 02 May 2025 15:15:53 +0200
Paul Cacheux via B4 Relay <devnull+paulcacheux.gmail.com@kernel.org> wrote:

> From: Paul Cacheux <paulcacheux@gmail.com>
> 
> The shared trace_probe_log variable can be accessed and modified
> by multiple processes using tracefs at the same time, this new
> mutex will guarantee it's always in a coherent state.
> 
> There is no guarantee that multiple errors happening at the same
> time will each have the correct error message, but at least this
> won't crash.
> 
> Fixes: ab105a4fb894 ("tracing: Use tracing error_log with probe events")
> 

No space needed between Fixes and SOB.

> Signed-off-by: Paul Cacheux <paulcacheux@gmail.com>
> ---
>  kernel/trace/trace_probe.c | 6 ++++++
>  1 file changed, 6 insertions(+)
> 
> diff --git a/kernel/trace/trace_probe.c b/kernel/trace/trace_probe.c
> index 2eeecb6c95eea55502b83af6775b7b6f0cc5ab94..14a7a0b59cd20a8bc43e3e7c653e986081f924c8 100644
> --- a/kernel/trace/trace_probe.c
> +++ b/kernel/trace/trace_probe.c
> @@ -154,9 +154,11 @@ static const struct fetch_type *find_fetch_type(const char *type, unsigned long
>  }
>  
>  static struct trace_probe_log trace_probe_log;
> +static DEFINE_MUTEX(trace_probe_log_lock);

Probably should add a comment here saying something like:

/*
 * The trace_probe_log_lock only protects against the individual
 * modification of the trace_probe_log. It does not protect against
 * the log from producing garbage if two probes use it at the same
 * time. That would only happen if two admins were trying to add
 * probes simultaneously which they shouldn't be doing.
 */

-- Steve


>  
>  void trace_probe_log_init(const char *subsystem, int argc, const char **argv)
>  {
> +	guard(mutex)(&trace_probe_log_lock);
>  	trace_probe_log.subsystem = subsystem;
>  	trace_probe_log.argc = argc;
>  	trace_probe_log.argv = argv;
> @@ -165,11 +167,13 @@ void trace_probe_log_init(const char *subsystem, int argc, const char **argv)
>  
>  void trace_probe_log_clear(void)
>  {
> +	guard(mutex)(&trace_probe_log_lock);
>  	memset(&trace_probe_log, 0, sizeof(trace_probe_log));
>  }
>  
>  void trace_probe_log_set_index(int index)
>  {
> +	guard(mutex)(&trace_probe_log_lock);
>  	trace_probe_log.index = index;
>  }
>  
> @@ -178,6 +182,8 @@ void __trace_probe_log_err(int offset, int err_type)
>  	char *command, *p;
>  	int i, len = 0, pos = 0;
>  
> +	guard(mutex)(&trace_probe_log_lock);
> +
>  	if (!trace_probe_log.argv)
>  		return;
>  
> 

Re: [PATCH v2 2/2] tracing: protect trace_probe_log with mutex

[Paul Cacheux]

On Fri, 2025-05-02 at 09:50 -0400, Steven Rostedt wrote:
> On Fri, 02 May 2025 15:15:53 +0200
> Paul Cacheux via B4 Relay <devnull+paulcacheux.gmail.com@kernel.org>
> wrote:
> 
> > From: Paul Cacheux <paulcacheux@gmail.com>
> > 
> > The shared trace_probe_log variable can be accessed and modified
> > by multiple processes using tracefs at the same time, this new
> > mutex will guarantee it's always in a coherent state.
> > 
> > There is no guarantee that multiple errors happening at the same
> > time will each have the correct error message, but at least this
> > won't crash.
> > 
> > Fixes: ab105a4fb894 ("tracing: Use tracing error_log with probe
> > events")
> > 
> 
> No space needed between Fixes and SOB.

Sorry about that, fixed in v3

> 
> > Signed-off-by: Paul Cacheux <paulcacheux@gmail.com>
> > ---
> >  kernel/trace/trace_probe.c | 6 ++++++
> >  1 file changed, 6 insertions(+)
> > 
> > diff --git a/kernel/trace/trace_probe.c
> > b/kernel/trace/trace_probe.c
> > index
> > 2eeecb6c95eea55502b83af6775b7b6f0cc5ab94..14a7a0b59cd20a8bc43e3e7c6
> > 53e986081f924c8 100644
> > --- a/kernel/trace/trace_probe.c
> > +++ b/kernel/trace/trace_probe.c
> > @@ -154,9 +154,11 @@ static const struct fetch_type
> > *find_fetch_type(const char *type, unsigned long
> >  }
> >  
> >  static struct trace_probe_log trace_probe_log;
> > +static DEFINE_MUTEX(trace_probe_log_lock);
> 
> Probably should add a comment here saying something like:
> 
> /*
>  * The trace_probe_log_lock only protects against the individual
>  * modification of the trace_probe_log. It does not protect against
>  * the log from producing garbage if two probes use it at the same
>  * time. That would only happen if two admins were trying to add
>  * probes simultaneously which they shouldn't be doing.
>  */

I sent a v3 with the space removed and this comment added, thank you
for the review.

> 
> -- Steve
> 
> 
> >  
> >  void trace_probe_log_init(const char *subsystem, int argc, const
> > char **argv)
> >  {
> > +	guard(mutex)(&trace_probe_log_lock);
> >  	trace_probe_log.subsystem = subsystem;
> >  	trace_probe_log.argc = argc;
> >  	trace_probe_log.argv = argv;
> > @@ -165,11 +167,13 @@ void trace_probe_log_init(const char
> > *subsystem, int argc, const char **argv)
> >  
> >  void trace_probe_log_clear(void)
> >  {
> > +	guard(mutex)(&trace_probe_log_lock);
> >  	memset(&trace_probe_log, 0, sizeof(trace_probe_log));
> >  }
> >  
> >  void trace_probe_log_set_index(int index)
> >  {
> > +	guard(mutex)(&trace_probe_log_lock);
> >  	trace_probe_log.index = index;
> >  }
> >  
> > @@ -178,6 +182,8 @@ void __trace_probe_log_err(int offset, int
> > err_type)
> >  	char *command, *p;
> >  	int i, len = 0, pos = 0;
> >  
> > +	guard(mutex)(&trace_probe_log_lock);
> > +
> >  	if (!trace_probe_log.argv)
> >  		return;
> >  
> > 

Best regards,

Paul Cacheux

Re: [PATCH v2 2/2] tracing: protect trace_probe_log with mutex

[Masami Hiramatsu]

On Fri, 02 May 2025 15:15:53 +0200
Paul Cacheux via B4 Relay <devnull+paulcacheux.gmail.com@kernel.org> wrote:

> From: Paul Cacheux <paulcacheux@gmail.com>
> 
> The shared trace_probe_log variable can be accessed and modified
> by multiple processes using tracefs at the same time, this new
> mutex will guarantee it's always in a coherent state.

Actually that's not happen. For the create part (and currently the
event_log is used only in the creation), `dyn_event_ops_mutex` is already
held in create_dyn_event(). Thus, it is already serialized.

And even if there are multiple events are done in parallel, this
is not enough because trace_probe_log::argc/argv can be changed
before other user finishs to use the log.

Thank you,

> 
> There is no guarantee that multiple errors happening at the same
> time will each have the correct error message, but at least this
> won't crash.
> 
> Fixes: ab105a4fb894 ("tracing: Use tracing error_log with probe events")
> 
> Signed-off-by: Paul Cacheux <paulcacheux@gmail.com>
> ---
>  kernel/trace/trace_probe.c | 6 ++++++
>  1 file changed, 6 insertions(+)
> 
> diff --git a/kernel/trace/trace_probe.c b/kernel/trace/trace_probe.c
> index 2eeecb6c95eea55502b83af6775b7b6f0cc5ab94..14a7a0b59cd20a8bc43e3e7c653e986081f924c8 100644
> --- a/kernel/trace/trace_probe.c
> +++ b/kernel/trace/trace_probe.c
> @@ -154,9 +154,11 @@ static const struct fetch_type *find_fetch_type(const char *type, unsigned long
>  }
>  
>  static struct trace_probe_log trace_probe_log;
> +static DEFINE_MUTEX(trace_probe_log_lock);
>  
>  void trace_probe_log_init(const char *subsystem, int argc, const char **argv)
>  {
> +	guard(mutex)(&trace_probe_log_lock);
>  	trace_probe_log.subsystem = subsystem;
>  	trace_probe_log.argc = argc;
>  	trace_probe_log.argv = argv;
> @@ -165,11 +167,13 @@ void trace_probe_log_init(const char *subsystem, int argc, const char **argv)
>  
>  void trace_probe_log_clear(void)
>  {
> +	guard(mutex)(&trace_probe_log_lock);
>  	memset(&trace_probe_log, 0, sizeof(trace_probe_log));
>  }
>  
>  void trace_probe_log_set_index(int index)
>  {
> +	guard(mutex)(&trace_probe_log_lock);
>  	trace_probe_log.index = index;
>  }
>  
> @@ -178,6 +182,8 @@ void __trace_probe_log_err(int offset, int err_type)
>  	char *command, *p;
>  	int i, len = 0, pos = 0;
>  
> +	guard(mutex)(&trace_probe_log_lock);
> +
>  	if (!trace_probe_log.argv)
>  		return;
>  
> 
> -- 
> 2.49.0
> 
> 


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>

Re: [PATCH v2 2/2] tracing: protect trace_probe_log with mutex

[Masami Hiramatsu]

On Sat, 10 May 2025 07:44:56 +0900
Masami Hiramatsu (Google) <mhiramat@kernel.org> wrote:

> On Fri, 02 May 2025 15:15:53 +0200
> Paul Cacheux via B4 Relay <devnull+paulcacheux.gmail.com@kernel.org> wrote:
> 
> > From: Paul Cacheux <paulcacheux@gmail.com>
> > 
> > The shared trace_probe_log variable can be accessed and modified
> > by multiple processes using tracefs at the same time, this new
> > mutex will guarantee it's always in a coherent state.
> 
> Actually that's not happen. For the create part (and currently the
> event_log is used only in the creation), `dyn_event_ops_mutex` is already
> held in create_dyn_event(). Thus, it is already serialized.

Oops, if user writes some commands not directly from dynevent,
(e.g. tracefs/{kprobe_events,uprobe_events} )the mutex is not held.
Hmm, we need to make another patch.

> 
> And even if there are multiple events are done in parallel, this
> is not enough because trace_probe_log::argc/argv can be changed
> before other user finishs to use the log.

But this is still valid. We need to reroute the creation to
dynamic_events.

Thank you,

> 
> Thank you,
> 
> > 
> > There is no guarantee that multiple errors happening at the same
> > time will each have the correct error message, but at least this
> > won't crash.
> > 
> > Fixes: ab105a4fb894 ("tracing: Use tracing error_log with probe events")
> > 
> > Signed-off-by: Paul Cacheux <paulcacheux@gmail.com>
> > ---
> >  kernel/trace/trace_probe.c | 6 ++++++
> >  1 file changed, 6 insertions(+)
> > 
> > diff --git a/kernel/trace/trace_probe.c b/kernel/trace/trace_probe.c
> > index 2eeecb6c95eea55502b83af6775b7b6f0cc5ab94..14a7a0b59cd20a8bc43e3e7c653e986081f924c8 100644
> > --- a/kernel/trace/trace_probe.c
> > +++ b/kernel/trace/trace_probe.c
> > @@ -154,9 +154,11 @@ static const struct fetch_type *find_fetch_type(const char *type, unsigned long
> >  }
> >  
> >  static struct trace_probe_log trace_probe_log;
> > +static DEFINE_MUTEX(trace_probe_log_lock);
> >  
> >  void trace_probe_log_init(const char *subsystem, int argc, const char **argv)
> >  {
> > +	guard(mutex)(&trace_probe_log_lock);
> >  	trace_probe_log.subsystem = subsystem;
> >  	trace_probe_log.argc = argc;
> >  	trace_probe_log.argv = argv;
> > @@ -165,11 +167,13 @@ void trace_probe_log_init(const char *subsystem, int argc, const char **argv)
> >  
> >  void trace_probe_log_clear(void)
> >  {
> > +	guard(mutex)(&trace_probe_log_lock);
> >  	memset(&trace_probe_log, 0, sizeof(trace_probe_log));
> >  }
> >  
> >  void trace_probe_log_set_index(int index)
> >  {
> > +	guard(mutex)(&trace_probe_log_lock);
> >  	trace_probe_log.index = index;
> >  }
> >  
> > @@ -178,6 +182,8 @@ void __trace_probe_log_err(int offset, int err_type)
> >  	char *command, *p;
> >  	int i, len = 0, pos = 0;
> >  
> > +	guard(mutex)(&trace_probe_log_lock);
> > +
> >  	if (!trace_probe_log.argv)
> >  		return;
> >  
> > 
> > -- 
> > 2.49.0
> > 
> > 
> 
> 
> -- 
> Masami Hiramatsu (Google) <mhiramat@kernel.org>


-- 
Masami Hiramatsu (Google) <mhiramat@kernel.org>