2018-10-23 14:35:33

by John Keeping

[permalink] [raw]
Subject: [PATCH] usb: dwc2: gadget: fix ISOC frame overflow handling

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 <[email protected]>
---
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;
}
}
--
2.19.1



2018-11-05 08:28:52

by Minas Harutyunyan

[permalink] [raw]
Subject: Re: [PATCH] usb: dwc2: gadget: fix ISOC frame overflow handling

Hi John,

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 <[email protected]>
> ---
> 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.

Thanks,
Minas


2018-11-08 17:37:55

by John Keeping

[permalink] [raw]
Subject: Re: [PATCH] usb: dwc2: gadget: fix ISOC frame overflow handling

Hi Minas,

On Mon, 5 Nov 2018 08:28:07 +0000
Minas Harutyunyan <[email protected]> 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 <[email protected]>
> > ---
> > 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< --

and I captured this log (the first entry is a separate error and then
the remaining ones show this bug being triggered):

[ 562.571227] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3eb9 target_frame=0x3ec0
[ 562.611213] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff8 target_frame=0x0008
[ 562.611219] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff8 target_frame=0x0010
[ 562.611223] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0018
[ 562.611228] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0020
[ 562.611232] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0028
[ 562.611236] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0030
[ 562.611240] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0038
[ 562.611244] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0040
[ 562.611249] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0048
[ 562.611253] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0050
[ 562.611257] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0058
[ 562.611261] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0060
[ 562.611265] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0068
[ 562.611269] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0070
[ 562.611274] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0078
[ 562.611278] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0080
[ 562.611282] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0088
[ 562.611286] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0090
[ 562.611290] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0098
[ 562.611294] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x00a0


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.


Regards,
John

2018-11-09 08:44:32

by Minas Harutyunyan

[permalink] [raw]
Subject: Re: [PATCH] usb: dwc2: gadget: fix ISOC frame overflow handling

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 <[email protected]> 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 <[email protected]>
>>> ---
>>> 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< --
>
> and I captured this log (the first entry is a separate error and then
> the remaining ones show this bug being triggered):
>
> [ 562.571227] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3eb9 target_frame=0x3ec0
> [ 562.611213] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff8 target_frame=0x0008
> [ 562.611219] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff8 target_frame=0x0010
> [ 562.611223] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0018
> [ 562.611228] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0020
> [ 562.611232] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0028
> [ 562.611236] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0030
> [ 562.611240] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0038
> [ 562.611244] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0040
> [ 562.611249] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0048
> [ 562.611253] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0050
> [ 562.611257] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0058
> [ 562.611261] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0060
> [ 562.611265] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0068
> [ 562.611269] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0070
> [ 562.611274] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0078
> [ 562.611278] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0080
> [ 562.611282] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0088
> [ 562.611286] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0090
> [ 562.611290] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0098
> [ 562.611294] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x00a0
>
According above patch in debug log should be printed overrun flag also.
Could you please resend log with this flag.

>
> 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?
>
>
> Regards,
> John
>

Thanks,
Minas


2018-11-09 14:37:37

by Minas Harutyunyan

[permalink] [raw]
Subject: Re: [PATCH] usb: dwc2: gadget: fix ISOC frame overflow handling

Hi John,

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 <[email protected]> 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 <[email protected]>
>>>> ---
>>>> 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< --
>>
>> and I captured this log (the first entry is a separate error and then
>> the remaining ones show this bug being triggered):
>>
>> [ 562.571227] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3eb9 target_frame=0x3ec0
>> [ 562.611213] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff8 target_frame=0x0008
>> [ 562.611219] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff8 target_frame=0x0010
>> [ 562.611223] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0018
>> [ 562.611228] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0020
>> [ 562.611232] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0028
>> [ 562.611236] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0030
>> [ 562.611240] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0038
>> [ 562.611244] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0040
>> [ 562.611249] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0048
>> [ 562.611253] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0050
>> [ 562.611257] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0058
>> [ 562.611261] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0060
>> [ 562.611265] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0068
>> [ 562.611269] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0070
>> [ 562.611274] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0078
>> [ 562.611278] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0080
>> [ 562.611282] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0088
>> [ 562.611286] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0090
>> [ 562.611290] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x0098
>> [ 562.611294] dwc2 ff580000.usb: dwc2_gadget_handle_ep_disabled: expiring request frame_number=0x3ff9 target_frame=0x00a0
>>
> According above patch in debug log should be printed overrun flag also.
> Could you please resend log with this flag.
>
One more request. Please add EP number to debug print.
>>
>> 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?
>>
>>
>> Regards,
>> John
>>
>
> Thanks,
> Minas
>
>


2018-11-09 18:44:37

by John Keeping

[permalink] [raw]
Subject: Re: [PATCH] usb: dwc2: gadget: fix ISOC frame overflow handling

Hi Minas,

On Fri, 9 Nov 2018 14:36:36 +0000
Minas Harutyunyan <[email protected]> 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 <[email protected]> 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 <[email protected]>
> >>>> ---
> >>>> 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

2018-11-12 08:54:29

by Minas Harutyunyan

[permalink] [raw]
Subject: Re: [PATCH] usb: dwc2: gadget: fix ISOC frame overflow handling

Hi John,

On 11/9/2018 10:43 PM, John Keeping wrote:
> Hi Minas,
>
> On Fri, 9 Nov 2018 14:36:36 +0000
> Minas Harutyunyan <[email protected]> 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 <[email protected]> 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 <[email protected]>
>>>>>> ---
>>>>>> 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. */

Thanks,
Minas


2018-11-12 22:49:29

by John Keeping

[permalink] [raw]
Subject: Re: [PATCH] usb: dwc2: gadget: fix ISOC frame overflow handling

Hi Minas,

On Mon, 12 Nov 2018 08:53:36 +0000
Minas Harutyunyan <[email protected]> wrote:
> On 11/9/2018 10:43 PM, John Keeping wrote:
> > On Fri, 9 Nov 2018 14:36:36 +0000
> > Minas Harutyunyan <[email protected]> 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 <[email protected]> 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 <[email protected]>
> >>>>>> ---
> >>>>>> 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

2018-12-14 09:01:18

by Minas Harutyunyan

[permalink] [raw]
Subject: Re: [PATCH] usb: dwc2: gadget: fix ISOC frame overflow handling

Hi John,

On 11/13/2018 2:46 AM, John Keeping wrote:
> Hi Minas,
>
> On Mon, 12 Nov 2018 08:53:36 +0000
> Minas Harutyunyan <[email protected]> wrote:
>> On 11/9/2018 10:43 PM, John Keeping wrote:
>>> On Fri, 9 Nov 2018 14:36:36 +0000
>>> Minas Harutyunyan <[email protected]> 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 <[email protected]> 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 <[email protected]>
>>>>>>>> ---
>>>>>>>> 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.

First of all, sorry for delayed answer.
Looks like similar issue seen by Andrzej Pietrasiewicz
<[email protected]>: "dwc2 isochronous transfers issues". Same
feedback provided to Andrzej.

I run tests on 4.20.0-rc4 in DDMA. By default IN ISOC traffic failed
because of BNA interrupts. It's happen because UAC2 requests count set
by default to 2. Our core and driver can't work in DDMA with descriptor
list length equal to 2. It's not possible on time prepare next
descriptors to avoid BNA interrupt.

By changing UAC2_DEF_REQ_NUM to 4 all audio gadget tests passed smoothly.
Could you please apply this patch and run tests in DDMA mode:

diff --git a/drivers/usb/gadget/function/u_uac2.h
b/drivers/usb/gadget/function/u_uac2.h
index 8362ee572e1e..5e649259ab76 100644
--- a/drivers/usb/gadget/function/u_uac2.h
+++ b/drivers/usb/gadget/function/u_uac2.h
@@ -21,7 +21,7 @@
#define UAC2_DEF_CCHMASK 0x3
#define UAC2_DEF_CSRATE 64000
#define UAC2_DEF_CSSIZE 2
-#define UAC2_DEF_REQ_NUM 2
+#define UAC2_DEF_REQ_NUM 4

struct f_uac2_opts {
struct usb_function_instance func_inst;


If it will OK on your side also then will switch to BDMA mode and debug.

Thanks,
Minas
>
>
> Regards,
> John
>


2018-12-18 14:36:25

by John Keeping

[permalink] [raw]
Subject: Re: [PATCH] usb: dwc2: gadget: fix ISOC frame overflow handling

Hi Minas,

On Fri, 14 Dec 2018 09:00:08 +0000
Minas Harutyunyan <[email protected]> wrote:
> First of all, sorry for delayed answer.
> Looks like similar issue seen by Andrzej Pietrasiewicz
> <[email protected]>: "dwc2 isochronous transfers issues". Same
> feedback provided to Andrzej.
>
> I run tests on 4.20.0-rc4 in DDMA. By default IN ISOC traffic failed
> because of BNA interrupts. It's happen because UAC2 requests count
> set by default to 2. Our core and driver can't work in DDMA with
> descriptor list length equal to 2. It's not possible on time prepare
> next descriptors to avoid BNA interrupt.
>
> By changing UAC2_DEF_REQ_NUM to 4 all audio gadget tests passed
> smoothly. Could you please apply this patch and run tests in DDMA
> mode:
>
> diff --git a/drivers/usb/gadget/function/u_uac2.h
> b/drivers/usb/gadget/function/u_uac2.h
> index 8362ee572e1e..5e649259ab76 100644
> --- a/drivers/usb/gadget/function/u_uac2.h
> +++ b/drivers/usb/gadget/function/u_uac2.h
> @@ -21,7 +21,7 @@
> #define UAC2_DEF_CCHMASK 0x3
> #define UAC2_DEF_CSRATE 64000
> #define UAC2_DEF_CSSIZE 2
> -#define UAC2_DEF_REQ_NUM 2
> +#define UAC2_DEF_REQ_NUM 4
>
> struct f_uac2_opts {
> struct usb_function_instance func_inst;
>
>
> If it will OK on your side also then will switch to BDMA mode and
> debug.

With DDMA enabled, I see the following error after the stream has been
running for a while (anything from a few seconds to a few minutes):

-- >8 --
[ 1798.836322] dwc2 ff580000.usb: dwc2_hsotg_ep_disable: called for ep0
[ 1798.836329] dwc2 ff580000.usb: dwc2_hsotg_ep_disable: called for ep0
[ 1798.851092] dwc2 ff580000.usb: new device is high-speed
[ 1798.924461] dwc2 ff580000.usb: new device is high-speed
[ 1798.982887] dwc2 ff580000.usb: new address 25
[ 1799.002463] configfs-gadget gadget: high-speed config #1: config
-- 8< --

On the host side (Linux 4.18.16 Intel xHCI), I see this logged at the
same time:

-- >8 --
[1735740.716242] retire_capture_urb: usb 1-2.2.7: frame 0 active: -71
[1735740.716990] retire_capture_urb: usb 1-2.2.7: frame 0 active: -71
[1735740.717906] retire_capture_urb: usb 1-2.2.7: frame 0 active: -71
[1735740.718905] retire_capture_urb: usb 1-2.2.7: frame 0 active: -71
[1735740.719916] retire_capture_urb: usb 1-2.2.7: frame 0 active: -71
[1735740.720032] usb 1-2.2-port7: disabled by hub (EMI?), re-enabling...
[1735740.720036] usb 1-2.2.7: USB disconnect, device number 28
[1735740.937500] usb 1-2.2.7: new high-speed USB device number 29 using xhci_hcd
-- 8< --

The device does then enumerate and works for a period of time before the
same error happens again.


Regards,
John

2018-12-19 17:05:23

by Minas Harutyunyan

[permalink] [raw]
Subject: Re: [PATCH] usb: dwc2: gadget: fix ISOC frame overflow handling

Hi John,

On 12/18/2018 6:35 PM, John Keeping wrote:
> Hi Minas,
>
> On Fri, 14 Dec 2018 09:00:08 +0000
> Minas Harutyunyan <[email protected]> wrote:
>> First of all, sorry for delayed answer.
>> Looks like similar issue seen by Andrzej Pietrasiewicz
>> <[email protected]>: "dwc2 isochronous transfers issues". Same
>> feedback provided to Andrzej.
>>
>> I run tests on 4.20.0-rc4 in DDMA. By default IN ISOC traffic failed
>> because of BNA interrupts. It's happen because UAC2 requests count
>> set by default to 2. Our core and driver can't work in DDMA with
>> descriptor list length equal to 2. It's not possible on time prepare
>> next descriptors to avoid BNA interrupt.
>>
>> By changing UAC2_DEF_REQ_NUM to 4 all audio gadget tests passed
>> smoothly. Could you please apply this patch and run tests in DDMA
>> mode:
>>
>> diff --git a/drivers/usb/gadget/function/u_uac2.h
>> b/drivers/usb/gadget/function/u_uac2.h
>> index 8362ee572e1e..5e649259ab76 100644
>> --- a/drivers/usb/gadget/function/u_uac2.h
>> +++ b/drivers/usb/gadget/function/u_uac2.h
>> @@ -21,7 +21,7 @@
>> #define UAC2_DEF_CCHMASK 0x3
>> #define UAC2_DEF_CSRATE 64000
>> #define UAC2_DEF_CSSIZE 2
>> -#define UAC2_DEF_REQ_NUM 2
>> +#define UAC2_DEF_REQ_NUM 4
>>
>> struct f_uac2_opts {
>> struct usb_function_instance func_inst;
>>
>>
>> If it will OK on your side also then will switch to BDMA mode and
>> debug.
>
> With DDMA enabled, I see the following error after the stream has been
> running for a while (anything from a few seconds to a few minutes):
>
> -- >8 --
> [ 1798.836322] dwc2 ff580000.usb: dwc2_hsotg_ep_disable: called for ep0
> [ 1798.836329] dwc2 ff580000.usb: dwc2_hsotg_ep_disable: called for ep0
> [ 1798.851092] dwc2 ff580000.usb: new device is high-speed
> [ 1798.924461] dwc2 ff580000.usb: new device is high-speed
> [ 1798.982887] dwc2 ff580000.usb: new address 25
> [ 1799.002463] configfs-gadget gadget: high-speed config #1: config
> -- 8< --
>
> On the host side (Linux 4.18.16 Intel xHCI), I see this logged at the
> same time:
>
> -- >8 --
> [1735740.716242] retire_capture_urb: usb 1-2.2.7: frame 0 active: -71
> [1735740.716990] retire_capture_urb: usb 1-2.2.7: frame 0 active: -71
> [1735740.717906] retire_capture_urb: usb 1-2.2.7: frame 0 active: -71
> [1735740.718905] retire_capture_urb: usb 1-2.2.7: frame 0 active: -71
> [1735740.719916] retire_capture_urb: usb 1-2.2.7: frame 0 active: -71
> [1735740.720032] usb 1-2.2-port7: disabled by hub (EMI?), re-enabling...
> [1735740.720036] usb 1-2.2.7: USB disconnect, device number 28
> [1735740.937500] usb 1-2.2.7: new high-speed USB device number 29 using xhci_hcd
> -- 8< --
>
> The device does then enumerate and works for a period of time before the
> same error happens again.
>
From logs not clear who initiate disconnect: host or device. More
probably host, after some errors in retire_capture_urb initiate
disconnect. Do you have any idea?
Can't you connect device to host on same platform?
If root cause of disconnect by host is device issue, i.e. not able to
send to host data packets in time then I need device side dmesg log with
debug enabled. USB trace around the disconnect will help to debug.

Thanks,
Minas

>
> Regards,
> John
>


2018-12-22 03:10:50

by John Keeping

[permalink] [raw]
Subject: Re: [PATCH] usb: dwc2: gadget: fix ISOC frame overflow handling

Hi Minas,

On Wed, 19 Dec 2018 14:09:01 +0000
Minas Harutyunyan <[email protected]> wrote:

> On 12/18/2018 6:35 PM, John Keeping wrote:
> > Hi Minas,
> >
> > On Fri, 14 Dec 2018 09:00:08 +0000
> > Minas Harutyunyan <[email protected]> wrote:
> >> First of all, sorry for delayed answer.
> >> Looks like similar issue seen by Andrzej Pietrasiewicz
> >> <[email protected]>: "dwc2 isochronous transfers issues". Same
> >> feedback provided to Andrzej.
> >>
> >> I run tests on 4.20.0-rc4 in DDMA. By default IN ISOC traffic
> >> failed because of BNA interrupts. It's happen because UAC2
> >> requests count set by default to 2. Our core and driver can't work
> >> in DDMA with descriptor list length equal to 2. It's not possible
> >> on time prepare next descriptors to avoid BNA interrupt.
> >>
> >> By changing UAC2_DEF_REQ_NUM to 4 all audio gadget tests passed
> >> smoothly. Could you please apply this patch and run tests in DDMA
> >> mode:
> >>
> >> diff --git a/drivers/usb/gadget/function/u_uac2.h
> >> b/drivers/usb/gadget/function/u_uac2.h
> >> index 8362ee572e1e..5e649259ab76 100644
> >> --- a/drivers/usb/gadget/function/u_uac2.h
> >> +++ b/drivers/usb/gadget/function/u_uac2.h
> >> @@ -21,7 +21,7 @@
> >> #define UAC2_DEF_CCHMASK 0x3
> >> #define UAC2_DEF_CSRATE 64000
> >> #define UAC2_DEF_CSSIZE 2
> >> -#define UAC2_DEF_REQ_NUM 2
> >> +#define UAC2_DEF_REQ_NUM 4
> >>
> >> struct f_uac2_opts {
> >> struct usb_function_instance func_inst;
> >>
> >>
> >> If it will OK on your side also then will switch to BDMA mode and
> >> debug.
> >
> > With DDMA enabled, I see the following error after the stream has
> > been running for a while (anything from a few seconds to a few
> > minutes):
> > -- >8 --
> > [ 1798.836322] dwc2 ff580000.usb: dwc2_hsotg_ep_disable: called for
> > ep0 [ 1798.836329] dwc2 ff580000.usb: dwc2_hsotg_ep_disable: called
> > for ep0 [ 1798.851092] dwc2 ff580000.usb: new device is high-speed
> > [ 1798.924461] dwc2 ff580000.usb: new device is high-speed
> > [ 1798.982887] dwc2 ff580000.usb: new address 25
> > [ 1799.002463] configfs-gadget gadget: high-speed config #1: config
> > -- 8< --
> >
> > On the host side (Linux 4.18.16 Intel xHCI), I see this logged at
> > the same time:
> >
> > -- >8 --
> > [1735740.716242] retire_capture_urb: usb 1-2.2.7: frame 0 active:
> > -71 [1735740.716990] retire_capture_urb: usb 1-2.2.7: frame 0
> > active: -71 [1735740.717906] retire_capture_urb: usb 1-2.2.7: frame
> > 0 active: -71 [1735740.718905] retire_capture_urb: usb 1-2.2.7:
> > frame 0 active: -71 [1735740.719916] retire_capture_urb: usb
> > 1-2.2.7: frame 0 active: -71 [1735740.720032] usb 1-2.2-port7:
> > disabled by hub (EMI?), re-enabling... [1735740.720036] usb
> > 1-2.2.7: USB disconnect, device number 28 [1735740.937500] usb
> > 1-2.2.7: new high-speed USB device number 29 using xhci_hcd -- 8< --
> >
> > The device does then enumerate and works for a period of time
> > before the same error happens again.
> >
> From logs not clear who initiate disconnect: host or device. More
> probably host, after some errors in retire_capture_urb initiate
> disconnect. Do you have any idea?
> Can't you connect device to host on same platform?
> If root cause of disconnect by host is device issue, i.e. not able to
> send to host data packets in time then I need device side dmesg log
> with debug enabled. USB trace around the disconnect will help to
> debug.

I remember running a test with a hardware USB analyzer and which showed
an isochronous packet with an incorrect length (much larger than it
should have been) when the failure occurred.

I don't have any logs from that test and I'm out of the office at the
moment, but I will capture logs when I'm back in January.


Thanks,
John

2018-12-24 07:20:12

by Minas Harutyunyan

[permalink] [raw]
Subject: Re: [PATCH] usb: dwc2: gadget: fix ISOC frame overflow handling

Hi John,

On 12/21/2018 8:05 PM, John Keeping wrote:
> Hi Minas,
>
> On Wed, 19 Dec 2018 14:09:01 +0000
> Minas Harutyunyan <[email protected]> wrote:
>
>> On 12/18/2018 6:35 PM, John Keeping wrote:
>>> Hi Minas,
>>>
>>> On Fri, 14 Dec 2018 09:00:08 +0000
>>> Minas Harutyunyan <[email protected]> wrote:
>>>> First of all, sorry for delayed answer.
>>>> Looks like similar issue seen by Andrzej Pietrasiewicz
>>>> <[email protected]>: "dwc2 isochronous transfers issues". Same
>>>> feedback provided to Andrzej.
>>>>
>>>> I run tests on 4.20.0-rc4 in DDMA. By default IN ISOC traffic
>>>> failed because of BNA interrupts. It's happen because UAC2
>>>> requests count set by default to 2. Our core and driver can't work
>>>> in DDMA with descriptor list length equal to 2. It's not possible
>>>> on time prepare next descriptors to avoid BNA interrupt.
>>>>
>>>> By changing UAC2_DEF_REQ_NUM to 4 all audio gadget tests passed
>>>> smoothly. Could you please apply this patch and run tests in DDMA
>>>> mode:
>>>>
>>>> diff --git a/drivers/usb/gadget/function/u_uac2.h
>>>> b/drivers/usb/gadget/function/u_uac2.h
>>>> index 8362ee572e1e..5e649259ab76 100644
>>>> --- a/drivers/usb/gadget/function/u_uac2.h
>>>> +++ b/drivers/usb/gadget/function/u_uac2.h
>>>> @@ -21,7 +21,7 @@
>>>> #define UAC2_DEF_CCHMASK 0x3
>>>> #define UAC2_DEF_CSRATE 64000
>>>> #define UAC2_DEF_CSSIZE 2
>>>> -#define UAC2_DEF_REQ_NUM 2
>>>> +#define UAC2_DEF_REQ_NUM 4
>>>>
>>>> struct f_uac2_opts {
>>>> struct usb_function_instance func_inst;
>>>>
>>>>
>>>> If it will OK on your side also then will switch to BDMA mode and
>>>> debug.
>>>
>>> With DDMA enabled, I see the following error after the stream has
>>> been running for a while (anything from a few seconds to a few
>>> minutes):
>>> -- >8 --
>>> [ 1798.836322] dwc2 ff580000.usb: dwc2_hsotg_ep_disable: called for
>>> ep0 [ 1798.836329] dwc2 ff580000.usb: dwc2_hsotg_ep_disable: called
>>> for ep0 [ 1798.851092] dwc2 ff580000.usb: new device is high-speed
>>> [ 1798.924461] dwc2 ff580000.usb: new device is high-speed
>>> [ 1798.982887] dwc2 ff580000.usb: new address 25
>>> [ 1799.002463] configfs-gadget gadget: high-speed config #1: config
>>> -- 8< --
>>>
>>> On the host side (Linux 4.18.16 Intel xHCI), I see this logged at
>>> the same time:
>>>
>>> -- >8 --
>>> [1735740.716242] retire_capture_urb: usb 1-2.2.7: frame 0 active:
>>> -71 [1735740.716990] retire_capture_urb: usb 1-2.2.7: frame 0
>>> active: -71 [1735740.717906] retire_capture_urb: usb 1-2.2.7: frame
>>> 0 active: -71 [1735740.718905] retire_capture_urb: usb 1-2.2.7:
>>> frame 0 active: -71 [1735740.719916] retire_capture_urb: usb
>>> 1-2.2.7: frame 0 active: -71 [1735740.720032] usb 1-2.2-port7:
>>> disabled by hub (EMI?), re-enabling... [1735740.720036] usb
>>> 1-2.2.7: USB disconnect, device number 28 [1735740.937500] usb
>>> 1-2.2.7: new high-speed USB device number 29 using xhci_hcd -- 8< --
>>>
>>> The device does then enumerate and works for a period of time
>>> before the same error happens again.
>>>
>> From logs not clear who initiate disconnect: host or device. More
>> probably host, after some errors in retire_capture_urb initiate
>> disconnect. Do you have any idea?
>> Can't you connect device to host on same platform?
>> If root cause of disconnect by host is device issue, i.e. not able to
>> send to host data packets in time then I need device side dmesg log
>> with debug enabled. USB trace around the disconnect will help to
>> debug.
>
> I remember running a test with a hardware USB analyzer and which showed
> an isochronous packet with an incorrect length (much larger than it
> should have been) when the failure occurred.
>
> I don't have any logs from that test and I'm out of the office at the
> moment, but I will capture logs when I'm back in January.

I think, if you enable debug prints, you will see BNA interrupts. So, my
recommendation is to increase more UAC2_DEF_REQ_NUM until BNA will
disappear. Per me value of UAC2_DEF_REQ_NUM is platform's latency dependent.

Thanks,
Minas

>
>
> Thanks,
> John
>