INFO: task hung in usb_kill_urb

From: syzbot <syzbot+d919b0f29d7b5a4994b9@syzkaller.appspotmail.com>
To: andreyknvl@google.com, gregkh@linuxfoundation.org,
	gustavo@embeddedor.com, linux-kernel@vger.kernel.org,
	linux-usb@vger.kernel.org, syzkaller-bugs@googlegroups.com
Subject: INFO: task hung in usb_kill_urb
Date: Fri, 12 Apr 2019 04:46:11 -0700	[thread overview]
Message-ID: <0000000000006f1596058653d991@google.com> (raw)

Hello,

syzbot found the following crash on:

HEAD commit:    9a33b369 usb-fuzzer: main usb gadget fuzzer driver
git tree:       https://github.com/google/kasan/tree/usb-fuzzer
console output: https://syzkaller.appspot.com/x/log.txt?x=14c4c1af200000
kernel config:  https://syzkaller.appspot.com/x/.config?x=23e37f59d94ddd15
dashboard link: https://syzkaller.appspot.com/bug?extid=d919b0f29d7b5a4994b9
compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=14410dbb200000
C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=12f0acd3200000

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

usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
INFO: task kworker/0:2:532 blocked for more than 143 seconds.
       Not tainted 5.1.0-rc4-319354-g9a33b36 #3
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
kworker/0:2     D26656   532      2 0x80000000
Workqueue: usb_hub_wq hub_event
Call Trace:
  schedule+0x8f/0x180 kernel/sched/core.c:3562
  usb_kill_urb drivers/usb/core/urb.c:695 [inline]
  usb_kill_urb+0x22a/0x2c0 drivers/usb/core/urb.c:687
  usb_start_wait_urb+0x257/0x4d0 drivers/usb/core/message.c:63
  usb_internal_control_msg drivers/usb/core/message.c:101 [inline]
  usb_control_msg+0x321/0x4a0 drivers/usb/core/message.c:152
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
  hub_port_init+0x81d/0x2d30 drivers/usb/core/hub.c:4655
  hub_port_connect drivers/usb/core/hub.c:5021 [inline]
  hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  port_event drivers/usb/core/hub.c:5350 [inline]
  hub_event+0x11b8/0x3b00 drivers/usb/core/hub.c:5432
  process_one_work+0x90f/0x1580 kernel/workqueue.c:2269
  worker_thread+0x9b/0xe20 kernel/workqueue.c:2415
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352

Showing all locks held in the system:
1 lock held by khungtaskd/23:
  #0: 00000000e5b75d53 (rcu_read_lock){....}, at:  
debug_show_all_locks+0x53/0x269 kernel/locking/lockdep.c:5059
5 locks held by kworker/0:2/532:
  #0: 0000000071ab50a3 ((wq_completion)usb_hub_wq){+.+.}, at:  
__write_once_size include/linux/compiler.h:220 [inline]
  #0: 0000000071ab50a3 ((wq_completion)usb_hub_wq){+.+.}, at:  
arch_atomic64_set arch/x86/include/asm/atomic64_64.h:34 [inline]
  #0: 0000000071ab50a3 ((wq_completion)usb_hub_wq){+.+.}, at: atomic64_set  
include/asm-generic/atomic-instrumented.h:855 [inline]
  #0: 0000000071ab50a3 ((wq_completion)usb_hub_wq){+.+.}, at:  
atomic_long_set include/asm-generic/atomic-long.h:40 [inline]
  #0: 0000000071ab50a3 ((wq_completion)usb_hub_wq){+.+.}, at: set_work_data  
kernel/workqueue.c:619 [inline]
  #0: 0000000071ab50a3 ((wq_completion)usb_hub_wq){+.+.}, at:  
set_work_pool_and_clear_pending kernel/workqueue.c:646 [inline]
  #0: 0000000071ab50a3 ((wq_completion)usb_hub_wq){+.+.}, at:  
process_one_work+0x81f/0x1580 kernel/workqueue.c:2240
  #1: 000000004253e0f6 ((work_completion)(&hub->events)){+.+.}, at:  
process_one_work+0x853/0x1580 kernel/workqueue.c:2244
  #2: 00000000eeaa16eb (&dev->mutex){....}, at: device_lock  
include/linux/device.h:1207 [inline]
  #2: 00000000eeaa16eb (&dev->mutex){....}, at: hub_event+0x18a/0x3b00  
drivers/usb/core/hub.c:5378
  #3: 000000004f32b3e5 (&port_dev->status_lock){+.+.}, at: usb_lock_port  
drivers/usb/core/hub.c:2994 [inline]
  #3: 000000004f32b3e5 (&port_dev->status_lock){+.+.}, at: hub_port_connect  
drivers/usb/core/hub.c:5020 [inline]
  #3: 000000004f32b3e5 (&port_dev->status_lock){+.+.}, at:  
hub_port_connect_change drivers/usb/core/hub.c:5204 [inline]
  #3: 000000004f32b3e5 (&port_dev->status_lock){+.+.}, at: port_event  
drivers/usb/core/hub.c:5350 [inline]
  #3: 000000004f32b3e5 (&port_dev->status_lock){+.+.}, at:  
hub_event+0x11a3/0x3b00 drivers/usb/core/hub.c:5432
  #4: 00000000bd3d99c8 (hcd->address0_mutex){+.+.}, at:  
hub_port_init+0x1bb/0x2d30 drivers/usb/core/hub.c:4529
1 lock held by rsyslogd/5433:
  #0: 00000000977dfa25 (&f->f_pos_lock){+.+.}, at: __fdget_pos+0xe8/0x100  
fs/file.c:801
2 locks held by getty/5523:
  #0: 0000000040ff7945 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000006c00c4a7 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5524:
  #0: 00000000cc012e5a (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000001fd3230f (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5525:
  #0: 00000000c53cd960 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 00000000e779c4bc (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5526:
  #0: 00000000a6b003b0 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 00000000bd516627 (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
usb-fuzzer-gadget dummy_udc.0: failed to start USB fuzzer: -22
2 locks held by getty/5527:
  #0: 00000000970614b6 (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000004a83542c (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5528:
  #0: 00000000c9f52a2b (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 0000000068927d8f (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156
2 locks held by getty/5529:
  #0: 00000000b02ccb7f (&tty->ldisc_sem){++++}, at:  
tty_ldisc_ref_wait+0x27/0x80 drivers/tty/tty_ldisc.c:272
  #1: 000000001e46199a (&ldata->atomic_read_lock){+.+.}, at:  
n_tty_read+0x21c/0x1a60 drivers/tty/n_tty.c:2156

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

NMI backtrace for cpu 1
CPU: 1 PID: 23 Comm: khungtaskd Not tainted 5.1.0-rc4-319354-g9a33b36 #3
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+0xe8/0x16e lib/dump_stack.c:113
  nmi_cpu_backtrace.cold+0x48/0x87 lib/nmi_backtrace.c:101
  nmi_trigger_cpumask_backtrace+0x1a6/0x1bd lib/nmi_backtrace.c:62
  trigger_all_cpu_backtrace include/linux/nmi.h:146 [inline]
  check_hung_uninterruptible_tasks kernel/hung_task.c:204 [inline]
  watchdog+0x98e/0xe20 kernel/hung_task.c:288
  kthread+0x313/0x420 kernel/kthread.c:253
  ret_from_fork+0x3a/0x50 arch/x86/entry/entry_64.S:352
Sending NMI from CPU 1 to CPUs 0:
NMI backtrace for cpu 0 skipped: idling at native_safe_halt+0x2/0x10  
arch/x86/include/asm/irqflags.h:57

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

syzbot will keep track of this bug report. See:
https://goo.gl/tpsmEJ#status for how to communicate with syzbot.
syzbot can test patches for this bug, for details see:
https://goo.gl/tpsmEJ#testing-patches