On Thu, 8 Mar 2007, Oliver Neukum wrote: > Hi, > > I am seeing khubd hanging on 2.6.21-rc3 blocking device enumeration. ... > Mar 8 09:54:45 valisk kernel: usb usb1: usb auto-resume > Mar 8 09:54:45 valisk kernel: usb usb1: finish resume > Mar 8 09:54:45 valisk kernel: hub 1-0:1.0: hub_resume > Mar 8 09:54:45 valisk kernel: ehci_hcd 0000:00:13.2: resume root hub > Mar 8 09:54:45 valisk kernel: hub 1-0:1.0: state 7 ports 8 chg 0000 evt 0000 > Mar 8 09:54:45 valisk kernel: ehci_hcd 0000:00:13.2: GetStatus port 8 status > 001403 POWER sig=k CSC CONNECT > Mar 8 09:54:45 valisk kernel: hub 1-0:1.0: port 8, status 0501, change 0001, > 480 Mb/s > Mar 8 09:54:45 valisk kernel: hub 1-0:1.0: debounce: port 8: total 100ms > stable 100ms status 0x501 > Mar 8 09:54:45 valisk kernel: ehci_hcd 0000:00:13.2: port 8 low speed --> > companion > Mar 8 09:54:45 valisk kernel: ehci_hcd 0000:00:13.2: GetStatus port 8 status > 003002 POWER OWNER sig=se0 CSC
Okay, you plugged in a low-speed device. ehci-hcd handed it off to one of the OHCI controllers. > Mar 8 09:54:45 valisk kernel: usb usb2: usb auto-resume > Mar 8 09:54:45 valisk kernel: usb usb2: finish resume > Mar 8 09:54:45 valisk kernel: hub 2-0:1.0: hub_resume > Mar 8 09:54:45 valisk kernel: ohci_hcd 0000:00:13.0: resume root hub > Mar 8 09:54:45 valisk kernel: hub 2-0:1.0: state 7 ports 4 chg 0000 evt 0000 > Mar 8 09:54:45 valisk kernel: usb usb3: usb auto-resume > Mar 8 09:54:45 valisk kernel: usb usb3: finish resume > Mar 8 09:54:45 valisk kernel: hub 3-0:1.0: hub_resume I don't understand this. Why did _both_ OHCI controllers wake up? > Mar 8 09:54:45 valisk kernel: ohci_hcd 0000:00:13.1: wakeup root hub This is what you would expect; the new connection causes a wakeup on usb3. But usb2 (00:13.0) got a plain resume, not a wakeup. Why? > Mar 8 09:54:46 valisk kernel: hub 3-0:1.0: state 7 ports 4 chg 0000 evt 0000 > Mar 8 09:54:46 valisk kernel: ohci_hcd 0000:00:13.1: GetStatus > roothub.portstatus [3] = 0x00010301 CSC LSDA PPS CCS > Mar 8 09:54:46 valisk kernel: hub 3-0:1.0: port 4, status 0301, change 0001, > 1.5 Mb/s > Mar 8 09:54:46 valisk kernel: hub 3-0:1.0: debounce: port 4: total 100ms > stable 100ms status 0x301 > Mar 8 09:54:46 valisk kernel: ohci_hcd 0000:00:13.1: GetStatus > roothub.portstatus [3] = 0x00100303 PRSC LSDA PPS PES CCS > Mar 8 09:54:46 valisk kernel: usb 3-4: new low speed USB device using > ohci_hcd and address 2 > Mar 8 09:54:46 valisk kernel: ohci_hcd 0000:00:13.0: auto-stop root hub > Mar 8 09:54:47 valisk kernel: usb 3-4: khubd timed out on ep0in len=0/64 Now it looks like the auto-stop on usb2 caused a failure on usb3. > Mar 8 09:54:47 valisk kernel: hub 1-0:1.0: hub_suspend > Mar 8 09:54:47 valisk kernel: ehci_hcd 0000:00:13.2: suspend root hub > Mar 8 09:54:47 valisk kernel: usb usb1: usb auto-suspend > Mar 8 09:54:47 valisk kernel: hub 2-0:1.0: hub_suspend > Mar 8 09:54:47 valisk kernel: ohci_hcd 0000:00:13.0: suspend root hub > Mar 8 09:54:47 valisk kernel: usb usb2: usb auto-suspend > Mar 8 09:58:05 valisk kernel: khubd D ffff81003dedc080 0 155 > 7 157 152 (L-TLB) > Mar 8 09:58:05 valisk kernel: ffff810037c7bc20 0000000000000046 > 0000000000000001 0000000000000002 > Mar 8 09:58:05 valisk kernel: 00000001803ea002 0000000000000002 > 000000000000000a ffff8100027ec180 > Mar 8 09:58:05 valisk kernel: ffff810037e08100 0000000000000416 > ffff8100027ec380 0000000080240d18 > Mar 8 09:58:06 valisk kernel: Call Trace: > Mar 8 09:58:06 valisk kernel: [<ffffffff804863f4>] > _spin_unlock_irqrestore+0x3e/0x44 > Mar 8 09:58:06 valisk kernel: [<ffffffff80240ef6>] > trace_hardirqs_on+0x11c/0x140 > Mar 8 09:58:06 valisk kernel: [<ffffffff803d5b34>] usb_kill_urb+0xbe/0xeb > Mar 8 09:58:06 valisk kernel: [<ffffffff8023addc>] > autoremove_wake_function+0x0/0x2e > Mar 8 09:58:06 valisk kernel: [<ffffffff803d67a6>] > usb_start_wait_urb+0x105/0x142 > Mar 8 09:58:06 valisk kernel: [<ffffffff803d6a3a>] > usb_control_msg+0xe1/0x106 > Mar 8 09:58:06 valisk kernel: [<ffffffff80240ef6>] > trace_hardirqs_on+0x11c/0x140 > Mar 8 09:58:06 valisk kernel: [<ffffffff803d06e1>] hub_port_init+0x2a0/0x5da > Mar 8 09:58:06 valisk kernel: [<ffffffff803d3341>] hub_thread+0x929/0xfcf > Mar 8 09:58:06 valisk kernel: [<ffffffff80240ef6>] > trace_hardirqs_on+0x11c/0x140 > Mar 8 09:58:06 valisk kernel: [<ffffffff80483874>] thread_return+0x88/0x12b > Mar 8 09:58:06 valisk kernel: [<ffffffff8023addc>] > autoremove_wake_function+0x0/0x2e > Mar 8 09:58:06 valisk kernel: [<ffffffff803d2a18>] hub_thread+0x0/0xfcf > Mar 8 09:58:06 valisk kernel: [<ffffffff8023aa56>] > keventd_create_kthread+0x0/0x6d > Mar 8 09:58:06 valisk kernel: [<ffffffff8023acc6>] kthread+0xd1/0x103 > Mar 8 09:58:06 valisk kernel: [<ffffffff8020a158>] child_rip+0xa/0x12 > Mar 8 09:58:06 valisk kernel: [<ffffffff8048638c>] > _spin_unlock_irq+0x24/0x27 > Mar 8 09:58:06 valisk kernel: [<ffffffff8020986c>] restore_args+0x0/0x30 > Mar 8 09:58:06 valisk kernel: [<ffffffff8023abf5>] kthread+0x0/0x103 > Mar 8 09:58:06 valisk kernel: [<ffffffff8020a14e>] child_rip+0x0/0x12 Evidently khubd is waiting for an unlink of an URB on usb3 to complete. Somehow the fact that usb2 is stopped is causing a problem. It looks as though there's some weird connection between the two OHCI controllers' hardware. A wakeup request on one caused the other to resume also. When the other then stopped, the first no longer worked. Could it be a memory-mapping error? Both sets of registers got mapped to the same address? See what dmesg says when you modprobe ohci-hcd, and do a detailed comparison between 2.6.21-rc3 and a working kernel. Alan Stern ------------------------------------------------------------------------- Take Surveys. Earn Cash. Influence the Future of IT Join SourceForge.net's Techsay panel and you'll get the chance to share your opinions on IT & business topics through brief surveys-and earn cash http://www.techsay.com/default.php?page=join.php&p=sourceforge&CID=DEVDEV _______________________________________________ linux-usb-devel@lists.sourceforge.net To unsubscribe, use the last form field at: https://lists.sourceforge.net/lists/listinfo/linux-usb-devel
