dynamic ftrace/recordmcount.c problem on ARMv5

From: Marc Kleine-Budde
Date: Wed Jan 13 2016 - 03:51:47 EST

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: signature.asc
Description: OpenPGP digital signature