Bug 6684

Summary: USB mouse stops working after disconnecting and reconnecting
Product: Drivers Reporter: Jure Repinc (jlp.bugs)
Component: USBAssignee: David Brownell (dbrownell)
Status: RESOLVED CODE_FIX    
Severity: normal CC: akpm, bunk, dbrownell, greg, stern
Priority: P2    
Hardware: i386   
OS: Linux   
Kernel Version: 2.6.17-mm5 Subsystem:
Regression: --- Bisected commit-id:
Bug Depends on:    
Bug Blocks: 5089    
Attachments: Output of dmesg
ohci root hub polling tweak
ohci-hub.c rejects
ohci root hub polling patch queued for 2.6.19

Description Jure Repinc 2006-06-13 06:20:44 UTC
Most recent kernel where this bug did not occur: 2.6.16.20 (will check other 
2.6.17-* later)
Distribution: Gentoo Linux (32-bit)
Hardware Environment: HP Compaq nx6125 laptop with Logitech MX 510 Optical 
Mouse

Problem Description:
When I unplug and then plug-in the USB mouse back it stops working. When I plug 
the mouse back into the USB port the light comes back for a very short period 
but then it just turns of and the mouse doesn't work anymore.

Steps to reproduce:
1. Boot up with mouse connected and make sure it works
2. Disconnect the mouse
3. Reconnect the mouse
Comment 1 Alan Stern 2006-06-13 07:48:27 UTC
Can you please turn on USB verbose debugging in the kernel configuration
(CONFIG_USB_DEBUG) and attach here the dmesg log showing what happens when you
unplug the mouse and then plug it back in?
Comment 2 Jure Repinc 2006-06-13 08:40:44 UTC
Created attachment 8294 [details]
Output of dmesg

This is the output of dmesg with USB debugging enabled.
Comment 3 Alan Stern 2006-06-13 11:52:38 UTC
This appears to be a problem with the OHCI controller.  I will ask someone who
is familiar with that driver to look at this bug report.
Comment 4 David Brownell 2006-06-13 12:55:42 UTC
Created attachment 8298 [details]
ohci root hub polling tweak

I suspect it's actually a previously-unknown issue with the
patch which teaches OHCI how to use the "new polling" scheme.
I know of what I think is a _different_ issue, addressed in
part by the attached patch, but there's still another problem
I found with that one.

If the issue is indeed with that OHCI patch (in the MM tree)
then it won't be found in the 2.6.17-rc tree.
Comment 5 Andrew Morton 2006-06-19 15:20:05 UTC
Jure, have you been able to test that patch?

Thanks.
Comment 6 Jure Repinc 2006-06-19 19:08:52 UTC
Sorry, not yet. I will do it in about 10 hours and report back.
Comment 7 Jure Repinc 2006-06-20 07:37:08 UTC
When trying to patch I got this:

cat ../ohci.patch | patch -p1
patching file drivers/usb/host/ohci-hub.c
Hunk #1 succeeded at 350 (offset -1 lines).
Hunk #2 FAILED at 366.
Hunk #3 FAILED at 373.
2 out of 3 hunks FAILED -- saving rejects to file drivers/usb/host/ohci-hub.c.rej

I'll now recompile kernel and see how it goes.
Comment 8 Jure Repinc 2006-06-20 07:45:13 UTC
Created attachment 8352 [details]
ohci-hub.c rejects
Comment 9 Jure Repinc 2006-06-20 08:04:51 UTC
It looks like the patch doesn't work, or it didn't apply correctly.
Comment 10 Alan Stern 2006-06-20 08:39:37 UTC
I think David needs to be on the CC list for this bug, since it's up his alley.
Comment 11 Jure Repinc 2006-07-01 18:32:27 UTC
Updating the kernel version since it still happens in 2.6.17-mm5. Is there any 
updated patch for this version that I could test again?
Comment 12 Adrian Bunk 2006-07-14 11:41:20 UTC
Is this issue still present in kernel 2.6.18-rc1-mm2?
Comment 13 Jure Repinc 2006-07-15 15:03:32 UTC
No it still doesn't work. I get this dmesg output when unplugging and
re-plugging the mouse:

tg3: eth0: Link is up at 100 Mbps, full duplex.
tg3: eth0: Flow control is on for TX and on for RX.
ohci_hcd 0000:00:13.1: urb d7dc8440 path 3 ep1in 5c160000 cc 5 --> status -110
usbhid 3-3:1.0: retrying intr urb
ohci_hcd 0000:00:13.1: urb d7dc8440 path 3 ep1in 5c160000 cc 5 --> status -110
usbhid 3-3:1.0: retrying intr urb
ohci_hcd 0000:00:13.1: urb d7dc8440 path 3 ep1in 5c160000 cc 5 --> status -110
usbhid 3-3:1.0: retrying intr urb
ohci_hcd 0000:00:13.1: urb d7dc8440 path 3 ep1in 5c160000 cc 5 --> status -110
usbhid 3-3:1.0: retrying intr urb
ohci_hcd 0000:00:13.1: urb d7dc8440 path 3 ep1in 5c160000 cc 5 --> status -110
usbhid 3-3:1.0: retrying intr urb
ohci_hcd 0000:00:13.1: urb d7dc8440 path 3 ep1in 5c160000 cc 5 --> status -110
usbhid 3-3:1.0: retrying intr urb
ohci_hcd 0000:00:13.1: urb d7dc8440 path 3 ep1in 5c160000 cc 5 --> status -110
usbhid 3-3:1.0: retrying intr urb
ohci_hcd 0000:00:13.1: urb d7dc8440 path 3 ep1in 5c160000 cc 5 --> status -110
usbhid 3-3:1.0: retrying intr urb
ohci_hcd 0000:00:13.1: urb d7dc8440 path 3 ep1in 5c160000 cc 5 --> status -110
usbhid 3-3:1.0: retrying intr urb
ohci_hcd 0000:00:13.1: urb d7dc8440 path 3 ep1in 5c160000 cc 5 --> status -110
usbhid 3-3:1.0: retrying intr urb
ohci_hcd 0000:00:13.1: urb d7dc8440 path 3 ep1in 5c160000 cc 5 --> status -110
usbhid 3-3:1.0: resetting device
ohci_hcd 0000:00:13.1: GetStatus roothub.portstatus [2] = 0x00030100 PESC CSC PPS
ohci_hcd 0000:00:13.1: GetStatus roothub.portstatus [2] = 0x00030100 PESC CSC PPS
ohci_hcd 0000:00:13.1: GetStatus roothub.portstatus [2] = 0x00030100 PESC CSC PPS
ohci_hcd 0000:00:13.1: GetStatus roothub.portstatus [2] = 0x00030100 PESC CSC PPS
hub 3-0:1.0: logical disconnect on port 3
hub 3-0:1.0: state 7 ports 4 chg 0008 evt 0000
ohci_hcd 0000:00:13.1: GetStatus roothub.portstatus [2] = 0x00030100 PESC CSC PPS
hub 3-0:1.0: port 3, status 0100, change 0003, 12 Mb/s
usb 3-3: USB disconnect, address 3
usb 3-3: unregistering device
usb 3-3: usb_disable_device nuking all URBs
BUG: unable to handle kernel NULL pointer dereference at virtual address 00000020
 printing eip:
c0134d2f
*pde = 00000000
Oops: 0000 [#1]
8K_STACKS PREEMPT
last sysfs file: /power/state
Modules linked in: radeon drm eth1394 evdev bcm43xx ohci1394 snd_atiixp
ieee80211softmac ieee80211 ieee1394 snd_ac97_codec sdhci pcspkr ati_agp agpgart
tg3 ieee80211_crypt snd_ac97_bus
CPU:    0
EIP:    0060:[<c0134d2f>]    Not tainted VLI
EFLAGS: 00010046   (2.6.18-rc1-mm2 #1)
EIP is at __lock_acquire+0x4f/0xd60
eax: 0000001c   ebx: 00000000   ecx: 00000000   edx: 00000000
esi: 00000001   edi: c05f0080   ebp: c13f9e3c   esp: c13f9de4
ds: 007b   es: 007b   ss: 0068
Process khubd (pid: 164, ti=c13f8000 task=d7f4e070 task.ti=c13f8000)
Stack: c04d4685 c05d8d00 d7f4e070 00000000 00000000 00000000 c04d27a5 00000000
       00000000 00000000 0000001c d7f4e070 c01345a8 00000000 00000046 c016659d
       d73e86c0 d7ea43ac d7ea4380 00000246 d6dacd18 c05f0080 c13f9e58 c0135d98
Call Trace:
 [<c0103b49>] show_stack_log_lvl+0xa9/0xd0
 [<c0103d98>] show_registers+0x1d8/0x260
 [<c0103f59>] die+0x139/0x340
 [<c0113762>] do_page_fault+0x292/0x5bd
 [<c01035d1>] error_code+0x39/0x40
 [<c0135d98>] lock_acquire+0x68/0x90
 [<c04d4035>] _spin_lock+0x45/0x60
 [<c04d0d69>] klist_remove+0x19/0x40
 [<c03d80f3>] bus_remove_device+0xa3/0xd0
 [<c03d69f0>] device_del+0x140/0x180
 [<c041d25a>] usb_disconnect+0xda/0x130
 [<c041e4f2>] hub_thread+0x3b2/0xfd0
 [<c012e029>] kthread+0xe9/0xf0
 [<c0100865>] kernel_thread_helper+0x5/0x10
Code: 45 d4 0f 84 cd 02 00 00 9c 58 f6 c4 02 0f 85 2a 0b 00 00 83 7d cc 07 0f 87
42 0b 00 00 8b 5d cc 85 db 0f 85 b9 02 00 00 8b 45 d0 <8b> 58 04 85 db 0f 84 ab
02 00 00 ff 83 9c 00 00 00 8b 45 d4 8b
EIP: [<c0134d2f>] __lock_acquire+0x4f/0xd60 SS:ESP 0068:c13f9de4
 <6>note: khubd[164] exited with preempt_count 1
Comment 14 Jure Repinc 2006-07-15 15:45:17 UTC
Well, I forgot to apply a patch from hotfixes folder, but after applying it and
recompiling it still doesn't work. The dmesg output still looks the same as in
the one I attached at the start.
Comment 15 David Brownell 2006-08-30 01:30:06 UTC
Created attachment 8902 [details]
ohci root hub polling patch queued for 2.6.19

Try the attached patch against 2.6.18-rc5 (the patch should already
be in the MM tree) ... if you had problems with the previous patch,
it's likely you were using the wrong base kernel version.  (No, we
don't want to hear about vendor kernels, even gentoo.)
Comment 16 David Brownell 2006-09-10 08:18:21 UTC
Unless I get confirmation that this bug is still showing  
up in the latest MM patchset, I'll mark this closed during  
the week of 18-Sept-2006 ... if it still appears then, 
then either reproduce it with the current kernel.org code 
(e.g. 2.6.18-rc6 right now) or else bisect the MM patches 
to show which patch there is causing the problem. 
  
FWIW this never looked like anything specific to OHCI. 
Looks most like a mouse/HID driver issue (the -110 errors) 
combined with a should-be-long-fixed driver model related 
problem (the oops). 
Comment 17 Alan Stern 2006-09-10 09:27:49 UTC
The reason I said it appeared to be related to OHCI was because the log shows
(at the end) the disconnection followed by the reconnection and EHCI handing off
to the companion -- but the companion doesn't notice it.

Of course, that's at the very end of the log so maybe the wakeup just wasn't
included in the report.  However it seems more likely that the new connection to
the OHCI controller just got lost.  That would explain why the mouse didn't
start working again.

BTW, all those -110 errors are normal and expected.  hid-core retries a failed
interrupt URB up to ten times (about 1 second total) before resetting the
device.  Maybe that limit should be reduced...
Comment 18 Jure Repinc 2006-09-10 13:04:36 UTC
I've just compiled version 2.6.18-rc6-mm1 and it looks like all is fine now. So 
I guess I can mark this bug as fixed now.