Card-Reader Problem continued

[Alan Stern]

On Wed, 17 May 2006, Christian Haul wrote:

> top shows no worrisome data
> CPU(s): 1.0% us,  1.3% sy,  0.0% ni, 96.4% id,  1.3% wa,  0.0% hi,  0.0% si
> load is perfectly OK: load average: 0.00, 0.19, 0.23
> 
> dmsg is as busy as on the "broken" host: (long!)
> 
> [  865.281154] usb-storage: *** thread awakened.
> [  865.281158] usb-storage: Command TEST_UNIT_READY (6 bytes)
> [  865.281161] usb-storage:  00 00 00 00 00 00
> [  865.281168] usb-storage: Bulk Command S 0x43425355 T 0x1eef L 0 F 0
> Trg 0 LUN 0 CL 6

> [  865.283006] usb-storage: Command TEST_UNIT_READY (6 bytes)
> [  865.283009] usb-storage:  00 00 00 00 00 00
> [  865.283016] usb-storage: Bulk Command S 0x43425355 T 0x1ef1 L 0 F 0
> Trg 0 LUN 0 CL 6

> [  865.285478] usb-storage: Command TEST_UNIT_READY (6 bytes)
> [  865.285481] usb-storage:  00 00 00 00 00 00
> [  865.285487] usb-storage: Bulk Command S 0x43425355 T 0x1ef3 L 0 F 0
> Trg 0 LUN 0 CL 6

> [  865.290862] usb-storage: Command TEST_UNIT_READY (6 bytes)
> [  865.290865] usb-storage:  00 60 00 00 00 00
> [  865.290872] usb-storage: Bulk Command S 0x43425355 T 0x1ef5 L 0 F 0
> Trg 0 LUN 3 CL 6

> [  865.292585] usb-storage: Command TEST_UNIT_READY (6 bytes)
> [  865.292587] usb-storage:  00 60 00 00 00 00
> [  865.292594] usb-storage: Bulk Command S 0x43425355 T 0x1ef7 L 0 F 0
> Trg 0 LUN 3 CL 6

> [  865.294045] usb-storage: Command TEST_UNIT_READY (6 bytes)
> [  865.294047] usb-storage:  00 60 00 00 00 00
> [  865.294054] usb-storage: Bulk Command S 0x43425355 T 0x1ef9 L 0 F 0
> Trg 0 LUN 3 CL 6

> [  865.295627] usb-storage: Command TEST_UNIT_READY (6 bytes)
> [  865.295630] usb-storage:  00 60 00 00 00 00
> [  865.295637] usb-storage: Bulk Command S 0x43425355 T 0x1efb L 0 F 0
> Trg 0 LUN 3 CL 6

As you can see, the log buffer includes 3 consecutive commands to LUN 0
followed a little later by 4 consecutive commands to LUN 3.  This suggests
that each command is being retried three times.

I don't know of anything in the kernel that would cause these retries, 
although it's possible that something in the sg driver is responsible.  
It's also possible that the application is doing the retries.

Interestingly, the actual amount of work being done here seems to be the 
same as on the other machine, and yet the total load is much lower.  I 
have no idea why that should be.

Alan Stern