Re: INFO: task hung in locks_remove_posix

[Jeff Layton]

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.

-- 
Jeff Layton <jlayton@xxxxxxxxxx>