I have a Variscite DART-MX8M evaluation board that I'm trying to use as a USB gadget, so I've written a user-mode gadget driver which talks to gadgetfs (mounted on /dev/gadget). It always returns a device descriptor to the host machine, but sometimes fails when responding to a requests for a string descriptor. The symptom is that when I write the string back to endpoint 0, I get EBUSY; it doesn't help to retry, as the subsequent attempt gets ESRCH.
It doesn't happen on the first request for the string descriptor, as you see lower down where the host gets the manufacturer and vendor (via udev rules, I think) but lsusb fails to retrieve them. But when it does fail, it's always at the same point in the execution.
I've done some print-tracing in the kernel (5.4.85, Variscite's "Dunfell" release) and found where the EBUSY originates:
/* we share one TRB for ep0/1 */ if (!list_empty(&dep->pending_list)) { ret = -EBUSY; goto out; }
But I don't understand why we might hit this.
I made the simplest driver I could to reproduce this - it has just one configuration, with no endpoints (not counting ep0):
#include <linux/usb/ch9.h>
#include <linux/usb/gadgetfs.h>
#include <fcntl.h>
#include <unistd.h>
#include <errno.h>
#include <stdint.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#define USB_DEV "/dev/gadget/dwc3-gadget"
enum string_id {
STRINGID_MANUFACTURER = 1,
STRINGID_PRODUCT,
STRINGID_SERIAL,
};
static const char *get_string_descriptor(enum string_id sid)
{
static const char mfr[] = { 10, USB_DT_STRING, 84, 0, 111, 0, 98, 0, 121, 0};
static const char prod[] = { 16, USB_DT_STRING, 119, 0, 105, 0, 100, 0, 103, 0, 101, 0, 116, 0};
static const char ser[] = { 8, USB_DT_STRING, 118, 0, 49, 0};
switch (sid) {
case STRINGID_MANUFACTURER:
return mfr;
case STRINGID_PRODUCT:
return prod;
case STRINGID_SERIAL:
return ser;
}
static const char fallback[] = { 20, USB_DT_STRING, 40, 0, 109, 0, 105, 0,
115, 0, 115, 0, 105, 0, 110, 0, 103, 0, 41, 0 };
return fallback;
}
static int write_string_descriptor(int fd, enum string_id sid) {
const char *buf = get_string_descriptor(sid);
return write(fd, buf, buf[0]);
}
static void handle_setup_request(int fd, struct usb_ctrlrequest* setup)
{
int status;
uint8_t buffer[512];
pthread_t thread;
printf("Setup request %d\n", setup->bRequest);
switch (setup->bRequest) {
case USB_REQ_GET_DESCRIPTOR:
if (setup->bRequestType != USB_DIR_IN)
goto stall;
switch (setup->wValue >> 8) {
case USB_DT_STRING:
printf("Get string id #%d(max length %d)\n", setup->wValue & 0xff,
setup->wLength);
status = write_string_descriptor(fd, setup->wValue & 0xff);
// Error
if (status < 0) {
fprintf(stderr, "Failed to write string descriptor %d\n", setup->wValue & 0xff);
}
return;
default:
fprintf(stderr, "Cannot return descriptor %d\n", (setup->wValue >> 8));
}
break;
case USB_REQ_SET_CONFIGURATION:
printf("Ignoring configuration value %d\n", setup->wValue);
// Just ACK
status = read(fd, &status, 0);
return;
case USB_REQ_GET_INTERFACE:
printf("GET_INTERFACE\n");
buffer[0] = 0;
write(fd, buffer, 1);
return;
case USB_REQ_SET_INTERFACE:
printf("SET_INTERFACE\n");
// ACK
status = read(fd, &status, 0);
return;
}
stall:
fprintf(stderr, "Stalled\n");
// Error
if (setup->bRequestType & USB_DIR_IN)
read (fd, &status, 0);
else
write (fd, &status, 0);
}
static void handle_ep0(int fd)
{
while (1) {
struct usb_gadgetfs_event events[5];
int readsize = read(fd, &events, sizeof events);
if (readsize < 0) {
fprintf(stderr, "Read error %d(%m)\n", readsize);
return;
}
const int nevents = readsize / sizeof events[0];
int surplus = readsize % sizeof events[0];
printf("%d event(s) and %d extra\n", nevents, surplus);
for (int i = 0; i < nevents; ++i) {
switch (events[i].type) {
case GADGETFS_CONNECT:
printf("EP0 CONNECT\n");
break;
case GADGETFS_DISCONNECT:
printf("EP0 DISCONNECT\n");
break;
case GADGETFS_SETUP:
printf("EP0 SETUP\n");
handle_setup_request(fd, &events[i].u.setup);
break;
case GADGETFS_NOP:
case GADGETFS_SUSPEND:
break;
}
}
}
}
int main()
{
const int fd = open(USB_DEV, O_RDWR|O_SYNC|O_EXCL);
if (fd < 0) {
fprintf(stderr, "Unable to open %s(%m)\n", USB_DEV);
return EXIT_FAILURE;
}
const struct usb_device_descriptor device_descriptor =
{ .bLength = USB_DT_DEVICE_SIZE,
.bDescriptorType = USB_DT_DEVICE,
.bDeviceClass = USB_CLASS_COMM,
.bDeviceSubClass = 0,
.bDeviceProtocol = 0,
.idVendor = 0xAA00, // Fake vendor ID
.idProduct = 0xBB, // Fake product ID
.bcdDevice = 0x0200, // Version
.iManufacturer = STRINGID_MANUFACTURER,
.iProduct = STRINGID_PRODUCT,
.iSerialNumber = STRINGID_SERIAL,
.bNumConfigurations = 1
};
const struct usb_interface_descriptor if_descriptor = {
.bLength = sizeof if_descriptor,
.bDescriptorType = USB_DT_INTERFACE,
.bInterfaceNumber = 0,
.bAlternateSetting = 0,
.bNumEndpoints = 2,
.bInterfaceClass = USB_CLASS_COMM,
.bInterfaceSubClass = 0,
.bInterfaceProtocol = 0,
.iInterface = 0
};
const struct usb_config_descriptor config = {
.bLength = sizeof config,
.bDescriptorType = USB_DT_CONFIG,
.wTotalLength = sizeof config + sizeof if_descriptor,
.bNumInterfaces = 1,
.bConfigurationValue = 1,
.iConfiguration = 0,
.bmAttributes = USB_CONFIG_ATT_ONE | USB_CONFIG_ATT_SELFPOWER,
.bMaxPower = 1
};
uint8_t init_config[2048];
uint8_t* p = init_config;
printf("Start init\n");
*p++ = 0;
*p++ = 0;
*p++ = 0;
*p++ = 0;
#define FETCH(desc) \
memcpy(p, &desc, desc.bLength); \
p += desc.bLength;
FETCH(config);
FETCH(if_descriptor);
FETCH(config); /* again for a high-speed i/f */
FETCH(if_descriptor);
FETCH(device_descriptor);
// Configure ep0
int send_size = p - init_config;
int sent = write(fd, init_config, send_size);
if (sent != send_size) {
fprintf(stderr, "Write error %d/%d (%m)\n", sent/send_size);
return EXIT_FAILURE;
}
printf("ep0 configured\n");
handle_ep0(fd);
}
Without changing the code, I unpredictably get two different results as seen from a Linux host using lsusb -v -d aa00:00bb. When it works, I get:
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 2.00
bDeviceClass 2 Communications
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 64
idVendor 0xaa00
idProduct 0x00bb
bcdDevice 2.00
iManufacturer 1 Toby
iProduct 2 widget
iSerial 3 v1
bNumConfigurations 1
Device Qualifier (for other device speed):
bLength 10
bDescriptorType 6
bcdUSB 2.00
bDeviceClass 2 Communications
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 64
bNumConfigurations 1
Device Status: 0x0000
(Bus Powered)
And when it fails:
Bus 001 Device 027: ID aa00:00bb Toby widget
Device Descriptor:
bLength 18
bDescriptorType 1
bcdUSB 2.00
bDeviceClass 2 Communications
bDeviceSubClass 0
bDeviceProtocol 0
bMaxPacketSize0 64
idVendor 0xaa00
idProduct 0x00bb
bcdDevice 2.00
iManufacturer 1 (error)
iProduct 2 (error)
iSerial 3 (error)
bNumConfigurations 1
And it won't work again until I unload the dwc3 driver and re-load it.
Here's the relevant kernel log messages for the failing case (I enabled CONFIG_USB_GADGET_VERBOSE to get these):
[342748.061482] gadgetfs: bound to dwc3-gadget driver [342748.066303] gadgetfs: bound to gadget device [342748.071482] gadgetfs: ep0_read wait [342748.344072] gadgetfs: connected [342748.347308] gadgetfs: event[0] = 1 [342748.347929] gadgetfs: ep0_read wait [342748.352265] gadgetfs: disconnected [342748.355755] gadgetfs: event[0] = 2 [342748.356315] gadgetfs: ep0_read wait [342748.504041] gadgetfs: connected [342748.507269] gadgetfs: event[0] = 1 [342748.507842] gadgetfs: ep0_read wait [342748.510596] gadgetfs: delegate req80.06 v0300 i0000 l255 [342748.510600] gadgetfs: event[0] = 3 [342748.511208] gadgetfs: usb_ep_queue returned 0 [342748.511213] gadgetfs: ep0_read wait [342748.511557] gadgetfs: delegate req80.06 v0302 i0028 l255 [342748.511563] gadgetfs: event[0] = 3 [342748.511630] gadgetfs: usb_ep_queue returned 0 [342748.511635] gadgetfs: ep0_read wait [342748.511934] gadgetfs: delegate req80.06 v0301 i0028 l255 [342748.511940] gadgetfs: event[0] = 3 [342748.511989] gadgetfs: usb_ep_queue returned 0 [342748.511995] gadgetfs: ep0_read wait [342748.512181] gadgetfs: delegate req80.06 v0303 i0028 l255 [342748.512187] gadgetfs: event[0] = 3 [342748.512232] gadgetfs: usb_ep_queue returned 0 [342748.512238] gadgetfs: ep0_read wait [342748.512711] gadgetfs: configuration #1 [342748.516551] gadgetfs: event[0] = 3 [342748.517139] gadgetfs: ep0_read wait [342748.953968] gadgetfs: delegate req80.06 v0300 i0000 l4 [342748.953974] gadgetfs: event[0] = 3 [342748.954544] dwc3 38100000.usb: ep0out: pending_list empty [342748.960062] gadgetfs: usb_ep_queue returned -16 [342748.960108] gadgetfs: ep0_read wait
(The line from dwc is the one I added to the ret = -EBUSY shown above).
A Wireshark trace perhaps points the finger at SET_CONFIGURATION, as it all works until that point:
No. Time delta Source Length Info Descriptor no
1 0.000000 0.000000 host 64 GET DESCRIPTOR Request DEVICE 0x00
2 0.004048 0.004048 1.113.0 82 GET DESCRIPTOR Response DEVICE
3 0.004074 0.000026 host 64 GET DESCRIPTOR Request CONFIGURATION 0x00
4 0.004669 0.000595 1.113.0 73 GET DESCRIPTOR Response CONFIGURATION
5 0.004682 0.000013 host 64 GET DESCRIPTOR Request CONFIGURATION 0x00
6 0.005918 0.001236 1.113.0 110 GET DESCRIPTOR Response CONFIGURATION
7 0.005948 0.000030 host 64 GET DESCRIPTOR Request STRING 0x00
8 0.570791 0.564843 1.113.0 68 GET DESCRIPTOR Response STRING
9 0.570822 0.000031 host 64 GET DESCRIPTOR Request STRING 0x02
10 0.571913 0.001091 1.113.0 86 GET DESCRIPTOR Response STRING
11 0.571933 0.000020 host 64 GET DESCRIPTOR Request STRING 0x01
12 0.572662 0.000729 1.113.0 84 GET DESCRIPTOR Response STRING
13 0.572680 0.000018 host 64 GET DESCRIPTOR Request STRING 0x03
14 0.573539 0.000859 1.113.0 98 GET DESCRIPTOR Response STRING
15 0.573806 0.000267 host 64 SET CONFIGURATION Request
16 0.578297 0.004491 1.113.0 64 SET CONFIGURATION Response
17 0.578325 0.000028 host 64 GET DESCRIPTOR Request STRING 0x04
18 5.703230 5.124905 1.113.0 64 GET DESCRIPTOR Response
19 5.703244 0.000014 host 64 GET DESCRIPTOR Request STRING 0x04
20 10.823171 5.119927 1.113.0 64 GET DESCRIPTOR Response
What could be causing this failure, and what do I need to do to avert it?
