2.6.33: Xorg+khubd lockup (D-state) BUG / ioctl EVIOCGNAME failed: Inappropriate ioctl for device / PreInit returned NULL
in [Kernel]
|
Prev: isdn: Cleanup Sections in PCMCIA driver teles
Next: [Patch 1/1 v2] pata_via: HDD of VT6410/6415/6330 cannot be detected issue
From: Justin Piszcz on 25 Mar 2010 12:50 On Thu, 25 Mar 2010, Alan Stern wrote: > On Thu, 25 Mar 2010, Justin Piszcz wrote: > > > # cat /sys/kernel/debug/usb/devices > > > > T: Bus=02 Lev=00 Prnt=00 Port=00 Cnt=00 Dev#= 1 Spd=12 MxCh= 8 > > B: Alloc= 26/900 us ( 3%), #Int= 2, #Iso= 0 > > D: Ver= 1.10 Cls=09(hub ) Sub=00 Prot=00 MxPS=64 #Cfgs= 1 > > P: Vendor=1d6b ProdID=0001 Rev= 2.06 > > S: Manufacturer=Linux 2.6.33 ohci_hcd > > S: Product=OHCI Host Controller > > S: SerialNumber=0000:00:0b.0 > > 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= 2 Ivl=255ms > > > > T: Bus=02 Lev=01 Prnt=01 Port=04 Cnt=01 Dev#= 2 Spd=1.5 MxCh= 0 > > D: Ver= 1.10 Cls=00(>ifc ) Sub=00 Prot=00 MxPS= 8 #Cfgs= 1 > > P: Vendor=413c ProdID=2005 Rev= 1.05 > > S: Manufacturer=DELL > > S: Product=DELL USB Keyboard > > C:* #Ifs= 1 Cfg#= 1 Atr=a0 MxPwr=100mA > > I:* If#= 0 Alt= 0 #EPs= 1 Cls=03(HID ) Sub=01 Prot=01 Driver=usbhid > > E: Ad=81(I) Atr=03(Int.) MxPS= 8 Ivl=10ms > > > > T: Bus=02 Lev=01 Prnt=01 Port=05 Cnt=02 Dev#= 3 Spd=1.5 MxCh= 0 > > D: Ver= 2.00 Cls=00(>ifc ) Sub=00 Prot=00 MxPS= 8 #Cfgs= 1 > > P: Vendor=046d ProdID=c018 Rev=43.01 > > S: Manufacturer=Logitech > > S: Product=USB Optical Mouse > > C:* #Ifs= 1 Cfg#= 1 Atr=a0 MxPwr=100mA > > I:* If#= 0 Alt= 0 #EPs= 1 Cls=03(HID ) Sub=01 Prot=02 Driver=usbhid > > E: Ad=81(I) Atr=03(Int.) MxPS= 5 Ivl=10ms > > All right, the problematic mouse is attached to bus 2 (as is the > keyboard). So the next step is to run a kernel with CONFIG_USB_DEBUG > enabled. When the mouse stops working, go to > /sys/kernel/debug/usb/ohci/0000:00:0b.0 and see what the various files > in that directory contain. Also, check if any additional debugging > info shows up in the system log. Ok, done, it froze up again: # cat async # # cat periodic size = 32 0 [117]: ed8/f674a040 (ls dev2 ep1in-int qlen 1 max 8 00083082) 1 [ 98]: ed8/f674a0c0 (ls dev3 ep1in-int qlen 1 max 5 00053083) 8 [117]: ed8/f674a040 9 [ 98]: ed8/f674a0c0 16 [117]: ed8/f674a040 17 [ 98]: ed8/f674a0c0 24 [117]: ed8/f674a040 25 [ 98]: ed8/f674a0c0 # cat registers bus pci, device 0000:00:0b.0 OHCI Host Controller ohci_hcd OHCI 1.0, NO legacy support registers control 0x68f RWE RWC HCFS=operational IE PLE CBSR=3 cmdstatus 0x00000 SOC=0 intrstatus 0x00000024 FNO SF intrenable 0x8000004a MIE RHSC RD WDH ed_controlhead 3674a080 hcca frame 0x61e7 fmintvl 0xa7782edf FIT FSMPS=0xa778 FI=0x2edf fmremaining 0x80002565 FRT FR=0x2565 periodicstart 0x2a2f lsthresh 0x0628 hub poll timer off roothub.a 01000208 POTPGT=1 NPS NDP=8(8) roothub.b 00000000 PPCM=0000 DR=0000 roothub.status 00008000 DRWE roothub.portstatus [0] 0x00000100 PPS roothub.portstatus [1] 0x00000100 PPS roothub.portstatus [2] 0x00000100 PPS roothub.portstatus [3] 0x00000100 PPS roothub.portstatus [4] 0x00000303 LSDA PPS PES CCS roothub.portstatus [5] 0x00000303 LSDA PPS PES CCS roothub.portstatus [6] 0x00000100 PPS roothub.portstatus [7] 0x00000100 PPS Nothing unusal in dmesg: [ 30.569377] usb 2-5:1.0: uevent [ 30.572365] usb 2-6:1.0: uevent [ 1053.663314] usb usb1: uevent [ 1053.663404] usb 1-0:1.0: uevent [ 1053.663455] usb usb2: uevent [ 1053.663530] usb 2-0:1.0: uevent [ 1053.663582] usb 2-5: uevent [ 1053.663656] usb 2-5:1.0: uevent [ 1053.663706] usb 2-6: uevent [ 1053.663777] usb 2-6:1.0: uevent <ends here> Anything else worth gathering? Does the above output show the problem? BTW this keyboard and mouse were used on another system for 4+ years without any problems, so it is not a device issue. Justin. > > > > Suppose you don't run X at all. Do the mouse and keyboard eventually > > > stop working even then? > > I have not tried that, the reason I use the host locally is for X. > > You should try it anyway. If the failure still occurs, then you can > rule out any connection with X or the nVidia graphics. It takes a very long time for it to happen when I want it to happen, but if the above output does not help/this bug cannot be found/fixed, I can try that too. Justin. -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
From: Alan Stern on 25 Mar 2010 17:10 On Thu, 25 Mar 2010, Justin Piszcz wrote: > Ok, done, it froze up again: > > # cat async > # > > # cat periodic > size = 32 > 0 [117]: ed8/f674a040 (ls dev2 ep1in-int qlen 1 max 8 00083082) > 1 [ 98]: ed8/f674a0c0 (ls dev3 ep1in-int qlen 1 max 5 00053083) > 8 [117]: ed8/f674a040 > 9 [ 98]: ed8/f674a0c0 > 16 [117]: ed8/f674a040 > 17 [ 98]: ed8/f674a0c0 > 24 [117]: ed8/f674a040 > 25 [ 98]: ed8/f674a0c0 > > # cat registers > bus pci, device 0000:00:0b.0 > OHCI Host Controller > ohci_hcd > OHCI 1.0, NO legacy support registers > control 0x68f RWE RWC HCFS=operational IE PLE CBSR=3 > cmdstatus 0x00000 SOC=0 > intrstatus 0x00000024 FNO SF > intrenable 0x8000004a MIE RHSC RD WDH > ed_controlhead 3674a080 > hcca frame 0x61e7 > fmintvl 0xa7782edf FIT FSMPS=0xa778 FI=0x2edf > fmremaining 0x80002565 FRT FR=0x2565 > periodicstart 0x2a2f > lsthresh 0x0628 > hub poll timer off > roothub.a 01000208 POTPGT=1 NPS NDP=8(8) > roothub.b 00000000 PPCM=0000 DR=0000 > roothub.status 00008000 DRWE > roothub.portstatus [0] 0x00000100 PPS > roothub.portstatus [1] 0x00000100 PPS > roothub.portstatus [2] 0x00000100 PPS > roothub.portstatus [3] 0x00000100 PPS > roothub.portstatus [4] 0x00000303 LSDA PPS PES CCS > roothub.portstatus [5] 0x00000303 LSDA PPS PES CCS > roothub.portstatus [6] 0x00000100 PPS > roothub.portstatus [7] 0x00000100 PPS > Anything else worth gathering? > Does the above output show the problem? No, it all looks normal. As a check you could compare this with the file contents while the mouse is still operating normally. About the only difference should be the "hcca frame" line, which changes constantly. I guess the next test should be to wait for the mouse to stop working, unplug the mouse, and then see once again what these files contain. Alan Stern -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
From: Justin Piszcz on 29 Mar 2010 07:50 On Thu, 25 Mar 2010, Alan Stern wrote: > On Thu, 25 Mar 2010, Justin Piszcz wrote: > > No, it all looks normal. As a check you could compare this with the > file contents while the mouse is still operating normally. About the > only difference should be the "hcca frame" line, which changes > constantly. > > I guess the next test should be to wait for the mouse to stop working, > unplug the mouse, and then see once again what these files contain. > > Alan Stern Done, here is the output: BEFORE UNPLUG: # cat ./kernel/debug/usb/ohci/0000:00:0b.0/periodic size = 32 0 [117]: ed8/f674a040 (ls dev2 ep1in-int qlen 1 max 8 00083082) 1 [ 98]: ed8/f674a0c0 (ls dev3 ep1in-int qlen 1 max 5 00053083) 8 [117]: ed8/f674a040 9 [ 98]: ed8/f674a0c0 16 [117]: ed8/f674a040 17 [ 98]: ed8/f674a0c0 24 [117]: ed8/f674a040 25 [ 98]: ed8/f674a0c0 UNPLUG: # cat ./kernel/debug/usb/ohci/0000:00:0b.0/periodic size = 32 0 [117]: ed8/f674a040 (ls dev2 ep1in-int qlen 1 max 8 00083082) 8 [117]: ed8/f674a040 16 [117]: ed8/f674a040 24 [117]: ed8/f674a040 AFTER PLUG BACK IN: # cat ./kernel/debug/usb/ohci/0000:00:0b.0/periodic size = 32 0 [117]: ed8/f674a040 (ls dev2 ep1in-int qlen 1 max 8 00083082) 8 [117]: ed8/f674a040 16 [117]: ed8/f674a040 24 [117]: ed8/f674a040 KERNEL MESSAGES: [ 30.569377] usb 2-5:1.0: uevent [ 30.572365] usb 2-6:1.0: uevent [ 1053.663314] usb usb1: uevent [ 1053.663404] usb 1-0:1.0: uevent [ 1053.663455] usb usb2: uevent [ 1053.663530] usb 2-0:1.0: uevent [ 1053.663582] usb 2-5: uevent [ 1053.663656] usb 2-5:1.0: uevent [ 1053.663706] usb 2-6: uevent [ 1053.663777] usb 2-6:1.0: uevent [333937.016444] hub 2-0:1.0: state 7 ports 8 chg 0000 evt 0040 [333937.016453] ohci_hcd 0000:00:0b.0: GetStatus roothub.portstatus [5] = 0x00030300 PESC CSC LSDA PPS [333937.016458] hub 2-0:1.0: port 6, status 0300, change 0003, 1.5 Mb/s [333937.016461] usb 2-6: USB disconnect, address 3 [333937.016463] usb 2-6: unregistering device [333937.016465] usb 2-6: usb_disable_device nuking all URBs [333937.016472] ohci_hcd 0000:00:0b.0: shutdown urb f6a2d540 ep1in-intr Justin. -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
From: Alan Stern on 29 Mar 2010 11:40 On Mon, 29 Mar 2010, Justin Piszcz wrote: > Done, here is the output: > > BEFORE UNPLUG: > > # cat ./kernel/debug/usb/ohci/0000:00:0b.0/periodic > size = 32 > 0 [117]: ed8/f674a040 (ls dev2 ep1in-int qlen 1 max 8 00083082) > 1 [ 98]: ed8/f674a0c0 (ls dev3 ep1in-int qlen 1 max 5 00053083) > 8 [117]: ed8/f674a040 > 9 [ 98]: ed8/f674a0c0 > 16 [117]: ed8/f674a040 > 17 [ 98]: ed8/f674a0c0 > 24 [117]: ed8/f674a040 > 25 [ 98]: ed8/f674a0c0 > > UNPLUG: > > # cat ./kernel/debug/usb/ohci/0000:00:0b.0/periodic > size = 32 > 0 [117]: ed8/f674a040 (ls dev2 ep1in-int qlen 1 max 8 00083082) > 8 [117]: ed8/f674a040 > 16 [117]: ed8/f674a040 > 24 [117]: ed8/f674a040 > > AFTER PLUG BACK IN: > > # cat ./kernel/debug/usb/ohci/0000:00:0b.0/periodic > size = 32 > 0 [117]: ed8/f674a040 (ls dev2 ep1in-int qlen 1 max 8 00083082) > 8 [117]: ed8/f674a040 > 16 [117]: ed8/f674a040 > 24 [117]: ed8/f674a040 What about the "registers" file? > KERNEL MESSAGES: > > [ 30.569377] usb 2-5:1.0: uevent > [ 30.572365] usb 2-6:1.0: uevent > [ 1053.663314] usb usb1: uevent > [ 1053.663404] usb 1-0:1.0: uevent > [ 1053.663455] usb usb2: uevent > [ 1053.663530] usb 2-0:1.0: uevent > [ 1053.663582] usb 2-5: uevent > [ 1053.663656] usb 2-5:1.0: uevent > [ 1053.663706] usb 2-6: uevent > [ 1053.663777] usb 2-6:1.0: uevent > [333937.016444] hub 2-0:1.0: state 7 ports 8 chg 0000 evt 0040 > [333937.016453] ohci_hcd 0000:00:0b.0: GetStatus roothub.portstatus [5] = 0x00030300 PESC CSC LSDA PPS > [333937.016458] hub 2-0:1.0: port 6, status 0300, change 0003, 1.5 Mb/s > [333937.016461] usb 2-6: USB disconnect, address 3 > [333937.016463] usb 2-6: unregistering device > [333937.016465] usb 2-6: usb_disable_device nuking all URBs > [333937.016472] ohci_hcd 0000:00:0b.0: shutdown urb f6a2d540 ep1in-intr This all looks normal. It's possible that we've been looking for the bug in the wrong place; maybe there's nothing wrong with the OHCI controller. So next you should get a usbmon trace showing what happens on bus 2 when one of these mouse failures occurs. Instructions for usbmon are in Documentation/usb/usbmon.txt. At the same time, just to be increase my level of certainty, you should apply the following debugging patch for ohci-hcd. Let's see both the usbmon trace and the dmesg log for the same event. The trace and the debugging patch will generate plenty of output during normal operation, but don't worry about that. Only the part starting from shortly before the mouse quits really matters. Alan Stern Index: usb-2.6/drivers/usb/host/ohci-hcd.c =================================================================== --- usb-2.6.orig/drivers/usb/host/ohci-hcd.c +++ usb-2.6/drivers/usb/host/ohci-hcd.c @@ -290,6 +290,8 @@ static int ohci_urb_dequeue(struct usb_h */ urb_priv = urb->hcpriv; if (urb_priv) { + ohci_info(ohci, "start unlink urb %p, ed %p\n", + urb, urb_priv->ed); if (urb_priv->ed->state == ED_OPER) start_ed_unlink (ohci, urb_priv->ed); } @@ -324,6 +326,9 @@ ohci_endpoint_disable (struct usb_hcd *h if (!ed) return; + ohci_info(ohci, "disable ed %p (#%02x) state %d%s\n", + ed, ep->desc.bEndpointAddress, ed->state, + list_empty(&ed->td_list) ? "" : " (has tds)"); rescan: spin_lock_irqsave (&ohci->lock, flags); @@ -770,6 +775,10 @@ static irqreturn_t ohci_irq (struct usb_ return IRQ_HANDLED; } + ohci_info(ohci, "int %x enable %x rm_list %p\n", ints, + ohci_readl(ohci, ®s->intrenable), + ohci->ed_rm_list); + /* We only care about interrupts that are enabled */ ints &= ohci_readl(ohci, ®s->intrenable); -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/
From: Justin Piszcz on 29 Mar 2010 12:30
On Mon, 29 Mar 2010, Alan Stern wrote: > On Mon, 29 Mar 2010, Justin Piszcz wrote: > > What about the "registers" file? Here it is (after I plugged it back in) bus pci, device 0000:00:0b.0 OHCI Host Controller ohci_hcd OHCI 1.0, NO legacy support registers control 0x68f RWE RWC HCFS=operational IE PLE CBSR=3 cmdstatus 0x00000 SOC=0 intrstatus 0x00000020 FNO intrenable 0x8000004e MIE RHSC RD SF WDH ed_controlhead 7bef1b90 hcca frame 0x4657 fmintvl 0xa7782edf FIT FSMPS=0xa778 FI=0x2edf fmremaining 0x80002b76 FRT FR=0x2b76 periodicstart 0x2a2f lsthresh 0x0628 hub poll timer off roothub.a 01000208 POTPGT=1 NPS NDP=8(8) roothub.b 00000000 PPCM=0000 DR=0000 roothub.status 00008000 DRWE roothub.portstatus [0] 0x00000100 PPS roothub.portstatus [1] 0x00000100 PPS roothub.portstatus [2] 0x00000100 PPS roothub.portstatus [3] 0x00000100 PPS roothub.portstatus [4] 0x00000303 LSDA PPS PES CCS roothub.portstatus [5] 0x00000303 LSDA PPS PES CCS roothub.portstatus [6] 0x00000100 PPS roothub.portstatus [7] 0x00000100 PPS > This all looks normal. It's possible that we've been looking for the > bug in the wrong place; maybe there's nothing wrong with the OHCI > controller. > > So next you should get a usbmon trace showing what happens on bus 2 > when one of these mouse failures occurs. Instructions for usbmon are > in Documentation/usb/usbmon.txt. > > At the same time, just to be increase my level of certainty, you should > apply the following debugging patch for ohci-hcd. Let's see both the > usbmon trace and the dmesg log for the same event. The trace and the > debugging patch will generate plenty of output during normal operation, > but don't worry about that. Only the part starting from shortly before > the mouse quits really matters. Yes, I've done this before for a bug in the Intel USB controller (P55) on another motherboard.. Should be doable, always funny though how it does not happen when you are trying to make it happen. For your patch, what does this patch against? It does not apply cleanly for 2.6.33. > > Alan Stern > > > Index: usb-2.6/drivers/usb/host/ohci-hcd.c > =================================================================== > --- usb-2.6.orig/drivers/usb/host/ohci-hcd.c > +++ usb-2.6/drivers/usb/host/ohci-hcd.c > @@ -290,6 +290,8 @@ static int ohci_urb_dequeue(struct usb_h > */ > urb_priv = urb->hcpriv; > if (urb_priv) { > + ohci_info(ohci, "start unlink urb %p, ed %p\n", > + urb, urb_priv->ed); > if (urb_priv->ed->state == ED_OPER) > start_ed_unlink (ohci, urb_priv->ed); > } > @@ -324,6 +326,9 @@ ohci_endpoint_disable (struct usb_hcd *h > > if (!ed) > return; > + ohci_info(ohci, "disable ed %p (#%02x) state %d%s\n", > + ed, ep->desc.bEndpointAddress, ed->state, > + list_empty(&ed->td_list) ? "" : " (has tds)"); > > rescan: > spin_lock_irqsave (&ohci->lock, flags); > @@ -770,6 +775,10 @@ static irqreturn_t ohci_irq (struct usb_ > return IRQ_HANDLED; > } > > + ohci_info(ohci, "int %x enable %x rm_list %p\n", ints, > + ohci_readl(ohci, ®s->intrenable), > + ohci->ed_rm_list); > + > /* We only care about interrupts that are enabled */ > ints &= ohci_readl(ohci, ®s->intrenable); > > -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo(a)vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/ |