USB MSD example fails to mount a storage device

Hi,

I'm having trouble getting the USB MSD example working on the nRF52840. I have attached the terminal output from the example with debug level logging enabled for both USB and MSD.

As far as I can see there seems to be some issue with the MSD part as USB enumaration seems to work on both Windows and Linux. But on both the example seems to get stuck just after the host sends MSC_REQUEST_GET_MAX_LUN. I think the next log line after that means that the example does send a reponse back but for some reason this is where it fails. After that it just waits for about 20s and then the host sends a USB reset. I tried this on both Windows 10 and also Linux on completely different physical machines with different USB cables. I''m running the example on a nRF52840-Preview-DK (compiled for nrf52840dk_nrf840 in VSCode).

I have tried compiling for different memory and filesystem configurations but that doesn't seem to have any effect on this issue.

I have tried the USB CDC example on the same board and that seems to work well.

Can you advise what else I should try. I can't find anyone else having a similar issue so I'm a bit stuck.

Here is what dmesg on Ubuntu shows for this:

[99610.787545] usb 1-6.2: new full-speed USB device number 38 using xhci_hcd
[99610.890092] usb 1-6.2: New USB device found, idVendor=2fe3, idProduct=0008, bcdDevice= 3.02
[99610.890098] usb 1-6.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[99610.890100] usb 1-6.2: Product: Zephyr MSC sample
[99610.890102] usb 1-6.2: Manufacturer: ZEPHYR
[99610.890103] usb 1-6.2: SerialNumber: CD561E4B0B6207A7
[99610.895885] usb-storage 1-6.2:1.0: USB Mass Storage device detected
[99610.896036] scsi host7: usb-storage 1-6.2:1.0
[99642.779806] usb 1-6.2: reset full-speed USB device number 38 using xhci_hcd
[99654.309563] usb 1-6.2: USB disconnect, device number 38
[99812.850577] usb 1-14: reset high-speed USB device number 6 using xhci_hcd

*** Booting Zephyr OS build v3.2.99-ncs1 ***
Area 0 at 0x0 on mx25r6435f@0 for 131072 bytes
[00:00:00.249,816] <dbg> usb_descriptor: ascii7_to_utf16le: char 7 : 37, idx 15 -> 31
[00:00:00.249,847] <dbg> usb_descriptor: ascii7_to_utf16le: char A : 41, idx 14 -> 29
--- 41 messages dropped ---
[00:00:00.249,877] <dbg> usb_descriptor: ascii7_to_utf16le: char 7 : 37, idx 13 -> 27
[00:00:00.249,877] <dbg> usb_descriptor: ascii7_to_utf16le: char 0 : 30, idx 12 -> 25
[00:00:00.249,908] <dbg> usb_descriptor: ascii7_to_utf16le: char 2 : 32, idx 11 -> 23
[00:00:00.249,908] <dbg> usb_deMount /NAND:: 0
sc/NAND:: bsize = 512 ; frsize = 512 ; blocks = 216 ; bfree = 216
/NAND: opendir: 0
riEnd of files
ptor: ascii7_to_utf16le: char 6 : 36, idx 10 -> 21
[00:00:00.249,938] <dbg> usb_descriptor: ascii7_to_utf16le: char B : 42, idx 9 -> 19
[00:00:00.249,969] <dbg> usb_descriptor: ascii7_to_utf16le: char 0 : 30, idx 8 -> 17
[00:00:00.249,969] <dbg> usb_descriptor: ascii7_to_utf16le: char B : 42, idx 7 -> 15
[00:00:00.250,000] <dbg> usb_descriptor: ascii7_to_utf16le: char 4 : 34, idx 6 -> 13
[00:00:00.250,030] <dbg> usb_descriptor: ascii7_to_utf16le: char E : 45, idx 5 -> 11
[00:00:00.250,030] <dbg> usb_descriptor: ascii7_to_utf16le: char 1 : 31, idx 4 -> 9
[00:00:00.250,061] <dbg> usb_descriptor: ascii7_to_utf16le: char 6 : 36, idx 3 -> 7
[00:00:00.250,061] <dbg> usb_descriptor: ascii7_to_utf16le: char 5 : 35, idx 2 -> 5
[00:00:00.250,091] <dbg> usb_descriptor: ascii7_to_utf16le: char D : 44, idx 1 -> 3
[00:00:00.250,122] <dbg> usb_descriptor: ascii7_to_utf16le: char C : 43, idx 0 -> 1
[00:00:00.254,150] <inf> flashdisk: Initialize device NAND
[00:00:00.254,150] <inf> flashdisk: offset 0, sector size 512, page size 4096, volume size 131072
[00:00:00.254,211] <inf> usb_msc: Sect Count 256
[00:00:00.254,211] <inf> usb_msc: Memory Size 131072
[00:00:00.254,333] <inf> main: Test

[00:00:00.258,514] <inf> flashdisk: Initialize device NAND
[00:00:00.258,544] <inf> flashdisk: offset 0, sector size 512, page size 4096, volume size 131072
[00:00:00.319,763] <dbg> usb_device: usb_enable: lock usb_enable_lock mutex
[00:00:00.319,854] <dbg> usb_device: composite_setup_ep_cb: set cb, ep: 0x1
[00:00:00.319,854] <dbg> usb_device: composite_setup_ep_cb: set cb, ep: 0x81
[00:00:00.319,885] <dbg> usb_device: usb_enable: unlock usb_enable_lock mutex
[00:00:00.319,885] <inf> main: The device is put in USB mass storage mode.

[00:00:14.732,238] <dbg> usb_msc: mass_storage_status_cb: USB device connected
[00:00:14.732,238] <inf> main: USB Connected
[00:00:14.735,351] <dbg> usb_msc: mass_storage_status_cb: USB device suspended
[00:00:14.735,351] <inf> main: USB Suspended
[00:00:14.853,881] <dbg> usb_msc: mass_storage_status_cb: USB device reset detected
[00:00:14.853,973] <inf> main: USB Reset
[00:00:14.853,973] <dbg> usb_msc: mass_storage_status_cb: USB device resumed
[00:00:14.854,003] <inf> main: USB Resumed
[00:00:14.941,864] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:14.941,894] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0000
[00:00:14.941,925] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:14.942,016] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:14.942,169] <dbg> usb_msc: mass_storage_status_cb: USB device reset detected
[00:00:14.942,230] <inf> main: USB Reset
[00:00:15.040,832] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
--- 1 messages dropped ---
[00:00:15.040,863] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:15.041,015] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:15.047,668] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:15.047,698] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0000
[00:00:15.047,698] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:15.047,851] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:15.047,943] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:15.047,973] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0409
[00:00:15.047,973] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:15.048,126] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:15.048,217] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:15.048,248] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0000
[00:00:15.048,248] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:15.048,339] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:15.048,431] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
--- 14 messages dropped ---
[00:00:15.201,385] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0000
--- 9 messages dropped ---
[00:00:15.201,385] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:15.201,507] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:15.201,599] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:15.201,629] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0000
[00:00:15.201,660] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:15.201,721] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:15.201,843] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:15.201,873] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0409
[00:00:15.201,873] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:15.201,995] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:15.202,087] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:15.202,117] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0409
[00:00:15.202,148] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:15.202,270] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:15.204,650] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:15.204,681] <dbg> usb_device: custom_handler: bRequest 0x09, wIndex 0x0000
[00:00:15.204,711] <dbg> usb_device: usb_set_configuration: Set Configuration 1 request
[00:00:15.204,742] <dbg> usb_device: set_endpoint: Set endpoint 0x81 type 2 MPS 64
[00:00:15.204,742] <dbg> usb_device: set_endpoint: Set endpoint 0x1 type 2 MPS 64
[00:00:15.204,803] <dbg> usb_msc: mass_storage_status_cb: USB device configured
[00:00:15.204,803] <inf> main: USB Configured
[00:00:15.205,535] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:15.205,566] <dbg> usb_device: class_handler: bRequest 0xfe, wIndex 0x0000
[00:00:15.205,566] <dbg> usb_msc: mass_storage_class_handle_req: MSC_REQUEST_GET_MAX_LUN
[00:00:15.205,657] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:35.219,512] <dbg> usb_msc: mass_storage_status_cb: USB device reset detected
[00:00:35.219,604] <inf> main: USB Reset
[00:00:35.307,342] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:35.307,373] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0000
[00:00:35.307,403] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:35.307,525] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:35.307,586] <dbg> usb_msc: mass_storage_status_cb: USB device reset detected
[00:00:35.307,647] <inf> main: USB Reset
[00:00:35.406,311] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:35.406,341] <dbg> usb_device: custom_handler: bRequest 0x06, wIndex 0x0000
[00:00:35.406,341] <dbg> usb_device: usb_get_descriptor: Get Descriptor request
[00:00:35.406,494] <dbg> usb_device: usb_handle_control_transfer: ep 0x80, status 0x02
[00:00:35.406,555] <dbg> usb_device: usb_handle_control_transfer: ep 0x00, status 0x00
[00:00:35.406,585] <dbg> usb_device: custom_handler: bRequest 0x09, wIndex 0x0000
[00:00:35.406,616] <dbg> usb_device: usb_set_configuration: Set Configuration 1 request
[00:00:35.406,616] <dbg> usb_device: set_endpoint: Set endpoint 0x81 type 2 MPS 64
[00:00:35.406,646] <dbg> usb_device: set_endpoint: Set endpoint 0x1 type 2 MPS 64
[00:00:35.406,677] <dbg> usb_msc: mass_storage_status_cb: USB device configured
[00:00:35.406,677] <inf> main: USB Configured

  • Hi,

    It should run mostly fine on the nRF52840 DK almost straight out of the box.

    You only need to:

    1. Add CONFIG_APP_MSC_STORAGE_FLASH_FATFS=y to the project config.
    2. Expand the partition to 8MB by changing 0x0020000 to 0x08000000 in the overlay file.

    If it still doesn't work then you should get a DK, the PDK are outdated and not guaranteed to work.

    regards

    Jared 

  • Hi,

    I was worried the issue might be the outdated PDK so I will order a new kit as soon as possible. But while that is on it's way I tried porting this example to my own board. I added the QSPI and memory parts to my custom board DTS file and now this example does run and enumerate as a USB MSD device. But logs show a lot of runtime errors like this:

    [00:00:11.513,916] <err> qspi_nor: read error: address or size exceeds expected values.Addr: 0x7ff0000 size 512
    [00:00:11.513,946] <err> usb_msc: !! Disk Read Error 262016 !

    I used the exact same memory chip used on the dev kit but I have mapped it to different pins on the SOC. Files saved on the enumerated disk seem to be ok and I can read and write them. Is this likely to be a hardware error or is it something I didn't configure correctly?

    I'm also having trouble getting the memory integrated into my own application correctly. Since the example seems to run at least enough to enumerate I guess my DTS file has to correct. But my own application also has BLE and lots of other subsystems active and something is causing hardfaults. I have CONFIG_SETTINGS set and I think it uses the storage partition as well. I would ideally make a whole separate partition for the external flash and only put the filesystem on that for now. I can't find a good example explaining how to do that correctly. Can you point me in the right direction to do that?

  • Hi,

    Tiit said:
    I used the exact same memory chip used on the dev kit but I have mapped it to different pins on the SOC. Files saved on the enumerated disk seem to be ok and I can read and write them. Is this likely to be a hardware error or is it something I didn't configure correctly?

    Are you able to reproduce this when you use the recommended QSPI pins instead?

    Tiit said:
    I'm also having trouble getting the memory integrated into my own application correctly. Since the example seems to run at least enough to enumerate I guess my DTS file has to correct. But my own application also has BLE and lots of other subsystems active and something is causing hardfaults. I have CONFIG_SETTINGS set and I think it uses the storage partition as well. I would ideally make a whole separate partition for the external flash and only put the filesystem on that for now. I can't find a good example explaining how to do that correctly. Can you point me in the right direction to do that?

    Can you create a new ticket for this? It will make it easier for others with the same problem to follow this ticket if we only stick to 1 topic. 

    Thanks,

    regards

    Jared 

Related