riscv/ftrace: fix ftrace_modify_call bug

Message ID 20221122075440.1165172-1-suagrfillet@gmail.com
State New
Headers
Series riscv/ftrace: fix ftrace_modify_call bug |

Commit Message

Song Shuai Nov. 22, 2022, 7:54 a.m. UTC
  With this commit (riscv: ftrace: Reduce the detour code size to half)
patched, ftrace bug occurred When hosting kprobe and function tracer
at the same function.

Obviously, the variable caller in ftrace_modify_call was assigned by
rec->ip with 4 offset failing the code replacing at function entry.
And the caller should be assigned by rec->ip directly to indicate
the function entry.

The following is the ftrace bug log.

```
[  419.632855] 00000000f8776803: expected (ffe00297 1a4282e7) but got (1a8282e7 f0227179)
[  419.633390] ------------[ ftrace bug ]------------
[  419.633553] ftrace failed to modify
[  419.633569] [<ffffffff802091cc>] kernel_read+0x0/0x52
[  419.633863]  actual:   97:02:e0:ff:e7:82:82:1a
[  419.634087] Updating ftrace call site to call a different ftrace function
[  419.634279] ftrace record flags: e0000002
[  419.634487]  (2) R
[  419.634487]  expected tramp: ffffffff800093cc
[  419.634935] ------------[ cut here ]------------
```

Signed-off-by: Song Shuai <suagrfillet@gmail.com>
---
 arch/riscv/kernel/ftrace.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)
  

Comments

Guo Ren Nov. 22, 2022, 8:57 a.m. UTC | #1
On Tue, Nov 22, 2022 at 3:54 PM Song Shuai <suagrfillet@gmail.com> wrote:
>
> With this commit (riscv: ftrace: Reduce the detour code size to half)
> patched, ftrace bug occurred When hosting kprobe and function tracer
> at the same function.
>
> Obviously, the variable caller in ftrace_modify_call was assigned by
> rec->ip with 4 offset failing the code replacing at function entry.
> And the caller should be assigned by rec->ip directly to indicate
> the function entry.
Thank you, it's my fault, but I think the problem is:

Before (riscv: ftrace: Reduce the detour code size to half)
     0: REG_S  ra, -SZREG(sp)
     4: auipc  ra, ?          <- We need "rec->ip + 4" here
     8: jalr   ?(ra)
    12: REG_L  ra, -SZREG(sp)

After (riscv: ftrace: Reduce the detour code size to half)
     0: auipc  t0, ?  <- We needn't "rec->ip + 4" anymore
     4: jalr   t0, ?(t0)

I copied rec->ip + 4 blindly, then caused the bug. Right?

>
> The following is the ftrace bug log.
>
> ```
> [  419.632855] 00000000f8776803: expected (ffe00297 1a4282e7) but got (1a8282e7 f0227179)
> [  419.633390] ------------[ ftrace bug ]------------
> [  419.633553] ftrace failed to modify
> [  419.633569] [<ffffffff802091cc>] kernel_read+0x0/0x52
> [  419.633863]  actual:   97:02:e0:ff:e7:82:82:1a
> [  419.634087] Updating ftrace call site to call a different ftrace function
> [  419.634279] ftrace record flags: e0000002
> [  419.634487]  (2) R
> [  419.634487]  expected tramp: ffffffff800093cc
> [  419.634935] ------------[ cut here ]------------
> ```
>
> Signed-off-by: Song Shuai <suagrfillet@gmail.com>
> ---
>  arch/riscv/kernel/ftrace.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
>
> diff --git a/arch/riscv/kernel/ftrace.c b/arch/riscv/kernel/ftrace.c
> index 8c77f236fc71..61b24d767e2e 100644
> --- a/arch/riscv/kernel/ftrace.c
> +++ b/arch/riscv/kernel/ftrace.c
> @@ -132,7 +132,7 @@ int ftrace_modify_call(struct dyn_ftrace *rec, unsigned long old_addr,
>                        unsigned long addr)
>  {
>         unsigned int call[2];
> -       unsigned long caller = rec->ip + 4;
> +       unsigned long caller = rec->ip;
>         int ret;
>
>         make_call_t0(caller, old_addr, call);
> --
> 2.20.1
>
  
Conor Dooley Nov. 22, 2022, 8:57 a.m. UTC | #2
On Tue, Nov 22, 2022 at 03:54:40PM +0800, Song Shuai wrote:
> With this commit (riscv: ftrace: Reduce the detour code size to half)

AFAICT the above patch has not been applied & this patch here should be
folded into the offending patch?
I've marked this one as "Not Applicable" in patchwork as a result, but
let me know if that is an incorrect assumption.

Thanks,
Conor.

> patched, ftrace bug occurred When hosting kprobe and function tracer
> at the same function.
> 
> Obviously, the variable caller in ftrace_modify_call was assigned by
> rec->ip with 4 offset failing the code replacing at function entry.
> And the caller should be assigned by rec->ip directly to indicate
> the function entry.
> 
> The following is the ftrace bug log.
> 
> ```
> [  419.632855] 00000000f8776803: expected (ffe00297 1a4282e7) but got (1a8282e7 f0227179)
> [  419.633390] ------------[ ftrace bug ]------------
> [  419.633553] ftrace failed to modify
> [  419.633569] [<ffffffff802091cc>] kernel_read+0x0/0x52
> [  419.633863]  actual:   97:02:e0:ff:e7:82:82:1a
> [  419.634087] Updating ftrace call site to call a different ftrace function
> [  419.634279] ftrace record flags: e0000002
> [  419.634487]  (2) R
> [  419.634487]  expected tramp: ffffffff800093cc
> [  419.634935] ------------[ cut here ]------------
> ```
> 
> Signed-off-by: Song Shuai <suagrfillet@gmail.com>
> ---
>  arch/riscv/kernel/ftrace.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/arch/riscv/kernel/ftrace.c b/arch/riscv/kernel/ftrace.c
> index 8c77f236fc71..61b24d767e2e 100644
> --- a/arch/riscv/kernel/ftrace.c
> +++ b/arch/riscv/kernel/ftrace.c
> @@ -132,7 +132,7 @@ int ftrace_modify_call(struct dyn_ftrace *rec, unsigned long old_addr,
>  		       unsigned long addr)
>  {
>  	unsigned int call[2];
> -	unsigned long caller = rec->ip + 4;
> +	unsigned long caller = rec->ip;
>  	int ret;
>  
>  	make_call_t0(caller, old_addr, call);
> -- 
> 2.20.1
>
  
Song Shuai Nov. 22, 2022, 9:11 a.m. UTC | #3
Guo Ren <guoren@kernel.org> 于2022年11月22日周二 08:57写道:
>
> On Tue, Nov 22, 2022 at 3:54 PM Song Shuai <suagrfillet@gmail.com> wrote:
> >
> > With this commit (riscv: ftrace: Reduce the detour code size to half)
> > patched, ftrace bug occurred When hosting kprobe and function tracer
> > at the same function.
> >
> > Obviously, the variable caller in ftrace_modify_call was assigned by
> > rec->ip with 4 offset failing the code replacing at function entry.
> > And the caller should be assigned by rec->ip directly to indicate
> > the function entry.
> Thank you, it's my fault, but I think the problem is:
>
> Before (riscv: ftrace: Reduce the detour code size to half)
>      0: REG_S  ra, -SZREG(sp)
>      4: auipc  ra, ?          <- We need "rec->ip + 4" here
>      8: jalr   ?(ra)
>     12: REG_L  ra, -SZREG(sp)
>
> After (riscv: ftrace: Reduce the detour code size to half)
>      0: auipc  t0, ?  <- We needn't "rec->ip + 4" anymore
>      4: jalr   t0, ?(t0)
>
> I copied rec->ip + 4 blindly, then caused the bug. Right?
>
Yes, you're right.

Here's my simple test case for your convenience.
```
echo kernel_read > set_ftrace_filter
echo function > current_tracer
echo 'p:myp kernel_read' > kprobe_events
echo 1 > events/kprobes/myp/enable # ftrace bug
```
> >
> > The following is the ftrace bug log.
> >
> > ```
> > [  419.632855] 00000000f8776803: expected (ffe00297 1a4282e7) but got (1a8282e7 f0227179)
> > [  419.633390] ------------[ ftrace bug ]------------
> > [  419.633553] ftrace failed to modify
> > [  419.633569] [<ffffffff802091cc>] kernel_read+0x0/0x52
> > [  419.633863]  actual:   97:02:e0:ff:e7:82:82:1a
> > [  419.634087] Updating ftrace call site to call a different ftrace function
> > [  419.634279] ftrace record flags: e0000002
> > [  419.634487]  (2) R
> > [  419.634487]  expected tramp: ffffffff800093cc
> > [  419.634935] ------------[ cut here ]------------
> > ```
> >
> > Signed-off-by: Song Shuai <suagrfillet@gmail.com>
> > ---
> >  arch/riscv/kernel/ftrace.c | 2 +-
> >  1 file changed, 1 insertion(+), 1 deletion(-)
> >
> > diff --git a/arch/riscv/kernel/ftrace.c b/arch/riscv/kernel/ftrace.c
> > index 8c77f236fc71..61b24d767e2e 100644
> > --- a/arch/riscv/kernel/ftrace.c
> > +++ b/arch/riscv/kernel/ftrace.c
> > @@ -132,7 +132,7 @@ int ftrace_modify_call(struct dyn_ftrace *rec, unsigned long old_addr,
> >                        unsigned long addr)
> >  {
> >         unsigned int call[2];
> > -       unsigned long caller = rec->ip + 4;
> > +       unsigned long caller = rec->ip;
> >         int ret;
> >
> >         make_call_t0(caller, old_addr, call);
> > --
> > 2.20.1
> >
>
>
> --
> Best Regards
>  Guo Ren
Thanks,
Song
  
Song Shuai Nov. 22, 2022, 9:46 a.m. UTC | #4
Conor Dooley <conor.dooley@microchip.com> 于2022年11月22日周二 08:57写道:
>
> On Tue, Nov 22, 2022 at 03:54:40PM +0800, Song Shuai wrote:
> > With this commit (riscv: ftrace: Reduce the detour code size to half)
>
> AFAICT the above patch has not been applied & this patch here should be
> folded into the offending patch?
> I've marked this one as "Not Applicable" in patchwork as a result, but
> let me know if that is an incorrect assumption.
>
> Thanks,
> Conor.
>
Hi, Conor:

Sorry to disturb you with this patch without against the merged commit list,

This patch actually is created for fixing (riscv: ftrace: Reduce the
detour code size to half)
which has not been merged yet.

As Guo replied, he will fold it in the target patch. You can ignore
this one. Sorry again.

BTW, for dispelling your confusion about my email name.
Actually, it was misspelled when registering, but I keep it for daily use.
So you can send it without concern. :P

-- Song


Sorry for bothering you with the
> > patched, ftrace bug occurred When hosting kprobe and function tracer
> > at the same function.
> >
> > Obviously, the variable caller in ftrace_modify_call was assigned by
> > rec->ip with 4 offset failing the code replacing at function entry.
> > And the caller should be assigned by rec->ip directly to indicate
> > the function entry.
> >
> > The following is the ftrace bug log.
> >
> > ```
> > [  419.632855] 00000000f8776803: expected (ffe00297 1a4282e7) but got (1a8282e7 f0227179)
> > [  419.633390] ------------[ ftrace bug ]------------
> > [  419.633553] ftrace failed to modify
> > [  419.633569] [<ffffffff802091cc>] kernel_read+0x0/0x52
> > [  419.633863]  actual:   97:02:e0:ff:e7:82:82:1a
> > [  419.634087] Updating ftrace call site to call a different ftrace function
> > [  419.634279] ftrace record flags: e0000002
> > [  419.634487]  (2) R
> > [  419.634487]  expected tramp: ffffffff800093cc
> > [  419.634935] ------------[ cut here ]------------
> > ```
> >
> > Signed-off-by: Song Shuai <suagrfillet@gmail.com>
> > ---
> >  arch/riscv/kernel/ftrace.c | 2 +-
> >  1 file changed, 1 insertion(+), 1 deletion(-)
> >
> > diff --git a/arch/riscv/kernel/ftrace.c b/arch/riscv/kernel/ftrace.c
> > index 8c77f236fc71..61b24d767e2e 100644
> > --- a/arch/riscv/kernel/ftrace.c
> > +++ b/arch/riscv/kernel/ftrace.c
> > @@ -132,7 +132,7 @@ int ftrace_modify_call(struct dyn_ftrace *rec, unsigned long old_addr,
> >                      unsigned long addr)
> >  {
> >       unsigned int call[2];
> > -     unsigned long caller = rec->ip + 4;
> > +     unsigned long caller = rec->ip;
> >       int ret;
> >
> >       make_call_t0(caller, old_addr, call);
> > --
> > 2.20.1
> >
  
Song Shuai Nov. 22, 2022, 9:51 a.m. UTC | #5
Guo Ren <guoren@kernel.org> 于2022年11月22日周二 09:29写道:
>
>
>
> On Tue, Nov 22, 2022 at 5:11 PM Song Shuai <suagrfillet@gmail.com> wrote:
>>
>> Guo Ren <guoren@kernel.org> 于2022年11月22日周二 08:57写道:
>> >
>> > On Tue, Nov 22, 2022 at 3:54 PM Song Shuai <suagrfillet@gmail.com> wrote:
>> > >
>> > > With this commit (riscv: ftrace: Reduce the detour code size to half)
>> > > patched, ftrace bug occurred When hosting kprobe and function tracer
>> > > at the same function.
>> > >
>> > > Obviously, the variable caller in ftrace_modify_call was assigned by
>> > > rec->ip with 4 offset failing the code replacing at function entry.
>> > > And the caller should be assigned by rec->ip directly to indicate
>> > > the function entry.
>> > Thank you, it's my fault, but I think the problem is:
>> >
>> > Before (riscv: ftrace: Reduce the detour code size to half)
>> >      0: REG_S  ra, -SZREG(sp)
>> >      4: auipc  ra, ?          <- We need "rec->ip + 4" here
>> >      8: jalr   ?(ra)
>> >     12: REG_L  ra, -SZREG(sp)
>> >
>> > After (riscv: ftrace: Reduce the detour code size to half)
>> >      0: auipc  t0, ?  <- We needn't "rec->ip + 4" anymore
>> >      4: jalr   t0, ?(t0)
>> >
>> > I copied rec->ip + 4 blindly, then caused the bug. Right?
>> >
>> Yes, you're right.
>>
>> Here's my simple test case for your convenience.
>> ```
>> echo kernel_read > set_ftrace_filter
>> echo function > current_tracer
>> echo 'p:myp kernel_read' > kprobe_events
>> echo 1 > events/kprobes/myp/enable # ftrace bug
>
>
> Thx, I would fold the patch into (riscv: ftrace: Reduce the detour code size to half). And add Co-developed-by: Song Shuai <suagrfillet@gmail.com> tag on that.
>
> I would send the v3 series involving your patches.
>
That's an honor for me.

Thanks,
Song
>>
>> ```
>> > >
>> > > The following is the ftrace bug log.
>> > >
>> > > ```
>> > > [  419.632855] 00000000f8776803: expected (ffe00297 1a4282e7) but got (1a8282e7 f0227179)
>> > > [  419.633390] ------------[ ftrace bug ]------------
>> > > [  419.633553] ftrace failed to modify
>> > > [  419.633569] [<ffffffff802091cc>] kernel_read+0x0/0x52
>> > > [  419.633863]  actual:   97:02:e0:ff:e7:82:82:1a
>> > > [  419.634087] Updating ftrace call site to call a different ftrace function
>> > > [  419.634279] ftrace record flags: e0000002
>> > > [  419.634487]  (2) R
>> > > [  419.634487]  expected tramp: ffffffff800093cc
>> > > [  419.634935] ------------[ cut here ]------------
>> > > ```
>> > >
>> > > Signed-off-by: Song Shuai <suagrfillet@gmail.com>
>> > > ---
>> > >  arch/riscv/kernel/ftrace.c | 2 +-
>> > >  1 file changed, 1 insertion(+), 1 deletion(-)
>> > >
>> > > diff --git a/arch/riscv/kernel/ftrace.c b/arch/riscv/kernel/ftrace.c
>> > > index 8c77f236fc71..61b24d767e2e 100644
>> > > --- a/arch/riscv/kernel/ftrace.c
>> > > +++ b/arch/riscv/kernel/ftrace.c
>> > > @@ -132,7 +132,7 @@ int ftrace_modify_call(struct dyn_ftrace *rec, unsigned long old_addr,
>> > >                        unsigned long addr)
>> > >  {
>> > >         unsigned int call[2];
>> > > -       unsigned long caller = rec->ip + 4;
>> > > +       unsigned long caller = rec->ip;
>> > >         int ret;
>> > >
>> > >         make_call_t0(caller, old_addr, call);
>> > > --
>> > > 2.20.1
>> > >
>> >
>> >
>> > --
>> > Best Regards
>> >  Guo Ren
>> Thanks,
>> Song
>
>
>
> --
> Best Regards
>  Guo Ren
  

Patch

diff --git a/arch/riscv/kernel/ftrace.c b/arch/riscv/kernel/ftrace.c
index 8c77f236fc71..61b24d767e2e 100644
--- a/arch/riscv/kernel/ftrace.c
+++ b/arch/riscv/kernel/ftrace.c
@@ -132,7 +132,7 @@  int ftrace_modify_call(struct dyn_ftrace *rec, unsigned long old_addr,
 		       unsigned long addr)
 {
 	unsigned int call[2];
-	unsigned long caller = rec->ip + 4;
+	unsigned long caller = rec->ip;
 	int ret;
 
 	make_call_t0(caller, old_addr, call);