ESP32S3 usb_host_cdc_acm Bad transfer status: CHECK_FULL_DEV_DESC (IDFGH-9036)

[barbiani]

Answers checklist.

• I have read the documentation ESP-IDF Programming Guide and the issue is not addressed there.
• I have updated my IDF branch (master or release) to the latest version and checked that the issue is present there.
• I have searched the issue tracker for a similar issue and not found a similar issue.

IDF version.

v5.0

Operating System used.

Windows

How did you build your project?

VS Code IDE

If you are using Windows, please specify command line type.

None

Development Kit.

ESP32-S3-DevKitC-1 v1.1

Power Supply used.

USB

What is the expected behavior?

Enumerate cdc acm device (pico rp2040) of pid:vid 0x000A:0x2E8A as per the example.

Device correctly enumerates and communicates on windows 11.

USB connection between the esp32 and the device seems to be fine because msc on the same device is working (and running another example).

What is the actual behavior?

Currently not finding the cdc acm device.

I (345) USB-CDC: Opening CDC ACM device 0x2E8A:0x000A
E (715) HUB: Bad transfer status: CHECK_FULL_DEV_DESC
E (715) HUB: Stage failed: CHECK_FULL_DEV_DESC
ESP_ERROR_CHECK failed: esp_err_t 0x105 (ESP_ERR_NOT_FOUND) at 0x4200844d

Steps to reproduce.

Flash example

Connect esp32s3 dp and dm to rp2040 (running the cdc acm stdio example) dp and dm.

Debug Logs.

I (0) cpu_start: App cpu up.
I (209) cpu_start: Pro cpu start user code
I (209) cpu_start: cpu freq: 160000000 Hz
I (209) cpu_start: Application information:
I (212) cpu_start: Project name:     usb-host
I (217) cpu_start: App version:      f8f7a4b-dirty
I (222) cpu_start: Compile time:     Dec 26 2022 18:39:43
I (228) cpu_start: ELF file SHA256:  fed41d198db243ff...
I (234) cpu_start: ESP-IDF:          v5.0-dirty
I (240) heap_init: Initializing. RAM available for dynamic allocation:
I (247) heap_init: At 3FC955C0 len 00054150 (336 KiB): D/IRAM
I (253) heap_init: At 3FCE9710 len 00005724 (21 KiB): STACK/DRAM
I (260) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (266) heap_init: At 600FE010 len 00001FF0 (7 KiB): RTCRAM
I (273) spi_flash: detected chip: generic
I (277) spi_flash: flash io: dio
W (281) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.       
I (295) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (315) USB-CDC: Installing USB Host
I (345) USB-CDC: Installing CDC-ACM driver
I (345) USB-CDC: Opening CDC ACM device 0x2E8A:0x000A
E (715) HUB: Bad transfer status: CHECK_FULL_DEV_DESC
E (715) HUB: Stage failed: CHECK_FULL_DEV_DESC
E (5345) cdc_acm: cdc_acm_host_open(719): USB device with VID: 0x2E8A, PID: 0x000A not found
ESP_ERROR_CHECK failed: esp_err_t 0x105 (ESP_ERR_NOT_FOUND) at 0x4200844d
0x4200844d: app_main at /main/cdc.c:66 (discriminator 1)

file: "./main/cdc.c" line 66
func: app_main
expression: cdc_acm_host_open(EXAMPLE_USB_DEVICE_VID, EXAMPLE_USB_DEVICE_PID, 0, &dev_config, &cdc_dev)

abort() was called at PC 0x40379ceb on core 0
0x40379ceb: _esp_error_check_failed at C:/esp/esp-idf/components/esp_system/esp_err.c:47
Backtrace: 0x40375d3e:0x3fcf39d0 0x40379cf5:0x3fcf39f0 0x4038001a:0x3fcf3a10 0x40379ceb:0x3fcf3a80 0x4200844d:0x3fcf3ab0 0x42022793:0x3fcf3b00 0x4037ce8d:0x3fcf3b30
0x40375d3e: panic_abort at C:/esp/esp-idf/components/esp_system/panic.c:412
0x40379cf5: esp_system_abort at C:/esp/esp-idf/components/esp_system/esp_system.c:135
0x4038001a: abort at C:/esp/esp-idf/components/newlib/abort.c:38
0x40379ceb: _esp_error_check_failed at C:/esp/esp-idf/components/esp_system/esp_err.c:47
0x4200844d: app_main at C:/main/cdc.c:66 (discriminator 1)
0x42022793: main_task at C:/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/port_common.c:131 (discriminator 2)
0x4037ce8d: vPortTaskWrapper at C:/esp/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:151

ELF file SHA256: fed41d198db243ff
Rebooting...

More Information.

No response

[barbiani]

Plugging in the rp2040 as msc:

I (2351) USB-CDC: Installing CDC-ACM driver
I (2351) USB-CDC: Opening CDC ACM device 0x2E8A:0x000A
E (7351) cdc_acm: cdc_acm_host_open(719): USB device with VID: 0x2E8A, PID: 0x000A not found

And as cdc acm right after ESP_ERROR_CHECK(usb_host_install(&host_config));:

I (2351) USB-CDC: Opening CDC ACM device 0x2E8A:0x000A
E (2721) HUB: Bad transfer status: CHECK_FULL_DEV_DESC
E (2721) HUB: Stage failed: CHECK_FULL_DEV_DESC

Saleae logic analyzer capture attached if it helps.

usb enum.zip

[tore-espressif]

Hello @barbiani this bug was fixed in master branch. Could you please try again?

[Dazza0]

@barbiani Thanks for the logic analyzer capture. From the capture, it looks your device is not acknowledge the setup packets of the "Get Device Descriptor" control transfer However, the previous "Set Address" control transfer was successful.

On the "Get Device Descriptor" control transfer, the Host is sending the setup packet, but the device not acknowledge this packet. The Host retries the setup packet 3 times before reporting back that the transfer has failed.

Maybe the device needs more time after the "Set Address" request before it starts responding to control transfers on its newly assigned address? Could you try adding a short delay before the "Get Device Descriptor" stage as follows and see if that resolves the issue (link to code).

// In hcd.c
#include "freertos/task.h"

...

        case ENUM_STAGE_GET_FULL_DEV_DESC: {
            // Add a short delay here
            vTaskDelay(pdMS_TO_TICKS(500));
            USB_SETUP_PACKET_INIT_GET_DEVICE_DESC((usb_setup_packet_t *)transfer->data_buffer);
            ....
        }

[oliverschmidt]

I have exactly the same scenario and had exactly the same issue. I can't assess if the suggested delay is to be classified as workaround or as fix. Anyhow, it solves the issue for me.

[Dazza0]

@oliverschmidt @barbiani We just double checked the USB2.0 specification. The delay is actually required (thus the lack of delay turns out to be a bug).

Quoting from section 9.2.6.3 Set Address Processing

After successful completion of the Status stage, the device is allowed a SetAddress() recovery interval of 2 ms. At the end of this interval, the device must be able to accept Setup packets addressed to the new address.

We'll add a fix for this.

[oliverschmidt]

Thanks :-)