| lists.openwall.net | lists / announce owl-users owl-dev john-users john-dev passwdqc-users yescrypt popa3d-users / oss-security kernel-hardening musl sabotage tlsify passwords / crypt-dev xvendor / Bugtraq Full-Disclosure linux-kernel linux-netdev linux-ext4 linux-hardening linux-cve-announce PHC | |
|
Open Source and information security mailing list archives
| ||
|
Message-ID: <20220314055057.GC24245@xsang-OptiPlex-9020>
Date: Mon, 14 Mar 2022 13:50:57 +0800
From: kernel test robot <oliver.sang@...el.com>
To: "Paul E. McKenney" <paulmck@...nel.org>
Cc: lkp@...ts.01.org, lkp@...el.com,
LKML <linux-kernel@...r.kernel.org>
Subject: [rcu] 758cf1496b: BUG:spinlock_bad_magic_on_CPU
Greeting,
FYI, we noticed the following commit (built with gcc-9):
commit: 758cf1496b94442c47c339b10d80cbaadf613425 ("rcu: Make UP-vacuous normal grace period advance sequence")
https://github.com/ammarfaizi2/linux-block paulmck/linux-rcu/dev.2022.03.09a
in testcase: boot
on test machine: qemu-system-x86_64 -enable-kvm -cpu Icelake-Server -smp 4 -m 16G
caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):
+--------------------------------------+------------+------------+
| | 6129c2b2dc | 758cf1496b |
+--------------------------------------+------------+------------+
| BUG:spinlock_bad_magic_on_CPU | 0 | 16 |
| WARNING:at_init/main.c:#start_kernel | 0 | 16 |
| RIP:start_kernel | 0 | 16 |
+--------------------------------------+------------+------------+
If you fix the issue, kindly add following tag
Reported-by: kernel test robot <oliver.sang@...el.com>
[ 2.351596][ T0] BUG: spinlock bad magic on CPU#0, swapper/0/0
[ 2.352231][ T0] lock: rcu_state+0x0/0xb35e0, .magic: 00000000, .owner: <none>/-1, .owner_cpu: 0
[ 2.353152][ T0] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.17.0-rc1-00188-g758cf1496b94 #1
[ 2.353978][ T0] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 2.354853][ T0] Call Trace:
[ 2.355161][ T0] <TASK>
[ 2.355451][ T0] dump_stack_lvl (lib/dump_stack.c:107)
[ 2.355914][ T0] do_raw_spin_lock (kernel/locking/spinlock_debug.c:77 kernel/locking/spinlock_debug.c:85 kernel/locking/spinlock_debug.c:114)
[ 2.356425][ T0] ? rwlock_bug+0xc0/0xc0
[ 2.356973][ T0] synchronize_rcu (kernel/rcu/tree.c:3844)
[ 2.357480][ T0] ? synchronize_rcu_expedited (kernel/rcu/tree.c:3833)
[ 2.358093][ T0] ? _printk (kernel/printk/printk.c:2261)
[ 2.358506][ T0] ? record_print_text.cold (kernel/printk/printk.c:2261)
[ 2.359055][ T0] rcu_early_boot_tests (kernel/rcu/update.c:224 kernel/rcu/update.c:564)
[ 2.359565][ T0] rcu_init (kernel/rcu/tree.c:4836 kernel/rcu/tree.c:4869)
[ 2.359984][ T0] start_kernel (init/main.c:1020 (discriminator 3))
[ 2.360480][ T0] secondary_startup_64_no_verify (arch/x86/kernel/head_64.S:300)
[ 2.361117][ T0] </TASK>
[ 2.361453][ T0] rcu: Hierarchical RCU implementation.
[ 2.362036][ T0] rcu: RCU lockdep checking is enabled.
[ 2.362612][ T0] rcu: RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=4.
[ 2.363370][ T0] RCU CPU stall warnings timeout set to 100 (rcu_cpu_stall_timeout).
[ 2.364185][ T0] Rude variant of Tasks RCU enabled.
[ 2.364727][ T0] Tracing variant of Tasks RCU enabled.
[ 2.365294][ T0] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
[ 2.366142][ T0] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=4
[ 2.403326][ T0] NR_IRQS: 524544, nr_irqs: 456, preallocated irqs: 16
[ 2.404729][ T0] rcu: srcu_init: Setting srcu_struct sizes based on contention.
[ 2.405802][ T0] ------------[ cut here ]------------
[ 2.406397][ T0] Interrupts were enabled early
[ 2.406929][ T0] WARNING: CPU: 0 PID: 0 at init/main.c:1055 start_kernel (init/main.c:1055 (discriminator 1))
[ 2.407793][ T0] Modules linked in:
[ 2.408205][ T0] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 5.17.0-rc1-00188-g758cf1496b94 #1
[ 2.409126][ T0] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[ 2.410088][ T0] RIP: 0010:start_kernel (init/main.c:1055 (discriminator 1))
[ 2.410628][ T0] Code: 0c 61 e8 20 12 01 00 e8 3b 1a 06 00 e8 40 35 41 fd e8 6b 94 05 00 9c 58 0f ba e0 09 73 0e 48 c7 c7 c0 0d 80 9c e8 a4 a6 2f fd <0f> 0b c6 05 a6 ba 7d ff 00 e8 99 cf fe fa fb e8 54 21 07 00 e8 67
All code
========
0: 0c 61 or $0x61,%al
2: e8 20 12 01 00 callq 0x11227
7: e8 3b 1a 06 00 callq 0x61a47
c: e8 40 35 41 fd callq 0xfffffffffd413551
11: e8 6b 94 05 00 callq 0x59481
16: 9c pushfq
17: 58 pop %rax
18: 0f ba e0 09 bt $0x9,%eax
1c: 73 0e jae 0x2c
1e: 48 c7 c7 c0 0d 80 9c mov $0xffffffff9c800dc0,%rdi
25: e8 a4 a6 2f fd callq 0xfffffffffd2fa6ce
2a:* 0f 0b ud2 <-- trapping instruction
2c: c6 05 a6 ba 7d ff 00 movb $0x0,-0x82455a(%rip) # 0xffffffffff7dbad9
33: e8 99 cf fe fa callq 0xfffffffffafecfd1
38: fb sti
39: e8 54 21 07 00 callq 0x72192
3e: e8 .byte 0xe8
3f: 67 addr32
Code starting with the faulting instruction
===========================================
0: 0f 0b ud2
2: c6 05 a6 ba 7d ff 00 movb $0x0,-0x82455a(%rip) # 0xffffffffff7dbaaf
9: e8 99 cf fe fa callq 0xfffffffffafecfa7
e: fb sti
f: e8 54 21 07 00 callq 0x72168
14: e8 .byte 0xe8
15: 67 addr32
[ 2.412704][ T0] RSP: 0000:ffffffff9d807f30 EFLAGS: 00010282
[ 2.413314][ T0] RAX: 0000000000000000 RBX: 0000000000000000 RCX: 0000000000000000
[ 2.414169][ T0] RDX: c0000000ffff7fff RSI: ffffffff9d807c50 RDI: fffffbfff3b00fd8
[ 2.415004][ T0] RBP: 0000000000000000 R08: 0000000000000000 R09: fffffbfff3b00f74
[ 2.415873][ T0] R10: ffffffff9d807b9f R11: fffffbfff3b00f73 R12: 0000000000000000
[ 2.416715][ T0] R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000000
[ 2.417529][ T0] FS: 0000000000000000(0000) GS:ffff8883dd400000(0000) knlGS:0000000000000000
[ 2.418485][ T0] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
[ 2.419166][ T0] CR2: ffff888289601000 CR3: 0000000286c2a001 CR4: 00000000000606b0
[ 2.420023][ T0] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
[ 2.420889][ T0] DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
[ 2.421702][ T0] Call Trace:
[ 2.422035][ T0] <TASK>
[ 2.422327][ T0] secondary_startup_64_no_verify (arch/x86/kernel/head_64.S:300)
[ 2.422986][ T0] </TASK>
[ 2.423288][ T0] irq event stamp: 0
[ 2.423686][ T0] hardirqs last enabled at (0): 0x0
[ 2.424438][ T0] hardirqs last disabled at (0): 0x0
[ 2.425159][ T0] softirqs last enabled at (0): 0x0
[ 2.425896][ T0] softirqs last disabled at (0): 0x0
[ 2.426628][ T0] ---[ end trace 0000000000000000 ]---
[ 2.432024][ T0] Console: colour VGA+ 80x25
[ 2.518020][ T0] printk: console [tty0] enabled
[ 2.518563][ T0] printk: console [ttyS0] enabled
[ 2.519391][ T0] printk: bootconsole [earlyser0] disabled
[ 2.520343][ T0] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[ 2.521187][ T0] ... MAX_LOCKDEP_SUBCLASSES: 8
[ 2.521683][ T0] ... MAX_LOCK_DEPTH: 48
[ 2.522183][ T0] ... MAX_LOCKDEP_KEYS: 8192
[ 2.522699][ T0] ... CLASSHASH_SIZE: 4096
[ 2.523214][ T0] ... MAX_LOCKDEP_ENTRIES: 32768
[ 2.523739][ T0] ... MAX_LOCKDEP_CHAINS: 65536
[ 2.524265][ T0] ... CHAINHASH_SIZE: 32768
[ 2.524805][ T0] memory used by lock dependency info: 6365 kB
[ 2.525555][ T0] memory used for stack traces: 4224 kB
[ 2.526234][ T0] per task-struct memory footprint: 1920 bytes
[ 2.527349][ T0] ACPI: Core revision 20211217
[ 2.528797][ T0] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
[ 2.530972][ T0] APIC: Switch to symmetric I/O mode setup
[ 2.532044][ T0] x2apic enabled
[ 2.532605][ T0] Switched APIC routing to physical x2apic.
[ 2.533324][ T0] masked ExtINT on CPU#0
[ 2.534282][ T0] ENABLING IO-APIC IRQs
[ 2.534892][ T0] init IO_APIC IRQs
[ 2.535565][ T0] apic 0 pin 0 not connected
[ 2.536419][ T0] IOAPIC[0]: Preconfigured routing entry (0-1 -> IRQ 1 Level:0 ActiveLow:0)
[ 2.537387][ T0] IOAPIC[0]: Preconfigured routing entry (0-2 -> IRQ 0 Level:0 ActiveLow:0)
[ 2.538291][ T0] IOAPIC[0]: Preconfigured routing entry (0-3 -> IRQ 3 Level:0 ActiveLow:0)
[ 2.539153][ T0] IOAPIC[0]: Preconfigured routing entry (0-4 -> IRQ 4 Level:0 ActiveLow:0)
[ 2.540041][ T0] IOAPIC[0]: Preconfigured routing entry (0-5 -> IRQ 5 Level:1 ActiveLow:0)
[ 2.540912][ T0] IOAPIC[0]: Preconfigured routing entry (0-6 -> IRQ 6 Level:0 ActiveLow:0)
[ 2.541783][ T0] IOAPIC[0]: Preconfigured routing entry (0-7 -> IRQ 7 Level:0 ActiveLow:0)
[ 2.542663][ T0] IOAPIC[0]: Preconfigured routing entry (0-8 -> IRQ 8 Level:0 ActiveLow:0)
[ 2.543555][ T0] IOAPIC[0]: Preconfigured routing entry (0-9 -> IRQ 9 Level:1 ActiveLow:0)
[ 2.544450][ T0] IOAPIC[0]: Preconfigured routing entry (0-10 -> IRQ 10 Level:1 ActiveLow:0)
[ 2.547733][ T0] IOAPIC[0]: Preconfigured routing entry (0-11 -> IRQ 11 Level:1 ActiveLow:0)
[ 2.549234][ T0] IOAPIC[0]: Preconfigured routing entry (0-12 -> IRQ 12 Level:0 ActiveLow:0)
[ 2.550301][ T0] IOAPIC[0]: Preconfigured routing entry (0-13 -> IRQ 13 Level:0 ActiveLow:0)
[ 2.551209][ T0] IOAPIC[0]: Preconfigured routing entry (0-14 -> IRQ 14 Level:0 ActiveLow:0)
[ 2.552219][ T0] IOAPIC[0]: Preconfigured routing entry (0-15 -> IRQ 15 Level:0 ActiveLow:0)
[ 2.553496][ T0] apic 0 pin 16 not connected
[ 2.553987][ T0] apic 0 pin 17 not connected
[ 2.554505][ T0] apic 0 pin 18 not connected
[ 2.555300][ T0] apic 0 pin 19 not connected
[ 2.556094][ T0] apic 0 pin 20 not connected
[ 2.556845][ T0] apic 0 pin 21 not connected
[ 2.557361][ T0] apic 0 pin 22 not connected
[ 2.557837][ T0] apic 0 pin 23 not connected
[ 2.558464][ T0] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[ 2.559177][ T0] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x1fa3704c1a9, max_idle_ns: 440795296692 ns
[ 2.560341][ T0] Calibrating delay loop (skipped) preset value.. 4389.83 BogoMIPS (lpj=2194916)
[ 2.561335][ T0] pid_max: default: 32768 minimum: 301
[ 2.562420][ T0] LSM: Security Framework initializing
[ 2.563009][ T0] landlock: Up and running.
[ 2.563334][ T0] Yama: becoming mindful.
[ 2.563915][ T0] Mount-cache hash table entries: 32768 (order: 6, 262144 bytes, linear)
[ 2.564381][ T0] Mountpoint-cache hash table entries: 32768 (order: 6, 262144 bytes, linear)
Poking KASLR using RDRAND RDTSC...
[ 2.567292][ T0] x86/cpu: User Mode Instruction Prevention (UMIP) activated
[ 2.567402][ T0] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[ 2.568334][ T0] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[ 2.569343][ T0] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[ 2.570339][ T0] Spectre V2 : Mitigation: Full generic retpoline
[ 2.570974][ T0] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[ 2.571334][ T0] Speculative Store Bypass: Vulnerable
[ 2.572342][ T0] TAA: Vulnerable: Clear CPU buffers attempted, no microcode
[ 2.573337][ T0] MDS: Vulnerable: Clear CPU buffers attempted, no microcode
[ 2.578010][ T0] Freeing SMP alternatives memory: 40K
[ 2.578746][ T1] smpboot: CPU0: Intel Xeon Processor (Icelake) (family: 0x6, model: 0x86, stepping: 0x0)
[ 2.580009][ T1] cblist_init_generic: Setting adjustable number of callback queues.
[ 2.580334][ T1] cblist_init_generic: Setting shift to 2 and lim to 1.
[ 2.581082][ T1] cblist_init_generic: Setting shift to 2 and lim to 1.
[ 2.581425][ T1] Running RCU-tasks wait API self tests
[ 2.582020][ T1] Performance Events: unsupported p6 CPU model 134 no PMU driver, software events only.
[ 2.582512][ T1] rcu: Hierarchical SRCU implementation.
[ 2.585292][ T1] NMI watchdog: Perf NMI watchdog permanently disabled
[ 2.586433][ T1] smp: Bringing up secondary CPUs ...
[ 2.587558][ T1] x86: Booting SMP configuration:
[ 2.588195][ T1] .... node #0, CPUs: #1
[ 0.151762][ T0] masked ExtINT on CPU#1
[ 0.151762][ T0] smpboot: CPU 1 Converting physical 0 to logical die 1
[ 2.591069][ T1] #2
[ 0.151762][ T0] masked ExtINT on CPU#2
[ 0.151762][ T0] smpboot: CPU 2 Converting physical 0 to logical die 2
[ 2.594618][ T1] #3
[ 0.151762][ T0] masked ExtINT on CPU#3
[ 0.151762][ T0] smpboot: CPU 3 Converting physical 0 to logical die 3
[ 2.596429][ T1] smp: Brought up 1 node, 4 CPUs
[ 2.597346][ T1] smpboot: Max logical packages: 4
[ 2.598180][ T1] smpboot: Total of 4 processors activated (17559.32 BogoMIPS)
[ 2.598374][ T10] Callback from call_rcu_tasks_trace() invoked.
[ 2.695355][ T9] Callback from call_rcu_tasks_rude() invoked.
[ 2.702666][ T31] node 0 deferred pages initialised in 102ms
[ 2.821489][ T1] allocated 201326592 bytes of page_ext
[ 2.822566][ T1] Node 0, zone DMA: page owner found early allocated 0 pages
[ 2.826920][ T1] Node 0, zone DMA32: page owner found early allocated 0 pages
To reproduce:
# build kernel
cd linux
cp config-5.17.0-rc1-00188-g758cf1496b94 .config
make HOSTCC=gcc-9 CC=gcc-9 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage modules
make HOSTCC=gcc-9 CC=gcc-9 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://lists.01.org/hyperkitty/list/lkp@lists.01.org
Thanks,
Oliver Sang
View attachment "config-5.17.0-rc1-00188-g758cf1496b94" of type "text/plain" (166010 bytes)
View attachment "job-script" of type "text/plain" (4654 bytes)
Download attachment "dmesg.xz" of type "application/x-xz" (14288 bytes)
Powered by blists - more mailing lists