[syzbot] possible deadlock in usb_reset_and_verify_device

From: syzbot
Date: Mon Nov 22 2021 - 00:21:34 EST

Next message: Huangzhaoyang: "[RFC PATCH] arch: arm64: introduce RODATA_FULL_USE_PTE_CONT"
Previous message: Huang Yiwei: "[PATCH 4/4] dt-bindings: mailbox: Add more protocol and client ID"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]

Hello,

syzbot found the following issue on:

HEAD commit: 5191249f8803 Add linux-next specific files for 20211118
git tree: linux-next
console output: https://syzkaller.appspot.com/x/log.txt?x=126edbc9b00000
kernel config: https://syzkaller.appspot.com/x/.config?x=fca39774e64812b0
dashboard link: https://syzkaller.appspot.com/bug?extid=7f3f8da319285fc76bcb
compiler: gcc (Debian 10.2.1-6) 10.2.1 20210110, GNU ld (GNU Binutils for Debian) 2.35.2

Unfortunately, I don't have any reproducer for this issue yet.

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+7f3f8da319285fc76bcb@xxxxxxxxxxxxxxxxxxxxxxxxx

======================================================
WARNING: possible circular locking dependency detected
5.16.0-rc1-next-20211118-syzkaller #0 Not tainted
------------------------------------------------------
kworker/1:2/136 is trying to acquire lock:
ffff88801d292c68 (hcd->address0_mutex){+.+.}-{3:3}, at: usb_reset_and_verify_device+0x3ee/0xee0 drivers/usb/core/hub.c:5923

but task is already holding lock:
ffff88801da345c0 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_lock_port drivers/usb/core/hub.c:3086 [inline]
ffff88801da345c0 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_port_resume+0x2a6/0x1950 drivers/usb/core/hub.c:3644

which lock already depends on the new lock.

the existing dependency chain (in reverse order) is:

-> #1 (&port_dev->status_lock){+.+.}-{3:3}:
__mutex_lock_common kernel/locking/mutex.c:607 [inline]
__mutex_lock+0x12f/0x12f0 kernel/locking/mutex.c:740
usb_lock_port drivers/usb/core/hub.c:3086 [inline]
hub_port_connect drivers/usb/core/hub.c:5279 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5493 [inline]
port_event drivers/usb/core/hub.c:5639 [inline]
hub_event+0x21c1/0x4450 drivers/usb/core/hub.c:5721
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2298
worker_thread+0x658/0x11f0 kernel/workqueue.c:2445
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295

-> #0 (hcd->address0_mutex){+.+.}-{3:3}:
check_prev_add kernel/locking/lockdep.c:3063 [inline]
check_prevs_add kernel/locking/lockdep.c:3186 [inline]
validate_chain kernel/locking/lockdep.c:3801 [inline]
__lock_acquire+0x2a07/0x54a0 kernel/locking/lockdep.c:5027
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__mutex_lock_common kernel/locking/mutex.c:607 [inline]
__mutex_lock+0x12f/0x12f0 kernel/locking/mutex.c:740
usb_reset_and_verify_device+0x3ee/0xee0 drivers/usb/core/hub.c:5923
finish_port_resume drivers/usb/core/hub.c:3499 [inline]
usb_port_resume+0x12f7/0x1950 drivers/usb/core/hub.c:3699
usb_generic_driver_resume+0x40/0xa0 drivers/usb/core/generic.c:305
usb_resume_device drivers/usb/core/driver.c:1288 [inline]
usb_resume_both+0x627/0x8d0 drivers/usb/core/driver.c:1512
__rpm_callback+0xc9/0x330 drivers/base/power/runtime.c:377
rpm_callback+0x1da/0x220 drivers/base/power/runtime.c:504
rpm_resume+0xf5d/0x1bd0 drivers/base/power/runtime.c:879
__pm_runtime_resume+0xb7/0x170 drivers/base/power/runtime.c:1110
pm_runtime_get_sync include/linux/pm_runtime.h:393 [inline]
usb_autoresume_device+0x1e/0x60 drivers/usb/core/driver.c:1705
usb_remote_wakeup+0x8b/0xe0 drivers/usb/core/hub.c:3723
hub_port_connect_change drivers/usb/core/hub.c:5479 [inline]
port_event drivers/usb/core/hub.c:5639 [inline]
hub_event+0x2d69/0x4450 drivers/usb/core/hub.c:5721
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2298
worker_thread+0x658/0x11f0 kernel/workqueue.c:2445
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295

other info that might help us debug this:

Possible unsafe locking scenario:

CPU0 CPU1
---- ----
lock(&port_dev->status_lock);
lock(hcd->address0_mutex);
lock(&port_dev->status_lock);
lock(hcd->address0_mutex);

*** DEADLOCK ***

5 locks held by kworker/1:2/136:
#0: ffff888011abb138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
#0: ffff888011abb138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: arch_atomic_long_set include/linux/atomic/atomic-long.h:41 [inline]
#0: ffff888011abb138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: atomic_long_set include/linux/atomic/atomic-instrumented.h:1198 [inline]
#0: ffff888011abb138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_data kernel/workqueue.c:635 [inline]
#0: ffff888011abb138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: set_work_pool_and_clear_pending kernel/workqueue.c:662 [inline]
#0: ffff888011abb138 ((wq_completion)usb_hub_wq){+.+.}-{0:0}, at: process_one_work+0x896/0x1690 kernel/workqueue.c:2269
#1: ffffc900027ffdb0 ((work_completion)(&hub->events)){+.+.}-{0:0}, at: process_one_work+0x8ca/0x1690 kernel/workqueue.c:2273
#2: ffff88801da31220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#2: ffff88801da31220 (&dev->mutex){....}-{3:3}, at: hub_event+0x1c1/0x4450 drivers/usb/core/hub.c:5667
#3: ffff88814a94a220 (&dev->mutex){....}-{3:3}, at: device_lock include/linux/device.h:760 [inline]
#3: ffff88814a94a220 (&dev->mutex){....}-{3:3}, at: usb_remote_wakeup+0x1f/0xe0 drivers/usb/core/hub.c:3720
#4: ffff88801da345c0 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_lock_port drivers/usb/core/hub.c:3086 [inline]
#4: ffff88801da345c0 (&port_dev->status_lock){+.+.}-{3:3}, at: usb_port_resume+0x2a6/0x1950 drivers/usb/core/hub.c:3644

stack backtrace:
CPU: 1 PID: 136 Comm: kworker/1:2 Not tainted 5.16.0-rc1-next-20211118-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: usb_hub_wq hub_event
Call Trace:
<TASK>
__dump_stack lib/dump_stack.c:88 [inline]
dump_stack_lvl+0xcd/0x134 lib/dump_stack.c:106
check_noncircular+0x25f/0x2e0 kernel/locking/lockdep.c:2143
check_prev_add kernel/locking/lockdep.c:3063 [inline]
check_prevs_add kernel/locking/lockdep.c:3186 [inline]
validate_chain kernel/locking/lockdep.c:3801 [inline]
__lock_acquire+0x2a07/0x54a0 kernel/locking/lockdep.c:5027
lock_acquire kernel/locking/lockdep.c:5637 [inline]
lock_acquire+0x1ab/0x510 kernel/locking/lockdep.c:5602
__mutex_lock_common kernel/locking/mutex.c:607 [inline]
__mutex_lock+0x12f/0x12f0 kernel/locking/mutex.c:740
usb_reset_and_verify_device+0x3ee/0xee0 drivers/usb/core/hub.c:5923
finish_port_resume drivers/usb/core/hub.c:3499 [inline]
usb_port_resume+0x12f7/0x1950 drivers/usb/core/hub.c:3699
usb_generic_driver_resume+0x40/0xa0 drivers/usb/core/generic.c:305
usb_resume_device drivers/usb/core/driver.c:1288 [inline]
usb_resume_both+0x627/0x8d0 drivers/usb/core/driver.c:1512
__rpm_callback+0xc9/0x330 drivers/base/power/runtime.c:377
rpm_callback+0x1da/0x220 drivers/base/power/runtime.c:504
rpm_resume+0xf5d/0x1bd0 drivers/base/power/runtime.c:879
__pm_runtime_resume+0xb7/0x170 drivers/base/power/runtime.c:1110
pm_runtime_get_sync include/linux/pm_runtime.h:393 [inline]
usb_autoresume_device+0x1e/0x60 drivers/usb/core/driver.c:1705
usb_remote_wakeup+0x8b/0xe0 drivers/usb/core/hub.c:3723
hub_port_connect_change drivers/usb/core/hub.c:5479 [inline]
port_event drivers/usb/core/hub.c:5639 [inline]
hub_event+0x2d69/0x4450 drivers/usb/core/hub.c:5721
process_one_work+0x9b2/0x1690 kernel/workqueue.c:2298
worker_thread+0x658/0x11f0 kernel/workqueue.c:2445
kthread+0x405/0x4f0 kernel/kthread.c:327
ret_from_fork+0x1f/0x30 arch/x86/entry/entry_64.S:295
</TASK>
usb 4-1: USB disconnect, device number 2
usblp0: removed
usb 6-1: new high-speed USB device number 2 using dummy_hcd
usb 6-1: Using ep0 maxpacket: 32
usb 6-1: config 1 interface 0 altsetting 0 endpoint 0x81 has an invalid bInterval 0, changing to 7
usb 6-1: config 1 interface 0 altsetting 0 endpoint 0x81 has invalid wMaxPacketSize 0
usb 6-1: config 1 interface 1 altsetting 1 endpoint 0x82 has invalid wMaxPacketSize 0
usb 6-1: config 1 interface 1 altsetting 1 bulk endpoint 0x82 has invalid maxpacket 0
usb 6-1: config 1 interface 1 altsetting 1 endpoint 0x3 has invalid wMaxPacketSize 0
usb 6-1: config 1 interface 1 altsetting 1 bulk endpoint 0x3 has invalid maxpacket 0
usb 6-1: New USB device found, idVendor=0525, idProduct=a4a1, bcdDevice= 0.40
usb 6-1: New USB device strings: Mfr=1, Product=2, SerialNumber=3
usb 6-1: Product: syz
usb 6-1: Manufacturer: syz
usb 6-1: SerialNumber: syz
cdc_ncm 6-1:1.0: bind() failure
cdc_ncm 6-1:1.1: CDC Union missing and no IAD found
cdc_ncm 6-1:1.1: bind() failure
usb 6-1: USB disconnect, device number 2

---
This report is generated by a bot. It may contain errors.
See https://goo.gl/tpsmEJ for more information about syzbot.
syzbot engineers can be reached at syzkaller@xxxxxxxxxxxxxxxx.

syzbot will keep track of this issue. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.

Next message: Huangzhaoyang: "[RFC PATCH] arch: arm64: introduce RODATA_FULL_USE_PTE_CONT"
Previous message: Huang Yiwei: "[PATCH 4/4] dt-bindings: mailbox: Add more protocol and client ID"
Messages sorted by: [ date ] [ thread ] [ subject ] [ author ]