2022-03-07 16:25:20

by Arend van Spriel

[permalink] [raw]
Subject: ftrace bug

Hi Steven,

I wanted to use FTRACE on an ARM platform and I hit the following
warning which results in ftrace bug. This happens upon loading a module.
Looking up the warning I suspect the branch target is too far off. The
module is quite large and therefor not loaded in the modules section. Is
there a way to exclude a module. In ftrace_module_init I see a check for
!mod->num_ftrace_callsites. Is there a way to avoid creating ftrace
callsites in a module?

Regards,
Arend

------------[ cut here ]------------

WARNING: CPU: 2 PID: 1525 at arch/arm/kernel/insn.c:47
__arm_gen_branch+0x70/0x78

CPU: 2 PID: 1525 Comm: insmod Tainted: P 4.19.183 #2

Hardware name: Generic DT based system

[<c02139e4>] (unwind_backtrace) from [<c020d4f8>] (show_stack+0x20/0x24)

[<c020d4f8>] (show_stack) from [<c0922aec>] (dump_stack+0x98/0xac)

[<c0922aec>] (dump_stack) from [<c0919b98>] (__warn.part.0+0xcc/0xe8)

[<c0919b98>] (__warn.part.0) from [<c0919d4c>]
(warn_slowpath_null+0x54/0x74)
[<c0919d4c>] (warn_slowpath_null) from [<c021225c>]
(__arm_gen_branch+0x70/0x78)
[<c021225c>] (__arm_gen_branch) from [<c02120e4>]
(ftrace_make_nop+0x64/0xec)
[<c02120e4>] (ftrace_make_nop) from [<c02ac2b0>]
(ftrace_process_locs+0x370/0x4b4)

[<c02ac2b0>] (ftrace_process_locs) from [<c02af538>]
(ftrace_module_init+0x38/0x3c)

[<c02af538>] (ftrace_module_init) from [<c02a47d8>]
(load_module+0x18d0/0x2570)
[<c02a47d8>] (load_module) from [<c02a56f8>]
(sys_finit_module+0xe0/0xf8)
[<c02a56f8>] (sys_finit_module) from [<c0201000>]
(ret_fast_syscall+0x0/0x58)
Exception stack(0xd9b1bfa8 to 0xd9b1bff0)

bfa0: 01170228 00000000 00000003 01170228 00000000
beb7ceb3
bfc0: 01170228 00000000 beb7cdc4 0000017b 00127010 00000000 00000000
00000000
bfe0: beb7cc38 beb7cc28 0001a0dc 00012890

---[ end trace f48808a851a4544a ]---

------------[ cut here ]------------

WARNING: CPU: 2 PID: 1525 at kernel/trace/ftrace.c:2034
ftrace_bug+0xfc/0x394


Attachments:
smime.p7s (4.12 kB)
S/MIME Cryptographic Signature

2022-03-08 19:33:47

by Alexander Sverdlin

[permalink] [raw]
Subject: Re: ftrace bug

Hi Arend!

On 08/03/2022 16:20, Steven Rostedt wrote:
>>> I wanted to use FTRACE on an ARM platform and I hit the following
>>> warning which results in ftrace bug. This happens upon loading a module.
>>> Looking up the warning I suspect the branch target is too far off. The
>>> module is quite large and therefor not loaded in the modules section. Is
>>> there a way to exclude a module. In ftrace_module_init I see a check for
>>> !mod->num_ftrace_callsites. Is there a way to avoid creating ftrace
>>> callsites in a module?
>> Are you sure it's the size. Just want to make sure that's the reason before
>> going with different solutions.
> Interpreting the warning statement in insn.c and given the fact that the
> module is loaded at 0xe3xxxxxx instead of kernel module space at
> 0xbfxxxxxx I made this assumption, but ....
>
>>> Regards,
>>> Arend
>>>
>>> ------------[ cut here ]------------
>>>
>>> WARNING: CPU: 2 PID: 1525 at arch/arm/kernel/insn.c:47
>>> __arm_gen_branch+0x70/0x78
>>>
>>> CPU: 2 PID: 1525 Comm: insmod Tainted: P 4.19.183 #2

This problem is addressed by:

commit 8113e622926ef6590771ede0f7f64821e1751b67
Author: Alex Sverdlin <[email protected]>
Date: Mon Sep 27 14:02:45 2021 -0700

ARM: 9079/1: ftrace: Add MODULE_PLTS support

commit 79f32b221b18c15a98507b101ef4beb52444cc6f upstream

Teach ftrace_make_call() and ftrace_make_nop() about PLTs.
Teach PLT code about FTRACE and all its callbacks.
Otherwise the following might happen:

------------[ cut here ]------------
WARNING: CPU: 14 PID: 2265 at .../arch/arm/kernel/insn.c:14 __arm_gen_branch+0x83/0x8c()
...
Hardware name: LSI Axxia AXM55XX
[<c0314a49>] (unwind_backtrace) from [<c03115e9>] (show_stack+0x11/0x14)
[<c03115e9>] (show_stack) from [<c0519f51>] (dump_stack+0x81/0xa8)
[<c0519f51>] (dump_stack) from [<c032185d>] (warn_slowpath_common+0x69/0x90)
[<c032185d>] (warn_slowpath_common) from [<c03218f3>] (warn_slowpath_null+0x17/0x1c)
[<c03218f3>] (warn_slowpath_null) from [<c03143cf>] (__arm_gen_branch+0x83/0x8c)
[<c03143cf>] (__arm_gen_branch) from [<c0314337>] (ftrace_make_nop+0xf/0x24)
[<c0314337>] (ftrace_make_nop) from [<c038ebcb>] (ftrace_process_locs+0x27b/0x3e8)
[<c038ebcb>] (ftrace_process_locs) from [<c0378d79>] (load_module+0x11e9/0x1a44)
[<c0378d79>] (load_module) from [<c037974d>] (SyS_finit_module+0x59/0x84)
[<c037974d>] (SyS_finit_module) from [<c030e981>] (ret_fast_syscall+0x1/0x18)
---[ end trace e1b64ced7a89adcc ]---
------------[ cut here ]------------

And if you wanna stick with 4.19.y, it's included starting from v4.19.209.

--
Best regards,
Alexander Sverdlin.

2022-03-08 21:09:38

by Arend van Spriel

[permalink] [raw]
Subject: Re: ftrace bug

On 3/7/2022 2:24 PM, Steven Rostedt wrote:
> On Mon, 7 Mar 2022 12:26:45 +0100
> Arend van Spriel <[email protected]> wrote:
>
>> Hi Steven,
>>
>> I wanted to use FTRACE on an ARM platform and I hit the following
>> warning which results in ftrace bug. This happens upon loading a module.
>> Looking up the warning I suspect the branch target is too far off. The
>> module is quite large and therefor not loaded in the modules section. Is
>> there a way to exclude a module. In ftrace_module_init I see a check for
>> !mod->num_ftrace_callsites. Is there a way to avoid creating ftrace
>> callsites in a module?
>
> Are you sure it's the size. Just want to make sure that's the reason before
> going with different solutions.

Interpreting the warning statement in insn.c and given the fact that the
module is loaded at 0xe3xxxxxx instead of kernel module space at
0xbfxxxxxx I made this assumption, but ....

>>
>> Regards,
>> Arend
>>
>> ------------[ cut here ]------------
>>
>> WARNING: CPU: 2 PID: 1525 at arch/arm/kernel/insn.c:47
>> __arm_gen_branch+0x70/0x78
>>
>> CPU: 2 PID: 1525 Comm: insmod Tainted: P 4.19.183 #2
>>
>> Hardware name: Generic DT based system
>>
>> [<c02139e4>] (unwind_backtrace) from [<c020d4f8>] (show_stack+0x20/0x24)
>>
>> [<c020d4f8>] (show_stack) from [<c0922aec>] (dump_stack+0x98/0xac)
>>
>> [<c0922aec>] (dump_stack) from [<c0919b98>] (__warn.part.0+0xcc/0xe8)
>>
>> [<c0919b98>] (__warn.part.0) from [<c0919d4c>]
>> (warn_slowpath_null+0x54/0x74)
>> [<c0919d4c>] (warn_slowpath_null) from [<c021225c>]
>> (__arm_gen_branch+0x70/0x78)
>> [<c021225c>] (__arm_gen_branch) from [<c02120e4>]
>> (ftrace_make_nop+0x64/0xec)
>> [<c02120e4>] (ftrace_make_nop) from [<c02ac2b0>]
>> (ftrace_process_locs+0x370/0x4b4)
>>
>> [<c02ac2b0>] (ftrace_process_locs) from [<c02af538>]
>> (ftrace_module_init+0x38/0x3c)
>>
>> [<c02af538>] (ftrace_module_init) from [<c02a47d8>]
>> (load_module+0x18d0/0x2570)
>> [<c02a47d8>] (load_module) from [<c02a56f8>]
>> (sys_finit_module+0xe0/0xf8)
>> [<c02a56f8>] (sys_finit_module) from [<c0201000>]
>> (ret_fast_syscall+0x0/0x58)
>> Exception stack(0xd9b1bfa8 to 0xd9b1bff0)
>>
>> bfa0: 01170228 00000000 00000003 01170228 00000000
>> beb7ceb3
>> bfc0: 01170228 00000000 beb7cdc4 0000017b 00127010 00000000 00000000
>> 00000000
>> bfe0: beb7cc38 beb7cc28 0001a0dc 00012890
>>
>> ---[ end trace f48808a851a4544a ]---
>>
>> ------------[ cut here ]------------
>>
>> WARNING: CPU: 2 PID: 1525 at kernel/trace/ftrace.c:2034
>> ftrace_bug+0xfc/0x394
>
> Three should be more content after the "cut here" that is very relevant (I
> hate that cut here, because I constantly need to tell people to show me
> more :-p I need to add a "ftrace bug cut here" line.)
>
>
> Could you show me the output right after that.

... here is the output I think you were looking for:

ftrace failed to modify

[<a82ca82d>] (suspected corrupt symbol)

actual: 63:17:16:eb

Initializing ftrace call sites

ftrace record flags: 2000000

(0)

expected tramp: c0211b88

ftrace failed to modify

[<6c88ec64>] (suspected corrupt symbol)

actual: 72:ab:08:eb

Initializing ftrace call sites

ftrace record flags: 2000000

(0)

expected tramp: c0211b88

ftrace failed to modify

[<b1ed303a>] (suspected corrupt symbol)

actual: 04:12:04:eb

Initializing ftrace call sites

ftrace record flags: 2000000

(0)

expected tramp: c0211b88

ftrace failed to modify

[<eb2fee66>] (suspected corrupt symbol)

actual: d6:7e:00:eb

Initializing ftrace call sites

ftrace record flags: 2000000

(0)

expected tramp: c0211b88

Regards,
Arend


Attachments:
smime.p7s (4.12 kB)
S/MIME Cryptographic Signature

2022-03-08 22:14:37

by Steven Rostedt

[permalink] [raw]
Subject: Re: ftrace bug

On Mon, 7 Mar 2022 12:26:45 +0100
Arend van Spriel <[email protected]> wrote:

> Hi Steven,
>
> I wanted to use FTRACE on an ARM platform and I hit the following
> warning which results in ftrace bug. This happens upon loading a module.
> Looking up the warning I suspect the branch target is too far off. The
> module is quite large and therefor not loaded in the modules section. Is
> there a way to exclude a module. In ftrace_module_init I see a check for
> !mod->num_ftrace_callsites. Is there a way to avoid creating ftrace
> callsites in a module?

Are you sure it's the size. Just want to make sure that's the reason before
going with different solutions.

>
> Regards,
> Arend
>
> ------------[ cut here ]------------
>
> WARNING: CPU: 2 PID: 1525 at arch/arm/kernel/insn.c:47
> __arm_gen_branch+0x70/0x78
>
> CPU: 2 PID: 1525 Comm: insmod Tainted: P 4.19.183 #2
>
> Hardware name: Generic DT based system
>
> [<c02139e4>] (unwind_backtrace) from [<c020d4f8>] (show_stack+0x20/0x24)
>
> [<c020d4f8>] (show_stack) from [<c0922aec>] (dump_stack+0x98/0xac)
>
> [<c0922aec>] (dump_stack) from [<c0919b98>] (__warn.part.0+0xcc/0xe8)
>
> [<c0919b98>] (__warn.part.0) from [<c0919d4c>]
> (warn_slowpath_null+0x54/0x74)
> [<c0919d4c>] (warn_slowpath_null) from [<c021225c>]
> (__arm_gen_branch+0x70/0x78)
> [<c021225c>] (__arm_gen_branch) from [<c02120e4>]
> (ftrace_make_nop+0x64/0xec)
> [<c02120e4>] (ftrace_make_nop) from [<c02ac2b0>]
> (ftrace_process_locs+0x370/0x4b4)
>
> [<c02ac2b0>] (ftrace_process_locs) from [<c02af538>]
> (ftrace_module_init+0x38/0x3c)
>
> [<c02af538>] (ftrace_module_init) from [<c02a47d8>]
> (load_module+0x18d0/0x2570)
> [<c02a47d8>] (load_module) from [<c02a56f8>]
> (sys_finit_module+0xe0/0xf8)
> [<c02a56f8>] (sys_finit_module) from [<c0201000>]
> (ret_fast_syscall+0x0/0x58)
> Exception stack(0xd9b1bfa8 to 0xd9b1bff0)
>
> bfa0: 01170228 00000000 00000003 01170228 00000000
> beb7ceb3
> bfc0: 01170228 00000000 beb7cdc4 0000017b 00127010 00000000 00000000
> 00000000
> bfe0: beb7cc38 beb7cc28 0001a0dc 00012890
>
> ---[ end trace f48808a851a4544a ]---
>
> ------------[ cut here ]------------
>
> WARNING: CPU: 2 PID: 1525 at kernel/trace/ftrace.c:2034
> ftrace_bug+0xfc/0x394

Three should be more content after the "cut here" that is very relevant (I
hate that cut here, because I constantly need to tell people to show me
more :-p I need to add a "ftrace bug cut here" line.)


Could you show me the output right after that.

-- Steve

2022-03-09 00:11:30

by Arend van Spriel

[permalink] [raw]
Subject: Re: ftrace bug

On March 8, 2022 5:03:00 PM Alexander Sverdlin
<[email protected]> wrote:

> Hi Arend!
>
> On 08/03/2022 16:20, Steven Rostedt wrote:
>>>> I wanted to use FTRACE on an ARM platform and I hit the following
>>>> warning which results in ftrace bug. This happens upon loading a module.
>>>> Looking up the warning I suspect the branch target is too far off. The
>>>> module is quite large and therefor not loaded in the modules section. Is
>>>> there a way to exclude a module. In ftrace_module_init I see a check for
>>>> !mod->num_ftrace_callsites. Is there a way to avoid creating ftrace
>>>> callsites in a module?
>>> Are you sure it's the size. Just want to make sure that's the reason before
>>> going with different solutions.
>> Interpreting the warning statement in insn.c and given the fact that the
>> module is loaded at 0xe3xxxxxx instead of kernel module space at
>> 0xbfxxxxxx I made this assumption, but ....
>>
>>>> Regards,
>>>> Arend
>>>>
>>>> ------------[ cut here ]------------
>>>>
>>>> WARNING: CPU: 2 PID: 1525 at arch/arm/kernel/insn.c:47
>>>> __arm_gen_branch+0x70/0x78
>>>>
>>>> CPU: 2 PID: 1525 Comm: insmod Tainted: P 4.19.183 #2
>
> This problem is addressed by:

Cool. Thanks for the info.

> commit 8113e622926ef6590771ede0f7f64821e1751b67
> Author: Alex Sverdlin <[email protected]>
> Date: Mon Sep 27 14:02:45 2021 -0700
>
> ARM: 9079/1: ftrace: Add MODULE_PLTS support
>
> commit 79f32b221b18c15a98507b101ef4beb52444cc6f upstream
>
> Teach ftrace_make_call() and ftrace_make_nop() about PLTs.
> Teach PLT code about FTRACE and all its callbacks.
> Otherwise the following might happen:
>
> ------------[ cut here ]------------
> WARNING: CPU: 14 PID: 2265 at .../arch/arm/kernel/insn.c:14
> __arm_gen_branch+0x83/0x8c()
> ...
> Hardware name: LSI Axxia AXM55XX
> [<c0314a49>] (unwind_backtrace) from [<c03115e9>] (show_stack+0x11/0x14)
> [<c03115e9>] (show_stack) from [<c0519f51>] (dump_stack+0x81/0xa8)
> [<c0519f51>] (dump_stack) from [<c032185d>] (warn_slowpath_common+0x69/0x90)
> [<c032185d>] (warn_slowpath_common) from [<c03218f3>]
> (warn_slowpath_null+0x17/0x1c)
> [<c03218f3>] (warn_slowpath_null) from [<c03143cf>]
> (__arm_gen_branch+0x83/0x8c)
> [<c03143cf>] (__arm_gen_branch) from [<c0314337>] (ftrace_make_nop+0xf/0x24)
> [<c0314337>] (ftrace_make_nop) from [<c038ebcb>]
> (ftrace_process_locs+0x27b/0x3e8)
> [<c038ebcb>] (ftrace_process_locs) from [<c0378d79>]
> (load_module+0x11e9/0x1a44)
> [<c0378d79>] (load_module) from [<c037974d>] (SyS_finit_module+0x59/0x84)
> [<c037974d>] (SyS_finit_module) from [<c030e981>] (ret_fast_syscall+0x1/0x18)
> ---[ end trace e1b64ced7a89adcc ]---
> ------------[ cut here ]------------
>
> And if you wanna stick with 4.19.y, it's included starting from v4.19.209.

Will see if our router kernel team wants to move. At least I can try my own
experiment with this.

Regards,
Arend




Attachments:
smime.p7s (4.12 kB)
S/MIME Cryptographic Signature

2022-03-09 00:45:06

by Arend van Spriel

[permalink] [raw]
Subject: Re: ftrace bug

On March 8, 2022 6:45:30 PM Steven Rostedt <[email protected]> wrote:

> On Tue, 8 Mar 2022 17:02:53 +0100
> Alexander Sverdlin <[email protected]> wrote:
>
>> This problem is addressed by:
>>
>> commit 8113e622926ef6590771ede0f7f64821e1751b67
>> Author: Alex Sverdlin <[email protected]>
>> Date: Mon Sep 27 14:02:45 2021 -0700
>
> Thanks Alex. I knew it was a good idea not to try to figure this out on my
> own ;-)

Ditto :-p

Arend




Attachments:
smime.p7s (4.12 kB)
S/MIME Cryptographic Signature

2022-03-09 01:05:48

by Steven Rostedt

[permalink] [raw]
Subject: Re: ftrace bug

On Tue, 8 Mar 2022 17:02:53 +0100
Alexander Sverdlin <[email protected]> wrote:

> This problem is addressed by:
>
> commit 8113e622926ef6590771ede0f7f64821e1751b67
> Author: Alex Sverdlin <[email protected]>
> Date: Mon Sep 27 14:02:45 2021 -0700

Thanks Alex. I knew it was a good idea not to try to figure this out on my
own ;-)

-- Steve

2022-03-09 01:19:32

by Steven Rostedt

[permalink] [raw]
Subject: Re: ftrace bug

[ Adding ARM folks (and those that touched the ftrace ARM port) as I don't
know the ARM code ]

On Tue, 8 Mar 2022 11:53:35 +0100
Arend van Spriel <[email protected]> wrote:

> On 3/7/2022 2:24 PM, Steven Rostedt wrote:
> > On Mon, 7 Mar 2022 12:26:45 +0100
> > Arend van Spriel <[email protected]> wrote:
> >
> >> Hi Steven,
> >>
> >> I wanted to use FTRACE on an ARM platform and I hit the following
> >> warning which results in ftrace bug. This happens upon loading a module.
> >> Looking up the warning I suspect the branch target is too far off. The
> >> module is quite large and therefor not loaded in the modules section. Is
> >> there a way to exclude a module. In ftrace_module_init I see a check for
> >> !mod->num_ftrace_callsites. Is there a way to avoid creating ftrace
> >> callsites in a module?
> >
> > Are you sure it's the size. Just want to make sure that's the reason before
> > going with different solutions.
>
> Interpreting the warning statement in insn.c and given the fact that the
> module is loaded at 0xe3xxxxxx instead of kernel module space at
> 0xbfxxxxxx I made this assumption, but ....
>
> >>
> >> Regards,
> >> Arend
> >>
> >> ------------[ cut here ]------------
> >>
> >> WARNING: CPU: 2 PID: 1525 at arch/arm/kernel/insn.c:47
> >> __arm_gen_branch+0x70/0x78
> >>
> >> CPU: 2 PID: 1525 Comm: insmod Tainted: P 4.19.183 #2
> >>
> >> Hardware name: Generic DT based system
> >>
> >> [<c02139e4>] (unwind_backtrace) from [<c020d4f8>] (show_stack+0x20/0x24)
> >>
> >> [<c020d4f8>] (show_stack) from [<c0922aec>] (dump_stack+0x98/0xac)
> >>
> >> [<c0922aec>] (dump_stack) from [<c0919b98>] (__warn.part.0+0xcc/0xe8)
> >>
> >> [<c0919b98>] (__warn.part.0) from [<c0919d4c>]
> >> (warn_slowpath_null+0x54/0x74)
> >> [<c0919d4c>] (warn_slowpath_null) from [<c021225c>]
> >> (__arm_gen_branch+0x70/0x78)
> >> [<c021225c>] (__arm_gen_branch) from [<c02120e4>]
> >> (ftrace_make_nop+0x64/0xec)
> >> [<c02120e4>] (ftrace_make_nop) from [<c02ac2b0>]
> >> (ftrace_process_locs+0x370/0x4b4)
> >>
> >> [<c02ac2b0>] (ftrace_process_locs) from [<c02af538>]
> >> (ftrace_module_init+0x38/0x3c)
> >>
> >> [<c02af538>] (ftrace_module_init) from [<c02a47d8>]
> >> (load_module+0x18d0/0x2570)
> >> [<c02a47d8>] (load_module) from [<c02a56f8>]
> >> (sys_finit_module+0xe0/0xf8)
> >> [<c02a56f8>] (sys_finit_module) from [<c0201000>]
> >> (ret_fast_syscall+0x0/0x58)
> >> Exception stack(0xd9b1bfa8 to 0xd9b1bff0)
> >>
> >> bfa0: 01170228 00000000 00000003 01170228 00000000
> >> beb7ceb3
> >> bfc0: 01170228 00000000 beb7cdc4 0000017b 00127010 00000000 00000000
> >> 00000000
> >> bfe0: beb7cc38 beb7cc28 0001a0dc 00012890
> >>
> >> ---[ end trace f48808a851a4544a ]---
> >>
> >> ------------[ cut here ]------------
> >>
> >> WARNING: CPU: 2 PID: 1525 at kernel/trace/ftrace.c:2034
> >> ftrace_bug+0xfc/0x394
> >
> > Three should be more content after the "cut here" that is very relevant (I
> > hate that cut here, because I constantly need to tell people to show me
> > more :-p I need to add a "ftrace bug cut here" line.)
> >
> >
> > Could you show me the output right after that.
>
> ... here is the output I think you were looking for:
>
> ftrace failed to modify
>
> [<a82ca82d>] (suspected corrupt symbol)

Is the above "suspected corrupt symbol" kernel output? I don't see it in my
tree. What version of the kernel is this.

I'm guessing the above address a82ca82d is where it is trying to modify,
and is not in the symbol table. So something looks to be messed up.

>
> actual: 63:17:16:eb

The above is what it found in that location.

Perhaps others have ideas.

-- Steve

>
> Initializing ftrace call sites
>
> ftrace record flags: 2000000
>
> (0)
>
> expected tramp: c0211b88
>
> ftrace failed to modify
>
> [<6c88ec64>] (suspected corrupt symbol)
>
> actual: 72:ab:08:eb
>
> Initializing ftrace call sites
>
> ftrace record flags: 2000000
>
> (0)
>
> expected tramp: c0211b88
>
> ftrace failed to modify
>
> [<b1ed303a>] (suspected corrupt symbol)
>
> actual: 04:12:04:eb
>
> Initializing ftrace call sites
>
> ftrace record flags: 2000000
>
> (0)
>
> expected tramp: c0211b88
>
> ftrace failed to modify
>
> [<eb2fee66>] (suspected corrupt symbol)
>
> actual: d6:7e:00:eb
>
> Initializing ftrace call sites
>
> ftrace record flags: 2000000
>
> (0)
>
> expected tramp: c0211b88
>
> Regards,
> Arend