Re: INFO: task hung in usb_bulk_msg

[Dmitry Vyukov <dvyukov@google.com>]

On Mon, Aug 31, 2020 at 3:08 PM 'Andrey Konovalov' via syzkaller-bugs
<syzkaller-bugs@googlegroups.com> wrote:
>
> On Sat, Aug 29, 2020 at 3:24 AM Alan Stern <stern@rowland.harvard.edu> wrote:
> >
> > 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@syzkaller.appspotmail.com
> > >
> > > 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?
>
> Hi Alan,
>
> Yeah, it's a bit confusing, sorry for that. Since syzkaller mutates
> the values that are passed into syscalls, it might mutate the cmd
> value of an ioctl. This results in a mismatch between the name of a
> syscall in syzkaller's notation, and the actual cmd value. In this
> case we have:
>
> ioctl$USBDEVFS_CONTROL(r0, 0x8108551b, ...)
>
> where 0x8108551b == 2164806939, which is the value for
> USBDEVFS_DISCONNECT_CLAIM [1], and
>
> ioctl$USBDEVFS_CLEAR_HALT(r0, 0xc0185502, ...)
>
> where 0xc0185502 == 3222820098, which is the value for USBDEVFS_BULK [2].
>
> I remember Dmitry did some changes to this part, but I think syzkaller
> only avoids getting disabled ioctls during mutations. Dmitry, maybe it
> would make sense to avoid getting other known ioctls during mutations?

Agree, it would make sense. I've started working on it but wasn't able
to finish. It also affects get/setsockopt, fcntl, prctl, bpf and
others. In this more general context it turns out to be an interesting
problem figuring out what is that exactly we don't want to mutate and
to what values.