[linus:master] [tracing] 9fe41efaca: WARNING:at_kernel/trace/trace_events.c:#event_trace_self_tests_init

From: kernel test robot
Date: Sun Sep 24 2023 - 11:15:13 EST




Hello,

kernel test robot noticed "WARNING:at_kernel/trace/trace_events.c:#event_trace_self_tests_init" on:

commit: 9fe41efaca08416657efa8731c0d47ccb6a3f3eb ("tracing: Add synth event generation test module")
https://git.kernel.org/cgit/linux/kernel/git/torvalds/linux.git master

in testcase: boot

compiler: gcc-7
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 in a separate patch/commit (i.e. not just a new version of
the same patch/commit), kindly add following tags
| Reported-by: kernel test robot <oliver.sang@xxxxxxxxx>
| Closes: https://lore.kernel.org/oe-lkp/202309242249.94de41a1-oliver.sang@xxxxxxxxx


[ 43.576702][ T1] ------------[ cut here ]------------
[ 43.577569][ T1] WARNING: CPU: 1 PID: 1 at kernel/trace/trace_events.c:3403 event_trace_self_tests_init (kernel/trace/trace_events.c:3402 kernel/trace/trace_events.c:3546)
[ 43.579528][ T1] Modules linked in:
[ 43.580160][ T1] CPU: 1 PID: 1 Comm: swapper/0 Not tainted 5.5.0-rc6-00065-g9fe41efaca0841 #1
[ 43.581559][ T1] RIP: 0010:event_trace_self_tests_init (kernel/trace/trace_events.c:3402 kernel/trace/trace_events.c:3546)
[ 43.582586][ T1] Code: fc 48 8d 7d 48 48 89 f8 48 c1 e8 03 42 80 3c 20 00 74 05 e8 fd 3b c6 fc f6 45 48 01 74 10 48 c7 c7 20 4a 91 8b e8 6f 10 8a fc <0f> 0b eb 2c 31 d2 be 01 00 00 00 48 89 ef e8 b8 a1 9f fc e8 b6 fa
All code
========
0: fc cld
1: 48 8d 7d 48 lea 0x48(%rbp),%rdi
5: 48 89 f8 mov %rdi,%rax
8: 48 c1 e8 03 shr $0x3,%rax
c: 42 80 3c 20 00 cmpb $0x0,(%rax,%r12,1)
11: 74 05 je 0x18
13: e8 fd 3b c6 fc callq 0xfffffffffcc63c15
18: f6 45 48 01 testb $0x1,0x48(%rbp)
1c: 74 10 je 0x2e
1e: 48 c7 c7 20 4a 91 8b mov $0xffffffff8b914a20,%rdi
25: e8 6f 10 8a fc callq 0xfffffffffc8a1099
2a:* 0f 0b ud2 <-- trapping instruction
2c: eb 2c jmp 0x5a
2e: 31 d2 xor %edx,%edx
30: be 01 00 00 00 mov $0x1,%esi
35: 48 89 ef mov %rbp,%rdi
38: e8 b8 a1 9f fc callq 0xfffffffffc9fa1f5
3d: e8 .byte 0xe8
3e: b6 fa mov $0xfa,%dh

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: eb 2c jmp 0x30
4: 31 d2 xor %edx,%edx
6: be 01 00 00 00 mov $0x1,%esi
b: 48 89 ef mov %rbp,%rdi
e: e8 b8 a1 9f fc callq 0xfffffffffc9fa1cb
13: e8 .byte 0xe8
14: b6 fa mov $0xfa,%dh
[ 43.585621][ T1] RSP: 0000:ffff8883ac827dd8 EFLAGS: 00010286
[ 43.586569][ T1] RAX: 000000000000001f RBX: ffffffff8c38ae60 RCX: 0000000000000000
[ 43.587821][ T1] RDX: 000000000000001f RSI: 0000000000000006 RDI: ffffed1075904fb1
[ 43.589057][ T1] RBP: ffff8883ad2d5618 R08: 00000000001f1194 R09: 0000000000000000
[ 43.590290][ T1] R10: 0000000000000001 R11: 0000000000000000 R12: dffffc0000000000
[ 43.591532][ T1] R13: ffff88837e7ed340 R14: ffff88837e5c6880 R15: ffffffff8c38cb78
[ 43.596827][ T1] FS: 0000000000000000(0000) GS:ffff8883af000000(0000) knlGS:0000000000000000
[ 43.598225][ T1] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 43.599253][ T1] CR2: 0000000000000000 CR3: 000000009a015000 CR4: 00000000000406e0
[ 43.600508][ T1] Call Trace:
[ 43.601044][ T1] ? test_work (kernel/trace/trace_events.c:3545)
[ 43.601718][ T1] do_one_initcall (init/main.c:1107)
[ 43.602455][ T1] ? boot_config_checksum (init/main.c:1098)
[ 43.603274][ T1] ? rcu_read_lock_sched_held (include/linux/lockdep.h:361 kernel/rcu/update.c:122)
[ 43.604158][ T1] ? rcu_read_lock_bh_held (kernel/rcu/update.c:117)
[ 43.604997][ T1] ? test_bit (arch/x86/include/asm/bitops.h:214 include/asm-generic/bitops/instrumented-non-atomic.h:111)
[ 43.605662][ T1] kernel_init_freeable (init/main.c:1174 init/main.c:1190 init/main.c:1210 init/main.c:1381)
[ 43.606481][ T1] ? rest_init (init/main.c:1285)
[ 43.607182][ T1] kernel_init (init/main.c:1290)
[ 43.607865][ T1] ? _raw_spin_unlock_irq (arch/x86/include/asm/irqflags.h:54 arch/x86/include/asm/irqflags.h:94 include/linux/spinlock_api_smp.h:168 kernel/locking/spinlock.c:199)
[ 43.608678][ T1] ? rest_init (init/main.c:1285)
[ 43.609368][ T1] ret_from_fork (arch/x86/entry/entry_64.S:358)
[ 43.610087][ T1] irq event stamp: 6455462
[ 43.610784][ T1] hardirqs last enabled at (6455461): console_unlock (arch/x86/include/asm/irqflags.h:41 (discriminator 2) arch/x86/include/asm/irqflags.h:84 (discriminator 2) kernel/printk/printk.c:2502 (discriminator 2))
[ 43.612288][ T1] hardirqs last disabled at (6455462): trace_hardirqs_off_thunk (arch/x86/entry/thunk_64.S:42)
[ 43.613880][ T1] softirqs last enabled at (6455326): __do_softirq (arch/x86/include/asm/preempt.h:26 kernel/softirq.c:320)
[ 43.615340][ T1] softirqs last disabled at (6455313): irq_exit (kernel/softirq.c:373 kernel/softirq.c:413)
[ 43.616764][ T1] ---[ end trace a06cced81771bf57 ]---
[ 43.617997][ T1] Testing event empty_synth_test:
[ 43.618000][ T1] Enabled event during self test!
[ 43.619614][ T1] Testing event gen_synth_test:


The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20230924/202309242249.94de41a1-oliver.sang@xxxxxxxxx



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