* dynamic ftrace/recordmcount.c problem on ARMv5
@ 2016-01-13 8:51 Marc Kleine-Budde
2016-01-13 16:08 ` Steven Rostedt
` (2 more replies)
0 siblings, 3 replies; 10+ messages in thread
From: Marc Kleine-Budde @ 2016-01-13 8:51 UTC (permalink / raw)
To: linux-kernel; +Cc: ptx kernel, Steven Rostedt (Red Hat)
[-- Attachment #1: Type: text/plain, Size: 4262 bytes --]
Hello,
I'm on a ARMv5 (freescale mx25) and seeing this ftrace bug during bootup:
> [ 0.059235] ------------[ cut here ]------------
> [ 0.059449] WARNING: CPU: 0 PID: 0 at kernel/trace/ftrace.c:1938 ftrace_bug+0x210/0x2c8()
> [ 0.059645] Modules linked in:
> [ 0.059780] CPU: 0 PID: 0 Comm: swapper Not tainted 4.0.9-20151211-1-g45dbe7d2c077 #1
> [ 0.059966] Hardware name: Freescale i.MX25 (Device Tree Support)
> [ 0.060157] [<8000f494>] (unwind_backtrace) from [<8000ce3c>] (show_stack+0x20/0x24)
> [ 0.060396] [<8000ce3c>] (show_stack) from [<8041ea68>] (dump_stack+0x20/0x28)
> [ 0.060630] [<8041ea68>] (dump_stack) from [<8001a74c>] (warn_slowpath_common+0x88/0xc0)
> [ 0.060853] [<8001a74c>] (warn_slowpath_common) from [<8001a840>] (warn_slowpath_null+0x2c/0x34)
> [ 0.061091] [<8001a840>] (warn_slowpath_null) from [<80083748>] (ftrace_bug+0x210/0x2c8)
> [ 0.061332] [<80083748>] (ftrace_bug) from [<80083bb8>] (ftrace_process_locs+0x330/0x6f0)
> [ 0.061576] [<80083bb8>] (ftrace_process_locs) from [<805bdc84>] (ftrace_init+0x8c/0x14c)
> [ 0.061815] [<805bdc84>] (ftrace_init) from [<805b0c80>] (start_kernel+0x33c/0x3b4)
> [ 0.062039] [<805b0c80>] (start_kernel) from [<80008040>] (0x80008040)
> [ 0.062238] ---[ end trace cb88537fdc8fa200 ]---
> [ 0.062364] ftrace failed to modify [<8000c7d8>] walk_stackframe+0x24/0x44
> [ 0.062544] actual: 16:ff:2f:e1
> [ 0.062702] ftrace record flags: 0
> [ 0.062803] (0) expected tramp: 8000e864
The problem is that walk_stackframe ends up in the __mcount_loc section,
although it has a "notrace" attribute:
> $ grep notrace arch/arm/kernel/stacktrace.c | grep walk_stackframe
> void notrace walk_stackframe(struct stackframe *frame,
To reproduce:
- use the arm compiler from kernel.org:
> https://www.kernel.org/pub/tools/crosstool/files/bin/x86_64/4.9.0/x86_64-gcc-4.9.0-nolibc_arm-unknown-linux-gnueabi.tar.xz
- linus master
(67990608c8b9 Merge tag 'pm+acpi-4.5-rc1-1' of
git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm)
- a ARMv5 config
> make imx_v4_v5_defconfig
- switch on the function tracer and dynamic ftrace
> CONFIG_HAVE_FUNCTION_TRACER=y
> CONFIG_HAVE_FUNCTION_GRAPH_TRACER=y
> CONFIG_HAVE_DYNAMIC_FTRACE=y
- build the object file that contains walk_stackframe:
> $ make arch/arm/kernel/stacktrace.o
Observations:
- There is no branch to the mcount function ("bl 0 <__gnu_mcount_nc>"),
which is good:
> $ objdump -d arch/arm/kernel/stacktrace.o |grep "<walk_stackframe>:" -A12
> 00000000 <walk_stackframe>:
> 0: e1a0c00d mov ip, sp
> 4: e92dd878 push {r3, r4, r5, r6, fp, ip, lr, pc}
> 8: e24cb004 sub fp, ip, #4
> c: e1a04000 mov r4, r0
> 10: e1a06001 mov r6, r1
> 14: e1a05002 mov r5, r2
> 18: e1a00004 mov r0, r4
> 1c: e1a01005 mov r1, r5
> 20: e1a0e00f mov lr, pc
> 24: e12fff16 bx r6
> 28: e3500000 cmp r0, #0
> 2c: 189da878 ldmne sp, {r3, r4, r5, r6, fp, sp, pc}
There are 5 calls to __gnu_mcount_nc in the object file:
> $ objdump -x arch/arm/kernel/stacktrace.o | grep R_ARM_CALL | grep __gnu_mcount_nc
> 00000054 R_ARM_CALL __gnu_mcount_nc
> 0000016c R_ARM_CALL __gnu_mcount_nc
> 00000234 R_ARM_CALL __gnu_mcount_nc
> 0000026c R_ARM_CALL __gnu_mcount_nc
> 000002f4 R_ARM_CALL __gnu_mcount_nc
However there are 6 references in the __mcount_loc section:
> $ readelf -R __mcount_loc arch/arm/kernel/stacktrace.o
>
> Hex dump of section '__mcount_loc':
> 0x00000000 24000000 54000000 6c010000 34020000 $...T...l...4...
> 0x00000010 6c020000 f4020000 l.......
Note: The first and wrong offset is 0x24, which is a "bx r6" (see above
objdump of stacktrace.o):
> 24: e12fff16 bx r6
I hacked scripts/Makefile.build to use the perl version of recordmcount,
that works without problems.
regards,
Marc
--
Pengutronix e.K. | Marc Kleine-Budde |
Industrial Linux Solutions | Phone: +49-231-2826-924 |
Vertretung West/Dortmund | Fax: +49-5121-206917-5555 |
Amtsgericht Hildesheim, HRA 2686 | http://www.pengutronix.de |
[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 455 bytes --]
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: dynamic ftrace/recordmcount.c problem on ARMv5
2016-01-13 8:51 dynamic ftrace/recordmcount.c problem on ARMv5 Marc Kleine-Budde
@ 2016-01-13 16:08 ` Steven Rostedt
2016-01-13 16:23 ` Marc Kleine-Budde
2016-02-08 15:38 ` Marc Kleine-Budde
2016-03-11 9:21 ` Uwe Kleine-König
2 siblings, 1 reply; 10+ messages in thread
From: Steven Rostedt @ 2016-01-13 16:08 UTC (permalink / raw)
To: Marc Kleine-Budde; +Cc: linux-kernel, ptx kernel
On Wed, 13 Jan 2016 09:51:28 +0100
Marc Kleine-Budde <mkl@pengutronix.de> wrote:
> There are 5 calls to __gnu_mcount_nc in the object file:
> > $ objdump -x arch/arm/kernel/stacktrace.o | grep R_ARM_CALL | grep __gnu_mcount_nc
> > 00000054 R_ARM_CALL __gnu_mcount_nc
> > 0000016c R_ARM_CALL __gnu_mcount_nc
> > 00000234 R_ARM_CALL __gnu_mcount_nc
> > 0000026c R_ARM_CALL __gnu_mcount_nc
> > 000002f4 R_ARM_CALL __gnu_mcount_nc
>
> However there are 6 references in the __mcount_loc section:
> > $ readelf -R __mcount_loc arch/arm/kernel/stacktrace.o
> >
> > Hex dump of section '__mcount_loc':
> > 0x00000000 24000000 54000000 6c010000 34020000 $...T...l...4...
> > 0x00000010 6c020000 f4020000 l.......
>
> Note: The first and wrong offset is 0x24, which is a "bx r6" (see above
> objdump of stacktrace.o):
> > 24: e12fff16 bx r6
Interesting. Have you tried a make mrproper and tried again? Also, do
you use hardlinks with ccache?
>
> I hacked scripts/Makefile.build to use the perl version of recordmcount,
> that works without problems.
Note, you could also just removed CONFIG_HAVE_C_RECORDMCOUNT from
arch/arm/Kconfig.
-- Steve
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: dynamic ftrace/recordmcount.c problem on ARMv5
2016-01-13 16:08 ` Steven Rostedt
@ 2016-01-13 16:23 ` Marc Kleine-Budde
2016-01-13 16:27 ` Steven Rostedt
0 siblings, 1 reply; 10+ messages in thread
From: Marc Kleine-Budde @ 2016-01-13 16:23 UTC (permalink / raw)
To: Steven Rostedt; +Cc: linux-kernel, ptx kernel
[-- Attachment #1: Type: text/plain, Size: 1771 bytes --]
On 01/13/2016 05:08 PM, Steven Rostedt wrote:
> On Wed, 13 Jan 2016 09:51:28 +0100
> Marc Kleine-Budde <mkl@pengutronix.de> wrote:
>
>> There are 5 calls to __gnu_mcount_nc in the object file:
>>> $ objdump -x arch/arm/kernel/stacktrace.o | grep R_ARM_CALL | grep __gnu_mcount_nc
>>> 00000054 R_ARM_CALL __gnu_mcount_nc
>>> 0000016c R_ARM_CALL __gnu_mcount_nc
>>> 00000234 R_ARM_CALL __gnu_mcount_nc
>>> 0000026c R_ARM_CALL __gnu_mcount_nc
>>> 000002f4 R_ARM_CALL __gnu_mcount_nc
>>
>> However there are 6 references in the __mcount_loc section:
>>> $ readelf -R __mcount_loc arch/arm/kernel/stacktrace.o
>>>
>>> Hex dump of section '__mcount_loc':
>>> 0x00000000 24000000 54000000 6c010000 34020000 $...T...l...4...
>>> 0x00000010 6c020000 f4020000 l.......
>>
>> Note: The first and wrong offset is 0x24, which is a "bx r6" (see above
>> objdump of stacktrace.o):
>>> 24: e12fff16 bx r6
>
> Interesting. Have you tried a make mrproper and tried again? Also, do
> you use hardlinks with ccache?
That happens on ARMv5 with a clean build. No ccache involved (this issue
should be fixed on >= v4.4)
>> I hacked scripts/Makefile.build to use the perl version of recordmcount,
>> that works without problems.
>
> Note, you could also just removed CONFIG_HAVE_C_RECORDMCOUNT from
> arch/arm/Kconfig.
This is the patch I'm using as a workaround.
regards,
Marc
--
Pengutronix e.K. | Marc Kleine-Budde |
Industrial Linux Solutions | Phone: +49-231-2826-924 |
Vertretung West/Dortmund | Fax: +49-5121-206917-5555 |
Amtsgericht Hildesheim, HRA 2686 | http://www.pengutronix.de |
[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 455 bytes --]
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: dynamic ftrace/recordmcount.c problem on ARMv5
2016-01-13 16:23 ` Marc Kleine-Budde
@ 2016-01-13 16:27 ` Steven Rostedt
2016-01-13 16:30 ` Marc Kleine-Budde
0 siblings, 1 reply; 10+ messages in thread
From: Steven Rostedt @ 2016-01-13 16:27 UTC (permalink / raw)
To: Marc Kleine-Budde; +Cc: linux-kernel, ptx kernel
On Wed, 13 Jan 2016 17:23:52 +0100
Marc Kleine-Budde <mkl@pengutronix.de> wrote:
> That happens on ARMv5 with a clean build. No ccache involved (this issue
> should be fixed on >= v4.4)
It's fixed in mainline? If so, maybe you can do a reverse bisect to
find the patch that fixes it.
-- Steve
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: dynamic ftrace/recordmcount.c problem on ARMv5
2016-01-13 16:27 ` Steven Rostedt
@ 2016-01-13 16:30 ` Marc Kleine-Budde
0 siblings, 0 replies; 10+ messages in thread
From: Marc Kleine-Budde @ 2016-01-13 16:30 UTC (permalink / raw)
To: Steven Rostedt; +Cc: linux-kernel, ptx kernel
[-- Attachment #1: Type: text/plain, Size: 923 bytes --]
On 01/13/2016 05:27 PM, Steven Rostedt wrote:
> On Wed, 13 Jan 2016 17:23:52 +0100
> Marc Kleine-Budde <mkl@pengutronix.de> wrote:
>
>> That happens on ARMv5 with a clean build. No ccache involved (this issue
>> should be fixed on >= v4.4)
>
> It's fixed in mainline? If so, maybe you can do a reverse bisect to
> find the patch that fixes it.
Sorry for the confusion - I mean the ccache hardlink issue should be
fixed on mainline, with:
dd39a26538e3 scripts: recordmcount: break hardlinks
a50bd4393558 ftrace/scripts: Have recordmcount copy the object file
The recordmcount.c problem on ARMv5 occurs on mainline.
Marc
--
Pengutronix e.K. | Marc Kleine-Budde |
Industrial Linux Solutions | Phone: +49-231-2826-924 |
Vertretung West/Dortmund | Fax: +49-5121-206917-5555 |
Amtsgericht Hildesheim, HRA 2686 | http://www.pengutronix.de |
[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 455 bytes --]
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: dynamic ftrace/recordmcount.c problem on ARMv5
2016-01-13 8:51 dynamic ftrace/recordmcount.c problem on ARMv5 Marc Kleine-Budde
2016-01-13 16:08 ` Steven Rostedt
@ 2016-02-08 15:38 ` Marc Kleine-Budde
2016-02-08 15:53 ` Steven Rostedt
2016-03-11 9:21 ` Uwe Kleine-König
2 siblings, 1 reply; 10+ messages in thread
From: Marc Kleine-Budde @ 2016-02-08 15:38 UTC (permalink / raw)
To: linux-kernel; +Cc: ptx kernel, Steven Rostedt (Red Hat)
[-- Attachment #1: Type: text/plain, Size: 4478 bytes --]
On 01/13/2016 09:51 AM, Marc Kleine-Budde wrote:
> Hello,
>
> I'm on a ARMv5 (freescale mx25) and seeing this ftrace bug during bootup:
>
>> [ 0.059235] ------------[ cut here ]------------
>> [ 0.059449] WARNING: CPU: 0 PID: 0 at kernel/trace/ftrace.c:1938 ftrace_bug+0x210/0x2c8()
>> [ 0.059645] Modules linked in:
>> [ 0.059780] CPU: 0 PID: 0 Comm: swapper Not tainted 4.0.9-20151211-1-g45dbe7d2c077 #1
>> [ 0.059966] Hardware name: Freescale i.MX25 (Device Tree Support)
>> [ 0.060157] [<8000f494>] (unwind_backtrace) from [<8000ce3c>] (show_stack+0x20/0x24)
>> [ 0.060396] [<8000ce3c>] (show_stack) from [<8041ea68>] (dump_stack+0x20/0x28)
>> [ 0.060630] [<8041ea68>] (dump_stack) from [<8001a74c>] (warn_slowpath_common+0x88/0xc0)
>> [ 0.060853] [<8001a74c>] (warn_slowpath_common) from [<8001a840>] (warn_slowpath_null+0x2c/0x34)
>> [ 0.061091] [<8001a840>] (warn_slowpath_null) from [<80083748>] (ftrace_bug+0x210/0x2c8)
>> [ 0.061332] [<80083748>] (ftrace_bug) from [<80083bb8>] (ftrace_process_locs+0x330/0x6f0)
>> [ 0.061576] [<80083bb8>] (ftrace_process_locs) from [<805bdc84>] (ftrace_init+0x8c/0x14c)
>> [ 0.061815] [<805bdc84>] (ftrace_init) from [<805b0c80>] (start_kernel+0x33c/0x3b4)
>> [ 0.062039] [<805b0c80>] (start_kernel) from [<80008040>] (0x80008040)
>> [ 0.062238] ---[ end trace cb88537fdc8fa200 ]---
>> [ 0.062364] ftrace failed to modify [<8000c7d8>] walk_stackframe+0x24/0x44
>> [ 0.062544] actual: 16:ff:2f:e1
>> [ 0.062702] ftrace record flags: 0
>> [ 0.062803] (0) expected tramp: 8000e864
>
> The problem is that walk_stackframe ends up in the __mcount_loc section,
> although it has a "notrace" attribute:
>
>> $ grep notrace arch/arm/kernel/stacktrace.c | grep walk_stackframe
>> void notrace walk_stackframe(struct stackframe *frame,
>
>
> To reproduce:
>
> - use the arm compiler from kernel.org:
>> https://www.kernel.org/pub/tools/crosstool/files/bin/x86_64/4.9.0/x86_64-gcc-4.9.0-nolibc_arm-unknown-linux-gnueabi.tar.xz
>
> - linus master
> (67990608c8b9 Merge tag 'pm+acpi-4.5-rc1-1' of
> git://git.kernel.org/pub/scm/linux/kernel/git/rafael/linux-pm)
>
> - a ARMv5 config
>> make imx_v4_v5_defconfig
>
> - switch on the function tracer and dynamic ftrace
>> CONFIG_HAVE_FUNCTION_TRACER=y
>> CONFIG_HAVE_FUNCTION_GRAPH_TRACER=y
>> CONFIG_HAVE_DYNAMIC_FTRACE=y
>
> - build the object file that contains walk_stackframe:
>> $ make arch/arm/kernel/stacktrace.o
>
>
> Observations:
>
> - There is no branch to the mcount function ("bl 0 <__gnu_mcount_nc>"),
> which is good:
>> $ objdump -d arch/arm/kernel/stacktrace.o |grep "<walk_stackframe>:" -A12
>> 00000000 <walk_stackframe>:
>> 0: e1a0c00d mov ip, sp
>> 4: e92dd878 push {r3, r4, r5, r6, fp, ip, lr, pc}
>> 8: e24cb004 sub fp, ip, #4
>> c: e1a04000 mov r4, r0
>> 10: e1a06001 mov r6, r1
>> 14: e1a05002 mov r5, r2
>> 18: e1a00004 mov r0, r4
>> 1c: e1a01005 mov r1, r5
>> 20: e1a0e00f mov lr, pc
>> 24: e12fff16 bx r6
>> 28: e3500000 cmp r0, #0
>> 2c: 189da878 ldmne sp, {r3, r4, r5, r6, fp, sp, pc}
>
> There are 5 calls to __gnu_mcount_nc in the object file:
>> $ objdump -x arch/arm/kernel/stacktrace.o | grep R_ARM_CALL | grep __gnu_mcount_nc
>> 00000054 R_ARM_CALL __gnu_mcount_nc
>> 0000016c R_ARM_CALL __gnu_mcount_nc
>> 00000234 R_ARM_CALL __gnu_mcount_nc
>> 0000026c R_ARM_CALL __gnu_mcount_nc
>> 000002f4 R_ARM_CALL __gnu_mcount_nc
>
> However there are 6 references in the __mcount_loc section:
>> $ readelf -R __mcount_loc arch/arm/kernel/stacktrace.o
>>
>> Hex dump of section '__mcount_loc':
>> 0x00000000 24000000 54000000 6c010000 34020000 $...T...l...4...
>> 0x00000010 6c020000 f4020000 l.......
>
> Note: The first and wrong offset is 0x24, which is a "bx r6" (see above
> objdump of stacktrace.o):
>> 24: e12fff16 bx r6
>
> I hacked scripts/Makefile.build to use the perl version of recordmcount,
> that works without problems.
Has anyone looked at this issue?
regards,
Marc
--
Pengutronix e.K. | Marc Kleine-Budde |
Industrial Linux Solutions | Phone: +49-231-2826-924 |
Vertretung West/Dortmund | Fax: +49-5121-206917-5555 |
Amtsgericht Hildesheim, HRA 2686 | http://www.pengutronix.de |
[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 455 bytes --]
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: dynamic ftrace/recordmcount.c problem on ARMv5
2016-02-08 15:38 ` Marc Kleine-Budde
@ 2016-02-08 15:53 ` Steven Rostedt
0 siblings, 0 replies; 10+ messages in thread
From: Steven Rostedt @ 2016-02-08 15:53 UTC (permalink / raw)
To: Marc Kleine-Budde; +Cc: linux-kernel, ptx kernel
On Mon, 8 Feb 2016 16:38:49 +0100
Marc Kleine-Budde <mkl@pengutronix.de> wrote:
> > I hacked scripts/Makefile.build to use the perl version of recordmcount,
> > that works without problems.
>
> Has anyone looked at this issue?
>
Sorry, I had a personal issue that took me offline for a while, and I
forgot about it. I'll try to make time this week to look into it.
-- Steve
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: dynamic ftrace/recordmcount.c problem on ARMv5
2016-01-13 8:51 dynamic ftrace/recordmcount.c problem on ARMv5 Marc Kleine-Budde
2016-01-13 16:08 ` Steven Rostedt
2016-02-08 15:38 ` Marc Kleine-Budde
@ 2016-03-11 9:21 ` Uwe Kleine-König
2016-03-20 3:48 ` Namhyung Kim
2 siblings, 1 reply; 10+ messages in thread
From: Uwe Kleine-König @ 2016-03-11 9:21 UTC (permalink / raw)
To: Marc Kleine-Budde; +Cc: linux-kernel, Steven Rostedt (Red Hat), ptx kernel
Hello,
On Wed, Jan 13, 2016 at 09:51:28AM +0100, Marc Kleine-Budde wrote:
> Hello,
>
> I'm on a ARMv5 (freescale mx25) and seeing this ftrace bug during bootup:
>
> > [ 0.059235] ------------[ cut here ]------------
> > [ 0.059449] WARNING: CPU: 0 PID: 0 at kernel/trace/ftrace.c:1938 ftrace_bug+0x210/0x2c8()
> > [ 0.059645] Modules linked in:
> > [ 0.059780] CPU: 0 PID: 0 Comm: swapper Not tainted 4.0.9-20151211-1-g45dbe7d2c077 #1
> > [ 0.059966] Hardware name: Freescale i.MX25 (Device Tree Support)
> > [ 0.060157] [<8000f494>] (unwind_backtrace) from [<8000ce3c>] (show_stack+0x20/0x24)
> > [ 0.060396] [<8000ce3c>] (show_stack) from [<8041ea68>] (dump_stack+0x20/0x28)
> > [ 0.060630] [<8041ea68>] (dump_stack) from [<8001a74c>] (warn_slowpath_common+0x88/0xc0)
> > [ 0.060853] [<8001a74c>] (warn_slowpath_common) from [<8001a840>] (warn_slowpath_null+0x2c/0x34)
> > [ 0.061091] [<8001a840>] (warn_slowpath_null) from [<80083748>] (ftrace_bug+0x210/0x2c8)
> > [ 0.061332] [<80083748>] (ftrace_bug) from [<80083bb8>] (ftrace_process_locs+0x330/0x6f0)
> > [ 0.061576] [<80083bb8>] (ftrace_process_locs) from [<805bdc84>] (ftrace_init+0x8c/0x14c)
> > [ 0.061815] [<805bdc84>] (ftrace_init) from [<805b0c80>] (start_kernel+0x33c/0x3b4)
> > [ 0.062039] [<805b0c80>] (start_kernel) from [<80008040>] (0x80008040)
> > [ 0.062238] ---[ end trace cb88537fdc8fa200 ]---
> > [ 0.062364] ftrace failed to modify [<8000c7d8>] walk_stackframe+0x24/0x44
> > [ 0.062544] actual: 16:ff:2f:e1
> > [ 0.062702] ftrace record flags: 0
> > [ 0.062803] (0) expected tramp: 8000e864
>
> The problem is that walk_stackframe ends up in the __mcount_loc section,
> although it has a "notrace" attribute:
Not having much clue about elf and stuff, but being hit by this problem
I added some debug output to recordmcount.c and found that
sift_rel_mcount (aka sift32_rel_mcount) loops over .rel.text which looks
as follows for me:
$ readelf -R .rel.text arch/arm/kernel/stacktrace.o
...
Relocation section '.rel.text' at offset 0xb5c contains 15 entries:
Offset Info Type Sym.Value Sym. Name
0000001c 00000028 R_ARM_V4BX
0000002c 00001d1c R_ARM_CALL 00000000 unwind_frame
00000044 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
00000104 0000201c R_ARM_CALL 00000000 in_sched_functions
00000118 00002102 R_ARM_ABS32 00000000 __exception_text_start
0000011c 00002202 R_ARM_ABS32 00000000 __exception_text_end
00000130 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
00000194 00001c1c R_ARM_CALL 00000000 walk_stackframe
000001e0 00000902 R_ARM_ABS32 0000003c save_trace
000001e4 00000c02 R_ARM_ABS32 00000120 __save_stack_trace
000001ec 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
00000218 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
00000260 00001c1c R_ARM_CALL 00000000 walk_stackframe
0000028c 00000902 R_ARM_ABS32 0000003c save_trace
00000294 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
...
and the unwanted entry in __mcount_loc is generated from the first line
which isn't a call, but just the information that there is a bx call
that needs a fixup for ARMv4 machines (that don't support the bx
instruction).
For this entry get_mcountsym returns 0.
recordmcount.pl only operates on R_ARM_(CALL|PC24|THM_CALL) types for
ARM and so does it right.
I don't know how to fix recordmcount.[ch], but maybe this is enough info
to allow someone more knowledgeable to fix it.
Best regards
Uwe
--
Pengutronix e.K. | Uwe Kleine-König |
Industrial Linux Solutions | http://www.pengutronix.de/ |
^ permalink raw reply [flat|nested] 10+ messages in thread
* Re: dynamic ftrace/recordmcount.c problem on ARMv5
2016-03-11 9:21 ` Uwe Kleine-König
@ 2016-03-20 3:48 ` Namhyung Kim
2016-03-20 20:00 ` Uwe Kleine-König
0 siblings, 1 reply; 10+ messages in thread
From: Namhyung Kim @ 2016-03-20 3:48 UTC (permalink / raw)
To: Uwe Kleine-König
Cc: Marc Kleine-Budde, linux-kernel, Steven Rostedt (Red Hat), ptx kernel
Hi,
On Fri, Mar 11, 2016 at 10:21:59AM +0100, Uwe Kleine-König wrote:
> Hello,
>
> On Wed, Jan 13, 2016 at 09:51:28AM +0100, Marc Kleine-Budde wrote:
> > Hello,
> >
> > I'm on a ARMv5 (freescale mx25) and seeing this ftrace bug during bootup:
> >
> > > [ 0.059235] ------------[ cut here ]------------
> > > [ 0.059449] WARNING: CPU: 0 PID: 0 at kernel/trace/ftrace.c:1938 ftrace_bug+0x210/0x2c8()
> > > [ 0.059645] Modules linked in:
> > > [ 0.059780] CPU: 0 PID: 0 Comm: swapper Not tainted 4.0.9-20151211-1-g45dbe7d2c077 #1
> > > [ 0.059966] Hardware name: Freescale i.MX25 (Device Tree Support)
> > > [ 0.060157] [<8000f494>] (unwind_backtrace) from [<8000ce3c>] (show_stack+0x20/0x24)
> > > [ 0.060396] [<8000ce3c>] (show_stack) from [<8041ea68>] (dump_stack+0x20/0x28)
> > > [ 0.060630] [<8041ea68>] (dump_stack) from [<8001a74c>] (warn_slowpath_common+0x88/0xc0)
> > > [ 0.060853] [<8001a74c>] (warn_slowpath_common) from [<8001a840>] (warn_slowpath_null+0x2c/0x34)
> > > [ 0.061091] [<8001a840>] (warn_slowpath_null) from [<80083748>] (ftrace_bug+0x210/0x2c8)
> > > [ 0.061332] [<80083748>] (ftrace_bug) from [<80083bb8>] (ftrace_process_locs+0x330/0x6f0)
> > > [ 0.061576] [<80083bb8>] (ftrace_process_locs) from [<805bdc84>] (ftrace_init+0x8c/0x14c)
> > > [ 0.061815] [<805bdc84>] (ftrace_init) from [<805b0c80>] (start_kernel+0x33c/0x3b4)
> > > [ 0.062039] [<805b0c80>] (start_kernel) from [<80008040>] (0x80008040)
> > > [ 0.062238] ---[ end trace cb88537fdc8fa200 ]---
> > > [ 0.062364] ftrace failed to modify [<8000c7d8>] walk_stackframe+0x24/0x44
> > > [ 0.062544] actual: 16:ff:2f:e1
> > > [ 0.062702] ftrace record flags: 0
> > > [ 0.062803] (0) expected tramp: 8000e864
> >
> > The problem is that walk_stackframe ends up in the __mcount_loc section,
> > although it has a "notrace" attribute:
>
> Not having much clue about elf and stuff, but being hit by this problem
> I added some debug output to recordmcount.c and found that
> sift_rel_mcount (aka sift32_rel_mcount) loops over .rel.text which looks
> as follows for me:
>
> $ readelf -R .rel.text arch/arm/kernel/stacktrace.o
> ...
> Relocation section '.rel.text' at offset 0xb5c contains 15 entries:
> Offset Info Type Sym.Value Sym. Name
> 0000001c 00000028 R_ARM_V4BX
> 0000002c 00001d1c R_ARM_CALL 00000000 unwind_frame
> 00000044 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
> 00000104 0000201c R_ARM_CALL 00000000 in_sched_functions
> 00000118 00002102 R_ARM_ABS32 00000000 __exception_text_start
> 0000011c 00002202 R_ARM_ABS32 00000000 __exception_text_end
> 00000130 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
> 00000194 00001c1c R_ARM_CALL 00000000 walk_stackframe
> 000001e0 00000902 R_ARM_ABS32 0000003c save_trace
> 000001e4 00000c02 R_ARM_ABS32 00000120 __save_stack_trace
> 000001ec 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
> 00000218 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
> 00000260 00001c1c R_ARM_CALL 00000000 walk_stackframe
> 0000028c 00000902 R_ARM_ABS32 0000003c save_trace
> 00000294 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
> ...
>
> and the unwanted entry in __mcount_loc is generated from the first line
> which isn't a call, but just the information that there is a bx call
> that needs a fixup for ARMv4 machines (that don't support the bx
> instruction).
>
> For this entry get_mcountsym returns 0.
>
> recordmcount.pl only operates on R_ARM_(CALL|PC24|THM_CALL) types for
> ARM and so does it right.
Hmm.. that means we need to check the reloc types? It seems the
binutils treats R_ARM_THM_PC22 as R_ARM_THM_CALL.
in /usr/include/elf.h:
#define R_ARM_SBREL32 9
#define R_ARM_THM_PC22 10 /* PC relative 24 bit (Thumb32 BL). */
#define R_ARM_THM_PC8 11 /* PC relative & 0x3FC
in binutils-gdb/include/elf/arm.h:
RELOC_NUMBER (R_ARM_SBREL32, 9)
RELOC_NUMBER (R_ARM_THM_CALL, 10)
RELOC_NUMBER (R_ARM_THM_PC8, 11)
So following patch (untested) works for you?
Thanks,
Namhyung
diff --git a/scripts/recordmcount.c b/scripts/recordmcount.c
index e167592793a7..dcc7896dce25 100644
--- a/scripts/recordmcount.c
+++ b/scripts/recordmcount.c
@@ -398,6 +398,20 @@ static void MIPS64_r_info(Elf64_Rel *const rp, unsigned sym, unsigned type)
}).r_info;
}
+static int ARM_is_fake_mcount(Elf32_Rel const *rp)
+{
+ unsigned r_type = ELF32_R_TYPE(w(rp->r_info));
+
+ switch (r_type) {
+ case R_ARM_CALL:
+ case R_ARM_PC24:
+ case R_ARM_THM_PC22:
+ return 0;
+ default:
+ return 1;
+ }
+}
+
static void
do_file(char const *const fname)
{
@@ -454,6 +468,7 @@ do_file(char const *const fname)
break;
case EM_ARM: reltype = R_ARM_ABS32;
altmcount = "__gnu_mcount_nc";
+ is_fake_mcount32 = ARM_is_fake_mcount;
break;
case EM_AARCH64:
reltype = R_AARCH64_ABS64;
^ permalink raw reply related [flat|nested] 10+ messages in thread
* Re: dynamic ftrace/recordmcount.c problem on ARMv5
2016-03-20 3:48 ` Namhyung Kim
@ 2016-03-20 20:00 ` Uwe Kleine-König
0 siblings, 0 replies; 10+ messages in thread
From: Uwe Kleine-König @ 2016-03-20 20:00 UTC (permalink / raw)
To: Namhyung Kim
Cc: ptx kernel, Marc Kleine-Budde, linux-kernel, Steven Rostedt (Red Hat)
Hello,
On Sun, Mar 20, 2016 at 12:48:30PM +0900, Namhyung Kim wrote:
> On Fri, Mar 11, 2016 at 10:21:59AM +0100, Uwe Kleine-König wrote:
> > On Wed, Jan 13, 2016 at 09:51:28AM +0100, Marc Kleine-Budde wrote:
> > > Hello,
> > >
> > > I'm on a ARMv5 (freescale mx25) and seeing this ftrace bug during bootup:
> > >
> > > > [ 0.059235] ------------[ cut here ]------------
> > > > [ 0.059449] WARNING: CPU: 0 PID: 0 at kernel/trace/ftrace.c:1938 ftrace_bug+0x210/0x2c8()
> > > > [ 0.059645] Modules linked in:
> > > > [ 0.059780] CPU: 0 PID: 0 Comm: swapper Not tainted 4.0.9-20151211-1-g45dbe7d2c077 #1
> > > > [ 0.059966] Hardware name: Freescale i.MX25 (Device Tree Support)
> > > > [ 0.060157] [<8000f494>] (unwind_backtrace) from [<8000ce3c>] (show_stack+0x20/0x24)
> > > > [ 0.060396] [<8000ce3c>] (show_stack) from [<8041ea68>] (dump_stack+0x20/0x28)
> > > > [ 0.060630] [<8041ea68>] (dump_stack) from [<8001a74c>] (warn_slowpath_common+0x88/0xc0)
> > > > [ 0.060853] [<8001a74c>] (warn_slowpath_common) from [<8001a840>] (warn_slowpath_null+0x2c/0x34)
> > > > [ 0.061091] [<8001a840>] (warn_slowpath_null) from [<80083748>] (ftrace_bug+0x210/0x2c8)
> > > > [ 0.061332] [<80083748>] (ftrace_bug) from [<80083bb8>] (ftrace_process_locs+0x330/0x6f0)
> > > > [ 0.061576] [<80083bb8>] (ftrace_process_locs) from [<805bdc84>] (ftrace_init+0x8c/0x14c)
> > > > [ 0.061815] [<805bdc84>] (ftrace_init) from [<805b0c80>] (start_kernel+0x33c/0x3b4)
> > > > [ 0.062039] [<805b0c80>] (start_kernel) from [<80008040>] (0x80008040)
> > > > [ 0.062238] ---[ end trace cb88537fdc8fa200 ]---
> > > > [ 0.062364] ftrace failed to modify [<8000c7d8>] walk_stackframe+0x24/0x44
> > > > [ 0.062544] actual: 16:ff:2f:e1
> > > > [ 0.062702] ftrace record flags: 0
> > > > [ 0.062803] (0) expected tramp: 8000e864
> > >
> > > The problem is that walk_stackframe ends up in the __mcount_loc section,
> > > although it has a "notrace" attribute:
> >
> > Not having much clue about elf and stuff, but being hit by this problem
> > I added some debug output to recordmcount.c and found that
> > sift_rel_mcount (aka sift32_rel_mcount) loops over .rel.text which looks
> > as follows for me:
> >
> > $ readelf -R .rel.text arch/arm/kernel/stacktrace.o
> > ...
> > Relocation section '.rel.text' at offset 0xb5c contains 15 entries:
> > Offset Info Type Sym.Value Sym. Name
> > 0000001c 00000028 R_ARM_V4BX
> > 0000002c 00001d1c R_ARM_CALL 00000000 unwind_frame
> > 00000044 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
> > 00000104 0000201c R_ARM_CALL 00000000 in_sched_functions
> > 00000118 00002102 R_ARM_ABS32 00000000 __exception_text_start
> > 0000011c 00002202 R_ARM_ABS32 00000000 __exception_text_end
> > 00000130 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
> > 00000194 00001c1c R_ARM_CALL 00000000 walk_stackframe
> > 000001e0 00000902 R_ARM_ABS32 0000003c save_trace
> > 000001e4 00000c02 R_ARM_ABS32 00000120 __save_stack_trace
> > 000001ec 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
> > 00000218 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
> > 00000260 00001c1c R_ARM_CALL 00000000 walk_stackframe
> > 0000028c 00000902 R_ARM_ABS32 0000003c save_trace
> > 00000294 00001f1c R_ARM_CALL 00000000 __gnu_mcount_nc
> > ...
> >
> > and the unwanted entry in __mcount_loc is generated from the first line
> > which isn't a call, but just the information that there is a bx call
> > that needs a fixup for ARMv4 machines (that don't support the bx
> > instruction).
> >
> > For this entry get_mcountsym returns 0.
> >
> > recordmcount.pl only operates on R_ARM_(CALL|PC24|THM_CALL) types for
> > ARM and so does it right.
>
> Hmm.. that means we need to check the reloc types? It seems the
> binutils treats R_ARM_THM_PC22 as R_ARM_THM_CALL.
>
> in /usr/include/elf.h:
> #define R_ARM_SBREL32 9
> #define R_ARM_THM_PC22 10 /* PC relative 24 bit (Thumb32 BL). */
> #define R_ARM_THM_PC8 11 /* PC relative & 0x3FC
>
> in binutils-gdb/include/elf/arm.h:
> RELOC_NUMBER (R_ARM_SBREL32, 9)
> RELOC_NUMBER (R_ARM_THM_CALL, 10)
> RELOC_NUMBER (R_ARM_THM_PC8, 11)
>
>
> So following patch (untested) works for you?
Yes, it changes the output of $(readelf -R __mcount_loc
arch/arm/kernel/stacktrace.o) from
Hex dump of section '__mcount_loc':
0x00000000 24000000 54000000 6c010000 34020000 $...T...l...4...
0x00000010 6c020000 f4020000 l.......
to
Hex dump of section '__mcount_loc':
0x00000000 54000000 6c010000 34020000 6c020000 T...l...4...l...
0x00000010 f4020000 ....
on top of 4.5. I don't have the machine handy where I saw the problem,
so I cannot test at the moment, but I assume your change is fine.
Thanks
Uwe
--
Pengutronix e.K. | Uwe Kleine-König |
Industrial Linux Solutions | http://www.pengutronix.de/ |
^ permalink raw reply [flat|nested] 10+ messages in thread
end of thread, other threads:[~2016-03-20 20:00 UTC | newest]
Thread overview: 10+ messages (download: mbox.gz / follow: Atom feed)
-- links below jump to the message on this page --
2016-01-13 8:51 dynamic ftrace/recordmcount.c problem on ARMv5 Marc Kleine-Budde
2016-01-13 16:08 ` Steven Rostedt
2016-01-13 16:23 ` Marc Kleine-Budde
2016-01-13 16:27 ` Steven Rostedt
2016-01-13 16:30 ` Marc Kleine-Budde
2016-02-08 15:38 ` Marc Kleine-Budde
2016-02-08 15:53 ` Steven Rostedt
2016-03-11 9:21 ` Uwe Kleine-König
2016-03-20 3:48 ` Namhyung Kim
2016-03-20 20:00 ` Uwe Kleine-König
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox;
as well as URLs for NNTP newsgroup(s).