Bug 4495

Summary: 2.6.12-rc6: Unplugging/replugging USB Logitech headset when in use busts USB, kills keyboard
Product: Drivers Reporter: Waldo (vvaldo)
Component: Sound(ALSA)Assignee: Jaroslav Kysela (perex)
Status: CLOSED CODE_FIX    
Severity: high CC: greg
Priority: P2    
Hardware: i386   
OS: Linux   
Kernel Version: 2.6.12-rc2 Subsystem:
Regression: --- Bisected commit-id:

Description Waldo 2005-04-14 12:53:55 UTC
Distribution: Gentoo (stable)
Hardware Environment: amd64 3500+ w/1 gig RAM.  USB Logitech headset.  PS/2 keyboard, USB 
5-button Intellimouse.  NForce 3 chipset.  Box is a Shuttle, model SN95G5.
Software Environment:  GNOME 2.10 (although it crashed w/2.8 too), Skype (to demonstrate the 
problem).  Kernel is 2.6.12-rc2.
 
Problem Description:  Hotplugging my USB Logitech headset works fine...unless I'm actually using it, at 
which point re-plugging does nothing to restore the device.  Also, when replugging it, my ps/2 
keyboard locks up and accepts no input.   Finally, when I attempt to reboot or shutdown following this, 
the shutdown sequence does not proceed past clearing the screen.  Rather, it hangs just after GNOME 
and gdm quit.

Steps to reproduce:  (All debug messages below are from dmesg)

1.  Upon startup, the logitech device is recognized.  (This is a bit of the startup sequence messages in 
dmesg):

usb 2-1.1: new full speed USB device using ohci_hcd and address 3
usb 2-1.1: ep0 maxpacket = 8
usb 2-1.1: skipped 11 descriptors after interface
usb 2-1.1: skipped 2 descriptors after interface
usb 2-1.1: skipped 1 descriptor after endpoint
usb 2-1.1: skipped 2 descriptors after interface
usb 2-1.1: skipped 1 descriptor after endpoint
usb 2-1.1: skipped 2 descriptors after interface
usb 2-1.1: skipped 1 descriptor after endpoint
usb 2-1.1: default language 0x0409
usb 2-1.1: new device strings: Mfr=1, Product=2, SerialNumber=0
usb 2-1.1: Product: Logitech USB Headset
usb 2-1.1: Manufacturer: Logitech
usb 2-1.1: hotplug
usb 2-1.1: adding 2-1.1:1.0 (config #1, interface 0)
usb 2-1.1:1.0: hotplug
usb 2-1.1: adding 2-1.1:1.1 (config #1, interface 1)
usb 2-1.1:1.1: hotplug
usb 2-1.1: adding 2-1.1:1.2 (config #1, interface 2)
usb 2-1.1:1.2: hotplug                                                  

2.  I'll demonstrate that USB unplug/replug works normally when the USB Logitech headset is not 
actively being used:

hub 2-1:1.0: state 5 ports 4 chg 0000 evt 0002
hub 2-1:1.0: port 1, status 0100, change 0001, 12 Mb/s
usb 2-1.1: USB disconnect, address 3
usb 2-1.1: usb_disable_device nuking all URBs
usb 2-1.1: unregistering interface 2-1.1:1.0
usb 2-1.1:1.0: hotplug
usb 2-1.1: unregistering interface 2-1.1:1.1
usb 2-1.1:1.1: hotplug
usb 2-1.1: unregistering interface 2-1.1:1.2
usb 2-1.1:1.2: hotplug
usb 2-1.1: unregistering device
usb 2-1.1: hotplug
hub 2-1:1.0: debounce: port 1: total 100ms stable 100ms status 0x100
hub 2-1:1.0: state 5 ports 4 chg 0000 evt 0002
hub 2-1:1.0: port 1, status 0101, change 0001, 12 Mb/s
hub 2-1:1.0: debounce: port 1: total 100ms stable 100ms status 0x101
usb 2-1.1: new full speed USB device using ohci_hcd and address 6
usb 2-1.1: ep0 maxpacket = 8
usb 2-1.1: skipped 11 descriptors after interface
usb 2-1.1: skipped 2 descriptors after interface
usb 2-1.1: skipped 1 descriptor after endpoint
usb 2-1.1: skipped 2 descriptors after interface
usb 2-1.1: skipped 1 descriptor after endpoint
usb 2-1.1: skipped 2 descriptors after interface
usb 2-1.1: skipped 1 descriptor after endpoint
usb 2-1.1: default language 0x0409
usb 2-1.1: new device strings: Mfr=1, Product=2, SerialNumber=0
usb 2-1.1: Product: Logitech USB Headset
usb 2-1.1: Manufacturer: Logitech
usb 2-1.1: hotplug
usb 2-1.1: adding 2-1.1:1.0 (config #1, interface 0)
usb 2-1.1:1.0: hotplug
snd-usb-audio 2-1.1:1.0: usb_probe_interface
snd-usb-audio 2-1.1:1.0: usb_probe_interface - got id
usb 2-1.1: adding 2-1.1:1.1 (config #1, interface 1)
usb 2-1.1:1.1: hotplug
usb 2-1.1: adding 2-1.1:1.2 (config #1, interface 2)
usb 2-1.1:1.2: hotplug
hub 2-1:1.0: 198mA power budget left
hub 2-1:1.0: state 5 ports 4 chg 0000 evt 0002    

3.  Now i'll unplug while talking to someone on Skype:

hub 2-1:1.0: state 5 ports 4 chg 0000 evt 0002
hub 2-1:1.0: port 1, status 0100, change 0001, 12 Mb/s
usb 2-1.1: USB disconnect, address 6
usb 2-1.1: usb_disable_device nuking all URBs
ohci_hcd 0000:00:02.0: shutdown urb ffff81002ed08900 pipe 00008600 ep1out-iso
ohci_hcd 0000:00:02.0: shutdown urb ffff81002ed08a80 pipe 00008600 ep1out-iso
usb 2-1.1: unregistering interface 2-1.1:1.0
usb 2-1.1:1.0: hotplug
usb 2-1.1: unregistering interface 2-1.1:1.1
usb 2-1.1:1.1: hotplug
usb 2-1.1: unregistering interface 2-1.1:1.2
usb 2-1.1:1.2: hotplug
usb 2-1.1: unregistering device
usb 2-1.1: hotplug
hub 2-1:1.0: debounce: port 1: total 100ms stable 100ms status 0x100 

4.  Now I'll replug it.  Note that this is where I lose the keyboard.

hub 2-1:1.0: state 5 ports 4 chg 0000 evt 0002
hub 2-1:1.0: port 1, status 0101, change 0001, 12 Mb/s
hub 2-1:1.0: debounce: port 1: total 100ms stable 100ms status 0x101
usb 2-1.1: new full speed USB device using ohci_hcd and address 7
usb 2-1.1: ep0 maxpacket = 8
usb 2-1.1: skipped 11 descriptors after interface
usb 2-1.1: skipped 2 descriptors after interface
usb 2-1.1: skipped 1 descriptor after endpoint
usb 2-1.1: skipped 2 descriptors after interface
usb 2-1.1: skipped 1 descriptor after endpoint
usb 2-1.1: skipped 2 descriptors after interface
usb 2-1.1: skipped 1 descriptor after endpoint
usb 2-1.1: default language 0x0409
usb 2-1.1: new device strings: Mfr=1, Product=2, SerialNumber=0
usb 2-1.1: Product: Logitech USB Headset
usb 2-1.1: Manufacturer: Logitech
usb 2-1.1: hotplug
usb 2-1.1: adding 2-1.1:1.0 (config #1, interface 0)
usb 2-1.1:1.0: hotplug
snd-usb-audio 2-1.1:1.0: usb_probe_interface
snd-usb-audio 2-1.1:1.0: usb_probe_interface - got id
cannot find the slot for index 1 (range 0-1)
cannot create card instance 0
snd-usb-audio: probe of 2-1.1:1.0 failed with error -5
usb 2-1.1: adding 2-1.1:1.1 (config #1, interface 1)
usb 2-1.1:1.1: hotplug
usb 2-1.1: adding 2-1.1:1.2 (config #1, interface 2)
usb 2-1.1:1.2: hotplug
hub 2-1:1.0: 198mA power budget left
hub 2-1:1.0: state 5 ports 4 chg 0000 evt 0002 

5.  Since I cannot type any more, I have no choice but to shutdown.   GNOME quits fine.  So does gdm.  
Then the screen blanks and I get a non-flashing cursor in the top left of the screen, and a total lockup.  
Here's what dmesg has to say about it:

Unable to handle kernel NULL pointer dereference at 0000000000000000 RIP: 
<ffffffff8023ba80>{strlen+0}
PGD 3ee97067 PUD 3ee8f067 PMD 0 
Oops: 0000 [1] PREEMPT 
CPU 0 
Modules linked in: it87 i2c_sensor i2c_isa i2c_nforce2 i2c_core sk98lin snd_usb_audio snd_usb_lib 
snd_rawmidi snd_intel8x0 snd_ac97_codec nvidia video loop
Pid: 3, comm: events/0 Tainted: P      2.6.12-rc2
RIP: 0010:[<ffffffff8023ba80>] <ffffffff8023ba80>{strlen+0}
RSP: 0018:ffff81000214bbc0  EFLAGS: 00010282
RAX: 0000000000000058 RBX: ffff8100022560e0 RCX: 000000000000001a
RDX: ffff8100022509f0 RSI: 00000000000000d0 RDI: 0000000000000000
RBP: 0000000000000001 R08: ffff810002256058 R09: 00000000000003a8
R10: ffffffff802a0da0 R11: ffffffff80325e00 R12: ffff8100022509f0
R13: 00000000000000d0 R14: ffff8100022560e0 R15: 000000000000001a
FS:  00002aaaaade7ae0(0000) GS:ffffffff80557f00(0000) knlGS:00000000560e2b30
CS:  0010 DS: 0018 ES: 0018 CR0: 000000008005003b
CR2: 0000000000000000 CR3: 000000003eea5000 CR4: 00000000000006e0
Process events/0 (pid: 3, threadinfo ffff81000214a000, task ffff81003ffb06d0)
Stack: ffffffff80238dbe ffffffff804bc620 ffff810002256098 ffff8100022509f0 
       00000000000003a8 ffff810002256058 ffffffff802a0e0a 0000000000000286 
       0000000000000003 000000000226ac00 
Call Trace:<ffffffff80238dbe>{kobject_get_path+30} <ffffffff802a0e0a>{class_hotplug+106} 
       <ffffffff80239bc2>{kobject_hotplug+498} <ffffffff802391de>{kobject_del+14} 
       <ffffffff802a1360>{class_device_del+256} <ffffffff802a1389>{class_device_unregister+9} 
       <ffffffff80359039>{snd_unregister_device+185} 
<ffffffff80363bc3>{snd_pcm_dev_unregister+115} 
       <ffffffff803599f0>{snd_card_free_thread+0} <ffffffff8035e5ba>{snd_device_free+90} 
       <ffffffff8035e81b>{snd_device_free_all+75} <ffffffff803598ed>{snd_card_free+349} 
       <ffffffff801458f0>{autoremove_wake_function+0} 
<ffffffff801458f0>{autoremove_wake_function+0} 
       <ffffffff80359a80>{snd_card_free_thread+144} <ffffffff8014099d>{worker_thread+541} 
       <ffffffff8012b080>{default_wake_function+0} <ffffffff8012b080>{default_wake_function+0} 
       <ffffffff80140780>{worker_thread+0} <ffffffff801452ad>{kthread+205} 
       <ffffffff8010e357>{child_rip+8} <ffffffff80236450>{dummy_d_instantiate+0} 
       <ffffffff801451e0>{kthread+0} <ffffffff8010e34f>{child_rip+0} 
       

Code: 80 3f 00 48 89 f8 74 08 48 ff c0 80 38 00 eb f6 48 29 f8 c3 
RIP <ffffffff8023ba80>{strlen+0} RSP <ffff81000214bbc0>
CR2: 0000000000000000    

At this point, all I can do is reset the machine.  This error is reproducible every time.

Hope this is useful.

W
Comment 1 Waldo 2005-05-07 13:22:06 UTC
solution is here:

http://cvs.sourceforge.net/viewcvs.py/alsa/alsa-kernel/usb/usbaudio.c?r1=1.119&r2=1.120
http://cvs.sourceforge.net/viewcvs.py/alsa/alsa-kernel/usb/usx2y/usbusx2y.c?r1=1.9&r2=1.10

These patches to 2.6.12-rc4 eliminated the crash. Thanks to Daniel Drake for
finding this.

Hope this makes it to the official kernel soon.

W
Comment 2 Daniel Drake 2005-05-19 04:45:49 UTC
This can be closed as CODE_FIX/CLOSED since the fix is included in Linus' tree.
Comment 3 Waldo 2005-06-06 20:56:00 UTC
These fixes were reported in 2.6.12-rc2 and have not yet shown up in the
official 2.6.12-rc6.  Will they be included anytime soon?  Sorry, I'm not sure
how this works exactly, but it would be nice for everyone w/this bug to not have
to patch manually w/every new release.

W
Comment 4 Greg Kroah-Hartman 2005-06-06 21:36:01 UTC
Hm, that's up to the ALSA developers.  reopening and assigning to them...
Comment 5 Waldo 2005-06-14 10:59:48 UTC
updating description-- bug persists into 2.6.12-rc6
Comment 6 Greg Kroah-Hartman 2005-06-14 11:27:57 UTC
Patches have been sent to Linus for this, hopefully will make it in before
2.6.12 is out.
Comment 7 Waldo 2005-06-18 18:13:06 UTC
I'm gonna close this, as it's finally fixed in 2.6.12.  Thanks Greg, Daniel,
Linus, and everyone else who helped w/this!

W