syzbot


INFO: task hung in usbdev_release

Status: auto-closed as invalid on 2021/04/27 06:36
Reported-by: syzbot+3eb3ce4b14f240e2cedd@syzkaller.appspotmail.com
First crash: 611d, last: 548d
similar bugs (3):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in usbdev_release 20 192d 599d 0/22 closed as invalid on 2022/02/07 19:19
linux-4.19 INFO: task hung in usbdev_release 1 612d 612d 0/1 auto-closed as invalid on 2021/02/21 22:17
linux-4.19 INFO: task hung in usbdev_release (2) 8 15d 333d 0/1 upstream: reported on 2021/07/31 01:53

Sample crash report:
EXT4-fs (loop4): mounting ext2 file system using the ext4 subsystem
EXT4-fs: failed to create workqueue
EXT4-fs (loop4): mount failed
INFO: task syz-executor.2:10130 blocked for more than 140 seconds.
      Not tainted 4.14.212-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.2  D28560 10130   8028 0x80000002
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
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3486
 __mutex_lock_common kernel/locking/mutex.c:833 [inline]
 __mutex_lock+0x669/0x1310 kernel/locking/mutex.c:893
 device_lock include/linux/device.h:1081 [inline]
 usbdev_release+0x73/0x380 drivers/usb/core/devio.c:1066
 __fput+0x25f/0x7a0 fs/file_table.c:210
 task_work_run+0x11f/0x190 kernel/task_work.c:113
 exit_task_work include/linux/task_work.h:22 [inline]
 do_exit+0xa44/0x2850 kernel/exit.c:868
 do_group_exit+0x100/0x2e0 kernel/exit.c:965
 get_signal+0x38d/0x1ca0 kernel/signal.c:2423
 do_signal+0x7c/0x1550 arch/x86/kernel/signal.c:814
 exit_to_usermode_loop+0x160/0x200 arch/x86/entry/common.c:160
 prepare_exit_to_usermode arch/x86/entry/common.c:199 [inline]
 syscall_return_slowpath arch/x86/entry/common.c:270 [inline]
 do_syscall_64+0x4a3/0x640 arch/x86/entry/common.c:297
 entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x45e229
RSP: 002b:00007fe0bc3fecf8 EFLAGS: 00000246 ORIG_RAX: 00000000000000ca
RAX: fffffffffffffe00 RBX: 000000000119bf88 RCX: 000000000045e229
RDX: 0000000000000000 RSI: 0000000000000080 RDI: 000000000119bf88
RBP: 000000000119bf80 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 000000000119bf8c
R13: 00007ffc70b9c06f R14: 00007fe0bc3ff9c0 R15: 000000000119bf8c
INFO: task kworker/1:0:13846 blocked for more than 140 seconds.
      Not tainted 4.14.212-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:0     D28160 13846      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+0x209/0x440 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
 usb_get_descriptor+0xc0/0x160 drivers/usb/core/message.c:652
 usb_get_device_descriptor+0x71/0xd0 drivers/usb/core/message.c:924
 hub_port_init+0x629/0x2970 drivers/usb/core/hub.c:4647
 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+0x1923/0x3dc0 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
INFO: task kworker/1:2:8939 blocked for more than 140 seconds.
      Not tainted 4.14.212-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/1:2     D28184  8939      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+0x209/0x440 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+0xfdc/0x2970 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+0x1923/0x3dc0 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
INFO: task kworker/0:0:9344 blocked for more than 140 seconds.
      Not tainted 4.14.212-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/0:0     D28520  9344      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+0x209/0x440 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+0xfdc/0x2970 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+0x1923/0x3dc0 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
INFO: task syz-executor.2:2403 blocked for more than 140 seconds.
      Not tainted 4.14.212-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.2  D29776  2403   8028 0x00000004
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
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3486
 __mutex_lock_common kernel/locking/mutex.c:833 [inline]
 __mutex_lock+0x669/0x1310 kernel/locking/mutex.c:893
 device_lock include/linux/device.h:1081 [inline]
 usbdev_open+0x142/0x780 drivers/usb/core/devio.c:1023
 chrdev_open+0x23c/0x6d0 fs/char_dev.c:423
 do_dentry_open+0x44b/0xec0 fs/open.c:777
 vfs_open+0x105/0x220 fs/open.c:888
 do_last fs/namei.c:3428 [inline]
 path_openat+0x628/0x2970 fs/namei.c:3569
 do_filp_open+0x179/0x3c0 fs/namei.c:3603
 do_sys_open+0x296/0x410 fs/open.c:1081
 do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
 entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x417d21
RSP: 002b:00007fe0bc3fe810 EFLAGS: 00000293 ORIG_RAX: 0000000000000002
RAX: ffffffffffffffda RBX: 6666666666666667 RCX: 0000000000417d21
RDX: 0000000000000000 RSI: 0000000000000000 RDI: 00007fe0bc3fe840
RBP: 000000000119bfc0 R08: 000000000000000f R09: 0000000000000000
R10: 00007fe0bc3ff9d0 R11: 0000000000000293 R12: 000000000119bf8c
R13: 00007ffc70b9c06f R14: 00007fe0bc3ff9c0 R15: 000000000119bf8c

Showing all locks held in the system:
1 lock held by khungtaskd/1530:
 #0:  (tasklist_lock){.+.?}, at: [<ffffffff81430cb4>] debug_show_all_locks+0x7c/0x21a kernel/locking/lockdep.c:4548
1 lock held by in:imklog/7694:
 #0:  (&f->f_pos_lock){+.+.}, at: [<ffffffff818f8b5b>] __fdget_pos+0x1fb/0x2b0 fs/file.c:769
1 lock held by syz-executor.2/10130:
 #0:  (&dev->mutex){....}, at: [<ffffffff8455edf3>] device_lock include/linux/device.h:1081 [inline]
 #0:  (&dev->mutex){....}, at: [<ffffffff8455edf3>] usbdev_release+0x73/0x380 drivers/usb/core/devio.c:1066
5 locks held by kworker/1:0/13846:
 #0:  ("usb_hub_wq"){+.+.}, at: [<ffffffff81373610>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
 #1:  ((&hub->events)){+.+.}, at: [<ffffffff81373646>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091
 #2:  (&dev->mutex){....}, at: [<ffffffff8452bed8>] device_lock include/linux/device.h:1081 [inline]
 #2:  (&dev->mutex){....}, at: [<ffffffff8452bed8>] hub_event+0x108/0x3dc0 drivers/usb/core/hub.c:5220
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] usb_lock_port drivers/usb/core/hub.c:2934 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] hub_port_connect drivers/usb/core/hub.c:4904 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] port_event drivers/usb/core/hub.c:5194 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] hub_event+0x190e/0x3dc0 drivers/usb/core/hub.c:5274
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff84521a1b>] hub_port_init+0x15b/0x2970 drivers/usb/core/hub.c:4429
5 locks held by kworker/1:2/8939:
 #0:  ("usb_hub_wq"){+.+.}, at: [<ffffffff81373610>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
 #1:  ((&hub->events)){+.+.}, at: [<ffffffff81373646>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091
 #2:  (&dev->mutex){....}, at: [<ffffffff8452bed8>] device_lock include/linux/device.h:1081 [inline]
 #2:  (&dev->mutex){....}, at: [<ffffffff8452bed8>] hub_event+0x108/0x3dc0 drivers/usb/core/hub.c:5220
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] usb_lock_port drivers/usb/core/hub.c:2934 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] hub_port_connect drivers/usb/core/hub.c:4904 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] port_event drivers/usb/core/hub.c:5194 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] hub_event+0x190e/0x3dc0 drivers/usb/core/hub.c:5274
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff84521a1b>] hub_port_init+0x15b/0x2970 drivers/usb/core/hub.c:4429
5 locks held by kworker/0:0/9344:
 #0:  ("usb_hub_wq"){+.+.}, at: [<ffffffff81373610>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2087
 #1:  ((&hub->events)){+.+.}, at: [<ffffffff81373646>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2091
 #2:  (&dev->mutex){....}, at: [<ffffffff8452bed8>] device_lock include/linux/device.h:1081 [inline]
 #2:  (&dev->mutex){....}, at: [<ffffffff8452bed8>] hub_event+0x108/0x3dc0 drivers/usb/core/hub.c:5220
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] usb_lock_port drivers/usb/core/hub.c:2934 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] hub_port_connect drivers/usb/core/hub.c:4904 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] hub_port_connect_change drivers/usb/core/hub.c:5088 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] port_event drivers/usb/core/hub.c:5194 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8452d6de>] hub_event+0x190e/0x3dc0 drivers/usb/core/hub.c:5274
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff84521a1b>] hub_port_init+0x15b/0x2970 drivers/usb/core/hub.c:4429
1 lock held by syz-executor.2/2403:
 #0:  (&dev->mutex){....}, at: [<ffffffff8455f282>] device_lock include/linux/device.h:1081 [inline]
 #0:  (&dev->mutex){....}, at: [<ffffffff8455f282>] usbdev_open+0x142/0x780 drivers/usb/core/devio.c:1023

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

NMI backtrace for cpu 0
CPU: 0 PID: 1530 Comm: khungtaskd Not tainted 4.14.212-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: 8 Comm: rcu_preempt Not tainted 4.14.212-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
task: ffff8880b5414200 task.stack: ffff8880b5418000
RIP: 0010:__preempt_count_dec_and_test arch/x86/include/asm/preempt.h:91 [inline]
RIP: 0010:rcu_read_unlock_sched_notrace include/linux/rcupdate.h:775 [inline]
RIP: 0010:trace_lock_acquire include/trace/events/lock.h:13 [inline]
RIP: 0010:lock_acquire+0x314/0x3f0 kernel/locking/lockdep.c:3997
RSP: 0018:ffff8880b541fad0 EFLAGS: 00000046
RAX: 0000000000000000 RBX: ffff8880a1c03f28 RCX: 0000000000000001
RDX: 0000000000000001 RSI: 0000000000000002 RDI: ffff8880b5414a84
RBP: ffffffff8bfb09e0 R08: 0000000000000000 R09: 0000000000000001
R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
R13: 0000000000000000 R14: 0000000000000000 R15: 0000000000000001
FS:  0000000000000000(0000) GS:ffff8880ba500000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fd451ec9000 CR3: 00000000a957c000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 __raw_spin_lock_irqsave include/linux/spinlock_api_smp.h:110 [inline]
 _raw_spin_lock_irqsave+0x8c/0xc0 kernel/locking/spinlock.c:160
 debug_object_assert_init lib/debugobjects.c:638 [inline]
 debug_object_assert_init+0xdd/0x2d0 lib/debugobjects.c:627
 debug_timer_assert_init kernel/time/timer.c:708 [inline]
 debug_assert_init kernel/time/timer.c:756 [inline]
 try_to_del_timer_sync+0x5d/0xe0 kernel/time/timer.c:1176
 del_timer_sync+0x17c/0x240 kernel/time/timer.c:1246
 schedule_timeout+0x4b7/0xe90 kernel/time/timer.c:1748
 rcu_gp_kthread+0xc0a/0x1e60 kernel/rcu/tree.c:2255
 kthread+0x30d/0x420 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Code: ff e8 64 36 bd ff e9 2b fe ff ff 65 ff 05 05 f4 be 7e 48 8b 05 16 20 b0 08 e8 c9 f8 04 00 85 c0 74 09 80 3d b9 cf af 08 00 74 3f <65> ff 0d e5 f3 be 7e 0f 85 1e fe ff ff e8 2d 36 bd ff e9 14 fe 

Crashes (2):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci2-linux-4-14 2020/12/28 06:35 linux-4.14.y 3f2ecb86cb90 2242f77f .config log report info
ci2-linux-4-14 2020/10/26 06:20 linux-4.14.y 5b7a52cd2eef a1839e81 .config log report info