Re: xhci_hcd and Canon Lide 110 not playing well together
Hey Alan,
On Mo, 2013-12-23 at 15:38 -0500, Alan Stern wrote:
On Mon, 23 Dec 2013, Matthias [ISO-8859-1] Blsing wrote:
Looking at the strace alone, I see, that the USBDEVFS_SETCONFIGURATION
ioctl calls take excessive time.
You're right; those calls took an excessively long time. The usbmon
traces show that the communication with the device was very quick. I
don't know where the rest of the time was spent.
The most likely possibility is locking the bandwidth mutex. But that
wouldn't require much time either, unless something else was going on
at the same time.
You could try adding a few statements of the form
dev_info(dev-dev, [Your message here]\n);
at various spots inside drivers/usb/core/message.c's
usb_reset_configuration() routine. Maybe you'll be able to see where
everything slows down. (Be sure to set CONFIG_PRINTK_TIME when you
build the kernel.)
The slow down can be tracked to:
usb_enable_interface(dev, intf, true);
I springled comments like this:
dev_info(dev-dev, T1\n);
/* re-init hc/hcd interface/endpoint state */
for (i = 0; i config-desc.bNumInterfaces; i++) {
struct usb_interface *intf = config-interface[i];
struct usb_host_interface *alt;
dev_info(dev-dev, T2-1\n);
alt = usb_altnum_to_altsetting(intf, 0);
dev_info(dev-dev, T2-2\n);
/* No altsetting 0? We'll assume the first altsetting.
* We could use a GetInterface call, but if a device is
* so non-compliant that it doesn't have altsetting 0
* then I wouldn't trust its reply anyway.
*/
if (!alt)
alt = intf-altsetting[0];
if (alt != intf-cur_altsetting) {
dev_info(dev-dev, T2-X1\n);
remove_intf_ep_devs(intf);
dev_info(dev-dev, T2-X2\n);
usb_remove_sysfs_intf_files(intf);
dev_info(dev-dev, T2-X3\n);
}
intf-cur_altsetting = alt;
dev_info(dev-dev, T2-3\n);
usb_enable_interface(dev, intf, true);
dev_info(dev-dev, T2-4\n);
if (device_is_registered(intf-dev)) {
dev_info(dev-dev, T2-5\n);
usb_create_sysfs_intf_files(intf);
dev_info(dev-dev, T2-6\n);
create_intf_ep_devs(intf);
dev_info(dev-dev, T2-7\n);
}
}
dev_info(dev-dev, T3\n);
And got the attached log (minus my inline comments). As you can see it
starts in the 5. call there it starts with a 5 second delay betewen T2-3
and T2-4. In the next round 15s is reached and there it stays.
My tests of a second run support this and are finalized by xsane
freezing and the final GPF.
Maybe this helps.
Greetings
Matthias
= Start
Dec 25 21:16:09 athena kernel: [ 104.886377] usb 3-2: T1
Dec 25 21:16:09 athena kernel: [ 104.886380] usb 3-2: T2-1
Dec 25 21:16:09 athena kernel: [ 104.886381] usb 3-2: T2-2
Dec 25 21:16:09 athena kernel: [ 104.886382] usb 3-2: T2-3
Dec 25 21:16:09 athena kernel: [ 104.886647] usb 3-2: T2-4
Dec 25 21:16:09 athena kernel: [ 104.886648] usb 3-2: T2-5
Dec 25 21:16:09 athena kernel: [ 104.886649] usb 3-2: T2-6
Dec 25 21:16:09 athena kernel: [ 104.886650] usb 3-2: T2-7
Dec 25 21:16:09 athena kernel: [ 104.886651] usb 3-2: T3
Dec 25 21:16:15 athena kernel: [ 111.329474] usb 3-2: T1
Dec 25 21:16:15 athena kernel: [ 111.329478] usb 3-2: T2-1
Dec 25 21:16:15 athena kernel: [ 111.329479] usb 3-2: T2-2
Dec 25 21:16:15 athena kernel: [ 111.329481] usb 3-2: T2-3
Dec 25 21:16:15 athena kernel: [ 111.329756] usb 3-2: T2-4
Dec 25 21:16:15 athena kernel: [ 111.329758] usb 3-2: T2-5
Dec 25 21:16:15 athena kernel: [ 111.329760] usb 3-2: T2-6
Dec 25 21:16:15 athena kernel: [ 111.329762] usb 3-2: T2-7
Dec 25 21:16:15 athena kernel: [ 111.329763] usb 3-2: T3
Dec 25 21:16:15 athena kernel: [ 111.390151] usb 3-2: T1
Dec 25 21:16:15 athena kernel: [ 111.390154] usb 3-2: T2-1
Dec 25 21:16:15 athena kernel: [ 111.390155] usb 3-2: T2-2
Dec 25 21:16:15 athena kernel: [ 111.390156] usb 3-2: T2-3
Dec 25 21:16:15 athena kernel: [ 111.390428] usb 3-2: T2-4
Dec 25 21:16:15 athena kernel: [ 111.390429] usb 3-2: T2-5
Dec 25 21:16:15 athena kernel: [ 111.390430] usb 3-2: T2-6
Dec 25 21:16:15 athena kernel: [ 111.390431] usb 3-2: T2-7
Dec 25 21:16:15 athena kernel: [ 111.390432] usb 3-2: T3
Dec 25 21:16:15 athena kernel: [ 111.470847] usb 3-2: T1
Dec 25 21:16:15 athena kernel: [ 111.470850] usb 3-2: T2-1
Dec 25 21:16:15 athena kernel: [ 111.470851] usb 3-2: T2-2
Dec 25 21:16:15 athena kernel: [ 111.470852] usb 3-2: T2-3
Dec 25 21:16:15 athena kernel: [ 111.471119] usb 3-2: T2-4
Dec 25 21:16:15 athena kernel: [ 111.471120]
Re: xhci_hcd and Canon Lide 110 not playing well together
Hey all, On Fr, 2013-12-13 at 17:53 +0100, Holger Hans Peter Freyther wrote: On Tue, May 28, 2013 at 07:40:57PM +0200, Holger Hans Peter Freyther wrote: Is there a timeline when you think this could be fixed? I tried with 3.10.x and 3.12.5 and the symptoms remain the same. The first time it is working, the second time the scanning does not start. The scanner is still working fine on other machines (with the identical cable). as I'm facing a similar problem (Canon Lide, though 25 instead of 110), I would also like to know if there are news about this. See http://thread.gmane.org/gmane.linux.usb.general/99815 for details about the hardware. If something is missing I'll try to provide it. Its strange, that the same hardware (notebook and scanner) works on one port, but not on the other). I tried again today and all physical ports I can access are either connected to Bus 03 (I suspect, that Bus 04 and Bus 03 are the same, only differing in their speed) or Bus 02. Bus 02 (Driver=ehci-pci/2p, 480M) works, Bus 03 (Driver=xhci_hcd/4p, 480M) fails. Any ideas? Greetings Matthias PS: I removed my subscription of linux-usb as I got flooded with mails, please keep me CCed. -- 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: Scanner works on EHCI port, fails on XHCI Port
Hey, On Mo, 2013-12-09 at 21:07 +0100, Matthias Bläsing wrote: [USB Scanner working on EHCI port, but not on XHCI] some more info - sorry I should have provided that in the first place. The USB Host is a DELL E 5530 Notebook, with this hardware: matthias@athena:~$ lspci 00:00.0 Host bridge: Intel Corporation 3rd Gen Core processor DRAM Controller (rev 09) 00:02.0 VGA compatible controller: Intel Corporation 3rd Gen Core processor Graphics Controller (rev 09) 00:14.0 USB controller: Intel Corporation 7 Series/C210 Series Chipset Family USB xHCI Host Controller (rev 04) 00:16.0 Communication controller: Intel Corporation 7 Series/C210 Series Chipset Family MEI Controller #1 (rev 04) 00:1a.0 USB controller: Intel Corporation 7 Series/C210 Series Chipset Family USB Enhanced Host Controller #2 (rev 04) 00:1b.0 Audio device: Intel Corporation 7 Series/C210 Series Chipset Family High Definition Audio Controller (rev 04) 00:1c.0 PCI bridge: Intel Corporation 7 Series/C210 Series Chipset Family PCI Express Root Port 1 (rev c4) 00:1c.1 PCI bridge: Intel Corporation 7 Series/C210 Series Chipset Family PCI Express Root Port 2 (rev c4) 00:1c.2 PCI bridge: Intel Corporation 7 Series/C210 Series Chipset Family PCI Express Root Port 3 (rev c4) 00:1c.3 PCI bridge: Intel Corporation 7 Series/C210 Series Chipset Family PCI Express Root Port 4 (rev c4) 00:1c.5 PCI bridge: Intel Corporation 7 Series/C210 Series Chipset Family PCI Express Root Port 6 (rev c4) 00:1c.6 PCI bridge: Intel Corporation 7 Series/C210 Series Chipset Family PCI Express Root Port 7 (rev c4) 00:1d.0 USB controller: Intel Corporation 7 Series/C210 Series Chipset Family USB Enhanced Host Controller #1 (rev 04) 00:1f.0 ISA bridge: Intel Corporation HM77 Express Chipset LPC Controller (rev 04) 00:1f.2 SATA controller: Intel Corporation 7 Series Chipset Family 6-port SATA Controller [AHCI mode] (rev 04) 00:1f.3 SMBus: Intel Corporation 7 Series/C210 Series Chipset Family SMBus Controller (rev 04) 02:00.0 Network controller: Intel Corporation Centrino Ultimate-N 6300 (rev 35) 0b:00.0 SD Host controller: O2 Micro, Inc. Device 8221 (rev 05) 0c:00.0 Ethernet controller: Broadcom Corporation NetXtreme BCM5761 Gigabit Ethernet PCIe (rev 10) matthias@athena:~$ I'm on a current kernel: matthias@athena:~$ uname -a Linux athena 3.12.4-031204-generic #201312081207 SMP Sun Dec 8 17:08:59 UTC 2013 x86_64 x86_64 x86_64 GNU/Linux matthias@athena:~$ Same happens with a 3.11 series kernel. The linux distribution is linux mint. Thanks Matthias -- 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
Scanner works on EHCI port, fails on XHCI Port
Hello, I hope this is the right place to ask. I own a Canon CanoScan LiDE 25. The scanner worked well the last few years and with my new notebook it only works in one port. From the tree it seems to be tied to the controller: This works: matthias@athena:~$ lsusb -t /: Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M |__ Port 4: Dev 2, If 0, Class=Hub, Driver=hub/3p, 5000M /: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 480M |__ Port 4: Dev 2, If 0, Class=Hub, Driver=hub/3p, 480M |__ Port 1: Dev 3, If 0, Class=Hub, Driver=hub/4p, 480M |__ Port 3: Dev 5, If 0, Class=Audio, Driver=snd-usb-audio, 12M |__ Port 3: Dev 5, If 1, Class=Audio, Driver=snd-usb-audio, 12M |__ Port 3: Dev 5, If 2, Class=Audio, Driver=snd-usb-audio, 12M |__ Port 3: Dev 5, If 3, Class=Human Interface Device, Driver=usbhid, 12M |__ Port 2: Dev 4, If 0, Class=Human Interface Device, Driver=usbhid, 1.5M /: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M |__ Port 8: Dev 3, If 0, Class=Hub, Driver=hub/3p, 480M /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M |__ Port 2: Dev 12, If 0, Class=Vendor Specific Class, Driver=, 12M |__ Port 4: Dev 3, If 0, Class=Vendor Specific Class, Driver=btusb, 12M |__ Port 4: Dev 3, If 1, Class=Vendor Specific Class, Driver=btusb, 12M |__ Port 4: Dev 3, If 2, Class=Vendor Specific Class, Driver=, 12M |__ Port 4: Dev 3, If 3, Class=Application Specific Interface, Driver=, 12M |__ Port 5: Dev 4, If 0, Class=Video, Driver=uvcvideo, 480M |__ Port 5: Dev 4, If 1, Class=Video, Driver=uvcvideo, 480M matthias@athena:~$ While this fails: matthias@athena:~$ lsusb -t /: Bus 04.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 5000M |__ Port 4: Dev 2, If 0, Class=Hub, Driver=hub/3p, 5000M /: Bus 03.Port 1: Dev 1, Class=root_hub, Driver=xhci_hcd/4p, 480M |__ Port 2: Dev 16, If 0, Class=Vendor Specific Class, Driver=, 12M |__ Port 4: Dev 2, If 0, Class=Hub, Driver=hub/3p, 480M |__ Port 1: Dev 3, If 0, Class=Hub, Driver=hub/4p, 480M |__ Port 3: Dev 5, If 0, Class=Audio, Driver=snd-usb-audio, 12M |__ Port 3: Dev 5, If 1, Class=Audio, Driver=snd-usb-audio, 12M |__ Port 3: Dev 5, If 2, Class=Audio, Driver=snd-usb-audio, 12M |__ Port 3: Dev 5, If 3, Class=Human Interface Device, Driver=usbhid, 12M |__ Port 2: Dev 4, If 0, Class=Human Interface Device, Driver=usbhid, 1.5M /: Bus 02.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/8p, 480M |__ Port 8: Dev 3, If 0, Class=Hub, Driver=hub/3p, 480M /: Bus 01.Port 1: Dev 1, Class=root_hub, Driver=ehci-pci/2p, 480M |__ Port 1: Dev 2, If 0, Class=Hub, Driver=hub/6p, 480M |__ Port 4: Dev 3, If 0, Class=Vendor Specific Class, Driver=btusb, 12M |__ Port 4: Dev 3, If 1, Class=Vendor Specific Class, Driver=btusb, 12M |__ Port 4: Dev 3, If 2, Class=Vendor Specific Class, Driver=, 12M |__ Port 4: Dev 3, If 3, Class=Application Specific Interface, Driver=, 12M |__ Port 5: Dev 4, If 0, Class=Video, Driver=uvcvideo, 480M |__ Port 5: Dev 4, If 1, Class=Video, Driver=uvcvideo, 480M matthias@athena:~$ Attached to this email you find a usbmon trace of both cases (different devices, as I got the trees after I made the traces). Basic intention: I want to be able to use the scanner on the port tied to the xhci, as I can on the EHCI one. If I can provide more information or if there is a more appropriate place to ask, please say so. Thank you in advance Matthias 88020d55cc00 4057213234 C Ii:3:001:1 0:2048 1 = 04 88020d55cc00 4057213263 S Ii:3:001:1 -115:2048 4 88020a9f7180 4057213307 S Ci:3:001:0 s a3 00 0002 0004 4 88020a9f7180 4057213318 C Ci:3:001:0 0 4 = 01010100 88020a9f7180 4057213322 S Co:3:001:0 s 23 01 0010 0002 0 88020a9f7180 4057213325 C Co:3:001:0 0 0 88020a9f7180 4057213327 S Ci:3:001:0 s a3 00 0002 0004 4 88020a9f7180 4057213329 C Ci:3:001:0 0 4 = 0101 88020d307780 4057243802 S Ci:3:001:0 s a3 00 0002 0004 4 88020d307780 4057243830 C Ci:3:001:0 0 4 = 0101 88020a9f7180 4057275809 S Ci:3:001:0 s a3 00 0002 0004 4 88020a9f7180 4057275829 C Ci:3:001:0 0 4 = 0101 88020f470b40 4057307784 S Ci:3:001:0 s a3 00 0002 0004 4 88020f470b40 4057307821 C Ci:3:001:0 0 4 = 0101 88020d307780 4057339809 S Ci:3:001:0 s a3 00 0002 0004 4 88020d307780 4057339829 C Ci:3:001:0 0 4 = 0101 88020d307780 4057339903 S Co:3:001:0 s 23 03 0004 0002 0 88020d307780 4057339910 C Co:3:001:0 0 0 88020a9f7900 4057395785 S Ci:3:001:0 s a3 00 0002 0004 4
