[U-Boot] testing: [PATCH v7 0/3] common: usb_storage: Implement logic to calculate optimal usb maximum trasfer blocks

Rajesh Bhagat rajesh.bhagat at nxp.com
Wed Jun 22 08:36:03 CEST 2016



From: Matthew Bright [mailto:Matthew.Bright at alliedtelesis.co.nz] 
Sent: Wednesday, June 22, 2016 11:42 AM
To: Rajesh Bhagat <rajesh.bhagat at nxp.com>; marex at denx.de
Cc: u-boot at lists.denx.de; Chris Packham <Chris.Packham at alliedtelesis.co.nz>; Mark Tomlinson <Mark.Tomlinson at alliedtelesis.co.nz>
Subject: testing: [PATCH v7 0/3] common: usb_storage: Implement logic to calculate optimal usb maximum trasfer blocks

On 06/16/2016 12:35 PM, Rajesh Bhagat wrote:
> Performs code cleanup by making common function for usb_stor_read/write
> and implements the logic to calculate the optimal usb maximum trasfer blocks
> instead of sending USB_MAX_XFER_BLK blocks which is 65535 and 20 in case
> of EHCI and other USB protocols respectively.
> 
> Rajesh Bhagat (3):
>   common: usb_storage: Make common function for usb_read_10/usb_write_10
>   common: usb_storage: Make common function for
>     usb_stor_read/usb_stor_write
>   common: usb_storage : Implement logic to calculate optimal usb maximum
>     trasfer blocks
> 
>  common/usb_storage.c | 213 +++++++++++++++++++++++----------------------------
>  include/usb.h        |   1 +
>  2 files changed, 98 insertions(+), 116 deletions(-)
> 
>
> Hi Rajesh & Marek
>
> I have spend the last couple of days testing these patches on the
> v2016.05 release, with an usb mass storage device that is able to
> consistently reproduce the USB_MAX_XFER_BLK issue as described in
> the "Issue with USB mass storage (thumb drives)" u-boot thread.
>
> http://lists.denx.de/pipermail/u-boot/2016-February/244464.html​
>

Hello Matt, 

> I can confirm the patch correctly increases the max transfer bocks
> after a successful read, and decreases the max transfer bocks after
> a read failure. However, I have noticed that once the ehci time out
> error occurs, the usb device appears to lock up. When in this state
> the usb device will stop responding to any further transfers. This
> behavior is independent of the number of blocks, and will continue
> until the ehci has been reset.
>

I believe the lockup behavior mentioned by you to be device specific quirk. 
I tested 3 pen drives, which recovered from EHCI timeout behavior by 
reducing the number of blocks (check below output): 

USB write: device 0 block # 0, count 524288 ... 
usb_stor_read_write: retry #2, cur_xfer_blks 4095, smallblks 4095
usb_stor_read_write: retry #2, cur_xfer_blks 8191, smallblks 8191
usb_stor_read_write: retry #2, cur_xfer_blks 16383, smallblks 16383
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 65535, smallblks 65535
EHCI timed out on TD - token=0xa6008c80
usb_stor_read_write: retry #1, cur_xfer_blks 32767, smallblks 32767 <== 
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 4114
524288 blocks write: OK

USB read: device 0 block # 0, count 524288 ... 
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 65535, smallblks 65535
EHCI timed out on TD - token=0x2c008d80
usb_stor_read_write: retry #1, cur_xfer_blks 32767, smallblks 32767 <== 
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 32767
usb_stor_read_write: retry #2, cur_xfer_blks 32767, smallblks 16
524288 blocks read: OK

Best Regards,
Rajesh Bhagat 

> The following debug output demonstrates this behavior:
>
> (note: the retry attempts has been set to 4)
>
> ----------------------------------------------------------------------
>
> => fatload usb 0:auto 0x1000000 test.rel
>
> ------
> (where test.rel is dd if=/dev/urandom of=test.rel bs=32M count=2)
> ------
>
> usb_stor_read_write: udev 0
>
> usb_stor_read_write: dev 0 startblk 0, blccnt 1 buffer 7fb0d980
> usb_stor_read_write: retry #4, cur_xfer_blks 4095, smallblks 1
> usb_read_write_10: start 0 blocks 1
> usb_stor_read_write: end startblk 1, blccnt 1 buffer 7fb0db80
>
> ------
> (40 further transfers occur with blccnt bewteen 1 and 8 blocks)
> ------
>
> usb_stor_read_write: udev 0
>
> usb_stor_read_write: dev 0 startblk 169a0, blccnt 20000 buffer 1000000
> usb_stor_read_write: retry #4, cur_xfer_blks 4095, smallblks 4095
> usb_read_write_10: start 169a0 blocks 4095
> usb_stor_read_write: retry #4, cur_xfer_blks 8191, smallblks 8191
> usb_read_write_10: start 1799f blocks 8191
> usb_stor_read_write: retry #4, cur_xfer_blks 16383, smallblks 16383
> usb_read_write_10: start 1999e blocks 16383
> usb_stor_read_write: retry #4, cur_xfer_blks 32767, smallblks 32767
> usb_read_write_10: start 1d99d blocks 32767
> usb_stor_read_write: retry #4, cur_xfer_blks 65535, smallblks 65535
> usb_read_write_10: start 2599c blocks 65535
> EHCI timed out on TD - token=0x26008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> usb_stor_read_write: retry #3, cur_xfer_blks 32767, smallblks 32767
> usb_read_write_10: start 2599c blocks 32767
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> usb_stor_read_write: retry #2, cur_xfer_blks 16383, smallblks 16383
> usb_read_write_10: start 2599c blocks 16383
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> usb_stor_read_write: retry #1, cur_xfer_blks 8191, smallblks 8191
> usb_read_write_10: start 2599c blocks 8191
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> usb_stor_read_write: retry #0, cur_xfer_blks 4095, smallblks 4095
> usb_read_write_10: start 2599c blocks 4095
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> usb_stor_read_write: end startblk 2599c, blccnt fff buffer 2dff800
> Error reading cluster
> ** Unable to read file test.rel **
> => fatload usb 0:auto 0x1000000 test.rel
>
> usb_stor_read_write: udev 0
>
> sb_stor_read_write: dev 0 startblk 0, blccnt 1 buffer 7fb0d980
> usb_stor_read_write: retry #4, cur_xfer_blks 4095, smallblks 1
> usb_read_write_10: start 0 blocks 1
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> usb_stor_read_write: retry #3, cur_xfer_blks 4095, smallblks 1
> usb_read_write_10: start 0 blocks 1
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> usb_stor_read_write: retry #2, cur_xfer_blks 4095, smallblks 1
> usb_read_write_10: start 0 blocks 1
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> usb_stor_read_write: retry #1, cur_xfer_blks 4095, smallblks 1
> usb_read_write_10: start 0 blocks 1
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> usb_stor_read_write: retry #0, cur_xfer_blks 4095, smallblks 1
> usb_read_write_10: start 0 blocks 1
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x801f8c80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> EHCI timed out on TD - token=0x80008d80
> usb_stor_read_write: end startblk 0, blccnt 1 buffer 7fb0d980
> ** Can't read partition table on 0:0 **
>
> ------
> (usb_read_write_10 is repeated 15 more times producing the same errors)
> ------
>
> ** No valid partitions found **
> => usb reset
> resetting USB...
> USB0:   USB EHCI 1.00
> scanning bus 0 for devices... 2 USB Device(s) found
>       scanning usb for storage devices... 
> usb_stor_read_write: udev 0
>
> usb_stor_read_write: dev 0 startblk 0, blccnt 1 buffer 7fb0d980
> usb_stor_read_write: retry #4, cur_xfer_blks 4095, smallblks 1
> usb_read_write_10: start 0 blocks 1
> usb_stor_read_write: end startblk 1, blccnt 1 buffer 7fb0db80
> 1 Storage Device(s) found
> => fatload usb 0:auto 0x1000000 test.rel
>
> usb_stor_read_write: udev 0
>
> usb_stor_read_write: dev 0 startblk 0, blccnt 1 buffer 7fb0d980
> usb_stor_read_write: retry #4, cur_xfer_blks 4095, smallblks 1
> usb_read_write_10: start 0 blocks 1
> usb_stor_read_write: end startblk 1, blccnt 1 buffer 7fb0db80
>
> ------
> (transfers continues on happily until 65535 blocks is hit again)
> ------
>
> ----------------------------------------------------------------------
>
> This debug output shows the ehci timeout error occur for a transfer
> with 65535 blocks (as expected) however the timeout error continues
> for each proceeding transfer. This occurs even though the number of
> blocks are reduced back to what should be an acceptable number. 
>
> I am currently unsure if this "lock up" behavior is simply a quirk of
> the specific usb device that I am using. However, if such behavior is
> common, then it could render this fix moot. This is assuming that the
> ehci cannot be reset part way through a transfer (i.e. after the echi
> time out error occurs).
>
> I have been able to consistently reproduce this "lock up" behavior on
> a single 4-GB Apacer usb flash device (details below). However I have
> been unable to reproduce this behavior on several 8GB counterparts as
> they appear to work fine with the maximum possible block size.
>
> ----------------------------------------------------------------------
>
> => usb info
> 1: Hub,  USB Revision 2.0
> - u-boot EHCI Host Controller 
> - Class: Hub
> - PacketSize: 64  Configurations: 1
> - Vendor: 0x0000  Product 0x0000 Version 1.0
>   Configuration: 1
>   - Interfaces: 1 Self Powered 0mA
>     Interface: 0
>     - Alternate Setting 0, Endpoints: 1
>     - Class Hub
>     - Endpoint 1 In Interrupt MaxPacket 2048 Interval 255ms
>
> 2: Mass Storage,  USB Revision 2.0
> - USB FLASH DRIVE AP9BDE1B0918CBDB
> - Class: (from Interface) Mass Storage
> - PacketSize: 64  Configurations: 1
> - Vendor: 0x1005  Product 0xb113 Version 1.0
>   Configuration: 1
>   - Interfaces: 1 Bus Powered 500mA
>     Interface: 0
>     - Alternate Setting 0, Endpoints: 2
>     - Class Mass Storage, Transp. SCSI, Bulk only
>     - Endpoint 2 In Bulk MaxPacket 512
>     - Endpoint 1 Out Bulk MaxPacket 512
>
> ----------------------------------------------------------------------
>
> I think this patch is a good solution to the original problem. Please
> let me know if there is anything I can do to help.
>
> Cheers.
> - Matt Bright


More information about the U-Boot mailing list