USB MSC reconnection failed (IDFGH-8121)

rmshub commented 2 years 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.0-beta1

Operating System used.

Linux

How did you build your project?

VS Code IDE

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

No response

Development Kit.

ESP32-S3 Parallel TFT with Touch 3.5'' ILI9488 Makerfabs

Power Supply used.

USB

What is the expected behavior?

Disconnect and connect USB MSC should work without error

What is the actual behavior?

Disconnect and connect USB MSC memory disk is not working.

Steps to reproduce.

Run USB MSC example

Debug Logs.

SPIWP:0xee
mode:DIO, clock div:1
load:0x3fce3810,len:0x163c
load:0x403c9700,len:0xbd0
load:0x403cc700,len:0x2d68
entry 0x403c9900
I (29) boot: ESP-IDF v5.0-beta1 2nd stage bootloader
I (29) boot: compile time 02:57:52
I (29) boot: chip revision: V001
I (31) boot_comm: chip revision: 1, min. bootloader chip revision: 0
I (38) boot.esp32s3: Boot SPI Speed : 80MHz
I (43) boot.esp32s3: SPI Mode       : DIO
I (48) boot.esp32s3: SPI Flash Size : 2MB
I (53) boot: Enabling RNG early entropy source...
I (58) boot: Partition Table:
I (62) boot: ## Label            Usage          Type ST Offset   Length
I (69) boot:  0 nvs              WiFi data        01 02 00009000 00006000
I (76) boot:  1 phy_init         RF data          01 01 0000f000 00001000
I (84) boot:  2 factory          factory app      00 00 00010000 00100000
I (91) boot: End of partition table
I (96) boot_comm: chip revision: 1, min. application chip revision: 0
I (103) esp_image: segment 0: paddr=00010020 vaddr=3c030020 size=0d9dch ( 55772) map
I (121) esp_image: segment 1: paddr=0001da04 vaddr=3fc91b00 size=02614h (  9748) load
I (124) esp_image: segment 2: paddr=00020020 vaddr=42000020 size=2fdb0h (196016) map
I (163) esp_image: segment 3: paddr=0004fdd8 vaddr=3fc94114 size=00654h (  1620) load
I (164) esp_image: segment 4: paddr=00050434 vaddr=40374000 size=0da38h ( 55864) load
I (181) esp_image: segment 5: paddr=0005de74 vaddr=50000000 size=00010h (    16) load
I (187) boot: Loaded app from partition at offset 0x10000
I (188) boot: Disabling RNG early entropy source...
I (201) cpu_start: Pro cpu up.
I (202) cpu_start: Starting app cpu, entry point is 0x403751f4
I (0) cpu_start: App cpu up.
I (216) cpu_start: Pro cpu start user code
I (216) cpu_start: cpu freq: 160000000 Hz
I (216) cpu_start: Application information:
I (219) cpu_start: Project name:     usb-msc
I (224) cpu_start: App version:      1
I (228) cpu_start: Compile time:     Aug 24 2022 02:58:56
I (235) cpu_start: ELF file SHA256:  650e093eb0f940e8...
I (241) cpu_start: ESP-IDF:          v5.0-beta1
I (246) heap_init: Initializing. RAM available for dynamic allocation:
I (253) heap_init: At 3FC95210 len 0004ADF0 (299 KiB): D/IRAM
I (259) heap_init: At 3FCE0000 len 0000EE34 (59 KiB): STACK/DRAM
I (266) heap_init: At 3FCF0000 len 00008000 (32 KiB): DRAM
I (272) heap_init: At 600FE010 len 00001FF0 (7 KiB): RTCRAM
I (279) spi_flash: detected chip: gd
I (283) spi_flash: flash io: dio
W (287) spi_flash: Detected size(16384k) larger than the size in the binary image header(2048k). Using the size in the binary image header.
I (301) cpu_start: Starting scheduler on PRO CPU.
I (0) cpu_start: Starting scheduler on APP CPU.
I (321) gpio: GPIO[10]| InputEn: 1| OutputEn: 0| OpenDrain: 0| Pullup: 1| Pulldown: 0| Intr:0 
I (351) example: Waiting for USB stick to be connected
0x403751f4: call_start_cpu1 at /opt/esp/idf/components/esp_system/port/cpu_start.c:154

I (721) example: MSC device connected
I (721) example: connection...
*** Device descriptor ***
bLength 18
bDescriptorType 1
bcdUSB 2.00
bDeviceClass 0x0
bDeviceSubClass 0x0
bDeviceProtocol 0x0
bMaxPacketSize0 64
idVendor 0x54c
idProduct 0x439
bcdDevice 1.00
iManufacturer 1
iProduct 2
iSerialNumber 3
bNumConfigurations 1
*** Configuration descriptor ***
bLength 9
bDescriptorType 2
wTotalLength 32
bNumInterfaces 1
bConfigurationValue 1
iConfiguration 0
bmAttributes 0x80
bMaxPower 200mA
        *** Interface descriptor ***
        bLength 9
        bDescriptorType 4
        bInterfaceNumber 0
        bAlternateSetting 0
        bNumEndpoints 2
        bInterfaceClass 0x8
        bInterfaceSubClass 0x6
        bInterfaceProtocol 0x50
        iInterface 0
                *** Endpoint descriptor ***
                bLength 7
                bDescriptorType 5
                bEndpointAddress 0x81   EP 1 IN
                bmAttributes 0x2        BULK
                wMaxPacketSize 64
                bInterval 0
                *** Endpoint descriptor ***
                bLength 7
                bDescriptorType 5
                bEndpointAddress 0x2    EP 2 OUT
                bmAttributes 0x2        BULK
                wMaxPacketSize 64
                bInterval 0
Device info:
         Capacity: 7639 MB
         Sector size: 512
         Sector count: 15645119
         PID: ***
         VID: ***
         iProduct: Storage Media 
         iManufacturer: Sony
         iSerialNumber: ******
I (2951) example: Reading file
I (2951) example: Read from file: 'Hello World!'
/**< discarded repeated Reading file logs */
E (59856) USBH: Device 1 gone
I (59856) example: MSC device disconnected
I (59856) example: Waiting for USB stick to be connected
I (72016) example: MSC device connected
I (72026) example: connection...
E (73106) Transfer failed: Status 3
E (73106) USB_MSC: msc_bulk_transfer(533): 
E (73106) USB_MSC_SCSI: bot_execute_command(292): 
E (73106) USB_MSC_SCSI: scsi_cmd_sense(384): 
E (73106) USB_MSC: msc_wait_for_ready_state(183): 
E (73116) USB_MSC: msc_host_install_device(368): 
ESP_ERROR_CHECK failed: esp_err_t 0x107 (ESP_ERR_TIMEOUT) at 0x42008b17
0x42008b17: app_main at /root/msc/main/msc_example_main.c:195 (discriminator 1)

file: "./main/msc_example_main.c" line 195
func: app_main
expression: msc_host_install_device(device_address, &msc_device)

More Information.

No response

rmshub commented 2 years ago

Hi Team,

Any clue on this error ?

rmshub commented 2 years ago

Any clue in this issue ?

espzav commented 2 years ago

@MaValki please, could you look at it?

MaValki commented 2 years ago

Hi, thank you for detailed description. I was not able to replicate this issue with three USB drives I have at hand. Although, based on provided log I assume it might has something to do with transfer timeout. According to USB specification, device may delay up to 5 seconds. Try to change xfer->timeout_ms to 5000 in components/src/msc_host.c on lines 529 and 547 Please let me know whether it helps or not.

rmshub commented 2 years ago

@MaValki Thanks for update. After updating timeout_ms to 5000, it is working as expected.

MaValki commented 2 years ago

Thank you @rmshub, I'll fix it.

tore-espressif commented 1 year ago

Fixed in usb_host_msc version 1.0.2

Alvin1Zhang commented 1 year ago

Thanks for reporting, feel free to reopen.

espressif / esp-idf