RE: usb: gadget: dwc2: not getting audio data

Minas Harutyunyan
2023-02-22T06:39:22Z

Hi Palak,

On 2/15/2023 11:48 PM, Palak SHAH wrote:
>From: Palak SHAH <palak.shah@raritan.com>
>Sent: Wednesday, February 15, 2023 11:48 PM
>To: Minas Harutyunyan <hminas@synopsys.com>; Maynard CABIENTE <maynard.cabiente@raritan.com>
>Cc: linux-usb@vger.kernel.org; Palak SHAH <palak.shah@raritan.com>
>Subject: RE: usb: gadget: dwc2: not getting audio data
>
>Hi Minas,
>I recently came back from vacation and resumed debugging the dwc2 audio data issue.
>
>Based on what you suggested in our last conversation, I put some more debugging messages the linux/driver/usb/gadget.c file and I am seeing the following -
>
>// When the data is coming in and the XferComp is successful, I see the following -
>[   81.279536]
>[   81.280336] dwc2 ffb40000.usb: dwc2_hsotg_irq: 04288028 00080000 (d08c3cc4) retry 8
>[   81.280348] dwc2 ffb40000.usb: dwc2_hsotg_irq: daint=00020000
>[   81.280357] dwc2 ffb40000.usb: dwc2_hsotg_irq, calling dwc2_hsotg_epint 0
>[   81.280367] dwc2 ffb40000.usb: ENTERING dwc2_hsotg_epint: EP(1) DIRECTION (out)
>[   81.280375] dwc2 ffb40000.usb: dwc2_gadget_read_ep_interrupts
>[   81.280395] dwc2 ffb40000.usb: dwc2_hsotg_epint: ep1(out) DxEPINT=0x00000001
>[   81.280406] dwc2 ffb40000.usb: dwc2_hsotg_epint: XferCompl: DxEPCTL=0x800480c8, DXEPTSIZ=0bee44f0
>[   81.280415] dwc2 ffb40000.usb: dwc2_hsotg_epint: calling dwc2_gadget_complete_isoc_request_ddma
>[   81.280424] dwc2 ffb40000.usb: dwc2_gadget_complete_isoc_request_ddma: calling dwc2_hsotg_complete_request()
>[   81.280437] dwc2 ffb40000.usb: dwc2_hsotg_complete_request, complete: ep 4a6713b7 ep1out, req 41f4c070, 0 => ea5b3941
>[   81.280456] dwc2 ffb40000.usb: dwc2_hsotg_ep_queue, ep1out: req 41f4c070: req len(200)@req buf(3fb7d86f), # of int=0, req zero=0, snok(short not ok)=0
>[   81.280474] dwc2 ffb40000.usb: dwc2_hsotg_ep_queue, EP #(ep1out) Handle DDMA isochronous transfers separately.
>[   81.280483] dwc2 ffb40000.usb: ENTERING dwc2_gadget_fill_isoc_desc
>[   81.280493] dwc2 ffb40000.usb: dwc2_gadget_fill_isoc_desc: Filling ep 1, dir (out) isoc desc # (132)
>[   81.280502] dwc2 ffb40000.usb: dwc2_gadget_complete_isoc_request_ddma: compl_desc # 130
>[   81.280511] dwc2 ffb40000.usb: dwc2_hsotg_epint: At the end of the function, dwc2_hsotg_epint()
>[   81.280511]  -------------------A GAP of 6 secs ---------------------------------------------------------------
>
>// After the gap, I don't see any XferCompl request, however I see dwc2_gadget_handle_out_token_ep_disabled() API getting called.
>
>[   87.871437] dwc2 ffb40000.usb: ENTERING dwc2_hsotg_epint: EP(1) DIRECTION (out)
>[   87.872434] dwc2 ffb40000.usb: ENTERING dwc2_hsotg_epint: EP(1) DIRECTION (out)
>[   87.872451] dwc2 ffb40000.usb: dwc2_gadget_read_ep_interrupts
>[   87.872461] dwc2 ffb40000.usb: dwc2_hsotg_epint: ep1(out) DxEPINT=0x00000010
>[   87.872470] dwc2 ffb40000.usb: dwc2_hsotg_epint, calling dwc2_gadget_handle_out_token_ep_disabled
>[   87.872478] dwc2 ffb40000.usb: dwc2_gadget_handle_out_token_ep_disabled: target_frame = 0x00002bd0
>[   87.872486] dwc2 ffb40000.usb: ENTERING dwc2_gadget_start_isoc_ddma
>[   87.872497] dwc2 ffb40000.usb: ENTERING dwc2_gadget_fill_isoc_desc
>[   87.872507] dwc2 ffb40000.usb: dwc2_gadget_fill_isoc_desc: Filling ep 1, dir (out) isoc desc # (0)
>[   87.872524] dwc2 ffb40000.usb: ENTERING dwc2_gadget_fill_isoc_desc
>[   87.872534] dwc2 ffb40000.usb: dwc2_gadget_fill_isoc_desc: Filling ep 1, dir (out) isoc desc # (1)
>[   87.872544] dwc2 ffb40000.usb: dwc2_hsotg_epint: At the end of the function, dwc2_hsotg_epint()
>[   87.872544]
>
>I have attached the full log here.
>
>When I look at the dwc2_hsotg_epint() API, I see that when the XFERCompl is successful, then the following is true -
>if (ints & DXEPINT_XFERCOMPL) {
>                dev_dbg(hsotg->dev,
>                        "%s: XferCompl: DxEPCTL=0x%08x, DXEPTSIZ=%08x\n",
>                        __func__, dwc2_readl(hsotg, epctl_reg),
>                        dwc2_readl(hsotg, epsiz_reg));
>
>                /* In DDMA handle isochronous requests separately */
>                if (using_desc_dma(hsotg) && hs_ep->isochronous) {
>                    dev_dbg(hsotg->dev, "%s: calling dwc2_gadget_complete_isoc_request_ddma\n", __func__);
>                    dwc2_gadget_complete_isoc_request_ddma(hs_ep);
>
>However, in case of no XferCompl, it bypasses this and goes to the following IF condition -
>        if (ints & DXEPINT_OUTTKNEPDIS){
>                dev_dbg(hsotg->dev,"%s, calling dwc2_gadget_handle_out_token_ep_disabled\n", __func__);
>                dwc2_gadget_handle_out_token_ep_disabled(hs_ep);
>        }
>
>In what scenario does the DXEPINT_XFERCOMPL change to DXEPINT_OUTTKNEPDIS?
>This change in the IF() condition, co incides with the time lapse. Can you please help me understand this?
>

DXEPINT_OUTTKNEPDIS asserted when OUT token for ISOC (ep1out) arrive to core
but EP not enabled yet. Based on this interrupt driver start ISOC transfer by
filling descriptors chain an enabling EP. This flow used for very beginning first
ISOC packet. This part not seen in the log but looks like it was successful
because we see expecting DXEPINT_XFERCOMPL interrupts until 6 sec gap.
After time gap due to some reasons EP became disabled and then driver trying
to re-start ISOC traffic based on DXEPINT_OUTTKNEPDIS interrupt as described
above. But something go wrong, EP not enabled and we got DXEPINT_OUTTKNEPDIS
interrupt and re-starting again and again.

In dwc2_gadget_start_isoc_ddma() function the final step is enabling EP:
ctrl = dwc2_readl(hsotg, depctl);
ctrl |= DXEPCTL_EPENA | DXEPCTL_CNAK;
dwc2_writel(hsotg, ctrl, depctl);
}
Let add at the end debug print depctl to check EP Enable bit set or not.
Additionally lets print some registers too: GRXSTSR, DCFG, DCTL and DSTS.
Apply this patch and send me debug log:

diff --git a/drivers/usb/dwc2/gadget.c b/drivers/usb/dwc2/gadget.c
index 62fa6378d2d7..34f786b514ec 100644
--- a/drivers/usb/dwc2/gadget.c
+++ b/drivers/usb/dwc2/gadget.c
@@ -1028,6 +1028,9 @@ static void dwc2_gadget_start_isoc_ddma(struct dwc2_hsotg_ep *hs_ep)
ctrl = dwc2_readl(hsotg, depctl);
ctrl |= DXEPCTL_EPENA | DXEPCTL_CNAK;
dwc2_writel(hsotg, ctrl, depctl);
+ dev_dbg(hsotg->dev, "%s: GRXSTSR=0x%08x DCFG==0x%08x DCTL=0x%08x DSTS=0x%08x DxEPCTL(%d)=0x%08x",
+ __func__, dwc2_readl(hsotg, GRXSTSR), dwc2_readl(hsotg, DCFG), dwc2_readl(hsotg, DCTL),
+ dwc2_readl(hsotg, DSTS), index, dwc2_readl(hsotg, depctl));
}

Another thing which I recommend to do is increasing request count of audio gadget.
Depend on which uac (uac1 or uac2) you use, accordingly increase 2 to 32:
u_uac1.h:
#define UAC1_DEF_REQ_NUM 2
u_uac2.h:
#define UAC2_DEF_REQ_NUM 2

Thanks,
Minas

Please reply emails in "Plain Text" format only.

>Thank you so much for your help all along.
>
>Thanks,
>Palak
>