Hi Minas,
On Mon, 12 Nov 2018 08:53:36 +0000
Minas Harutyunyan <minas.harutyunyan@xxxxxxxxxxxx> wrote:
> On 11/9/2018 10:43 PM, John Keeping wrote:
> > On Fri, 9 Nov 2018 14:36:36 +0000
> > Minas Harutyunyan <minas.harutyunyan@xxxxxxxxxxxx> wrote:
> >
> >> On 11/9/2018 12:43 PM, Minas Harutyunyan wrote:
> >>> Hi John,
> >>>
> >>> On 11/8/2018 9:37 PM, John Keeping wrote:
> >>>> Hi Minas,
> >>>>
> >>>> On Mon, 5 Nov 2018 08:28:07 +0000
> >>>> Minas Harutyunyan <minas.harutyunyan@xxxxxxxxxxxx> wrote:
> >>>>
> >>>>> On 10/23/2018 5:43 PM, John Keeping wrote:
> >>>>>> By clearing the overrun flag as soon as the target frame is
> >>>>>> next incremented, we can end up incrementing the target frame
> >>>>>> more than expected in dwc2_gadget_handle_ep_disabled() when the
> >>>>>> endpoint's interval is greater than 1. This happens if the
> >>>>>> target frame has just wrapped at the point when the endpoint is
> >>>>>> disabled and the frame number has not yet done so.
> >>>>>>
> >>>>>> Instead, wait until the frame number also wraps and then clear
> >>>>>> the overrun flag.
> >>>>>>
> >>>>>> Signed-off-by: John Keeping <john@xxxxxxxxxxxx>
> >>>>>> ---
> >>>>>> drivers/usb/dwc2/gadget.c | 2 +-
> >>>>>> 1 file changed, 1 insertion(+), 1 deletion(-)
> >>>>>>
> >>>>>> diff --git a/drivers/usb/dwc2/gadget.c
> >>>>>> b/drivers/usb/dwc2/gadget.c index 2d6d2c8244de..8da2c052dfa1
> >>>>>> 100644 --- a/drivers/usb/dwc2/gadget.c
> >>>>>> +++ b/drivers/usb/dwc2/gadget.c
> >>>>>> @@ -117,7 +117,7 @@ static inline void
> >>>>>> dwc2_gadget_incr_frame_num(struct dwc2_hsotg_ep *hs_ep) if
> >>>>>> (hs_ep->target_frame > DSTS_SOFFN_LIMIT)
> >>>>>> { hs_ep->frame_overrun = true; hs_ep->target_frame &=
> >>>>>> DSTS_SOFFN_LIMIT;
> >>>>>> - } else {
> >>>>>> + } else if (hs_ep->parent->frame_number <
> >>>>>> hs_ep->target_frame) { hs_ep->frame_overrun = false;
> >>>>>> }
> >>>>>> }
> >>>>>>
> >>>>> Did you tested mentioned by you scenario? If you see issue can
> >>>>> you provide debug log and point the issue line in the log.
> >>>>
> >>>> It only reproduces very occasionally so it's difficult to capture
> >>>> a full debug log containing the error.
> >>>>
> >>>> I applied this patch to capture logging specifically around this
> >>>> scenario:
> >>>>
> >>>> -- >8 --
> >>>> diff --git a/drivers/usb/dwc2/gadget.c
> >>>> b/drivers/usb/dwc2/gadget.c index 220c0f9b89b0..3770b9d3b523
> >>>> 100644 --- a/drivers/usb/dwc2/gadget.c
> >>>> +++ b/drivers/usb/dwc2/gadget.c
> >>>> @@ -2722,13 +2722,20 @@ static void
> >>>> dwc2_gadget_handle_ep_disabled(struct dwc2_hsotg_ep *hs_ep) }
> >>>>
> >>>> do {
> >>>> + unsigned int target_frame = hs_ep->target_frame;
> >>>> + bool frame_overrun = hs_ep->frame_overrun;
> >>>> +
> >>>> hs_req = get_ep_head(hs_ep);
> >>>> if (hs_req)
> >>>> dwc2_hsotg_complete_request(hsotg,
> >>>> hs_ep, hs_req, -ENODATA);
> >>>> +
> >>>> dwc2_gadget_incr_frame_num(hs_ep);
> >>>> /* Update current frame number value. */
> >>>> hsotg->frame_number =
> >>>> dwc2_hsotg_read_frameno(hsotg); +
> >>>> + dev_warn(hsotg->dev, "%s: expiring request
> >>>> frame_number=0x%04x target_frame=0x%04x overrun=%u\n",
> >>>> + __func__, hsotg->frame_number,
> >>>> target_frame, frame_overrun); } while
> >>>> (dwc2_gadget_target_frame_elapsed(hs_ep));
> >>>> dwc2_gadget_start_next_request(hs_ep);
> >>>> -- 8< --
> >>>>
> >>> According above patch in debug log should be printed overrun flag
> >>> also. Could you please resend log with this flag.
> >
> > D'oh! I included a log from an earlier version before I added the
> > overrun flag.
> >
> >> One more request. Please add EP number to debug print.
> >
> > Here's an updated log:
> >
> > -- >8 --
> > [ 264.926385] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled:
> > expiring request ep=2 frame_number=0x2161 target_frame=0x2168
> > overrun=0 [ 265.905413] dwc2 ff580000.usb:
> > dwc2_gadget_handle_ep_disabled: expiring request ep=2
> > frame_number=0x3ff9 target_frame=0x0008 overrun=0 [ 265.905421]
> > dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request
> > ep=2 frame_number=0x3ff9 target_frame=0x0010 overrun=0
> > [ 265.905427] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled:
> > expiring request ep=2 frame_number=0x3ff9 target_frame=0x0018
> > overrun=0 [ 265.905432] dwc2 ff580000.usb:
> > dwc2_gadget_handle_ep_disabled: expiring request ep=2
> > frame_number=0x3ff9 target_frame=0x0020 overrun=0 [ 265.905438]
> > dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request
> > ep=2 frame_number=0x3ff9 target_frame=0x0028 overrun=0
> > [ 265.905443] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled:
> > expiring request ep=2 frame_number=0x3ff9 target_frame=0x0030
> > overrun=0 [ 265.905448] dwc2 ff580000.usb:
> > dwc2_gadget_handle_ep_disabled: expiring request ep=2
> > frame_number=0x3ff9 target_frame=0x0038 overrun=0 [ 265.905454]
> > dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request
> > ep=2 frame_number=0x3ff9 target_frame=0x0040 overrun=0
> > [ 265.905459] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled:
> > expiring request ep=2 frame_number=0x3ff9 target_frame=0x0048
> > overrun=0 -- 8< --
> >
> > Once again there is an initial failure before it enters the failure
> > mode my patch is trying to address. This seems to be consistent,
> > so it may be important, but there is ~80ms before the failure
> > starts.
> >>>> This was on v4.19 with an additional patch to disable descriptor
> >>>> DMA because that seems to be causing problems on RK3288 although
> >>>> I haven't figured out exactly why it's a problem.
> >>>
> >>> In which mode you run tests Slave or Buffer DMA?
> >
> > Buffer DMA but with descriptor DMA forced off (g_dma=1,
> > g_dma_desc=0).
> >
> > For the record, my test case is the standard UAC2 gadget with:
> >
> > c_srate = p_srate = 44100
> > c_ssize = p_ssize = 4
> > c_chmask = 0xf
> > p_chmask = 3
> >
> > and it seems that the failure only triggers when using arecord to
> > capture from the gadget interface (this is with a host program both
> > streaming in both directions over the USB connection); I suspect
> > that actually it just makes it more likely because there is more
> > work done in the completion handler, but I haven't seen the failure
> > without arecord running.
> >
> >
> > Regards,
> > John
> >
> I think cause of issue not in dwc2_gadget_target_frame_elapsed()
> function, but in do-while loop in dwc2_gadget_handle_ep_disabled().
> Could you please try below patch:
>
> diff --git a/drivers/usb/dwc2/gadget.c b/drivers/usb/dwc2/gadget.c
> index 8eb25e3597b0..4ad869853bfa 100644
> --- a/drivers/usb/dwc2/gadget.c
> +++ b/drivers/usb/dwc2/gadget.c
> @@ -2762,8 +2762,11 @@ static void
> dwc2_gadget_handle_ep_disabled(struct dwc2_hsotg_ep *hs_ep)
>
> do {
> hs_req = get_ep_head(hs_ep);
> - if (hs_req)
> - dwc2_hsotg_complete_request(hsotg, hs_ep,
> hs_req,
> + if (!hs_req) {
> + dev_warn(hsotg->dev, "%s: ISOC EP queue
> empty\n", __func__);
> + return;
> + }
> + dwc2_hsotg_complete_request(hsotg, hs_ep, hs_req,
> -ENODATA);
> dwc2_gadget_incr_frame_num(hs_ep);
> /* Update current frame number value. */
I don't see any difference after applying this patch, and the new
dev_warn message does not appear.
I think what happens is that dwc2_hsotg_complete_request() completes the
outstanding request and the completion handler (in this case
u_audio_iso_complete) enqueues a new request, so the queue is never
empty.
Regards,
John
