espressif / esp-idf

Espressif IoT Development Framework. Official development framework for Espressif SoCs.
Apache License 2.0
13.32k stars 7.2k forks source link

ESP32-S3 USB Host CDC Generic (IDFGH-13439) #14345

Closed antunesls closed 4 weeks ago

antunesls commented 1 month ago

Answers checklist.

General issue report

Hi,

I have tried all available examples in ESP-IDF related to USB communication, including both the Host CDC and Host USB libraries, but I am unable to establish communication with my UPS device.

I can successfully communicate with other devices using known drivers like CP210x, but I am struggling with my Ragtech Easy Pro 1200 UPS, which uses a generic driver.

Here is the output of the dmesg | tail command from Linux with my UPS connected:

[ 7855.208112] usb 1-1.3: new full-speed USB device number 3 using xhci_hcd [ 7855.320032] usb 1-1.3: New USB device found, idVendor=04d8, idProduct=000a, bcdDevice= 1.00 [ 7855.320049] usb 1-1.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ 7855.320055] usb 1-1.3: Product: USB Serial Port [ 7855.320059] usb 1-1.3: Manufacturer: Ragtech Sistemas de Energia [ 7855.419658] cdc_acm 1-1.3:1.0: ttyACM0: USB ACM device [ 7855.419897] usbcore: registered new interface driver cdc_acm [ 7855.419902] cdc_acm: USB Abstract Control Model driver for USB modems and ISDN adapters

Despite this, I am unable to establish serial communication with the UPS from the ESP32-S3.

I have been attempting to resolve this issue for a month without success. I have also tried using MicroPython and TinyUSB with no results.

Any assistance or guidance on how to resolve this issue would be greatly appreciated.

Thank you.

roma-jam commented 1 month ago

Hi @antunesls ,

Thanks for reporting the problem.

Could you specify the issue which prevents the Host CDC and USB Host libraries to communicate with the device?

If that is possible, share the debug output log with verbosity level=VERBOSE (can be changed via idf.py menuconfig) for:

  1. usb/host/cdc/* example you are using
  2. usb/host/usb_host_lib example for your device

Thanks.

antunesls commented 1 month ago

I'm using USB CDC-ACM Host Driver Example

For some reason the device take a few seconds more than others to connect, I just have to wait :? .

Now its connecting but shows up a buffer error.

My buffer is set to 4096 in the code and in the menuconfig. (CONFIG_USB_HOST_CONTROL_TRANSFER_MAX_SIZE=4096)

usb_cdc_example_main.zip

ESP-ROM:esp32s3-20210327 Build:Mar 27 2021 rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT) SPIWP:0xee mode:DIO, clock div:1 load:0x3fce2810,len:0x178c load:0x403c8700,len:0x4 load:0x403c8704,len:0xcb8 load:0x403cb700,len:0x2db0 entry 0x403c8914 I (27) boot: ESP-IDF v5.3 2nd stage bootloader

I (27) boot: compile time Aug 10 2024 12:23:54 I (27) boot: Multicore bootloader I (30) boot: chip revision: v0.2 I (34) boot.esp32s3: Boot SPI Speed : 80MHz I (38) boot.esp32s3: SPI Mode : DIO I (43) boot.esp32s3: SPI Flash Size : 2MB I (48) boot: Enabling RNG early entropy source... I (53) boot: Partition Table: I (57) boot: ## Label Usage Type ST Offset Length I (64) boot: 0 nvs WiFi data 01 02 00009000 00006000 I (71) boot: 1 phy_init RF data 01 01 0000f000 00001000 I (79) boot: 2 factory factory app 00 00 00010000 00100000 I (86) boot: End of partition table I (91) esp_image: segment 0: paddr=00010020 vaddr=3c030020 size=0c954h ( 51540) map I (108) esp_image: segment 1: paddr=0001c97c vaddr=3fc92b00 size=02904h ( 10500) load I (111) esp_image: segment 2: paddr=0001f288 vaddr=40374000 size=00d90h ( 3472) load I (117) esp_image: segment 3: paddr=00020020 vaddr=42000020 size=21c44h (138308) map I (149) esp_image: segment 4: paddr=00041c6c vaddr=40374d90 size=0dca8h ( 56488) load I (168) boot: Loaded app from partition at offset 0x10000 I (168) boot: Disabling RNG early entropy source... I (180) cpu_start: Multicore app I (189) cpu_start: Pro cpu start user code I (189) cpu_start: cpu freq: 160000000 Hz I (189) app_init: Application information: I (192) app_init: Project name: cdc-host-example I (198) app_init: App version: 1 I (202) app_init: Compile time: Aug 10 2024 14:04:58 I (208) app_init: ELF file SHA256: 4454c768a... I (213) app_init: ESP-IDF: v5.3 I (218) efuse_init: Min chip rev: v0.0 I (223) efuse_init: Max chip rev: v0.99 I (228) efuse_init: Chip rev: v0.2 I (232) heap_init: Initializing. RAM available for dynamic allocation: I (240) heap_init: At 3FC95C78 len 00053A98 (334 KiB): RAM I (246) heap_init: At 3FCE9710 len 00005724 (21 KiB): RAM I (252) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM I (258) heap_init: At 600FE100 len 00001EE8 (7 KiB): RTCRAM I (265) spi_flash: detected chip: winbond I (269) spi_flash: flash io: dio W (273) spi_flash: Detected size(16384k) larger than the size in the binary image header(2048k). Using the size in the binary image header. I (286) sleep: Configure to isolate all GPIO pins in sleep state I (293) sleep: Enable automatic switching of GPIO sleep configuration I (300) main_task: Started on CPU0 I (310) main_task: Calling app_main() I (310) USB-CDC: Instalando USB Host I (340) USB-CDC: Instalando driver CDC-ACM I (340) USB-CDC: Abrindo dispositivo CDC ACM 0x04D8:0x000A... E (440) cdc_acm: cdc_acm_host_open(731): USB device with VID: 0x04D8, PID: 0x000A not found I (440) USB-CDC: Falha ao abrir dispositivo I (440) USB-CDC: Abrindo dispositivo CDC ACM 0x04D8:0x000A... E (540) cdc_acm: cdc_acm_host_open(731): USB device with VID: 0x04D8, PID: 0x000A not found I (540) USB-CDC: Falha ao abrir dispositivo I (540) USB-CDC: Abrindo dispositivo CDC ACM 0x04D8:0x000A... E (640) cdc_acm: cdc_acm_host_open(731): USB device with VID: 0x04D8, PID: 0x000A not found I (640) USB-CDC: Falha ao abrir dispositivo I (640) USB-CDC: Abrindo dispositivo CDC ACM 0x04D8:0x000A... E (740) cdc_acm: cdc_acm_host_open(731): USB device with VID: 0x04D8, PID: 0x000A not found I (740) USB-CDC: Falha ao abrir dispositivo I (740) USB-CDC: Abrindo dispositivo CDC ACM 0x04D8:0x000A... E (750) USBH: usb_transfer_t num_bytes > data_buffer_size E (750) cdc_acm: cdc_acm_host_send_custom_request(1257): CTRL transfer failed E (760) cdc_acm: cdc_acm_host_line_coding_set(1196): ESP_ERROR_CHECK failed: esp_err_t 0x102 (ESP_ERR_INVALID_ARG) at 0x4200752a 0x4200752a: app_main at C:/Users/lukss/cdc-host-example/main/usb_cdc_example_main.c:218 (discriminator 1)

file: "./main/usb_cdc_example_main.c" line 218 func: app_main expression: cdc_acm_host_line_coding_set(cdc_dev, &line_coding)

abort() was called at PC 0x40379bd7 on core 0 0x40379bd7: _esp_error_check_failed at C:/Users/lukss/esp/v5.3/esp-idf/components/esp_system/esp_err.c:49

Backtrace: 0x40375abe:0x3fc98010 0x40379be1:0x3fc98030 0x4038092d:0x3fc98050 0x40379bd7:0x3fc980c0 0x4200752a:0x3fc980f0 0x420213bb:0x3fc98150 0x4037a571:0x3fc98180 0x40375abe: panic_abort at C:/Users/lukss/esp/v5.3/esp-idf/components/esp_system/panic.c:463 0x40379be1: esp_system_abort at C:/Users/lukss/esp/v5.3/esp-idf/components/esp_system/port/esp_system_chip.c:92 0x4038092d: abort at C:/Users/lukss/esp/v5.3/esp-idf/components/newlib/abort.c:38 0x40379bd7: _esp_error_check_failed at C:/Users/lukss/esp/v5.3/esp-idf/components/esp_system/esp_err.c:49 0x4200752a: app_main at C:/Users/lukss/cdc-host-example/main/usb_cdc_example_main.c:218 (discriminator 1) 0x420213bb: main_task at C:/Users/lukss/esp/v5.3/esp-idf/components/freertos/app_startup.c:208 0x4037a571: vPortTaskWrapper at C:/Users/lukss/esp/v5.3/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:134

ELF file SHA256: 4454c768a

tore-espressif commented 1 month ago

Hi @antunesls thank you for the log.

There indeed might be a bug, because we always allocate bMaxPacketSize0 for Endpoint 0. https://github.com/espressif/esp-usb/blob/master/host/class/cdc/usb_host_cdc_acm/cdc_acm_host.c#L572 . Up until now, we have not seen this problem because USB devices usually implement 64 bytes MPS for EP0, which is enough for most control transfers.

Could you confirm this by running lsusb -v with the USB device plugged in on your linux machine a copy relevant part of the output here?

your example fails on cdc_acm_host_line_coding_set/get API (which uses EP0). I think you might not need this at all. This API is useful only for real USB<->UART converters. Could you just remove these calls and try again?

antunesls commented 1 month ago

Hi @tore-espressif ,

Its runs but I not having the same result as the intend when a I used plugged in a machine linux x86 , so I was trying set the boundrate and other configs to try solved it.

Follow the resquest (lsusb -v) :

Bus 001 Device 005: ID 04d8:000a Microchip Technology, Inc. CDC RS-232 Emulation Demo Couldn't open device, some information will be missing Device Descriptor: bLength 18 bDescriptorType 1 bcdUSB 2.00 bDeviceClass 2 Communications bDeviceSubClass 2 Abstract (modem) bDeviceProtocol 0 bMaxPacketSize0 8 idVendor 0x04d8 Microchip Technology, Inc. idProduct 0x000a CDC RS-232 Emulation Demo bcdDevice 1.00 iManufacturer 1 Ragtech Sistemas de Energia iProduct 2 USB Serial Port iSerial 0 bNumConfigurations 1 Configuration Descriptor: bLength 9 bDescriptorType 2 wTotalLength 0x0043 bNumInterfaces 2 bConfigurationValue 1 iConfiguration 0 bmAttributes 0xc0 Self Powered MaxPower 100mA Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 0 bAlternateSetting 0 bNumEndpoints 1 bInterfaceClass 2 Communications bInterfaceSubClass 2 Abstract (modem) bInterfaceProtocol 1 AT-commands (v.25ter) iInterface 0 CDC Header: bcdCDC 1.10 CDC Call Management: bmCapabilities 0x00 bDataInterface 1 CDC ACM: bmCapabilities 0x02 line coding and serial state CDC Union: bMasterInterface 0 bSlaveInterface 1 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x82 EP 2 IN bmAttributes 3 Transfer Type Interrupt Synch Type None Usage Type Data wMaxPacketSize 0x0008 1x 8 bytes bInterval 2 Interface Descriptor: bLength 9 bDescriptorType 4 bInterfaceNumber 1 bAlternateSetting 0 bNumEndpoints 2 bInterfaceClass 10 CDC Data bInterfaceSubClass 0 bInterfaceProtocol 0 iInterface 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x01 EP 1 OUT bmAttributes 2 Transfer Type Bulk Synch Type None Usage Type Data wMaxPacketSize 0x0040 1x 64 bytes bInterval 0 Endpoint Descriptor: bLength 7 bDescriptorType 5 bEndpointAddress 0x81 EP 1 IN bmAttributes 2 Transfer Type Bulk Synch Type None Usage Type Data wMaxPacketSize 0x0040 1x 64 bytes bInterval 0

tore-espressif commented 1 month ago

bMaxPacketSize0 8

This confirms the problem.

As a temporary workaround you can try to avoid calling the set/get line coding API, until it is fixed in esp-usb

antunesls commented 1 month ago

OK, while the bug is not fixed, I'll resume my issue with the comunication, so maybe my issue could be not related with this bug.

If someone could help me.

My base is my raspberry pi 4 , running raspbery OS.

Follow my code in python (it works).


import serial
import time
import datetime

import json

# Configuração Serial
cfg_serial_port = '/dev/ttyACM0'
cfg_serial_interval = 5

# payloads
cmd_req1 = bytes.fromhex("FF FE 00 8E 01 8F")
cmd_req2 = bytes.fromhex("AA 04 00 80 1E 9E")
cmd_get_data = bytes.fromhex("AA 04 00 80 1E 9E")

power_current_kwh_out = 0.0
power_current_kwh_in = 0.0
power_last_update = time.time()

def logData(text, end):
    current_datetime = datetime.datetime.now()
    formatted_datetime = current_datetime.strftime("%d/%b/%Y %H:%M:%S")
    if end:
        print(f"[{formatted_datetime}] {text}", end=" ")
    else:
        print(f"[{formatted_datetime}] {text}")

def linear(val, a, b, decimals = 1):
    return round(b + val * a, decimals)

def processPower(wOut, wIn):
    global power_last_update
    global power_current_kwh_out
    global power_current_kwh_in

    curr = time.time()
    diff = curr - power_last_update # in seconds
    power_last_update = curr

    slice = (wOut / 1000) * (diff / 3600)
    power_current_kwh_out += slice

    slice = (wIn / 1000) * (diff / 3600)
    power_current_kwh_in += slice

def build_payload(buffer):
    iOut = linear(buffer[0x0D], 0.1152, 0, 2)

    vOut = linear(buffer[0x1E], 0.555, 0, 2)
    wOut = iOut*vOut

    vIn = linear(buffer[0x0C], 1.06, 0, 2)
    wIn = iOut*vIn # não tem "iIn"

    processPower(wOut, wIn)

    payload = {
        "Power_Out_Percent": {"value": linear(buffer[0x0E], 1, 0), "unit": "%"},
        "Current_Out": {"value": iOut, "unit": "A"},
        "Voltage_Out": {"value": round(vOut, 1), "unit": "V"},
        "Voltage_In": {"value": round(vIn, 1), "unit": "V"},
        "Power_Out": {"value": round(wOut, 1), "unit": "W"},
        "Power_In": {"value": round(wIn, 1), "unit": "W"},
        "Energy_Out": {"value": round(power_current_kwh_out, 2), "unit": "kWh"},
        "Energy_In": {"value": round(power_current_kwh_in, 2), "unit": "kWh"},
        "Temperature": {"value": linear(buffer[0x0F], 1, 0), "unit": "C"},
        "Battery_State": {"value": linear(buffer[0x08], 0.392, 0), "unit": "%"},
        "Battery_Voltage": {"value": linear(buffer[0x0B], 0.0671, 0), "unit": "V"},
        "Frequency": {"value": linear(buffer[0x18], -0.1152, 65), "unit": "Hz"},
    }

    return payload

def send_and_ignore(serial_port, command, wait_time=0.1):
    while True:
        serial_port.write(command)
        time.sleep(wait_time)
        if serial_port.in_waiting > 0:
            logData(str(serial_port.in_waiting)+" Available", False)
            serial_port.read()
            return
        logData("No response ...", False)

def mainLoop():
    # Configuração da porta serial
    logData(f"serial open: {cfg_serial_port}", False)
    serial_port = serial.Serial(cfg_serial_port)
    if serial_port.isOpen():
        logData(serial_port.name + " is open…", False)
    else:
        logData(f"serial fail: {ret}", False)
        time.sleep(10)
        return

    serial_port.write(cmd_req1)
    serial_port.write(cmd_req2)

    while True:
        time.sleep(cfg_serial_interval)

        serial_port.write(cmd_get_data)
        logData(f"Requesting Data... ", True)

        #wait = 100
        while serial_port.in_waiting < 31:
            time.sleep(0.1)
            print(serial_port.in_waiting, end=" ")

        print()

        time.sleep(0.1)
        buffer = serial_port.read(serial_port.in_waiting)

        # Monta o payload
        payload = build_payload(buffer)

        strPayload = json.dumps(payload)
        logData(strPayload, False)

while True:
    mainLoop()

The output:

antunesls@valkyrie:~ $ python ups2.py [12/Aug/2024 10:46:42] serial open: /dev/ttyACM0 [12/Aug/2024 10:46:42] /dev/ttyACM0 is open… [12/Aug/2024 10:46:47] Requesting Data... 11 32 [12/Aug/2024 10:46:47] {"Power_Out_Percent": {"value": 3, "unit": "%"}, "Current_Out": {"value": 23.04, "unit": "A"}, "Voltage_Out": {"value": 0.0, "unit": "V"}, "Voltage_In": {"value": 209.9, "unit": "V"}, "Power_Out": {"value": 0.0, "unit": "W"}, "Power_In": {"value": 4835.6, "unit": "W"}, "Energy_Out": {"value": 0.0, "unit": "kWh"}, "Energy_In": {"value": 0.01, "unit": "kWh"}, "Temperature": {"value": 2, "unit": "C"}, "Battery_State": {"value": 53.7, "unit": "%"}, "Battery_Voltage": {"value": 16.8, "unit": "V"}, "Frequency": {"value": 47.0, "unit": "Hz"}}

But my code in the ESP32S3 attached not return the response more than 31 cacracters, like the python code.

It could be related with the boudrate ?

tore-espressif commented 1 month ago

It could be related with the boudrate ?

From the information you provided, it doesn't seem be related.

Looking at your handle_rx funciton

// Callback para processar dados recebidos e montar o payload
static bool handle_rx(const uint8_t *data, size_t data_len, void *arg)
{
    ESP_LOGI(TAG, "Dados recebidos");
    ESP_LOG_BUFFER_HEXDUMP(TAG, data, data_len, ESP_LOG_INFO);

    // Verifica se recebeu dados suficientes
    if (data_len >= 31)
    {
        char json_payload[512];
        build_payload(data, json_payload, sizeof(json_payload));
        ESP_LOGI(TAG, "Payload: %s", json_payload);
    }
    else
    {
        vTaskDelay(pdMS_TO_TICKS(100));
    }

    return true;
}

You should not call any blocking API (vTaskDelay) in the callback. Could you do something as simple as

static bool handle_rx(const uint8_t *data, size_t data_len, void *arg) {
    ESP_LOG_BUFFER_HEXDUMP(TAG, data, data_len, ESP_LOG_INFO);
    return true;
}

This way we can see what exactly is received

antunesls commented 1 month ago

I did some changes on the code (attached), its better but still not return the whole data.

usb_cdc_example_main.zip

Should be like this, (when it works on python code).

Imagem sem título1 Imagem sem título

The output after the code change (ESP32/ NOT WORKING):

 antunesls on  ~/cdc-host-example 
# & 'C:\Users\lukss\.espressif\python_env\idf5.3_py3.11_env\Scripts\python.exe' 'C:\Users\lukss\esp\v5.3\esp-idf\tools\idf_monitor.py' -p COM17 -b 115200 --toolchain-prefix xtensa-esp32s3-elf- --target esp32s3 'c:\Users\lukss\cdc-host-example\build\cdc-host-example.elf'
--- WARNING: GDB cannot open serial ports accessed as COMx
--- Using \\.\COM17 instead...
--- esp-idf-monitor 1.4.0 on \\.\COM17 115200 ---
--- Quit: Ctrl+] | Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---
ESP-ROM:esp32s3-20210327
Build:Mar 27 2021
rst:0x1 (POWERON),boot:0x8 (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce2810,len:0x2420
load:0x403c8700,len:0x4
load:0x403c8704,len:0xe50
load:0x403cb700,len:0x329c
entry 0x403c895c
I (27) boot: ESP-IDF v5.3 2nd stage bootloader
I (27) boot: compile time Aug 12 2024 14:07:29
I (27) boot: Multicore bootloader
D (30) bootloader_flash: non-XMC chip detected by SFDP Read (00), skip.
D (36) bootloader_flash: mmu set block paddr=0x00000000 (was 0xffffffff)
I (43) boot: chip revision: v0.2
D (47) boot.esp32s3: magic e9
D (50) boot.esp32s3: segments 04
D (53) boot.esp32s3: spi_mode 02
D (57) boot.esp32s3: spi_speed 0f
D (60) boot.esp32s3: spi_size 01
I (63) boot.esp32s3: Boot SPI Speed : 80MHz
I (68) boot.esp32s3: SPI Mode       : DIO
I (73) boot.esp32s3: SPI Flash Size : 2MB
D (78) boot: Enabling RTCWDT(9000 ms)
I (81) boot: Enabling RNG early entropy source...
D (87) bootloader_flash: rodata starts from paddr=0x00008000, size=0xc00, will be mapped to vaddr=0x3c000000
V (97) bootloader_flash: after mapping, starting from paddr=0x00000000 and vaddr=0x3c000000, 0x10000 bytes are mapped
D (107) boot: mapped partition table 0x8000 at 0x3c008000
D (113) flash_parts: partition table verified, 4 entries
I (118) boot: Partition Table:
I (122) boot: ## Label            Usage          Type ST Offset   Length
D (129) boot: load partition table entry 0x3c008000
D (134) boot: type=1 subtype=2
I (137) boot:  0 nvs              WiFi data        01 02 00009000 00006000
D (145) boot: load partition table entry 0x3c008020
D (150) boot: type=1 subtype=1
I (153) boot:  1 phy_init         RF data          01 01 0000f000 00001000
D (161) boot: load partition table entry 0x3c008040
D (166) boot: type=0 subtype=0
I (169) boot:  2 factory          factory app      00 00 00010000 00100000
I (176) boot: End of partition table
D (180) boot: Trying partition index -1 offs 0x10000 size 0x100000
D (187) esp_image: reading image header @ 0x10000
D (191) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
D (198) esp_image: image header: 0xe9 0x05 0x02 0x01 403753f0
V (204) esp_image: loading segment header 0 at offset 0x10018
V (210) esp_image: segment data length 0xc904 data starts 0x10020
V (216) esp_image: segment 0 map_segment 1 segment_data_offs 0x10020 load_addr 0x3c030020
I (224) esp_image: segment 0: paddr=00010020 vaddr=3c030020 size=0c904h ( 51460) map
D (233) esp_image: free data page_count 0x00000200
D (238) bootloader_flash: rodata starts from paddr=0x00010020, size=0xc904, will be mapped to vaddr=0x3c000000
V (248) bootloader_flash: after mapping, starting from paddr=0x00010000 and vaddr=0x3c000000, 0x10000 bytes are mapped
V (268) esp_image: loading segment header 1 at offset 0x1c924
D (268) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
V (271) esp_image: segment data length 0x2904 data starts 0x1c92c
V (277) esp_image: segment 1 map_segment 0 segment_data_offs 0x1c92c load_addr 0x3fc92b00
I (286) esp_image: segment 1: paddr=0001c92c vaddr=3fc92b00 size=02904h ( 10500) load
D (294) esp_image: free data page_count 0x00000200
D (299) bootloader_flash: rodata starts from paddr=0x0001c92c, size=0x2904, will be mapped to vaddr=0x3c000000
V (309) bootloader_flash: after mapping, starting from paddr=0x00010000 and vaddr=0x3c000000, 0x10000 bytes are mapped
V (322) esp_image: loading segment header 2 at offset 0x1f230
D (326) bootloader_flash: mmu set block paddr=0x00010000 (was 0xffffffff)
V (332) esp_image: segment data length 0xde0 data starts 0x1f238
V (339) esp_image: segment 2 map_segment 0 segment_data_offs 0x1f238 load_addr 0x40374000       
0x40374000: _WindowOverflow4 at C:/Users/lukss/esp/v5.3/esp-idf/components/xtensa/xtensa_vectors.S:2027

I (347) esp_image: segment 2: paddr=0001f238 vaddr=40374000 size=00de0h (  3552) load
D (355) esp_image: free data page_count 0x00000200
D (360) bootloader_flash: rodata starts from paddr=0x0001f238, size=0xde0, will be mapped to vaddr=0x3c000000
V (370) bootloader_flash: after mapping, starting from paddr=0x00010000 and vaddr=0x3c000000, 0x20000 bytes are mapped
V (382) esp_image: loading segment header 3 at offset 0x20018
D (387) bootloader_flash: mmu set block paddr=0x00020000 (was 0xffffffff)
V (394) esp_image: segment data length 0x21b84 data starts 0x20020
V (400) esp_image: segment 3 map_segment 1 segment_data_offs 0x20020 load_addr 0x42000020       
0x42000020: _stext at ??:?

I (408) esp_image: segment 3: paddr=00020020 vaddr=42000020 size=21b84h (138116) map
D (416) esp_image: free data page_count 0x00000200
D (421) bootloader_flash: rodata starts from paddr=0x00020020, size=0x21b84, will be mapped to vaddr=0x3c000000
V (431) bootloader_flash: after mapping, starting from paddr=0x00020000 and vaddr=0x3c000000, 0x30000 bytes are mapped
V (467) esp_image: loading segment header 4 at offset 0x41ba4
D (467) bootloader_flash: mmu set block paddr=0x00040000 (was 0xffffffff)
V (469) esp_image: segment data length 0xdc58 data starts 0x41bac
V (475) esp_image: segment 4 map_segment 0 segment_data_offs 0x41bac load_addr 0x40374de0       
I (483) esp_image: segment 4: paddr=00041bac vaddr=40374de0 size=0dc58h ( 56408) load
D (491) esp_image: free data page_count 0x00000200
D (496) bootloader_flash: rodata starts from paddr=0x00041bac, size=0xdc58, will be mapped to vaddr=0x3c000000
V (506) bootloader_flash: after mapping, starting from paddr=0x00040000 and vaddr=0x3c000000, 0x10000 bytes are mapped
V (530) esp_image: image start 0x00010000 end of last section 0x0004f804
D (530) bootloader_flash: mmu set block paddr=0x00040000 (was 0xffffffff)
D (532) boot: Calculated hash: fd365f7b9d25943bfd6afe66ef6409e8d6acd93e1e02629e2a03c2812b28ba68 
I (547) boot: Loaded app from partition at offset 0x10000
I (547) boot: Disabling RNG early entropy source...
D (553) boot: Mapping segment 0 as DROM
D (557) boot: Mapping segment 3 as IROM
D (560) boot: calling set_cache_and_start_app
D (565) boot: configure drom and irom and start
V (570) boot: rodata starts from paddr=0x00010020, vaddr=0x3c030020, size=0xc904
V (577) boot: after mapping rodata, starting from paddr=0x00010000 and vaddr=0x3c030000, 0x10000 bytes are mapped
V (587) boot: mapped one page of the rodata, from paddr=0x00010000 and vaddr=0x3c030000, 0x10000 bytes are mapped
V (598) boot: text starts from paddr=0x00020020, vaddr=0x42000020, size=0x21b84
0x42000020: _stext at ??:?

V (605) boot: after mapping text, starting from paddr=0x00020000 and vaddr=0x42000000, 0x30000 bytes are mapped
D (615) boot: start: 0x403753f0
0x403753f0: call_start_cpu0 at C:/Users/lukss/esp/v5.3/esp-idf/components/esp_system/port/cpu_start.c:376

I (630) cpu_start: Multicore app
I (639) cpu_start: Pro cpu start user code
I (639) cpu_start: cpu freq: 160000000 Hz
I (639) app_init: Application information:
I (642) app_init: Project name:     cdc-host-example
I (648) app_init: App version:      1
I (652) app_init: Compile time:     Aug 12 2024 14:06:43
I (658) app_init: ELF file SHA256:  59d0fc86e...
I (663) app_init: ESP-IDF:          v5.3
I (668) efuse_init: Min chip rev:     v0.0
I (673) efuse_init: Max chip rev:     v0.99
I (678) efuse_init: Chip rev:         v0.2
I (683) heap_init: Initializing. RAM available for dynamic allocation:
I (690) heap_init: At 3FC95C78 len 00053A98 (334 KiB): RAM
I (696) heap_init: At 3FCE9710 len 00005724 (21 KiB): RAM
I (702) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (708) heap_init: At 600FE100 len 00001EE8 (7 KiB): RTCRAM
I (715) spi_flash: detected chip: winbond
I (719) spi_flash: flash io: dio
W (723) spi_flash: Detected size(16384k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (736) sleep: Configure to isolate all GPIO pins in sleep state
I (743) sleep: Enable automatic switching of GPIO sleep configuration
I (750) main_task: Started on CPU0
I (760) main_task: Calling app_main()
I (760) USB-CDC: Instalando USB Host
I (790) USB-CDC: Instalando driver CDC-ACM
I (790) USB-CDC: Abrindo dispositivo CDC ACM 0x04D8:0x000A...
I (1190) USB-CDC: Setting up line coding
*** Device descriptor ***
bLength 18
bDescriptorType 1
bcdUSB 2.00
bDeviceClass 0x2
bDeviceSubClass 0x2
bDeviceProtocol 0x0
bMaxPacketSize0 8
idVendor 0x4d8
idProduct 0xa
bcdDevice 1.00
iManufacturer 1
iProduct 2
iSerialNumber 0
bNumConfigurations 1
*** Configuration descriptor ***
bLength 9
bDescriptorType 2
wTotalLength 67
bNumInterfaces 2
bConfigurationValue 1
iConfiguration 0
bmAttributes 0xc0
bMaxPower 100mA
        *** Interface descriptor ***
        bLength 9
        bDescriptorType 4
        bInterfaceNumber 0
        bAlternateSetting 0
        bNumEndpoints 1
        bInterfaceClass 0x2
        bInterfaceSubClass 0x2
        bInterfaceProtocol 0x1
        iInterface 0
        *** CDC Header Descriptor ***
        bcdCDC: 1.10
        *** CDC Call Descriptor ***
        bmCapabilities: 0x00
        bDataInterface: 1
        *** CDC ACM Descriptor ***
        bmCapabilities: 0x02
        *** CDC Union Descriptor ***
        bControlInterface: 0
        bSubordinateInterface[0]: 1
                *** Endpoint descriptor ***
                bLength 7
                bDescriptorType 5
                bEndpointAddress 0x82   EP 2 IN
                bmAttributes 0x3        INT
                wMaxPacketSize 8
                bInterval 2
        *** Interface descriptor ***
        bLength 9
        bDescriptorType 4
        bInterfaceNumber 1
        bAlternateSetting 0
        bNumEndpoints 2
        bInterfaceClass 0xa
        bInterfaceSubClass 0x0
        bInterfaceProtocol 0x0
        iInterface 0
                *** Endpoint descriptor ***
                bLength 7
                bDescriptorType 5
                bEndpointAddress 0x1    EP 1 OUT
                bmAttributes 0x2        BULK
                wMaxPacketSize 64
                bInterval 0
                *** Endpoint descriptor ***
                bLength 7
                bDescriptorType 5
                bEndpointAddress 0x81   EP 1 IN
                bmAttributes 0x2        BULK
                wMaxPacketSize 64
                bInterval 0
I (1410) USB-CDC: Enviando CMD1...
I (1410) USB-CDC: 0x3c03a050   ff fe 00 8e 01 8f                                 |......|       
I (1430) USB-CDC: Dados recebidos
I (1430) USB-CDC: 0x3fc9d804   ca                                                |.|
I (1510) USB-CDC: Enviando CMD2...
I (1510) USB-CDC: 0x3c03a048   aa 04 00 80 1e 9e                                 |......|       
I (1530) USB-CDC: Dados recebidos
I (1530) USB-CDC: 0x3fc9d805   aa                                                |.|
I (1540) USB-CDC: Dados recebidos
I (1540) USB-CDC: 0x3fc9d806   21                                                |!|
I (1580) USB-CDC: Dados recebidos
I (1580) USB-CDC: 0x3fc9d807   00 0c 4e 00 00 89 ff 00                           |..N.....|     
I (1620) USB-CDC: Dados recebidos
I (1620) USB-CDC: 0x3fc9d80f   fa c8 c7 03 02 26 ec 00                           |.....&..|     
I (1660) USB-CDC: Dados recebidos
I (1660) USB-CDC: 0x3fc9d817   00 01 82 c2 01 9c 48 00  c7                       |......H..|    
I (1700) USB-CDC: Dados recebidos
I (1700) USB-CDC: 0x3fc9d820   06 0e 00 ca                                       |....|
I (6610) USB-CDC: Solicitando dados...
I (6610) USB-CDC: 0x3c03a040   aa 04 00 80 1e 9e                                 |......|       
I (6630) USB-CDC: Dados recebidos
I (6640) USB-CDC: 0x3fc9d824   aa                                                |.|
I (6640) USB-CDC: Dados recebidos
I (6640) USB-CDC: 0x3fc9d825   21                                                |!|
I (6680) USB-CDC: Dados recebidos
I (6680) USB-CDC: 0x3fc9d826   00 0c 4e 00 00 89 ff 00                           |..N.....|     
I (6720) USB-CDC: Dados recebidos
I (6720) USB-CDC: 0x3fc9d82e   fa c9 c7 03 02 26 eb 00                           |.....&..|     
I (6760) USB-CDC: Dados recebidos
I (6760) USB-CDC: 0x3fc9d836   00 01 82 82 01 9c 48 00                           |......H.|     
I (6800) USB-CDC: Dados recebidos
I (6800) USB-CDC: 0x3fc9d83e   c7 06 0e 00 ca                                    |.....|        
I (11610) USB-CDC: Solicitando dados...
I (11610) USB-CDC: 0x3c03a040   aa 04 00 80 1e 9e                                 |......|      
I (11640) USB-CDC: Dados recebidos
I (11640) USB-CDC: 0x3fc9d843   aa                                                |.|
I (11640) USB-CDC: Dados recebidos
I (11640) USB-CDC: 0x3fc9d844   21                                                |!|
I (11680) USB-CDC: Dados recebidos
I (11680) USB-CDC: 0x3fc9d845   00 0c 4e 00 00 89 ff 00                           |..N.....|    
I (11720) USB-CDC: Dados recebidos
I (11720) USB-CDC: 0x3fc9d84d   fa c7 c7 03 02 26 eb 00                           |.....&..|    
I (11760) USB-CDC: Dados recebidos
I (11760) USB-CDC: 0x3fc9d855   00 01 86 c2 01 9c 48 00  c7                       |......H..|   
I (11800) USB-CDC: Dados recebidos
I (11800) USB-CDC: 0x3fc9d85e   06 0e 00 c9                                       |....|        
I (16610) USB-CDC: Solicitando dados...
I (16610) USB-CDC: 0x3c03a040   aa 04 00 80 1e 9e                                 |......|      
I (16630) USB-CDC: Dados recebidos
I (16640) USB-CDC: 0x3fc9d862   aa                                                |.|
I (16640) USB-CDC: Dados recebidos
I (16640) USB-CDC: 0x3fc9d863   21                                                |!|
I (16680) USB-CDC: Dados recebidos
I (16680) USB-CDC: 0x3fc9d864   00 0c 4e 00 00 89 ff 00                           |..N.....|
I (16720) USB-CDC: Dados recebidos
I (16720) USB-CDC: 0x3fc9d86c   fa c7 c8 03 02 26 eb 00                           |.....&..|    
I (16760) USB-CDC: Dados recebidos
I (16760) USB-CDC: 0x3fc9d874   00 01 86 c2 01 9c 48 00                           |......H.|    
I (16800) USB-CDC: Dados recebidos
I (16800) USB-CDC: 0x3fc9d87c   c7 06 0e 00 c9                                    |.....|       
I (21610) USB-CDC: S
tore-espressif commented 1 month ago

@antunesls I'm sorry but I'm afraid I can't help you any further. It seems that the CDC-ACM driver gives you the data your device has sent.

If there is any other data post-processing (such as reaction on timeout, or concatenating messages as you do in your python code) you will have to implement this yourself

tore-espressif commented 4 weeks ago

@antunesls We closed the issue because the fix has been merged. If you have any new findings or you require additional help, feel free to reopen

antunesls commented 4 weeks ago

Hi @tore-espressif , thanks for all support.

I saw that this fiz was merged in the ESP-USB repository, can I use it now or should I wait for a new Esp-Idf release ?

tore-espressif commented 2 weeks ago

Luckily the CDC driver releases are not tight to ESP-IDF releases.

However, I have not releases a new version yet, we wanted to add one more change to the next release. Should be done in ~2-3 weeks. You use code from https://github.com/espressif/esp-usb/pull/57 in the meantime