Re: INFO: task hung in locks_remove_posix

[Andrey Konovalov <andreyknvl@google.com>]

On Thu, May 21, 2020 at 4:48 PM Jeff Layton <jlayton@kernel.org> wrote:
>
> On Thu, 2020-05-21 at 23:09 +0900, Tetsuo Handa wrote:
> > On 2020/05/21 5:53, syzbot wrote:
> > > Hello,
> > >
> > > syzbot found the following crash on:
> > >
> > > HEAD commit:    806d8acc USB: dummy-hcd: use configurable endpoint naming ..
> > > git tree:       https://github.com/google/kasan.git usb-fuzzer
> > > console output: https://syzkaller.appspot.com/x/log.txt?x=16c9ece2100000
> > > kernel config:  https://syzkaller.appspot.com/x/.config?x=d800e9bad158025f
> > > dashboard link: https://syzkaller.appspot.com/bug?extid=f5bc30abd8916982419c
> > > compiler:       gcc (GCC) 9.0.0 20181231 (experimental)
> > >
> > > Unfortunately, I don't have any reproducer for this crash yet.
> >
> > This seems to be a mislabeling due to '?' in all lines in a trace.
> >
> > #syz dup: INFO: task hung in wdm_flush
>
>
> I'm not sure I trust those stack traces. The console output shows '?'
> characters in front of every frame. Doesn't that mean that that address
> it found on the stack is unreliable?
>
> In principle, unless you're overriding the filp->lock operation (and the
> wdm fs doesn't do that, afaict), locks_remove_posix should not block.
> I'll also note that there is some of this in the logs before the hung
> task warnings:
>
> [  182.020388][   T12] usb 5-1: too many endpoints for config 0 interface 107 altsetting 116: 116, using maximum allowed: 30
> [  182.031661][   T12] usb 5-1: config 0 interface 107 altsetting 116 has 0 endpoint descriptors, different from the interface descriptor's value: 116
> [  182.045145][   T12] usb 5-1: config 0 interface 107 has no altsetting 0
> [  182.052028][   T12] usb 5-1: New USB device found, idVendor=0926, idProduct=3333, bcdDevice= 0.40
> [  182.060120][ T3525] usb 6-1: USB disconnect, device number 20
> [  182.061148][    C0] xpad 6-1:0.65: xpad_irq_out - usb_submit_urb failed with result -19
> [  182.075465][ T3525] xpad 6-1:0.65: xpad_try_sending_next_out_packet - usb_submit_urb failed with result -19
> [  182.075565][   T12] usb 5-1: New USB device strings: Mfr=0, Product=0, SerialNumber=0
> [  182.109020][   T12] usb 5-1: config 0 descriptor??
> [  182.136857][  T163] usb usb2-port1: attempt power cycle
> [  182.410396][ T4447] udc-core: couldn't find an available UDC or it's busy
> [  182.417562][ T4447] misc raw-gadget: fail, usb_gadget_probe_driver returned -16
> [  182.856513][  T163] usb 2-1: new high-speed USB device number 18 using dummy_hcd
> [  183.026601][  T163] usb 2-1: device descriptor read/8, error -61
> [  183.236577][  T163] usb 2-1: device descriptor read/8, error -71
> [  184.068991][ T3525] usb 5-1: USB disconnect, device number 21
> [  206.185571][   T23] INFO: task syz-executor.2:3145 blocked for more than 143 seconds.
> [  206.193630][   T23]       Not tainted 5.7.0-rc5-syzkaller #0
> [  206.199512][   T23] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> [  206.208242][   T23] syz-executor.2  D28552  3145    370 0x80004006
>
> ...which leads me to believe that this might have more to do with the
> USB subsystem than anything in the posix locking code.
>
> In any case, I doubt there's much we can do here without a more reliable
> stack trace to work from. That call stack doesn't seem to make much
> sense.

Most likely this is a duplicate of:

https://syzkaller.appspot.com/bug?id=e7b761593b23eb50855b9ea31e3be5472b711186

(with more than 30000 crashes now :)

#syz dup: INFO: task hung in wdm_flush