[BUG REPORT] usb: dwc3: "failed to enable ep0out" when enabling mass storage mode

[BUG REPORT] usb: dwc3: "failed to enable ep0out" when enabling mass storage mode

[evan]

[-- Attachment #1: Type: text/plain, Size: 2121 bytes --]

Hi Felipe,

I'm picking up a bug my coworker Rob touched on in this thread:
https://marc.info/?l=linux-usb&m=155349928622570&w=2

We occasionally see the following dmesg when enabling mass storage mode:

	dwc3 dwc3.1.auto: failed to enable ep0out

To reproduce after a clean boot:

	Enable mass storage mode
	Disable mass storage mode
	Enable mass storage mode

I don't need to plug any devices, just switch modes.

The error does not happen every boot.  If I don't get the error on that
second enable, then as far as I can tell I won't get the error at all
during that boot.

I've attached the trace and regdump.  When capturing these I was running
a 4.9.115 kernel and using the g_mass_storage driver for simplicity.
Here is the shell session:

	root@gnarbox-2:~# echo device > /sys/class/usb_role/intel_xhci_usb_sw-role-switch/role && modprobe g_mass_storage file=/dev/nvme0n1p7 iSerialNumber=90405
	[  118.627628] Mass Storage Function, version: 2009/09/11
	[  118.633426] LUN: removable file: (no medium)
	[  118.638283] LUN: file: /dev/nvme0n1p7
	[  118.642397] Number of LUNs=1
	[  118.646080] g_mass_storage gadget: Mass Storage Gadget, version: 2009/09/11
	[  118.653902] g_mass_storage gadget: g_mass_storage ready
	root@gnarbox-2:~# modprobe -r g_mass_storage && echo host > /sys/class/usb_role/intel_xhci_usb_sw-role-switch/role 
	root@gnarbox-2:~# echo device > /sys/class/usb_role/intel_xhci_usb_sw-role-switch/role && modprobe g_mass_storage file=/dev/nvme0n1p7 iSerialNumber=90405
	[  123.416789] Mass Storage Function, version: 2009/09/11
	[  123.422546] LUN: removable file: (no medium)
	[  123.427386] LUN: file: /dev/nvme0n1p7
	[  123.431531] Number of LUNs=1
	[  123.435278] g_mass_storage gadget: Mass Storage Gadget, version: 2009/09/11
	[  123.443168] g_mass_storage gadget: g_mass_storage ready
	[  123.451998] dwc3 dwc3.1.auto: failed to enable ep0out
	root@gnarbox-2:~# 

I still get the error when using the gadget configfs instead of
g_mass_storage.  I still get the error on kernel 5.0.5.

Do you have any idea what's happening here?  What steps can I take to
help debug this?

Thanks,
Evan

[-- Attachment #2: dwc3-trace-20190513.txz --]
[-- Type: application/x-xz, Size: 5372 bytes --]

Re: [BUG REPORT] usb: dwc3: "failed to enable ep0out" when enabling mass storage mode

[Felipe Balbi]

Hi,

evan@gnarbox.com writes:

> Hi Felipe,
>
> I'm picking up a bug my coworker Rob touched on in this thread:
> https://marc.info/?l=linux-usb&m=155349928622570&w=2
>
> We occasionally see the following dmesg when enabling mass storage mode:
>
> 	dwc3 dwc3.1.auto: failed to enable ep0out
>
> To reproduce after a clean boot:
>
> 	Enable mass storage mode
> 	Disable mass storage mode
> 	Enable mass storage mode
>
> I don't need to plug any devices, just switch modes.
>
> The error does not happen every boot.  If I don't get the error on that
> second enable, then as far as I can tell I won't get the error at all
> during that boot.
>
> I've attached the trace and regdump.  When capturing these I was running
> a 4.9.115 kernel and using the g_mass_storage driver for simplicity.
> Here is the shell session:
>
> 	root@gnarbox-2:~# echo device > /sys/class/usb_role/intel_xhci_usb_sw-role-switch/role && modprobe g_mass_storage file=/dev/nvme0n1p7 iSerialNumber=90405
> 	[  118.627628] Mass Storage Function, version: 2009/09/11
> 	[  118.633426] LUN: removable file: (no medium)
> 	[  118.638283] LUN: file: /dev/nvme0n1p7
> 	[  118.642397] Number of LUNs=1
> 	[  118.646080] g_mass_storage gadget: Mass Storage Gadget, version: 2009/09/11
> 	[  118.653902] g_mass_storage gadget: g_mass_storage ready
> 	root@gnarbox-2:~# modprobe -r g_mass_storage && echo host > /sys/class/usb_role/intel_xhci_usb_sw-role-switch/role 
> 	root@gnarbox-2:~# echo device > /sys/class/usb_role/intel_xhci_usb_sw-role-switch/role && modprobe g_mass_storage file=/dev/nvme0n1p7 iSerialNumber=90405
> 	[  123.416789] Mass Storage Function, version: 2009/09/11
> 	[  123.422546] LUN: removable file: (no medium)
> 	[  123.427386] LUN: file: /dev/nvme0n1p7
> 	[  123.431531] Number of LUNs=1
> 	[  123.435278] g_mass_storage gadget: Mass Storage Gadget, version: 2009/09/11
> 	[  123.443168] g_mass_storage gadget: g_mass_storage ready
> 	[  123.451998] dwc3 dwc3.1.auto: failed to enable ep0out

When this happens, I see this:

        modprobe-1046  [001] d..1   123.450054: dwc3_gadget_ep_cmd: ep0out: cmd 'Start New Configuration' [9] params 00000000 00000000 00000000 --> status: Successful
        modprobe-1046  [001] d..1   123.451990: dwc3_gadget_ep_cmd: ep0out: cmd 'Set Endpoint Transfer Resource' [2] params 00000001 00000000 00000000 --> status: Timed Out

Why is that waiting only 1ms? Maybe your platform takes longer,
sometimes, to complete xfer resource allocation?

Try this:

diff --git a/drivers/usb/dwc3/gadget.c b/drivers/usb/dwc3/gadget.c
index d67655384eb2..ad1069fe3b8f 100644
--- a/drivers/usb/dwc3/gadget.c
+++ b/drivers/usb/dwc3/gadget.c
@@ -270,7 +270,7 @@ int dwc3_send_gadget_ep_cmd(struct dwc3_ep *dep, unsigned cmd,
 {
 	const struct usb_endpoint_descriptor *desc = dep->endpoint.desc;
 	struct dwc3		*dwc = dep->dwc;
-	u32			timeout = 1000;
+	u32			timeout = 5000;
 	u32			saved_config = 0;
 	u32			reg;
 
Let me know if it helps or not. I guess it's also time to switch this
block of code to readl_poll_timeout_atomic().

-- 
balbi

Re: Re: [BUG REPORT] usb: dwc3: "failed to enable ep0out" when enabling mass storage mode

[evan]

[-- Attachment #1: Type: text/plain, Size: 1952 bytes --]

Hi Felipe,

Thanks for your prompt reply!

Felipe Balbi <felipe.balbi@linux.intel.com> wrote:
> Why is that waiting only 1ms? Maybe your platform takes longer,
> sometimes, to complete xfer resource allocation?
> 
> Try this:

I tried the patch and still see the problem.  I even extended it to
100ms just to see, but no luck.

I think I left out some details that are probably important:

> > To reproduce after a clean boot:
> >
> > 	Enable mass storage mode
> > 	Disable mass storage mode
> > 	Enable mass storage mode
> >
> > I don't need to plug any devices, just switch modes.

The error message shows up on the second time to enable mass storage but
not the first.  If the message showed up on that second time, then it will
show up every subsequent time for this boot.  I've attached a new trace
that includes switching out of and into mass storage mode again.  On the
third time, instead of timing out at 'Set Endpoint Transfer Resource'
it times out at 'Start New Configuration'.  This trace is much larger
than the last one.

I've also included a trace for the success case, switching the same
amount of times (enable mass storage, disable, enable, disable, enable)
just in case it can be helpful.

> > I don't need to plug any devices, just switch modes.

While this is true, there is some more behavior that may be helpful
in debugging.  After enabling mass storage mode for the first time and
plugging into a host:

	If we get enumerated correctly then the 'failed to enable ep0out'
	error will not happen at all for this boot.

	If we don't get enumerated correctly (nothing shows in our dmesg,
	host doesn't recognize us) then the error will happen when we
	switch back and forth between modes next time.

I can trace these scenarios if that is helpful.  Initially I thought it
would be unnecessary as the error shows up with or without plugging into
a host.

If there is anything else I can do to help debug please let me know.

-Evan

[-- Attachment #2: dwc3-trace-20190514-success.txz --]
[-- Type: application/x-xz, Size: 6092 bytes --]

[-- Attachment #3: dwc3-trace-20190514-fail.txz --]
[-- Type: application/x-xz, Size: 128376 bytes --]