Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

USB Host sometimes freezes randomly (IDFGH-14198) #14996

Open
3 tasks done
alex-k8 opened this issue Dec 7, 2024 · 5 comments
Open
3 tasks done

USB Host sometimes freezes randomly (IDFGH-14198) #14996

alex-k8 opened this issue Dec 7, 2024 · 5 comments
Assignees
@roma-jam
Labels
Status: Opened Issue is new Type: Bug bugs in IDF

Comments

@alex-k8
Copy link

alex-k8 commented Dec 7, 2024 •
edited
Loading

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.3.1

Espressif SoC revision.

ESP32-S3

Operating System used.

Windows

How did you build your project?

VS Code IDE

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

PowerShell

Development Kit.

ESP32-S3-DevKitC-1 & Custom Board

Power Supply used.

USB

What is the expected behavior?

I expected the USB Host functionality to work without randomly freezing.

What is the actual behavior?

Randomly, either after 5 minutes or 5 hours, the USB Host does not receive any more data from the connected device. I press keys on my keyboard, or move my mouse, and I don't see any logs. I either have to replug the device, or restart the ESP board. This happens only on a few keyboards and mice. I suspect it has something to do with higher polling rate devices, since I never experienced it on my older keyboard.

Steps to reproduce.

  1. Build and upload the HID Host Example code
  2. Connect a high polling rate mouse to the ESP
  3. Move the mouse and see that you receive data properly
  4. Move it for some time...
  5. After some time the logs will not show any more output, it's like the device either stops sending data, or the library stops receiving data. However the "Disconnect - Device gone" callback is called if I remove the device.

Debug Logs.

Nothing more is shown in the logs, no matter what log level I choose.

More Information.

The only change I made to the code was that I use hid_class_request_set_protocol(hid_device_handle, HID_REPORT_PROTOCOL_REPORT) instead of hid_class_request_set_protocol(hid_device_handle, HID_REPORT_PROTOCOL_BOOT) in order to receive all the data that I need. This happens on a custom board as well as the ESP32-S3-DevKitC-1. It happens in both USB power and battery power. I've logged the available memory and there's no memory leak. Seems to be software related and not hardware. It happens in both the ESP-IDF through VS Code, and in the Arduino IDE port.
Specific devices that I have noticed this issue is happening: UHK keyboard with pointer module, All CharaChorder keyboards, Logitech G430 Hero
@alex-k8 alex-k8 added the Type: Bug bugs in IDF label Dec 7, 2024
@github-actions github-actions bot changed the title USB Host sometimes freezes randomly USB Host sometimes freezes randomly (IDFGH-14198) Dec 7, 2024
@espressif-bot espressif-bot added the Status: Opened Issue is new label Dec 7, 2024
@roma-jam
Copy link
Collaborator

roma-jam commented Dec 7, 2024

Hi @alex-k8,

Could you please attach the usb_host_lib example output for all devices you experience problems with?

Thanks.

@alex-k8
Copy link
Author

alex-k8 commented Dec 7, 2024

Hey @roma-jam

I only have access to two of them at the moment, so I'll attach those.

CharaChorder Lite:

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 0xESP-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.1 2nd stage bootloader
I (27) boot: compile time Oct 24 2024 20:46:56
I (27) boot: Multicore bootloader
I (30) boot: chip revision: v0.1
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 (72) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (79) boot:  2 factory          factory app      00 00 00010000 00100000
I (87) boot: End of partition table
I (91) esp_image: segment 0: paddr=00010020 vaddr=3c020020 size=0b714h ( 46868) map
I (108) esp_image: segment 1: paddr=0001b73c vaddr=3fc92700 size=028e4h ( 10468) load
I (110) esp_image: segment 2: paddr=0001e028 vaddr=40374000 size=01ff0h (  8176) load
I (118) esp_image: segment 3: paddr=00020020 vaddr=42000020 size=1d6dch (120540) map
I (146) esp_image: segment 4: paddr=0003d704 vaddr=40375ff0 size=0c6c8h ( 50888) load
I (163) boot: Loaded app from partition at offset 0x10000
I (164) boot: Disabling RNG early entropy source...
I (176) cpu_start: Multicore app
I (185) cpu_start: Pro cpu start user code
I (185) cpu_start: cpu freq: 160000000 Hz
I (185) app_init: Application information:
I (188) app_init: Project name:     usb_host_lib_example
I (194) app_init: App version:      1
I (198) app_init: Compile time:     Dec  6 2024 19:35:39
I (204) app_init: ELF file SHA256:  c8e55ece3...
I (210) app_init: ESP-IDF:          v5.3.1
I (214) efuse_init: Min chip rev:     v0.0
I (219) efuse_init: Max chip rev:     v0.99 
I (224) efuse_init: Chip rev:         v0.1
I (229) heap_init: Initializing. RAM available for dynamic allocation:
I (236) heap_init: At 3FC95848 len 00053EC8 (335 KiB): RAM
I (242) heap_init: At 3FCE9710 len 00005724 (21 KiB): RAM
I (248) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (254) heap_init: At 600FE100 len 00001EE8 (7 KiB): RTCRAM
I (261) spi_flash: detected chip: generic
I (265) spi_flash: flash io: dio
W (269) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (282) sleep: Configure to isolate all GPIO pins in sleep state
I (289) sleep: Enable automatic switching of GPIO sleep configuration
I (297) main_task: Started on CPU0
I (307) main_task: Calling app_main()
I (307) USB host lib: USB host library example
I (307) gpio: GPIO[13]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (317) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:2 
I (327) USB host lib: Installing USB Host Library
I (367) CLASS: Registering Client
I (23717) CLASS: Opening device at address 1
I (23717) CLASS: Getting device information
I (23717) CLASS:        Full speed
I (23717) CLASS:        bConfigurationValue 1
I (23717) CLASS: Getting device descriptor
*** Device descriptor ***
bLength 18
bDescriptorType 1
bcdUSB 2.00
bDeviceClass 0xef
bDeviceSubClass 0x2
bDeviceProtocol 0x1
bMaxPacketSize0 64
idVendor 0x303a
idProduct 0x812e
bcdDevice 1.00
iManufacturer 1
iProduct 2
iSerialNumber 3
bNumConfigurations 1
I (23747) CLASS: Getting config descriptor
*** Configuration descriptor ***
bLength 9
bDescriptorType 2
wTotalLength 107
bNumInterfaces 3
bConfigurationValue 1
iConfiguration 6
bmAttributes 0xc0
bMaxPower 500mA
        *** Interface descriptor ***
        bLength 9
        bDescriptorType 4
        bInterfaceNumber 0
        bAlternateSetting 0
        bNumEndpoints 2
        bInterfaceClass 0x3
        bInterfaceSubClass 0x0
        bInterfaceProtocol 0x0
        iInterface 4
                *** Endpoint descriptor ***
                bLength 7
                bDescriptorType 5
                bEndpointAddress 0x4    EP 4 OUT
                bmAttributes 0x3        INT
                wMaxPacketSize 64
                bInterval 1
                *** Endpoint descriptor ***
                bLength 7
                bDescriptorType 5
                bEndpointAddress 0x83   EP 3 IN
                bmAttributes 0x3        INT
                wMaxPacketSize 64
                bInterval 1
*** Interface Association Descriptor ***
bLength 8
bDescriptorType 11
bFirstInterface 1
bInterfaceCount 2
bFunctionClass 0x2
bFunctionSubClass 0x2
bFunctionProtocol 0x0
iFunction 0
        *** Interface descriptor ***
        bLength 9
        bDescriptorType 4
        bInterfaceNumber 1
        bAlternateSetting 0
        bNumEndpoints 1
        bInterfaceClass 0x2
        bInterfaceSubClass 0x2
        bInterfaceProtocol 0x0
        iInterface 5
                *** Endpoint descriptor ***
                bLength 7
                bDescriptorType 5
                bEndpointAddress 0x85   EP 5 IN
                bmAttributes 0x3        INT
                wMaxPacketSize 64
                bInterval 16
        *** Interface descriptor ***
        bLength 9
        bDescriptorType 4
        bInterfaceNumber 2
        bAlternateSetting 0
        bNumEndpoints 2
        bInterfaceClass 0xa
        bInterfaceSubClass 0x0
        bInterfaceProtocol 0x0
        iInterface 0
                *** Endpoint descriptor ***
                bLength 7
                bDescriptorType 5
                bEndpointAddress 0x3    EP 3 OUT
                bmAttributes 0x2        BULK
                wMaxPacketSize 64
                bInterval 0
                *** Endpoint descriptor ***
                bLength 7
                bDescriptorType 5
                bEndpointAddress 0x84   EP 4 IN
                bmAttributes 0x2        BULK
                wMaxPacketSize 64
                bInterval 0
I (23897) CLASS: Getting Manufacturer string descriptor
CharaChorder
I (23907) CLASS: Getting Product string descriptor
CC Lite S2
I (23917) CLASS: Getting Serial Number string descriptor
84:f7:03:da:cc:a0

Logitech G403 Hero Mouse:

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.1 2nd stage bootloader
I (27) boot: compile time Oct 24 2024 20:46:56
I (27) boot: Multicore bootloader
I (30) boot: chip revision: v0.1
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 (72) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (79) boot:  2 factory          factory app      00 00 00010000 00100000
I (87) boot: End of partition table
I (91) esp_image: segment 0: paddr=00010020 vaddr=3c020020 size=0b714h ( 46868) map
I (108) esp_image: segment 1: paddr=0001b73c vaddr=3fc92700 size=028e4h ( 10468) load
I (110) esp_image: segment 2: paddr=0001e028 vaddr=40374000 size=01ff0h (  8176) load
I (118) esp_image: segment 3: paddr=00020020 vaddr=42000020 size=1d6dch (120540) map
I (146) esp_image: segment 4: paddr=0003d704 vaddr=40375ff0 size=0c6c8h ( 50888) load
I (163) boot: Loaded app from partition at offset 0x10000
I (164) boot: Disabling RNG early entropy source...
I (176) cpu_start: Multicore app
I (185) cpu_start: Pro cpu start user code
I (185) cpu_start: cpu freq: 160000000 Hz
I (185) app_init: Application information:
I (188) app_init: Project name:     usb_host_lib_example
I (194) app_init: App version:      1
I (198) app_init: Compile time:     Dec  6 2024 19:35:39
I (204) app_init: ELF file SHA256:  c8e55ece3...
I (210) app_init: ESP-IDF:          v5.3.1
I (214) efuse_init: Min chip rev:     v0.0
I (219) efuse_init: Max chip rev:     v0.99 
I (224) efuse_init: Chip rev:         v0.1
I (229) heap_init: Initializing. RAM available for dynamic allocation:
I (236) heap_init: At 3FC95848 len 00053EC8 (335 KiB): RAM
I (242) heap_init: At 3FCE9710 len 00005724 (21 KiB): RAM
I (248) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (254) heap_init: At 600FE100 len 00001EE8 (7 KiB): RTCRAM
I (261) spi_flash: detected chip: generic
I (265) spi_flash: flash io: dio
W (269) spi_flash: Detected size(8192k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (282) sleep: Configure to isolate all GPIO pins in sleep state
I (289) sleep: Enable automatic switching of GPIO sleep configuration
I (297) main_task: Started on CPU0
I (307) main_task: Calling app_main()
I (307) USB host lib: USB host library example
I (307) gpio: GPIO[13]| InputEn: 0| OutputEn: 1| OpenDrain: 0| Pullup: 0| Pulldown: 0| Intr:0 
I (317) gpio: GPIO[0]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:2 
I (327) USB host lib: Installing USB Host Library
I (367) CLASS: Registering Client
I (747) CLASS: Opening device at address 1
I (747) CLASS: Getting device information
I (747) CLASS:  Full speed
I (747) CLASS:  bConfigurationValue 1
I (747) CLASS: Getting device descriptor
*** Device descriptor ***
bLength 18
bDescriptorType 1
bcdUSB 2.00
bDeviceClass 0x0
bDeviceSubClass 0x0
bDeviceProtocol 0x0
bMaxPacketSize0 64
idVendor 0x46d
idProduct 0xc08f
bcdDevice 5.00
iManufacturer 1
iProduct 2
iSerialNumber 3
bNumConfigurations 1
I (777) CLASS: Getting config descriptor
*** Configuration descriptor ***
bLength 9
bDescriptorType 2
wTotalLength 59
bNumInterfaces 2
bConfigurationValue 1
iConfiguration 4
bmAttributes 0xa0
bMaxPower 300mA
        *** Interface descriptor ***
        bLength 9
        bDescriptorType 4
        bInterfaceNumber 0
        bAlternateSetting 0
        bNumEndpoints 1
        bInterfaceClass 0x3
        bInterfaceSubClass 0x1
        bInterfaceProtocol 0x2
        iInterface 0
                *** Endpoint descriptor ***
                bLength 7
                bDescriptorType 5
                bEndpointAddress 0x81   EP 1 IN
                bmAttributes 0x3        INT
                wMaxPacketSize 8
                bInterval 1
        *** Interface descriptor ***
        bLength 9
        bDescriptorType 4
        bInterfaceNumber 1
        bAlternateSetting 0
        bNumEndpoints 1
        bInterfaceClass 0x3
        bInterfaceSubClass 0x0
        bInterfaceProtocol 0x0
        iInterface 0
                *** Endpoint descriptor ***
                bLength 7
                bDescriptorType 5
                bEndpointAddress 0x82   EP 2 IN
                bmAttributes 0x3        INT
                wMaxPacketSize 20
                bInterval 1
I (857) CLASS: Getting Manufacturer string descriptor
Logitech
I (867) CLASS: Getting Product string descriptor
G403 HERO Gaming Mouse
I (867) CLASS: Getting Serial Number string descriptor
0C80387B3636

Let me know if you need anything further. I've been trying to troubleshoot this for months but unfortunately I couldn't figure it out.

Thank you!

@roma-jam
Copy link
Collaborator

roma-jam commented Dec 7, 2024

Hi @alex-k8 ,

Thanks for the prompt response. I‘ll try to find a way to reproduce the problem.

Meanwhile, could you try to reproduce it with esp-idf, release v5.1 and help to confirm, that the problem is also present there?

Thanks.

@alex-k8
Copy link
Author

alex-k8 commented Dec 7, 2024

Thank you @roma-jam
I'll downgrade and let you know. I usually reproduce it by spamming keys, but I'm not sure if that's actually what's causing it. I think I had let the esp run all night on its own, without pressing buttons, and the next morning it had not froze, so it's probably related to the callbacks that are called when receiving key input.

@alex-k8
Copy link
Author

alex-k8 commented Dec 7, 2024

Hey @roma-jam

I managed to reproduce it on v5.1.2. I reproduced it twice in about 10 minutes with my mouse. I think it's running either at 500 or 1000hz. Mouse data is definitely faster than keyboard data so if my theory is correct, it makes sense because the keyboard cannot send data that fast compared to the mouse.

So if you have a gaming mouse or something laying around, I suspect you will be able to reproduce it. Unfortunately I don't have another high polling rate mouse to test it. I tested it with a cheap aliexpress mouse and I couldn't reproduce it, at least in the 30 minutes that I tried.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@roma-jam roma-jam

Labels
Status: Opened Issue is new Type: Bug bugs in IDF
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@roma-jam @alex-k8 @espressif-bot