| Message ID | 20221122075440.1165172-1-suagrfillet@gmail.com (mailing list archive) |
|---|---|
| State | Not Applicable |
| Headers | show |
| Series | riscv/ftrace: fix ftrace_modify_call bug | expand |
| Context | Check | Description |
|---|---|---|
| conchuod/tree_selection | fail | Guessing tree name failed |
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 >
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 >
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
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 > >
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
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);
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(-)