Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-11-04 Thread Prasad Koya 
Hi

I'm attaching dmesg with old_scheme_first=1 and
CONFIG_USB_STORAGE_DEBUG enabled. I compiled code with
old_scheme_first set to 1. I see that it doesn't do get descriptor
early in the loop so it doesn't run into khubd time out. But as I
mentioned earlier usb-storage runs into some sort of error and resets
the device 20s later it was first initialized.

Thanks for looking.


[1.787606] usb-storage: *** thread sleeping.
[   22.816061] usb-storage: command_abort called
[   22.816066] usb-storage: usb_stor_stop_transport called
[   22.816068] usb-storage: -- cancelling URB
[   22.816117] usb-storage: Status code -104; transferred 0/31
[   22.816120] usb-storage: -- transfer cancelled
[   22.816122] usb-storage: Bulk command transfer result=4
[   22.816125] usb-storage: -- command was aborted
[   22.816129] usb-storage: usb_stor_pre_reset
[   22.928057] usb 1-3: reset high speed USB device using ehci_hcd and address 2
[   22.928062] usb 1-3: old_scheme_first 1 USE_NEW_SCHEME 0 retry_counter 0
[   22.949263] usb-storage: usb_stor_post_reset
[   22.949270] usb-storage: usb_reset_device returns 0
[   22.949274] usb-storage: scsi command aborted

On Sun, Nov 3, 2013 at 8:22 AM, Alan Stern st...@rowland.harvard.edu wrote:
 On Sat, 2 Nov 2013, Prasad Koya wrote:

 Hi

 I didn't have luck reproducing with both CONFIG_USB_DEBUG and
 CONFIG_USB_STORAGE_DEBUG. I could reproduce with each of them enabled
 separately. Am attaching the whole dmesg of both as zip files. If I
 should send them in different format, please let me know. I didn't see
 anything warnings or errors with USB_STORAGE_DEBUG enabled. The USB in
 question is usb 1-3 on hub 1 and bus 1. I see no errors or warnings
 in that 5s timeout. Am trying with both 3.4 kernel and our older
 2.6.32 kernel based images on bunch of setups.

 It looks like you didn't use usbcore.old_scheme_first=1.

 Alan Stern



dmesg_config_usb_storage_old_scheme_first.gz
Description: GNU Zip compressed data

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-11-04 Thread Alan Stern 
On Mon, 4 Nov 2013, Prasad Koya wrote:

 Hi
 
 I'm attaching dmesg with old_scheme_first=1 and
 CONFIG_USB_STORAGE_DEBUG enabled. I compiled code with
 old_scheme_first set to 1. I see that it doesn't do get descriptor
 early in the loop so it doesn't run into khubd time out. But as I
 mentioned earlier usb-storage runs into some sort of error and resets
 the device 20s later it was first initialized.
 
 Thanks for looking.
 
 
 [1.787606] usb-storage: *** thread sleeping.
 [   22.816061] usb-storage: command_abort called

I need to see the earlier part of the log -- that's when the problem 
occurred.  By the time of the reset, it's already too late.

Alan Stern

--
To unsubscribe from this list: send the line unsubscribe linux-usb in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-11-04 Thread Alan Stern 
On Mon, 4 Nov 2013, Alan Stern wrote:

 On Mon, 4 Nov 2013, Prasad Koya wrote:
 
  Hi
  
  I'm attaching dmesg with old_scheme_first=1 and
  CONFIG_USB_STORAGE_DEBUG enabled. I compiled code with
  old_scheme_first set to 1. I see that it doesn't do get descriptor
  early in the loop so it doesn't run into khubd time out. But as I
  mentioned earlier usb-storage runs into some sort of error and resets
  the device 20s later it was first initialized.
  
  Thanks for looking.
  
  
  [1.787606] usb-storage: *** thread sleeping.
  [   22.816061] usb-storage: command_abort called
 
 I need to see the earlier part of the log -- that's when the problem 
 occurred.  By the time of the reset, it's already too late.

Sorry -- I wrote that before noticing you had attached the entire log.
The log shows that the SMART eUSB device failed to respond to the 
initial INQUIRY command.

Face it; that device simply is buggy.  If you can't replace it, you 
will have to live with its shortcomings.

Alan Stern

--
To unsubscribe from this list: send the line unsubscribe linux-usb in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-11-03 Thread Alan Stern 
On Sat, 2 Nov 2013, Prasad Koya wrote:

 Hi
 
 I didn't have luck reproducing with both CONFIG_USB_DEBUG and
 CONFIG_USB_STORAGE_DEBUG. I could reproduce with each of them enabled
 separately. Am attaching the whole dmesg of both as zip files. If I
 should send them in different format, please let me know. I didn't see
 anything warnings or errors with USB_STORAGE_DEBUG enabled. The USB in
 question is usb 1-3 on hub 1 and bus 1. I see no errors or warnings
 in that 5s timeout. Am trying with both 3.4 kernel and our older
 2.6.32 kernel based images on bunch of setups.

It looks like you didn't use usbcore.old_scheme_first=1.

Alan Stern

--
To unsubscribe from this list: send the line unsubscribe linux-usb in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-11-02 Thread Prasad Koya 
Hi

I didn't have luck reproducing with both CONFIG_USB_DEBUG and
CONFIG_USB_STORAGE_DEBUG. I could reproduce with each of them enabled
separately. Am attaching the whole dmesg of both as zip files. If I
should send them in different format, please let me know. I didn't see
anything warnings or errors with USB_STORAGE_DEBUG enabled. The USB in
question is usb 1-3 on hub 1 and bus 1. I see no errors or warnings
in that 5s timeout. Am trying with both 3.4 kernel and our older
2.6.32 kernel based images on bunch of setups.

thank you.

On Thu, Oct 31, 2013 at 11:15 AM, Alan Stern st...@rowland.harvard.edu wrote:
 On Thu, 31 Oct 2013, Prasad Koya wrote:

 I tried usbmon before forcing crash:

 As this USB is on bus 1, I tried below:

 cat /sys/kernel/debug/usb/usbmon/1u

 I didn't see anything till I copied a file or did some activity on it.
 While cat'ing above, I copied a file to that flash with dd in another
 terminal and I got this:

 ...

 But I'm seeing the issue in early boot. So is there any other way to
 get the usbmon traces out?

 That makes it more difficult.  You can't use usbmon during early boot,
 so your only option is to enable CONFIG_USB_STORAGE_DEBUG.  The output
 is more verbose, but we should be able to see what's going on.

 Alan Stern



dmesg_with_usb_debug_config.gz
Description: GNU Zip compressed data


dmesg_with_usb_storage_debug.gz
Description: GNU Zip compressed data

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-10-31 Thread Prasad Koya 
Hi

Here are dmesg's with old_scheme_first=1 and where it took about 20s
for usb-storage to start using this device. Is there a way I can
enable debugs from usb-storage to see what it is doing in that 20s
gap. The device in question is at usb1-3 (sdb), manufactured by SMART.

Thank you.


[1.628068] usb 1-3: new high speed USB device using ehci_hcd and address 2
[1.628073] usb 1-3: usenewscheme 0 retry_counter 0 i 0
[1.628103] EXT4-fs (sda1): warning: maximal mount count reached,
running e2fsck is recommended
[1.628671] EXT4-fs (sda1): recovery complete
[1.628680] EXT4-fs (sda1): mounted filesystem with ordered data mode
[1.649360] usb 1-3: default language 0x0409
[1.650118] usb 1-3: udev 2, busnum 1, minor = 1
[1.650123] usb 1-3: New USB device found, idVendor=0e39, idProduct=2b00
[1.650127] usb 1-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[1.650131] usb 1-3: Product: eUSB
[1.650133] usb 1-3: Manufacturer: SMART
[1.650136] usb 1-3: SerialNumber: 29879006164049261011
[1.650311] usb 1-3: usb_probe_device
[1.650316] usb 1-3: configuration #1 chosen from 1 choice
[1.650465] usb 1-3: adding 1-3:1.0 (config #1, interface 0)
[1.650708] usb-storage 1-3:1.0: usb_probe_interface
[1.650716] usb-storage 1-3:1.0: usb_probe_interface - got id
[1.650927] scsi4 : SCSI emulation for USB Mass Storage devices
[1.651428] /bld/Kernel/Artools-rpmbuild/linux/drivers/usb/core/inode.c:
creating file '002'
[1.651453] hub 2-0:1.0: state 7 ports 5 chg 0020 evt 
[1.651464] hub 2-0:1.0: port 5, status 0501, change , 480 Mb/s
[1.651477] usb-storage: device found at 2
[1.651770] usb-storage: device scan complete
[1.704076] ehci_hcd :00:13.2: port 5 high speed
[1.704083] ehci_hcd :00:13.2: GetStatus port 5 status 001005
POWER sig=se0 PE CONNECT
[1.760060] usb 2-5: new high speed USB device using ehci_hcd and address 2
[1.760065] usb 2-5: usenewscheme 0 retry_counter 0 i 0
[1.781500] usb 2-5: default language 0x0409
[1.781880] usb 2-5: udev 2, busnum 2, minor = 129
[1.781885] usb 2-5: New USB device found, idVendor=0781, idProduct=5571
[1.781888] usb 2-5: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[1.781892] usb 2-5: Product: Cruzer Fit
[1.781895] usb 2-5: Manufacturer: SanDisk
[1.781897] usb 2-5: SerialNumber: 4C532008870615120374
[1.782072] usb 2-5: usb_probe_device
[1.782077] usb 2-5: configuration #1 chosen from 1 choice
[1.782228] usb 2-5: adding 2-5:1.0 (config #1, interface 0)
[1.782463] usb-storage 2-5:1.0: usb_probe_interface
[1.782471] usb-storage 2-5:1.0: usb_probe_interface - got id
[1.782678] scsi5 : SCSI emulation for USB Mass Storage devices
[1.783176] /bld/Kernel/Artools-rpmbuild/linux/drivers/usb/core/inode.c:
creating file '002'
[1.783202] hub 5-0:1.0: state 7 ports 5 chg  evt 
[1.783207] hub 6-0:1.0: state 7 ports 4 chg  evt 
[1.783212] usb-storage: device found at 2
[1.783532] usb-storage: device scan complete
[1.784053] scsi 5:0:0:0: Direct-Access SanDisk  Cruzer Fit
  1.26 PQ: 0 ANSI: 5
[   22.872067] ehci_hcd :00:12.2: port 3 high speed
[   22.872075] ehci_hcd :00:12.2: GetStatus port 3 status 001005
POWER sig=se0 PE CONNECT
[   22.928057] usb 1-3: reset high speed USB device using ehci_hcd and address 2
[   22.928062] usb 1-3: usenewscheme 0 retry_counter 0 i 0
[   22.952867] scsi 4:0:0:0: Direct-Access SMARTeUSB
  883C PQ: 0 ANSI: 0 CCS
[   22.955195] sd 4:0:0:0: [sdb] 4014080 512-byte logical blocks:
(2.05 GB/1.91 GiB)
[   22.955724] sd 4:0:0:0: [sdb] Write Protect is off
[   22.955730] sd 4:0:0:0: [sdb] Mode Sense: 43 00 00 00
[   22.955733] sd 4:0:0:0: [sdb] Assuming drive cache: write through
[   23.031197] sd 5:0:0:0: [sdc] 7821312 512-byte logical blocks:
(4.00 GB/3.72 GiB)
[   23.032940] sd 5:0:0:0: [sdc] Write Protect is off
[   23.032946] sd 5:0:0:0: [sdc] Mode Sense: 43 00 00 00
[   23.032949] sd 5:0:0:0: [sdc] Assuming drive cache: write through
[   23.118414] sd 4:0:0:0: [sdb] Assuming drive cache: write through
[   23.191151]  sdb: sdb1 sdb2
[   23.194175] sd 5:0:0:0: [sdc] Assuming drive cache: write through
[   23.266918]  sdc:
[   23.268744] sd 4:0:0:0: [sdb] Assuming drive cache: write through
[   23.344071]  sdc1
[   23.344766] sd 4:0:0:0: [sdb] Attached SCSI disk
[   23.346889] sd 5:0:0:0: [sdc] Assuming drive cache: write through
[   23.419967] sd 5:0:0:0: [sdc] Attached SCSI removable disk

On Wed, Oct 30, 2013 at 3:21 PM, Prasad Koya prasad.k...@gmail.com wrote:
 Hi

 Thanks for suggesting the alternatives.

 With CONFIG_USB_DEBUG and CONFIG_USB_MON enabled I see below messages
 related to the USB device in question. This is not reproducible
 easily. I'll try the old_scheme_first. We are seeing this issue with
 flash that is internal to our box and not accessible outside and we
 ship them with this brand of flash. Will see if I

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-10-31 Thread Alan Stern 
On Wed, 30 Oct 2013, Prasad Koya wrote:

 Hi
 
 Here are dmesg's with old_scheme_first=1 and where it took about 20s
 for usb-storage to start using this device. Is there a way I can
 enable debugs from usb-storage to see what it is doing in that 20s
 gap. The device in question is at usb1-3 (sdb), manufactured by SMART.

The easiest way to find out is by using usbmon, not by enabling debug 
in usb-storage.

Alan Stern

--
To unsubscribe from this list: send the line unsubscribe linux-usb in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-10-31 Thread Prasad Koya 
I tried usbmon before forcing crash:

T:  Bus=01 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#=  1 Spd=480 MxCh= 5
B:  Alloc=  0/800 us ( 0%), #Int=  0, #Iso=  0
D:  Ver= 2.00 Cls=09(hub  ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=1d6b ProdID=0002 Rev= 2.06
S:  Manufacturer=Linux 2.6.32.28 ehci_hcd
S:  Product=EHCI Host Controller
S:  SerialNumber=:00:12.2
C:* #Ifs= 1 Cfg#= 1 Atr=e0 MxPwr=  0mA
I:* If#= 0 Alt= 0 #EPs= 1 Cls=09(hub  ) Sub=00 Prot=00 Driver=hub
E:  Ad=81(I) Atr=03(Int.) MxPS=   4 Ivl=256ms

T:  Bus=01 Lev=01 Prnt=01 Port=02 Cnt=01 Dev#=  2 Spd=480 MxCh= 0
D:  Ver= 2.00 Cls=00(ifc ) Sub=00 Prot=00 MxPS=64 #Cfgs=  1
P:  Vendor=0e39 ProdID=2b00 Rev=88.3c
S:  Manufacturer=SMART
S:  Product=eUSB
S:  SerialNumber=29879006164049261011
C:* #Ifs= 1 Cfg#= 1 Atr=80 MxPwr=100mA
I:* If#= 0 Alt= 0 #EPs= 2 Cls=08(stor.) Sub=06 Prot=50 Driver=usb-storage
E:  Ad=81(I) Atr=02(Bulk) MxPS= 512 Ivl=0ms
E:  Ad=02(O) Atr=02(Bulk) MxPS= 512 Ivl=31875us
bash-4.1#


As this USB is on bus 1, I tried below:

cat /sys/kernel/debug/usb/usbmon/1u

I didn't see anything till I copied a file or did some activity on it.
While cat'ing above, I copied a file to that flash with dd in another
terminal and I got this:

-bash-4.1# cat /sys/kernel/debug/usb/usbmon/1u
88013e81acc0 1352058978 S Bo:1:002:2 -115 31 = 55534243 301d
00e00100 0a2a 1a8f 97f0  00
88013e81acc0 1352059090 C Bo:1:002:2 0 31 
8800a9a306c0 1352059112 S Bo:1:002:2 -115 4096 =  
     
8800a9a30600 1352059115 S Bo:1:002:2 -115 8192 =  
     
8800a9a30480 1352059117 S Bo:1:002:2 -115 8192 =  
     
8800b2981d40 1352059119 S Bo:1:002:2 -115 8192 =  
     
8800b2981c80 1352059120 S Bo:1:002:2 -115 8192 =  
     
8800b2981b00 1352059122 S Bo:1:002:2 -115 8192 =  
     
8800b2981bc0 1352059123 S Bo:1:002:2 -115 8192 =  
     
8800b2981a40 1352059125 S Bo:1:002:2 -115 8192 =  
     
88013e8a3140 1352059126 S Bo:1:002:2 -115 8192 =  
     
88013e8a3500 1352059127 S Bo:1:002:2 -115 8192 =  
     
88013e8a3440 1352059129 S Bo:1:002:2 -115 8192 =  
     
88013e8a3740 1352059130 S Bo:1:002:2 -115 8192 =  
     
88013e8a3380 1352059131 S Bo:1:002:2 -115 8192 =  
     
88013e8a3080 1352059133 S Bo:1:002:2 -115 8192 =  
     
88013e8532c0 1352059134 S Bo:1:002:2 -115 8192 =  
     
88013e9cd900 1352059135 S Bo:1:002:2 -115 4096 =  
     
8800a9a306c0 1352068401 C Bo:1:002:2 0 4096 
8800a9a30600 1352068410 C Bo:1:002:2 0 8192 
8800a9a30480 1352068411 C Bo:1:002:2 0 8192 
8800b2981d40 1352068413 C Bo:1:002:2 0 8192 
8800b2981c80 1352068414 C Bo:1:002:2 0 8192 
8800b2981b00 1352068416 C Bo:1:002:2 0 8192 
8800b2981bc0 1352068424 C Bo:1:002:2 0 8192 
8800b2981a40 1352068425 C Bo:1:002:2 0 8192 
88013e8a3140 1352068427 C Bo:1:002:2 0 8192 
88013e8a3500 1352068428 C Bo:1:002:2 0 8192 
88013e8a3440 1352068430 C Bo:1:002:2 0 8192 
88013e8a3740 1352068431 C Bo:1:002:2 0 8192 
88013e8a3380 1352068432 C Bo:1:002:2 0 8192 
88013e8a3080 1352068434 C Bo:1:002:2 0 8192 
88013e8532c0 1352069318 C Bo:1:002:2 0 8192 
88013e9cd900 1352069328 C Bo:1:002:2 0 4096 
88013e81acc0 1352069359 S Bi:1:002:1 -115 13 
88013e81acc0 1352069818 C Bi:1:002:1 0 13 = 55534253 301d  00
88013e81acc0 1352069918 S Bo:1:002:2 -115 31 = 55534243 311d
00e00100 0a2a 1a90 87f0  00
88013e81acc0 1352070055 C Bo:1:002:2 0 31 

But I'm seeing the issue in early boot. So is there any other way to
get the usbmon traces out?

Thank you.

On Thu, Oct 31, 2013 at 8:52 AM, Alan Stern st...@rowland.harvard.edu wrote:
 On Wed, 30 Oct 2013, Prasad Koya wrote:

 Hi

 Here are dmesg's with old_scheme_first=1 and where it took about 20s
 for usb-storage to start using this device. Is there a way I can
 enable debugs from usb-storage to see what it is doing in that 20s
 gap. The device in question is at usb1-3 (sdb),

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-10-31 Thread Alan Stern 
On Thu, 31 Oct 2013, Prasad Koya wrote:

 I tried usbmon before forcing crash:

 As this USB is on bus 1, I tried below:
 
 cat /sys/kernel/debug/usb/usbmon/1u
 
 I didn't see anything till I copied a file or did some activity on it.
 While cat'ing above, I copied a file to that flash with dd in another
 terminal and I got this:

...

 But I'm seeing the issue in early boot. So is there any other way to
 get the usbmon traces out?

That makes it more difficult.  You can't use usbmon during early boot, 
so your only option is to enable CONFIG_USB_STORAGE_DEBUG.  The output 
is more verbose, but we should be able to see what's going on.

Alan Stern

--
To unsubscribe from this list: send the line unsubscribe linux-usb in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-10-30 Thread Alan Stern 
On Tue, 29 Oct 2013, Prasad Koya wrote:

 Thanks for looking into the patch. Am fairly new to the USB subsystem.
 You are right. There is a possibility of going into infinite loop with
 hub_port_init - usb_reset_device - usb_reset_and_verify_device -
 hub_port_init.
 
 We are trying to achieve two things inside crash_kexec'ed kerrnel:
 
 1. avoid the 5s timeout during get_device_descriptor
 2. and get USB device working
 
 When I tried this in hub_port_init() (in 2.6.38)
 
 default:
 if (r == 0)
 r = -EPROTO;
 break;
 }
 
 +if (r == -ETIMEDOUT) {
 +   if(udev-speed == USB_SPEED_HIGH) {
 +dev_info(udev-dev,
 %s: force maxpktsize\n,
 +
 __FUNCTION__);
 +buf-bMaxPacketSize0 = 64;
 +r = 0;
 +break;
 +}
 +}

I prefer not to do it this way.  First, because it avoids the retry 
loop, and second, because the same technique can apply to other speeds, 
not only high speed.

 the function completed fine i.e., even hub_port_reset below went fine
 with wPortStatus reflecting that reset is complete. However, 20s after
 that the USB block driver had called usb_reset_device() and the device
 is accessible since then.

I can't understand this last sentence.  20 seconds after what -- the
reset?  Do you mean usb-storage rather than USB block driver?  
usb-storage called usb_reset_device 20 seconds after the reset was
complete?  The device is accessible since when (the first reset or the
second)?

 When usb_reset_device was called by higher
 layer, the state of the USB is CONFIGURED. Below is the backtrace to
 usb_reset_device.

The backtrace only tells you that usb-storage called
usb_reset_device.  If you want to know _why_ it called 
usb_reset_device, you need to collect a usbmon trace.

 As you suggested earlier, I'm thinking of if there is a way to
 unbind/rebind the driver. From above backtrace and after looking at
 usb_reset_device(), I thought usb_reset_device() is doing the
 unbind/rebind.

Why do you want to unbind and rebind usb-storage?

 Since I'm seeing 'r' as -110 (ETIMEDOUT) or -71 (EPROTO) (EPROTO on
 later 2 retries), the code you gave in first part of your patch would
 never get executed.
 
 Thanks for your help.

Maybe it would be best to switch devices instead of trying to change 
the driver.  Find a device that complies with the USB spec.

Alternatively, you could create a new quirk flag for this device.  When 
that flag is set, you could skip the 64-byte Get-Descriptor entirely.

Or you could try setting the usbcore.old_scheme_first=1 option in the 
kernel command line.  That might be the easiest answer.

Alan Stern

--
To unsubscribe from this list: send the line unsubscribe linux-usb in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-10-29 Thread Alan Stern 
On Mon, 28 Oct 2013, Prasad Koya wrote:

 Hi
 
 I tried resetting usb device when it gets ETIMEDOUT during get
 descriptor. On second retry, I don't see timeout. Please see this
 patch:
 
 Index: linux-3.4/drivers/usb/core/hub.c
 ===
 --- linux-3.4.orig/drivers/usb/core/hub.c
 +++ linux-3.4/drivers/usb/core/hub.c
 @@ -3213,6 +3213,14 @@ hub_port_init (struct usb_hub *hub, stru
   r = -EPROTO;
   break;
   }
 +
 +if (r == -ETIMEDOUT) {
 + r = usb_reset_device(hdev);
 + if (r) {
 + dev_dbg(udev-dev, failed to reset usb %d\n, r);
 + }
 + }
 +
   if (r == 0)
   break;
   }

The patch has been whitespace-damaged.  Besides, what is the point of 
calling usb_reset_device()?  You might as well just break out of the 
loop, because just after the end of the loop there is a call to 
hub_port_reset().

In addition, you run the risk of infinite recursion since
usb_reset_device() calls usb_reset_and_verify_device(), which calls
hub_port_init().

Finally, the patch is wrong because it never does carry out the 
Get-Device-Descriptor(64) request.  That means it won't work with a 
full-speed device if the ep0 maxpacket size is smaller than 64.

What you could do instead is this:

Index: usb-3.12/drivers/usb/core/hub.c
===
--- usb-3.12.orig/drivers/usb/core/hub.c
+++ usb-3.12/drivers/usb/core/hub.c
@@ -4106,11 +4106,12 @@ hub_port_init (struct usb_hub *hub, stru
r = -EPROTO;
break;
}
-   if (r == 0)
+   if (r == 0) {
+   udev-descriptor.bMaxPacketSize0 =
+   buf-bMaxPacketSize0;
break;
+   }
}
-   udev-descriptor.bMaxPacketSize0 =
-   buf-bMaxPacketSize0;
kfree(buf);
 
retval = hub_port_reset(hub, port1, udev, delay, false);
@@ -4126,8 +4127,15 @@ hub_port_init (struct usb_hub *hub, stru
if (r != -ENODEV)
dev_err(udev-dev, device descriptor 
read/64, error %d\n,
r);
-   retval = -EMSGSIZE;
-   continue;
+
+   /*
+* For every speed except full speed, the
+* ep0 maxpacket size is already known.
+*/
+   if (udev-speed == USB_SPEED_FULL) {
+   retval = -EMSGSIZE;
+   continue;
+   }
}
 #undef GET_DESCRIPTOR_BUFSIZE
}

Alan Stern

--
To unsubscribe from this list: send the line unsubscribe linux-usb in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-10-28 Thread Prasad Koya 
Hi

I tried resetting usb device when it gets ETIMEDOUT during get
descriptor. On second retry, I don't see timeout. Please see this
patch:

Index: linux-3.4/drivers/usb/core/hub.c
===
--- linux-3.4.orig/drivers/usb/core/hub.c
+++ linux-3.4/drivers/usb/core/hub.c
@@ -3213,6 +3213,14 @@ hub_port_init (struct usb_hub *hub, stru
  r = -EPROTO;
  break;
  }
+
+if (r == -ETIMEDOUT) {
+ r = usb_reset_device(hdev);
+ if (r) {
+ dev_dbg(udev-dev, failed to reset usb %d\n, r);
+ }
+ }
+
  if (r == 0)
  break;
  }


Here are debugs (sorry if they are too verbose) where it recovers from
timeout. At 6.632 is the first timeout and at 6.968 it was able to get
bMaxPacketSize0. I couldn't reproduce the issue with this patch.

[1.632081] usb 1-3: new high speed USB device using ehci_hcd and address 2
[6.632092] usb 1-3: khubd timed out on ep0in len=0/64 status -2
[6.632110] usb 1-3: hub_port_init: iter 0 maxpktsize 0 r -110
[6.736140] hub 1-0:1.0: port 3: status 0503 change 
[6.736208] usb 1-3: hub_port_init reset usb ret -21
[6.864079] usb 1-3: device descriptor read/64, error -71
[6.968342] usb 1-3: hub_port_init: iter 0 maxpktsize 64 r 18
[7.101325] usb 1-3: default language 0x0409
[7.102201] usb 1-3: udev 2, busnum 1, minor = 1
[7.102205] usb 1-3: New USB device found, idVendor=0e39, idProduct=2b00
[7.102208] usb 1-3: New USB device strings: Mfr=1, Product=2, SerialNumber=3
[7.102212] usb 1-3: Product: eUSB
[7.102214] usb 1-3: Manufacturer: SMART
[7.102217] usb 1-3: SerialNumber: 3E3B2F01123531050102
[7.102424] usb 1-3: configuration #1 chosen from 1 choice
[7.102674] usb 1-3: adding 1-3:1.0 (config #1, interface 0)
[7.460377] hub 1-0:1.0: state 7 ports 5 chg 0008 evt 
[7.460429] hub 1-0:1.0: port 3, status 0503, change , 480 Mb/s

thank you.

On Fri, Oct 25, 2013 at 7:38 AM, Alan Stern st...@rowland.harvard.edu wrote:
 On Fri, 25 Oct 2013, Prasad Koya wrote:

 Resending in plain-text.

 On Thu, Oct 24, 2013 at 11:06 PM, Prasad Koya prasad.k...@gmail.com wrote:
  Hi
 
  I tried with even unmounting the USB before forcing panic and I see same
  time out while getting device descriptor.

 A better test would be to unbind usb-storage from the device
 beforehand.

 Anyway, if the device doesn't allow itself to be reset properly then
 the device is buggy.  You can test this easily enough by forcing a
 device reset by hand; see

 http://marc.info/?l=linux-usbm=126028634531290w=2

  From debugs, I see that the portstatus is 0x501 to start with ie,
  (high-speed attached, power-on, device is attached). After reset I see
  wPortStatus and wPortChange bits as expected. However, get descriptor
  timesout with status as -ENOENT. If I ignore this error and set
  bMaxPacketSize0 to 64, it gets through the initialization but i see
  usb-storage driver doing a reset much later.
 
  Pl see the debugs:

 You have added so many new debugging messages, I can't tell what they
 mean.

 Alan Stern

--
To unsubscribe from this list: send the line unsubscribe linux-usb in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-10-25 Thread Prasad Koya 
Resending in plain-text.

On Thu, Oct 24, 2013 at 11:06 PM, Prasad Koya prasad.k...@gmail.com wrote:
 Hi

 I tried with even unmounting the USB before forcing panic and I see same
 time out while getting device descriptor.

 From debugs, I see that the portstatus is 0x501 to start with ie,
 (high-speed attached, power-on, device is attached). After reset I see
 wPortStatus and wPortChange bits as expected. However, get descriptor
 timesout with status as -ENOENT. If I ignore this error and set
 bMaxPacketSize0 to 64, it gets through the initialization but i see
 usb-storage driver doing a reset much later.

 Pl see the debugs:

 [1.516055] hub 1-0:1.0: state 7 ports 5 chg 0008 evt 
 [1.516060] hub 1-0:1.0: nbr ports 5
 [1.516087] hub 1-0:1.0: hub_port_status: port1 3 ret 4
 [1.516090] hub 1-0:1.0: hub_port_status: port1 3 0x501 0x0   XXX
 
 [1.516094] hub 1-0:1.0: port3 0x501 0x0 ret 0 connchng -1
 [1.516107] hub 1-0:1.0: port 3, status 0501, change , 480 Mb/s
 [1.516119] hub 1-0:1.0: hub_port_connect_change 3209
 [1.516123] hub 1-0:1.0: call hub_port_init hub_port_connect_change 3247
 [1.516199] usb 1-3: hub_port_init 2747: speed 0
 [1.516202] hub 1-0:1.0: resetting port
 [1.516220] hub 1-0:1.0: reset port 3 (err = 0)
 [1.522147] hub 1-0:1.0: usb_device_match
 [1.572069] hub 1-0:1.0: hub_port_status: port1 3 ret 4
 [1.572073] hub 1-0:1.0: hub_port_status: port1 3 0x503 0x10 = XXX
 = (reset complete)
 [1.572076] hub 1-0:1.0: port 3 status 0x503 change 0x10 ret 0
 [1.572080] hub 1-0:1.0: hub_port_wait_reset 2008 speed 3
 [1.572083] hub 1-0:1.0: hub_port_reset port_wait_reset: err = 0
 [1.628044] hub 1-0:1.0: update_address
 [1.628073] hub 1-0:1.0: hub_port_reset port 3.  status 0 2164
 [1.628076] usb 1-3: hub_port_init 2762: retval 0
 [1.628080] usb 1-3: new high speed USB device using ehci_hcd and address
 2
 [1.628083] usb 1-3: hub_port_init get DESCRIPTOR
 [1.628087] usb 1-3: try 0 2868
 [1.628089] usb 1-3: usb_start_wait_urb timeout 5000
 [6.628080] usb 1-3: khubd timed out on ep0in len=0/64 status -2  ==
 -ENOENT
 [6.628097] usb 1-3: hub_port_init: iter 0 maxpktsize 0 r -110  ==
 -ETIMEDOUT
 [6.628101] usb 1-3: hub_port_init: force maxpktsize
 [6.628104] usb 1-3: hub_port_init: call hub_port_reset 2907 port 3
 [6.628130] hub 1-0:1.0: hub_port_status: port1 3 ret 4
 [6.628133] hub 1-0:1.0: hub_port_status: port1 3 0x503 0x0
 [6.628137] usb 1-3: hub_port_init: port_status 2913 ret 0 0x503 0x0
 [6.628141] hub 1-0:1.0: resetting port
 [6.628159] hub 1-0:1.0: reset port 3 (err = 0)
 [6.684097] hub 1-0:1.0: hub_port_status: port1 3 ret 4
 [6.684100] hub 1-0:1.0: hub_port_status: port1 3 0x503 0x10
 [6.684104] hub 1-0:1.0: port 3 status 0x503 change 0x10 ret 0
 [6.684108] hub 1-0:1.0: hub_port_wait_reset 2008 speed 3
 [6.684111] hub 1-0:1.0: hub_port_reset port_wait_reset: err = 0
 [6.740044] hub 1-0:1.0: update_address
 [6.740073] hub 1-0:1.0: hub_port_reset port 3.  status 0 2164
 [6.740077] usb 1-3: hub_port_init: hub_port_reset 2917 port 3 rv 0
 [6.740080] usb 1-3: usb_start_wait_urb timeout 5000
 [6.744048] usb 1-3: usb_ep0_reinit
 [6.760049] usb 1-3: usb_start_wait_urb timeout 5000
 [6.760477] hub 1-0:1.0: call hub_port_init hub_port_connect_change 3249
 status 0x0
 [6.760485] usb 1-3: usb_start_wait_urb timeout 5000
 [6.761221] usb 1-3: default language 0x0409
 [6.761226] usb 1-3: usb_start_wait_urb timeout 5000
 [6.761973] usb 1-3: udev 2, busnum 1, minor = 1
 [6.761976] usb 1-3: New USB device found, idVendor=0e39, idProduct=2b00
 [6.761979] usb 1-3: New USB device strings: Mfr=1, Product=2,
 SerialNumber=3
 [6.761982] usb 1-3: Product: eUSB
 [6.761985] usb 1-3: Manufacturer: SMART
 [6.761987] usb 1-3: SerialNumber: 3E3B2F01123531050102
 [6.762265] usb 1-3: usb_device_match
 [6.762457] usb 1-3: configuration #1 chosen from 1 choice
 [6.762462] usb 1-3: usb_start_wait_urb timeout 5000
 [6.763226] usb 1-3: adding 1-3:1.0 (config #1, interface 0)
 [6.763519] usb 1-3:1.0: usb_device_match
 [6.764961] hub 1-0:1.0: hub_events 3553
 [   27.816144] usb 1-3: usb_reset_device in state 7
 [   27.816153] usb 1-3: usb_ep0_reinit
 [   27.816156] usb_reset_and_verify_device: 3797 calling hub_port_init
 [   27.816161] Pid: 522, comm: usb-storage Not tainted 2.6.32.28.Ar-1399732
 #49
 [   27.816165] Call Trace:
 [   27.816174]  [81204908] hub_port_init+0x3b/0x9f3
 [   27.816181]  [812054a7] usb_reset_device+0x1e7/0x6ed
 [   27.816188]  [81221459] usb_stor_port_reset+0x31/0x4e
 [   27.816192]  [81221ace] usb_stor_invoke_transport+0x2c3/0x31e
 [   27.816199]  [8131405c] ? __mutex_lock_slowpath+0x26c/0x294
 [   27.816204]  [812213a3]
 usb_stor_transparent_scsi_command+0x9/0xb
 [   27.816209]  [81223170]

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-10-25 Thread Alan Stern 
On Fri, 25 Oct 2013, Prasad Koya wrote:

 Resending in plain-text.
 
 On Thu, Oct 24, 2013 at 11:06 PM, Prasad Koya prasad.k...@gmail.com wrote:
  Hi
 
  I tried with even unmounting the USB before forcing panic and I see same
  time out while getting device descriptor.

A better test would be to unbind usb-storage from the device 
beforehand.

Anyway, if the device doesn't allow itself to be reset properly then 
the device is buggy.  You can test this easily enough by forcing a 
device reset by hand; see

http://marc.info/?l=linux-usbm=126028634531290w=2

  From debugs, I see that the portstatus is 0x501 to start with ie,
  (high-speed attached, power-on, device is attached). After reset I see
  wPortStatus and wPortChange bits as expected. However, get descriptor
  timesout with status as -ENOENT. If I ignore this error and set
  bMaxPacketSize0 to 64, it gets through the initialization but i see
  usb-storage driver doing a reset much later.
 
  Pl see the debugs:

You have added so many new debugging messages, I can't tell what they 
mean.

Alan Stern

--
To unsubscribe from this list: send the line unsubscribe linux-usb in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html

Re: khubd timed out on ep0in len=0/64 with 3.4 kernel

2013-10-23 Thread Alan Stern 
On Tue, 22 Oct 2013, Prasad Koya wrote:

 Hi
 
 I have a USB subsystem question. If there is a specific mailing list for
 USB queries I could post it there.

The specific mailing list for USB queries is
linux-usb@vger.kernel.org.  It's listed in the kernel's MAINTAINERS
file.

  I'm seeing this problem with both 2.6.38
 and 3.4 kernels.

Have you tried anything more up to date, such as 3.11?

 I have an embedded system that boots off flash. If the main kernel crashes,

Why does your kernel crash?  That should be the first thing you want to 
fix.

 we go into another kernel to save dmesg from previous kernel. Inside
 crash_kexec'ed kernel, we wait for same flash that main kernel booted off
 to be mounted before we copy out the dmesg from old kernel. At times, I see
 this error inside crash_kexec'ed kernel:
 
  usb 1-3: khubd timed out on ep0in len=0/64
 
 and the USB flash fails to come up with ehci driver. CONFIG_PM is not
 defined.
 
 Here are some more debugs with return codes around this. I
 tried USB_PORT_FEAT_SUSPEND before USB_PORT_FEAT_RESET and I get EPIPE.
 
 [6.628118] usb 1-3: khubd timed out on ep0in len=0/64 status -2
 [6.628124] usb_start_wait_urb 78: retval -110 status -2
 [6.628128] usb_internal_control_msg retv -110 len 0
 [6.628132] usb_control_msg pipe 8080 reqtype 80 ret -110
 [6.628135] hub_port_init: iter 0 maxpktsize 0 r -110
 [6.628140] usb 1-3: usb_start_wait_urb timeout 5000
 [7.793311] usb_start_wait_urb 78: retval -71 status -71
 [7.793316] usb_internal_control_msg retv -71 len 0
 [7.793319] usb_control_msg pipe 8080 reqtype 80 ret -71
 [7.793323] hub_port_init: iter 1 maxpktsize 0 r -71
 [7.793328] usb 1-3: usb_start_wait_urb timeout 5000
 [7.801435] usb_start_wait_urb 78: retval -71 status -71
 [7.801439] usb_internal_control_msg retv -71 len 0
 [7.801443] usb_control_msg pipe 8080 reqtype 80 ret -71
 [7.801446] hub_port_init: iter 2 maxpktsize 0 r -71
 [7.801452] usb usb1: usb_start_wait_urb timeout 1000
 [7.801459] usb_start_wait_urb 78: retval -32 status -32
 [7.801461] usb_internal_control_msg retv -32 len 0
 [7.801464] usb_control_msg pipe 8100 reqtype 23 ret -32
 [7.801468] hub 1-0:1.0: suspend port 3 (err = -32)

It looks like the firmware in the USB flash device has crashed.  That
could explain the original kernel crash.

Or maybe the kernel crashed while the flash device was in the middle of 
executing a command.  Lots of USB storage devices don't reset properly 
when that happens.

 Appreciate any help/pointers.

The kernel log from the time of the original crash might provide some
clues.

Alan Stern



--
To unsubscribe from this list: send the line unsubscribe linux-usb in
the body of a message to majord...@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html