Date:   Wed, 2 Jun 2021 13:40:01 +0800
From:   kernel test robot <oliver.sang@...el.com>
To:     Hannes Reinecke <hare@...e.de>
Cc:     0day robot <lkp@...el.com>, LKML <linux-kernel@...r.kernel.org>,
        lkp@...ts.01.org, Jens Axboe <axboe@...nel.dk>,
        Christoph Hellwig <hch@....de>, linux-block@...r.kernel.org,
        Hannes Reinecke <hare@...e.de>
Subject: [block/genhd]  8107f5f540: WARNING:bad_unlock_balance_detected



Greeting,

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

commit: 8107f5f540ff2700d9b300343ccbd3368970cf40 ("[PATCH] block/genhd: use atomic_t for disk_event->block")
url: https://github.com/0day-ci/linux/commits/Hannes-Reinecke/block-genhd-use-atomic_t-for-disk_event-block/20210601-190226
base: https://git.kernel.org/cgit/linux/kernel/git/axboe/linux-block.git for-next

in testcase: boot

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

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


+-----------------------------------------------+------------+------------+
|                                               | 3fc19ec343 | 8107f5f540 |
+-----------------------------------------------+------------+------------+
| boot_successes                                | 10         | 0          |
| boot_failures                                 | 0          | 6          |
| WARNING:bad_unlock_balance_detected           | 0          | 6          |
| is_trying_to_release_lock(&ev->block_mutex)at | 0          | 6          |
| calltrace:__disk_unblock_events               | 0          | 6          |
+-----------------------------------------------+------------+------------+


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


[   65.041606] WARNING: bad unlock balance detected!
[   65.042098] 5.13.0-rc3-00039-g8107f5f540ff #1 Not tainted
[   65.042660] -------------------------------------
[   65.043157] kworker/u4:5/139 is trying to release lock (&ev->block_mutex) at:
[   65.043913] __disk_unblock_events (kbuild/src/consumer/block/genhd.c:1477) 
[   65.044130] but there are no more locks to release!
[   65.044130]
[   65.044130] other info that might help us debug this:
[   65.044130] 2 locks held by kworker/u4:5/139:
[   65.044130] #0: 410078b8 ((wq_completion)events_unbound){+.+.}-{0:0}, at: process_one_work (kbuild/src/consumer/kernel/workqueue.c:615 kbuild/src/consumer/kernel/workqueue.c:643 kbuild/src/consumer/kernel/workqueue.c:2246) 
[   65.044130] #1: 4264df34 ((work_completion)(&entry->work)){+.+.}-{0:0}, at: process_one_work (kbuild/src/consumer/kernel/workqueue.c:615 kbuild/src/consumer/kernel/workqueue.c:643 kbuild/src/consumer/kernel/workqueue.c:2246) 
[   65.044130]
[   65.044130] stack backtrace:
[   65.044130] CPU: 1 PID: 139 Comm: kworker/u4:5 Not tainted 5.13.0-rc3-00039-g8107f5f540ff #1
[   65.044130] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.12.0-1 04/01/2014
[   65.044130] Workqueue: events_unbound async_run_entry_fn
[   65.044130] Call Trace:
[   65.044130] ? dump_stack (kbuild/src/consumer/lib/dump_stack.c:122) 
[   65.044130] ? __disk_unblock_events (kbuild/src/consumer/block/genhd.c:1477) 
[   65.052205] ? print_unlock_imbalance_bug.cold (kbuild/src/consumer/kernel/locking/lockdep.c:4955 kbuild/src/consumer/kernel/locking/lockdep.c:4931) 
[   65.052205] ? __disk_unblock_events (kbuild/src/consumer/block/genhd.c:1477) 
[   65.052205] ? lock_release (kbuild/src/consumer/kernel/locking/lockdep.c:5192 kbuild/src/consumer/kernel/locking/lockdep.c:5532) 
[   65.052205] ? __mutex_unlock_slowpath (kbuild/src/consumer/arch/x86/include/asm/atomic.h:29 kbuild/src/consumer/include/asm-generic/atomic-instrumented.h:28 kbuild/src/consumer/include/asm-generic/atomic-long.h:523 kbuild/src/consumer/kernel/locking/mutex.c:1238) 
[   65.052205] ? mutex_unlock (kbuild/src/consumer/kernel/locking/mutex.c:741) 
[   65.052205] ? __disk_unblock_events (kbuild/src/consumer/block/genhd.c:1477) 
[   65.052205] ? __device_add_disk (kbuild/src/consumer/block/genhd.c:565) 
[   65.052205] ? device_add_disk (kbuild/src/consumer/block/genhd.c:572) 
[   65.052205] ? do_floppy_init (kbuild/src/consumer/drivers/block/floppy.c:4704) 
[   65.052205] ? ktime_get (kbuild/src/consumer/kernel/time/timekeeping.c:831) 
[   65.052205] ? floppy_async_init (kbuild/src/consumer/drivers/block/floppy.c:4742) 
[   65.052205] ? async_run_entry_fn (kbuild/src/consumer/kernel/async.c:134) 
[   65.052205] ? process_one_work (kbuild/src/consumer/arch/x86/include/asm/atomic.h:29 kbuild/src/consumer/include/asm-generic/atomic-instrumented.h:28 kbuild/src/consumer/include/linux/jump_label.h:254 kbuild/src/consumer/include/linux/jump_label.h:264 kbuild/src/consumer/include/trace/events/workqueue.h:108 kbuild/src/consumer/kernel/workqueue.c:2280) 
[   65.052205] ? worker_thread (kbuild/src/consumer/include/linux/list.h:282 kbuild/src/consumer/kernel/workqueue.c:2422) 
[   65.052205] ? kthread (kbuild/src/consumer/kernel/kthread.c:313) 
[   65.052205] ? process_one_work (kbuild/src/consumer/kernel/workqueue.c:2364) 
[   65.052205] ? kthread_create_worker_on_cpu (kbuild/src/consumer/kernel/kthread.c:266) 
[   65.052205] ? ret_from_fork (kbuild/src/consumer/arch/x86/entry/entry_32.S:775) 
[   65.066846] loop: module loaded
[   65.078122] null_blk: module loaded
[   65.078673] Silicon Labs C2 port support v. 0.51.0 - (C) 2007 Rodolfo Giometti
[   65.079489] c2port c2port0: C2 port uc added
[   65.079958] c2port c2port0: uc flash has 30 blocks x 512 bytes (15360 bytes total)
[   65.081010] usbcore: registered new interface driver rtsx_usb
[   65.082303] usbcore: registered new interface driver pn533_usb
[   65.082978] usbcore: registered new interface driver nfcmrvl
[   65.083597] NCI uart driver 'nfcmrvl_uart [0]' registered
[   65.084302] Uniform Multi-Platform E-IDE driver
[   65.085233] ide_generic: please use "probe_mask=0x3f" module parameter for probing all legacy ISA IDE ports
[   65.086270] ide-cd driver 5.00
[   65.087896] SSFDC read-only Flash Translation layer
[   65.088484] mtdoops: mtd device (mtddev=name/number) must be supplied
[   65.089317] platform physmap-flash.0: failed to claim resource 0: [mem 0x08000000-0x07ffffff]
[   65.090255] SBC-GXx flash: IO:0x258-0x259 MEM:0xdc000-0xdffff
[   65.090961] slram: not enough parameters.
[   65.091621] Driver 'dfl-spi-altera' was unable to register with bus_type 'dfl' because the bus was not initialized.
[   65.095780] wireguard: allowedips self-tests: pass
[   65.113505] wireguard: nonce counter self-tests: pass
[   65.691142] wireguard: ratelimiter self-tests: pass
[   65.691780] wireguard: WireGuard 1.0.0 loaded. See www.wireguard.com for information.
[   65.692614] wireguard: Copyright (C) 2015-2019 Jason A. Donenfeld <Jason@...c4.com>. All Rights Reserved.
[   65.693599] eql: Equalizer2002: Simon Janes (simon@....com) and David S. Miller (davem@...hat.com)
[   65.694895] MACsec IEEE 802.1AE
[   65.696576] libphy: Fixed MDIO Bus: probed
[   65.698059] usbcore: registered new interface driver mvusb_mdio
[   65.698765] tun: Universal TUN/TAP device driver, 1.6
[   65.699721] e1000: Intel(R) PRO/1000 Network Driver
[   65.700291] e1000: Copyright (c) 1999-2006 Intel Corporation.
[   65.870690] ACPI: _SB_.LNKC: Enabled at IRQ 11
[   66.238500] e1000 0000:00:03.0 eth0: (PCI:33MHz:32-bit) 52:54:00:12:34:56
[   66.239265] e1000 0000:00:03.0 eth0: Intel(R) PRO/1000 Network Connection
[   66.240099] mkiss: AX.25 Multikiss, Hans Albas PE1AYX
[   66.240719] AX.25: 6pack driver, Revision: 0.3.0
[   66.241245] AX.25: bpqether driver version 004
[   66.241704] baycom_ser_fdx: (C) 1996-2000 Thomas Sailer, HB9JNX/AE4WA
[   66.241704] baycom_ser_fdx: version 0.10
[   66.243814] hdlcdrv: (C) 1996-2000 Thomas Sailer HB9JNX/AE4WA
[   66.244511] hdlcdrv: version 0.8
[   66.244882] baycom_ser_hdx: (C) 1996-2000 Thomas Sailer, HB9JNX/AE4WA
[   66.244882] baycom_ser_hdx: version 0.10
[   66.246962] baycom_par: (C) 1996-2000 Thomas Sailer, HB9JNX/AE4WA
[   66.246962] baycom_par: version 0.9
[   66.249490] PPP generic driver version 2.4.2
[   66.250116] PPP BSD Compression module registered
[   66.250727] PPP MPPE Compression module registered
[   66.251273] hdlc: HDLC support module revision 1.22
[   66.251874] airo(): Probing for PCI adapters
[   66.252564] airo(): Finished probing for PCI adapters
[   66.253144] usbcore: registered new interface driver usb8xxx
[   66.253752] libertas_spi: Libertas SPI driver
[   66.254320] usbcore: registered new interface driver zd1201
[   66.255021] usbcore: registered new interface driver rndis_wlan
[   66.255744] usbcore: registered new interface driver kaweth
[   66.256395] pegasus: v0.9.3 (2013/04/25), Pegasus/Pegasus II USB Ethernet driver
[   66.257252] usbcore: registered new interface driver pegasus
[   66.257925] usbcore: registered new interface driver rtl8150
[   66.258615] usbcore: registered new interface driver r8152
[   66.259237] hso: drivers/net/usb/hso.c: Option Wireless
[   66.259929] usbcore: registered new interface driver hso
[   66.260559] usbcore: registered new interface driver cdc_ether
[   66.261214] usbcore: registered new interface driver cdc_eem
[   66.261836] usbcore: registered new interface driver dm9601


To reproduce:

        # build kernel
	cd linux
	cp config-5.13.0-rc3-00039-g8107f5f540ff .config
	make HOSTCC=gcc-9 CC=gcc-9 ARCH=i386 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



---
0DAY/LKP+ Test Infrastructure                   Open Source Technology Center
https://lists.01.org/hyperkitty/list/lkp@lists.01.org       Intel Corporation

Thanks,
Oliver Sang


View attachment "config-5.13.0-rc3-00039-g8107f5f540ff" of type "text/plain" (158528 bytes)

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

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

Powered by blists - more mailing lists