Re: [PATCH v3 2/6] usb: dwc3: gadget: cancel requests instead of release after missed isoc

[Thinh Nguyen]

Hi,

On Wed, Oct 19, 2022, Jeff Vanhoof wrote:
> Hi Thinh,
> On Wed, Oct 19, 2022 at 07:08:27PM +0000, Thinh Nguyen wrote:
> > On Wed, Oct 19, 2022, Jeff Vanhoof wrote:

<snip>

> > > 
> > > From what I can gather from the log, with the current changes it seems that
> > > after a missed isoc event few requests are staying longer than expected in the
> > > started_list (not getting reclaimed) and this is preventing the transmission
> > > from stopping/starting again, and opening the door for continuous stream of
> > > missed isoc events that cause what appears to the user as a frozen video.
> > > 
> > > So one thought, if IOC bit is not set every frame, but IMI bit is, when a
> > > missed isoc related interrupt occurs it seems likely that more than one trb
> > > request will need to be reclaimed, but the current set of changes is not
> > > handling this.
> > > 
> > > In the good transfer case this issue seems to be taken care of since the IOC
> > > bit is not set every frame and the reclaimation will loop through every item in
> > > the started_list and only stop if there are no additional trbs or if one has
> > 
> > It should stop at the request that associated with the interrupt event,
> > whether it's because of IMI or IOC.
> 
> In this case I was concerned that if multipled queued reqs did not have IOC bit
> set, but there was a missed isoc on one of the last reqs, whether or not we would
> reclaim all of the requests up to the missed isoc related req. I'm not sure if
> my concern is valid or not.
> 

There should be no problem. If there's an interrupt event indicating a
TRB completion, the driver will give back all the requests up to the
request associated with the interrupt event, and the controller will
continue processing the remaining TRBs. On the next TRB completion
event, the driver will again give back all the requests up to the
request associated with that event.

> > 
> > > its HWO bit set. Although I am a bit surprised that we are not yet seeing iommu
> > > related panics here too since the trb is being reclaimed and given back even
> > > the HWO bit still set, but maybe I am misunderstanding something. In my earlier
> > > testing, if a missed isoc event was received and we attempted to
> > > reclaim/giveback a trb with its HWO bit set, a iommu related panic would be
> > > seen.
> > 
> > If the controller processed the TRB, it would clear the HWO bit after
> > completion. There are cases which the HWO bit is still set for some
> > TRBs, but the request is completed (e.g. short transfers causing the
> > controller to stop processing further). That those cases, the driver
> > would clear the HWO bit manually.
> > 
> > > 
> > > Can you propose an additional change to handle freeing up the extra trbs in the
> > > missed isoc case? I think that somehow the HWO bit should be checked before
> > > entering dwc3_gadget_ep_cleanup_completed_request in order to avoid the trb
> > > being given back too soon.
> > 
> > We should not check for TRBs of requests beyond the request associated
> > with the interrupt event.
> > 
> > > 
> > > Your thoughts?
> > > 
> > 
> > The capture shows underrun, and it causes missed isoc.
> > 
> > Let's take a look at the first missed isoc request (req ffffff88f834db00)
> > 
> >            <...>-22551   [002] d..2 13985.789684: dwc3_ep_queue: ep2in: req ffffff88f834db00 length 0/49152 zsi ==> -115
> >            <...>-22551   [002] dn.2 13985.789728: dwc3_prepare_trb: ep2in: trb ffffffc016071970 (E152:D149) buf 00000000ea800000 size 1x 49152 ctrl 00000461 (Hlcs:Sc:isoc-first)
> > 
> > Each request uses a one TRB. From above, you can see that there are only
> > 3 intervals prepared (E152 - D149 = 3).
> > 
> > The timestamp of the last request completion is 13985.788919.
> > The timestamp which the queued request is 13985.789728.
> > We can roughly estimate the diff is at least 809us.
> > 
> > 3 intervals (3x125us) is less than 809us. So missed isoc is expected:
> > 
> >     irq/399-dwc3-15269   [002] d..1 13985.790754: dwc3_event: event (f9acc08a): ep2in: Transfer In Progress [63916] (sIM)
> >     irq/399-dwc3-15269   [002] d..1 13985.790758: dwc3_complete_trb: ep2in: trb ffffffc016071970 (E154:D152) buf 00000000ea800000 size 1x 49152 ctrl 3e6a0460 (hlcs:Sc:isoc-first)
> >     irq/399-dwc3-15269   [002] d..1 13985.790808: dwc3_gadget_giveback: ep2in: req ffffff88f834db00 length 0/49152 zsi ==> -18
> > 
> > 
> > After this point, the uvc driver keeps playing catch up to stay in sync
> > with the host. It tries, but it couldn't catch up. Also, occasionally
> > something seems to be blocking dwc3, creating time gaps. Maybe because
> > of a spin_lock held somewhere?
> >
> 
> Could the time gaps be created by the interrupt frequency changes? They
> completely change up the timing of when the transfers are kicked in dwc3 and
> when uvc_video_complete/uvcg_video_pump is called.

You can check all the "fastrpc_msg" tracepoints in the log. These steps
seem to slow down the queuing process in uvc.

> 
> > The logic to detect underrun doesn't trigger because the queued list is
> > always non-empty, but the queued requests are expected to be missed
> > already. So you keep seeing missed isoc.
> > 
> > There are a few things you can mitigate this issue:
> > 1) Don't set IMI if the request indicates no_interrupt. This reduces the
> >    time software needs to handle interrupts.
> 
> I did try this out earlier and it did not prevent the video freeze. It does
> make sense what you are suggesting, but because it didn't work for me it made
> me think that not all reqs are being reclaimed after a missed isoc is seen.
> I'll revisit this area again.

I don't expect this to improve much.

> 
> > 2) Improve the underrun detection logic.
> 
> I like this idea a lot but I'm not up to the task just yet. Will attempt to
> follow your recommendations below and see where I get with this.
> 
> > 3) Increase the queuing frequency from the uvc to keep the request queue
> >    full. Note that reduce/avoid setting no_interrupt will allow the
> >    controller driver to update uvc often to keep requeuing new requests.
> > 
> > Best option is 3), but maybe we can do all 3.
> >
> 
> I think that this is our best option too. Dan provided a patch to make
> the interrupt skip logic configurable in the uvc driver:
> https://urldefense.com/v3/__https://patchwork.kernel.org/project/linux-usb/patch/20221018215044.765044-6-w36195@xxxxxxxxxxxx/__;!!A4F2R9G_pg!eBu4j9m9C_XJHcuTXmYqo4CAe8bcQ0ZC3UWT3NJUZYYG6S-VJpriVwd2Q5NmAOFnN2PLgTauFDZ-fBM35ftO$  
> https://urldefense.com/v3/__https://lore.kernel.org/linux-usb/20221018215044.765044-6-w36195@xxxxxxxxxxxx/__;!!A4F2R9G_pg!eBu4j9m9C_XJHcuTXmYqo4CAe8bcQ0ZC3UWT3NJUZYYG6S-VJpriVwd2Q5NmAOFnN2PLgTauFDZ-fCLOxuhL$  
> 
> > For 2), you can set IMI for all isoc request as it is now. On missed
> > isoc, check for the TRB's scheduled uframe (from TRB info) and compare
> > it to the current uframe (from DSTS) for the number of intervals in
> > between. With the number of queued requests, you can calculate whether
> > the gadget driver queued enough requests. If it doesn't, send End
> > Transfer command and cancel all the queued requests. The next set of
> > requests will be in-sync again.
> > 
> > BR,
> > Thinh
> > 
> > PS. On a side note, I notice that there are reports of issue when using
> > SG right? Please note that dwc3 driver only allocates 256 TRBs
> > (including a link TRB). Each SG entry takes a TRB. If a request has many
> > SG entries, that eats up the available TRBs. So, even though the UVC may
> > queue many requests, not all of them are prepared immediately. If the
> > TRB ring is full, the driver need to wait for more TRBs to free up
> > before preparing more. From the log, I see that it's sending 48KB. Let's
> > say the uvc splits it into PAGE_SIZE of 4KB, that would take at least 12
> > TRB per request. (Side thought: I'm not sure why UVC needs SG in the
> > first place with its current implementation)
> 
> On our platform I am seeing 2 items in the sg list being sent out from the uvc
> driver. The 1st item in the list is a 2 byte uvc header and the 2nd item is
> the 48KBs of data. To me this seems inefficient but sort of makes sense why it
> was done, likely to avoid a memory copy just for the 2 byte header.  But I

That doesn't make sense to me, but I'm sure there's a real reason. Just
curious, that's all. :)

> share your concern here, it's possible that other users wont be so lucky and
> will wind up having a lot of page sized items in the sg list.
> 
> We are also hoping to make the use of sg configurable with the change:
> https://urldefense.com/v3/__https://patchwork.kernel.org/project/linux-usb/patch/20221018215044.765044-7-w36195@xxxxxxxxxxxx/__;!!A4F2R9G_pg!eBu4j9m9C_XJHcuTXmYqo4CAe8bcQ0ZC3UWT3NJUZYYG6S-VJpriVwd2Q5NmAOFnN2PLgTauFDZ-fAiSl95Q$  
> https://urldefense.com/v3/__https://lore.kernel.org/linux-usb/20221018215044.765044-7-w36195@xxxxxxxxxxxx/__;!!A4F2R9G_pg!eBu4j9m9C_XJHcuTXmYqo4CAe8bcQ0ZC3UWT3NJUZYYG6S-VJpriVwd2Q5NmAOFnN2PLgTauFDZ-fDoaNx6Q$  
> 

Ok.

Thanks,
Thinh