(Throwing at everybody in MAINTAINERS that might know something...) OK. To start off - I *know* it's a trackball that is on its last legs. However, (a) it's my favorite mouse design *ever* and (b) it's out of production, so I'm trying to delay as long as possible replacing it. Especially when the entire problem is that the USB cord has one broken/loose conductor, which means that four or five times a day I have to wiggle the cord a 1/16" to wake it back up, and I get this sort of spewage in my console logs if running a -mmotm0702 or earlier kernel: [ 305.300116] usb 1-8.3: USB disconnect, address 6 [ 305.480251] usb 1-8.3: new low speed USB device using ehci_hcd and address 7 [ 305.559595] SELinux: Context staff_u:object_r:gconf_home_t:s0 is not valid (left unmapped). [ 305.570989] usb 1-8.3: New USB device found, idVendor=045e, idProduct=0023 [ 305.570999] usb 1-8.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ 305.571043] usb 1-8.3: Product: Microsoft Trackball Optical® [ 305.571050] usb 1-8.3: Manufacturer: Microsoft [ 305.571367] usb 1-8.3: configuration #1 chosen from 1 choice [ 305.580597] input: Microsoft Microsoft Trackball Optical® as /devices/pci0000:00/0000:00:1d.7/usb1/1-8/1-8.3/1-8.3:1.0/input/input9 [ 305.580845] generic-usb 0003:045E:0023.0002: input,hidraw0: USB HID v1.00 Mouse [Microsoft Microsoft Trackball Optical®] on usb-0000:00:1d.7-8.3/input0 [ 308.116101] usb 1-8.3: USB disconnect, address 7 [ 308.291271] usb 1-8.3: new low speed USB device using ehci_hcd and address 8 [ 308.381867] usb 1-8.3: New USB device found, idVendor=045e, idProduct=0023 [ 308.381876] usb 1-8.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ 308.381883] usb 1-8.3: Product: Microsoft Trackball Optical® [ 308.381889] usb 1-8.3: Manufacturer: Microsoft [ 308.382181] usb 1-8.3: configuration #1 chosen from 1 choice [ 308.389974] input: Microsoft Microsoft Trackball Optical® as /devices/pci0000:00/0000:00:1d.7/usb1/1-8/1-8.3/1-8.3:1.0/input/input10 [ 308.390266] generic-usb 0003:045E:0023.0003: input,hidraw0: USB HID v1.00 Mouse [Microsoft Microsoft Trackball Optical®] on usb-0000:00:1d.7-8.3/input0 Pretty much what you'd *expect* to see if a device keeps dropping in and out... Well... Usually. Today, on a -mmotm0716 kernel, the loose conductor struck again, and no amount of wiggling would resurrect it as far as the system was concerned. Note however that it *did* wake up just fine when I finally rebooted the machine, even though I had not touched the mouse any further - which says to me that the wires were making a connection again, but the kernel wasn't picking up on it. Meanwhile, in my kernel logs, I had: [ 571.965568] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71 [ 571.965661] usb 1-8: clear tt 3 (0060) error -32 [ 571.981570] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71 [ 571.981668] usb 1-8: clear tt 3 (0060) error -32 [ 571.997698] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71 [ 571.997782] usb 1-8: clear tt 3 (0060) error -32 [ 572.013568] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71 [ 572.013656] usb 1-8: clear tt 3 (0060) error -32 [ 572.029694] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71 [ 572.029783] usb 1-8: clear tt 3 (0060) error -32 [ 572.045696] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71 [ 572.045781] usb 1-8: clear tt 3 (0060) error -32 [ 572.061567] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71 [ 572.061655] usb 1-8: clear tt 3 (0060) error -32 [ 572.077698] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71 [ 572.077782] usb 1-8: clear tt 3 (0060) error -32 [ 572.088910] usb 1-8.3: USB disconnect, address 6 [ 572.267417] usb 1-8.3: new low speed USB device using ehci_hcd and address 7 [ 572.357781] usb 1-8.3: New USB device found, idVendor=045e, idProduct=0023 [ 572.357789] usb 1-8.3: New USB device strings: Mfr=1, Product=2, SerialNumber=0 [ 572.357796] usb 1-8.3: Product: Microsoft Trackball Optical® [ 572.357802] usb 1-8.3: Manufacturer: Microsoft [ 572.358075] usb 1-8.3: configuration #1 chosen from 1 choice [ 572.365574] input: Microsoft Microsoft Trackball Optical® as /devices/pci0000:00/0000:00:1d.7/usb1/1-8/1-8.3/1-8.3:1.0/input/input9 [ 572.365829] generic-usb 0003:045E:0023.0002: input,hidraw0: USB HID v1.00 Mouse [Microsoft Microsoft Trackball Optical®] on usb-0000:00:1d.7-8.3/input0 The "can't reset device" is apparently new with mm-0716 - I've not seen it before in at least the 6 weeks my logs go back. And it seems to be the beginning of things going pear-shaped, even though it manages to reset the device. A few seconds, the events thread whinges that not all is fine in USB land: [ 588.903158] usb 1-8.3: reset low speed USB device using ehci_hcd and address 7 [ 593.903075] ------------[ cut here ]------------ [ 593.903091] WARNING: at drivers/usb/host/ehci-hcd.c:906 ehci_urb_dequeue+0xa9/0x145() [ 593.903098] Hardware name: Latitude D820 [ 593.903102] Modules linked in: ext4 jbd2 crc16 nvidia(P) [last unloaded: microcode] [ 593.903127] Pid: 10, comm: events/0 Tainted: P 2.6.31-rc3-mmotm0716 #5 [ 593.903133] Call Trace: [ 593.903147] [<ffffffff8103f459>] warn_slowpath_common+0x77/0x8f [ 593.903156] [<ffffffff8103f480>] warn_slowpath_null+0xf/0x11 [ 593.903165] [<ffffffff812d66cb>] ehci_urb_dequeue+0xa9/0x145 [ 593.903176] [<ffffffff812c20f6>] unlink1+0xcd/0xe0 [ 593.903185] [<ffffffff812c2279>] usb_hcd_unlink_urb+0x60/0x84 [ 593.903194] [<ffffffff812c34d0>] usb_kill_urb+0x4f/0xc7 [ 593.903204] [<ffffffff812c4ae4>] usb_start_wait_urb+0x9e/0xde [ 593.903214] [<ffffffff812c3b1d>] ? usb_init_urb+0x22/0x33 [ 593.903224] [<ffffffff812c4dd1>] usb_control_msg+0x172/0x196 [ 593.903233] [<ffffffff812be39b>] hub_port_init+0x348/0x71e [ 593.903244] [<ffffffff812be80e>] usb_reset_and_verify_device+0x9d/0x3f0 [ 593.903253] [<ffffffff812c34a0>] ? usb_kill_urb+0x1f/0xc7 [ 593.903263] [<ffffffff81034cb0>] ? get_parent_ip+0x11/0x42 [ 593.903273] [<ffffffff81327812>] ? hid_cease_io+0x36/0x3b [ 593.903282] [<ffffffff812bebfa>] usb_reset_device+0x99/0x11c [ 593.903291] [<ffffffff8132808f>] ? hid_reset+0x0/0x128 [ 593.903299] [<ffffffff8132812a>] hid_reset+0x9b/0x128 [ 593.903309] [<ffffffff81051a48>] worker_thread+0x2ba/0x3e9 [ 593.903317] [<ffffffff810519ef>] ? worker_thread+0x261/0x3e9 [ 593.903328] [<ffffffff81056841>] ? autoremove_wake_function+0x0/0x34 [ 593.903337] [<ffffffff8105178e>] ? worker_thread+0x0/0x3e9 [ 593.903346] [<ffffffff81056433>] kthread+0x85/0x8d [ 593.903357] [<ffffffff8100c41a>] child_rip+0xa/0x20 [ 593.903367] [<ffffffff8100bd80>] ? restore_args+0x0/0x30 [ 593.903377] [<ffffffff810563ae>] ? kthread+0x0/0x8d [ 593.903385] [<ffffffff8100c410>] ? child_rip+0x0/0x20 [ 593.903391] ---[ end trace 816b51bf46b6656d ]--- And 2 minutes later, things are *still* not fine, and other things are hanging as well. Since the 'events' thread is hung, both my mouse and keyboard are dead (though alt-sysrq kept working, since it does its magic behind 'events' back). [ 720.548076] INFO: task events/0:10 blocked for more than 120 seconds. [ 720.548083] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 720.548090] events/0 D 0000000000000000 4640 10 2 0x00000000 [ 720.548104] ffff88007f8d7ae0 0000000000000046 ffff88007f8d7a80 0000000000000046 [ 720.548119] 0000000000000000 ffffffff81056a51 0000000000000000 ffffffff8174c658 [ 720.548133] ffff88007f8d7a70 ffff88007f8d4660 000000000000df88 ffff88007f8d4660 [ 720.548147] Call Trace: [ 720.548166] [<ffffffff81056a51>] ? prepare_to_wait+0x1c/0x5c [ 720.548178] [<ffffffff814a2819>] ? _spin_unlock_irqrestore+0x72/0x80 [ 720.548190] [<ffffffff812c352a>] usb_kill_urb+0xa9/0xc7 [ 720.548199] [<ffffffff81056841>] ? autoremove_wake_function+0x0/0x34 [ 720.548209] [<ffffffff812c4ae4>] usb_start_wait_urb+0x9e/0xde [ 720.548219] [<ffffffff812c3b1d>] ? usb_init_urb+0x22/0x33 [ 720.548229] [<ffffffff812c4dd1>] usb_control_msg+0x172/0x196 [ 720.548239] [<ffffffff812be39b>] hub_port_init+0x348/0x71e [ 720.548250] [<ffffffff812be80e>] usb_reset_and_verify_device+0x9d/0x3f0 [ 720.548282] [<ffffffff812c34a0>] ? usb_kill_urb+0x1f/0xc7 [ 720.548295] [<ffffffff81034cb0>] ? get_parent_ip+0x11/0x42 [ 720.548308] [<ffffffff81327812>] ? hid_cease_io+0x36/0x3b [ 720.548317] [<ffffffff812bebfa>] usb_reset_device+0x99/0x11c [ 720.548326] [<ffffffff8132808f>] ? hid_reset+0x0/0x128 [ 720.548334] [<ffffffff8132812a>] hid_reset+0x9b/0x128 [ 720.548344] [<ffffffff81051a48>] worker_thread+0x2ba/0x3e9 [ 720.548352] [<ffffffff810519ef>] ? worker_thread+0x261/0x3e9 [ 720.548362] [<ffffffff81056841>] ? autoremove_wake_function+0x0/0x34 [ 720.548371] [<ffffffff8105178e>] ? worker_thread+0x0/0x3e9 [ 720.548380] [<ffffffff81056433>] kthread+0x85/0x8d [ 720.548391] [<ffffffff8100c41a>] child_rip+0xa/0x20 [ 720.548402] [<ffffffff8100bd80>] ? restore_args+0x0/0x30 [ 720.548411] [<ffffffff810563ae>] ? kthread+0x0/0x8d [ 720.548419] [<ffffffff8100c410>] ? child_rip+0x0/0x20 [ 720.548424] INFO: lockdep is turned off. [ 720.548455] INFO: task pcscd:2022 blocked for more than 120 seconds. [ 720.548461] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. [ 720.548466] pcscd D 0000000000000000 5640 2022 1 0x00020080 [ 720.548480] ffff880075287ae8 0000000000000046 0000000000000000 ffff880002139e58 [ 720.548494] 0000000000000003 0000000000000002 ffff880075287fd8 ffff880075286000 [ 720.548508] ffff880075287a78 ffff880073e588e0 000000000000df88 ffff880073e588e0 [ 720.548522] Call Trace: [ 720.548533] [<ffffffff81065fd6>] ? trace_hardirqs_on_caller+0x1f/0x145 [ 720.548545] [<ffffffff814a0718>] schedule_timeout+0x22/0xc5 [ 720.548555] [<ffffffff81171412>] ? avc_has_perm_noaudit+0x51d/0x546 [ 720.548565] [<ffffffff81065fd6>] ? trace_hardirqs_on_caller+0x1f/0x145 [ 720.548574] [<ffffffff814a2889>] ? _spin_unlock_irq+0x62/0x6f [ 720.548583] [<ffffffff814a1746>] __down_common+0xa7/0xe9 [ 720.548593] [<ffffffff814a17e7>] __down+0x18/0x1a [ 720.548601] [<ffffffff8105ab38>] down+0x49/0x5d [ 720.548611] [<ffffffff812cc5a1>] usbdev_ioctl+0x4e/0x14b0 [ 720.548620] [<ffffffff81171412>] ? avc_has_perm_noaudit+0x51d/0x546 [ 720.548630] [<ffffffff81171492>] ? avc_has_perm+0x57/0x69 [ 720.548638] [<ffffffff814a2c90>] ? unlock_kernel+0x98/0xa5 [ 720.548648] [<ffffffff81172209>] ? inode_has_perm+0x85/0x92 [ 720.548659] [<ffffffff810dd4c2>] vfs_ioctl+0x6a/0x82 [ 720.548668] [<ffffffff810dda01>] do_vfs_ioctl+0x4b0/0x4f6 [ 720.548678] [<ffffffff810dda9e>] sys_ioctl+0x57/0x95 [ 720.548688] [<ffffffff8110a817>] do_ioctl32_pointer+0xb/0xd [ 720.548697] [<ffffffff8110cd13>] compat_sys_ioctl+0x437/0x4a8 [ 720.548705] [<ffffffff810d8905>] ? path_put+0x1d/0x21 [ 720.548714] [<ffffffff81065374>] ? trace_hardirqs_off_caller+0x1f/0xa2 [ 720.548724] [<ffffffff8107d83f>] ? audit_syscall_entry+0xcb/0x19c [ 720.548736] [<ffffffff8102b5f8>] sysenter_dispatch+0x7/0x2c [ 720.548745] [<ffffffff814a1f32>] ? trace_hardirqs_on_thunk+0x3a/0x3f [ 720.548751] INFO: lockdep is turned off. >From there, things went downhill fast (I tried to ssh in, but *that* got hung up as well), and I ended up rebooting.
Attachment:
pgpFKvj4Kz1Zg.pgp
Description: PGP signature
