[v5.1.2] USB crashes in hub.c when unplugging device (IDFGH-12331)

chipweinberger commented 7 months ago

Answers checklist.

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

IDF version.

v5.1.2

Espressif SoC revision.

esp32s3

Operating System used.

macOS

How did you build your project?

Command line with idf.py

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

None

Development Kit.

devkit-c

Power Supply used.

USB

What is the expected behavior?

no crash

What is the actual behavior?

crashes ~10% of the time when unplugging a USB device, at abort(); //Should never occur

This is because the hub is in state HUB_DRIVER_STATE_ROOT_RECOVERY

        case HCD_PORT_EVENT_DISCONNECTION:
        case HCD_PORT_EVENT_ERROR:
        case HCD_PORT_EVENT_OVERCURRENT: {
            bool pass_event_to_usbh = false;
            HUB_DRIVER_ENTER_CRITICAL();
            switch (p_hub_driver_obj->dynamic.driver_state) {
                case HUB_DRIVER_STATE_ROOT_POWERED: //This occurred before enumeration
                case HUB_DRIVER_STATE_ROOT_ENUM_FAILED: //This occurred after a failed enumeration.
                    //Therefore, there's no device and we can go straight to port recovery
                    p_hub_driver_obj->dynamic.flags.actions |= HUB_DRIVER_FLAG_ACTION_PORT_RECOVER;
                    break;
                case HUB_DRIVER_STATE_ROOT_ENUM:
                    //This occurred during enumeration. Therefore, we need to recover the failed enumeration
                    p_hub_driver_obj->dynamic.flags.actions |= HUB_DRIVER_FLAG_ACTION_ENUM_EVENT;
                    p_hub_driver_obj->single_thread.enum_ctrl.stage = ENUM_STAGE_CLEANUP_FAILED;
                    break;
                case HUB_DRIVER_STATE_ROOT_ACTIVE:
                    //There was an enumerated device. We need to indicate to USBH that the device is gone
                    pass_event_to_usbh = true;
                    break;
                default:
                    abort();    //Should never occur 
                    break;
            }
            p_hub_driver_obj->dynamic.driver_state = HUB_DRIVER_STATE_ROOT_RECOVERY;
            HUB_DRIVER_EXIT_CRITICAL();
            if (pass_event_to_usbh) {
                assert(p_hub_driver_obj->single_thread.root_dev_hdl);
                ESP_ERROR_CHECK(usbh_hub_pass_event(p_hub_driver_obj->single_thread.root_dev_hdl, USBH_HUB_EVENT_PORT_ERROR));
            }
            break;
        }

Steps to reproduce.

unplug usb device

Debug Logs.

(10768) pd midi usb IN: 10.326 (usb open time)
junk: 10.328 | Cb:0 Ch:0  | Note Off A#4 vel:127
jmx-console> I (11568) pd usbh: wait for all devices to close...
E (11968) USBH: Device 1 gone
semaphore: 14
I (11968) : e1 : [pd usbh] USB TRANSFER FAILED - no device
e2 : [pd usbh [device]] pd_usbh_service_submitTransferAndWait() failed.
e3 : [pd midi usb IN] xfer IN task: DEV GONE

W (11968) pd usbh: [client task] DEV_GONE dev_hdl: 0x3c3b7100
I (11968) pd midi usb IN: xferInTask_loop ended. wait for usb replug.
I (11978) pd alerts: notify usb
I (11978) pd buzz: USB Device Removed Sound
W (11978) pd usbh: [close device] closing, dev_hdl: 0x3c3b7100
buzz F 4 698Hz 100ms
I (11978) pd usbh: [close device] unblocking usb transfer 3
I (11978) pd usbh: usb_host_interface_release(0x3c3b609c, device: 0x3c3b7100, bInterfaceNumber: 1
I (11988) pd usbh: interface fully released
I (11988) pd usbh: [close device] usb_host_device_close(client:0x3c3b609c,dev:0x3c3b7100)
I (11988) pd usbh: [close device] 0 devices still open
I (11968) pd usbh: [host task] usb_host_lib_handle_events()

abort() was called at PC 0x42090a07 on core 0
0x42090a07: root_port_handle_events at /Volumes/User/MBP-Google-Drive/jamcorder/firmware/esp-idf/components/usb/hub.c:838
 (inlined by) hub_process at /Volumes/User/MBP-Google-Drive/jamcorder/firmware/esp-idf/components/usb/hub.c:1043

Backtrace: 0x40376037:0x3c3b5c00 0x40384b3d:0x3c3b5c30 0x4038d837:0x3c3b5c60 0x42090a07:0x3c3b5ce0 0x4208b49b:0x3c3b5d30 0x4204777f:0x3c3b5d70 0x40385aae:0x3c3b5da0
0x40376037: panic_abort at /Volumes/User/MBP-Google-Drive/jamcorder/firmware/esp-idf/components/esp_system/panic.c:452

0x40384b3d: esp_system_abort at /Volumes/User/MBP-Google-Drive/jamcorder/firmware/esp-idf/components/esp_system/port/esp_system_chip.c:84

0x4038d837: abort at /Volumes/User/MBP-Google-Drive/jamcorder/firmware/esp-idf/components/newlib/abort.c:38

0x42090a07: root_port_handle_events at /Volumes/User/MBP-Google-Drive/jamcorder/firmware/esp-idf/components/usb/hub.c:838
 (inlined by) hub_process at /Volumes/User/MBP-Google-Drive/jamcorder/firmware/esp-idf/components/usb/hub.c:1043

0x4208b49b: usb_host_lib_handle_events at /Volumes/User/MBP-Google-Drive/jamcorder/firmware/esp-idf/components/usb/usb_host.c:515

0x4204777f: usbHostTaskLoop(void*) at /Volumes/User/MBP-Google-Drive/jamcorder/firmware/jamcorder-firmware/jcommon/usb/pd_usbh_service.cpp:70

0x40385aae: vPortTaskWrapper at /Volumes/User/MBP-Google-Drive/jamcorder/firmware/esp-idf/components/freertos/FreeRTOS-Kernel/portable/xtensa/port.c:162

More Information.

See original issue: https://github.com/espressif/esp-idf/issues/9707

chipweinberger commented 7 months ago

The USB device causing the crash is an Akai LPK25: https://www.akaipro.com/lpk25-mk2

chipweinberger commented 7 months ago

also : See original issue: https://github.com/espressif/esp-idf/issues/9707

tore-espressif commented 7 months ago

@chipweinberger I'm really sorry about the extraordinary time this issue is reported. We had troubles reproducing it.

Now, we have a test that can reproduce it and we are looking for the root cause. Thank you for your patience, we'll let you know as soon as we identify the problem

chipweinberger commented 7 months ago

thanks. please let me know when the cause is found & fixed

I'd like to add the fix to my product asap

chipweinberger commented 7 months ago

any updates?

chipweinberger commented 6 months ago

bump

roma-jam commented 6 months ago

Hi @chipweinberger, Thanks for bumping, it is always good to know that someone is waiting for the solution.

Currently, we are in the final steps of refactoring (to support external hubs) usb host library, so we will be back with the new code asap.

chipweinberger commented 4 months ago

@Dazza0 any thoughts?

paulblid commented 1 month ago

Hi,

I am encountering this same issue with a BG95 module connected via USB, IDF v5.3.0, right as the device is about to disconnect this abort is triggered, I am seeing this at a roughly 1 in 30 usb disconnects.

Is there any known workaround to this while we wait for an official fix?

thank you!

roma-jam commented 1 month ago

Hi @paulblid ,

Could you share the backtrace log? There were several changes made in v5,3, so it is better to have a freash backtrace log to check that the problem is the same.

Thanks.

espressif / esp-idf