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

Matthew Bright Matthew.Bright at alliedtelesis.co.nz
Wed Jun 22 08:12:24 CEST 2016 

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​

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.

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

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
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