USB autosuspend vs. URB submission

USB autosuspend vs. URB submission

[Josh Boyer]

Hi,

We've had a few reports in Fedora of users hitting the WARN_ONCE in
drivers/usb/core/urb.c that prints a warning about a usb_submit_urb
being called on an active URB.  One of them[1] is from the ums_realtek
driver and the other[2] is from the uvcvideo driver.  However, I noticed
that in both instances it seems the devices were coming back from what I
think is autosuspend.

I didn't immediately find any similar reports, and to my rather
inexperienced eyes the drivers didn't seem to be doing anything clearly
wrong.  I'm wondering if anyone has some possible ideas for debugging
and whether or not this might be a general issue?

The backtraces can be found in the bugs.  I've ommitted them here for
brevity, but if someone hates bugzilla that much I'd be happy to send
them along.

josh

[1] https://bugzilla.redhat.com/show_bug.cgi?id=889286
[2] https://bugzilla.redhat.com/show_bug.cgi?id=879462

Re: USB autosuspend vs. URB submission

[Alan Stern]

On Mon, 7 Jan 2013, Josh Boyer wrote:

> Hi,
> 
> We've had a few reports in Fedora of users hitting the WARN_ONCE in
> drivers/usb/core/urb.c that prints a warning about a usb_submit_urb
> being called on an active URB.  One of them[1] is from the ums_realtek
> driver and the other[2] is from the uvcvideo driver.  However, I noticed
> that in both instances it seems the devices were coming back from what I
> think is autosuspend.
> 
> I didn't immediately find any similar reports, and to my rather
> inexperienced eyes the drivers didn't seem to be doing anything clearly
> wrong.  I'm wondering if anyone has some possible ideas for debugging
> and whether or not this might be a general issue?

I don't see anything wrong either.

Can you ask the users to collect a usbmon trace covering the period 
when the problem occurs?

Alan Stern

Re: USB autosuspend vs. URB submission

[Josh Boyer]

On Tue, Jan 08, 2013 at 10:51:20AM -0500, Alan Stern wrote:
> On Mon, 7 Jan 2013, Josh Boyer wrote:
> 
> > Hi,
> > 
> > We've had a few reports in Fedora of users hitting the WARN_ONCE in
> > drivers/usb/core/urb.c that prints a warning about a usb_submit_urb
> > being called on an active URB.  One of them[1] is from the ums_realtek
> > driver and the other[2] is from the uvcvideo driver.  However, I noticed
> > that in both instances it seems the devices were coming back from what I
> > think is autosuspend.
> > 
> > I didn't immediately find any similar reports, and to my rather
> > inexperienced eyes the drivers didn't seem to be doing anything clearly
> > wrong.  I'm wondering if anyone has some possible ideas for debugging
> > and whether or not this might be a general issue?
> 
> I don't see anything wrong either.
> 
> Can you ask the users to collect a usbmon trace covering the period 
> when the problem occurs?

I'll certainly ask.  I'm not particularly hopeful for great results
though, as the problems seem to be rather intermittent.

Thanks for taking a look.

josh

Re: USB autosuspend vs. URB submission

[Laurent Pinchart]

Hi Josh,

On Tuesday 08 January 2013 11:03:22 Josh Boyer wrote:
> On Tue, Jan 08, 2013 at 10:51:20AM -0500, Alan Stern wrote:
> > On Mon, 7 Jan 2013, Josh Boyer wrote:
> > > Hi,
> > > 
> > > We've had a few reports in Fedora of users hitting the WARN_ONCE in
> > > drivers/usb/core/urb.c that prints a warning about a usb_submit_urb
> > > being called on an active URB.  One of them[1] is from the ums_realtek
> > > driver and the other[2] is from the uvcvideo driver.  However, I noticed
> > > that in both instances it seems the devices were coming back from what I
> > > think is autosuspend.
> > > 
> > > I didn't immediately find any similar reports, and to my rather
> > > inexperienced eyes the drivers didn't seem to be doing anything clearly
> > > wrong.  I'm wondering if anyone has some possible ideas for debugging
> > > and whether or not this might be a general issue?
> > 
> > I don't see anything wrong either.
> > 
> > Can you ask the users to collect a usbmon trace covering the period
> > when the problem occurs?
> 
> I'll certainly ask. I'm not particularly hopeful for great results though,
> as the problems seem to be rather intermittent.
> 
> Thanks for taking a look.

I've never heard of such problems with the uvcvideo driver, and I don't see 
anything wrong with the code at first sight. The driver only submits URBs when 
starting the video capture (at that point no URB should be in flight) or in 
the URB completion handler (by definition the URB has completed then).

I've had a quick look at the trace posted at 
https://bugzilla.redhat.com/show_bug.cgi?id=879462 but usbmon only shows URBs 
that are successfully submitted. I'm not sure what useful information I could 
get from the trace.

-- 
Regards,

Laurent Pinchart

Re: USB autosuspend vs. URB submission

[Ming Lei]

On Thu, Jan 10, 2013 at 7:05 AM, Laurent Pinchart
<laurent.pinchart@ideasonboard.com> wrote:
>
> I've never heard of such problems with the uvcvideo driver, and I don't see
> anything wrong with the code at first sight. The driver only submits URBs when

IMO, there is a minor fault in the error handling path of
uvc_status_start() inside uvc_v4l2_open(), and the 'users' count
should have been decreased before usb_autopm_put_interface().
In theory, the warning can be triggered when the device is
opened just between usb_autopm_put_interface() and
atomic_dec(&stream->dev->users), but I don't think it is
the cause of the report.

> starting the video capture (at that point no URB should be in flight) or in
> the URB completion handler (by definition the URB has completed then).
>
> I've had a quick look at the trace posted at
> https://bugzilla.redhat.com/show_bug.cgi?id=879462 but usbmon only shows URBs
> that are successfully submitted. I'm not sure what useful information I could
> get from the trace.

It might be useful to post the relevant 'dmesg' and the usbmon together.

Thanks,
-- 
Ming Lei

Re: USB autosuspend vs. URB submission

[Oliver Neukum]

On Thursday 10 January 2013 00:05:55 Laurent Pinchart wrote:

> I've had a quick look at the trace posted at 
> https://bugzilla.redhat.com/show_bug.cgi?id=879462 but usbmon only shows URBs 
> that are successfully submitted. I'm not sure what useful information I could 
> get from the trace.

The test is at the very start of usb_submit_urb()

        if (!urb || !urb->complete)
                return -EINVAL;
        if (urb->hcpriv) { 
                WARN_ONCE(1, "URB %p submitted while active\n", urb);
                return -EBUSY;
        }

usbmon will never see such URBs

I suggest that for debugging you change the WARN_ONCE into a WARN and compare
the URB pointers of usbmon and dmesg.

In the long run it is probably a good idea to pass duplicated URBs to usbmon by
a special code path.

	Regards
		Oliver

Re: USB autosuspend vs. URB submission

[Oliver Neukum]

On Thursday 10 January 2013 13:13:58 Ming Lei wrote:
> IMO, there is a minor fault in the error handling path of
> uvc_status_start() inside uvc_v4l2_open(), and the 'users' count
> should have been decreased before usb_autopm_put_interface().
> In theory, the warning can be triggered when the device is
> opened just between usb_autopm_put_interface() and
> atomic_dec(&stream->dev->users), but I don't think it is
> the cause of the report.

Hi,

the analysis is sound. Good catch. As the fix is trivial, I am making
a quick patch.

	Regards
		Oliver

Re: USB autosuspend vs. URB submission

[Alan Stern]

On Thu, 10 Jan 2013, Laurent Pinchart wrote:

> Hi Josh,
> 
> On Tuesday 08 January 2013 11:03:22 Josh Boyer wrote:
> > On Tue, Jan 08, 2013 at 10:51:20AM -0500, Alan Stern wrote:
> > > On Mon, 7 Jan 2013, Josh Boyer wrote:
> > > > Hi,
> > > > 
> > > > We've had a few reports in Fedora of users hitting the WARN_ONCE in
> > > > drivers/usb/core/urb.c that prints a warning about a usb_submit_urb
> > > > being called on an active URB.  One of them[1] is from the ums_realtek
> > > > driver and the other[2] is from the uvcvideo driver.  However, I noticed
> > > > that in both instances it seems the devices were coming back from what I
> > > > think is autosuspend.
> > > > 
> > > > I didn't immediately find any similar reports, and to my rather
> > > > inexperienced eyes the drivers didn't seem to be doing anything clearly
> > > > wrong.  I'm wondering if anyone has some possible ideas for debugging
> > > > and whether or not this might be a general issue?
> > > 
> > > I don't see anything wrong either.
> > > 
> > > Can you ask the users to collect a usbmon trace covering the period
> > > when the problem occurs?
> > 
> > I'll certainly ask. I'm not particularly hopeful for great results though,
> > as the problems seem to be rather intermittent.
> > 
> > Thanks for taking a look.
> 
> I've never heard of such problems with the uvcvideo driver, and I don't see 

Such problems could have existed silently.  The new kernel calls 
WARN_ONCE but otherwise treats the error the same as the old kernels.

> anything wrong with the code at first sight. The driver only submits URBs when 
> starting the video capture (at that point no URB should be in flight) or in 
> the URB completion handler (by definition the URB has completed then).
> 
> I've had a quick look at the trace posted at 
> https://bugzilla.redhat.com/show_bug.cgi?id=879462 but usbmon only shows URBs 
> that are successfully submitted. I'm not sure what useful information I could 
> get from the trace.

As Ming Lei pointed out, we would have to combine the dmesg information 
with the usbmon trace.  The WARN_ONCE and usbmon both provide the URB's 
address, so we could tell if that URB really was still pending when the 
WARN_ONCE was triggered.  We also might be able to tell (by looking at 
the URB's contents) what piece of code had submitted it the first time.

Alan Stern

Re: USB autosuspend vs. URB submission

[Alan Stern]

On Thu, 10 Jan 2013, Oliver Neukum wrote:

> On Thursday 10 January 2013 00:05:55 Laurent Pinchart wrote:
> 
> > I've had a quick look at the trace posted at 
> > https://bugzilla.redhat.com/show_bug.cgi?id=879462 but usbmon only shows URBs 
> > that are successfully submitted. I'm not sure what useful information I could 
> > get from the trace.
> 
> The test is at the very start of usb_submit_urb()
> 
>         if (!urb || !urb->complete)
>                 return -EINVAL;
>         if (urb->hcpriv) { 
>                 WARN_ONCE(1, "URB %p submitted while active\n", urb);
>                 return -EBUSY;
>         }
> 
> usbmon will never see such URBs

Not quite -- it will see them the first time they are submitted, when
the submission succeeds.

> I suggest that for debugging you change the WARN_ONCE into a WARN and compare
> the URB pointers of usbmon and dmesg.

Good idea.

> In the long run it is probably a good idea to pass duplicated URBs to usbmon by
> a special code path.

I'd prefer to add extra information to the WARN_ONCE message.  Even 
though it would require the extra effort of correlating the dmesg 
output with the usbmon output.

You know, it's possible that the URB really was not submitted before 
but instead the urb->hcpriv field got overwritten.  Of course, that 
would also be a bug.

Alan Stern

Re: USB autosuspend vs. URB submission

[Oliver Neukum]

On Thursday 10 January 2013 10:20:42 Alan Stern wrote:
> On Thu, 10 Jan 2013, Oliver Neukum wrote:

> > In the long run it is probably a good idea to pass duplicated URBs to usbmon by
> > a special code path.
> 
> I'd prefer to add extra information to the WARN_ONCE message.  Even 
> though it would require the extra effort of correlating the dmesg 
> output with the usbmon output.

A stack_trace() I presume.
But what is the use of needing two logs?

> You know, it's possible that the URB really was not submitted before 
> but instead the urb->hcpriv field got overwritten.  Of course, that 
> would also be a bug.

We could log a corrupted URB generically speaking.

	Regards
		Oliver