syzbot


INFO: task hung in hub_event

Status: auto-closed as invalid on 2022/05/10 10:19
Reported-by: syzbot+8488769862e6de1de44a@syzkaller.appspotmail.com
First crash: 189d, last: 167d
similar bugs (2):
Kernel Title Repro Cause bisect Fix bisect Count Last Reported Patched Status
upstream INFO: task hung in hub_event 19 996d 1172d 0/22 auto-closed as invalid on 2020/01/02 20:34
upstream INFO: task hung in hub_event (2) 27 167d 212d 0/22 closed as invalid on 2022/02/08 09:40

Sample crash report:
INFO: task kworker/0:3:9048 blocked for more than 140 seconds.
      Not tainted 4.14.261-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/0:3     D27216  9048      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
 context_switch kernel/sched/core.c:2811 [inline]
 __schedule+0x88b/0x1de0 kernel/sched/core.c:3387
 schedule+0x8d/0x1b0 kernel/sched/core.c:3431
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3489
 __mutex_lock_common kernel/locking/mutex.c:833 [inline]
 __mutex_lock+0x669/0x1310 kernel/locking/mutex.c:893
 hub_port_connect drivers/usb/core/hub.c:4921 [inline]
 hub_port_connect_change drivers/usb/core/hub.c:5144 [inline]
 port_event drivers/usb/core/hub.c:5250 [inline]
 hub_event+0x15ea/0x3f60 drivers/usb/core/hub.c:5330
 process_one_work+0x793/0x14a0 kernel/workqueue.c:2117
 worker_thread+0x5cc/0xff0 kernel/workqueue.c:2251
 kthread+0x30d/0x420 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
INFO: task kworker/0:6:11985 blocked for more than 140 seconds.
      Not tainted 4.14.261-syzkaller #0
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/0:6     D28280 11985      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
 context_switch kernel/sched/core.c:2811 [inline]
 __schedule+0x88b/0x1de0 kernel/sched/core.c:3387
 schedule+0x8d/0x1b0 kernel/sched/core.c:3431
 schedule_preempt_disabled+0xf/0x20 kernel/sched/core.c:3489
 __mutex_lock_common kernel/locking/mutex.c:833 [inline]
 __mutex_lock+0x669/0x1310 kernel/locking/mutex.c:893
 hub_port_connect drivers/usb/core/hub.c:4921 [inline]
 hub_port_connect_change drivers/usb/core/hub.c:5144 [inline]
 port_event drivers/usb/core/hub.c:5250 [inline]
 hub_event+0x15ea/0x3f60 drivers/usb/core/hub.c:5330
 process_one_work+0x793/0x14a0 kernel/workqueue.c:2117
 worker_thread+0x5cc/0xff0 kernel/workqueue.c:2251
 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: [<ffffffff81364b80>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2088
 #1:  ((&hub->events)){+.+.}, at: [<ffffffff81364bb6>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2092
 #2:  (&dev->mutex){....}, at: [<ffffffff8445b738>] device_lock include/linux/device.h:1082 [inline]
 #2:  (&dev->mutex){....}, at: [<ffffffff8445b738>] hub_event+0x108/0x3f60 drivers/usb/core/hub.c:5276
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] usb_lock_port drivers/usb/core/hub.c:2936 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_port_connect drivers/usb/core/hub.c:4920 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_port_connect_change drivers/usb/core/hub.c:5144 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] port_event drivers/usb/core/hub.c:5250 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_event+0x15c0/0x3f60 drivers/usb/core/hub.c:5330
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_port_connect drivers/usb/core/hub.c:4921 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_port_connect_change drivers/usb/core/hub.c:5144 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] port_event drivers/usb/core/hub.c:5250 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_event+0x15ea/0x3f60 drivers/usb/core/hub.c:5330
1 lock held by khungtaskd/1532:
 #0:  (tasklist_lock){.+.+}, at: [<ffffffff8701ef67>] debug_show_all_locks+0x7c/0x21a kernel/locking/lockdep.c:4548
5 locks held by kworker/0:3/9048:
 #0:  ("usb_hub_wq"){+.+.}, at: [<ffffffff81364b80>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2088
 #1:  ((&hub->events)){+.+.}, at: [<ffffffff81364bb6>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2092
 #2:  (&dev->mutex){....}, at: [<ffffffff8445b738>] device_lock include/linux/device.h:1082 [inline]
 #2:  (&dev->mutex){....}, at: [<ffffffff8445b738>] hub_event+0x108/0x3f60 drivers/usb/core/hub.c:5276
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] usb_lock_port drivers/usb/core/hub.c:2936 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_port_connect drivers/usb/core/hub.c:4920 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_port_connect_change drivers/usb/core/hub.c:5144 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] port_event drivers/usb/core/hub.c:5250 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_event+0x15c0/0x3f60 drivers/usb/core/hub.c:5330
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_port_connect drivers/usb/core/hub.c:4921 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_port_connect_change drivers/usb/core/hub.c:5144 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] port_event drivers/usb/core/hub.c:5250 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_event+0x15ea/0x3f60 drivers/usb/core/hub.c:5330
5 locks held by kworker/0:5/11307:
 #0:  ("usb_hub_wq"){+.+.}, at: [<ffffffff81364b80>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2088
 #1:  ((&hub->events)){+.+.}, at: [<ffffffff81364bb6>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2092
 #2:  (&dev->mutex){....}, at: [<ffffffff8445b738>] device_lock include/linux/device.h:1082 [inline]
 #2:  (&dev->mutex){....}, at: [<ffffffff8445b738>] hub_event+0x108/0x3f60 drivers/usb/core/hub.c:5276
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] usb_lock_port drivers/usb/core/hub.c:2936 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_port_connect drivers/usb/core/hub.c:4920 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_port_connect_change drivers/usb/core/hub.c:5144 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] port_event drivers/usb/core/hub.c:5250 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_event+0x15c0/0x3f60 drivers/usb/core/hub.c:5330
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_port_connect drivers/usb/core/hub.c:4921 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_port_connect_change drivers/usb/core/hub.c:5144 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] port_event drivers/usb/core/hub.c:5250 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_event+0x15ea/0x3f60 drivers/usb/core/hub.c:5330
5 locks held by kworker/0:6/11985:
 #0:  ("usb_hub_wq"){+.+.}, at: [<ffffffff81364b80>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2088
 #1:  ((&hub->events)){+.+.}, at: [<ffffffff81364bb6>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2092
 #2:  (&dev->mutex){....}, at: [<ffffffff8445b738>] device_lock include/linux/device.h:1082 [inline]
 #2:  (&dev->mutex){....}, at: [<ffffffff8445b738>] hub_event+0x108/0x3f60 drivers/usb/core/hub.c:5276
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] usb_lock_port drivers/usb/core/hub.c:2936 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_port_connect drivers/usb/core/hub.c:4920 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_port_connect_change drivers/usb/core/hub.c:5144 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] port_event drivers/usb/core/hub.c:5250 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_event+0x15c0/0x3f60 drivers/usb/core/hub.c:5330
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_port_connect drivers/usb/core/hub.c:4921 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_port_connect_change drivers/usb/core/hub.c:5144 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] port_event drivers/usb/core/hub.c:5250 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_event+0x15ea/0x3f60 drivers/usb/core/hub.c:5330
5 locks held by kworker/1:3/10574:
 #0:  ("usb_hub_wq"){+.+.}, at: [<ffffffff81364b80>] process_one_work+0x6b0/0x14a0 kernel/workqueue.c:2088
 #1:  ((&hub->events)){+.+.}, at: [<ffffffff81364bb6>] process_one_work+0x6e6/0x14a0 kernel/workqueue.c:2092
 #2:  (&dev->mutex){....}, at: [<ffffffff8445b738>] device_lock include/linux/device.h:1082 [inline]
 #2:  (&dev->mutex){....}, at: [<ffffffff8445b738>] hub_event+0x108/0x3f60 drivers/usb/core/hub.c:5276
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] usb_lock_port drivers/usb/core/hub.c:2936 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_port_connect drivers/usb/core/hub.c:4920 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_port_connect_change drivers/usb/core/hub.c:5144 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] port_event drivers/usb/core/hub.c:5250 [inline]
 #3:  (&port_dev->status_lock){+.+.}, at: [<ffffffff8445cbf0>] hub_event+0x15c0/0x3f60 drivers/usb/core/hub.c:5330
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_port_connect drivers/usb/core/hub.c:4921 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_port_connect_change drivers/usb/core/hub.c:5144 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] port_event drivers/usb/core/hub.c:5250 [inline]
 #4:  (hcd->address0_mutex){+.+.}, at: [<ffffffff8445cc1a>] hub_event+0x15ea/0x3f60 drivers/usb/core/hub.c:5330

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

NMI backtrace for cpu 1
CPU: 1 PID: 1532 Comm: khungtaskd Not tainted 4.14.261-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/0x281 lib/dump_stack.c:58
 nmi_cpu_backtrace.cold+0x57/0x93 lib/nmi_backtrace.c:101
 nmi_trigger_cpumask_backtrace+0x13a/0x180 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 1 to CPUs 0:
NMI backtrace for cpu 0
CPU: 0 PID: 2858 Comm: kworker/u4:4 Not tainted 4.14.261-syzkaller #0
Hardware name: Google Google Compute Engine/Google Compute Engine, BIOS Google 01/01/2011
Workqueue: bat_events batadv_nc_worker
task: ffff8880ac01a0c0 task.stack: ffff8880ac078000
RIP: 0010:debug_lockdep_rcu_enabled kernel/rcu/update.c:300 [inline]
RIP: 0010:debug_lockdep_rcu_enabled+0x9f/0xe0 kernel/rcu/update.c:297
RSP: 0018:ffff8880ac07fc38 EFLAGS: 00000002
RAX: 0000000000000007 RBX: ffff8880ac01a0c0 RCX: 0000000000000001
RDX: 0000000000000000 RSI: 0000000000000002 RDI: ffff8880ac01a944
RBP: ffffffff88f77980 R08: 0000000000000000 R09: 0000000000020012
R10: 0000000000000000 R11: ffff8880ac01a0c0 R12: ffffffff86eb30d0
R13: ffff8880ac01a0c0 R14: ffff88813fe468c0 R15: ffff8880a4a43c00
FS:  0000000000000000(0000) GS:ffff8880ba400000(0000) knlGS:0000000000000000
CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007f2637830741 CR3: 0000000019fd4000 CR4: 00000000003406f0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
 trace_lock_release include/trace/events/lock.h:58 [inline]
 lock_release+0x5a6/0x870 kernel/locking/lockdep.c:4016
 rcu_lock_release include/linux/rcupdate.h:247 [inline]
 rcu_read_unlock include/linux/rcupdate.h:685 [inline]
 batadv_nc_purge_orig_hash net/batman-adv/network-coding.c:422 [inline]
 batadv_nc_worker+0x5a7/0xc50 net/batman-adv/network-coding.c:728
 process_one_work+0x793/0x14a0 kernel/workqueue.c:2117
 worker_thread+0x5cc/0xff0 kernel/workqueue.c:2251
 kthread+0x30d/0x420 kernel/kthread.c:232
 ret_from_fork+0x24/0x30 arch/x86/entry/entry_64.S:404
Code: 02 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 00 31 c0 5b 85 d2 0f 94 c0 c3 31 c0 
----------------
Code disassembly (best guess):
   0:	02 00                	add    (%rax),%al
   2:	48 8d bb 84 08 00 00 	lea    0x884(%rbx),%rdi
   9:	48 b8 00 00 00 00 00 	movabs $0xdffffc0000000000,%rax
  10:	fc ff df
  13:	48 89 fa             	mov    %rdi,%rdx
  16:	48 c1 ea 03          	shr    $0x3,%rdx
  1a:	0f b6 14 02          	movzbl (%rdx,%rax,1),%edx
  1e:	48 89 f8             	mov    %rdi,%rax
  21:	83 e0 07             	and    $0x7,%eax
  24:	83 c0 03             	add    $0x3,%eax
  27:	38 d0                	cmp    %dl,%al
  29:	7c 04                	jl     0x2f
* 2b:	84 d2                	test   %dl,%dl <-- trapping instruction
  2d:	75 32                	jne    0x61
  2f:	8b 93 84 08 00 00    	mov    0x884(%rbx),%edx
  35:	31 c0                	xor    %eax,%eax
  37:	5b                   	pop    %rbx
  38:	85 d2                	test   %edx,%edx
  3a:	0f 94 c0             	sete   %al
  3d:	c3                   	retq
  3e:	31 c0                	xor    %eax,%eax

Crashes (5):
Manager Time Kernel Commit Syzkaller Config Log Report Syz repro C repro VM info Title
ci2-linux-4-14 2022/01/10 10:19 linux-4.14.y bfdef05c8da4 2ca0d385 .config log report info INFO: task hung in hub_event
ci2-linux-4-14 2022/01/08 15:42 linux-4.14.y bfdef05c8da4 2ca0d385 .config log report info INFO: task hung in hub_event
ci2-linux-4-14 2022/01/07 01:48 linux-4.14.y bfdef05c8da4 6acc789a .config log report info INFO: task hung in hub_event
ci2-linux-4-14 2021/12/19 23:06 linux-4.14.y 9dfbac0e6b86 44068e19 .config log report info INFO: task hung in hub_event
ci2-linux-4-14 2021/12/19 11:10 linux-4.14.y 9dfbac0e6b86 44068e19 .config log report info INFO: task hung in hub_event