dwc2 gadget rejecting new AIO transfer when bus is suspended

Hello,

I am writing a functionfs-based gadget, using the raspberry pi zero. Depending on the time my userland process takes between the moment the UDC is bound to the gadget and the moment it submits AIO transfers, it either works as expected or results in immediate transfer completion with status -11 (-EAGAIN).

Enabling dynamic debug, I see the
dev_dbg(hs->dev, "%s: submit request only in active state\n",
line being output when this issue occurs (see log extract at the end of this email - note the 4 seconds gap between GINTSTS_ErlySusp - whatever that means - and io happening and being rejected).

While I am sure there are hardware-dependent reasons to reject these transfers, and while I can shift processing around to reduce this delay and (apparently) reliably avoid this error, I think it is making using this UDC rather hard: if my understanding is correct, this is a race between userland and the bus. If the HCI suspends the bus first, I cannot even submit buffers to be ready to receive some future OUT transfer, but if the userland submits these buffers before suspension then they are accepted - even if they get filled hours later. In my case, the IN transfer is on an interrupt endpoint, so I also think it would make more sense for the UDC to accept it: then, data is ready for whenever the host wakes the bus and polls for interrupt transfers.

Being a very occasional kernel contributor, have no immediate idea on how both sides could be conciliated, so this is more a "I noticed that it could be more convenient if..." than a proper bug report.

Checking the dwc3 I do not identify such EAGAIN in its io submission code, and I did not (yet ?) trigger such error on my Intel Edison.

Dec 24 12:29:19 sushi kernel: [218828.497937] dwc2 20980000.usb: ep0 state:1
Dec 24 12:29:19 sushi kernel: [218828.497948] dwc2 20980000.usb: dwc2_hsotg_start_req: DxEPCTL=0x84028000
Dec 24 12:29:19 sushi kernel: [218828.497959] dwc2 20980000.usb: dwc2_hsotg_start_req: DXEPCTL=0x80008000
Dec 24 12:29:19 sushi kernel: [218828.497984] dwc2 20980000.usb: dwc2_hsotg_irq: 04048028 00040000 (d0bc3cc4) retry 8
Dec 24 12:29:19 sushi kernel: [218828.497996] dwc2 20980000.usb: dwc2_hsotg_irq: daint=00000001
Dec 24 12:29:19 sushi kernel: [218828.498008] dwc2 20980000.usb: dwc2_hsotg_epint: ep0(in) DxEPINT=0x00000001
Dec 24 12:29:19 sushi kernel: [218828.498022] dwc2 20980000.usb: dwc2_hsotg_epint: XferCompl: DxEPCTL=0x00008000, DXEPTSIZ=00000000
Dec 24 12:29:19 sushi kernel: [218828.498034] dwc2 20980000.usb: dwc2_hsotg_complete_in: adjusting size done 0 => 36
Dec 24 12:29:19 sushi kernel: [218828.498046] dwc2 20980000.usb: req->length:36 req->actual:36 req->zero:1
Dec 24 12:29:19 sushi kernel: [218828.498056] dwc2 20980000.usb: Receiving zero-length packet on ep0
Dec 24 12:29:19 sushi kernel: [218828.498078] dwc2 20980000.usb: dwc2_hsotg_irq: 04088028 00080000 (d0bc3cc4) retry 8
Dec 24 12:29:19 sushi kernel: [218828.498089] dwc2 20980000.usb: dwc2_hsotg_irq: daint=00010000
Dec 24 12:29:19 sushi kernel: [218828.498101] dwc2 20980000.usb: dwc2_hsotg_epint: ep0(out) DxEPINT=0x00000001
Dec 24 12:29:19 sushi kernel: [218828.498113] dwc2 20980000.usb: dwc2_hsotg_epint: XferCompl: DxEPCTL=0x00028000, DXEPTSIZ=20000000
Dec 24 12:29:19 sushi kernel: [218828.498122] dwc2 20980000.usb: zlp packet received
Dec 24 12:29:19 sushi kernel: [218828.498138] dwc2 20980000.usb: complete: ep 42dd5aad ep0, req 29f392ab, 0 => 5c316413
Dec 24 12:29:19 sushi kernel: [218828.498152] dwc2 20980000.usb: dwc2_hsotg_enqueue_setup: queueing setup request
Dec 24 12:29:19 sushi kernel: [218828.498169] dwc2 20980000.usb: ep0: req 8e14c7b2: 8@d91bfc39, noi=0, zero=0, snok=0
Dec 24 12:29:19 sushi kernel: [218828.498186] dwc2 20980000.usb: dwc2_hsotg_start_req: DxEPCTL=0x00028000, ep 0, dir out
Dec 24 12:29:19 sushi kernel: [218828.498198] dwc2 20980000.usb: ureq->length:8 ureq->actual:0
Dec 24 12:29:19 sushi kernel: [218828.498212] dwc2 20980000.usb: dwc2_hsotg_start_req: 1@8/8, 0x00080008 => 0x00000b10
Dec 24 12:29:19 sushi kernel: [218828.498225] dwc2 20980000.usb: dwc2_hsotg_start_req: 0x54ab8a20 => 0x00000b14
Dec 24 12:29:19 sushi kernel: [218828.498235] dwc2 20980000.usb: ep0 state:0
Dec 24 12:29:19 sushi kernel: [218828.498245] dwc2 20980000.usb: dwc2_hsotg_start_req: DxEPCTL=0x80028000
Dec 24 12:29:19 sushi kernel: [218828.498256] dwc2 20980000.usb: dwc2_hsotg_start_req: DXEPCTL=0x80028000
Dec 24 12:29:22 sushi kernel: [218830.967016] dwc2 20980000.usb: dwc2_hsotg_irq: 04008428 00000400 (d0bc3cc4) retry 8
Dec 24 12:29:22 sushi kernel: [218830.967035] dwc2 20980000.usb: GINTSTS_ErlySusp
Dec 24 12:29:22 sushi kernel: [218830.970039] dwc2 20980000.usb: dwc2_hsotg_irq: 04008028 00000000 (d0bc3cc4) retry 8
Dec 24 12:29:25 sushi kernel: [218834.485152] dwc2 20980000.usb: ep1out: req 91851ac5: 10240@e55aa59c, noi=0, zero=0, snok=0
Dec 24 12:29:25 sushi kernel: [218834.485172] dwc2 20980000.usb: dwc2_hsotg_ep_queue: submit request only in active state
Dec 24 12:29:25 sushi kernel: [218834.485261] dwc2 20980000.usb: ep1out: req 91851ac5: 10240@e55aa59c, noi=0, zero=0, snok=0
Dec 24 12:29:25 sushi kernel: [218834.485273] dwc2 20980000.usb: dwc2_hsotg_ep_queue: submit request only in active state
Dec 24 12:29:25 sushi kernel: [218834.515516] dwc2 20980000.usb: ep2in: req 91851ac5: 2@8925e53a, noi=0, zero=0, snok=0
Dec 24 12:29:25 sushi kernel: [218834.515536] dwc2 20980000.usb: dwc2_hsotg_ep_queue: submit request only in active state
Dec 24 12:29:31 sushi kernel: [218840.337809] dwc2 20980000.usb: dwc2_hsotg_pullup: is_on: 0 op_state: 3
Dec 24 12:29:31 sushi kernel: [218840.337844] dwc2 20980000.usb: complete: ep 42dd5aad ep0, req 8e14c7b2, -108 => 97e9bd28
Dec 24 12:29:31 sushi kernel: [218840.337865] dwc2 20980000.usb: dwc2_hsotg_complete_setup: failed -108

Regards,

Vincent Pelletier

Hi Vincent,

According your debug log core enters suspend on receiving an GINTSTS_ErlySusp interrupt. It means that the driver goes to L2 state (suspend). In suspend mode accepting and processing EP requests can lead to unexpected behavior. That is why the driver rejects EP request with -EAGAIN.

As core may use power saving modes which are initiated by the Suspend interrupt, then in any suspend mode whether it is hibernation or partial power down the core registers are not available. This is why we avoid to get new EP requests.

The main question is why on usb bus seen ErlySusp interrupt. Is it initiated by host? If yes, why?

Regards,
Artur

Hello Artur,

This is my understanding from reading the commit history, yes.

But from userland's point of view this causes a weird situation:
- sequence 1:
- userland submits buffer (ex: to receive the next host request)
- UDC is suspended
- UDC is awoken by host initiating a transfer
Result: the AIO completes successfully, the suspension was completely invisible to userland, and I'm happy.
- sequence 2:
- UDC is suspended
- userland submits buffer (ex: to receive the next host request)
Result: the AIO completes with an error, the suspension got in the way, and I'm confused about what I need to make my code do to
recover: should I change my IO completion codepath so that it resubmits any EAGAIN completion, hoping to catch the UDC at a time it is awoken so the AIO finally sticks and everything can sleep until an actual transfer completion ?

I do not know if it makes sense from a kernel point of view, but would it be possible for the dwc2 module to sit on the AIO requests while the controller is suspended, and submit them when it wakes up rather than failing them immediately and sending them back to userland ? I expect that this code actually knows (without polling) when the controller is awoken.

My pre-USB-analyser guess is it would just be the normal USB-idle-to- bus-suspend behaviour. Besides device enumeration, the host is not accessing the device right after it is plugged in, so there should be no reason to keep the bus ticking.

Unless there is something fundamentally wrong with the suspension happening at all, my biggest issue is the poor userland-level usability *if* suspension happens, and the race-condition this behaviour creates (IO cannot be submitted before the UDC is bound to the gadget, and IO cannot be submitted after either if it happens after an external event, leaving only a short time window where it works).

If I am missing anything there which would allow userland to guarantee keeping the UDC awoken so the transfers would stay in-queue, please do tell me.

Regards,

Vincent Pelletier

This seems like a design mistake. Even though the controller may be in a low-power state, there's no reason the UDC driver can't accept new requests or unlink old ones. It even ought to be willing to halt endpoints.

None of these actions require the driver to touch the hardware. The hardware-specific parts of the actions can be carried out when the controller returns to full power.

Indeed, the same problem will occur with synchronous (non-AIO) submissions.

The kernel shouldn't have to sit on anything. The requests should be accepted immediately.

Alan Stern

Hello Alan,

I must have used this sentence incorrectly: I meant what you described, the kernel accepting the transfer and the module submitting it to hardware whenever able.

Also, strictly speaking (and to avoid confusion if I failed further at English expression in my previous emails) aio_submit itself does succeed, so in a sense the kernel already accepts the transfer. The issue is that the transfer completion happens immediately after, with this EAGAIN status.

Regards,

Vincent Pelletier

Hi Vincent,

Refactoring the driver to always accept any EP request independent of the state (suspend), requires lot of investigation. We will decide and implement later.

For your case we suggest the following workaround in "dwc2_hsotg_ep_queue()" function to additionally check "hsotg->power_down":

/* Prevent new request submission when controller is suspended */

if (hs->lx_state != DWC2_L0 && hsotg->power_down) {
	dev_dbg(hs->dev, "%s: submit request only in active state\n",
		__func__);
	return -EAGAIN;
}

Please test and let us know the results.

Hello Artur,

I did test your change (with a trivial adaptation, see below) on 5.11.0-rc1 and I can confirm the AIO submission is accepted in my use-case, despite a 4-seconds sleep between UDC being bound and AIO submission to try to trigger the issue (which it does on an unpatched 5.10).

The gadget goes on to correctly respond to the host, so this looks good to me.

index 0a0d11151cfb8..dc676f3b1d799 100644
@@ -1387,7 +1387,7 @@ static int dwc2_hsotg_ep_queue(struct usb_ep *ep, struct usb_request *req,
 		req->zero, req->short_not_ok);
 
 	/* Prevent new request submission when controller is suspended */
-	if (hs->lx_state != DWC2_L0) {
+	if (hs->lx_state != DWC2_L0 && hs->params.power_down) {
 		dev_dbg(hs->dev, "%s: submit request only in active state\n",
 			__func__);
 		return -EAGAIN;

Regards,

Vincent Pelletier