Re: ppc64le: ftrace self-tests and $(CC_FLAGS_FTRACE) broken?
On 3/23/19 1:27 PM, Joe Lawrence wrote: On 03/23/2019 12:17 PM, Steven Rostedt wrote: On Sat, 23 Mar 2019 09:19:50 -0400 Joe Lawrence wrote: Perhaps this is gcc version specific? I didn't see any other reports, so maybe its specific to my config. If I run make V=1, I can see that gcc is called with '-pg -mprofile-kernel', but then the record_mcount script is skipped. Any ideas? But you see it running the script if you remove that commit? Do you happen to see -mrecord-mcount at all in a V=1 make? See entire make output from the two runs here: http://people.redhat.com/~jolawren/ppc64le-mprofile/ Mystery solved! That other commit inadvertently added a trailing space to CC_FLAGS_FTRACE, which then confused the findstring call in the cmd_record_mcount Makefile function. Workaround patch just posted ... kbuild experts can suggest better fixes if that one is sub optimal. Thanks, -- Joe
Re: ppc64le: ftrace self-tests and $(CC_FLAGS_FTRACE) broken?
On 03/23/2019 12:17 PM, Steven Rostedt wrote: On Sat, 23 Mar 2019 09:19:50 -0400 Joe Lawrence wrote: Perhaps this is gcc version specific? I didn't see any other reports, so maybe its specific to my config. If I run make V=1, I can see that gcc is called with '-pg -mprofile-kernel', but then the record_mcount script is skipped. Any ideas? But you see it running the script if you remove that commit? Do you happen to see -mrecord-mcount at all in a V=1 make? See entire make output from the two runs here: http://people.redhat.com/~jolawren/ppc64le-mprofile/ -- Joe
Re: ppc64le: ftrace self-tests and $(CC_FLAGS_FTRACE) broken?
On Sat, Mar 23, 2019 at 12:17:32PM -0400, Steven Rostedt wrote: > On Sat, 23 Mar 2019 09:19:50 -0400 > Joe Lawrence wrote: > > > Perhaps this is gcc version specific? I didn't see any other reports, > > so maybe its specific to my config. If I run make V=1, I can see that > > gcc is called with '-pg -mprofile-kernel', but then the record_mcount > > script is skipped. Any ideas? > > But you see it running the script if you remove that commit? Do you > happen to see -mrecord-mcount at all in a V=1 make? > Hey Steve, Here's a diff of output from 'make V=1 kernel/trace/trace_selftest_dynamic.o' with stock v5.0 vs. v5.0 and that commit reverted. The part that I think is interesting is where it decides to invoke recordmcount.pl I can send or pastebin the entire output from make if that is easier to read. -- Joe --- v5.0.out2019-03-23 12:54:09.540042581 -0400 +++ v5.0-revert.out 2019-03-23 12:53:05.253264482 -0400 @@ -20,29 +20,18 @@ make -f ./scripts/Makefile.build obj=scr make -f ./scripts/Makefile.build obj=scripts/selinux/genheaders need-builtin= make -f ./scripts/Makefile.build obj=scripts/selinux/mdp need-builtin= make -f ./scripts/Makefile.build obj=scripts/mod - gcc -Wp,-MD,scripts/mod/.empty.o.d -nostdinc -isystem /usr/lib/gcc/ppc64le-redhat-linux/8/include -I./arch/powerpc/include -I./arch/powerpc/include/generated -I./include -I./arch/powerpc/include/uapi -I./arch/powerpc/include/generated/uapi -I./include/uapi -I./include/generated/uapi -include ./include/linux/kconfig.h -include ./include/linux/compiler_types.h -D__KERNEL__ -Iarch/powerpc -DHAVE_AS_ATHIGH=1 -Wall -Wundef -Werror=strict-prototypes -Wno-trigraphs -fno-strict-aliasing -fno-common -fshort-wchar -fno-PIE -Werror=implicit-function-declaration -Werror=implicit-int -Wno-format-security -std=gnu89 -mlittle-endian -m64 -msoft-float -pipe -mtraceback=no -mabi=elfv2 -mcmodel=medium -mno-pointers-to-nested-functions -mcpu=power8 -mtune=power9 -mno-altivec -mno-vsx -fno-dwarf2-cfi-asm -mno-string -Wa,-maltivec -Wa,-mpower4 -Wa,-many -mno-strict-align -mlittle-endian -mstack-protector-guard=tls -mstack-protector-guard-reg=r13 -fno-delete-null-pointer-checks -Wno-frame-address -Wno-format-truncation -Wno-format-overflow -Wno-int-in-bool-context -O2 --param=allow-store-data-races=0 -Wframe-larger-than=2048 -fstack-protector-strong -Wno-unused-but-set-variable -Wno-unused-const-variable -fno-var-tracking-assignments -g -gdwarf-4 -pg -mprofile-kernel -fno-inline-functions-called-once -Wdeclaration-after-statement -Wvla -Wno-pointer-sign -Wno-stringop-truncation -fno-strict-overflow -fno-merge-all-constants -fmerge-constants -fno-stack-check -fconserve-stack -Werror=date-time -Werror=incompatible-pointer-types -Werror=designated-init -fmacro-prefix-map=./= -Wno-packed-not-aligned-DKBUILD_BASENAME='"empty"' -DKBUILD_MODNAME='"empty"' -c -o scripts/mod/empty.o scripts/mod/empty.c - if objdump -h scripts/mod/empty.o | grep -q __ksymtab; then gcc -E -Wall -Wundef -Werror=strict-prototypes -Wno-trigraphs -fno-strict-aliasing -fno-common -fshort-wchar -fno-PIE -Werror=implicit-function-declaration -Werror=implicit-int -Wno-format-security -std=gnu89 -mlittle-endian -m64 -msoft-float -pipe -mtraceback=no -mabi=elfv2 -mcmodel=medium -mno-pointers-to-nested-functions -mcpu=power8 -mtune=power9 -mno-altivec -mno-vsx -fno-dwarf2-cfi-asm -mno-string -Wa,-maltivec -Wa,-mpower4 -Wa,-many -mno-strict-align -mlittle-endian -mstack-protector-guard=tls -mstack-protector-guard-reg=r13 -fno-delete-null-pointer-checks -Wno-frame-address -Wno-format-truncation -Wno-format-overflow -Wno-int-in-bool-context -O2 --param=allow-store-data-races=0 -Wframe-larger-than=2048 -fstack-protector-strong -Wno-unused-but-set-variable -Wno-unused-const-variable -fno-var-tracking-assignments -g -gdwarf-4 -pg -mprofile-kernel-fno-inline-functions-called-once -Wdeclaration-after-statement -Wvla -Wno-pointer-sign -Wno-stringop-truncation -fno-strict-overflow -fno-merge-all-constants -fmerge-constants -fno-stack-check -fconserve-stack -Werror=date-time -Werror=incompatible-pointer-types -Werror=designated-init -fmacro-prefix-map=./= -Wno-packed-not-aligned -D__GENKSYMS__ -Wp,-MD,scripts/mod/.empty.o.d -nostdinc -isystem /usr/lib/gcc/ppc64le-redhat-linux/8/include -I./arch/powerpc/include -I./arch/powerpc/include/generated -I./include -I./arch/powerpc/include/uapi -I./arch/powerpc/include/generated/uapi -I./include/uapi -I./include/generated/uapi -include ./include/linux/kconfig.h -include ./include/linux/compiler_types.h -D__KERNEL__ -Iarch/powerpc -DHAVE_AS_ATHIGH=1 -Wall -Wundef -Werror=strict-prototypes -Wno-trigraphs -fno-strict-aliasing -fno-common -fshort-wchar -fno-PIE -Werror=implicit-function-declaration -Werror=implicit-int -Wno-format-security -std=gnu89 -mlittle-endian -m64 -msoft-float -pipe -mtraceback=no -mabi=elfv2 -mcmodel=medium -mno-pointers-to-nested-functions -mcpu=power8
Re: ppc64le: ftrace self-tests and $(CC_FLAGS_FTRACE) broken?
On Sat, 23 Mar 2019 09:19:50 -0400 Joe Lawrence wrote: > Perhaps this is gcc version specific? I didn't see any other reports, > so maybe its specific to my config. If I run make V=1, I can see that > gcc is called with '-pg -mprofile-kernel', but then the record_mcount > script is skipped. Any ideas? But you see it running the script if you remove that commit? Do you happen to see -mrecord-mcount at all in a V=1 make? -- Steve
ppc64le: ftrace self-tests and $(CC_FLAGS_FTRACE) broken?
Hi Steve, Nicholas,
I stumbled across this while working on livepatch self-tests, which like
the ftrace self-tests, specify $(CC_FLAGS_FTRACE) to ensure that target
functions are indeed trace-able.
On ppc64le, v5.0 fails the self-tests on my machine:
% gcc --version
gcc (GCC) 8.2.1 20180905 (Red Hat 8.2.1-3)
% git checkout v5.0
% grep FTRACE_SELFTEST .config
CONFIG_FTRACE_SELFTEST=y
After building the kernel, I noticed no mcount sections and of course
the self-tests fail as it can't hook functions:
% readelf --sections kernel/trace/trace_selftest_dynamic.o | grep mcount
(nothing)
[ ... snip ... ]
[ 126.147892] Testing all events: OK
[ 126.390487] WARNING: CPU: 0 PID: 1 at kernel/trace/trace_events.c:3421
event_trace_self_tests_init+0x94/0xf4
[ 126.390498] Modules linked in:
[ 126.390510] CPU: 0 PID: 1 Comm: swapper/0 Tainted: GW
5.0.0 #10
[ 126.390520] NIP: c0f044d4 LR: c0f044cc CTR:
c0b63d70
[ 126.390530] REGS: c001fb183910 TRAP: 0700 Tainted: GW
(5.0.0)
[ 126.390540] MSR: 82029033 CR:
28000222 XER: 20040007
[ 126.390564] CFAR: c025b1f4 IRQMASK: 0
[ 126.390564] GPR00: c0f044cc c001fb183ba0 c1453c00
ffed
[ 126.390564] GPR04: c17a0aac 037d
c001fb142d00
[ 126.390564] GPR08: 0001
[ 126.390564] GPR12: c188 c0010530
[ 126.390564] GPR16:
[ 126.390564] GPR20:
[ 126.390564] GPR24: c0eb8908
c0f4ea68
[ 126.390564] GPR28: c0f4eaa8 c0f04440
c0f581a8
[ 126.390662] NIP [c0f044d4] event_trace_self_tests_init+0x94/0xf4
[ 126.390672] LR [c0f044cc] event_trace_self_tests_init+0x8c/0xf4
[ 126.390682] Call Trace:
[ 126.390690] [c001fb183ba0] [c0f044cc]
event_trace_self_tests_init+0x8c/0xf4 (unreliable)
[ 126.390705] [c001fb183c10] [c0010134]
do_one_initcall+0x64/0x264
[ 126.390719] [c001fb183ce0] [c0ed443c]
kernel_init_freeable+0x36c/0x470
[ 126.390731] [c001fb183db0] [c0010554] kernel_init+0x2c/0x148
[ 126.390744] [c001fb183e20] [c000b65c]
ret_from_kernel_thread+0x5c/0x80
[ 126.390755] Instruction dump:
[ 126.390765] 3fe2ffb0 f9284578 3bff3d50 794ad182 0b0a 2fa9 419e0058
3bff0858
[ 126.390789] 7fe3fb78 4b356cc1 6000 54690ffe <0b09> 2f83
409c0018 3c62ff96
[ 126.390814] ---[ end trace b5898e7f7f73e163 ]---
[ 126.390822] Failed to enable function tracer for event tests
I git bisected to 6977f95e63b9 ("powerpc: avoid -mno-sched-epilog on GCC
4.9 and newer"). Reverting this change and rebuilding, I could see the
mcount sections once again:
% readelf --sections kernel/trace/trace_selftest_dynamic.o | grep mcount
[ 3] __mcount_loc PROGBITS 0060
[ 4] .rela__mcount_loc RELA 000258c8
Reboot and the self-test now passes.
Perhaps this is gcc version specific? I didn't see any other reports,
so maybe its specific to my config. If I run make V=1, I can see that
gcc is called with '-pg -mprofile-kernel', but then the record_mcount
script is skipped. Any ideas?
Regards,
-- Joe
