USB host crash on remove device (IDFGH-5797) #7505

chegewara · 2021-09-01T12:58:17Z

Im not sure if it is bug or just i am still missing some code.

Description:

some random BT dongle connected with external power supply,
disconnect power supply from dongle, saola stays powered
code crashed (see logs)
the same crash when dongle is removed

Example to reproduce:

#include <stdio.h>
#include "freertos/FreeRTOS.h"
#include "freertos/task.h"
#include "esp_log.h"
#include "usb/usb_host.h"

usb_host_client_handle_t client_hdl;
uint8_t dev_addr = 2; 
usb_device_handle_t dev_hdl;

void client_event_callback(const usb_host_client_event_msg_t *event_msg, void *arg)
{
    if (event_msg->event == USB_HOST_CLIENT_EVENT_NEW_DEV)
    {
        ESP_LOGI("", "client event: %d, address: %d", event_msg->event, event_msg->new_dev.address);
        esp_err_t err = usb_host_device_open(client_hdl,  event_msg->new_dev.address, &dev_hdl);
        const usb_device_desc_t *device_desc;
        usb_host_get_device_descriptor(dev_hdl, &device_desc);
        ESP_LOG_BUFFER_HEX("", device_desc->val, USB_DEVICE_DESC_SIZE);
    }
}

void client_async_seq_task(void* param)
{
    const usb_host_client_config_t client_config = {
        .client_event_callback = client_event_callback,
        .callback_arg = NULL,
        .max_num_event_msg = 5
    };

    esp_err_t err = usb_host_client_register(&client_config, &client_hdl);
    ESP_LOGI("", "client register status: %d", err);

    while (1)
    {
        usb_host_client_handle_events(client_hdl, portMAX_DELAY);
    }
}

void app_main(void)
{
    const usb_host_config_t config = {
        .intr_flags = ESP_INTR_FLAG_LEVEL1,
    };
    esp_err_t err = usb_host_install(&config);
    ESP_LOGI("", "install status: %d", err);

    xTaskCreatePinnedToCore(client_async_seq_task, "async", 4096, NULL, 2, NULL, 0);
    while (1) {
        //Start handling system events
        uint32_t event_flags;
        usb_host_lib_handle_events(portMAX_DELAY, &event_flags);
        if (event_flags & USB_HOST_LIB_EVENT_FLAGS_NO_CLIENTS) {
            printf("No more clients\n");
            usb_host_device_free_all();
        }
        if (event_flags & USB_HOST_LIB_EVENT_FLAGS_ALL_FREE) {
            break;
        }
    }
}

crash logs:

ESP-ROM:esp32s2-rc4-20191025
Build:Oct 25 2019
rst:0x1 (POWERON),boot:0xa (SPI_FAST_FLASH_BOOT)
SPIWP:0xee
mode:DIO, clock div:1
load:0x3ffe6100,len:0x498
load:0x4004c000,len:0xa88
load:0x40050000,len:0x25a8
entry 0x4004c19c
I (65) cachņ~���~Սѥ���cache     : size 8KB, 4Ways, cache line size 32Byte
I (65) cpu_start: Pro cpu up.
I (76) cpu_start: Pro cpu start user code
I (77) cpu_start: cpu freq: 160000000
I (77) cpu_start: Application information:
I (81) cpu_start: Project name:     usb_host_arduino
I (87) cpu_start: App version:      1
I (91) cpu_start: Compile time:     Sep  1 2021 13:50:44
I (97) cpu_start: ELF file SHA256:  c7e01af088a88467...
I (103) cpu_start: ESP-IDF:          v4.4-dev-2875-g5f38b766a8
I (109) heap_init: Initializing. RAM available for dynamic allocation:
I (117) heap_init: At 3FF9E000 len 00002000 (8 KiB): RTCRAM
I (123) heap_init: At 3FFBF678 len 0003C988 (242 KiB): DRAM
I (129) heap_init: At 3FFFC000 len 00003A10 (14 KiB): DRAM
I (136) spi_flash: detected chip: generic
I (140) spi_flash: flash io: dio
I (144) cpu_start: Starting scheduler on PRO CPU.
I (209) : install status: 0
I (209) : client register status: 0
I (579) : client event: 0, address: 1
I (579) : 12 01 00 02 00 00 00 08 6d 04 34 c5 01 29 01 02 
I (579) : 00 01 
E (95929) USBH: Device 1 gone

assert failed: usbh_hal_chan_request_halt IDF/components/hal/usbh_hal.c:294 (chan_obj->flags.active && !chan_obj->flags.error_pending)


Backtrace:0x400234c7:0x3ffc0ad00x40026815:0x3ffc0af0 0x4002be49:0x3ffc0b10 0x4008c431:0x3ffc0c30 0x400878d0:0x3ffc0c50 0x40088c5c:0x3ffc0c70 0x400863b5:0x3ffc0c90 0x40085b0d:0x3ffc0cb0 0x400855b7:0x3ffc0cd0 0x4009a896:0x3ffc0d10 0x40028b5d:0x3ffc0d30 
0x400234c7: panic_abort at /home/chegewara/esp/master/components/esp_system/panic.c:391

0x40026815: esp_system_abort at /home/chegewara/esp/master/components/esp_system/esp_system.c:129

0x4002be49: __assert_func at /home/chegewara/esp/master/components/newlib/assert.c:85

0x4008c431: usbh_hal_chan_request_halt at /home/chegewara/esp/master/components/hal/usbh_hal.c:294 (discriminator 1)

0x400878d0: _pipe_cmd_halt at /home/chegewara/esp/master/components/usb/hcd.c:1726

0x40088c5c: hcd_pipe_command at /home/chegewara/esp/master/components/usb/hcd.c:2023

0x400863b5: usbh_process at /home/chegewara/esp/master/components/usb/usbh.c:353

0x40085b0d: usb_host_lib_handle_events at /home/chegewara/esp/master/components/usb/usb_host.c:483

0x400855b7: app_main at /home/chegewara/demos/esp32s2/usb_host_arduino/build/../main/usb_host_arduino.c:52

0x4009a896: main_task at /home/chegewara/esp/master/components/freertos/port/port_common.c:136 (discriminator 2)

0x40028b5d: vPortTaskWrapper at /home/chegewara/esp/master/components/freertos/port/xtensa/port.c:159

esp-idf branch: master
board: esp32S2 saola

The text was updated successfully, but these errors were encountered:

chegewara · 2021-09-05T22:16:01Z

I have another bug/crash in USB host.
I know esp32 S2 and stack does not support hub, but IMO connecting USB HUB should not cause crash:

E (732) HUB: Configuration descriptor too small

assert failed: usbh_hal_chan_request_halt IDF/components/hal/usbh_hal.c:294 (chan_obj->flags.active && !chan_obj->flags.error_pending)


Backtrace:0x4002346b:0x3ffc21400x40026825:0x3ffc2160 0x4002bea1:0x3ffc2180 0x4008de59:0x3ffc22a0 0x400892c8:0x3ffc22c0 0x4008a684:0x3ffc22e0 0x4008b002:0x3ffc2300 0x4008b17b:0x3ffc2320 0x4008b3f2:0x3ffc2340 0x40086d21:0x3ffc2360 0x40085d41:0x3ffc2380 0x40028c05:0x3ffc23b0 
0x4002346b: panic_abort at /home/chegewara/esp/master/components/esp_system/panic.c:391

0x40026825: esp_system_abort at /home/chegewara/esp/master/components/esp_system/esp_system.c:129

0x4002bea1: __assert_func at /home/chegewara/esp/master/components/newlib/assert.c:85

0x4008de59: usbh_hal_chan_request_halt at /home/chegewara/esp/master/components/hal/usbh_hal.c:294 (discriminator 1)

0x400892c8: _pipe_cmd_halt at /home/chegewara/esp/master/components/usb/hcd.c:1726

0x4008a684: hcd_pipe_command at /home/chegewara/esp/master/components/usb/hcd.c:2023

0x4008b002: enum_stage_cleanup_failed at /home/chegewara/esp/master/components/usb/hub.c:450

0x4008b17b: enum_handle_events at /home/chegewara/esp/master/components/usb/hub.c:515

0x4008b3f2: hub_process at /home/chegewara/esp/master/components/usb/hub.c:652

0x40086d21: usb_host_lib_handle_events at /home/chegewara/esp/master/components/usb/usb_host.c:486

0x40085d41: client_async_seq_task(void*) at /home/chegewara/demos/esp32s2/usb_host_arduino/components/usb_host/host/usb_host.cpp:31

0x40028c05: vPortTaskWrapper at /home/chegewara/esp/master/components/freertos/port/xtensa/port.c:159

leemagnusson · 2021-10-26T14:50:26Z

It would be nice if this could be fixed. Adding to the first issue I also noticed that the crash seems to be before the client callback is called. So the below code is not executed.

} else if (event_msg->event == USB_HOST_CLIENT_EVENT_DEV_GONE) {
        ESP_LOGI(TAG, "device gone");

Dazza0 · 2021-10-27T05:54:29Z

@leemagnusson We have already have a fix in the works pending an internal review.

This commit fixes how the USBH handling of a sudden device disconnection, more specifically handling of device gone. - Previously the USBH would only halt, flush, and dequeue the device's default EP, then send a device gone event to the Host Library layer. - Now the USBH will also halt and flush all non-default EPs, allowing all of the URBs to be dequeud. - Some internal object members are now protected by a mutex instead of a spinlock. Closes #7505

chegewara · 2021-11-04T08:06:38Z

Hi @Dazza0
i see no longer crash on remove, but i am having some problem with re-register client.

Logs seems to be ok on first look, but i think there is some lock somewhere:

I (320) : client register status: 0
create async task
usb_host_lib_handle_events event_flags: 0
usb_host_lib_handle_events event_flags: 0
usb_host_lib_handle_events event_flags: 0
usb_host_lib_handle_events event_flags: 0
usb_host_lib_handle_events event_flags: 0
usb_host_lib_handle_events event_flags: 0
usb_host_lib_handle_events event_flags: 0
I (11801) USB_HOST_CLIENT_EVENT_NEW_DEV: client event: 0, address: 1
W (11808) : usb_host_client_event_msg_t event: 0
I (11814) USB_HOST_CLIENT_EVENT_NEW_DEV: device speed: USB_SPEED_LOW, device address: 1, max ep_ctrl size: 8, config: 1
usb_host_lib_handle_events event_flags: 0
E (13160) USBH: Device 1 gone
usb_host_lib_handle_events event_flags: 0
I (13160) USB_HOST_CLIENT_EVENT_DEV_GONE: client event: 1
W (13163) : usb_host_client_event_msg_t event: 1
usb_host_lib_handle_events event_flags: 2
usb_host_lib_handle_events event_flags: 1
No more clients
delete async task

--------------> here i am trying again call usb_host_client_register()
I (13179) : client register status: 0
create async task
usb_host_lib_handle_events event_flags: 0

// no more events even if i unplug and plug device again

As you can see, when device is connected first time we have 7 usb_host_lib_handle_events with event 0, and second time there is only 1 event.

btw do we need to know what is event 0 and do we have to make use of it?
ESP-IDF: v5.0-dev-178-g417ef24b06-dirty
board: S2 saola

ok, i found the problem register/deregister client is not enough, it is also required to install/uninstall host each time; im not sure if it is by design, so please comment

Thanks

Dazza0 · 2021-11-04T11:04:09Z

@chegewara Having to uninstall to recover from a DCONN is a bit undesirable IMO (but I'm guessing the reason why that's working for you now is that the reinstall resets the underlying HCD port).

Ideally, connections should be detectable again as soon as the last client of a previously DCONN'd device has closed that device. I'll see about adding either some new API to recover the port explicitly or make the recovery automatic.

chegewara · 2021-11-04T11:11:04Z

Thanks
I can provide simple test app to show this case.

This commit fixes how the USB Host HCD handles sudden disconnections. Bugs: - HW channels remain active when the port suddenly disconnects, and previously the channel would be disabled by setting the disabled bit, then waiting for a disabled interrupt. However, ISOC channels do not generate the disabled interrupt when the port is invalid, thus leading to tasks getting indefinitely blocked in hcd_pipe_command(). Fix: On a sudden disconnection, forcibly treat all channels as halted even if their HCCHAR.ChEna bit is still set. We do a soft reset after a port error anyways, so the channels will eventually be reset. Closes #7505

This commit fixes how the USBH handling of a sudden device disconnection, more specifically handling of device gone. - Previously the USBH would only halt, flush, and dequeue the device's default EP, then send a device gone event to the Host Library layer. - Now the USBH will also halt and flush all non-default EPs, allowing all of the URBs to be dequeud. - Some internal object members are now protected by a mutex instead of a spinlock. Closes #7505

espressif-bot added the Status: Opened Issue is new label Sep 1, 2021

github-actions bot changed the title ~~USB host crash on remove device~~ USB host crash on remove device (IDFGH-5797) Sep 1, 2021

Dazza0 self-assigned this Sep 2, 2021

espressif-bot added Status: In Progress Work is in progress and removed Status: Opened Issue is new labels Oct 27, 2021

Dazza0 mentioned this issue Oct 27, 2021

Support USB host control IN transfers (IDFGH-6108) #7786

Closed

espressif-bot added Resolution: NA Issue resolution is unavailable Status: Done Issue is done internally Resolution: Done Issue is done internally and removed Status: In Progress Work is in progress Resolution: NA Issue resolution is unavailable labels Nov 2, 2021

espressif-bot closed this as completed in 0c758c8 Nov 4, 2021

chegewara mentioned this issue Nov 25, 2021

ESP32S2 host crash when removing device chegewara/EspTinyUSB#62

Open

Dazza0 mentioned this issue Dec 13, 2021

[USB host] failed to run on S3, works fine on S2 (IDFGH-6402) #8061

Closed

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

USB host crash on remove device (IDFGH-5797) #7505

USB host crash on remove device (IDFGH-5797) #7505

chegewara commented Sep 1, 2021

chegewara commented Sep 5, 2021

leemagnusson commented Oct 26, 2021

Dazza0 commented Oct 27, 2021

chegewara commented Nov 4, 2021 •

edited

Loading

Dazza0 commented Nov 4, 2021

chegewara commented Nov 4, 2021

USB host crash on remove device (IDFGH-5797) #7505

USB host crash on remove device (IDFGH-5797) #7505

Comments

chegewara commented Sep 1, 2021

chegewara commented Sep 5, 2021

leemagnusson commented Oct 26, 2021

Dazza0 commented Oct 27, 2021

chegewara commented Nov 4, 2021 • edited Loading

Dazza0 commented Nov 4, 2021

chegewara commented Nov 4, 2021

chegewara commented Nov 4, 2021 •

edited

Loading