usb: dwc3: gadget: lower informal user notifaction dequeue operation

Printing an error message during usb_ep_dequeue() is more confusing than
helpful since the usb_ep_dequeue() could be call during unbind() just
in case that everything is canceld before unbinding the driver. Lower
the dev_err() message to dev_dbg() to keep the message for developers.

Fixes: fcd2def66392 ("usb: dwc3: gadget: Refactor dwc3_gadget_ep_dequeue")
Signed-off-by: Marco Felsch <m.felsch@pengutronix.de>
---
 drivers/usb/dwc3/gadget.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

Hi,

On Thu, Mar 23, 2023, Marco Felsch wrote:
> Printing an error message during usb_ep_dequeue() is more confusing than
> helpful since the usb_ep_dequeue() could be call during unbind() just
> in case that everything is canceld before unbinding the driver. Lower
> the dev_err() message to dev_dbg() to keep the message for developers.
> 
> Fixes: fcd2def66392 ("usb: dwc3: gadget: Refactor dwc3_gadget_ep_dequeue")
> Signed-off-by: Marco Felsch <m.felsch@pengutronix.de>
> ---
>  drivers/usb/dwc3/gadget.c | 2 +-
>  1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/drivers/usb/dwc3/gadget.c b/drivers/usb/dwc3/gadget.c
> index 89dcfac01235f..6699db26cc7b5 100644
> --- a/drivers/usb/dwc3/gadget.c
> +++ b/drivers/usb/dwc3/gadget.c
> @@ -2106,7 +2106,7 @@ static int dwc3_gadget_ep_dequeue(struct usb_ep *ep,
>  		}
>  	}
>  
> -	dev_err(dwc->dev, "request %pK was not queued to %s\n",
> +	dev_dbg(dwc->dev, "request %pK was not queued to %s\n",
>  		request, ep->name);
>  	ret = -EINVAL;
>  out:
> -- 
> 2.30.2
> 

How were you able to reproduce this error message?

During unbind(), the function driver would typically call to
usb_ep_disable(). Before the call usb_ep_disable() completes, all queued
and incompleted requests are expected to be returned with -ESHUTDOWN.
For you to see this error, this means that the function driver issued
usb_ep_dequeue() to an already disabled endpoint, and the request was
probably already given back.

Even though this error message is not critical and shouldn't affect the
driver's behavior, it's better to fix the function driver to handle this
race.

Thanks,
Thinh

On Fri, Mar 24, 2023, Marco Felsch wrote:
> Hi,
> 
> On 23-03-23, Thinh Nguyen wrote:
> > Hi,
> > 
> > On Thu, Mar 23, 2023, Marco Felsch wrote:
> > > Printing an error message during usb_ep_dequeue() is more confusing than
> > > helpful since the usb_ep_dequeue() could be call during unbind() just
> > > in case that everything is canceld before unbinding the driver. Lower
> > > the dev_err() message to dev_dbg() to keep the message for developers.
> > > 
> > > Fixes: fcd2def66392 ("usb: dwc3: gadget: Refactor dwc3_gadget_ep_dequeue")
> > > Signed-off-by: Marco Felsch <m.felsch@pengutronix.de>
> > > ---
> > >  drivers/usb/dwc3/gadget.c | 2 +-
> > >  1 file changed, 1 insertion(+), 1 deletion(-)
> > > 
> > > diff --git a/drivers/usb/dwc3/gadget.c b/drivers/usb/dwc3/gadget.c
> > > index 89dcfac01235f..6699db26cc7b5 100644
> > > --- a/drivers/usb/dwc3/gadget.c
> > > +++ b/drivers/usb/dwc3/gadget.c
> > > @@ -2106,7 +2106,7 @@ static int dwc3_gadget_ep_dequeue(struct usb_ep *ep,
> > >  		}
> > >  	}
> > >  
> > > -	dev_err(dwc->dev, "request %pK was not queued to %s\n",
> > > +	dev_dbg(dwc->dev, "request %pK was not queued to %s\n",
> > >  		request, ep->name);
> > >  	ret = -EINVAL;
> > >  out:
> > > -- 
> > > 2.30.2
> > > 
> > 
> > How were you able to reproduce this error message?
> 
> We use the driver within barebox where we do have support for fastboot.
> During the driver unbind usb_ep_dequeue() is called which throw this
> error.

I mean which gadget/function driver did you use.

> 
> > During unbind(), the function driver would typically call to
> > usb_ep_disable(). Before the call usb_ep_disable() completes, all queued
> > and incompleted requests are expected to be returned with -ESHUTDOWN.
> 
> So the unbind() function driver should use usb_ep_disable() instead of
> usb_ep_dequeue()?

No, it can do whatever it wants. I'm just pointing out the typical
behavior when this case happens during unbind().

> 
> > For you to see this error, this means that the function driver issued
> > usb_ep_dequeue() to an already disabled endpoint, and the request was
> > probably already given back.
> 
> The unbind() just calls usb_ep_dequeue() which isn't forbidden according
> the API doc. We just want to ensure that the request is cancled if any.

It's not forbidden, and it's not unexpected for this message to be
generated if usb_ep_dequeue() is called after usb_ep_disable(). However,
knowing the behavior of usb_ep_disable(), does it make sense to call
usb_ep_dequeue() after usb_ep_disable() completes? (I'm assuming this is
what happened in your case from the commit description).

> 
> > Even though this error message is not critical and shouldn't affect the
> > driver's behavior, it's better to fix the function driver to handle this
> > race.
> 
> As you have pointed out: 'it is not criticial' and therefore we shouldn't
> use dev_err() for non crictical information since this can cause
> user-space confusion.

I noted this particular case that it's not critical because we know
where/when it happened because you pointed out that it occurs during
unbind(). However, in any case, we want to notify that the
usb_ep_dequeue() was used on a wrong request, allowing the user to
review and fix this if needed.

Thanks,
Thinh