[anna-maria-devel:timers/misc] [timers/migration] ee1ad08e03: WARNING:at_kernel/time/timer_migration.c:#tmigr_cpu_prepare

From: kernel test robot
Date: Thu Jul 25 2024 - 03:11:49 EST



Hello,

kernel test robot noticed "WARNING:at_kernel/time/timer_migration.c:#tmigr_cpu_prepare" on:

commit: ee1ad08e0366fe66622aef140c22ebb380d959a7 ("timers/migration: Move hierarchy setup into cpuhotplug prepare callback")
https://git.kernel.org/cgit/linux/kernel/git/anna-maria/linux-devel.git timers/misc

in testcase: boot

compiler: clang-18
test machine: qemu-system-i386 -enable-kvm -cpu SandyBridge -smp 2 -m 4G

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


+-------------------------------------------------------------+------------+------------+
| | 9714ad78e6 | ee1ad08e03 |
+-------------------------------------------------------------+------------+------------+
| WARNING:at_kernel/time/timer_migration.c:#tmigr_cpu_prepare | 0 | 6 |
| EIP:tmigr_cpu_prepare | 0 | 6 |
+-------------------------------------------------------------+------------+------------+


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/202407251320.b449fbc6-lkp@xxxxxxxxx


[ 0.525858][ T1] ------------[ cut here ]------------
[ 0.526356][ T1] WARNING: CPU: 0 PID: 1 at kernel/time/timer_migration.c:1742 tmigr_cpu_prepare (kernel/time/timer_migration.c:1742)
[ 0.527259][ T1] Modules linked in:
[ 0.527605][ T1] CPU: 0 PID: 1 Comm: swapper/0 Not tainted 6.10.0-00002-gee1ad08e0366 #1
[ 0.527898][ T1] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.16.2-debian-1.16.2-1 04/01/2014
[ 0.528831][ T1] EIP: tmigr_cpu_prepare (kernel/time/timer_migration.c:1742)
[ 0.529299][ T1] Code: ff ff f6 05 47 9e 65 c2 01 0f 85 21 fe ff ff c6 05 47 9e 65 c2 01 68 43 d4 03 c2 e8 d8 d4 f2 ff 83 c4 04 0f 0b e9 06 fe ff ff <0f> 0b e9 e6 fa ff ff e8 ea 5d ac 00 eb aa 56 68 00 a2 52 c2 e8 15
All code
========
0: ff (bad)
1: ff f6 push %rsi
3: 05 47 9e 65 c2 add $0xc2659e47,%eax
8: 01 0f add %ecx,(%rdi)
a: 85 21 test %esp,(%rcx)
c: fe (bad)
d: ff (bad)
e: ff c6 inc %esi
10: 05 47 9e 65 c2 add $0xc2659e47,%eax
15: 01 68 43 add %ebp,0x43(%rax)
18: d4 (bad)
19: 03 c2 add %edx,%eax
1b: e8 d8 d4 f2 ff call 0xfffffffffff2d4f8
20: 83 c4 04 add $0x4,%esp
23: 0f 0b ud2
25: e9 06 fe ff ff jmp 0xfffffffffffffe30
2a:* 0f 0b ud2 <-- trapping instruction
2c: e9 e6 fa ff ff jmp 0xfffffffffffffb17
31: e8 ea 5d ac 00 call 0xac5e20
36: eb aa jmp 0xffffffffffffffe2
38: 56 push %rsi
39: 68 00 a2 52 c2 push $0xffffffffc252a200
3e: e8 .byte 0xe8
3f: 15 .byte 0x15

Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: e9 e6 fa ff ff jmp 0xfffffffffffffaed
7: e8 ea 5d ac 00 call 0xac5df6
c: eb aa jmp 0xffffffffffffffb8
e: 56 push %rsi
f: 68 00 a2 52 c2 push $0xffffffffc252a200
14: e8 .byte 0xe8
15: 15 .byte 0x15
[ 0.531045][ T1] EAX: dbe85914 EBX: 00000000 ECX: 00000000 EDX: 00000040
[ 0.531668][ T1] ESI: 00000000 EDI: 19714000 EBP: c315dbcc ESP: c315dba8
[ 0.531853][ T1] DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068 EFLAGS: 00010246
[ 0.532540][ T1] CR0: 80050033 CR2: ff9ff000 CR3: 02785000 CR4: 000406d0
[ 0.533273][ T1] DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
[ 0.534229][ T1] DR6: fffe0ff0 DR7: 00000400
[ 0.534600][ T1] Call Trace:
[ 0.534824][ T1] ? show_regs (arch/x86/kernel/dumpstack.c:478)
[ 0.535119][ T1] ? __warn (kernel/panic.c:239 kernel/panic.c:693)
[ 0.535396][ T1] ? tmigr_cpu_prepare (kernel/time/timer_migration.c:1742)
[ 0.535744][ T1] ? report_bug (lib/bug.c:199)
[ 0.535811][ T1] ? exc_overflow (arch/x86/kernel/traps.c:252)
[ 0.536118][ T1] ? handle_bug (arch/x86/kernel/traps.c:?)
[ 0.536411][ T1] ? exc_invalid_op (arch/x86/kernel/traps.c:260)
[ 0.536728][ T1] ? handle_exception (arch/x86/entry/entry_32.S:1054)
[ 0.537072][ T1] ? exc_overflow (arch/x86/kernel/traps.c:252)
[ 0.537412][ T1] ? tmigr_cpu_prepare (kernel/time/timer_migration.c:1742)
[ 0.537784][ T1] ? exc_overflow (arch/x86/kernel/traps.c:252)
[ 0.538089][ T1] ? tmigr_cpu_prepare (kernel/time/timer_migration.c:1742)
[ 0.538433][ T1] ? __mutex_lock_common (kernel/locking/mutex.c:608)
[ 0.538791][ T1] cpuhp_invoke_callback (kernel/cpu.c:194)
[ 0.539149][ T1] ? tmigr_update_events (kernel/time/timer_migration.c:1732)
[ 0.539505][ T1] cpuhp_issue_call (kernel/cpu.c:?)
[ 0.539806][ T1] ? mutex_lock_nested (kernel/locking/mutex.c:752 kernel/locking/mutex.c:804)
[ 0.540142][ T1] __cpuhp_setup_state_cpuslocked (kernel/cpu.c:2495)
[ 0.540551][ T1] __cpuhp_setup_state (kernel/cpu.c:2524)
[ 0.540886][ T1] ? tmigr_update_events (kernel/time/timer_migration.c:1732)
[ 0.541242][ T1] tmigr_init (include/linux/cpuhotplug.h:276 kernel/time/timer_migration.c:1822)
[ 0.541540][ T1] ? tmigr_update_events (kernel/time/timer_migration.c:1732)
[ 0.541901][ T1] do_one_initcall (init/main.c:1267)
[ 0.542224][ T1] ? skew_tick (kernel/time/timer_migration.c:1767)
[ 0.542518][ T1] ? entry_INT80_32 (arch/x86/entry/entry_32.S:944)
[ 0.542849][ T1] ? __kernel_text_address (kernel/extable.c:79)
[ 0.543209][ T1] ? entry_INT80_32 (arch/x86/entry/entry_32.S:944)
[ 0.543541][ T1] ? __kernel_text_address (kernel/extable.c:79)
[ 0.543806][ T1] ? rcu_read_lock_any_held (kernel/rcu/update.c:386)
[ 0.544174][ T1] ? __bfs (kernel/locking/lockdep.c:1799)
[ 0.544456][ T1] ? check_path (kernel/locking/lockdep.c:1832 kernel/locking/lockdep.c:2143)
[ 0.544751][ T1] ? check_path (kernel/locking/lockdep.c:2016)
[ 0.545046][ T1] ? rcu_read_lock_any_held (kernel/rcu/update.c:386)
[ 0.545980][ T1] ? __bfs (kernel/locking/lockdep.c:1799)
[ 0.546266][ T1] ? __lock_acquire (kernel/locking/lockdep.c:1832 kernel/locking/lockdep.c:2321 kernel/locking/lockdep.c:2822 kernel/locking/lockdep.c:3138 kernel/locking/lockdep.c:3253 kernel/locking/lockdep.c:3869 kernel/locking/lockdep.c:5137)
[ 0.546609][ T1] ? __lock_acquire (kernel/locking/lockdep.c:? kernel/locking/lockdep.c:3873 kernel/locking/lockdep.c:5137)
[ 0.546964][ T1] ? lock_acquire (kernel/locking/lockdep.c:5754)
[ 0.547276][ T1] ? debug_object_activate (lib/debugobjects.c:708)
[ 0.547647][ T1] ? debug_object_activate (lib/debugobjects.c:?)
[ 0.547809][ T1] ? __mod_timer (kernel/time/timer.c:?)
[ 0.548131][ T1] ? rcu_lock_acquire (include/linux/rcupdate.h:338)
[ 0.548469][ T1] ? call_rcu_tasks_generic (kernel/rcu/tasks.h:381)
[ 0.548849][ T1] ? rest_init (init/main.c:1459)
[ 0.549172][ T1] do_pre_smp_initcalls (init/main.c:1372)
[ 0.549516][ T1] ? rest_init (init/main.c:1459)
[ 0.549815][ T1] kernel_init_freeable (init/main.c:1568)
[ 0.550155][ T1] kernel_init (init/main.c:1469)
[ 0.550450][ T1] ret_from_fork (arch/x86/kernel/process.c:153)
[ 0.550752][ T1] ret_from_fork_asm (arch/x86/entry/entry_32.S:737)
[ 0.551076][ T1] entry_INT80_32 (arch/x86/entry/entry_32.S:944)
[ 0.551401][ T1] irq event stamp: 1333
[ 0.551685][ T1] hardirqs last enabled at (1341): console_unlock (arch/x86/include/asm/irqflags.h:19 arch/x86/include/asm/irqflags.h:67 arch/x86/include/asm/irqflags.h:127 kernel/printk/printk.c:341 kernel/printk/printk.c:2731 kernel/printk/printk.c:3050)
[ 0.551805][ T1] hardirqs last disabled at (1350): console_unlock (kernel/printk/printk.c:339)
[ 0.552387][ T1] softirqs last enabled at (882): __do_softirq (kernel/softirq.c:589)
[ 0.552946][ T1] softirqs last disabled at (859): __do_softirq (kernel/softirq.c:589)
[ 0.553493][ T1] ---[ end trace 0000000000000000 ]---



The kernel config and materials to reproduce are available at:
https://download.01.org/0day-ci/archive/20240725/202407251320.b449fbc6-lkp@xxxxxxxxx



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