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

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

[kernel test robot]

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@intel.com>
| Closes: https://lore.kernel.org/oe-lkp/202309242249.94de41a1-oliver.sang@intel.com


[   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@intel.com



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