Hi Minas and other USB experts,
I'm currently developing new features for UAC1/UAC2 audio gadgets
like Volume/Mute controls which use Control SETUP + DATA OUT
transactions through ep0.
While it works fine on BeagleBone black board with MUSB UDC,
on Raspberry Pi 4 with DWC2 UDC there is an issue.
I found that when DWC2 receives ep0 SETUP + DATA OUT transaction,
it doesn't copy data transferred from the host to EP0 in DATA OUT stage
to the usb_request->buf buffer. This buffer contains unchanged data from
previous transactions.
However, when I disable DMA for DWC2 controller (see the patch below)
it starts to work as expected and correctly copies data transferred from
the host in the DATA OUT stage, to the usb_request->buf buffer.
So far I tested it on v5.9 kernel and v5.10.10 stable kernel both have
the same issue.
This issue is easily reproducible with RNDIS gadget which also
uses ep0 SETUP + DATA OUT transactions for transferring
RNDIS control messages.
During enumeration of RNDIS gadget attached to Linux host,
I see next messages for RPi4 DWC2 with DMA enabled:
| ## RPi4 DWC2 DMA
| [ 91.029881] rndis_msg_parser: unknown RNDIS message 0x0052033A len 4456526
| [ 91.029889] RNDIS command error -524, 24/24
In this case rndis_msg_parser can't parse messages from the host
because they are sent through SETUP + DATA OUT transaction and
DWC2 didn't copy that messages to the buffer, so buffer contains
some garbage from previous transactions which can't be parsed.
In case of BBB black or DWC2 with disabled DMA, it looks like:
| ## BBB black
| [ 32.867751] rndis_msg_parser: RNDIS_MSG_INIT
| ## RPi4 DWC2 no DMA
| [ 151.080724] rndis_msg_parser: RNDIS_MSG_INIT
I also did a quick googling and found that same issue was
recently reported for Raspberry pi OS:
https://github.com/raspberrypi/Raspberry-Pi-OS-64bit/issues/127
I spent some time on debugging this issue, but without having
DWC2 documentation and experience with DWC2 internals
that's all that I found so far.
Is this a known issue? Anybody debugging it? Any ideas?
Thanks,
Ruslan
-------------------------------------8<----------------------------------------
From ced7a3631d9800d04bcbcd756dac4583459fe48c Mon Sep 17 00:00:00 2001
From: Ruslan Bilovol <[email protected]>
Date: Wed, 20 Jan 2021 00:27:52 +0200
Subject: [PATCH] usb: dwc2: workaround: disable DMA for gadget
On Raspberry PI 4 it was observer that in case of control
transfers with DATA phase from a host, the driver for some
reason doesn't copy transferred data to the buffer, leaving
previous data in it.
With disabled DMA the issue isn't reproducible, thus
temporarily disable it
Signed-off-by: Ruslan Bilovol <[email protected]>
---
drivers/usb/dwc2/params.c | 8 ++++++++
1 file changed, 8 insertions(+)
diff --git a/drivers/usb/dwc2/params.c b/drivers/usb/dwc2/params.c
index 267543c..46c18af 100644
--- a/drivers/usb/dwc2/params.c
+++ b/drivers/usb/dwc2/params.c
@@ -357,7 +357,11 @@ static void dwc2_set_default_params(struct
dwc2_hsotg *hsotg)
{
struct dwc2_hw_params *hw = &hsotg->hw_params;
struct dwc2_core_params *p = &hsotg->params;
+#if 0
bool dma_capable = !(hw->arch == GHWCFG2_SLAVE_ONLY_ARCH);
+#else
+ bool dma_capable = 0;
+#endif
dwc2_set_param_otg_cap(hsotg);
dwc2_set_param_phy_type(hsotg);
@@ -651,7 +655,11 @@ static void dwc2_check_params(struct dwc2_hsotg *hsotg)
{
struct dwc2_hw_params *hw = &hsotg->hw_params;
struct dwc2_core_params *p = &hsotg->params;
+#if 0
bool dma_capable = !(hw->arch == GHWCFG2_SLAVE_ONLY_ARCH);
+#else
+ bool dma_capable = 0;
+#endif
dwc2_check_param_otg_cap(hsotg);
dwc2_check_param_phy_type(hsotg);
--
1.9.1
Hi Ruslan,
On 2/1/2021 3:44 AM, Ruslan Bilovol wrote:
> Hi Minas and other USB experts,
>
> I'm currently developing new features for UAC1/UAC2 audio gadgets
> like Volume/Mute controls which use Control SETUP + DATA OUT
> transactions through ep0.
>
> While it works fine on BeagleBone black board with MUSB UDC,
> on Raspberry Pi 4 with DWC2 UDC there is an issue.
>
> I found that when DWC2 receives ep0 SETUP + DATA OUT transaction,
> it doesn't copy data transferred from the host to EP0 in DATA OUT stage
> to the usb_request->buf buffer. This buffer contains unchanged data from
> previous transactions.
>
Could you please send debug log with issue and usb trace.
Thanks,
Minas
Hi Pavel,
On 4/19/2021 5:22 PM, Pavel Hofman wrote:
>
> Dne 11. 02. 21 v 12:21 Minas Harutyunyan napsal(a):
>> Hi Ruslan,
>>
>> On 2/1/2021 3:44 AM, Ruslan Bilovol wrote:
>>> Hi Minas and other USB experts,
>>>
>>> I'm currently developing new features for UAC1/UAC2 audio gadgets
>>> like Volume/Mute controls which use Control SETUP + DATA OUT
>>> transactions through ep0.
>>>
>>> While it works fine on BeagleBone black board with MUSB UDC,
>>> on Raspberry Pi 4 with DWC2 UDC there is an issue.
>>>
>>> I found that when DWC2 receives ep0 SETUP + DATA OUT transaction,
>>> it doesn't copy data transferred from the host to EP0 in DATA OUT stage
>>> to the usb_request->buf buffer. This buffer contains unchanged data from
>>> previous transactions.
>>>
>>
>> Could you please send debug log with issue and usb trace.
>>
>
> Hi Minas,
>
> I confirm this problem with DWC2 gadget on RPi4. I rebased Julian's
> multiple audio clocks patch
> https://urldefense.com/v3/__https://lore.kernel.org/patchwork/patch/803422/__;!!A4F2R9G_pg!J3zujH0Tzsp0DBsJm6EPTzG0vdr9plGNx7jmoik8JvN4NqODulvND5RXZiLE8d70RkUod4ZZ$ on top of Ruslan's
> implicit feedback patches
> https://urldefense.com/v3/__https://patchwork.kernel.org/project/linux-usb/list/?series=&submitter=121671&state=&q=&archive=&delegate=__;!!A4F2R9G_pg!J3zujH0Tzsp0DBsJm6EPTzG0vdr9plGNx7jmoik8JvN4NqODulvND5RXZiLE8d70Rtv_duVh$
> on branch rpi-5.12.y
> https://urldefense.com/v3/__https://github.com/raspberrypi/linux/tree/rpi-5.12.y__;!!A4F2R9G_pg!J3zujH0Tzsp0DBsJm6EPTzG0vdr9plGNx7jmoik8JvN4NqODulvND5RXZiLE8d70Rkqjb2Qb$ and compiled for arm64.
>
> When USB host switches audio playback to non-default samplerate (from
> 96000 to 192000 in my case), usb_request->buf contains the previous
> default value of 96000, instead of the new value sent by the host - see
> the captured USB packet below:
>
> ===============
> Frame 9: 68 bytes on wire (544 bits), 68 bytes captured (544 bits) on
> interface usbmon1, id 0
> Interface id: 0 (usbmon1)
> Interface name: usbmon1
> Encapsulation type: USB packets with Linux header and padding (115)
> Arrival Time: Apr 19, 2021 13:41:25.146650000 CEST
> [Time shift for this packet: 0.000000000 seconds]
> Epoch Time: 1618832485.146650000 seconds
> [Time delta from previous captured frame: 0.000050000 seconds]
> [Time delta from previous displayed frame: 0.000050000 seconds]
> [Time since reference or first frame: 6.013518000 seconds]
> Frame Number: 9
> Frame Length: 68 bytes (544 bits)
> Capture Length: 68 bytes (544 bits)
> [Frame is marked: False]
> [Frame is ignored: False]
> [Protocols in frame: usb]
> USB URB
> [Source: host]
> [Destination: 1.14.0]
> URB id: 0xffff8c37444f2480
> URB type: URB_SUBMIT ('S')
> URB transfer type: URB_CONTROL (0x02)
> Endpoint: 0x00, Direction: OUT
> 0... .... = Direction: OUT (0)
> .... 0000 = Endpoint number: 0
> Device: 14
> URB bus id: 1
> Device setup request: relevant (0)
> Data: present (0)
> URB sec: 1618832485
> URB usec: 146650
> URB status: Operation now in progress (-EINPROGRESS) (-115)
> URB length [bytes]: 4
> Data length [bytes]: 4
> [Response in: 10]
> Interval: 0
> Start frame: 0
> Copy of Transfer Flags: 0x00000000
> .... .... .... .... .... .... .... ...0 = Short not OK: False
> .... .... .... .... .... .... .... ..0. = ISO ASAP: False
> .... .... .... .... .... .... .... .0.. = No transfer DMA map: False
> .... .... .... .... .... .... ..0. .... = No FSBR: False
> .... .... .... .... .... .... .0.. .... = Zero Packet: False
> .... .... .... .... .... .... 0... .... = No Interrupt: False
> .... .... .... .... .... ...0 .... .... = Free Buffer: False
> .... .... .... .... .... ..0. .... .... = Dir IN: False
> .... .... .... ...0 .... .... .... .... = DMA Map Single: False
> .... .... .... ..0. .... .... .... .... = DMA Map Page: False
> .... .... .... .0.. .... .... .... .... = DMA Map SG: False
> .... .... .... 0... .... .... .... .... = Map Local: False
> .... .... ...0 .... .... .... .... .... = Setup Map Single: False
> .... .... ..0. .... .... .... .... .... = Setup Map Local: False
> .... .... .0.. .... .... .... .... .... = DMA S-G Combined: False
> .... .... 0... .... .... .... .... .... = Aligned Temp Buffer: False
> Number of ISO descriptors: 0
> [bInterfaceClass: Unknown (0xffff)]
> Setup Data
> bmRequestType: 0x21
> 0... .... = Direction: Host-to-device
> .01. .... = Type: Class (0x1)
> ...0 0001 = Recipient: Interface (0x01)
> bRequest: 1
> wValue: 0x0100
> wIndex: 1792 (0x0700)
> wLength: 4
> Data Fragment: 00ee0200 <------------------------------
> ===============
>
>
Some clarifications required:
1. gadget works in scatter/gather DMA mode (g_dma_desc is true)?
2. Above captured Host side USB packet corresponds in dmesg to line#39907:
[ 1261.789552] dwc2 fe980000.usb: ctrl Type=21, Req=01, V=0100, I=0700,
L=0004
Correct?
3. You assume that issue seen in below printk's (lines##39923-39927):
[ 1261.789640] g_audio gadget: Calling uac2_cs_control_sam_freq 1.
[ 1261.789652] g_audio gadget: Calling uac2_cs_control_sam_freq 2.
[ 1261.789655] g_audio gadget: uac2_cs_control_sam_freq val: 96000.
[ 1261.789659] g_audio gadget: Calling uac2_cs_control_sam_freq OUT.
[ 1261.789665] Calling u_audio_set_capture_srate with srate 96000
Instead both 96000 should be 192000? Could you please provide me
messages sequence for correct behaviour for 192000.
4. Below dmesg fragment not corresponds to observed issue, it's just for
show added printk's in g_audio. Correct?
Thanks,
Minas
> The value sent 00ee0200 corresponds to 192000, but the gadget received
> the original 96000 (I added some printks to g_audio):
>
> ==========
> [ 1260.277857] dwc2 fe980000.usb: ep0: req 00000000cf0a7502:
> 4@000000000e574c90, noi=0, zero=0, snok=0
> [ 1260.277865] dwc2 fe980000.usb: dwc2_hsotg_start_req:
> DxEPCTL=0x00028000, ep 0, dir in
> [ 1260.277870] dwc2 fe980000.usb: ureq->length:4 ureq->actual:0
> [ 1260.277886] dwc2 fe980000.usb: ep0 state:1
> [ 1260.277913] dwc2 fe980000.usb: req->length:4 req->actual:4 req->zero:0
> [ 1260.277944] dwc2 fe980000.usb: zlp packet received
> [ 1260.277948] dwc2 fe980000.usb: complete: ep 0000000018e5b31a ep0, req
> 00000000cf0a7502, 0 => 0000000023e79ed8
> [ 1260.277984] dwc2 fe980000.usb: ureq->length:8 ureq->actual:0
> [ 1260.278078] dwc2 fe980000.usb: dwc2_hsotg_epint: ep0(out)
> DxEPINT=0x00000018
> [ 1260.278104] dwc2 fe980000.usb: ep0: req 00000000cf0a7502:
> 4@000000000e574c90, noi=0, zero=0, snok=0
> [ 1260.278128] dwc2 fe980000.usb: dwc2_hsotg_start_req:
> 0x00000000fb0cb800 => 0x00000b14
> [ 1260.278163] dwc2 fe980000.usb: dwc2_hsotg_epint: XferCompl:
> DxEPCTL=0x00028000, DXEPTSIZ=00000000
> [ 1260.278182] g_audio gadget: Calling uac2_cs_control_sam_freq 2.
> [ 1260.278186] g_audio gadget: uac2_cs_control_sam_freq val: 96000.
> ============
>
> Please find attached the whole dmesg from modprobing the gadget modules
> through playback of 192000.
>
> Please let me know if you need any more logs/tests. Thank you very much
> for your help.
>
> Best regards,
>
> Pavel.
>
>
>
Dne 11. 02. 21 v 12:21 Minas Harutyunyan napsal(a):
> Hi Ruslan,
>
> On 2/1/2021 3:44 AM, Ruslan Bilovol wrote:
>> Hi Minas and other USB experts,
>>
>> I'm currently developing new features for UAC1/UAC2 audio gadgets
>> like Volume/Mute controls which use Control SETUP + DATA OUT
>> transactions through ep0.
>>
>> While it works fine on BeagleBone black board with MUSB UDC,
>> on Raspberry Pi 4 with DWC2 UDC there is an issue.
>>
>> I found that when DWC2 receives ep0 SETUP + DATA OUT transaction,
>> it doesn't copy data transferred from the host to EP0 in DATA OUT stage
>> to the usb_request->buf buffer. This buffer contains unchanged data from
>> previous transactions.
>>
>
> Could you please send debug log with issue and usb trace.
>
Hi Minas,
I confirm this problem with DWC2 gadget on RPi4. I rebased Julian's
multiple audio clocks patch
https://lore.kernel.org/patchwork/patch/803422/ on top of Ruslan's
implicit feedback patches
https://patchwork.kernel.org/project/linux-usb/list/?series=&submitter=121671&state=&q=&archive=&delegate=
on branch rpi-5.12.y
https://github.com/raspberrypi/linux/tree/rpi-5.12.y and compiled for arm64.
When USB host switches audio playback to non-default samplerate (from
96000 to 192000 in my case), usb_request->buf contains the previous
default value of 96000, instead of the new value sent by the host - see
the captured USB packet below:
===============
Frame 9: 68 bytes on wire (544 bits), 68 bytes captured (544 bits) on
interface usbmon1, id 0
Interface id: 0 (usbmon1)
Interface name: usbmon1
Encapsulation type: USB packets with Linux header and padding (115)
Arrival Time: Apr 19, 2021 13:41:25.146650000 CEST
[Time shift for this packet: 0.000000000 seconds]
Epoch Time: 1618832485.146650000 seconds
[Time delta from previous captured frame: 0.000050000 seconds]
[Time delta from previous displayed frame: 0.000050000 seconds]
[Time since reference or first frame: 6.013518000 seconds]
Frame Number: 9
Frame Length: 68 bytes (544 bits)
Capture Length: 68 bytes (544 bits)
[Frame is marked: False]
[Frame is ignored: False]
[Protocols in frame: usb]
USB URB
[Source: host]
[Destination: 1.14.0]
URB id: 0xffff8c37444f2480
URB type: URB_SUBMIT ('S')
URB transfer type: URB_CONTROL (0x02)
Endpoint: 0x00, Direction: OUT
0... .... = Direction: OUT (0)
.... 0000 = Endpoint number: 0
Device: 14
URB bus id: 1
Device setup request: relevant (0)
Data: present (0)
URB sec: 1618832485
URB usec: 146650
URB status: Operation now in progress (-EINPROGRESS) (-115)
URB length [bytes]: 4
Data length [bytes]: 4
[Response in: 10]
Interval: 0
Start frame: 0
Copy of Transfer Flags: 0x00000000
.... .... .... .... .... .... .... ...0 = Short not OK: False
.... .... .... .... .... .... .... ..0. = ISO ASAP: False
.... .... .... .... .... .... .... .0.. = No transfer DMA map: False
.... .... .... .... .... .... ..0. .... = No FSBR: False
.... .... .... .... .... .... .0.. .... = Zero Packet: False
.... .... .... .... .... .... 0... .... = No Interrupt: False
.... .... .... .... .... ...0 .... .... = Free Buffer: False
.... .... .... .... .... ..0. .... .... = Dir IN: False
.... .... .... ...0 .... .... .... .... = DMA Map Single: False
.... .... .... ..0. .... .... .... .... = DMA Map Page: False
.... .... .... .0.. .... .... .... .... = DMA Map SG: False
.... .... .... 0... .... .... .... .... = Map Local: False
.... .... ...0 .... .... .... .... .... = Setup Map Single: False
.... .... ..0. .... .... .... .... .... = Setup Map Local: False
.... .... .0.. .... .... .... .... .... = DMA S-G Combined: False
.... .... 0... .... .... .... .... .... = Aligned Temp Buffer: False
Number of ISO descriptors: 0
[bInterfaceClass: Unknown (0xffff)]
Setup Data
bmRequestType: 0x21
0... .... = Direction: Host-to-device
.01. .... = Type: Class (0x1)
...0 0001 = Recipient: Interface (0x01)
bRequest: 1
wValue: 0x0100
wIndex: 1792 (0x0700)
wLength: 4
Data Fragment: 00ee0200 <------------------------------
===============
The value sent 00ee0200 corresponds to 192000, but the gadget received
the original 96000 (I added some printks to g_audio):
==========
[ 1260.277857] dwc2 fe980000.usb: ep0: req 00000000cf0a7502:
4@000000000e574c90, noi=0, zero=0, snok=0
[ 1260.277865] dwc2 fe980000.usb: dwc2_hsotg_start_req:
DxEPCTL=0x00028000, ep 0, dir in
[ 1260.277870] dwc2 fe980000.usb: ureq->length:4 ureq->actual:0
[ 1260.277886] dwc2 fe980000.usb: ep0 state:1
[ 1260.277913] dwc2 fe980000.usb: req->length:4 req->actual:4 req->zero:0
[ 1260.277944] dwc2 fe980000.usb: zlp packet received
[ 1260.277948] dwc2 fe980000.usb: complete: ep 0000000018e5b31a ep0, req
00000000cf0a7502, 0 => 0000000023e79ed8
[ 1260.277984] dwc2 fe980000.usb: ureq->length:8 ureq->actual:0
[ 1260.278078] dwc2 fe980000.usb: dwc2_hsotg_epint: ep0(out)
DxEPINT=0x00000018
[ 1260.278104] dwc2 fe980000.usb: ep0: req 00000000cf0a7502:
4@000000000e574c90, noi=0, zero=0, snok=0
[ 1260.278128] dwc2 fe980000.usb: dwc2_hsotg_start_req:
0x00000000fb0cb800 => 0x00000b14
[ 1260.278163] dwc2 fe980000.usb: dwc2_hsotg_epint: XferCompl:
DxEPCTL=0x00028000, DXEPTSIZ=00000000
[ 1260.278182] g_audio gadget: Calling uac2_cs_control_sam_freq 2.
[ 1260.278186] g_audio gadget: uac2_cs_control_sam_freq val: 96000.
============
Please find attached the whole dmesg from modprobing the gadget modules
through playback of 192000.
Please let me know if you need any more logs/tests. Thank you very much
for your help.
Best regards,
Pavel.
Dne 19. 04. 21 v 18:30 Minas Harutyunyan napsal(a):
> Hi Pavel,
>
> On 4/19/2021 5:22 PM, Pavel Hofman wrote:
>>
>> Dne 11. 02. 21 v 12:21 Minas Harutyunyan napsal(a):
>>> Hi Ruslan,
>>>
>>> On 2/1/2021 3:44 AM, Ruslan Bilovol wrote:
>>>> Hi Minas and other USB experts,
>>>>
>>>> I'm currently developing new features for UAC1/UAC2 audio gadgets
>>>> like Volume/Mute controls which use Control SETUP + DATA OUT
>>>> transactions through ep0.
>>>>
>>>> While it works fine on BeagleBone black board with MUSB UDC,
>>>> on Raspberry Pi 4 with DWC2 UDC there is an issue.
>>>>
>>>> I found that when DWC2 receives ep0 SETUP + DATA OUT transaction,
>>>> it doesn't copy data transferred from the host to EP0 in DATA OUT stage
>>>> to the usb_request->buf buffer. This buffer contains unchanged data from
>>>> previous transactions.
>>>>
>>>
>>> Could you please send debug log with issue and usb trace.
>>>
>>
>> Hi Minas,
>>
>> I confirm this problem with DWC2 gadget on RPi4. I rebased Julian's
>> multiple audio clocks patch
>> https://urldefense.com/v3/__https://lore.kernel.org/patchwork/patch/803422/__;!!A4F2R9G_pg!J3zujH0Tzsp0DBsJm6EPTzG0vdr9plGNx7jmoik8JvN4NqODulvND5RXZiLE8d70RkUod4ZZ$ on top of Ruslan's
>> implicit feedback patches
>> https://urldefense.com/v3/__https://patchwork.kernel.org/project/linux-usb/list/?series=&submitter=121671&state=&q=&archive=&delegate=__;!!A4F2R9G_pg!J3zujH0Tzsp0DBsJm6EPTzG0vdr9plGNx7jmoik8JvN4NqODulvND5RXZiLE8d70Rtv_duVh$
>> on branch rpi-5.12.y
>> https://urldefense.com/v3/__https://github.com/raspberrypi/linux/tree/rpi-5.12.y__;!!A4F2R9G_pg!J3zujH0Tzsp0DBsJm6EPTzG0vdr9plGNx7jmoik8JvN4NqODulvND5RXZiLE8d70Rkqjb2Qb$ and compiled for arm64.
>>
>> When USB host switches audio playback to non-default samplerate (from
>> 96000 to 192000 in my case), usb_request->buf contains the previous
>> default value of 96000, instead of the new value sent by the host - see
>> the captured USB packet below:
>>
>> ===============
>> Frame 9: 68 bytes on wire (544 bits), 68 bytes captured (544 bits) on
>> interface usbmon1, id 0
>> Interface id: 0 (usbmon1)
>> Interface name: usbmon1
>> Encapsulation type: USB packets with Linux header and padding (115)
>> Arrival Time: Apr 19, 2021 13:41:25.146650000 CEST
>> [Time shift for this packet: 0.000000000 seconds]
>> Epoch Time: 1618832485.146650000 seconds
>> [Time delta from previous captured frame: 0.000050000 seconds]
>> [Time delta from previous displayed frame: 0.000050000 seconds]
>> [Time since reference or first frame: 6.013518000 seconds]
>> Frame Number: 9
>> Frame Length: 68 bytes (544 bits)
>> Capture Length: 68 bytes (544 bits)
>> [Frame is marked: False]
>> [Frame is ignored: False]
>> [Protocols in frame: usb]
>> USB URB
>> [Source: host]
>> [Destination: 1.14.0]
>> URB id: 0xffff8c37444f2480
>> URB type: URB_SUBMIT ('S')
>> URB transfer type: URB_CONTROL (0x02)
>> Endpoint: 0x00, Direction: OUT
>> 0... .... = Direction: OUT (0)
>> .... 0000 = Endpoint number: 0
>> Device: 14
>> URB bus id: 1
>> Device setup request: relevant (0)
>> Data: present (0)
>> URB sec: 1618832485
>> URB usec: 146650
>> URB status: Operation now in progress (-EINPROGRESS) (-115)
>> URB length [bytes]: 4
>> Data length [bytes]: 4
>> [Response in: 10]
>> Interval: 0
>> Start frame: 0
>> Copy of Transfer Flags: 0x00000000
>> .... .... .... .... .... .... .... ...0 = Short not OK: False
>> .... .... .... .... .... .... .... ..0. = ISO ASAP: False
>> .... .... .... .... .... .... .... .0.. = No transfer DMA map: False
>> .... .... .... .... .... .... ..0. .... = No FSBR: False
>> .... .... .... .... .... .... .0.. .... = Zero Packet: False
>> .... .... .... .... .... .... 0... .... = No Interrupt: False
>> .... .... .... .... .... ...0 .... .... = Free Buffer: False
>> .... .... .... .... .... ..0. .... .... = Dir IN: False
>> .... .... .... ...0 .... .... .... .... = DMA Map Single: False
>> .... .... .... ..0. .... .... .... .... = DMA Map Page: False
>> .... .... .... .0.. .... .... .... .... = DMA Map SG: False
>> .... .... .... 0... .... .... .... .... = Map Local: False
>> .... .... ...0 .... .... .... .... .... = Setup Map Single: False
>> .... .... ..0. .... .... .... .... .... = Setup Map Local: False
>> .... .... .0.. .... .... .... .... .... = DMA S-G Combined: False
>> .... .... 0... .... .... .... .... .... = Aligned Temp Buffer: False
>> Number of ISO descriptors: 0
>> [bInterfaceClass: Unknown (0xffff)]
>> Setup Data
>> bmRequestType: 0x21
>> 0... .... = Direction: Host-to-device
>> .01. .... = Type: Class (0x1)
>> ...0 0001 = Recipient: Interface (0x01)
>> bRequest: 1
>> wValue: 0x0100
>> wIndex: 1792 (0x0700)
>> wLength: 4
>> Data Fragment: 00ee0200 <------------------------------
>> ===============
>>
>>
Hi Minas,
> Some clarifications required:
> 1. gadget works in scatter/gather DMA mode (g_dma_desc is true)?
I guess not, this is /sys/kernel/debug/usb/fe980000.usb/params:
otg_cap : 0
dma_desc_enable : 0
dma_desc_fs_enable : 0
speed : 0
enable_dynamic_fifo : 1
en_multiple_tx_fifo : 1
host_rx_fifo_size : 774
host_nperio_tx_fifo_size : 256
host_perio_tx_fifo_size : 512
max_transfer_size : 65535
max_packet_count : 511
host_channels : 8
phy_type : 1
phy_utmi_width : 8
phy_ulpi_ddr : 0
phy_ulpi_ext_vbus : 0
i2c_enable : 0
ipg_isoc_en : 0
ulpi_fs_ls : 0
host_support_fs_ls_low_power : 0
host_ls_low_power_phy_clk : 0
ts_dline : 0
reload_ctl : 0
ahbcfg : 0x10
uframe_sched : 1
external_id_pin_ctl : 0
power_down : 0
lpm : 0
lpm_clock_gating : 0
besl : 0
hird_threshold_en : 0
hird_threshold : 0
service_interval : 0
host_dma : 1
g_dma : 1
g_dma_desc : 0
g_rx_fifo_size : 558
g_np_tx_fifo_size : 32
g_tx_fifo_size[0] : 0
g_tx_fifo_size[1] : 512
g_tx_fifo_size[2] : 512
g_tx_fifo_size[3] : 512
g_tx_fifo_size[4] : 512
g_tx_fifo_size[5] : 512
g_tx_fifo_size[6] : 256
g_tx_fifo_size[7] : 256
g_tx_fifo_size[8] : 0
g_tx_fifo_size[9] : 0
g_tx_fifo_size[10] : 0
g_tx_fifo_size[11] : 0
g_tx_fifo_size[12] : 0
g_tx_fifo_size[13] : 0
g_tx_fifo_size[14] : 0
g_tx_fifo_size[15] : 0
Also /sys/kernel/debug/usb/fe980000.usb/regdump attached.
> 2. Above captured Host side USB packet corresponds in dmesg to line#39907:
>
> [ 1261.789552] dwc2 fe980000.usb: ctrl Type=21, Req=01, V=0100, I=0700,
> L=0004
>
> Correct?
I think more likely from line #2319 - the value 96000 should be 192000
instead.
[ 1260.277683] dwc2 fe980000.usb: dwc2_hsotg_start_req:
DxEPCTL=0x00028000, ep 0, dir out
[ 1260.277690] dwc2 fe980000.usb: ureq->length:8 ureq->actual:0
[ 1260.277696] dwc2 fe980000.usb: dwc2_hsotg_start_req: 1@8/8,
0x00080008 => 0x00000b10
[ 1260.277702] dwc2 fe980000.usb: dwc2_hsotg_start_req:
0x00000000fb0ca000 => 0x00000b14
[ 1260.277707] dwc2 fe980000.usb: ep0 state:0
[ 1260.277711] dwc2 fe980000.usb: dwc2_hsotg_start_req: DxEPCTL=0x80028000
[ 1260.277718] dwc2 fe980000.usb: dwc2_hsotg_start_req: DXEPCTL=0x80028000
[ 1260.277806] dwc2 fe980000.usb: dwc2_hsotg_irq: 040c8028 000c0000
(d0bc3cc4) retry 8
[ 1260.277813] dwc2 fe980000.usb: dwc2_hsotg_irq: daint=00010001
[ 1260.277818] dwc2 fe980000.usb: dwc2_hsotg_epint: ep0(out)
DxEPINT=0x00000008
[ 1260.277823] dwc2 fe980000.usb: dwc2_hsotg_epint: Setup/Timeout
[ 1260.277831] dwc2 fe980000.usb: complete: ep 0000000018e5b31a ep0, req
00000000432c9718, 0 => 000000002d523fc0
[ 1260.277839] dwc2 fe980000.usb: ctrl Type=a1, Req=01, V=0100, I=0700,
L=0004
[ 1260.277846] g_audio gadget: ac_rq_in(): 1
[ 1260.277850] g_audio gadget: in_rq_cur(): 96000
[ 1260.277857] dwc2 fe980000.usb: ep0: req 00000000cf0a7502:
4@000000000e574c90, noi=0, zero=0, snok=0
[ 1260.277865] dwc2 fe980000.usb: dwc2_hsotg_start_req:
DxEPCTL=0x00028000, ep 0, dir in
[ 1260.277870] dwc2 fe980000.usb: ureq->length:4 ureq->actual:0
[ 1260.277886] dwc2 fe980000.usb: ep0 state:1
[ 1260.277913] dwc2 fe980000.usb: req->length:4 req->actual:4 req->zero:0
[ 1260.277944] dwc2 fe980000.usb: zlp packet received
[ 1260.277948] dwc2 fe980000.usb: complete: ep 0000000018e5b31a ep0, req
00000000cf0a7502, 0 => 0000000023e79ed8
[ 1260.277984] dwc2 fe980000.usb: ureq->length:8 ureq->actual:0
[ 1260.278078] dwc2 fe980000.usb: dwc2_hsotg_epint: ep0(out)
DxEPINT=0x00000018
[ 1260.278104] dwc2 fe980000.usb: ep0: req 00000000cf0a7502:
4@000000000e574c90, noi=0, zero=0, snok=0
[ 1260.278128] dwc2 fe980000.usb: dwc2_hsotg_start_req:
0x00000000fb0cb800 => 0x00000b14
[ 1260.278163] dwc2 fe980000.usb: dwc2_hsotg_epint: XferCompl:
DxEPCTL=0x00028000, DXEPTSIZ=00000000
[ 1260.278182] g_audio gadget: Calling uac2_cs_control_sam_freq 2.
[ 1260.278186] g_audio gadget: uac2_cs_control_sam_freq val: 96000.
[ 1260.278190] g_audio gadget: Calling uac2_cs_control_sam_freq OUT.
>
> 3. You assume that issue seen in below printk's (lines##39923-39927):
Maybe this part later in the dmesg dump is switching back to the default
96000 after playback stops, I am sorry for my lack of USB protocol
knowledge.
But lines starting at #2319 correspond to the SETUP packet with 192000
value.
>
> [ 1261.789640] g_audio gadget: Calling uac2_cs_control_sam_freq 1.
> [ 1261.789652] g_audio gadget: Calling uac2_cs_control_sam_freq 2.
> [ 1261.789655] g_audio gadget: uac2_cs_control_sam_freq val: 96000.
> [ 1261.789659] g_audio gadget: Calling uac2_cs_control_sam_freq OUT.
> [ 1261.789665] Calling u_audio_set_capture_srate with srate 96000
>
> Instead both 96000 should be 192000? Could you please provide me
> messages sequence for correct behaviour for 192000.
I am afraid I do not know how to do that. The host sends 192000 but the
gadget function receives 96000. When stopping playback and starting at
96000, again 96000 is received. When going back to 192000, again 96000
is received.
>
> 4. Below dmesg fragment not corresponds to observed issue, it's just for
> show added printk's in g_audio. Correct?
It's the same sequence I listed in point 1 of this message. It shows the
observed issue.
My wireshark packet was captured in an earlier run, therefore some
possible packet IDs (if any exist) would not fit with the dump. But it
is the same observed situation - the packet carries 192000, yet f_uac2
->u_audio receive 96000.
I pushed my current source code with all the rebased patches to
https://github.com/pavhofman/linux-rpi/tree/fb5afcec549a998cafe9e0d11534400f508d8be3
for reference.
The function receiving incorrect value is
https://github.com/pavhofman/linux-rpi/blob/fb5afcec549a998cafe9e0d11534400f508d8be3/drivers/usb/gadget/function/f_uac2.c#L1476
, registered in req->complete callback in
https://github.com/pavhofman/linux-rpi/blob/fb5afcec549a998cafe9e0d11534400f508d8be3/drivers/usb/gadget/function/f_uac2.c#L1573
Thanks a lot!
Pavel.
>
> Thanks,
> Minas
>
>
>> The value sent 00ee0200 corresponds to 192000, but the gadget received
>> the original 96000 (I added some printks to g_audio):
>>
>> ==========
>> [ 1260.277857] dwc2 fe980000.usb: ep0: req 00000000cf0a7502:
>> 4@000000000e574c90, noi=0, zero=0, snok=0
>> [ 1260.277865] dwc2 fe980000.usb: dwc2_hsotg_start_req:
>> DxEPCTL=0x00028000, ep 0, dir in
>> [ 1260.277870] dwc2 fe980000.usb: ureq->length:4 ureq->actual:0
>> [ 1260.277886] dwc2 fe980000.usb: ep0 state:1
>> [ 1260.277913] dwc2 fe980000.usb: req->length:4 req->actual:4 req->zero:0
>> [ 1260.277944] dwc2 fe980000.usb: zlp packet received
>> [ 1260.277948] dwc2 fe980000.usb: complete: ep 0000000018e5b31a ep0, req
>> 00000000cf0a7502, 0 => 0000000023e79ed8
>> [ 1260.277984] dwc2 fe980000.usb: ureq->length:8 ureq->actual:0
>> [ 1260.278078] dwc2 fe980000.usb: dwc2_hsotg_epint: ep0(out)
>> DxEPINT=0x00000018
>> [ 1260.278104] dwc2 fe980000.usb: ep0: req 00000000cf0a7502:
>> 4@000000000e574c90, noi=0, zero=0, snok=0
>> [ 1260.278128] dwc2 fe980000.usb: dwc2_hsotg_start_req:
>> 0x00000000fb0cb800 => 0x00000b14
>> [ 1260.278163] dwc2 fe980000.usb: dwc2_hsotg_epint: XferCompl:
>> DxEPCTL=0x00028000, DXEPTSIZ=00000000
>> [ 1260.278182] g_audio gadget: Calling uac2_cs_control_sam_freq 2.
>> [ 1260.278186] g_audio gadget: uac2_cs_control_sam_freq val: 96000.
>> ============
>>