On Sat, Aug 29, 2020 at 3:24 AM Alan Stern [off-list ref] wrote:

On Fri, Aug 28, 2020 at 05:52:16AM -0700, syzbot wrote:

quoted

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?

Thanks!

[1] https://github.com/google/syzkaller/blob/master/sys/linux/dev_bus_usb.txt.const#L13
[2] https://github.com/google/syzkaller/blob/master/sys/linux/dev_bus_usb.txt.const#L4