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
 
Hash Suite: Windows password security audit tool. GUI, reports in PDF.
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20200717073924.GB19262@shao2-debian>
Date:   Fri, 17 Jul 2020 15:39:24 +0800
From:   kernel test robot <lkp@...el.com>
To:     Waiman Long <longman@...hat.com>
Cc:     Peter Zijlstra <peterz@...radead.org>,
        Ingo Molnar <mingo@...hat.com>,
        Will Deacon <will.deacon@....com>,
        Thomas Gleixner <tglx@...utronix.de>,
        Borislav Petkov <bp@...en8.de>, Arnd Bergmann <arnd@...db.de>,
        linux-kernel@...r.kernel.org, x86@...nel.org,
        linux-arch@...r.kernel.org, Nicholas Piggin <npiggin@...il.com>,
        Davidlohr Bueso <dave@...olabs.net>,
        Waiman Long <longman@...hat.com>, lkp@...ts.01.org
Subject: [locking/qspinlock] 45877ea393: BUG:spinlock_already_unlocked_on_CPU

Greeting,

FYI, we noticed the following commit (built with gcc-9):

commit: 45877ea3934b977dd4fd9fa8b4b7e9a2a8925d38 ("[PATCH v2 4/5] locking/qspinlock: Make qspinhlock store lock holder cpu number")
url: https://github.com/0day-ci/linux/commits/Waiman-Long/x86-locking-qspinlock-Allow-lock-to-store-lock-holder-cpu-number/20200717-033319
base: https://git.kernel.org/cgit/linux/kernel/git/tip/tip.git f9ad4a5f3f20bee022b1bdde94e5ece6dc0b0edc

in testcase: trinity
with following parameters:

	runtime: 300s

test-description: Trinity is a linux system call fuzz tester.
test-url: http://codemonkey.org.uk/projects/trinity/


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

caused below changes (please refer to attached dmesg/kmsg for entire log/backtrace):


+--------------------------------------+------------+------------+
|                                      | a104f8329b | 45877ea393 |
+--------------------------------------+------------+------------+
| boot_successes                       | 6          | 0          |
| boot_failures                        | 0          | 8          |
| BUG:spinlock_already_unlocked_on_CPU | 0          | 8          |
+--------------------------------------+------------+------------+


If you fix the issue, kindly add following tag
Reported-by: kernel test robot <lkp@...el.com>


[    0.174207] BUG: spinlock already unlocked on CPU#0, swapper/0
[    0.174208]  lock: logbuf_lock+0x0/0x40, .magic: dead4ead, .owner: swapper/0, .owner_cpu: 0
[    0.174209] CPU: 0 PID: 0 Comm: swapper Not tainted 5.8.0-rc4-00016-g45877ea3934b9 #1
[    0.174210] Call Trace:
[    0.174210]  ? dump_stack+0x96/0xd0
[    0.174211]  ? do_raw_spin_unlock+0x81/0xc0
[    0.174211]  ? _raw_spin_unlock+0x1f/0x40
[    0.174212]  ? vprintk_emit+0x141/0x370
[    0.174212]  ? printk+0x58/0x6f
[    0.174213]  ? start_kernel+0x60/0x664
[    0.174213]  ? x86_family+0x5/0x20
[    0.174214]  ? secondary_startup_64+0xb6/0xc0
[    0.174215] BUG: spinlock already unlocked on CPU#0, swapper/0
[    0.174216]  lock: logbuf_lock+0x0/0x40, .magic: dead4ead, .owner: swapper/0, .owner_cpu: 0
[    0.174217] CPU: 0 PID: 0 Comm: swapper Not tainted 5.8.0-rc4-00016-g45877ea3934b9 #1
[    0.174217] Call Trace:
[    0.174218]  ? dump_stack+0x96/0xd0
[    0.174218]  ? do_raw_spin_unlock+0x81/0xc0
[    0.174219]  ? _raw_spin_unlock+0x1f/0x40
[    0.174219]  ? vprintk_emit+0x141/0x370
[    0.174220]  ? printk+0x58/0x6f
[    0.174220]  ? start_kernel+0x60/0x664
[    0.174221]  ? x86_family+0x5/0x20
[    0.174222]  ? secondary_startup_64+0xb6/0xc0
[    0.179324] Dentry cache hash table entries: 2097152 (order: 12, 16777216 bytes, linear)
[    0.203325] Inode-cache hash table entries: 1048576 (order: 11, 8388608 bytes, linear)
[    0.204873] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.303179] Memory: 2330956K/16776640K available (16390K kernel code, 3578K rwdata, 9300K rodata, 2508K init, 17536K bss, 1290512K reserved, 0K cma-reserved)
[    0.306358] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[    0.307555] Kernel/User page tables isolation: enabled
[    0.308477] ftrace: allocating 49199 entries in 193 pages
[    0.334062] ftrace: allocated 193 pages with 3 groups
[    0.335730] Running RCU self tests
[    0.336314] rcu: Preemptible hierarchical RCU implementation.
[    0.337275] rcu: 	RCU lockdep checking is enabled.
[    0.338117] rcu: 	RCU restricting CPUs from NR_CPUS=8192 to nr_cpu_ids=2.
[    0.339252] 	RCU CPU stall warnings timeout set to 100 (rcu_cpu_stall_timeout).
[    0.340525] 	Trampoline variant of Tasks RCU enabled.
[    0.341420] 	Rude variant of Tasks RCU enabled.
[    0.342120] rcu: RCU calculated value of scheduler-enlistment delay is 100 jiffies.
[    0.343410] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[    0.350046] NR_IRQS: 524544, nr_irqs: 440, preallocated irqs: 16
[    0.351568] random: get_random_bytes called from start_kernel+0x47c/0x664 with crng_init=0
[    0.360133] Console: colour VGA+ 80x25
[    0.488053] printk: console [tty0] enabled
[    0.489397] printk: console [ttyS0] enabled
[    0.491484] printk: bootconsole [earlyser0] disabled
[    0.493957] Lock dependency validator: Copyright (c) 2006 Red Hat, Inc., Ingo Molnar
[    0.496330] ... MAX_LOCKDEP_SUBCLASSES:  8
[    0.497667] ... MAX_LOCK_DEPTH:          48
[    0.498992] ... MAX_LOCKDEP_KEYS:        8192
[    0.500345] ... CLASSHASH_SIZE:          4096
[    0.501709] ... MAX_LOCKDEP_ENTRIES:     32768
[    0.502983] ... MAX_LOCKDEP_CHAINS:      65536
[    0.504225] ... CHAINHASH_SIZE:          32768
[    0.505597]  memory used by lock dependency info: 6301 kB
[    0.507170]  memory used for stack traces: 4224 kB
[    0.508622]  per task-struct memory footprint: 1920 bytes
[    0.510320] ACPI: Core revision 20200528
[    0.511870] clocksource: hpet: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604467 ns
[    0.514831] APIC: Switch to symmetric I/O mode setup
[    0.516572] x2apic enabled
[    0.517835] Switched APIC routing to physical x2apic.
[    0.519267] masked ExtINT on CPU#0
[    0.521620] ENABLING IO-APIC IRQs
[    0.522862] init IO_APIC IRQs
[    0.523904]  apic 0 pin 0 not connected
[    0.525142] IOAPIC[0]: Set routing entry (0-1 -> 0xef -> IRQ 1 Mode:0 Active:0 Dest:0)
[    0.527588] IOAPIC[0]: Set routing entry (0-2 -> 0x30 -> IRQ 0 Mode:0 Active:0 Dest:0)
[    0.530160] IOAPIC[0]: Set routing entry (0-3 -> 0xef -> IRQ 3 Mode:0 Active:0 Dest:0)
[    0.532595] IOAPIC[0]: Set routing entry (0-4 -> 0xef -> IRQ 4 Mode:0 Active:0 Dest:0)
[    0.535040] IOAPIC[0]: Set routing entry (0-5 -> 0xef -> IRQ 5 Mode:1 Active:0 Dest:0)
[    0.537473] IOAPIC[0]: Set routing entry (0-6 -> 0xef -> IRQ 6 Mode:0 Active:0 Dest:0)
[    0.539907] IOAPIC[0]: Set routing entry (0-7 -> 0xef -> IRQ 7 Mode:0 Active:0 Dest:0)
[    0.542375] IOAPIC[0]: Set routing entry (0-8 -> 0xef -> IRQ 8 Mode:0 Active:0 Dest:0)
[    0.544872] IOAPIC[0]: Set routing entry (0-9 -> 0xef -> IRQ 9 Mode:1 Active:0 Dest:0)
[    0.547321] IOAPIC[0]: Set routing entry (0-10 -> 0xef -> IRQ 10 Mode:1 Active:0 Dest:0)
[    0.549764] IOAPIC[0]: Set routing entry (0-11 -> 0xef -> IRQ 11 Mode:1 Active:0 Dest:0)
[    0.552139] IOAPIC[0]: Set routing entry (0-12 -> 0xef -> IRQ 12 Mode:0 Active:0 Dest:0)
[    0.554509] IOAPIC[0]: Set routing entry (0-13 -> 0xef -> IRQ 13 Mode:0 Active:0 Dest:0)
[    0.556877] IOAPIC[0]: Set routing entry (0-14 -> 0xef -> IRQ 14 Mode:0 Active:0 Dest:0)
[    0.559407] IOAPIC[0]: Set routing entry (0-15 -> 0xef -> IRQ 15 Mode:0 Active:0 Dest:0)
[    0.561851]  apic 0 pin 16 not connected
[    0.563100]  apic 0 pin 17 not connected
[    0.564382]  apic 0 pin 18 not connected
[    0.565667]  apic 0 pin 19 not connected
[    0.566978]  apic 0 pin 20 not connected
[    0.568223]  apic 0 pin 21 not connected
[    0.569546]  apic 0 pin 22 not connected
[    0.574439]  apic 0 pin 23 not connected
[    0.575852] ..TIMER: vector=0x30 apic1=0 pin1=2 apic2=-1 pin2=-1
[    0.577696] clocksource: tsc-early: mask: 0xffffffffffffffff max_cycles: 0x26d349e8249, max_idle_ns: 440795288087 ns
[    0.580936] Calibrating delay loop (skipped) preset value.. 5387.01 BogoMIPS (lpj=2693508)
[    0.581945] pid_max: default: 32768 minimum: 301
[    0.583003] LSM: Security Framework initializing
[    0.583943] Yama: becoming mindful.
[    0.585038] Mount-cache hash table entries: 32768 (order: 6, 262144 bytes, linear)
[    0.586506] Mountpoint-cache hash table entries: 32768 (order: 6, 262144 bytes, linear)
Poking KASLR using RDTSC...
[    0.589007] Last level iTLB entries: 4KB 0, 2MB 0, 4MB 0
[    0.589936] Last level dTLB entries: 4KB 0, 2MB 0, 4MB 0, 1GB 0
[    0.590943] Spectre V1 : Mitigation: usercopy/swapgs barriers and __user pointer sanitization
[    0.591952] Spectre V2 : Mitigation: Full generic retpoline
[    0.592937] Spectre V2 : Spectre v2 / SpectreRSB mitigation: Filling RSB on context switch
[    0.593941] Speculative Store Bypass: Vulnerable
[    0.594944] MDS: Vulnerable: Clear CPU buffers attempted, no microcode
[    0.597034] Freeing SMP alternatives memory: 40K
[    0.600063] smpboot: CPU0: Intel Xeon E312xx (Sandy Bridge) (family: 0x6, model: 0x2a, stepping: 0x1)
[    0.601429] Performance Events: unsupported p6 CPU model 42 no PMU driver, software events only.
[    0.602098] rcu: Hierarchical SRCU implementation.
[    0.604237] NMI watchdog: Perf NMI watchdog permanently disabled
[    0.605187] smp: Bringing up secondary CPUs ...
[    0.606363] x86: Booting SMP configuration:


To reproduce:

        # build kernel
	cd linux
	cp config-5.8.0-rc4-00016-g45877ea3934b9 .config
	make HOSTCC=gcc-9 CC=gcc-9 ARCH=x86_64 olddefconfig prepare modules_prepare bzImage

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



Thanks,
lkp


View attachment "config-5.8.0-rc4-00016-g45877ea3934b9" of type "text/plain" (209057 bytes)

View attachment "job-script" of type "text/plain" (4729 bytes)

Download attachment "dmesg.xz" of type "application/x-xz" (17468 bytes)

Powered by blists - more mailing lists

Powered by Openwall GNU/*/Linux Powered by OpenVZ