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 can get usbmon
traces.
thank you.
[ 1.306200] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[ 1.306204] ehci_hcd: block sizes: qh 104 qtd 96 itd 192 sitd 96
[ 1.306235] ehci_hcd 0000:00:12.2: PCI->APIC IRQ transform: INT B -> IRQ 23
[ 1.306251] ehci_hcd 0000:00:12.2: EHCI Host Controller
[ 1.306278] /bld/Kernel/Artools-rpmbuild/linux/drivers/usb/core/inode.c:
creating file 'devices'
[ 1.306288] /bld/Kernel/Artools-rpmbuild/linux/drivers/usb/core/inode.c:
creating file '001'
[ 1.306295] ehci_hcd 0000:00:12.2: new USB bus registered, assigned
bus number 1
[ 1.306305] ehci_hcd 0000:00:12.2: reset hcs_params 0x101505 dbg=1
cc=1 pcc=5 ordered !ppc ports=5
[ 1.306311] ehci_hcd 0000:00:12.2: reset hcc_params a072 thresh 7
uframes 256/512/1024
[ 1.306343] ehci_hcd 0000:00:12.2: debug port 1
[ 1.306350] ehci_hcd 0000:00:12.2: reset command 01002a (park)=0
ithresh=1 Async period=256 Reset HALT
[ 1.306360] ehci_hcd 0000:00:12.2: MWI active
[ 1.306378] ehci_hcd 0000:00:12.2: irq 23, io mem 0xe4113400
[ 1.306385] ehci_hcd 0000:00:12.2: reset command 080002 (park)=0
ithresh=8 period=1024 Reset HALT
[ 1.306393] ehci_hcd 0000:00:12.2: init command 010009 (park)=0
ithresh=1 period=256 RUN
[ 1.316049] ehci_hcd 0000:00:12.2: USB 2.0 started, EHCI 1.00
[ 1.316090] usb usb1: default language 0x0409
[ 1.316100] usb usb1: udev 1, busnum 1, minor = 0
[ 1.316104] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[ 1.316107] usb usb1: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[ 1.316111] usb usb1: Product: EHCI Host Controller
[ 1.316114] usb usb1: Manufacturer: Linux 2.6.32.28.Ar-150692 ehci_hcd
[ 1.316118] usb usb1: SerialNumber: 0000:00:12.2
[ 1.316238] usb usb1: usb_probe_device
[ 1.316243] usb usb1: configuration #1 chosen from 1 choice
[ 1.316253] usb usb1: adding 1-0:1.0 (config #1, interface 0)
[ 1.316316] hub 1-0:1.0: usb_probe_interface
[ 1.316319] hub 1-0:1.0: usb_probe_interface - got id
[ 1.316322] hub 1-0:1.0: USB hub found
[ 1.316335] hub 1-0:1.0: 5 ports detected
[ 1.316338] hub 1-0:1.0: standalone hub
[ 1.316341] hub 1-0:1.0: no power switching (usb 1.0)
[ 1.316343] hub 1-0:1.0: individual port over-current protection
[ 1.316347] hub 1-0:1.0: power on to power good time: 20ms
[ 1.316354] hub 1-0:1.0: local power source is good
[ 1.316357] hub 1-0:1.0: trying to enable port power on non-switchable hub
:
[ 1.340448] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[ 1.340451] ohci_hcd: block sizes: ed 80 td 96
[ 1.340475] ohci_hcd 0000:00:12.0: PCI->APIC IRQ transform: INT A -> IRQ 22
[ 1.340494] ohci_hcd 0000:00:12.0: OHCI Host Controller
[ 1.340504] /bld/Kernel/Artools-rpmbuild/linux/drivers/usb/core/inode.c:
creating file '004'
[ 1.340511] ohci_hcd 0000:00:12.0: new USB bus registered, assigned
bus number 4
[ 1.340525] ohci_hcd 0000:00:12.0: enabled AMD prefetch quirk
[ 1.340535] ohci_hcd 0000:00:12.0: created debug files
[ 1.340545] ohci_hcd 0000:00:12.0: irq 22, io mem 0xe4110000
[ 1.400028] ohci_hcd 0000:00:12.0: OHCI controller state
[ 1.400036] ohci_hcd 0000:00:12.0: OHCI 1.0, NO legacy support registers
[ 1.400041] ohci_hcd 0000:00:12.0: control 0x083 HCFS=operational CBSR=3
[ 1.400046] ohci_hcd 0000:00:12.0: cmdstatus 0x00000 SOC=0
[ 1.400051] ohci_hcd 0000:00:12.0: intrstatus 0x00000004 SF
[ 1.400056] ohci_hcd 0000:00:12.0: intrenable 0x8000005a MIE RHSC UE RD WDH
[ 1.400067] ohci_hcd 0000:00:12.0: hcca frame #0005
[ 1.400072] ohci_hcd 0000:00:12.0: roothub.a 02000205 POTPGT=2 NPS NDP=5(5)
[ 1.400077] ohci_hcd 0000:00:12.0: roothub.b 00000000 PPCM=0000 DR=0000
[ 1.400082] ohci_hcd 0000:00:12.0: roothub.status 00008000 DRWE
[ 1.400087] ohci_hcd 0000:00:12.0: roothub.portstatus [0] 0x00000100 PPS
[ 1.400092] ohci_hcd 0000:00:12.0: roothub.portstatus [1] 0x00000100 PPS
[ 1.400097] ohci_hcd 0000:00:12.0: roothub.portstatus [2] 0x00000100 PPS
[ 1.400102] ohci_hcd 0000:00:12.0: roothub.portstatus [3] 0x00000100 PPS
[ 1.400107] ohci_hcd 0000:00:12.0: roothub.portstatus [4] 0x00000100 PPS
:
[ 1.572140] ehci_hcd 0000:00:12.2: port 3 high speed
[ 1.572146] ehci_hcd 0000:00:12.2: GetStatus port 3 status 001005
POWER sig=se0 PE CONNECT
:
[ 1.628093] usb 1-3: new high speed USB device using ehci_hcd and address 2
:
[ 6.628159] usb 1-3: khubd timed out on ep0in len=0/64
[ 7.665178] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 1
[ 7.665428] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 2
[ 7.665677] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 3
[ 7.665927] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 4
[ 7.666176] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 5
[ 7.666426] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 6
[ 7.666676] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 7
[ 7.666926] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 8
[ 7.667176] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 9
[ 7.667425] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 10
[ 7.667675] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 11
[ 7.667925] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 12
[ 7.668180] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 13
[ 7.668429] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 14
[ 7.668678] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 15
[ 7.668928] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 16
[ 7.669178] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 17
[ 7.669428] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 18
[ 7.669678] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 19
[ 7.669927] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 20
[ 7.670177] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 21
[ 7.670426] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 22
[ 7.670676] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 23
[ 7.670926] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 24
[ 7.671176] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 25
[ 7.671425] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 26
[ 7.671675] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 27
[ 7.671925] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 28
[ 7.672180] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 29
[ 7.672429] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 30
[ 7.672679] ehci_hcd 0000:00:12.2: detected XactErr len 0/64 retry 31
[ 7.672928] ehci_hcd 0000:00:12.2: devpath 3 ep0in 3strikes
[ 7.673302] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 1
[ 7.673552] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 2
[ 7.673802] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 3
[ 7.674052] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 4
[ 7.674302] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 5
[ 7.674552] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 6
[ 7.674801] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 7
[ 7.675051] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 8
[ 7.675301] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 9
[ 7.675550] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 10
[ 7.675800] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 11
[ 7.676045] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 12
[ 7.676304] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 13
[ 7.676554] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 14
[ 7.676804] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 15
[ 7.677053] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 16
[ 7.677303] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 17
[ 7.677553] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 18
[ 7.677803] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 19
[ 7.678052] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 20
[ 7.678302] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 21
[ 7.678552] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 22
[ 7.678801] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 23
[ 7.679051] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 24
[ 7.679301] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 25
[ 7.679550] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 26
[ 7.679800] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 27
[ 7.680045] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 28
[ 7.680304] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 29
[ 7.680554] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 30
[ 7.680804] ehci_hcd 0000:00:12.2: detected XactErr len 0/8 retry 31
[ 7.681053] ehci_hcd 0000:00:12.2: devpath 3 ep0in 3strikes
[ 7.736055] ehci_hcd 0000:00:12.2: port 3 full speed --> companion
[ 7.736064] ehci_hcd 0000:00:12.2: GetStatus port 3 status 003801
POWER OWNER sig=j CONNECT
On Wed, Oct 30, 2013 at 7:48 AM, Alan Stern <stern@xxxxxxxxxxxxxxxxxxx> wrote:
> 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 majordomo@xxxxxxxxxxxxxxx
More majordomo info at http://vger.kernel.org/majordomo-info.html
