syzbot


INFO: task hung in usb_remote_wakeup

Status: auto-closed as invalid on 2021/04/07 18:31
Reported-by: syzbot+2f072bd302ca4104bd81@syzkaller.appspotmail.com
First crash: 1445d, last: 1445d
Similar bugs (6)
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in usb_remote_wakeup (2) usb syz inconclusive done 9 1191d 1389d 20/28 fixed on 2021/11/10 00:50
upstream INFO: task hung in usb_remote_wakeup (3) usb 1 1004d 1004d 0/28 auto-closed as invalid on 2022/05/24 13:32
upstream INFO: task hung in usb_remote_wakeup (5) usb 1 563d 563d 0/28 auto-obsoleted due to no activity on 2023/08/08 04:40
upstream INFO: task hung in usb_remote_wakeup usb 7 1854d 2041d 0/28 auto-closed as invalid on 2020/01/24 14:16
upstream INFO: task hung in usb_remote_wakeup (4) usb 2 744d 794d 0/28 auto-obsoleted due to no activity on 2023/02/10 23:06
linux-4.14 INFO: task hung in usb_remote_wakeup 1 1506d 1506d 0/1 auto-closed as invalid on 2021/02/06 13:01

Sample crash report:
INFO: task kworker/0:3:22597 blocked for more than 140 seconds.
      Not tainted 4.19.162-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/0:3     D30136 22597      2 0x80000000
Workqueue: pm hcd_resume_work
vhci_hcd vhci_hcd.0: pdev(4) rhport(0) sockfd(4)
vhci_hcd vhci_hcd.0: devid(0) speed(2) speed_str(full-speed)
Call Trace:
 context_switch kernel/sched/core.c:2828 [inline]
 __schedule+0x887/0x2040 kernel/sched/core.c:3517
vhci_hcd: connection closed
vhci_hcd: stop threads
vhci_hcd: release socket
vhci_hcd: disconnect device
 schedule+0x8d/0x1b0 kernel/sched/core.c:3561
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3619
 __mutex_lock_common kernel/locking/mutex.c:1002 [inline]
 __mutex_lock+0x647/0x1260 kernel/locking/mutex.c:1072
 device_lock include/linux/device.h:1173 [inline]
 usb_remote_wakeup+0x1f/0xe0 drivers/usb/core/hub.c:3589
 process_one_work+0x864/0x1570 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/1:5:22605 blocked for more than 140 seconds.
      Not tainted 4.19.162-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:5     D29104 22605      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
 context_switch kernel/sched/core.c:2828 [inline]
 __schedule+0x887/0x2040 kernel/sched/core.c:3517
 schedule+0x8d/0x1b0 kernel/sched/core.c:3561
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3619
 __mutex_lock_common kernel/locking/mutex.c:1002 [inline]
 __mutex_lock+0x647/0x1260 kernel/locking/mutex.c:1072
 hub_port_init+0x1b6/0x2fa0 drivers/usb/core/hub.c:4528
 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+0x1cf8/0x43f0 drivers/usb/core/hub.c:5391
 process_one_work+0x864/0x1570 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:
1 lock held by khungtaskd/1566:
 #0: 000000006f2f1457 (rcu_read_lock){....}, at: debug_show_all_locks+0x53/0x265 kernel/locking/lockdep.c:4440
1 lock held by in:imklog/7795:
 #0: 000000007e970508 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0x26f/0x310 fs/file.c:767
5 locks held by kworker/1:3/7801:
 #0: 0000000023c44d9f ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2126
 #1: 0000000090641e1f ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2130
 #2: 00000000b93548d2 (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
 #2: 00000000b93548d2 (&dev->mutex){....}, at: hub_event+0x11b/0x43f0 drivers/usb/core/hub.c:5337
 #3: 00000000b30d61ec (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
 #3: 00000000b30d61ec (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
 #3: 00000000b30d61ec (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
 #3: 00000000b30d61ec (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
 #3: 00000000b30d61ec (&port_dev->status_lock){+.+.}, at: hub_event+0x1ce3/0x43f0 drivers/usb/core/hub.c:5391
 #4: 00000000507fb051 (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b6/0x2fa0 drivers/usb/core/hub.c:4528
5 locks held by kworker/0:4/9353:
 #0: 0000000023c44d9f ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2126
 #1: 000000007c04be4a ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2130
 #2: 00000000eaa87535 (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
 #2: 00000000eaa87535 (&dev->mutex){....}, at: hub_event+0x11b/0x43f0 drivers/usb/core/hub.c:5337
 #3: 00000000ef961a56 (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
 #3: 00000000ef961a56 (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
 #3: 00000000ef961a56 (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
 #3: 00000000ef961a56 (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
 #3: 00000000ef961a56 (&port_dev->status_lock){+.+.}, at: hub_event+0x1ce3/0x43f0 drivers/usb/core/hub.c:5391
 #4: 000000001288681d (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b6/0x2fa0 drivers/usb/core/hub.c:4528
5 locks held by kworker/0:1/20623:
 #0: 0000000023c44d9f ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2126
vhci_hcd vhci_hcd.0: port 1 already used
 #1: 000000008c5796ab ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2130
 #2: 000000001aa4e9e3 (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
 #2: 000000001aa4e9e3 (&dev->mutex){....}, at: hub_event+0x11b/0x43f0 drivers/usb/core/hub.c:5337
 #3: 0000000014956f4e (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
 #3: 0000000014956f4e (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
 #3: 0000000014956f4e (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
 #3: 0000000014956f4e (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
 #3: 0000000014956f4e (&port_dev->status_lock){+.+.}, at: hub_event+0x1ce3/0x43f0 drivers/usb/core/hub.c:5391
 #4: 0000000081da597e (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b6/0x2fa0 drivers/usb/core/hub.c:4528
5 locks held by kworker/1:1/12146:
 #0: 0000000023c44d9f ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2126
 #1: 000000004f00ebd6 ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2130
 #2: 000000001b413407 (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
 #2: 000000001b413407 (&dev->mutex){....}, at: hub_event+0x11b/0x43f0 drivers/usb/core/hub.c:5337
netlink: 216 bytes leftover after parsing attributes in process `syz-executor.5'.
 #3: 000000004fdd0409 (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
 #3: 000000004fdd0409 (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
 #3: 000000004fdd0409 (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
 #3: 000000004fdd0409 (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
 #3: 000000004fdd0409 (&port_dev->status_lock){+.+.}, at: hub_event+0x1ce3/0x43f0 drivers/usb/core/hub.c:5391
netlink: 216 bytes leftover after parsing attributes in process `syz-executor.5'.
 #4: 000000006ae7f2de (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b6/0x2fa0 drivers/usb/core/hub.c:4528
5 locks held by kworker/1:4/16897:
 #0: 0000000023c44d9f ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2126
 #1: 00000000bf6220b1 ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2130
 #2: 00000000a0b6ce8f (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
 #2: 00000000a0b6ce8f (&dev->mutex){....}, at: hub_event+0x11b/0x43f0 drivers/usb/core/hub.c:5337
 #3: 00000000891a00c1 (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
 #3: 00000000891a00c1 (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
 #3: 00000000891a00c1 (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
 #3: 00000000891a00c1 (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
 #3: 00000000891a00c1 (&port_dev->status_lock){+.+.}, at: hub_event+0x1ce3/0x43f0 drivers/usb/core/hub.c:5391
 #4: 00000000c377f230 (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b6/0x2fa0 drivers/usb/core/hub.c:4528
3 locks held by kworker/0:3/22597:
 #0: 00000000b70bfb8e ((wq_completion)"pm"){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2126
 #1: 000000008be158e0 ((work_completion)(&hcd->wakeup_work)){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2130
 #2: 000000009c0be3c0 (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
 #2: 000000009c0be3c0 (&dev->mutex){....}, at: usb_remote_wakeup+0x1f/0xe0 drivers/usb/core/hub.c:3589
5 locks held by kworker/1:5/22605:
 #0: 0000000023c44d9f ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2126
 #1: 00000000b182c118 ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2130
 #2: 000000009c0be3c0 (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
 #2: 000000009c0be3c0 (&dev->mutex){....}, at: hub_event+0x11b/0x43f0 drivers/usb/core/hub.c:5337
 #3: 000000007ec54b76 (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
 #3: 000000007ec54b76 (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
 #3: 000000007ec54b76 (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
 #3: 000000007ec54b76 (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
 #3: 000000007ec54b76 (&port_dev->status_lock){+.+.}, at: hub_event+0x1ce3/0x43f0 drivers/usb/core/hub.c:5391
 #4: 000000006ae7f2de (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b6/0x2fa0 drivers/usb/core/hub.c:4528
5 locks held by kworker/1:6/2297:
 #0: 0000000023c44d9f ((wq_completion)"usb_hub_wq"){+.+.}, at: process_one_work+0x767/0x1570 kernel/workqueue.c:2126
 #1: 00000000e72214ec ((work_completion)(&hub->events)){+.+.}, at: process_one_work+0x79c/0x1570 kernel/workqueue.c:2130
 #2: 000000000acf2ad6 (&dev->mutex){....}, at: device_lock include/linux/device.h:1173 [inline]
 #2: 000000000acf2ad6 (&dev->mutex){....}, at: hub_event+0x11b/0x43f0 drivers/usb/core/hub.c:5337
 #3: 0000000022d78c92 (&port_dev->status_lock){+.+.}, at: usb_lock_port drivers/usb/core/hub.c:2977 [inline]
 #3: 0000000022d78c92 (&port_dev->status_lock){+.+.}, at: hub_port_connect drivers/usb/core/hub.c:5019 [inline]
 #3: 0000000022d78c92 (&port_dev->status_lock){+.+.}, at: hub_port_connect_change drivers/usb/core/hub.c:5203 [inline]
 #3: 0000000022d78c92 (&port_dev->status_lock){+.+.}, at: port_event drivers/usb/core/hub.c:5311 [inline]
 #3: 0000000022d78c92 (&port_dev->status_lock){+.+.}, at: hub_event+0x1ce3/0x43f0 drivers/usb/core/hub.c:5391
 #4: 00000000c377f230 (hcd->address0_mutex){+.+.}, at: hub_port_init+0x1b6/0x2fa0 drivers/usb/core/hub.c:4528

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

NMI backtrace for cpu 0
CPU: 0 PID: 1566 Comm: khungtaskd Not tainted 4.19.162-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+0x1fc/0x2fe lib/dump_stack.c:118
 nmi_cpu_backtrace.cold+0x63/0xa2 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+0x991/0xe60 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 0 to CPUs 1:
NMI backtrace for cpu 1
CPU: 1 PID: 34 Comm: kworker/u4:2 Not tainted 4.19.162-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: bat_events batadv_nc_worker
RIP: 0010:mark_lock+0xa6/0x1160 kernel/locking/lockdep.c:3105
Code: 01 00 00 48 81 eb 50 01 00 00 48 81 c3 40 55 d5 8c 48 8d 7b 30 48 b8 00 00 00 00 00 fc ff df 48 89 fa 48 c1 ea 03 80 3c 02 00 <0f> 85 04 0d 00 00 4c 89 e0 48 23 43 30 0f 84 ad 00 00 00 b8 01 00
RSP: 0018:ffff8880b50cf9a8 EFLAGS: 00000046
RAX: dffffc0000000000 RBX: ffffffff8cd59050 RCX: 1ffff11016a1794f
RDX: 1ffffffff19ab210 RSI: ffff8880b50bca58 RDI: ffffffff8cd59080
RBP: ffff8880b50bca58 R08: 000000000000002e R09: 0000000000000002
R10: ffff8880b50bca58 R11: 0000000000000000 R12: 0000000000000100
R13: ffff8880b50bc180 R14: ffff8880b50bca78 R15: 0000000000000008
FS:  0000000000000000(0000) GS:ffff8880ba100000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f32438c7000 CR3: 0000000074895000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 __lock_acquire+0x6de/0x3ff0 kernel/locking/lockdep.c:3376
 lock_acquire+0x170/0x3c0 kernel/locking/lockdep.c:3907
 rcu_lock_acquire include/linux/rcupdate.h:242 [inline]
 rcu_read_lock include/linux/rcupdate.h:627 [inline]
 batadv_nc_process_nc_paths.part.0+0xec/0x3d0 net/batman-adv/network-coding.c:698
 batadv_nc_process_nc_paths net/batman-adv/network-coding.c:690 [inline]
 batadv_nc_worker+0x9bb/0xd50 net/batman-adv/network-coding.c:739
 process_one_work+0x864/0x1570 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

Crashes (1):
Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Assets (help?) Manager Title
2020/12/08 18:30 linux-4.19.y 4abf26854aad 9af51e31 .config console log report info ci2-linux-4-19
* Struck through repros no longer work on HEAD.