2023-04-20 07:09:11

by kernel test robot

[permalink] [raw]
Subject: [linus:master] [ftrace] b56c68f705: WARNING:at_samples/ftrace/ftrace-ops.c:#ops_alloc_init

Hello,

kernel test robot noticed "WARNING:at_samples/ftrace/ftrace-ops.c:#ops_alloc_init" on:

commit: b56c68f705cad0cff61fbe132c66ced2c737c65c ("ftrace: Add sample with custom ops")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master

[test failed on linux-next/master 4aa1da8d99724f6c0b762b58a71cee7c5e2e109b]

in testcase: boot

compiler: gcc-11
test machine: qemu-system-x86_64 -enable-kvm -cpu SandyBridge -smp 2 -m 16G

(please refer to attached dmesg/kmsg for entire log/backtrace)


If you fix the issue, kindly add following tag
| Reported-by: kernel test robot <[email protected]>
| Link: https://lore.kernel.org/oe-lkp/[email protected]


[ 26.436367][ T1] ------------[ cut here ]------------
[ 26.437610][ T1] WARNING: CPU: 0 PID: 1 at samples/ftrace/ftrace-ops.c:132 ops_alloc_init+0x125/0x1c1
[ 26.439984][ T1] Modules linked in:
[ 26.440925][ T1] CPU: 0 PID: 1 Comm: swapper Not tainted 6.2.0-rc5-00013-gb56c68f705ca #1
[ 26.442875][ T1] RIP: ops_alloc_init+0x125/0x1c1
[ 26.444388][ T1] Code: 46 5f fd 48 8b 45 c8 48 89 03 48 8b 45 c0 48 89 43 10 b9 01 00 00 00 31 d2 be 01 00 00 00 48 c7 c7 50 ed cc 85 e8 72 91 63 fd <0f> 0b b9 01 00 00 00 31 d2 be 01 00 00 00 48 c7 c7 20 ed cc 85 e8
All code
========
0: 46 5f rex.RX pop %rdi
2: fd std
3: 48 8b 45 c8 mov -0x38(%rbp),%rax
7: 48 89 03 mov %rax,(%rbx)
a: 48 8b 45 c0 mov -0x40(%rbp),%rax
e: 48 89 43 10 mov %rax,0x10(%rbx)
12: b9 01 00 00 00 mov $0x1,%ecx
17: 31 d2 xor %edx,%edx
19: be 01 00 00 00 mov $0x1,%esi
1e: 48 c7 c7 50 ed cc 85 mov $0xffffffff85cced50,%rdi
25: e8 72 91 63 fd call 0xfffffffffd63919c
2a:* 0f 0b ud2 <-- trapping instruction
2c: b9 01 00 00 00 mov $0x1,%ecx
31: 31 d2 xor %edx,%edx
33: be 01 00 00 00 mov $0x1,%esi
38: 48 c7 c7 20 ed cc 85 mov $0xffffffff85cced20,%rdi
3f: e8 .byte 0xe8

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: b9 01 00 00 00 mov $0x1,%ecx
7: 31 d2 xor %edx,%edx
9: be 01 00 00 00 mov $0x1,%esi
e: 48 c7 c7 20 ed cc 85 mov $0xffffffff85cced20,%rdi
15: e8 .byte 0xe8
[ 26.448712][ T1] RSP: 0000:ffff88810033bdc8 EFLAGS: 00010293
[ 26.450091][ T1] RAX: 0000000000000000 RBX: ffff888108f12680 RCX: 0000000000000000
[ 26.451822][ T1] RDX: ffff888100334000 RSI: ffffffff812b7786 RDI: 0000000000000003
[ 26.453584][ T1] RBP: ffff88810033be08 R08: 0000000000000001 R09: ffff888108f12680
[ 26.455406][ T1] R10: 0000000000000000 R11: ffff888100040298 R12: ffff888108f12680
[ 26.457138][ T1] R13: 0000000000000000 R14: 0000000000000000 R15: ffffffff84ac6169
[ 26.458904][ T1] FS: 0000000000000000(0000) GS:ffffffff85065000(0000) knlGS:0000000000000000
[ 26.460915][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 26.462398][ T1] CR2: ffff88843ffff000 CR3: 0000000005027000 CR4: 00000000000406f0
[ 26.464202][ T1] Call Trace:
[ 26.464948][ T1] <TASK>
[ 26.465618][ T1] ? tracee_irrelevant (samples/ftrace/ftrace-ops.c:103)
[ 26.466782][ T1] ftrace_ops_sample_init (samples/ftrace/ftrace-ops.c:209)
[ 26.468062][ T1] ? hte_subsys_dbgfs_init (samples/ftrace/ftrace-ops.c:170)
[ 26.469268][ T1] do_one_initcall (init/main.c:1306)
[ 26.470362][ T1] ? write_comp_data (kernel/kcov.c:236)
[ 26.471509][ T1] do_initcalls (init/main.c:1378 init/main.c:1395)
[ 26.472618][ T1] kernel_init_freeable (init/main.c:1638)
[ 26.473787][ T1] ? rest_init (init/main.c:1514)
[ 26.474834][ T1] kernel_init (init/main.c:1524)
[ 26.475826][ T1] ? rest_init (init/main.c:1514)
[ 26.476799][ T1] ret_from_fork (arch/x86/entry/entry_64.S:314)
[ 26.477904][ T1] </TASK>
[ 26.478612][ T1] irq event stamp: 2116901
[ 26.479591][ T1] hardirqs last enabled at (2116909): __up_console_sem (kernel/printk/printk.c:345 (discriminator 1))
[ 26.481781][ T1] hardirqs last disabled at (2116918): __up_console_sem (kernel/printk/printk.c:343 (discriminator 1))
[ 26.483938][ T1] softirqs last enabled at (2116626): __do_softirq (arch/x86/include/asm/preempt.h:27 kernel/softirq.c:415 kernel/softirq.c:600)
[ 26.486103][ T1] softirqs last disabled at (2116615): irq_exit_rcu (kernel/softirq.c:625)
[ 26.488217][ T1] ---[ end trace 0000000000000000 ]---
[ 26.532899][ T1] ftrace_ops: Attempted 100000 calls to tracee_relevant in 43401441ns (434ns / call)
[ 26.535738][ T1] initcall ftrace_ops_sample_init+0x0/0x2aa returned -22 after 108559 usecs


To reproduce:

# build kernel
cd linux
cp config-6.2.0-rc5-00013-gb56c68f705ca .config
make HOSTCC=gcc-11 CC=gcc-11 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage modules
make HOSTCC=gcc-11 CC=gcc-11 ARCH=x86_64 INSTALL_MOD_PATH=<mod-install-dir> modules_install
cd <mod-install-dir>
find lib/ | cpio -o -H newc --quiet | gzip > modules.cgz


git clone https://github.com/intel/lkp-tests.git
cd lkp-tests
bin/lkp qemu -k <bzImage> -m modules.cgz job-script # job-script is attached in this email

# if come across any failure that blocks the test,
# please remove ~/.lkp and /lkp dir to run from a clean state.


--
0-DAY CI Kernel Test Service
https://github.com/intel/lkp-tests


Attachments:
(No filename) (5.52 kB)
config-6.2.0-rc5-00013-gb56c68f705ca (172.79 kB)
job-script (4.74 kB)
dmesg.xz (65.51 kB)
Download all attachments