INFO: task hung in hub_port_init

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: cbfa1702 Linux 4.14.198
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=11acc567900000
kernel config: https://syzkaller.appspot.com/x/.config?x=3990958d85b55e59
dashboard link: https://syzkaller.appspot.com/bug?extid=84efe2118f0c865caf18
compiler: gcc (GCC) 10.1.0-syz 20200507

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+84efe2...@syzkaller.appspotmail.com

INFO: task kworker/1:0:18 blocked for more than 140 seconds.
Not tainted 4.14.198-syzkaller #0
Bluetooth: hci5 command 0x0409 tx timeout
FAT-fs (loop4): Unrecognized mount option "mask=^MAY_APPEND" or missing value
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
audit: type=1800 audit(1601713114.010:38): pid=30788 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op="collect_data" cause="failed" comm="syz-executor.3" name="file0" dev="sda1" ino=16249 res=0
kworker/1:0 D25696 18 2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3384
schedule+0x8d/0x1b0 kernel/sched/core.c:3428
usb_kill_urb.part.0+0x125/0x190 drivers/usb/core/urb.c:691
usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:686
usb_start_wait_urb+0x206/0x260 drivers/usb/core/message.c:62
usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
usb_control_msg+0x302/0x450 drivers/usb/core/message.c:151
hub_port_init+0xfb1/0x28b0 drivers/usb/core/hub.c:4555
hub_port_connect drivers/usb/core/hub.c:4905 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
port_event drivers/usb/core/hub.c:5194 [inline]
hub_event+0x1bc5/0x39a0 drivers/usb/core/hub.c:5274
process_one_work+0x793/0x14a0 kernel/workqueue.c:2116
worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

Showing all locks held in the system:
5 locks held by kworker/1:0/18:
#0: ("usb_hub_wq"){+.+.}, at: [<ffffffff813ba640>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
#1: ((&hub->events)){+.+.}, at: [<ffffffff813ba676>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] device_lock include/linux/device.h:1081 [inline]
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] hub_event+0xfc/0x39a0 drivers/usb/core/hub.c:5220
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] usb_lock_port drivers/usb/core/hub.c:2934 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect drivers/usb/core/hub.c:4904 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] port_event drivers/usb/core/hub.c:5194 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_event+0x1bb0/0x39a0 drivers/usb/core/hub.c:5274
#4: (hcd->address0_mutex){+.+.}, at: [<ffffffff842a4b1b>] hub_port_init+0x15b/0x28b0 drivers/usb/core/hub.c:4429
1 lock held by khungtaskd/1067:
#0: (tasklist_lock){.+.+}, at: [<ffffffff814777f4>] debug_show_all_locks+0x7c/0x21a kernel/locking/lockdep.c:4548

=============================================

NMI backtrace for cpu 0
CPU: 0 PID: 1067 Comm: khungtaskd Not tainted 4.14.198-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x1b2/0x283 lib/dump_stack.c:58
nmi_cpu_backtrace.cold+0x57/0x93 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x13a/0x17f lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:140 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:195 [inline]
watchdog+0x5b9/0xb40 kernel/hung_task.c:274
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Sending NMI from CPU 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 3654 Comm: systemd-udevd Not tainted 4.14.198-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
task: ffff88808eb803c0 task.stack: ffff88808eb88000
RIP: 0010:lock_is_held_type+0x30/0x210 kernel/locking/lockdep.c:4029
RSP: 0018:ffff88808eb8f740 EFLAGS: 00000a07
RAX: dffffc0000000000 RBX: ffff88808eb803c0 RCX: 0000000000000001
RDX: 0000000000000000 RSI: 00000000ffffffff RDI: ffff88808eb80c44
RBP: ffffffff87d84de0 R08: ffffffff8a0ace40 R09: 0000000000000001
R10: 0000000000000000 R11: ffff88808eb803c0 R12: 0000000000000bf9
R13: 00000000014000c0 R14: ffff88821f8b9680 R15: ffff88808eb8fd18
FS: 00007f329ca7f8c0(0000) GS:ffff8880aeb00000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00000000016a9e60 CR3: 000000008e52e000 CR4: 00000000001426e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
lock_is_held include/linux/lockdep.h:437 [inline]
___might_sleep+0x227/0x2b0 kernel/sched/core.c:6007
cache_alloc_debugcheck_before mm/slab.c:3065 [inline]
slab_alloc mm/slab.c:3380 [inline]
kmem_cache_alloc+0x2be/0x3c0 mm/slab.c:3550
__d_alloc+0x2a/0xa20 fs/dcache.c:1623
d_alloc+0x46/0x240 fs/dcache.c:1710
d_alloc_parallel+0xd6/0x16b0 fs/dcache.c:2492
lookup_slow+0x175/0x400 fs/namei.c:1679
walk_component+0x6a1/0xbc0 fs/namei.c:1825
lookup_last fs/namei.c:2293 [inline]
path_lookupat+0x1bb/0x780 fs/namei.c:2343
filename_lookup+0x18a/0x510 fs/namei.c:2377
user_path_at include/linux/namei.h:57 [inline]
SYSC_faccessat fs/open.c:403 [inline]
SyS_faccessat+0x21b/0x680 fs/open.c:353
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x7f329b8f29c7
RSP: 002b:00007ffff721b478 EFLAGS: 00000246 ORIG_RAX: 0000000000000015
RAX: ffffffffffffffda RBX: 0000561995089980 RCX: 00007f329b8f29c7
RDX: 00746e657665752f RSI: 0000000000000000 RDI: 00007ffff721b480
RBP: 00007ffff721b4f0 R08: 000000000000c480 R09: 0000000000001010
R10: 0000000000000020 R11: 0000000000000246 R12: 0000561994b73856
R13: 0000561995080c40 R14: 00007ffff721b480 R15: 0000561995090bf0
Code: 00 00 fc ff df 41 54 55 48 89 fd 53 65 48 8b 1c 25 40 ee 01 00 48 8d bb 84 08 00 00 48 83 ec 08 48 89 fa 48 c1 ea 03 0f b6 14 02 <48> 89 f8 83 e0 07 83 c0 03 38 d0 7c 08 84 d2 0f 85 5e 01 00 00


---
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 syzk...@googlegroups.com.

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

[syzbot]

Hello,

syzbot found the following issue on:

HEAD commit: b09c3451 Linux 4.19.149
git tree: linux-4.19.y
console output: https://syzkaller.appspot.com/x/log.txt?x=15e83a0b900000
kernel config: https://syzkaller.appspot.com/x/.config?x=d7c6dfb55644e8fd
dashboard link: https://syzkaller.appspot.com/bug?extid=b4d10b9f0e9790f1843e

compiler: gcc (GCC) 10.1.0-syz 20200507

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+b4d10b...@syzkaller.appspotmail.com

INFO: task kworker/0:2:3723 blocked for more than 140 seconds.
Not tainted 4.19.149-syzkaller #0

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

kworker/0:2 D26472 3723 2 0x80000000

Workqueue: usb_hub_wq hub_event
Call Trace:

context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x8e5/0x22e0 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:697
usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:692
usb_start_wait_urb+0x24f/0x2b0 drivers/usb/core/message.c:63
usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:152
hub_port_init+0x8b3/0x2ea0 drivers/usb/core/hub.c:4654
hub_port_connect drivers/usb/core/hub.c:5020 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
port_event drivers/usb/core/hub.c:5311 [inline]
hub_event+0x1981/0x3fc0 drivers/usb/core/hub.c:5391
process_one_work+0x796/0x14e0 kernel/workqueue.c:2155
worker_thread+0x64c/0x1130 kernel/workqueue.c:2298
kthread+0x33f/0x460 kernel/kthread.c:259
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
INFO: task kworker/0:4:7687 blocked for more than 140 seconds.
Not tainted 4.19.149-syzkaller #0

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

kworker/0:4 D26376 7687 2 0x80000000

Workqueue: usb_hub_wq hub_event
Call Trace:

context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x8e5/0x22e0 kernel/sched/core.c:3517
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:697
audit: type=1800 audit(1601717029.140:16): pid=19513 uid=0 auid=0 ses=4 subj=system_u:system_r:kernel_t:s0 op=collect_data cause=failed(directio) comm="syz-executor.4" name="file0" dev="sda1" ino=17017 res=0
usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:692
usb_start_wait_urb+0x24f/0x2b0 drivers/usb/core/message.c:63
usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:152
hub_port_init+0x8b3/0x2ea0 drivers/usb/core/hub.c:4654
hub_port_connect drivers/usb/core/hub.c:5020 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
port_event drivers/usb/core/hub.c:5311 [inline]
hub_event+0x1981/0x3fc0 drivers/usb/core/hub.c:5391
process_one_work+0x796/0x14e0 kernel/workqueue.c:2155
worker_thread+0x64c/0x1130 kernel/workqueue.c:2298
kthread+0x33f/0x460 kernel/kthread.c:259
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415

Showing all locks held in the system:

2 locks held by kworker/1:1/25:
#0: 00000000dfe32dc1 (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 00000000dfe32dc1 (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
#1: 0000000044cb48a2 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 0000000044cb48a2 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
3 locks held by kworker/u4:2/88:
1 lock held by khungtaskd/1094:
#0: 0000000044cb48a2 (rcu_read_lock){....}, at: debug_show_all_locks+0x53/0x291 kernel/locking/lockdep.c:4440
5 locks held by kworker/u4:4/2365:
5 locks held by kworker/0:2/3723:
#0: 000000001f586335 ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x692/0x14e0 kernel/workqueue.c:2126
#1: 000000001896eeb1 ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x6c8/0x14e0 kernel/workqueue.c:2130
#2: 00000000cac653a4 (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
#2: 00000000cac653a4 (&dev->mutex){....}, at: hub_event+0x10f/0x3fc0 drivers/usb/core/hub.c:5337
#3: 0000000059a6b2ae (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
#3: 0000000059a6b2ae (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
#3: 0000000059a6b2ae (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
#3: 0000000059a6b2ae (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
#3: 0000000059a6b2ae (&port_dev->status_lock){+.+.}, at: hub_event+0x196c/0x3fc0 drivers/usb/core/hub.c:5391
#4: 0000000037868464 (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b5/0x2ea0 drivers/usb/core/hub.c:4528
1 lock held by systemd-udevd/3724:
1 lock held by in:imklog/6221:
#0: 00000000546c78ca (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xe3/0x100 fs/file.c:767
5 locks held by kworker/0:4/7687:
#0: 000000001f586335 ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x692/0x14e0 kernel/workqueue.c:2126
#1: 0000000007573ae9 ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x6c8/0x14e0 kernel/workqueue.c:2130
#2: 00000000d3aa4617 (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
#2: 00000000d3aa4617 (&dev->mutex){....}, at: hub_event+0x10f/0x3fc0 drivers/usb/core/hub.c:5337
#3: 00000000ffe35808 (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
#3: 00000000ffe35808 (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
#3: 00000000ffe35808 (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
#3: 00000000ffe35808 (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
#3: 00000000ffe35808 (&port_dev->status_lock){+.+.}, at: hub_event+0x196c/0x3fc0 drivers/usb/core/hub.c:5391
#4: 000000000ae92859 (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b5/0x2ea0 drivers/usb/core/hub.c:4528
3 locks held by kworker/u4:6/7901:
2 locks held by syz-executor.1/19609:
#0: 000000008ba24353 (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 000000008ba24353 (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
#1: 0000000044cb48a2 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 0000000044cb48a2 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857

=============================================

NMI backtrace for cpu 1
CPU: 1 PID: 1094 Comm: khungtaskd Not tainted 4.19.149-syzkaller #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Call Trace:

__dump_stack lib/dump_stack.c:77 [inline]
dump_stack+0x22c/0x33e lib/dump_stack.c:118
nmi_cpu_backtrace.cold+0x18/0x3d lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x1a6/0x1eb lib/nmi_backtrace.c:62
trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:203 [inline]
watchdog+0xa62/0x1020 kernel/hung_task.c:287
kthread+0x33f/0x460 kernel/kthread.c:259
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
Sending NMI from CPU 1 to CPUs 0:

NMI backtrace for cpu 0

CPU: 0 PID: 3724 Comm: systemd-udevd Not tainted 4.19.149-syzkaller #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011

RIP: 0010:debug_lockdep_rcu_enabled kernel/rcu/update.c:254 [inline]
RIP: 0010:debug_lockdep_rcu_enabled+0x92/0xe0 kernel/rcu/update.c:251
Code: 08 85 c9 74 45 65 48 8b 1c 25 40 ee 01 00 48 8d bb 84 08 00 00 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 0f b6 14 02 <48> 89 f8 83 e0 07 83 c0 03 38 d0 7c 04 84 d2 75 32 8b 93 84 08 00
RSP: 0018:ffff88809017fad8 EFLAGS: 00000a07
RAX: dffffc0000000000 RBX: ffff888090176340 RCX: 0000000000000001
RDX: 0000000000000000 RSI: 0000000000000002 RDI: ffff888090176bc4
RBP: ffff88809017fb28 R08: 0000000000000001 R09: 0000000000000000
R10: 0000000000000005 R11: 0000000000000000 R12: 0000000000000008
R13: ffffffff8d3fd840 R14: 0000000000000000 R15: 0000000000000000
FS: 00007fe2d4d908c0(0000) GS:ffff8880ae200000(0000) knlGS:0000000000000000

CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033

CR2: 00000000016a5374 CR3: 00000000902ab000 CR4: 00000000001406f0

DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000

DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000600
Call Trace:
rcu_read_unlock include/linux/rcupdate.h:677 [inline]
avc_has_perm_noaudit security/selinux/avc.c:1159 [inline]
avc_has_perm+0x18c/0x450 security/selinux/avc.c:1185
inode_has_perm+0x175/0x210 security/selinux/hooks.c:1852
path_has_perm security/selinux/hooks.c:1885 [inline]
selinux_inode_getattr+0x176/0x200 security/selinux/hooks.c:3272
security_inode_getattr+0xcf/0x140 security/security.c:724
vfs_getattr fs/stat.c:113 [inline]
vfs_statx+0x131/0x210 fs/stat.c:189
vfs_lstat include/linux/fs.h:3138 [inline]
__do_sys_newlstat fs/stat.c:350 [inline]
__se_sys_newlstat+0x96/0x120 fs/stat.c:344
do_syscall_64+0xf9/0x670 arch/x86/entry/common.c:293
entry_SYSCALL_64_after_hwframe+0x49/0xbe
RIP: 0033:0x7fe2d3c03335
Code: 69 db 2b 00 64 c7 00 16 00 00 00 b8 ff ff ff ff c3 0f 1f 40 00 83 ff 01 48 89 f0 77 30 48 89 c7 48 89 d6 b8 06 00 00 00 0f 05 <48> 3d 00 f0 ff ff 77 03 f3 c3 90 48 8b 15 31 db 2b 00 f7 d8 64 89
RSP: 002b:00007fff195f2838 EFLAGS: 00000246 ORIG_RAX: 0000000000000006
RAX: ffffffffffffffda RBX: 0000557f9805b290 RCX: 00007fe2d3c03335
RDX: 00007fff195f2870 RSI: 00007fff195f2870 RDI: 0000557f9805a290
RBP: 00007fff195f2930 R08: 00007fe2d3ec21b8 R09: 0000000000001010
R10: 00007fe2d3ec1b58 R11: 0000000000000246 R12: 0000557f9805a290
R13: 0000557f9805a29c R14: 0000557f980678e5 R15: 0000557f980678ec

[syzbot]

syzbot has found a reproducer for the following issue on:

HEAD commit: b09c3451 Linux 4.19.149
git tree: linux-4.19.y

console output: https://syzkaller.appspot.com/x/log.txt?x=137a9a13900000

kernel config: https://syzkaller.appspot.com/x/.config?x=d7c6dfb55644e8fd
dashboard link: https://syzkaller.appspot.com/bug?extid=b4d10b9f0e9790f1843e
compiler: gcc (GCC) 10.1.0-syz 20200507

syz repro: https://syzkaller.appspot.com/x/repro.syz?x=17340c93900000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=15a3cec7900000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+b4d10b...@syzkaller.appspotmail.com

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
INFO: task kworker/1:2:3418 blocked for more than 140 seconds.
vhci_hcd: disconnect device

Not tainted 4.19.149-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

kworker/1:2 D27752 3418 2 0x80000000
Workqueue: usb_hub_wq hub_event
vhci_hcd vhci_hcd.0: port 0 already used
Call Trace:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x8e5/0x22e0 kernel/sched/core.c:3517

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
vhci_hcd: stop threads
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:697
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:692
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
usb_start_wait_urb+0x24f/0x2b0 drivers/usb/core/message.c:63
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd: connection closed

usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:152

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
hub_port_init+0x8b3/0x2ea0 drivers/usb/core/hub.c:4654
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.

hub_port_connect drivers/usb/core/hub.c:5020 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
port_event drivers/usb/core/hub.c:5311 [inline]
hub_event+0x1981/0x3fc0 drivers/usb/core/hub.c:5391

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
process_one_work+0x796/0x14e0 kernel/workqueue.c:2155
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd vhci_hcd.0: port 0 already used
worker_thread+0x64c/0x1130 kernel/workqueue.c:2298
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
kthread+0x33f/0x460 kernel/kthread.c:259
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
INFO: task kworker/0:3:3727 blocked for more than 140 seconds.
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

Not tainted 4.19.149-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
kworker/0:3 D27024 3727 2 0x80000000
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
Workqueue: usb_hub_wq hub_event
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
Call Trace:
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x8e5/0x22e0 kernel/sched/core.c:3517

systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
vhci_hcd vhci_hcd.0: port 0 already used
usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:697
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: disconnect device
usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:692
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
usb_start_wait_urb+0x24f/0x2b0 drivers/usb/core/message.c:63
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd: connection closed
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:152

vhci_hcd: connection closed
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
hub_port_init+0x8b3/0x2ea0 drivers/usb/core/hub.c:4654
vhci_hcd: connection closed
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

hub_port_connect drivers/usb/core/hub.c:5020 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
port_event drivers/usb/core/hub.c:5311 [inline]
hub_event+0x1981/0x3fc0 drivers/usb/core/hub.c:5391

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: connection closed
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
process_one_work+0x796/0x14e0 kernel/workqueue.c:2155
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
worker_thread+0x64c/0x1130 kernel/workqueue.c:2298
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
kthread+0x33f/0x460 kernel/kthread.c:259
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
INFO: task kworker/0:4:6529 blocked for more than 140 seconds.
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: release socket
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
Not tainted 4.19.149-syzkaller #0
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
kworker/0:4 D27688 6529 2 0x80000000
vhci_hcd: connection closed
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
Workqueue: usb_hub_wq hub_event
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
Call Trace:
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x8e5/0x22e0 kernel/sched/core.c:3517

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
schedule+0x8d/0x1b0 kernel/sched/core.c:3561
vhci_hcd: stop threads
usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:697
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: release socket
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:692
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
usb_start_wait_urb+0x24f/0x2b0 drivers/usb/core/message.c:63
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:152

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
hub_port_init+0x8b3/0x2ea0 drivers/usb/core/hub.c:4654
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

hub_port_connect drivers/usb/core/hub.c:5020 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
port_event drivers/usb/core/hub.c:5311 [inline]
hub_event+0x1981/0x3fc0 drivers/usb/core/hub.c:5391

vhci_hcd: connection closed
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
process_one_work+0x796/0x14e0 kernel/workqueue.c:2155
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
process_scheduled_works kernel/workqueue.c:2214 [inline]
worker_thread+0x82b/0x1130 kernel/workqueue.c:2300
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
kthread+0x33f/0x460 kernel/kthread.c:259
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415
vhci_hcd: stop threads
INFO: task kworker/1:1:6545 blocked for more than 140 seconds.
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
Not tainted 4.19.149-syzkaller #0
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

vhci_hcd: connection closed
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
kworker/1:1 D28184 6545 2 0x80000000
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
Workqueue: usb_hub_wq hub_event
vhci_hcd vhci_hcd.0: port 0 already used
Call Trace:
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device

context_switch kernel/sched/core.c:2828 [inline]
__schedule+0x8e5/0x22e0 kernel/sched/core.c:3517

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

schedule+0x8d/0x1b0 kernel/sched/core.c:3561
usb_kill_urb.part.0+0x197/0x220 drivers/usb/core/urb.c:697

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: stop threads
vhci_hcd: connection closed
vhci_hcd: release socket
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:692
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
usb_start_wait_urb+0x24f/0x2b0 drivers/usb/core/message.c:63
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
usb_control_msg+0x31c/0x4a0 drivers/usb/core/message.c:152

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
hub_port_init+0x8b3/0x2ea0 drivers/usb/core/hub.c:4654
vhci_hcd: disconnect device

hub_port_connect drivers/usb/core/hub.c:5020 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
port_event drivers/usb/core/hub.c:5311 [inline]
hub_event+0x1981/0x3fc0 drivers/usb/core/hub.c:5391

vhci_hcd: stop threads
process_one_work+0x796/0x14e0 kernel/workqueue.c:2155
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: connection closed
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

worker_thread+0x64c/0x1130 kernel/workqueue.c:2298
kthread+0x33f/0x460 kernel/kthread.c:259
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:415

Showing all locks held in the system:

vhci_hcd: stop threads
5 locks held by kworker/u4:3/207:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
1 lock held by khungtaskd/1095:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#0: 00000000a387eb56 (rcu_read_lock){....}, at: debug_show_all_locks+0x53/0x291 kernel/locking/lockdep.c:4440
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed
5 locks held by kworker/1:2/3418:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
#0: 00000000fb24e8ee ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x692/0x14e0 kernel/workqueue.c:2126
vhci_hcd vhci_hcd.0: port 0 already used
#1: 000000001ac3be55 ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x6c8/0x14e0 kernel/workqueue.c:2130
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: disconnect device
#2: 00000000076024ec (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
#2: 00000000076024ec (&dev->mutex){....}, at: hub_event+0x10f/0x3fc0 drivers/usb/core/hub.c:5337
vhci_hcd vhci_hcd.0: port 0 already used
#3: 00000000388185d5 (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
#3: 00000000388185d5 (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
#3: 00000000388185d5 (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
#3: 00000000388185d5 (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
#3: 00000000388185d5 (&port_dev->status_lock){+.+.}, at: hub_event+0x196c/0x3fc0 drivers/usb/core/hub.c:5391
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
#4: 0000000011360ac4 (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b5/0x2ea0 drivers/usb/core/hub.c:4528
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
5 locks held by kworker/0:3/3727:
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#0: 00000000fb24e8ee ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x692/0x14e0 kernel/workqueue.c:2126
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
#1: 00000000075c80c9 ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x6c8/0x14e0 kernel/workqueue.c:2130
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed
#2:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
0000000066229dc0 (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
0000000066229dc0 (&dev->mutex){....}, at: hub_event+0x10f/0x3fc0 drivers/usb/core/hub.c:5337
vhci_hcd: disconnect device
#3: 0000000010252681 (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
#3: 0000000010252681 (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
#3: 0000000010252681 (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
#3: 0000000010252681 (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
#3: 0000000010252681 (&port_dev->status_lock){+.+.}, at: hub_event+0x196c/0x3fc0 drivers/usb/core/hub.c:5391
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: release socket
vhci_hcd: connection closed
#4:
vhci_hcd vhci_hcd.0: port 0 already used
000000002f68e3ea (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b5/0x2ea0 drivers/usb/core/hub.c:4528
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
1 lock held by in:imklog/6152:
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: stop threads
#0: 00000000a32141a9 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xe3/0x100 fs/file.c:767
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
5 locks held by kworker/0:4/6529:
vhci_hcd: disconnect device
#0: 00000000fb24e8ee ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x692/0x14e0 kernel/workqueue.c:2126
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
#1: 00000000424d2a55 ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x6c8/0x14e0 kernel/workqueue.c:2130
vhci_hcd: release socket
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
#2: 0000000060a72af4 (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
#2: 0000000060a72af4 (&dev->mutex){....}, at: hub_event+0x10f/0x3fc0 drivers/usb/core/hub.c:5337
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
#3: 000000005284b8a6 (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
#3: 000000005284b8a6 (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
#3: 000000005284b8a6 (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
#3: 000000005284b8a6 (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
#3: 000000005284b8a6 (&port_dev->status_lock){+.+.}, at: hub_event+0x196c/0x3fc0 drivers/usb/core/hub.c:5391
vhci_hcd vhci_hcd.0: port 0 already used
#4: 0000000014233f88 (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b5/0x2ea0 drivers/usb/core/hub.c:4528
vhci_hcd: stop threads
5 locks held by kworker/1:1/6545:
vhci_hcd vhci_hcd.0: port 0 already used
#0: 00000000fb24e8ee ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x692/0x14e0 kernel/workqueue.c:2126
vhci_hcd vhci_hcd.0: port 0 already used
#1: 000000007c7ab800 ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x6c8/0x14e0 kernel/workqueue.c:2130
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd: connection closed
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#2: 00000000efad3966 (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
#2: 00000000efad3966 (&dev->mutex){....}, at: hub_event+0x10f/0x3fc0 drivers/usb/core/hub.c:5337
vhci_hcd: release socket
vhci_hcd: disconnect device
#3: 000000007cb2e58f (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
#3: 000000007cb2e58f (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
#3: 000000007cb2e58f (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
#3: 000000007cb2e58f (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
#3: 000000007cb2e58f (&port_dev->status_lock){+.+.}, at: hub_event+0x196c/0x3fc0 drivers/usb/core/hub.c:5391
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
#4: 0000000055daaa86 (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b5/0x2ea0 drivers/usb/core/hub.c:4528
vhci_hcd: disconnect device
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
5 locks held by kworker/1:4/25816:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#0: 00000000fb24e8ee ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x692/0x14e0 kernel/workqueue.c:2126
vhci_hcd vhci_hcd.0: port 0 already used
#1: 00000000a54b26d4 ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x6c8/0x14e0 kernel/workqueue.c:2130
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
#2: 00000000c717a30f (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
#2: 00000000c717a30f (&dev->mutex){....}, at: hub_event+0x10f/0x3fc0 drivers/usb/core/hub.c:5337
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#3: 0000000027c391c4 (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
#3: 0000000027c391c4 (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
#3: 0000000027c391c4 (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
#3: 0000000027c391c4 (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
#3: 0000000027c391c4 (&port_dev->status_lock){+.+.}, at: hub_event+0x196c/0x3fc0 drivers/usb/core/hub.c:5391
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
#4: 00000000a757b511 (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b5/0x2ea0 drivers/usb/core/hub.c:4528
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
3 locks held by syz-executor528/1389:
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: stop threads
vhci_hcd: connection closed
#0:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
0000000034e07c2d (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
0000000034e07c2d (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
#2: 0000000027f1f094 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
3 locks held by syz-executor528/1409:
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
#2: 00000000de0893d1 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd: stop threads
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
3 locks held by syz-executor528/1427:
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: disconnect device
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
#2: 00000000cdd92234 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
3 locks held by syz-executor528/1439:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
3 locks held by syz-executor528/1447:
vhci_hcd: connection closed
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
#2: 0000000001c37d81 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
3 locks held by syz-executor528/1462:
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#0: 00000000d808908e (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 00000000d808908e (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
#2: 000000007a44100d (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
3 locks held by syz-executor528/1474:
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
3 locks held by syz-executor528/1476:
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
#0: 00000000d808908e (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 00000000d808908e (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd: disconnect device
vhci_hcd: stop threads
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
#2: 00000000de0893d1 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd vhci_hcd.0: port 0 already used
3 locks held by syz-executor528/1503:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
#0: 00000000b71e1b49 (sb_writers#5){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline]
#0: 00000000b71e1b49 (sb_writers#5){.+.+}, at: vfs_write+0x463/0x540 fs/read_write.c:548
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd: connection closed
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
#2: 00000000cdd92234 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
1 lock held by syz-executor528/1527:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd: connection closed
systemd-journald[19281]: /dev/kmsg buffer overrun, some messages lost.
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
3 locks held by syz-executor528/1543:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
#2: 00000000cdd92234 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
3 locks held by syz-executor528/1553:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
#0:
vhci_hcd vhci_hcd.0: port 0 already used
00000000d808908e (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
00000000d808908e (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
#2: 00000000de0893d1 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd vhci_hcd.0: port 0 already used
3 locks held by syz-executor528/1576:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#0: 00000000d808908e (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 00000000d808908e (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd: disconnect device
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#2: 0000000027f1f094 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
3 locks held by syz-executor528/1593:
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#2: 0000000027f1f094 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
3 locks held by syz-executor528/1606:
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
#0: 00000000d808908e (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 00000000d808908e (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
#2: 000000007a44100d (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd: release socket
3 locks held by syz-executor528/1616:
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd: release socket
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#2: 0000000027f1f094 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
3 locks held by syz-executor528/1636:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
3 locks held by syz-executor528/1641:
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
3 locks held by syz-executor528/1643:
vhci_hcd: connection closed
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd vhci_hcd.0: port 0 already used
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
#2:
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
00000000de0893d1 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
3 locks held by syz-executor528/1659:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: rq_lock kernel/sched/sched.h:1823 [inline]
#0: 0000000034e07c2d (&rq->lock){-.-.}, at: __schedule+0x257/0x22e0 kernel/sched/core.c:3455
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
#2: 00000000cdd92234 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
3 locks held by syz-executor528/1679:
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
#0: 00000000b71e1b49 (sb_writers#5){.+.+}, at: file_start_write include/linux/fs.h:2780 [inline]
#0: 00000000b71e1b49 (sb_writers#5){.+.+}, at: vfs_write+0x463/0x540 fs/read_write.c:548
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: devid(0) speed(3) speed_str(high-speed)
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
#1: 00000000a387eb56 (rcu_read_lock){....}, at: trace_sched_stat_runtime include/trace/events/sched.h:428 [inline]
#1: 00000000a387eb56 (rcu_read_lock){....}, at: update_curr+0x2c3/0x8b0 kernel/sched/fair.c:857
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
#2: 00000000de0893d1 (&sig->wait_chldexit){....}, at: __wake_up_common_lock+0xb0/0x170 kernel/sched/wait.c:120
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: st

[syzbot]

syzbot has found a reproducer for the following issue on:

HEAD commit: cbfa1702 Linux 4.14.198
git tree: linux-4.14.y

console output: https://syzkaller.appspot.com/x/log.txt?x=122c923f900000

kernel config: https://syzkaller.appspot.com/x/.config?x=3990958d85b55e59
dashboard link: https://syzkaller.appspot.com/bug?extid=84efe2118f0c865caf18
compiler: gcc (GCC) 10.1.0-syz 20200507

syz repro: https://syzkaller.appspot.com/x/repro.syz?x=167f55bd900000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+84efe2...@syzkaller.appspotmail.com

device hsr_slave_0 entered promiscuous mode
device hsr_slave_1 entered promiscuous mode
IPv6: ADDRCONF(NETDEV_UP): hsr_slave_0: link is not ready
IPv6: ADDRCONF(NETDEV_UP): hsr_slave_1: link is not ready
INFO: task kworker/0:2:2874 blocked for more than 140 seconds.
Not tainted 4.14.198-syzkaller #0

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

kworker/0:2 D27152 2874 2 0x80000000

Workqueue: usb_hub_wq hub_event
Call Trace:

IPv6: ADDRCONF(NETDEV_UP): bridge0: link is not ready

context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3384
schedule+0x8d/0x1b0 kernel/sched/core.c:3428
usb_kill_urb.part.0+0x125/0x190 drivers/usb/core/urb.c:691

IPv6: ADDRCONF(NETDEV_UP): bond0: link is not ready
usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:686
8021q: adding VLAN 0 to HW filter on device bond0
usb_start_wait_urb+0x206/0x260 drivers/usb/core/message.c:62
IPv6: ADDRCONF(NETDEV_UP): veth0: link is not ready
IPv6: ADDRCONF(NETDEV_UP): veth1: link is not ready

usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
usb_control_msg+0x302/0x450 drivers/usb/core/message.c:151
hub_port_init+0xfb1/0x28b0 drivers/usb/core/hub.c:4555
hub_port_connect drivers/usb/core/hub.c:4905 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
port_event drivers/usb/core/hub.c:5194 [inline]
hub_event+0x1bc5/0x39a0 drivers/usb/core/hub.c:5274
process_one_work+0x793/0x14a0 kernel/workqueue.c:2116
worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

Showing all locks held in the system:

1 lock held by khungtaskd/1068:

#0: (tasklist_lock){.+.+}, at: [<ffffffff814777f4>] debug_show_all_locks+0x7c/0x21a kernel/locking/lockdep.c:4548

5 locks held by kworker/0:2/2874:

#0: ("usb_hub_wq"){+.+.}, at: [<ffffffff813ba640>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
#1: ((&hub->events)){+.+.}, at: [<ffffffff813ba676>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091

IPv6: ADDRCONF(NETDEV_CHANGE): veth1: link becomes ready

#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] device_lock include/linux/device.h:1081 [inline]
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] hub_event+0xfc/0x39a0 drivers/usb/core/hub.c:5220
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] usb_lock_port drivers/usb/core/hub.c:2934 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect drivers/usb/core/hub.c:4904 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] port_event drivers/usb/core/hub.c:5194 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_event+0x1bb0/0x39a0 drivers/usb/core/hub.c:5274
#4: (hcd->address0_mutex){+.+.}, at: [<ffffffff842a4b1b>] hub_port_init+0x15b/0x28b0 drivers/usb/core/hub.c:4429

3 locks held by kworker/1:0/6350:
#0: ("%s"("ipv6_addrconf")){+.+.}, at: [<ffffffff813ba640>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
#1: ((&(&ifa->dad_work)->work)){+.+.}, at: [<ffffffff813ba676>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091
#2: (rtnl_mutex){+.+.}, at: [<ffffffff858691a9>] addrconf_dad_work+0x89/0xef0 net/ipv6/addrconf.c:3917
1 lock held by syz-executor.0/19326:
IPv6: ADDRCONF(NETDEV_CHANGE): veth0: link becomes ready
#0:
IPv6: ADDRCONF(NETDEV_UP): team0: link is not ready
(rtnl_mutex){+.+.}, at: [<ffffffff85186d2d>] rtnl_lock net/core/rtnetlink.c:72 [inline]
(rtnl_mutex){+.+.}, at: [<ffffffff85186d2d>] rtnetlink_rcv_msg+0x31d/0xb10 net/core/rtnetlink.c:4311

8021q: adding VLAN 0 to HW filter on device team0

=============================================

NMI backtrace for cpu 0

IPv6: ADDRCONF(NETDEV_UP): veth0_to_bridge: link is not ready
CPU: 0 PID: 1068 Comm: khungtaskd Not tainted 4.14.198-syzkaller #0
IPv6: ADDRCONF(NETDEV_CHANGE): veth0_to_bridge: link becomes ready

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011

IPv6: ADDRCONF(NETDEV_CHANGE): bridge_slave_0: link becomes ready

Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x1b2/0x283 lib/dump_stack.c:58
nmi_cpu_backtrace.cold+0x57/0x93 lib/nmi_backtrace.c:101

bridge0: port 1(bridge_slave_0) entered blocking state
nmi_trigger_cpumask_backtrace+0x13a/0x17f lib/nmi_backtrace.c:62
bridge0: port 1(bridge_slave_0) entered forwarding state

trigger_all_cpu_backtrace include/linux/nmi.h:140 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:195 [inline]
watchdog+0x5b9/0xb40 kernel/hung_task.c:274

IPv6: ADDRCONF(NETDEV_UP): veth1_to_bridge: link is not ready
kthread+0x30d/0x420 kernel/kthread.c:232
IPv6: ADDRCONF(NETDEV_CHANGE): bridge0: link becomes ready

ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Sending NMI from CPU 0 to CPUs 1:

IPv6: ADDRCONF(NETDEV_CHANGE): veth1_to_bridge: link becomes ready

NMI backtrace for cpu 1

CPU: 1 PID: 6587 Comm: kworker/1:3 Not tainted 4.14.198-syzkaller #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011

Workqueue: events linkwatch_event
task: ffff8880941ac040 task.stack: ffff888094d18000
RIP: 0010:reacquire_held_locks+0x5/0x3f0 kernel/locking/lockdep.c:3633
RSP: 0018:ffff888094d1f8b8 EFLAGS: 00000046
RAX: 0000000000000005 RBX: 1ffff110129a3f1b RCX: 1ffff1101283592d
RDX: 0000000000000005 RSI: 0000000000000005 RDI: ffff8880941ac040
RBP: 0000000000000004 R08: 0000000000000001 R09: 0000000000000001
R10: 0000000000000000 R11: ffff8880941ac040 R12: 11e65c9d028e9ccb
R13: ffffffff8a5a8c00 R14: ffff8880941ac040 R15: 0000000000000005
FS: 0000000000000000(0000) GS:ffff8880aeb00000(0000) knlGS:0000000000000000

CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033

CR2: 00007fc273539018 CR3: 000000008fd8f000 CR4: 00000000001406e0

DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:

__lock_release kernel/locking/lockdep.c:3797 [inline]
lock_release+0x36b/0x870 kernel/locking/lockdep.c:4017
__raw_spin_unlock include/linux/spinlock_api_smp.h:150 [inline]
_raw_spin_unlock+0x17/0x40 kernel/locking/spinlock.c:184
console_unlock+0x326/0xf20 kernel/printk/printk.c:2386
vprintk_emit+0x224/0x620 kernel/printk/printk.c:1923
vprintk_func+0x58/0x152 kernel/printk/printk_safe.c:401
printk+0x9e/0xbc kernel/printk/printk.c:1996
addrconf_notify.cold+0x5e/0x17c net/ipv6/addrconf.c:3450
notifier_call_chain+0x108/0x1a0 kernel/notifier.c:93
call_netdevice_notifiers_info net/core/dev.c:1667 [inline]
netdev_state_change net/core/dev.c:1314 [inline]
netdev_state_change+0xca/0xf0 net/core/dev.c:1308
linkwatch_do_dev+0x8a/0xf0 net/core/link_watch.c:164
__linkwatch_run_queue+0x260/0x480 net/core/link_watch.c:202
linkwatch_event+0x3c/0x50 net/core/link_watch.c:237

process_one_work+0x793/0x14a0 kernel/workqueue.c:2116
worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

Code: 24 68 4c 8b 54 24 60 0f b6 74 24 58 4c 8b 44 24 50 48 8b 54 24 48 e9 4e d5 ff ff 90 66 2e 0f 1f 84 00 00 00 00 00 48 63 c2 39 d6 <48> 8d 04 80 48 8d 84 c7 88 08 00 00 0f 86 40 02 00 00 83 ee 01

[syzbot]

syzbot has found a reproducer for the following issue on:

HEAD commit: cbfa1702 Linux 4.14.198
git tree: linux-4.14.y

console output: https://syzkaller.appspot.com/x/log.txt?x=142675ff900000

kernel config: https://syzkaller.appspot.com/x/.config?x=3990958d85b55e59
dashboard link: https://syzkaller.appspot.com/bug?extid=84efe2118f0c865caf18
compiler: gcc (GCC) 10.1.0-syz 20200507

syz repro: https://syzkaller.appspot.com/x/repro.syz?x=133715a3900000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=17ca061f900000

IMPORTANT: if you fix the issue, please add the following tag to the commit:
Reported-by: syzbot+84efe2...@syzkaller.appspotmail.com

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

INFO: task kworker/0:0:3 blocked for more than 140 seconds.

vhci_hcd vhci_hcd.0: port 0 already used

Not tainted 4.14.198-syzkaller #0

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: stop threads

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

kworker/0:0 D28584 3 2 0x80000000
vhci_hcd: connection closed

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device

Workqueue: usb_hub_wq hub_event
Call Trace:

vhci_hcd vhci_hcd.0: port 0 already used

context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3384

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd: release socket

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed

vhci_hcd: stop threads
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

schedule+0x8d/0x1b0 kernel/sched/core.c:3428

vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)

usb_kill_urb.part.0+0x125/0x190 drivers/usb/core/urb.c:691
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used

usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:686
usb_start_wait_urb+0x206/0x260 drivers/usb/core/message.c:62

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd: release socket
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(3)
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
usb_control_msg+0x302/0x450 drivers/usb/core/message.c:151

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd: release socket

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed

hub_port_init+0xfb1/0x28b0 drivers/usb/core/hub.c:4555

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

hub_port_connect drivers/usb/core/hub.c:4905 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
port_event drivers/usb/core/hub.c:5194 [inline]
hub_event+0x1bc5/0x39a0 drivers/usb/core/hub.c:5274

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed
vhci_hcd: stop threads

vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd: release socket

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)

process_one_work+0x793/0x14a0 kernel/workqueue.c:2116
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used

process_scheduled_works kernel/workqueue.c:2176 [inline]
worker_thread+0x7d3/0xff0 kernel/workqueue.c:2252

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

kthread+0x30d/0x420 kernel/kthread.c:232

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

vhci_hcd vhci_hcd.0: port 0 already used

INFO: task kworker/1:0:18 blocked for more than 140 seconds.

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

Not tainted 4.14.198-syzkaller #0

vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used

kworker/1:0 D

vhci_hcd: connection closed
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed
28472 18 2 0x80000000

vhci_hcd vhci_hcd.0: port 0 already used

Workqueue: usb_hub_wq hub_event
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
Call Trace:
vhci_hcd vhci_hcd.0: port 0 already used

context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3384

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

schedule+0x8d/0x1b0 kernel/sched/core.c:3428

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

usb_kill_urb.part.0+0x125/0x190 drivers/usb/core/urb.c:691

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:686

vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: stop threads
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

usb_start_wait_urb+0x206/0x260 drivers/usb/core/message.c:62

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device

vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used

usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
usb_control_msg+0x302/0x450 drivers/usb/core/message.c:151

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used

hub_port_init+0xfb1/0x28b0 drivers/usb/core/hub.c:4555

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd: disconnect device

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

hub_port_connect drivers/usb/core/hub.c:4905 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
port_event drivers/usb/core/hub.c:5194 [inline]
hub_event+0x1bc5/0x39a0 drivers/usb/core/hub.c:5274

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

process_one_work+0x793/0x14a0 kernel/workqueue.c:2116

vhci_hcd: stop threads
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

kthread+0x30d/0x420 kernel/kthread.c:232

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd: release socket

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)
vhci_hcd: connection closed
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

INFO: task kworker/0:2:2690 blocked for more than 140 seconds.

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd: connection closed
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

Not tainted 4.14.198-syzkaller #0

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed

kworker/0:2 D

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

27320 2690 2 0x80000000

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

Workqueue: usb_hub_wq hub_event

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

Call Trace:
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: disconnect device

context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3384

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd: release socket

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

schedule+0x8d/0x1b0 kernel/sched/core.c:3428

vhci_hcd vhci_hcd.0: port 0 already used

usb_kill_urb.part.0+0x125/0x190 drivers/usb/core/urb.c:691

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:686
usb_start_wait_urb+0x206/0x260 drivers/usb/core/message.c:62

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: stop threads

vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(3)
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed

usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
usb_control_msg+0x302/0x450 drivers/usb/core/message.c:151

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

hub_port_init+0xfb1/0x28b0 drivers/usb/core/hub.c:4555

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

hub_port_connect drivers/usb/core/hub.c:4905 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
port_event drivers/usb/core/hub.c:5194 [inline]
hub_event+0x1bc5/0x39a0 drivers/usb/core/hub.c:5274

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: release socket
process_one_work+0x793/0x14a0 kernel/workqueue.c:2116

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: stop threads
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

process_scheduled_works kernel/workqueue.c:2176 [inline]
worker_thread+0x7d3/0xff0 kernel/workqueue.c:2252

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used

kthread+0x30d/0x420 kernel/kthread.c:232

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: release socket
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

vhci_hcd: connection closed
INFO: task kworker/1:2:2749 blocked for more than 140 seconds.

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used

Not tainted 4.14.198-syzkaller #0

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device

kworker/1:2 D28568 2749 2 0x80000000

vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd: connection closed
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

Workqueue: usb_hub_wq hub_event
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

Call Trace:

vhci_hcd: stop threads
vhci_hcd: release socket

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3384

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

schedule+0x8d/0x1b0 kernel/sched/core.c:3428

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)

usb_kill_urb.part.0+0x125/0x190 drivers/usb/core/urb.c:691
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: disconnect device
vhci_hcd: connection closed

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

vhci_hcd: disconnect device
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:686

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

usb_start_wait_urb+0x206/0x260 drivers/usb/core/message.c:62

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd: stop threads

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
usb_control_msg+0x302/0x450 drivers/usb/core/message.c:151

vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

hub_port_init+0xfb1/0x28b0 drivers/usb/core/hub.c:4555

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

hub_port_connect drivers/usb/core/hub.c:4905 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
port_event drivers/usb/core/hub.c:5194 [inline]
hub_event+0x1bc5/0x39a0 drivers/usb/core/hub.c:5274

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

process_one_work+0x793/0x14a0 kernel/workqueue.c:2116

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)

worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed

vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

kthread+0x30d/0x420 kernel/kthread.c:232

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)

ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed

vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

INFO: task kworker/1:1:6349 blocked for more than 140 seconds.

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd: connection closed

vhci_hcd: disconnect device
Not tainted 4.14.198-syzkaller #0

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

kworker/1:1 D28200 6349 2 0x80000000

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

Workqueue: usb_hub_wq hub_event
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
Call Trace:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3384

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used

schedule+0x8d/0x1b0 kernel/sched/core.c:3428

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)

usb_kill_urb.part.0+0x125/0x190 drivers/usb/core/urb.c:691
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:686

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

usb_start_wait_urb+0x206/0x260 drivers/usb/core/message.c:62

vhci_hcd: connection closed
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: stop threads
vhci_hcd: release socket

usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
usb_control_msg+0x302/0x450 drivers/usb/core/message.c:151

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed

vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: stop threads

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd: connection closed
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

hub_port_init+0xfb1/0x28b0 drivers/usb/core/hub.c:4555

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

hub_port_connect drivers/usb/core/hub.c:4905 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
port_event drivers/usb/core/hub.c:5194 [inline]
hub_event+0x1bc5/0x39a0 drivers/usb/core/hub.c:5274

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

process_one_work+0x793/0x14a0 kernel/workqueue.c:2116

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed

vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

kthread+0x30d/0x420 kernel/kthread.c:232

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used

ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

INFO: task kworker/1:3:6392 blocked for more than 140 seconds.

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device

Not tainted 4.14.198-syzkaller #0

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

kworker/1:3 D28632 6392 2 0x80000000
vhci_hcd: connection closed

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device

vhci_hcd vhci_hcd.0: port 0 already used

Workqueue: usb_hub_wq hub_event
vhci_hcd vhci_hcd.0: port 0 already used
Call Trace:
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used

context_switch kernel/sched/core.c:2808 [inline]
__schedule+0x88b/0x1de0 kernel/sched/core.c:3384

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device

schedule+0x8d/0x1b0 kernel/sched/core.c:3428

vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used

usb_kill_urb.part.0+0x125/0x190 drivers/usb/core/urb.c:691

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

usb_kill_urb+0x7c/0x90 drivers/usb/core/urb.c:686

vhci_hcd: connection closed
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed

usb_start_wait_urb+0x206/0x260 drivers/usb/core/message.c:62

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd: connection closed

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

usb_internal_control_msg drivers/usb/core/message.c:100 [inline]
usb_control_msg+0x302/0x450 drivers/usb/core/message.c:151

vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

hub_port_init+0xfb1/0x28b0 drivers/usb/core/hub.c:4555

vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)

hub_port_connect drivers/usb/core/hub.c:4905 [inline]
hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
port_event drivers/usb/core/hub.c:5194 [inline]
hub_event+0x1bc5/0x39a0 drivers/usb/core/hub.c:5274

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(2) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: connection closed
process_one_work+0x793/0x14a0 kernel/workqueue.c:2116

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250

vhci_hcd: stop threads
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: pdev(3) rhport(0) sockfd(3)

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads

vhci_hcd vhci_hcd.0: pdev(0) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed

vhci_hcd: release socket
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used

kthread+0x30d/0x420 kernel/kthread.c:232

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: release socket

ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

vhci_hcd vhci_hcd.0: pdev(5) rhport(0) sockfd(3)
vhci_hcd: disconnect device

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used

Showing all locks held in the system:

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

5 locks held by kworker/0:0/3:

#0: ("usb_hub_wq"){+.+.}, at: [<ffffffff813ba640>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
#1: ((&hub->events)){+.+.}, at: [<ffffffff813ba676>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] device_lock include/linux/device.h:1081 [inline]
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] hub_event+0xfc/0x39a0 drivers/usb/core/hub.c:5220
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] usb_lock_port drivers/usb/core/hub.c:2934 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect drivers/usb/core/hub.c:4904 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] port_event drivers/usb/core/hub.c:5194 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_event+0x1bb0/0x39a0 drivers/usb/core/hub.c:5274
#4: (hcd->address0_mutex){+.+.}, at: [<ffffffff842a4b1b>] hub_port_init+0x15b/0x28b0 drivers/usb/core/hub.c:4429
5 locks held by kworker/1:0/18:
#0: ("usb_hub_wq"){+.+.}, at: [<ffffffff813ba640>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
#1: ((&hub->events)){+.+.}, at: [<ffffffff813ba676>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] device_lock include/linux/device.h:1081 [inline]
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] hub_event+0xfc/0x39a0 drivers/usb/core/hub.c:5220
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] usb_lock_port drivers/usb/core/hub.c:2934 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect drivers/usb/core/hub.c:4904 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] port_event drivers/usb/core/hub.c:5194 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_event+0x1bb0/0x39a0 drivers/usb/core/hub.c:5274
#4: (hcd->address0_mutex){+.+.}, at: [<ffffffff842a4b1b>] hub_port_init+0x15b/0x28b0 drivers/usb/core/hub.c:4429
1 lock held by khungtaskd/1067:
#0: (tasklist_lock){.+.+}, at: [<ffffffff814777f4>] debug_show_all_locks+0x7c/0x21a kernel/locking/lockdep.c:4548

2 locks held by kworker/u4:4/2335:
#0: ("%s""usbip_event"){+.+.}, at: [<ffffffff813ba640>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
#1: (usbip_work){+.+.}, at: [<ffffffff813ba676>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091
5 locks held by kworker/0:2/2690:

#0: ("usb_hub_wq"){+.+.}, at: [<ffffffff813ba640>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
#1: ((&hub->events)){+.+.}, at: [<ffffffff813ba676>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] device_lock include/linux/device.h:1081 [inline]
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] hub_event+0xfc/0x39a0 drivers/usb/core/hub.c:5220
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] usb_lock_port drivers/usb/core/hub.c:2934 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect drivers/usb/core/hub.c:4904 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] port_event drivers/usb/core/hub.c:5194 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_event+0x1bb0/0x39a0 drivers/usb/core/hub.c:5274
#4: (hcd->address0_mutex){+.+.}, at: [<ffffffff842a4b1b>] hub_port_init+0x15b/0x28b0 drivers/usb/core/hub.c:4429

5 locks held by kworker/1:2/2749:

#0: ("usb_hub_wq"){+.+.}, at: [<ffffffff813ba640>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
#1: ((&hub->events)){+.+.}, at: [<ffffffff813ba676>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] device_lock include/linux/device.h:1081 [inline]
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] hub_event+0xfc/0x39a0 drivers/usb/core/hub.c:5220
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] usb_lock_port drivers/usb/core/hub.c:2934 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect drivers/usb/core/hub.c:4904 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] port_event drivers/usb/core/hub.c:5194 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_event+0x1bb0/0x39a0 drivers/usb/core/hub.c:5274
#4: (hcd->address0_mutex){+.+.}, at: [<ffffffff842a4b1b>] hub_port_init+0x15b/0x28b0 drivers/usb/core/hub.c:4429

5 locks held by kworker/1:1/6349:

#0: ("usb_hub_wq"){+.+.}, at: [<ffffffff813ba640>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
#1: ((&hub->events)){+.+.}, at: [<ffffffff813ba676>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] device_lock include/linux/device.h:1081 [inline]
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] hub_event+0xfc/0x39a0 drivers/usb/core/hub.c:5220
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] usb_lock_port drivers/usb/core/hub.c:2934 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect drivers/usb/core/hub.c:4904 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] port_event drivers/usb/core/hub.c:5194 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_event+0x1bb0/0x39a0 drivers/usb/core/hub.c:5274
#4: (hcd->address0_mutex){+.+.}, at: [<ffffffff842a4b1b>] hub_port_init+0x15b/0x28b0 drivers/usb/core/hub.c:4429

1 lock held by syz-executor463/6366:
#0: (tasklist_lock){.+.+}, at: [<ffffffff8136c26d>] release_task+0x14d/0x1380 kernel/exit.c:198
5 locks held by kworker/1:3/6392:

#0: ("usb_hub_wq"){+.+.}, at: [<ffffffff813ba640>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
#1: ((&hub->events)){+.+.}, at: [<ffffffff813ba676>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] device_lock include/linux/device.h:1081 [inline]
#2: (&dev->mutex){....}, at: [<ffffffff842ae59c>] hub_event+0xfc/0x39a0 drivers/usb/core/hub.c:5220
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] usb_lock_port drivers/usb/core/hub.c:2934 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect drivers/usb/core/hub.c:4904 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] port_event drivers/usb/core/hub.c:5194 [inline]
#3: (&port_dev->status_lock){+.+.}, at: [<ffffffff842b0050>] hub_event+0x1bb0/0x39a0 drivers/usb/core/hub.c:5274
#4: (hcd->address0_mutex){+.+.}, at: [<ffffffff842a4b1b>] hub_port_init+0x15b/0x28b0 drivers/usb/core/hub.c:4429

3 locks held by syz-executor463/8451:
#0: (sb_writers#5){.+.+}, at: [<ffffffff818d56f8>] file_start_write include/linux/fs.h:2712 [inline]
#0: (sb_writers#5){.+.+}, at: [<ffffffff818d56f8>] vfs_write+0x3d8/0x4d0 fs/read_write.c:543
#1: (&of->mutex){+.+.}, at: [<ffffffff81a9ebf9>] kernfs_fop_write+0x1d9/0x440 fs/kernfs/file.c:307
#2: (kn->count#72){.+.+}, at: [<ffffffff81a9ec1c>] kernfs_fop_write+0x1fc/0x440 fs/kernfs/file.c:308

=============================================

vhci_hcd: stop threads
vhci_hcd: release socket
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: pdev(1) rhport(0) sockfd(3)

vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd: disconnect device
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: connection closed
vhci_hcd: stop threads
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd: release socket
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(3)
vhci_hcd vhci_hcd.0: port 0 already used

vhci_hcd vhci_hcd.0: devid(0) speed(1) speed_str(low-speed)

vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd: disconnect device
vhci_hcd: connection closed
vhci_hcd vhci_hcd.0: port 0 already used
vhci_hcd vhci_hcd.0: port 0 already used

NMI backtrace for cpu 0

vhci_hcd vhci_hcd.0: port 0 already used

CPU: 0 PID: 1067 Comm: khungtaskd Not tainted 4.14.198-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011

vhci_hcd vhci_hcd.0: port 0 already used

Call Trace:
__dump_stack lib/dump_stack.c:17 [inline]
dump_stack+0x1b2/0x283 lib/dump_stack.c:58
nmi_cpu_backtrace.cold+0x57/0x93 lib/nmi_backtrace.c:101

vhci_hcd: stop threads
nmi_trigger_cpumask_backtrace+0x13a/0x17f lib/nmi_backtrace.c:62
vhci_hcd: release socket

trigger_all_cpu_backtrace include/linux/nmi.h:140 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:195 [inline]
watchdog+0x5b9/0xb40 kernel/hung_task.c:274
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

vhci_hcd: disconnect device

Sending NMI from CPU 0 to CPUs 1:

vhci_hcd: stop threads

NMI backtrace for cpu 1

CPU: 1 PID: 2335 Comm: kworker/u4:4 Not tainted 4.14.198-syzkaller #0

Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011

Workqueue: usbip_event event_handler
task: ffff8880a15a6300 task.stack: ffff8880a15b0000
RIP: 0010:mark_irqflags kernel/locking/lockdep.c:3086 [inline]
RIP: 0010:__lock_acquire+0xcf4/0x3f20 kernel/locking/lockdep.c:3448
RSP: 0018:ffff8880a15b7940 EFLAGS: 00000046
RAX: 0000000000000004 RBX: 0000000000000080 RCX: 0000000000000000
RDX: 0000000000000002 RSI: ffff8880a15a6bd8 RDI: ffff8880a15a6300
RBP: ffff8880a15a6bfa R08: 0000000000000001 R09: 0000000000048006
R10: ffff8880a15a6bd8 R11: ffff8880a15a6300 R12: ffff8880a15a6bf0
R13: 0000000000000006 R14: 0000000000000006 R15: ffffffff8a5a8c00
FS: 0000000000000000(0000) GS:ffff8880aeb00000(0000) knlGS:0000000000000000

CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033

CR2: 00000000006cc0a0 CR3: 000000009f0d4000 CR4: 00000000001406e0

DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:

lock_acquire+0x170/0x3f0 kernel/locking/lockdep.c:3998
console_trylock_spinning kernel/printk/printk.c:1692 [inline]
vprintk_emit+0x41a/0x620 kernel/printk/printk.c:1922

vprintk_func+0x58/0x152 kernel/printk/printk_safe.c:401
printk+0x9e/0xbc kernel/printk/printk.c:1996

vhci_shutdown_connection.cold+0x3c/0x7f3 drivers/usb/usbip/vhci_hcd.c:1038
event_handler+0x18a/0x420 drivers/usb/usbip/usbip_event.c:92

process_one_work+0x793/0x14a0 kernel/workqueue.c:2116
worker_thread+0x5cc/0xff0 kernel/workqueue.c:2250
kthread+0x30d/0x420 kernel/kthread.c:232
ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404

Code: 24 20 e8 90 61 3e 00 4c 8b 5c 24 28 4c 8b 54 24 20 e9 8a f8 ff ff ba 02 00 00 00 4c 89 d6 4c 89 df 4c 89 54 24 28 4c 89 5c 24 20 <e8> 37 dc ff ff 85 c0 0f 84 7d f4 ff ff 48 b8 00 00 00 00 00 fc