On Fri, 17 Jun 2016, Michael Schaller wrote: > Alan, here is the requested information. Sorry for the delay. > > Started usbmon log with no connected USB devices: > $ sudo cat /sys/kernel/debug/usb/usbmon/0u | tee usbmon.txt > ... > > See the attached usbmon.txt.gz Okay, it's got what we need. > Timing: > > Connect of flash drive at: 16:09:04 > > > dmesg output after connect of flash drive: > [ 421.660488] usb 2-2: new SuperSpeed USB device number 3 using xhci_hcd > [ 421.677113] usb 2-2: New USB device found, idVendor=05dc, idProduct=a212 > [ 421.677116] usb 2-2: New USB device strings: Mfr=1, Product=2, SerialNumber=3 > [ 421.677118] usb 2-2: Product: USB Flash Drive > [ 421.677119] usb 2-2: Manufacturer: Lexar > [ 421.677121] usb 2-2: SerialNumber: 0C5E8B182D1D474C This is basically a thumb drive? > [ 421.861807] usb-storage 2-2:1.0: USB Mass Storage device detected > [ 421.862034] scsi host2: usb-storage 2-2:1.0 > [ 421.862194] usbcore: registered new interface driver usb-storage > [ 421.865557] usbcore: registered new interface driver uas > [ 422.861240] scsi 2:0:0:0: Direct-Access Lexar USB Flash > Drive PMAP PQ: 0 ANSI: 6 > [ 422.862053] sd 2:0:0:0: Attached scsi generic sg1 type 0 > [ 422.863780] sd 2:0:0:0: [sdb] 125173760 512-byte logical blocks: > (64.1 GB/59.7 GiB) > [ 422.864287] sd 2:0:0:0: [sdb] Write Protect is off > [ 422.864343] sd 2:0:0:0: [sdb] Mode Sense: 2b 00 00 08 > [ 422.864864] sd 2:0:0:0: [sdb] Write cache: disabled, read cache: > enabled, doesn't support DPO or FUA > [ 423.150473] sd 2:0:0:0: [sdb] Attached SCSI removable disk > > > lsusb -t at: 16:10:21 > > > $ lsusb -t > /: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/3p, 480M > |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M > /: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M > |__ Port 2: Dev 3, If 0, Class=Mass Storage, Driver=usb-storage, > 5000M <-- the flash drive > |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/4p, 5000M > /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/9p, 480M > |__ Port 3: Dev 2, If 0, Class=Hub, Driver=hub/4p, 480M > |__ Port 2: Dev 4, If 0, Class=Wireless, Driver=btusb, 12M > |__ Port 2: Dev 4, If 1, Class=Wireless, Driver=btusb, 12M > |__ Port 4: Dev 6, If 0, Class=Vendor Specific Class, Driver=, 12M > |__ Port 7: Dev 9, If 0, Class=Video, Driver=uvcvideo, 480M > |__ Port 7: Dev 9, If 1, Class=Video, Driver=uvcvideo, 480M > > > > dd at: 16:11:50 > > > $ sudo dd if=/dev/zero of=/dev/sdb bs=1M count=256 > 256+0 records in > 256+0 records out > 268435456 bytes (268 MB, 256 MiB) copied, 5,84305 s, 45,9 MB/s I think the limitation is the flash storage itself. The bus is capable of transferring the data faster than the drive can store it. Here's an example taken from the middle of the usbmon trace. The second column is a timestamp, in microseconds. > ffff88042981bc00 588209102 S Bo:2:003:2 -115 31 = 55534243 b9000000 00e00100 00000a2a 00000015 900000f0 00000000 000000 > ffff88042981bc00 588209160 C Bo:2:003:2 0 31 > This is a write command for 224 blocks (122 KB) being sent to the flash drive. > ffff880401f90b40 588209178 S Bo:2:003:2 -115 122880 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 > ffff880401f90b40 588209952 C Bo:2:003:2 0 122880 > This is the data being sent. 122880 bytes were transferred over the bus in a little under 800 us. That's over 150 MB/s. > ffff88042981bc00 588209958 S Bi:2:003:1 -115 13 < > ffff88042981bc00 588210861 C Bi:2:003:1 0 13 = 55534253 b9000000 00000000 00 This is the status reply from the drive. It says that all the data got written with no errors, but it took an additional 900 us to do so. The next transfer is even worse: > ffff88042981bc00 588210900 S Bo:2:003:2 -115 31 = 55534243 ba000000 00e00100 00000a2a 00000016 800000f0 00000000 000000 > ffff88042981bc00 588210909 C Bo:2:003:2 0 31 > > ffff880401f90b40 588210912 S Bo:2:003:2 -115 122880 = 00000000 00000000 00000000 00000000 00000000 00000000 00000000 00000000 > ffff880401f90b40 588211398 C Bo:2:003:2 0 122880 > > ffff88042981bc00 588211403 S Bi:2:003:1 -115 13 < > ffff88042981bc00 588213441 C Bi:2:003:1 0 13 = 55534253 ba000000 00000000 00 This required only 486 us to send the data (250 MB/s), but the status reply added an additional 2038 us, driving the total rate way down to 48 MB/s. The timings in the trace file vary, but these two seem to be fairly typical. At any rate, it seems clear that the bottleneck here lies in the flash drive, not in the computer. Alan Stern -- To unsubscribe from this list: send the line "unsubscribe linux-usb" in the body of a message to majordomo@xxxxxxxxxxxxxxx More majordomo info at http://vger.kernel.org/majordomo-info.html
