[PATCH bpf-next] bpf: Fix deadlock between rcu_tasks_trace and event_mutex.

[PATCH bpf-next] bpf: Fix deadlock between rcu_tasks_trace and event_mutex.

[Alexei Starovoitov]

From: Alexei Starovoitov <ast@kernel.org>

Fix the following deadlock:
CPU A
_free_event()
  perf_kprobe_destroy()
    mutex_lock(&event_mutex)
      perf_trace_event_unreg()
        synchronize_rcu_tasks_trace()

There are several paths where _free_event() grabs event_mutex
and calls sync_rcu_tasks_trace. Above is one such case.

CPU B
bpf_prog_test_run_syscall()
  rcu_read_lock_trace()
    bpf_prog_run_pin_on_cpu()
      bpf_prog_load()
        bpf_tracing_func_proto()
          trace_set_clr_event()
            mutex_lock(&event_mutex)

Delegate trace_set_clr_event() to workqueue to avoid
such lock dependency.

Signed-off-by: Alexei Starovoitov <ast@kernel.org>
---
 kernel/trace/bpf_trace.c | 7 ++++---
 1 file changed, 4 insertions(+), 3 deletions(-)

diff --git a/kernel/trace/bpf_trace.c b/kernel/trace/bpf_trace.c
index a612f6f182e5..13bef2462e94 100644
--- a/kernel/trace/bpf_trace.c
+++ b/kernel/trace/bpf_trace.c
@@ -392,7 +392,7 @@ static const struct bpf_func_proto bpf_trace_printk_proto = {
 	.arg2_type	= ARG_CONST_SIZE,
 };
 
-static void __set_printk_clr_event(void)
+static void __set_printk_clr_event(struct work_struct *work)
 {
 	/*
 	 * This program might be calling bpf_trace_printk,
@@ -405,10 +405,11 @@ static void __set_printk_clr_event(void)
 	if (trace_set_clr_event("bpf_trace", "bpf_trace_printk", 1))
 		pr_warn_ratelimited("could not enable bpf_trace_printk events");
 }
+static DECLARE_WORK(set_printk_work, __set_printk_clr_event);
 
 const struct bpf_func_proto *bpf_get_trace_printk_proto(void)
 {
-	__set_printk_clr_event();
+	schedule_work(&set_printk_work);
 	return &bpf_trace_printk_proto;
 }
 
@@ -451,7 +452,7 @@ static const struct bpf_func_proto bpf_trace_vprintk_proto = {
 
 const struct bpf_func_proto *bpf_get_trace_vprintk_proto(void)
 {
-	__set_printk_clr_event();
+	schedule_work(&set_printk_work);
 	return &bpf_trace_vprintk_proto;
 }
 
-- 
2.43.5

Re: [PATCH bpf-next] bpf: Fix deadlock between rcu_tasks_trace and event_mutex.

[Andrii Nakryiko]

On Mon, Feb 24, 2025 at 2:16 PM Alexei Starovoitov
<alexei.starovoitov@gmail.com> wrote:
>
> From: Alexei Starovoitov <ast@kernel.org>
>
> Fix the following deadlock:
> CPU A
> _free_event()
>   perf_kprobe_destroy()
>     mutex_lock(&event_mutex)
>       perf_trace_event_unreg()
>         synchronize_rcu_tasks_trace()
>
> There are several paths where _free_event() grabs event_mutex
> and calls sync_rcu_tasks_trace. Above is one such case.
>
> CPU B
> bpf_prog_test_run_syscall()
>   rcu_read_lock_trace()
>     bpf_prog_run_pin_on_cpu()
>       bpf_prog_load()
>         bpf_tracing_func_proto()
>           trace_set_clr_event()
>             mutex_lock(&event_mutex)
>
> Delegate trace_set_clr_event() to workqueue to avoid
> such lock dependency.
>
> Signed-off-by: Alexei Starovoitov <ast@kernel.org>
> ---
>  kernel/trace/bpf_trace.c | 7 ++++---
>  1 file changed, 4 insertions(+), 3 deletions(-)
>

There is a tiny chance that bpf_printk() might not produce data (for a
little bit) if the time between program verification and its
triggering right after that is shorter than workqueue delay, right?
It's probably negligible in practice, so lgtm

Acked-by: Andrii Nakryiko <andrii@kernel.org>

> diff --git a/kernel/trace/bpf_trace.c b/kernel/trace/bpf_trace.c
> index a612f6f182e5..13bef2462e94 100644
> --- a/kernel/trace/bpf_trace.c
> +++ b/kernel/trace/bpf_trace.c
> @@ -392,7 +392,7 @@ static const struct bpf_func_proto bpf_trace_printk_proto = {
>         .arg2_type      = ARG_CONST_SIZE,
>  };
>
> -static void __set_printk_clr_event(void)
> +static void __set_printk_clr_event(struct work_struct *work)
>  {
>         /*
>          * This program might be calling bpf_trace_printk,
> @@ -405,10 +405,11 @@ static void __set_printk_clr_event(void)
>         if (trace_set_clr_event("bpf_trace", "bpf_trace_printk", 1))
>                 pr_warn_ratelimited("could not enable bpf_trace_printk events");
>  }
> +static DECLARE_WORK(set_printk_work, __set_printk_clr_event);
>
>  const struct bpf_func_proto *bpf_get_trace_printk_proto(void)
>  {
> -       __set_printk_clr_event();
> +       schedule_work(&set_printk_work);
>         return &bpf_trace_printk_proto;
>  }
>
> @@ -451,7 +452,7 @@ static const struct bpf_func_proto bpf_trace_vprintk_proto = {
>
>  const struct bpf_func_proto *bpf_get_trace_vprintk_proto(void)
>  {
> -       __set_printk_clr_event();
> +       schedule_work(&set_printk_work);
>         return &bpf_trace_vprintk_proto;
>  }
>
> --
> 2.43.5
>

Re: [PATCH bpf-next] bpf: Fix deadlock between rcu_tasks_trace and event_mutex.

[Alexei Starovoitov]

On Mon, Feb 24, 2025 at 5:06 PM Andrii Nakryiko
<andrii.nakryiko@gmail.com> wrote:
>
> On Mon, Feb 24, 2025 at 2:16 PM Alexei Starovoitov
> <alexei.starovoitov@gmail.com> wrote:
> >
> > From: Alexei Starovoitov <ast@kernel.org>
> >
> > Fix the following deadlock:
> > CPU A
> > _free_event()
> >   perf_kprobe_destroy()
> >     mutex_lock(&event_mutex)
> >       perf_trace_event_unreg()
> >         synchronize_rcu_tasks_trace()
> >
> > There are several paths where _free_event() grabs event_mutex
> > and calls sync_rcu_tasks_trace. Above is one such case.
> >
> > CPU B
> > bpf_prog_test_run_syscall()
> >   rcu_read_lock_trace()
> >     bpf_prog_run_pin_on_cpu()
> >       bpf_prog_load()
> >         bpf_tracing_func_proto()
> >           trace_set_clr_event()
> >             mutex_lock(&event_mutex)
> >
> > Delegate trace_set_clr_event() to workqueue to avoid
> > such lock dependency.
> >
> > Signed-off-by: Alexei Starovoitov <ast@kernel.org>
> > ---
> >  kernel/trace/bpf_trace.c | 7 ++++---
> >  1 file changed, 4 insertions(+), 3 deletions(-)
> >
>
> There is a tiny chance that bpf_printk() might not produce data (for a
> little bit) if the time between program verification and its
> triggering right after that is shorter than workqueue delay, right?

yeah, but also see the comment in __set_printk_clr_event().
Unfortunately users can enable/disable this event at any time
just like other ftrace events.
The trace_bpf_trace_printk is fragile and racy.
In addition, trace_pipe can be configured in weird ways.
cat /sys/kernel/tracing/trace_pipe
will look nothing like normal.
All existing footgun warnings apply.

With Kumar we started discussing a new debug/printk mechanism.
So that arena faults, res_spin_lock timeous can be printed there
and consumed per program instead of global trace_pipe.

> It's probably negligible in practice, so lgtm
>
> Acked-by: Andrii Nakryiko <andrii@kernel.org>
>
> > diff --git a/kernel/trace/bpf_trace.c b/kernel/trace/bpf_trace.c
> > index a612f6f182e5..13bef2462e94 100644
> > --- a/kernel/trace/bpf_trace.c
> > +++ b/kernel/trace/bpf_trace.c
> > @@ -392,7 +392,7 @@ static const struct bpf_func_proto bpf_trace_printk_proto = {
> >         .arg2_type      = ARG_CONST_SIZE,
> >  };
> >
> > -static void __set_printk_clr_event(void)
> > +static void __set_printk_clr_event(struct work_struct *work)
> >  {
> >         /*
> >          * This program might be calling bpf_trace_printk,
> > @@ -405,10 +405,11 @@ static void __set_printk_clr_event(void)
> >         if (trace_set_clr_event("bpf_trace", "bpf_trace_printk", 1))
> >                 pr_warn_ratelimited("could not enable bpf_trace_printk events");
> >  }
> > +static DECLARE_WORK(set_printk_work, __set_printk_clr_event);
> >
> >  const struct bpf_func_proto *bpf_get_trace_printk_proto(void)
> >  {
> > -       __set_printk_clr_event();
> > +       schedule_work(&set_printk_work);
> >         return &bpf_trace_printk_proto;
> >  }
> >
> > @@ -451,7 +452,7 @@ static const struct bpf_func_proto bpf_trace_vprintk_proto = {
> >
> >  const struct bpf_func_proto *bpf_get_trace_vprintk_proto(void)
> >  {
> > -       __set_printk_clr_event();
> > +       schedule_work(&set_printk_work);
> >         return &bpf_trace_vprintk_proto;
> >  }
> >
> > --
> > 2.43.5
> >

Re: [PATCH bpf-next] bpf: Fix deadlock between rcu_tasks_trace and event_mutex.

[Hou Tao]

Hi,

On 2/25/2025 6:16 AM, Alexei Starovoitov wrote:
> From: Alexei Starovoitov <ast@kernel.org>
>
> Fix the following deadlock:
> CPU A
> _free_event()
>   perf_kprobe_destroy()
>     mutex_lock(&event_mutex)
>       perf_trace_event_unreg()
>         synchronize_rcu_tasks_trace()
>
> There are several paths where _free_event() grabs event_mutex
> and calls sync_rcu_tasks_trace. Above is one such case.
>
> CPU B
> bpf_prog_test_run_syscall()
>   rcu_read_lock_trace()
>     bpf_prog_run_pin_on_cpu()
>       bpf_prog_load()
>         bpf_tracing_func_proto()
>           trace_set_clr_event()
>             mutex_lock(&event_mutex)

Considering the unregistered case is not so frequency, would it better
to use mutex_trylock firstly, then fallback to workqueue when the
event_mutex is busy ?
>
> Delegate trace_set_clr_event() to workqueue to avoid
> such lock dependency.
>
> Signed-off-by: Alexei Starovoitov <ast@kernel.org>
> ---
>  kernel/trace/bpf_trace.c | 7 ++++---
>  1 file changed, 4 insertions(+), 3 deletions(-)
>
> diff --git a/kernel/trace/bpf_trace.c b/kernel/trace/bpf_trace.c
> index a612f6f182e5..13bef2462e94 100644
> --- a/kernel/trace/bpf_trace.c
> +++ b/kernel/trace/bpf_trace.c
> @@ -392,7 +392,7 @@ static const struct bpf_func_proto bpf_trace_printk_proto = {
>  	.arg2_type	= ARG_CONST_SIZE,
>  };
>  
> -static void __set_printk_clr_event(void)
> +static void __set_printk_clr_event(struct work_struct *work)
>  {
>  	/*
>  	 * This program might be calling bpf_trace_printk,
> @@ -405,10 +405,11 @@ static void __set_printk_clr_event(void)
>  	if (trace_set_clr_event("bpf_trace", "bpf_trace_printk", 1))
>  		pr_warn_ratelimited("could not enable bpf_trace_printk events");
>  }
> +static DECLARE_WORK(set_printk_work, __set_printk_clr_event);
>  
>  const struct bpf_func_proto *bpf_get_trace_printk_proto(void)
>  {
> -	__set_printk_clr_event();
> +	schedule_work(&set_printk_work);
>  	return &bpf_trace_printk_proto;
>  }
>  
> @@ -451,7 +452,7 @@ static const struct bpf_func_proto bpf_trace_vprintk_proto = {
>  
>  const struct bpf_func_proto *bpf_get_trace_vprintk_proto(void)
>  {
> -	__set_printk_clr_event();
> +	schedule_work(&set_printk_work);
>  	return &bpf_trace_vprintk_proto;
>  }
>  

Re: [PATCH bpf-next] bpf: Fix deadlock between rcu_tasks_trace and event_mutex.

[Alexei Starovoitov]

On Tue, Feb 25, 2025 at 5:03 AM Hou Tao <houtao@huaweicloud.com> wrote:
>
> Hi,
>
> On 2/25/2025 6:16 AM, Alexei Starovoitov wrote:
> > From: Alexei Starovoitov <ast@kernel.org>
> >
> > Fix the following deadlock:
> > CPU A
> > _free_event()
> >   perf_kprobe_destroy()
> >     mutex_lock(&event_mutex)
> >       perf_trace_event_unreg()
> >         synchronize_rcu_tasks_trace()
> >
> > There are several paths where _free_event() grabs event_mutex
> > and calls sync_rcu_tasks_trace. Above is one such case.
> >
> > CPU B
> > bpf_prog_test_run_syscall()
> >   rcu_read_lock_trace()
> >     bpf_prog_run_pin_on_cpu()
> >       bpf_prog_load()
> >         bpf_tracing_func_proto()
> >           trace_set_clr_event()
> >             mutex_lock(&event_mutex)
>
> Considering the unregistered case is not so frequency, would it better
> to use mutex_trylock firstly, then fallback to workqueue when the
> event_mutex is busy ?

No. That would be an unnecessary complication.

Re: [PATCH bpf-next] bpf: Fix deadlock between rcu_tasks_trace and event_mutex.

[patchwork-bot+netdevbpf]

Hello:

This patch was applied to bpf/bpf-next.git (master)
by Andrii Nakryiko <andrii@kernel.org>:

On Mon, 24 Feb 2025 14:16:37 -0800 you wrote:
> From: Alexei Starovoitov <ast@kernel.org>
> 
> Fix the following deadlock:
> CPU A
> _free_event()
>   perf_kprobe_destroy()
>     mutex_lock(&event_mutex)
>       perf_trace_event_unreg()
>         synchronize_rcu_tasks_trace()
> 
> [...]

Here is the summary with links:
  - [bpf-next] bpf: Fix deadlock between rcu_tasks_trace and event_mutex.
    https://git.kernel.org/bpf/bpf-next/c/4580f4e0ebdf

You are awesome, thank you!
-- 
Deet-doot-dot, I am a bot.
https://korg.docs.kernel.org/patchwork/pwbot.html