Hi Vincent, On 12/24/2020 16:50, Vincent Pelletier wrote: > 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). 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? > > 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, > Regards, Artur
