[PATCH] ftrace: Fixup lockdep assert held of text_mutex

[PATCH] ftrace: Fixup lockdep assert held of text_mutex

[guoren]

From: Guo Ren <guoren@linux.alibaba.com>

The function ftrace_process_locs() will modify text code, so we
should give a text_mutex lock. Because some arch's patch code
will assert held of text_mutex even during start_kernel->
ftrace_init().

backtrace log:
   assert by lockdep_assert_held(&text_mutex)
0  patch_insn_write (addr=0xffffffe0000010fc <set_reset_devices+10>, insn=0xffffffe001203eb8, len=8) at arch/riscv/kernel/patch.c:63
1  0xffffffe0002042ec in patch_text_nosync (addr=<optimized out>, insns=<optimized out>, len=<optimized out>) at arch/riscv/kernel/patch.c:93
2  0xffffffe00020628e in __ftrace_modify_call (hook_pos=<optimized out>, target=<optimized out>, enable=<optimized out>) at arch/riscv/kernel/ftrace.c:68
3  0xffffffe0002063c0 in ftrace_make_nop (mod=<optimized out>, rec=0xffffffe001221c70 <text_mutex+96>, addr=18446743936272720288) at arch/riscv/kernel/ftrace.c:97
4  0xffffffe0002b13f0 in ftrace_init_nop (rec=<optimized out>, mod=<optimized out>) at ./include/linux/ftrace.h:647
5  ftrace_nop_initialize (rec=<optimized out>, mod=<optimized out>) at kernel/trace/ftrace.c:2619
6  ftrace_update_code (new_pgs=<optimized out>, mod=<optimized out>) at kernel/trace/ftrace.c:3063
7  ftrace_process_locs (mod=<optimized out>, start=<optimized out>, end=<optimized out>) at kernel/trace/ftrace.c:6154
8  0xffffffe00000b6e6 in ftrace_init () at kernel/trace/ftrace.c:6715
9  0xffffffe000001b48 in start_kernel () at init/main.c:888
10 0xffffffe0000010a8 in _start_kernel () at arch/riscv/kernel/head.S:247

Signed-off-by: Guo Ren <guoren@linux.alibaba.com>
Cc: Steven Rostedt <rostedt@goodmis.org>
Cc: Ingo Molnar <mingo@redhat.com>
---
 kernel/trace/ftrace.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
index 1903b80..4b48b88 100644
--- a/kernel/trace/ftrace.c
+++ b/kernel/trace/ftrace.c
@@ -26,6 +26,7 @@
 #include <linux/uaccess.h>
 #include <linux/bsearch.h>
 #include <linux/module.h>
+#include <linux/memory.h>
 #include <linux/ftrace.h>
 #include <linux/sysctl.h>
 #include <linux/slab.h>
@@ -6712,9 +6713,11 @@ void __init ftrace_init(void)
 
 	last_ftrace_enabled = ftrace_enabled = 1;
 
+	mutex_lock(&text_mutex);
 	ret = ftrace_process_locs(NULL,
 				  __start_mcount_loc,
 				  __stop_mcount_loc);
+	mutex_unlock(&text_mutex);
 
 	pr_info("ftrace: allocated %ld pages with %ld groups\n",
 		ftrace_number_of_pages, ftrace_number_of_groups);
-- 
2.7.4

Re: [PATCH] ftrace: Fixup lockdep assert held of text_mutex

[Steven Rostedt]

On Thu,  6 Aug 2020 14:50:54 +0000
guoren@kernel.org wrote:

> From: Guo Ren <guoren@linux.alibaba.com>
> 
> The function ftrace_process_locs() will modify text code, so we
> should give a text_mutex lock. Because some arch's patch code
> will assert held of text_mutex even during start_kernel->
> ftrace_init().

NAK.

This looks like a bug in the lockdep_assert_held() in whatever arch
(riscv) is running.

> 
> backtrace log:
>    assert by lockdep_assert_held(&text_mutex)
> 0  patch_insn_write (addr=0xffffffe0000010fc <set_reset_devices+10>, insn=0xffffffe001203eb8, len=8) at arch/riscv/kernel/patch.c:63
> 1  0xffffffe0002042ec in patch_text_nosync (addr=<optimized out>, insns=<optimized out>, len=<optimized out>) at arch/riscv/kernel/patch.c:93
> 2  0xffffffe00020628e in __ftrace_modify_call (hook_pos=<optimized out>, target=<optimized out>, enable=<optimized out>) at arch/riscv/kernel/ftrace.c:68
> 3  0xffffffe0002063c0 in ftrace_make_nop (mod=<optimized out>, rec=0xffffffe001221c70 <text_mutex+96>, addr=18446743936272720288) at arch/riscv/kernel/ftrace.c:97
> 4  0xffffffe0002b13f0 in ftrace_init_nop (rec=<optimized out>, mod=<optimized out>) at ./include/linux/ftrace.h:647
> 5  ftrace_nop_initialize (rec=<optimized out>, mod=<optimized out>) at kernel/trace/ftrace.c:2619
> 6  ftrace_update_code (new_pgs=<optimized out>, mod=<optimized out>) at kernel/trace/ftrace.c:3063
> 7  ftrace_process_locs (mod=<optimized out>, start=<optimized out>, end=<optimized out>) at kernel/trace/ftrace.c:6154
> 8  0xffffffe00000b6e6 in ftrace_init () at kernel/trace/ftrace.c:6715
> 9  0xffffffe000001b48 in start_kernel () at init/main.c:888
> 10 0xffffffe0000010a8 in _start_kernel () at arch/riscv/kernel/head.S:247
> 
> Signed-off-by: Guo Ren <guoren@linux.alibaba.com>
> Cc: Steven Rostedt <rostedt@goodmis.org>
> Cc: Ingo Molnar <mingo@redhat.com>
> ---
>  kernel/trace/ftrace.c | 3 +++
>  1 file changed, 3 insertions(+)
> 
> diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
> index 1903b80..4b48b88 100644
> --- a/kernel/trace/ftrace.c
> +++ b/kernel/trace/ftrace.c
> @@ -26,6 +26,7 @@
>  #include <linux/uaccess.h>
>  #include <linux/bsearch.h>
>  #include <linux/module.h>
> +#include <linux/memory.h>
>  #include <linux/ftrace.h>
>  #include <linux/sysctl.h>
>  #include <linux/slab.h>
> @@ -6712,9 +6713,11 @@ void __init ftrace_init(void)

ftrace_init() is called before SMP is initialized. Nothing else should
be running here. That means grabbing a mutex is useless.

-- Steve


>  
>  	last_ftrace_enabled = ftrace_enabled = 1;
>  
> +	mutex_lock(&text_mutex);
>  	ret = ftrace_process_locs(NULL,
>  				  __start_mcount_loc,
>  				  __stop_mcount_loc);
> +	mutex_unlock(&text_mutex);
>  
>  	pr_info("ftrace: allocated %ld pages with %ld groups\n",
>  		ftrace_number_of_pages, ftrace_number_of_groups);

Re: [PATCH] ftrace: Fixup lockdep assert held of text_mutex

[Guo Ren]

On Thu, Aug 6, 2020 at 11:48 PM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Thu,  6 Aug 2020 14:50:54 +0000
> guoren@kernel.org wrote:
>
> > From: Guo Ren <guoren@linux.alibaba.com>
> >
> > The function ftrace_process_locs() will modify text code, so we
> > should give a text_mutex lock. Because some arch's patch code
> > will assert held of text_mutex even during start_kernel->
> > ftrace_init().
>
> NAK.
>
> This looks like a bug in the lockdep_assert_held() in whatever arch
> (riscv) is running.
Seems you think it's a bug of arch implementation with the wrong usage
of text_mutex?

Also @riscv maintainer,
How about modifying it in riscv's code? we still need to solve it.

----------------
diff --git a/arch/riscv/include/asm/ftrace.h b/arch/riscv/include/asm/ftrace.h
index ace8a6e..fb266c3 100644
--- a/arch/riscv/include/asm/ftrace.h
+++ b/arch/riscv/include/asm/ftrace.h
@@ -23,6 +23,12 @@ static inline unsigned long
ftrace_call_adjust(unsigned long addr)

 struct dyn_arch_ftrace {
 };
+
+#ifdef CONFIG_DYNAMIC_FTRACE
+struct dyn_ftrace;
+int ftrace_init_nop(struct module *mod, struct dyn_ftrace *rec);
+#define ftrace_init_nop ftrace_init_nop
+#endif
 #endif

 #ifdef CONFIG_DYNAMIC_FTRACE
diff --git a/arch/riscv/kernel/ftrace.c b/arch/riscv/kernel/ftrace.c
index 2ff63d0..9e9f7c0 100644
--- a/arch/riscv/kernel/ftrace.c
+++ b/arch/riscv/kernel/ftrace.c
@@ -97,6 +97,17 @@ int ftrace_make_nop(struct module *mod, struct
dyn_ftrace *rec,
        return __ftrace_modify_call(rec->ip, addr, false);
 }

+int ftrace_init_nop(struct module *mod, struct dyn_ftrace *rec)
+{
+       int ret;
+
+       mutex_lock(&text_mutex);
+       ret = ftrace_make_nop(mod, rec, MCOUNT_ADDR);
+       mutex_unlock(&text_mutex);
+
+       return ret;
+}
+
 int ftrace_update_ftrace_func(ftrace_func_t func)
 {
        int ret = __ftrace_modify_call((unsigned long)&ftrace_call,
-------------------

>
> >
> > backtrace log:
> >    assert by lockdep_assert_held(&text_mutex)
> > 0  patch_insn_write (addr=0xffffffe0000010fc <set_reset_devices+10>, insn=0xffffffe001203eb8, len=8) at arch/riscv/kernel/patch.c:63
> > 1  0xffffffe0002042ec in patch_text_nosync (addr=<optimized out>, insns=<optimized out>, len=<optimized out>) at arch/riscv/kernel/patch.c:93
> > 2  0xffffffe00020628e in __ftrace_modify_call (hook_pos=<optimized out>, target=<optimized out>, enable=<optimized out>) at arch/riscv/kernel/ftrace.c:68
> > 3  0xffffffe0002063c0 in ftrace_make_nop (mod=<optimized out>, rec=0xffffffe001221c70 <text_mutex+96>, addr=18446743936272720288) at arch/riscv/kernel/ftrace.c:97
> > 4  0xffffffe0002b13f0 in ftrace_init_nop (rec=<optimized out>, mod=<optimized out>) at ./include/linux/ftrace.h:647
> > 5  ftrace_nop_initialize (rec=<optimized out>, mod=<optimized out>) at kernel/trace/ftrace.c:2619
> > 6  ftrace_update_code (new_pgs=<optimized out>, mod=<optimized out>) at kernel/trace/ftrace.c:3063
> > 7  ftrace_process_locs (mod=<optimized out>, start=<optimized out>, end=<optimized out>) at kernel/trace/ftrace.c:6154
> > 8  0xffffffe00000b6e6 in ftrace_init () at kernel/trace/ftrace.c:6715
> > 9  0xffffffe000001b48 in start_kernel () at init/main.c:888
> > 10 0xffffffe0000010a8 in _start_kernel () at arch/riscv/kernel/head.S:247
> >
> > Signed-off-by: Guo Ren <guoren@linux.alibaba.com>
> > Cc: Steven Rostedt <rostedt@goodmis.org>
> > Cc: Ingo Molnar <mingo@redhat.com>
> > ---
> >  kernel/trace/ftrace.c | 3 +++
> >  1 file changed, 3 insertions(+)
> >
> > diff --git a/kernel/trace/ftrace.c b/kernel/trace/ftrace.c
> > index 1903b80..4b48b88 100644
> > --- a/kernel/trace/ftrace.c
> > +++ b/kernel/trace/ftrace.c
> > @@ -26,6 +26,7 @@
> >  #include <linux/uaccess.h>
> >  #include <linux/bsearch.h>
> >  #include <linux/module.h>
> > +#include <linux/memory.h>
> >  #include <linux/ftrace.h>
> >  #include <linux/sysctl.h>
> >  #include <linux/slab.h>
> > @@ -6712,9 +6713,11 @@ void __init ftrace_init(void)
>
> ftrace_init() is called before SMP is initialized. Nothing else should
> be running here. That means grabbing a mutex is useless.
I don't agree, ftrace_init are modifying kernel text, so we should
give the lock of text_mutex to keep semantic consistency.


>
> -- Steve
>
>
> >
> >       last_ftrace_enabled = ftrace_enabled = 1;
> >
> > +     mutex_lock(&text_mutex);
> >       ret = ftrace_process_locs(NULL,
> >                                 __start_mcount_loc,
> >                                 __stop_mcount_loc);
> > +     mutex_unlock(&text_mutex);
> >
> >       pr_info("ftrace: allocated %ld pages with %ld groups\n",
> >               ftrace_number_of_pages, ftrace_number_of_groups);
>


-- 
Best Regards
 Guo Ren

ML: https://lore.kernel.org/linux-csky/

Re: [PATCH] ftrace: Fixup lockdep assert held of text_mutex

[Steven Rostedt]

On Fri, 7 Aug 2020 10:59:16 +0800
Guo Ren <guoren@kernel.org> wrote:
> >
> > This looks like a bug in the lockdep_assert_held() in whatever arch
> > (riscv) is running.  
> Seems you think it's a bug of arch implementation with the wrong usage
> of text_mutex?
> 
> Also @riscv maintainer,
> How about modifying it in riscv's code? we still need to solve it.
> 
> ----------------
> diff --git a/arch/riscv/include/asm/ftrace.h b/arch/riscv/include/asm/ftrace.h
> index ace8a6e..fb266c3 100644
> --- a/arch/riscv/include/asm/ftrace.h
> +++ b/arch/riscv/include/asm/ftrace.h
> @@ -23,6 +23,12 @@ static inline unsigned long
> ftrace_call_adjust(unsigned long addr)
> 
>  struct dyn_arch_ftrace {
>  };
> +
> +#ifdef CONFIG_DYNAMIC_FTRACE
> +struct dyn_ftrace;
> +int ftrace_init_nop(struct module *mod, struct dyn_ftrace *rec);
> +#define ftrace_init_nop ftrace_init_nop
> +#endif
>  #endif
> 
>  #ifdef CONFIG_DYNAMIC_FTRACE
> diff --git a/arch/riscv/kernel/ftrace.c b/arch/riscv/kernel/ftrace.c
> index 2ff63d0..9e9f7c0 100644
> --- a/arch/riscv/kernel/ftrace.c
> +++ b/arch/riscv/kernel/ftrace.c
> @@ -97,6 +97,17 @@ int ftrace_make_nop(struct module *mod, struct
> dyn_ftrace *rec,
>         return __ftrace_modify_call(rec->ip, addr, false);
>  }
> 
> +int ftrace_init_nop(struct module *mod, struct dyn_ftrace *rec)
> +{
> +       int ret;
> +
> +       mutex_lock(&text_mutex);
> +       ret = ftrace_make_nop(mod, rec, MCOUNT_ADDR);

Looking at x86, we have the following code:

static int ftrace_poke_late = 0;

int ftrace_arch_code_modify_prepare(void)
    __acquires(&text_mutex)
{
	/*
	 * Need to grab text_mutex to prevent a race from module loading
	 * and live kernel patching from changing the text permissions while
	 * ftrace has it set to "read/write".
	 */
	mutex_lock(&text_mutex);
	ftrace_poke_late = 1;
	return 0;
}

int ftrace_arch_code_modify_post_process(void)
    __releases(&text_mutex)
{
	/*
	 * ftrace_make_{call,nop}() may be called during
	 * module load, and we need to finish the text_poke_queue()
	 * that they do, here.
	 */
	text_poke_finish();
	ftrace_poke_late = 0;
	mutex_unlock(&text_mutex);
	return 0;
}

And if ftrace_poke_late is not set, then ftrace_make_nop() does direct
modification (calls text_poke_early(), which is basically a memcpy).

This path doesn't have any checks against text_mutex being held,
because it only happens at boot up.

> +       mutex_unlock(&text_mutex);
> +
> +       return ret;
> +}
> +
>  int ftrace_update_ftrace_func(ftrace_func_t func)
>  {
>         int ret = __ftrace_modify_call((unsigned long)&ftrace_call,
> -------------------
> 
> > > --- a/kernel/trace/ftrace.c
> > > +++ b/kernel/trace/ftrace.c
> > > @@ -26,6 +26,7 @@
> > >  #include <linux/uaccess.h>
> > >  #include <linux/bsearch.h>
> > >  #include <linux/module.h>
> > > +#include <linux/memory.h>
> > >  #include <linux/ftrace.h>
> > >  #include <linux/sysctl.h>
> > >  #include <linux/slab.h>
> > > @@ -6712,9 +6713,11 @@ void __init ftrace_init(void)  
> >
> > ftrace_init() is called before SMP is initialized. Nothing else should
> > be running here. That means grabbing a mutex is useless.  
> I don't agree, ftrace_init are modifying kernel text, so we should
> give the lock of text_mutex to keep semantic consistency.


Did you test your patch on x86 with lockdep?

ftrace_process_locs() grabs the ftrace_lock, which I believe is held
when text_mutex is taken in other locations. So this will probably not
work anyway.

text_mutex isn't to be taken at the ftrace level.

-- Steve

Re: [PATCH] ftrace: Fixup lockdep assert held of text_mutex

[Guo Ren]

On Fri, Aug 7, 2020 at 12:01 PM Steven Rostedt <rostedt@goodmis.org> wrote:
>
> On Fri, 7 Aug 2020 10:59:16 +0800
> Guo Ren <guoren@kernel.org> wrote:
> > >
> > > This looks like a bug in the lockdep_assert_held() in whatever arch
> > > (riscv) is running.
> > Seems you think it's a bug of arch implementation with the wrong usage
> > of text_mutex?
> >
> > Also @riscv maintainer,
> > How about modifying it in riscv's code? we still need to solve it.
> >
> > ----------------
> > diff --git a/arch/riscv/include/asm/ftrace.h b/arch/riscv/include/asm/ftrace.h
> > index ace8a6e..fb266c3 100644
> > --- a/arch/riscv/include/asm/ftrace.h
> > +++ b/arch/riscv/include/asm/ftrace.h
> > @@ -23,6 +23,12 @@ static inline unsigned long
> > ftrace_call_adjust(unsigned long addr)
> >
> >  struct dyn_arch_ftrace {
> >  };
> > +
> > +#ifdef CONFIG_DYNAMIC_FTRACE
> > +struct dyn_ftrace;
> > +int ftrace_init_nop(struct module *mod, struct dyn_ftrace *rec);
> > +#define ftrace_init_nop ftrace_init_nop
> > +#endif
> >  #endif
> >
> >  #ifdef CONFIG_DYNAMIC_FTRACE
> > diff --git a/arch/riscv/kernel/ftrace.c b/arch/riscv/kernel/ftrace.c
> > index 2ff63d0..9e9f7c0 100644
> > --- a/arch/riscv/kernel/ftrace.c
> > +++ b/arch/riscv/kernel/ftrace.c
> > @@ -97,6 +97,17 @@ int ftrace_make_nop(struct module *mod, struct
> > dyn_ftrace *rec,
> >         return __ftrace_modify_call(rec->ip, addr, false);
> >  }
> >
> > +int ftrace_init_nop(struct module *mod, struct dyn_ftrace *rec)
> > +{
> > +       int ret;
> > +
> > +       mutex_lock(&text_mutex);
> > +       ret = ftrace_make_nop(mod, rec, MCOUNT_ADDR);
>
> Looking at x86, we have the following code:
>
> static int ftrace_poke_late = 0;
>
> int ftrace_arch_code_modify_prepare(void)
>     __acquires(&text_mutex)
> {
>         /*
>          * Need to grab text_mutex to prevent a race from module loading
>          * and live kernel patching from changing the text permissions while
>          * ftrace has it set to "read/write".
>          */
>         mutex_lock(&text_mutex);
>         ftrace_poke_late = 1;
>         return 0;
> }
>
> int ftrace_arch_code_modify_post_process(void)
>     __releases(&text_mutex)
> {
>         /*
>          * ftrace_make_{call,nop}() may be called during
>          * module load, and we need to finish the text_poke_queue()
>          * that they do, here.
>          */
>         text_poke_finish();
>         ftrace_poke_late = 0;
>         mutex_unlock(&text_mutex);
>         return 0;
> }
>
> And if ftrace_poke_late is not set, then ftrace_make_nop() does direct
> modification (calls text_poke_early(), which is basically a memcpy).
>
> This path doesn't have any checks against text_mutex being held,
> because it only happens at boot up.
The solution is ok for me, but I want to get riscv maintainer's
opinion before the next patch.
@Paul Walmsley
@Palmer Dabbelt

>
> > +       mutex_unlock(&text_mutex);
> > +
> > +       return ret;
> > +}
> > +
> >  int ftrace_update_ftrace_func(ftrace_func_t func)
> >  {
> >         int ret = __ftrace_modify_call((unsigned long)&ftrace_call,
> > -------------------
> >
> > > > --- a/kernel/trace/ftrace.c
> > > > +++ b/kernel/trace/ftrace.c
> > > > @@ -26,6 +26,7 @@
> > > >  #include <linux/uaccess.h>
> > > >  #include <linux/bsearch.h>
> > > >  #include <linux/module.h>
> > > > +#include <linux/memory.h>
> > > >  #include <linux/ftrace.h>
> > > >  #include <linux/sysctl.h>
> > > >  #include <linux/slab.h>
> > > > @@ -6712,9 +6713,11 @@ void __init ftrace_init(void)
> > >
> > > ftrace_init() is called before SMP is initialized. Nothing else should
> > > be running here. That means grabbing a mutex is useless.
> > I don't agree, ftrace_init are modifying kernel text, so we should
> > give the lock of text_mutex to keep semantic consistency.
>
>
> Did you test your patch on x86 with lockdep?
Ah.., no :P

>
> ftrace_process_locs() grabs the ftrace_lock, which I believe is held
> when text_mutex is taken in other locations. So this will probably not
> work anyway.
>
> text_mutex isn't to be taken at the ftrace level.
Yes, currently it seemed only to be used by kernel/kprobes.c.

-- 
Best Regards
 Guo Ren

ML: https://lore.kernel.org/linux-csky/

Re: [PATCH] ftrace: Fixup lockdep assert held of text_mutex

[Palmer Dabbelt]

On Thu, 06 Aug 2020 22:01:01 PDT (-0700), guoren@kernel.org wrote:
> On Fri, Aug 7, 2020 at 12:01 PM Steven Rostedt <rostedt@goodmis.org> wrote:
>>
>> On Fri, 7 Aug 2020 10:59:16 +0800
>> Guo Ren <guoren@kernel.org> wrote:
>> > >
>> > > This looks like a bug in the lockdep_assert_held() in whatever arch
>> > > (riscv) is running.
>> > Seems you think it's a bug of arch implementation with the wrong usage
>> > of text_mutex?
>> >
>> > Also @riscv maintainer,
>> > How about modifying it in riscv's code? we still need to solve it.
>> >
>> > ----------------
>> > diff --git a/arch/riscv/include/asm/ftrace.h b/arch/riscv/include/asm/ftrace.h
>> > index ace8a6e..fb266c3 100644
>> > --- a/arch/riscv/include/asm/ftrace.h
>> > +++ b/arch/riscv/include/asm/ftrace.h
>> > @@ -23,6 +23,12 @@ static inline unsigned long
>> > ftrace_call_adjust(unsigned long addr)
>> >
>> >  struct dyn_arch_ftrace {
>> >  };
>> > +
>> > +#ifdef CONFIG_DYNAMIC_FTRACE
>> > +struct dyn_ftrace;
>> > +int ftrace_init_nop(struct module *mod, struct dyn_ftrace *rec);
>> > +#define ftrace_init_nop ftrace_init_nop
>> > +#endif
>> >  #endif
>> >
>> >  #ifdef CONFIG_DYNAMIC_FTRACE
>> > diff --git a/arch/riscv/kernel/ftrace.c b/arch/riscv/kernel/ftrace.c
>> > index 2ff63d0..9e9f7c0 100644
>> > --- a/arch/riscv/kernel/ftrace.c
>> > +++ b/arch/riscv/kernel/ftrace.c
>> > @@ -97,6 +97,17 @@ int ftrace_make_nop(struct module *mod, struct
>> > dyn_ftrace *rec,
>> >         return __ftrace_modify_call(rec->ip, addr, false);
>> >  }
>> >
>> > +int ftrace_init_nop(struct module *mod, struct dyn_ftrace *rec)
>> > +{
>> > +       int ret;
>> > +
>> > +       mutex_lock(&text_mutex);
>> > +       ret = ftrace_make_nop(mod, rec, MCOUNT_ADDR);
>>
>> Looking at x86, we have the following code:
>>
>> static int ftrace_poke_late = 0;
>>
>> int ftrace_arch_code_modify_prepare(void)
>>     __acquires(&text_mutex)
>> {
>>         /*
>>          * Need to grab text_mutex to prevent a race from module loading
>>          * and live kernel patching from changing the text permissions while
>>          * ftrace has it set to "read/write".
>>          */
>>         mutex_lock(&text_mutex);
>>         ftrace_poke_late = 1;
>>         return 0;
>> }
>>
>> int ftrace_arch_code_modify_post_process(void)
>>     __releases(&text_mutex)
>> {
>>         /*
>>          * ftrace_make_{call,nop}() may be called during
>>          * module load, and we need to finish the text_poke_queue()
>>          * that they do, here.
>>          */
>>         text_poke_finish();
>>         ftrace_poke_late = 0;
>>         mutex_unlock(&text_mutex);
>>         return 0;
>> }
>>
>> And if ftrace_poke_late is not set, then ftrace_make_nop() does direct
>> modification (calls text_poke_early(), which is basically a memcpy).
>>
>> This path doesn't have any checks against text_mutex being held,
>> because it only happens at boot up.
> The solution is ok for me, but I want to get riscv maintainer's
> opinion before the next patch.
> @Paul Walmsley
> @Palmer Dabbelt

Sorry, I'm not really sure what's going on here.  I'm not really seeing code
that matches this in our port right now, so maybe this is aginst some other
tree?  If it's the RISC-V kprobes patch set then I was hoping to take a look at
that tomorrow (or I guess a bit earlier this week, but I had some surprise work
stuff to do).  IIRC there were a handful of races in the last patch set I saw,
but it's been a while so I don't remember for sure.

That said, I certainly wouldn't be surprised if there's a locking bug in our
ftrace stuff.  It'd be way easier for me to figure out what's going on if you
have a concrete suggestion as to how to fix the issues -- even if it's just a
workaround.

>
>>
>> > +       mutex_unlock(&text_mutex);
>> > +
>> > +       return ret;
>> > +}
>> > +
>> >  int ftrace_update_ftrace_func(ftrace_func_t func)
>> >  {
>> >         int ret = __ftrace_modify_call((unsigned long)&ftrace_call,
>> > -------------------
>> >
>> > > > --- a/kernel/trace/ftrace.c
>> > > > +++ b/kernel/trace/ftrace.c
>> > > > @@ -26,6 +26,7 @@
>> > > >  #include <linux/uaccess.h>
>> > > >  #include <linux/bsearch.h>
>> > > >  #include <linux/module.h>
>> > > > +#include <linux/memory.h>
>> > > >  #include <linux/ftrace.h>
>> > > >  #include <linux/sysctl.h>
>> > > >  #include <linux/slab.h>
>> > > > @@ -6712,9 +6713,11 @@ void __init ftrace_init(void)
>> > >
>> > > ftrace_init() is called before SMP is initialized. Nothing else should
>> > > be running here. That means grabbing a mutex is useless.
>> > I don't agree, ftrace_init are modifying kernel text, so we should
>> > give the lock of text_mutex to keep semantic consistency.
>>
>>
>> Did you test your patch on x86 with lockdep?
> Ah.., no :P
>
>>
>> ftrace_process_locs() grabs the ftrace_lock, which I believe is held
>> when text_mutex is taken in other locations. So this will probably not
>> work anyway.
>>
>> text_mutex isn't to be taken at the ftrace level.
> Yes, currently it seemed only to be used by kernel/kprobes.c.

Re: [PATCH] ftrace: Fixup lockdep assert held of text_mutex

[Steven Rostedt]

On Wed, 12 Aug 2020 22:13:19 -0700 (PDT)
Palmer Dabbelt <palmer@dabbelt.com> wrote:

> Sorry, I'm not really sure what's going on here.  I'm not really seeing code
> that matches this in our port right now, so maybe this is aginst some other
> tree?  If it's the RISC-V kprobes patch set then I was hoping to take a look at
> that tomorrow (or I guess a bit earlier this week, but I had some surprise work
> stuff to do).  IIRC there were a handful of races in the last patch set I saw,
> but it's been a while so I don't remember for sure.
> 
> That said, I certainly wouldn't be surprised if there's a locking bug in our
> ftrace stuff.  It'd be way easier for me to figure out what's going on if you
> have a concrete suggestion as to how to fix the issues -- even if it's just a
> workaround.

The issue is actually quite basic.

ftrace_init_nop() is called quite early in boot up and never called
again. It's called before SMP is set up, so it's on a single CPU, and
no worries about synchronization with other CPUs is needed.

On x86, it is called before text_poke() is initialized (which is used
to synchronize code updates across CPUs), and thus can't be called.
There's a "text_poke_early()" that is used instead, which is basically
just a memcpy().

Now, if ftrace_init_nop() is not defined by the architecture, it is a
simple call to ftrace_make_nop(), which is also used to disable ftrace
callbacks.

The issue is that we have the following path on riscv:

 ftrace_init_nop()
   ftrace_make_nop()
     __ftrace_modify_call()
       patch_text_nosync()
         patch_insn_write()
           lockdep_assert_held(&text_mutex);

Boom! text_mutex is not held, and lockdep complains.


The difference between ftrace_make_nop() being called by
ftrace_init_nop() and being called later to disable function tracing is
that the latter will have:


	ftrace_arch_code_modify_prepare();
	[..]
	ftrace_make_nop();
	[..]
	ftrace_arch_code_modify_post_process();

and the former will not have those called.

On x86, we handle the two different cases with:


static int ftrace_poke_late = 0;

int ftrace_arch_code_modify_prepare(void)
{
	mutex_lock(&text_mutex);
	ftrace_poke_late = 1;
	return 0;
}

int ftrace_arch_code_modify_post_process(void)
{
	text_poke_finish();
	ftrace_poke_late = 0;
	mutex_unlock(&text_mutex);
}

Although, the post_process() probably doesn't even need to set
ftrace_poke_late back to zero.

Then in ftrace_make_nop(), we have:

  ftrace_make_nop()
    ftrace_modify_code_direct()
      if (ftrace_poke_late)
        text_poke_queue(...); // this checks if text_mutex is held
      else
        text_poke_early(...); // is basically just memcpy, no test on text_mutex.

The two solutions for riscv, is either to implement the same thing as
above, or you can create your own ftrace_init_nop() to take the
text_mutex before calling ftrace_make_nop(), and that should work too.

-- Steve

Re: [PATCH] ftrace: Fixup lockdep assert held of text_mutex

[Palmer Dabbelt]

On Thu, 13 Aug 2020 08:37:43 PDT (-0700), rostedt@goodmis.org wrote:
> On Wed, 12 Aug 2020 22:13:19 -0700 (PDT)
> Palmer Dabbelt <palmer@dabbelt.com> wrote:
>
>> Sorry, I'm not really sure what's going on here.  I'm not really seeing code
>> that matches this in our port right now, so maybe this is aginst some other
>> tree?  If it's the RISC-V kprobes patch set then I was hoping to take a look at
>> that tomorrow (or I guess a bit earlier this week, but I had some surprise work
>> stuff to do).  IIRC there were a handful of races in the last patch set I saw,
>> but it's been a while so I don't remember for sure.
>>
>> That said, I certainly wouldn't be surprised if there's a locking bug in our
>> ftrace stuff.  It'd be way easier for me to figure out what's going on if you
>> have a concrete suggestion as to how to fix the issues -- even if it's just a
>> workaround.
>
> The issue is actually quite basic.
>
> ftrace_init_nop() is called quite early in boot up and never called
> again. It's called before SMP is set up, so it's on a single CPU, and
> no worries about synchronization with other CPUs is needed.
>
> On x86, it is called before text_poke() is initialized (which is used
> to synchronize code updates across CPUs), and thus can't be called.
> There's a "text_poke_early()" that is used instead, which is basically
> just a memcpy().
>
> Now, if ftrace_init_nop() is not defined by the architecture, it is a
> simple call to ftrace_make_nop(), which is also used to disable ftrace
> callbacks.
>
> The issue is that we have the following path on riscv:
>
>  ftrace_init_nop()
>    ftrace_make_nop()
>      __ftrace_modify_call()
>        patch_text_nosync()
>          patch_insn_write()
>            lockdep_assert_held(&text_mutex);
>
> Boom! text_mutex is not held, and lockdep complains.
>
>
> The difference between ftrace_make_nop() being called by
> ftrace_init_nop() and being called later to disable function tracing is
> that the latter will have:
>
>
> 	ftrace_arch_code_modify_prepare();
> 	[..]
> 	ftrace_make_nop();
> 	[..]
> 	ftrace_arch_code_modify_post_process();
>
> and the former will not have those called.
>
> On x86, we handle the two different cases with:
>
>
> static int ftrace_poke_late = 0;
>
> int ftrace_arch_code_modify_prepare(void)
> {
> 	mutex_lock(&text_mutex);
> 	ftrace_poke_late = 1;
> 	return 0;
> }
>
> int ftrace_arch_code_modify_post_process(void)
> {
> 	text_poke_finish();
> 	ftrace_poke_late = 0;
> 	mutex_unlock(&text_mutex);
> }
>
> Although, the post_process() probably doesn't even need to set
> ftrace_poke_late back to zero.
>
> Then in ftrace_make_nop(), we have:
>
>   ftrace_make_nop()
>     ftrace_modify_code_direct()
>       if (ftrace_poke_late)
>         text_poke_queue(...); // this checks if text_mutex is held
>       else
>         text_poke_early(...); // is basically just memcpy, no test on text_mutex.
>
> The two solutions for riscv, is either to implement the same thing as
> above, or you can create your own ftrace_init_nop() to take the
> text_mutex before calling ftrace_make_nop(), and that should work too.

Ya, thanks, that's a pretty straight-forward issue.  I've To'd you on a patch,
but it's essentially just exactly what you suggested so I doubt it's that
interesting.

I pointed out in the patch notes that it seems reasonable to have the generic
code handle this case, would you be opposed to doing it that way?

Re: [PATCH] ftrace: Fixup lockdep assert held of text_mutex

[Steven Rostedt]

On Mon, 24 Aug 2020 17:29:32 -0700 (PDT)
Palmer Dabbelt <palmer@dabbelt.com> wrote:

> I pointed out in the patch notes that it seems reasonable to have the generic
> code handle this case, would you be opposed to doing it that way?

For now, lets hold off and see if other archs start to do it the same
way. Then we should look into making it more generic. It's an easy
enough fix per arch, so there's no urgency to this.

-- Steve