INFO: task hung in usb_bulk_msg

[syzbot]

Hello,

syzbot found the following crash on:

HEAD commit: bb263a2a Linux 4.14.128
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=140c7909a00000
kernel config: https://syzkaller.appspot.com/x/.config?x=3aa328d51a4a3719
dashboard link: https://syzkaller.appspot.com/bug?extid=bf202cb877bfb7f2f886
compiler: gcc (GCC) 9.0.0 20181231 (experimental)

Unfortunately, I don't have any reproducer for this crash yet.

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

audit: type=1400 audit(1561000622.001:8213): avc: denied { map } for
pid=13671 comm="run-parts" path="/bin/run-parts" dev="sda1" ino=1451
scontext=system_u:system_r:insmod_t:s0-s0:c0.c1023
tcontext=system_u:object_r:file_t:s0 tclass=file permissive=1
INFO: task syz-executor.5:13615 blocked for more than 140 seconds.
Not tainted 4.14.128 #22
"echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
syz-executor.5 D28672 13615 7340 0x00000004
Call Trace:
context_switch kernel/sched/core.c:2807 [inline]
__schedule+0x7b8/0x1cd0 kernel/sched/core.c:3383
schedule+0x92/0x1c0 kernel/sched/core.c:3427
schedule_timeout+0x93b/0xe10 kernel/time/timer.c:1721
do_wait_for_common kernel/sched/completion.c:91 [inline]
__wait_for_common kernel/sched/completion.c:112 [inline]
wait_for_common kernel/sched/completion.c:123 [inline]
wait_for_completion_timeout+0x297/0x460 kernel/sched/completion.c:163
usb_start_wait_urb+0x151/0x290 drivers/usb/core/message.c:61
usb_bulk_msg+0x1f8/0x500 drivers/usb/core/message.c:252
proc_bulk+0x3b1/0x6c0 drivers/usb/core/devio.c:1210
usbdev_do_ioctl+0x5a2/0x2a60 drivers/usb/core/devio.c:2438
usbdev_ioctl+0x26/0x30 drivers/usb/core/devio.c:2588
vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]
do_vfs_ioctl+0x7ae/0x1060 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x8f/0xc0 fs/ioctl.c:692
do_syscall_64+0x1e8/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x42/0xb7
RIP: 0033:0x4592c9
RSP: 002b:00007f0058056c78 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 0000000000000003 RCX: 00000000004592c9
RDX: 0000000020000000 RSI: 00000000c0185502 RDI: 0000000000000004
RBP: 000000000075bf20 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000246 R12: 00007f00580576d4
R13: 00000000004c1974 R14: 00000000004d46b8 R15: 00000000ffffffff

Showing all locks held in the system:
1 lock held by khungtaskd/1010:
#0: (tasklist_lock){.+.+}, at: [<ffffffff81483348>]
debug_show_all_locks+0x7f/0x21f kernel/locking/lockdep.c:4541
1 lock held by rsyslogd/7177:
#0: (&f->f_pos_lock){+.+.}, at: [<ffffffff8193e92b>]
__fdget_pos+0xab/0xd0 fs/file.c:769
2 locks held by getty/7299:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff861a3db3>]
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83105ee6>]
n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/7300:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff861a3db3>]
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83105ee6>]
n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/7301:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff861a3db3>]
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83105ee6>]
n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/7302:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff861a3db3>]
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83105ee6>]
n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/7303:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff861a3db3>]
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83105ee6>]
n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/7304:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff861a3db3>]
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83105ee6>]
n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156
2 locks held by getty/7305:
#0: (&tty->ldisc_sem){++++}, at: [<ffffffff861a3db3>]
ldsem_down_read+0x33/0x40 drivers/tty/tty_ldsem.c:377
#1: (&ldata->atomic_read_lock){+.+.}, at: [<ffffffff83105ee6>]
n_tty_read+0x1e6/0x17b0 drivers/tty/n_tty.c:2156

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

NMI backtrace for cpu 0
CPU: 0 PID: 1010 Comm: khungtaskd Not tainted 4.14.128 #22
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+0x138/0x19c lib/dump_stack.c:53
nmi_cpu_backtrace.cold+0x57/0x94 lib/nmi_backtrace.c:101
nmi_trigger_cpumask_backtrace+0x141/0x189 lib/nmi_backtrace.c:62
arch_trigger_cpumask_backtrace+0x14/0x20 arch/x86/kernel/apic/hw_nmi.c:38
trigger_all_cpu_backtrace include/linux/nmi.h:140 [inline]
check_hung_uninterruptible_tasks kernel/hung_task.c:195 [inline]
watchdog+0x5e7/0xb90 kernel/hung_task.c:274
kthread+0x319/0x430 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 skipped: idling at pc 0xffffffff861a489e


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

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

[syzbot]

syzbot has found a reproducer for the following issue on:

HEAD commit: 2c8a3fce Linux 4.14.218
git tree: linux-4.14.y
console output: https://syzkaller.appspot.com/x/log.txt?x=132806e8d00000
kernel config: https://syzkaller.appspot.com/x/.config?x=80e596b8b0902d96
dashboard link: https://syzkaller.appspot.com/bug?extid=bf202cb877bfb7f2f886
syz repro: https://syzkaller.appspot.com/x/repro.syz?x=10c726e8d00000
C reproducer: https://syzkaller.appspot.com/x/repro.c?x=144b08a0d00000

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

INFO: task syz-executor818:7961 blocked for more than 140 seconds.
Not tainted 4.14.218-syzkaller #0

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

syz-executor818 D27848 7961 7960 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_timeout+0x80a/0xe90 kernel/time/timer.c:1724

do_wait_for_common kernel/sched/completion.c:91 [inline]
__wait_for_common kernel/sched/completion.c:112 [inline]

wait_for_common+0x272/0x430 kernel/sched/completion.c:123
usb_start_wait_urb+0x125/0x440 drivers/usb/core/message.c:61
usb_bulk_msg+0x1f6/0x500 drivers/usb/core/message.c:252
proc_bulk+0x331/0x6d0 drivers/usb/core/devio.c:1223
usbdev_do_ioctl+0x5b0/0x2b70 drivers/usb/core/devio.c:2449
usbdev_ioctl+0x21/0x30 drivers/usb/core/devio.c:2599

vfs_ioctl fs/ioctl.c:46 [inline]
file_ioctl fs/ioctl.c:500 [inline]

do_vfs_ioctl+0x75a/0xff0 fs/ioctl.c:684
SYSC_ioctl fs/ioctl.c:701 [inline]
SyS_ioctl+0x7f/0xb0 fs/ioctl.c:692
do_syscall_64+0x1d5/0x640 arch/x86/entry/common.c:292
entry_SYSCALL_64_after_hwframe+0x46/0xbb
RIP: 0033:0x444209
RSP: 002b:00007ffefeb3d318 EFLAGS: 00000246 ORIG_RAX: 0000000000000010
RAX: ffffffffffffffda RBX: 00000000004004a0 RCX: 0000000000444209
RDX: 00000000200002c0 RSI: 00000000c0185502 RDI: 0000000000000003
RBP: 0000000000000000 R08: 00007ffefeb3d4b8 R09: 00007ffefeb3d4b8
R10: 00007ffefeb3cd90 R11: 0000000000000246 R12: 0000000000403520
R13: 431bde82d7b634db R14: 00000000004b2018 R15: 00000000004004a0

Showing all locks held in the system:

1 lock held by khungtaskd/1533:
#0: (tasklist_lock){.+.+}, at: [<ffffffff86fedc17>] debug_show_all_locks+0x7c/0x21a kernel/locking/lockdep.c:4548
1 lock held by in:imklog/7668:
#0: (&f->f_pos_lock){+.+.}, at: [<ffffffff818cffbb>] __fdget_pos+0x1fb/0x2b0 fs/file.c:769

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

NMI backtrace for cpu 0

CPU: 0 PID: 1533 Comm: khungtaskd Not tainted 4.14.218-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 0 to CPUs 1:
NMI backtrace for cpu 1

CPU: 1 PID: 4615 Comm: systemd-journal Not tainted 4.14.218-syzkaller #0

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

task: ffff8880a1b06600 task.stack: ffff8880a1b08000
RIP: 0010:___bpf_prog_run+0x2f49/0x5a70 kernel/bpf/core.c:1134
RSP: 0018:ffff8880a1b0fa48 EFLAGS: 00000246
RAX: 0000000000000080 RBX: dffffc0000000000 RCX: ffff8880a1b0fe68
RDX: 1ffff11014361f6b RSI: ffffc900019c7030 RDI: ffffc900019c7059
RBP: ffff8880a1b0fb58 R08: 0000000000000000 R09: 0000000000000000
R10: 0000000000000000 R11: 0000000000000000 R12: ffffffff878eff60
R13: 1ffff11014361f50 R14: ffffc900019c7058 R15: ffff8880a1b0fb58
FS: 00007fa2e86528c0(0000) GS:ffff8880ba500000(0000) knlGS:0000000000000000
CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
CR2: 00007fa2e5a23000 CR3: 00000000a1f82000 CR4: 00000000001406e0
DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
DR3: 0000000000000000 DR6: 00000000fffe0ff0 DR7: 0000000000000400
Call Trace:
Code: 0f b6 04 18 38 d0 7f 08 84 c0 0f 85 47 18 00 00 41 0f b6 46 01 48 89 c2 83 e2 0f 4c 8d 7c d5 00 4c 89 fa 48 c1 ea 03 80 3c 1a 00 <0f> 85 a6 1d 00 00 c0 e8 04 49 8b 17 0f b6 c0 4c 8d 7c c5 00 4c