31-rc3-mmotm0716 - dead USB trackball mouse kills entire system

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



(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


[Index of Archives]     [Linux Media]     [Linux Input]     [Linux Audio Users]     [Yosemite News]     [Linux Kernel]     [Linux SCSI]     [Old Linux USB Devel Archive]

  Powered by Linux