RE: Re: [syzbot] INFO: rcu detected stall in tx

RE: Re: [syzbot] INFO: rcu detected stall in tx

[Guido Kiener]

Hi all,

The error is in usbtmc_interrupt(struct urb *urb) since five years. The status code EPROTO is not handled correctly.
It's not a showstopper, but we should fix it and check the status code according to usbtmc_read_bulk_cb() or
usb_skeleton.c.
@Dave: Do you have time? Otherwise I can do it.
@Greg: Is it urgent?

- Guido

-----Original Message-----
From: Dmitry 
Sent: Monday, April 19, 2021 9:27 AM
Subject: Re: [syzbot] INFO: rcu detected stall in tx

On Mon, Apr 19, 2021 at 9:19 AM syzbot
<syzbot+e2eae5639e7203360018@syzkaller.appspotmail.com> wrote:
>
> Hello,
>
> syzbot found the following issue on:
>
> HEAD commit:    50987bec Merge tag 'trace-v5.12-rc7' of git://git.kernel.o..
> git tree:       upstream
> console output: 
> https://syzkaller.appspot.com/x/log.txt?x=1065c5fcd00000
> kernel config:  
> https://syzkaller.appspot.com/x/.config?x=398c4d0fe6f66e68
> dashboard link: 
> https://syzkaller.appspot.com/bug?extid=e2eae5639e7203360018
>
> Unfortunately, I don't have any reproducer for this issue yet.
>
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: syzbot+e2eae5639e7203360018@syzkaller.appspotmail.com
>
> usbtmc 5-1:0.0: unknown status received: -71 usbtmc 3-1:0.0: unknown 
> status received: -71 usbtmc 5-1:0.0: unknown status received: -71

The log shows an infinite stream of these before the stall, so I assume it's an infinite loop in usbtmc.
+usbtmc maintainers

[  370.171634][    C0] usbtmc 6-1:0.0: unknown status received: -71
[  370.177799][    C1] usbtmc 3-1:0.0: unknown status received: -71
[  370.183912][    C0] usbtmc 4-1:0.0: unknown status received: -71
[  370.190076][    C1] usbtmc 5-1:0.0: unknown status received: -71
[  370.196194][    C0] usbtmc 2-1:0.0: unknown status received: -71
[  370.202387][    C1] usbtmc 3-1:0.0: unknown status received: -71
[  370.208460][    C0] usbtmc 6-1:0.0: unknown status received: -71
[  370.214615][    C1] usbtmc 5-1:0.0: unknown status received: -71
[  370.220736][    C0] usbtmc 4-1:0.0: unknown status received: -71
[  370.226902][    C1] usbtmc 3-1:0.0: unknown status received: -71
[  370.233005][    C0] usbtmc 2-1:0.0: unknown status received: -71
[  370.239168][    C1] usbtmc 5-1:0.0: unknown status received: -71
[  370.245271][    C0] usbtmc 6-1:0.0: unknown status received: -71
[  370.251426][    C1] usbtmc 3-1:0.0: unknown status received: -71
[  370.257552][    C0] usbtmc 4-1:0.0: unknown status received: -71
[  370.263715][    C1] usbtmc 5-1:0.0: unknown status received: -71
[  370.269819][    C0] usbtmc 2-1:0.0: unknown status received: -71
[  370.275974][    C1] usbtmc 3-1:0.0: unknown status received: -71
[  370.282100][    C0] usbtmc 6-1:0.0: unknown status received: -71
[  370.288262][    C1] usbtmc 5-1:0.0: unknown status received: -71
[  370.294399][    C0] usbtmc 4-1:0.0: unknown status received: -71



Content provided within this e-mail including any attachments, is for the use of the intended recipients and may contain Rohde & Schwarz company restricted information. Any unauthorized use, disclosure, or distribution of this communication in whole or in part is strictly prohibited. If you are not the intended recipient, please notify the sender by reply email or by telephone and delete the communication in its entirety.

Re: Re: [syzbot] INFO: rcu detected stall in tx

[Greg Kroah-Hartman]

On Mon, Apr 19, 2021 at 08:56:19PM +0000, Guido Kiener wrote:
> Hi all,
> 
> The error is in usbtmc_interrupt(struct urb *urb) since five years. The status code EPROTO is not handled correctly.
> It's not a showstopper, but we should fix it and check the status code according to usbtmc_read_bulk_cb() or
> usb_skeleton.c.
> @Dave: Do you have time? Otherwise I can do it.
> @Greg: Is it urgent?

No idea, but patches for known problems are always good to get completed
as soon as possible :)

thanks,

greg k-h

RE: Re: [syzbot] INFO: rcu detected stall in tx

[Guido Kiener]

Hi all,

Dave and I discussed the "self-detected stall on CPU" caused by the usbtmc driver.

What happened?
The callback handler usbtmc_interrupt(struct urb *urb) for the INT pipe receives an erroneous urb with status -EPROTO (-71).
See https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/drivers/usb/class/usbtmc.c?h=v5.12#n2340
-EPROTO does not abort/shutdown the pipe and the urb is resubmitted to receive the next packet. However the callback handler usbtmc_interrupt is called again with the same erroneous status -EPROTO and this seems to result in an endless loop.
According to https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/Documentation/driver-api/usb/error-codes.rst?h=v5.12#n177
the error -EPROTO indicates a hardware problem or a bad cable.

Most usb drivers do not react in a specific way on this hardware problems and resubmit the urb. We assume these drivers will run into the same endless loop. Some other driver samples are:
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/drivers/usb/class/cdc-acm.c?h=v5.12#n379
https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/drivers/hid/usbhid/usbmouse.c?h=v5.12#n65

Possible solutions:
Hardware defects or bad cables seems to be a common problem for most usb drivers and I assume we do not want to fix this problem in all class specific drivers, but in lower level host drivers, e.g:
1. Using a counter and close the pipe after some detected errors
2. Delay the resubmission of the urb to avoid high cpu usage
3. Do nothing, since it is just a rare problem.

We've never seen this problem in our products and we do not dare to change anything.

- Guido

-----Original Message-----
From: Dmitry
Sent: Monday, April 19, 2021 9:27 AM
Subject: Re: [syzbot] INFO: rcu detected stall in tx

On Mon, Apr 19, 2021 at 9:19 AM syzbot
<syzbot+e2eae5639e7203360018@syzkaller.appspotmail.com> wrote:
>
> Hello,
>
> syzbot found the following issue on:
>
> HEAD commit:    50987bec Merge tag 'trace-v5.12-rc7' of git://git.kernel.o..
> git tree:       upstream
> console output: 
> https://syzkaller.appspot.com/x/log.txt?x=1065c5fcd00000
> kernel config:  
> https://syzkaller.appspot.com/x/.config?x=398c4d0fe6f66e68
> dashboard link: 
> https://syzkaller.appspot.com/bug?extid=e2eae5639e7203360018
>
> Unfortunately, I don't have any reproducer for this issue yet.
>
> IMPORTANT: if you fix the issue, please add the following tag to the commit:
> Reported-by: syzbot+e2eae5639e7203360018@syzkaller.appspotmail.com
>
> usbtmc 5-1:0.0: unknown status received: -71 usbtmc 3-1:0.0: unknown 
> status received: -71 usbtmc 5-1:0.0: unknown status received: -71

The log shows an infinite stream of these before the stall, so I assume it's an infinite loop in usbtmc.
+usbtmc maintainers

[  370.171634][    C0] usbtmc 6-1:0.0: unknown status received: -71
[  370.177799][    C1] usbtmc 3-1:0.0: unknown status received: -71
[  370.183912][    C0] usbtmc 4-1:0.0: unknown status received: -71
[  370.190076][    C1] usbtmc 5-1:0.0: unknown status received: -71
[  370.196194][    C0] usbtmc 2-1:0.0: unknown status received: -71
[  370.202387][    C1] usbtmc 3-1:0.0: unknown status received: -71
[  370.208460][    C0] usbtmc 6-1:0.0: unknown status received: -71
[  370.214615][    C1] usbtmc 5-1:0.0: unknown status received: -71
[  370.220736][    C0] usbtmc 4-1:0.0: unknown status received: -71
[  370.226902][    C1] usbtmc 3-1:0.0: unknown status received: -71
[  370.233005][    C0] usbtmc 2-1:0.0: unknown status received: -71
[  370.239168][    C1] usbtmc 5-1:0.0: unknown status received: -71
[  370.245271][    C0] usbtmc 6-1:0.0: unknown status received: -71
[  370.251426][    C1] usbtmc 3-1:0.0: unknown status received: -71
[  370.257552][    C0] usbtmc 4-1:0.0: unknown status received: -71
[  370.263715][    C1] usbtmc 5-1:0.0: unknown status received: -71
[  370.269819][    C0] usbtmc 2-1:0.0: unknown status received: -71
[  370.275974][    C1] usbtmc 3-1:0.0: unknown status received: -71
[  370.282100][    C0] usbtmc 6-1:0.0: unknown status received: -71
[  370.288262][    C1] usbtmc 5-1:0.0: unknown status received: -71
[  370.294399][    C0] usbtmc 4-1:0.0: unknown status received: -71

Re: Re: [syzbot] INFO: rcu detected stall in tx

[Alan Stern]

On Mon, May 03, 2021 at 09:56:05PM +0000, Guido Kiener wrote:
> Hi all,
> 
> Dave and I discussed the "self-detected stall on CPU" caused by the usbtmc driver.
> 
> What happened?
> The callback handler usbtmc_interrupt(struct urb *urb) for the INT pipe receives an erroneous urb with status -EPROTO (-71).
> See https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/drivers/usb/class/usbtmc.c?h=v5.12#n2340
> -EPROTO does not abort/shutdown the pipe and the urb is resubmitted to receive the next packet. However the callback handler usbtmc_interrupt is called again with the same erroneous status -EPROTO and this seems to result in an endless loop.
> According to https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/Documentation/driver-api/usb/error-codes.rst?h=v5.12#n177
> the error -EPROTO indicates a hardware problem or a bad cable.
> 
> Most usb drivers do not react in a specific way on this hardware problems and resubmit the urb. We assume these drivers will run into the same endless loop. Some other driver samples are:
> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/drivers/usb/class/cdc-acm.c?h=v5.12#n379
> https://git.kernel.org/pub/scm/linux/kernel/git/torvalds/linux.git/tree/drivers/hid/usbhid/usbmouse.c?h=v5.12#n65
> 
> Possible solutions:
> Hardware defects or bad cables seems to be a common problem for most usb drivers and I assume we do not want to fix this problem in all class specific drivers, but in lower level host drivers, e.g:
> 1. Using a counter and close the pipe after some detected errors
> 2. Delay the resubmission of the urb to avoid high cpu usage
> 3. Do nothing, since it is just a rare problem.
> 
> We've never seen this problem in our products and we do not dare to change anything.

Drivers are not consistent in the way they handle these errors, as you 
have seen.  A few try to take active measures, such as retrys with 
increasing timeouts.  Many drivers just ignore them, which is not a very 
good idea.

The general feeling among kernel USB developers is that a -EPROTO, 
-EILSEQ, or -ETIME error should be regarded as fatal, much the same as 
an unplug event.  The driver should avoid resubmitting URBs and just 
wait to be unbound from the device.

If you would like to audit drivers and fix them up to behave this way, 
that would be great.

(FYI, by far the most common causes of these errors are: The user has 
unplugged the USB cable, or the device's firmware has crashed.  It is 
quite rare for the cause to be intermittent, although not entirely 
unheard of -- for example, someone once reported errors resulting from 
EM or power-line interference caused by flickering fluorescent lights or 
something of that sort.  It's pretty safe to ignore this possibility.)

Alan Stern