Re: Large USB storage devices cause df to hang and cpu load reaches 100%

Alan Stern wrote:
> On Mon, 30 Jul 2007, Kostas Peletidis wrote:
>
>   
>> Hi all,
>>
>> I would like to report a problem I have noticed since linux-2.6.22 that 
>> most likely has to do with the USB subsystem.
>>
>> I have tried both kernel versions 2.6.22 and 2.6.22.1(configured with 
>> make oldconfig) and in both cases whenever I plug in a fairly 
>> large(500GB) MyBook usb2 hard disk df stops producing output and hangs 
>> for about a minute when it reaches the usb disk. Interestingly enough 
>> the disk's directory tree can be accessed immediately. It is only df and 
>> Thunar, the xfce window manager, that slow down. During this temporary 
>> hang the cpu load fluctuates and reaches 100% several times.
>>
>> When I plugged in a small(512MB) usb2 memory stick, instead of the disk, 
>> df paused only momentarily before terminating normally. This suggests to 
>> me that the size of the device affects the duration of the delay.
>>
>> The modules I use, apart from usb_storage, are ehci_hcd and uhci_hcd. 
>> With linux-2.6.21.5 both usb devices work fine.
>>
>> I don't know how to proceed from here. Please let me know if you need 
>> additional information or if I need to contact someone else. Thank you.
>>     
>
> Turn on CONFIG_USB_DEBUG and then check the output from dmesg after 
> running the df program.
>
> If it shows something peculiar then you should try using usbmon.  
> Instructions are in the kernel source file 
> Documentation/usb/usbmon.txt.
>
> If all else fails, you can install Git and use bisection on the set of 
> kernel versions between 2.6.21 and 2.6.22, to find which patch caused 
> the odd behavior to start.
>
> Alan Stern
>
>
>   
Hi Alan,

I enabled CONFIG_USB_DEBUG and reproduced the problem but didn't see any 
messages in the dmesg output. To ensure that the debug code was indeed 
built in I unplugged the disk then plugged it back in. I got quite a few 
messages, here are the last of them:

Jul 31 21:05:28 dragon kernel: [ 915.850000] usb 1-3.2: usb_probe_device
Jul 31 21:05:28 dragon kernel: [ 915.850000] usb 1-3.2: configuration #1 
chosen from 1 choice
Jul 31 21:05:28 dragon kernel: [ 915.851000] usb 1-3.2: adding 1-3.2:1.0 
(config #1, interface 0)
Jul 31 21:05:28 dragon kernel: [ 915.851000] usb 1-3.2:1.0: uevent
Jul 31 21:05:28 dragon kernel: [ 915.851000] usb 1-3.2:1.0: uevent
Jul 31 21:05:28 dragon kernel: [ 915.851000] usb-storage 1-3.2:1.0: 
usb_probe_interface
Jul 31 21:05:28 dragon kernel: [ 915.851000] usb-storage 1-3.2:1.0: 
usb_probe_interface - got id
Jul 31 21:05:28 dragon kernel: [ 915.852000] scsi1 : SCSI emulation for 
USB Mass Storage devices
Jul 31 21:05:28 dragon kernel: [ 915.852000] usb-storage: device found at 8
Jul 31 21:05:28 dragon kernel: [ 915.852000] usb-storage: waiting for 
device to settle before scanning
Jul 31 21:05:28 dragon kernel: [ 915.853000] drivers/usb/core/inode.c: 
creating file '008'
Jul 31 21:05:33 dragon kernel: [ 920.853000] scsi 1:0:0:0: Direct-Access 
WD 5000AAKS Externa 101a PQ: 0 ANSI: 4
Jul 31 21:05:33 dragon kernel: [ 920.856000] sd 1:0:0:0: [sda] 976773168 
512-byte hardware sectors (500108 MB)
Jul 31 21:05:33 dragon kernel: [ 920.856000] sd 1:0:0:0: [sda] Write 
Protect is off
Jul 31 21:05:33 dragon kernel: [ 920.856000] sd 1:0:0:0: [sda] Mode 
Sense: 11 00 00 00
Jul 31 21:05:33 dragon kernel: [ 920.856000] sd 1:0:0:0: [sda] Assuming 
drive cache: write through
Jul 31 21:05:33 dragon kernel: [ 920.859000] sd 1:0:0:0: [sda] 976773168 
512-byte hardware sectors (500108 MB)
Jul 31 21:05:33 dragon kernel: [ 920.860000] sd 1:0:0:0: [sda] Write 
Protect is off
Jul 31 21:05:33 dragon kernel: [ 920.860000] sd 1:0:0:0: [sda] Mode 
Sense: 11 00 00 00
Jul 31 21:05:33 dragon kernel: [ 920.860000] sd 1:0:0:0: [sda] Assuming 
drive cache: write through
Jul 31 21:05:33 dragon kernel: [ 920.860000] sda: sda1
Jul 31 21:05:33 dragon kernel: [ 920.863000] sd 1:0:0:0: [sda] Attached 
SCSI disk
Jul 31 21:05:33 dragon kernel: [ 920.863000] sd 1:0:0:0: Attached scsi 
generic sg0 type 0
Jul 31 21:05:33 dragon kernel: [ 920.866000] usb-storage: device scan 
complete

I see most of these messages at boot time even with older 2.6 kernels. 
The problem appears after the "device scan complete" message is traced.

The patch that caused this issue was added between the 2.6.21.5 and 
2.6.22 releases. The only patch that led to 2.6.21.6 had to do with 
nf_conntrack_h323 so this leaves us with the patches between 2.6.21.6 
and 2.6.22. There are quite a few usb changes in that changelog so I was 
hoping that someone might recognise/remember something relevant.

Regards,
Kostas

-------------------------------------------------------------------------
This SF.net email is sponsored by: Splunk Inc.
Still grepping through log files to find problems?  Stop.
Now Search log events and configuration files using AJAX and a browser.
Download your FREE copy of Splunk now >>  http://get.splunk.com/

_______________________________________________
[email protected]
To unsubscribe, use the last form field at:
https://lists.sourceforge.net/lists/listinfo/linux-usb-devel