Re: INFO: task hung in usb_bulk_msg

[Alan Stern]

On Fri, Aug 28, 2020 at 05:52:16AM -0700, syzbot wrote:
> syzbot has found a reproducer for the following issue on:
> 
> HEAD commit:    15bc20c6 Merge tag 'tty-5.9-rc3' of git://git.kernel.org/p..
> git tree:       upstream
> console output: https://syzkaller.appspot.com/x/log.txt?x=1052a669900000
> kernel config:  https://syzkaller.appspot.com/x/.config?x=978db74cb30aa994
> dashboard link: https://syzkaller.appspot.com/bug?extid=7a7613e5ba9ae7bd15f9
> compiler:       gcc (GCC) 10.1.0-syz 20200507
> syz repro:      https://syzkaller.appspot.com/x/repro.syz?x=101c328e900000
> C reproducer:   https://syzkaller.appspot.com/x/repro.c?x=155eff41900000
> 
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: syzbot+7a7613e5ba9ae7bd15f9@xxxxxxxxxxxxxxxxxxxxxxxxx
> 
> INFO: task syz-executor790:9958 blocked for more than 143 seconds.
>       Not tainted 5.9.0-rc2-syzkaller #0
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> task:syz-executor790 state:D stack:28240 pid: 9958 ppid:  6854 flags:0x00004004
> Call Trace:
>  context_switch kernel/sched/core.c:3778 [inline]
>  __schedule+0x8e5/0x21e0 kernel/sched/core.c:4527
>  schedule+0xd0/0x2a0 kernel/sched/core.c:4602
>  schedule_timeout+0x1d8/0x250 kernel/time/timer.c:1855
>  do_wait_for_common kernel/sched/completion.c:85 [inline]
>  __wait_for_common kernel/sched/completion.c:106 [inline]
>  wait_for_common kernel/sched/completion.c:117 [inline]
>  wait_for_completion_timeout+0x15e/0x270 kernel/sched/completion.c:157
>  usb_start_wait_urb+0x144/0x2b0 drivers/usb/core/message.c:63
>  usb_bulk_msg+0x226/0x550 drivers/usb/core/message.c:254
>  do_proc_bulk+0x39b/0x710 drivers/usb/core/devio.c:1231
>  proc_bulk drivers/usb/core/devio.c:1268 [inline]
>  usbdev_do_ioctl drivers/usb/core/devio.c:2542 [inline]
>  usbdev_ioctl+0x586/0x3360 drivers/usb/core/devio.c:2708

I'm confused about this bug report.

Here's the syz reproducer from the link listed above:

# 
https://syzkaller.appspot.com/bug?id=bf172344c5f1d3487a4feff67c3dd30e08d5b635
# See https://goo.gl/kgGztJ for information about syzkaller reproducers.
#{"threaded":true,"repeat":true,"procs":6,"sandbox":"none","fault_call":-1,"netdev":true,"close_fds":true}
r0 = syz_open_dev$usbfs(&(0x7f0000000040)='/dev/bus/usb/00#/00#\x00', 
0x4000000000000071, 0x28081)
r1 = socket$inet6(0xa, 0x2, 0x0)
r2 = dup(r1)
ioctl$PERF_EVENT_IOC_ENABLE(r2, 0x8912, 0x400200)
socketpair$unix(0x1, 0x0, 0x0, &(0x7f0000000000))
ioctl$USBDEVFS_CONTROL(r0, 0x8108551b, &(0x7f0000001140)={0x0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0})
ioctl$USBDEVFS_CLEAR_HALT(r0, 0xc0185502, &(0x7f0000000000)={0x1, 0x1})

As far as I can see, the only USB ioctls used in this test are 
USBDEVFS_CONTROL and USBDEVFS_CLEAR_HALT.  Neither of those calls 
do_proc_bulk() or usb_bulk_msg(), so how did those routines end up in 
the stack trace?

In fact, do_proc_bulk() is called only for USBDEVFS_BULK.  But the test 
doesn't use that ioctl!

What's going on?  Am I missing part of the test?

Alan Stern