USB: DW driver does not work properly with mass storage class

[jfischer-no]

DW USB device driver does not work properly with mass storage class (MSC).

Tested with sample/subsys/usb/mass on Arduino 101 connected to Linux host:

• does not work on UHCI. Arduino 101 flashed with the sample can be enumerated by the host, after detecting the mass storage device, the host resets the device several times because the device stops respond to requests. Works sometimes (mount, read and write to partition) on UHCI with path introduced in USB:Flush tx fifo when available space not enough #5496.
• does not work on XHCI. Behavior is similar to above, in addition, the partition will not be detected.
  There is also a note in sample/subsys/usb/mass/README.txt about issues with Arduino 101.

I have also tested sample/subsys/usb/mass on FRDM-K64F with #542 and I have not observed any problems with Linux and Windows 7 host.

Similar behavior was observed under Windows OS, see #5496

[jfischer-no]

@finikorg Can you test please sample/subsys/usb/mass on quark_se_c1000_devboard?

[finikorg]

@jfischer-phytec-iot Should it build without extra configuration? I cannot do fresh build only specifying the board.

disk_access_flash.c:21:27: error: ‘CONFIG_DISK_ERASE_BLOCK_SIZE’ undeclared here (not in a function)
 static u8_t read_copy_buf[CONFIG_DISK_ERASE_BLOCK_SIZE];
                           ^~~~~~~~~~~~~~~~~~~~~~~~~~~~

This is defined only for:
boards/x86/arduino_101/Kconfig.defconfig:config DISK_ERASE_BLOCK_SIZE

[jfischer-no]

@finikorg another issue 😄, it should build with DISK_ACCESS_RAM enabled.

--- a/samples/subsys/usb/mass/prj.conf
+++ b/samples/subsys/usb/mass/prj.conf
@@ -17,8 +17,8 @@ CONFIG_SYS_LOG_USB_MASS_STORAGE_LEVEL=1
 #CONFIG_FILE_SYSTEM=y
 
 #SPI flash related configs
-CONFIG_DISK_ACCESS_FLASH=y
-CONFIG_SPI=y
+#CONFIG_DISK_ACCESS_FLASH=y
+#CONFIG_SPI=y
 
 #Want RAM DISK instead ? comment the whole flash block and uncomment
-#CONFIG_DISK_ACCESS_RAM=y
+CONFIG_DISK_ACCESS_RAM=y

[finikorg]

@jfischer-phytec-iot that configuration seems to work somehow. I see new disk added in my (virtual) Linux

[80370.696107] usb 1-2.8.2: reset full-speed USB device number 5 using uhci_hcd
[80476.591288] usb 1-2.8.2: USB disconnect, device number 5
[80490.484192] usb 1-2.8.2: new full-speed USB device number 6 using uhci_hcd
[80490.809696] usb 1-2.8.2: New USB device found, idVendor=2fe3, idProduct=0100
[80490.809699] usb 1-2.8.2: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[80490.809701] usb 1-2.8.2: Product: USB-DEV
[80490.809738] usb 1-2.8.2: Manufacturer: ZEPHYR
[80490.809740] usb 1-2.8.2: SerialNumber: 0.01
[80490.818195] usb-storage 1-2.8.2:1.0: USB Mass Storage device detected
[80490.818656] scsi host2: usb-storage 1-2.8.2:1.0
[80491.860398] scsi 2:0:0:0: Direct-Access     ZEPHYR   ZEPHYR USB DISK  0.01 PQ: 0 ANSI: 0 CCS
[80491.876222] sd 2:0:0:0: Attached scsi generic sg2 type 0
[80491.906381] sd 2:0:0:0: [sdb] 32 512-byte logical blocks: (16.4 kB/16.0 KiB)
[80491.926938] sd 2:0:0:0: [sdb] Write Protect is off
[80491.926941] sd 2:0:0:0: [sdb] Mode Sense: 03 00 00 00
[80491.947771] sd 2:0:0:0: [sdb] No Caching mode page found
[80491.949092] sd 2:0:0:0: [sdb] Assuming drive cache: write through
[80492.163342]  sdb:
[80492.311284] sd 2:0:0:0: [sdb] Attached SCSI removable disk

I can create partition:

Disk /dev/sdb: 16 KiB, 16384 bytes, 32 sectors
Units: sectors of 1 * 512 = 512 bytes
Sector size (logical/physical): 512 bytes / 512 bytes
I/O size (minimum/optimal): 512 bytes / 512 bytes
Disklabel type: dos
Disk identifier: 0x7f018a19

Device     Boot Start End Sectors  Size Id Type
/dev/sdb1           1  31      31 15.5K 83 Linux

I think that the size of the disk is a bit small to create file system, how do you test it?

[jfischer-no]

There is a text file on it. You can also test it with something like:

dd if=/dev/urandom of=test.in bs=16k count=1
dd if=test.in of=/dev/sdb; sync
dd if=/dev/sdb of=test.out
diff test.in test.out

[jfischer-no]

I found usb analyzer in our storage room.

The error seems to be in the usb_dw_tx . Below kernel log and the screenshots (master and #5496)

[60101.323665] usb-storage 9-2:1.0: USB Mass Storage device detected              
[60101.323956] scsi host8: usb-storage 9-2:1.0                              
[60102.338663] scsi 8:0:0:0: Direct-Access     ZEPHYR   ZEPHYR USB DISK  0.01 PQ: 0 ANSI: 0 CCS
[60102.339253] sd 8:0:0:0: Attached scsi generic sg3 type 0                                  
[60102.344582] sd 8:0:0:0: [sdc] 4096 512-byte logical blocks: (2.10 MB/2.00 MiB) 
[60102.347655] sd 8:0:0:0: [sdc] Write Protect is off                                        
[60102.347659] sd 8:0:0:0: [sdc] Mode Sense: 03 00 00 00                          
[60102.350645] sd 8:0:0:0: [sdc] No Caching mode page found                 
[60102.350650] sd 8:0:0:0: [sdc] Assuming drive cache: write through                         
[60102.490702] sd 8:0:0:0: [sdc] Attached SCSI removable disk                     
[60102.637594] usb 9-2: reset full-speed USB device number 23 using uhci_hcd                 
[60102.961482] usb 9-2: reset full-speed USB device number 23 using uhci_hcd                 
[60103.277449] usb 9-2: reset full-speed USB device number 23 using uhci_hcd                 
[60103.593552] usb 9-2: reset full-speed USB device number 23 using uhci_hcd                 
[60103.905564] usb 9-2: reset full-speed USB device number 23 using uhci_hcd      
[60104.221484] usb 9-2: reset full-speed USB device number 23 using uhci_hcd                 
[60104.389645] sd 8:0:0:0: [sdc] tag#0 FAILED Result: hostbyte=DID_ERROR driverbyte=DRIVER_OK
[60104.389651] sd 8:0:0:0: [sdc] tag#0 CDB: Read(10) 28 00 00 00 0f 80 00 00 08 00           
[60104.389654] print_req_error: I/O error, dev sdc, sector 3968                              
[60104.729527] usb 9-2: reset full-speed USB device number 23 using uhci_hcd

sample/subsys/usb/mass, master

sample/subsys/usb/mass, #5496

@SavinayDharmappa FYI

[nashif]

@finikorg are you looking at this bug?

[finikorg]

@nashif Yes, at the moment I see that when sending data we sometimes "send" extra 4 bytes, apparently left from the previous send operation. This is clearly seen in the trace below. The extra 4 bytes is CSW Signature, which is first 4 bytes of usual reply sent to this endpoint. If we remove these 4 bytes the operation would succeed. Looks like issue with USD DW driver, although the MSC code is not very good in terms that it handles most of operations in callbacks called from ISR, it would be better to use packets queues and processing in threads, ...

After receiving this message Linux resets USB device, and since we do not reset our USB stack usually everything works even after reset.

[finikorg]

Root cause is the same as for #3515

[nashif]

@finikorg so is this fixed? Can we close it?

[finikorg]

@nashif we still have no solution yet for this issue

[jfischer-no]

It behaves differently now, I noticed it when I tested #4661 on Arduino 101. With the longer cable it works without problems on xhci, if the cable is short (0.5m), the host resets the device again and again. @finikorg What about quark_se_c1000_devboard?

[finikorg]

@jfischer-phytec-iot I see the same issue like before, first 4 bytes duplicated.

[galak]

You guys still work on this?

[laperie]

@jfischer-phytec-iot - Is this isssue still relevant to you?

[jfischer-no]

@laperie It is not relevant, but in consideration of all the USB issues on this SiP/SoC we maybe have to disable USB support on Arduino 101 or at last document all the issues?

[laperie]

@jfischer-phytec-iot actually, Arduino 101 is no longer (officially) supported, as per @nashif . So we can just close this one