2009-07-23 16:07:28

by Valdis Klētnieks

[permalink] [raw]
Subject: 31-rc3-mmotm0716 - dead USB trackball mouse kills entire system

(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.


Attachments:
(No filename) (226.00 B)

2009-07-23 18:20:02

by Alan Stern

[permalink] [raw]
Subject: Re: 31-rc3-mmotm0716 - dead USB trackball mouse kills entire system

On Thu, 23 Jul 2009 [email protected] wrote:

> 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.

I don't think it is new. You might try using an older kernel with your
decaying trackball to see.

> And it seems to be the
> beginning of things going pear-shaped, even though it manages to reset the
> device.

No it doesn't. The device gets disconnected and reconnected.

> 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 ]---

This is a bug. For more discussion see this thread:

http://marc.info/?t=124807676700001&r=1&w=2

You should try the patch given there.

> 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).

Try the patch and see if it fixes the hang.

Alan Stern

2009-07-23 20:23:33

by Valdis Klētnieks

[permalink] [raw]
Subject: Re: 31-rc3-mmotm0716 - dead USB trackball mouse kills entire system

On Thu, 23 Jul 2009 14:19:59 EDT, Alan Stern said:

> > 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.
>
> I don't think it is new. You might try using an older kernel with your
> decaying trackball to see.

Umm.. I've *been* using it with older kernels for *months*. Not a *single*
hit in my logs, which go back till June 10. Except for today, when I started
running -0716, and now I've gotten hit by the same messages, and then
the same hang 4 times today.

So either the codepath in -0716 is different from -0702 and -0604 and -0517 and
every other -mm before, or the trackball spontaneously developed a *different*
behavior overnight at the same time I upgraded the kernel.

See the logs below...

> This is a bug. For more discussion see this thread:
>
> http://marc.info/?t=124807676700001&r=1&w=2
>
> You should try the patch given there.

OK, will do that, see if it improves things...

The logs back to June 10 (and I was on vacation Jun 20-26):

% egrep -h 'USB disc|reset device' mess* | grep -e '-8.3'
Jun 10 12:05:22 turing-police kernel: [93125.340042] usb 1-8.3: USB disconnect, address 7
Jun 11 16:26:48 turing-police kernel: [195210.844332] usb 1-8.3: USB disconnect, address 8
Jun 11 16:56:12 turing-police kernel: [196975.450198] usb 1-8.3: USB disconnect, address 9
Jun 12 12:20:58 turing-police kernel: [266860.805915] usb 1-8.3: USB disconnect, address 10
Jun 12 12:20:58 turing-police kernel: [266861.317793] usb 1-8.3: USB disconnect, address 11
Jun 12 12:21:00 turing-police kernel: [266862.853911] usb 1-8.3: USB disconnect, address 13
Jun 13 00:04:40 turing-police kernel: [309083.085168] usb 1-8.3: USB disconnect, address 15
Jun 13 00:19:00 turing-police kernel: [309943.499877] usb 1-8.3: USB disconnect, address 16
Jun 13 21:00:08 turing-police kernel: [384411.506588] usb 1-8.3: USB disconnect, address 17
Jun 14 02:39:04 turing-police kernel: [404747.349968] usb 1-8.3: USB disconnect, address 18
Jun 15 11:34:12 turing-police kernel: [ 130.073577] usb 1-8.3: USB disconnect, address 7
Jun 16 11:28:07 turing-police kernel: [ 7224.839479] usb 1-8.3: USB disconnect, address 7
Jun 16 11:33:36 turing-police kernel: [ 7553.542989] usb 1-8.3: USB disconnect, address 8
Jun 16 12:44:40 turing-police kernel: [11817.473391] usb 1-8.3: USB disconnect, address 9
Jun 16 14:07:39 turing-police kernel: [16796.411826] usb 1-8.3: USB disconnect, address 10
Jun 16 14:36:44 turing-police kernel: [18541.305681] usb 1-8.3: USB disconnect, address 11
Jun 16 15:11:47 turing-police kernel: [20644.855582] usb 1-8.3: USB disconnect, address 12
Jun 16 16:23:58 turing-police kernel: [24975.602702] usb 1-8.3: USB disconnect, address 14
Jun 17 14:48:21 turing-police kernel: [12850.443754] usb 1-8.3: USB disconnect, address 6
Jun 18 15:11:55 turing-police kernel: [15216.375804] usb 1-8.3: USB disconnect, address 5
Jun 18 16:20:42 turing-police kernel: [19342.578643] usb 1-8.3: USB disconnect, address 6
Jun 18 16:25:16 turing-police kernel: [19616.498551] usb 1-8.3: USB disconnect, address 7
Jun 19 10:18:42 turing-police kernel: [ 435.712336] usb 1-8.3: USB disconnect, address 6
Jun 26 21:25:42 turing-police kernel: [ 1023.223891] usb 1-8.3: USB disconnect, address 6
Jun 26 22:12:18 turing-police kernel: [ 3818.996721] usb 1-8.3: USB disconnect, address 7
Jun 27 01:04:11 turing-police kernel: [14131.683456] usb 1-8.3: USB disconnect, address 8
Jun 27 09:25:54 turing-police kernel: [44234.915415] usb 1-8.3: USB disconnect, address 10
Jun 27 11:28:31 turing-police kernel: [51591.295831] usb 1-8.3: USB disconnect, address 11
Jun 29 15:05:58 turing-police kernel: [19491.827368] usb 1-8.3: USB disconnect, address 6
Jun 29 15:05:59 turing-police kernel: [19492.851261] usb 1-8.3: USB disconnect, address 7
Jun 29 15:42:29 turing-police kernel: [21683.439937] usb 1-8.3: USB disconnect, address 8
Jun 29 15:48:50 turing-police kernel: [22064.111496] usb 1-8.3: USB disconnect, address 9
Jun 29 16:23:31 turing-police kernel: [24145.644821] usb 1-8.3: USB disconnect, address 10
Jun 29 16:59:37 turing-police kernel: [26311.402052] usb 1-8.3: USB disconnect, address 11
Jun 29 18:18:01 turing-police kernel: [31015.595575] usb 1-8.3: USB disconnect, address 12
Jun 29 19:10:49 turing-police kernel: [34183.724930] usb 1-8.3: USB disconnect, address 15
Jun 29 21:51:55 turing-police kernel: [43848.890868] usb 1-8.3: USB disconnect, address 20
Jun 29 22:10:23 turing-police kernel: [44957.650230] usb 1-8.3: USB disconnect, address 29
Jun 30 11:55:54 turing-police kernel: [ 4831.052171] usb 1-8.3: USB disconnect, address 6
Jun 30 15:10:30 turing-police kernel: [16507.465867] usb 1-8.3: USB disconnect, address 7
Jul 2 13:11:54 turing-police kernel: [ 7093.765139] usb 1-8.3: USB disconnect, address 5
Jul 2 13:24:23 turing-police kernel: [ 7843.076442] usb 1-8.3: USB disconnect, address 6
Jul 2 14:03:02 turing-police kernel: [10161.665586] usb 1-8.3: USB disconnect, address 7
Jul 2 15:51:35 turing-police kernel: [ 5852.438552] usb 1-8.3: USB disconnect, address 5
Jul 2 18:20:12 turing-police kernel: [14769.420729] usb 1-8.3: USB disconnect, address 6
Jul 2 21:39:05 turing-police kernel: [ 1644.983724] usb 1-8.3: USB disconnect, address 6
Jul 2 22:38:32 turing-police kernel: [ 5212.596444] usb 1-8.3: USB disconnect, address 7
Jul 2 22:42:12 turing-police kernel: [ 5431.732078] usb 1-8.3: USB disconnect, address 8
Jul 2 22:43:35 turing-police kernel: [ 5514.931740] usb 1-8.3: USB disconnect, address 9
Jul 2 22:46:46 turing-police kernel: [ 5706.675404] usb 1-8.3: USB disconnect, address 10
Jul 2 22:54:17 turing-police kernel: [ 6157.235123] usb 1-8.3: USB disconnect, address 11
Jul 3 00:40:51 turing-police kernel: [12551.590521] usb 1-8.3: USB disconnect, address 12
Jul 3 04:41:35 turing-police kernel: [26995.348790] usb 1-8.3: USB disconnect, address 13
Jul 3 04:54:14 turing-police kernel: [27754.644344] usb 1-8.3: USB disconnect, address 14
Jul 3 05:37:13 turing-police kernel: [30332.816530] usb 1-8.3: USB disconnect, address 19
Jul 3 06:09:58 turing-police kernel: [ 855.410519] usb 1-8.3: USB disconnect, address 6
Jul 3 11:20:07 turing-police kernel: [19463.514881] usb 1-8.3: USB disconnect, address 7
Jul 3 11:20:31 turing-police kernel: [19488.346840] usb 1-8.3: USB disconnect, address 8
Jul 3 11:40:13 turing-police kernel: [20669.529547] usb 1-8.3: USB disconnect, address 9
Jul 3 12:17:10 turing-police kernel: [22886.486471] usb 1-8.3: USB disconnect, address 10
Jul 3 16:11:42 turing-police kernel: [36958.528807] usb 1-8.3: USB disconnect, address 11
Jul 3 16:13:48 turing-police kernel: [37085.240866] usb 1-8.3: USB disconnect, address 12
Jul 3 17:06:06 turing-police kernel: [40222.779998] usb 1-8.3: USB disconnect, address 13
Jul 3 17:12:54 turing-police kernel: [40631.099400] usb 1-8.3: USB disconnect, address 14
Jul 6 11:43:47 turing-police kernel: [ 3292.581525] usb 1-8.3: USB disconnect, address 7
Jul 6 15:55:33 turing-police kernel: [18398.609861] usb 1-8.3: USB disconnect, address 8
Jul 6 15:55:34 turing-police kernel: [18399.633879] usb 1-8.3: USB disconnect, address 9
Jul 6 16:20:52 turing-police kernel: [19917.199664] usb 1-8.3: USB disconnect, address 16
Jul 6 19:37:06 turing-police kernel: [31691.647785] usb 1-8.3: USB disconnect, address 18
Jul 7 13:15:15 turing-police kernel: [10368.686517] usb 1-8.3: USB disconnect, address 6
Jul 7 13:20:42 turing-police kernel: [10695.597919] usb 1-8.3: USB disconnect, address 7
Jul 7 13:46:18 turing-police kernel: [12232.439811] usb 1-8.3: USB disconnect, address 8
Jul 8 12:22:37 turing-police kernel: [11966.920540] usb 1-8.3: USB disconnect, address 6
Jul 8 12:23:18 turing-police kernel: [12008.648501] usb 1-8.3: USB disconnect, address 7
Jul 8 12:29:33 turing-police kernel: [12383.688085] usb 1-8.3: USB disconnect, address 8
Jul 8 13:01:59 turing-police kernel: [14329.542468] usb 1-8.3: USB disconnect, address 9
Jul 8 14:00:05 turing-police kernel: [17815.233490] usb 1-8.3: USB disconnect, address 10
Jul 8 14:06:47 turing-police kernel: [18217.152988] usb 1-8.3: USB disconnect, address 11
Jul 8 15:01:42 turing-police kernel: [21511.868495] usb 1-8.3: USB disconnect, address 14
Jul 8 15:55:06 turing-police kernel: [24715.820705] usb 1-8.3: USB disconnect, address 15
Jul 8 16:59:17 turing-police kernel: [28567.109854] usb 1-8.3: USB disconnect, address 17
Jul 8 17:27:27 turing-police kernel: [30257.626040] usb 1-8.3: USB disconnect, address 18
Jul 9 11:38:23 turing-police kernel: [ 3296.205121] usb 1-8.3: USB disconnect, address 6
Jul 9 11:38:46 turing-police kernel: [ 3319.757056] usb 1-8.3: USB disconnect, address 7
Jul 9 13:50:46 turing-police kernel: [11239.107773] usb 1-8.3: USB disconnect, address 8
Jul 9 14:48:14 turing-police kernel: [14687.194044] usb 1-8.3: USB disconnect, address 9
Jul 9 15:24:35 turing-police kernel: [16868.796504] usb 1-8.3: USB disconnect, address 11
Jul 9 15:45:28 turing-police kernel: [18120.955889] usb 1-8.3: USB disconnect, address 15
Jul 9 15:45:54 turing-police kernel: [18147.258735] usb 1-8.3: USB disconnect, address 19
Jul 9 17:18:20 turing-police kernel: [23693.746921] usb 1-8.3: USB disconnect, address 20
Jul 9 17:25:27 turing-police kernel: [24120.242364] usb 1-8.3: USB disconnect, address 21
Jul 10 15:31:33 turing-police kernel: [17313.732647] usb 1-8.3: USB disconnect, address 6
Jul 10 16:44:31 turing-police kernel: [21691.327035] usb 1-8.3: USB disconnect, address 7
Jul 10 17:06:21 turing-police kernel: [23001.533485] usb 1-8.3: USB disconnect, address 9
Jul 10 17:28:37 turing-police kernel: [24337.339792] usb 1-8.3: USB disconnect, address 12
Jul 12 02:07:34 turing-police kernel: [16675.255886] usb 1-8.3: USB disconnect, address 5
Jul 12 02:38:31 turing-police kernel: [18532.020360] usb 1-8.3: USB disconnect, address 6
Jul 12 02:41:12 turing-police kernel: [18693.044003] usb 1-8.3: USB disconnect, address 7
Jul 12 02:57:36 turing-police kernel: [19677.106322] usb 1-8.3: USB disconnect, address 8
Jul 12 06:54:00 turing-police kernel: [33860.828804] usb 1-8.3: USB disconnect, address 9
Jul 12 10:02:25 turing-police kernel: [45166.466061] usb 1-8.3: USB disconnect, address 10
Jul 12 13:04:12 turing-police kernel: [56073.128083] usb 1-8.3: USB disconnect, address 14
Jul 12 15:58:29 turing-police kernel: [66530.647876] usb 1-8.3: USB disconnect, address 15
Jul 12 15:58:41 turing-police kernel: [66541.911830] usb 1-8.3: USB disconnect, address 16
Jul 12 16:35:09 turing-police kernel: [68729.940201] usb 1-8.3: USB disconnect, address 20
Jul 12 16:41:56 turing-police kernel: [69137.491817] usb 1-8.3: USB disconnect, address 22
Jul 12 17:21:53 turing-police kernel: [71533.917784] usb 1-8.3: USB disconnect, address 26
Jul 12 17:24:57 turing-police kernel: [71718.677972] usb 1-8.3: USB disconnect, address 32
Jul 13 10:32:00 turing-police kernel: [ 305.107104] usb 1-8.3: USB disconnect, address 6
Jul 13 10:46:02 turing-police kernel: [ 1147.620721] usb 1-8.3: USB disconnect, address 7
Jul 13 12:54:05 turing-police kernel: [ 8830.665678] usb 1-8.3: USB disconnect, address 8
Jul 13 14:17:52 turing-police kernel: [13857.780833] usb 1-8.3: USB disconnect, address 9
Jul 16 11:28:50 turing-police kernel: [ 1481.182088] usb 1-8.3: USB disconnect, address 6
Jul 16 11:36:03 turing-police kernel: [ 1914.203339] usb 1-8.3: USB disconnect, address 8
Jul 16 13:31:34 turing-police kernel: [ 8844.879249] usb 1-8.3: USB disconnect, address 9
Jul 16 13:31:55 turing-police kernel: [ 8866.128241] usb 1-8.3: USB disconnect, address 10
Jul 16 14:17:42 turing-police kernel: [11613.526380] usb 1-8.3: USB disconnect, address 12
Jul 16 14:21:22 turing-police kernel: [11833.175214] usb 1-8.3: USB disconnect, address 13
Jul 16 14:23:42 turing-police kernel: [11972.951501] usb 1-8.3: USB disconnect, address 14
Jul 16 17:40:37 turing-police kernel: [23788.560389] usb 1-8.3: USB disconnect, address 15
Jul 16 18:18:04 turing-police kernel: [26035.469728] usb 1-8.3: USB disconnect, address 16
Jul 16 18:18:56 turing-police kernel: [26087.437651] usb 1-8.3: USB disconnect, address 17
Jul 16 19:12:39 turing-police kernel: [29310.821758] usb 1-8.3: USB disconnect, address 18
Jul 18 22:20:41 turing-police kernel: [ 7676.887799] usb 1-8.3: USB disconnect, address 6
Jul 18 22:22:14 turing-police kernel: [ 7770.071194] usb 1-8.3: USB disconnect, address 10
Jul 18 22:37:00 turing-police kernel: [ 8656.341954] usb 1-8.3: USB disconnect, address 14
Jul 18 22:44:24 turing-police kernel: [ 9100.625554] usb 1-8.3: USB disconnect, address 16
Jul 18 23:22:26 turing-police kernel: [11382.480949] usb 1-8.3: USB disconnect, address 17
Jul 19 00:03:31 turing-police kernel: [13846.907699] usb 1-8.3: USB disconnect, address 18
Jul 19 00:41:49 turing-police kernel: [16145.094099] usb 1-8.3: USB disconnect, address 20
Jul 19 00:42:03 turing-police kernel: [16159.430078] usb 1-8.3: USB disconnect, address 22
Jul 19 02:13:44 turing-police kernel: [21660.092639] usb 1-8.3: USB disconnect, address 23
Jul 19 04:26:04 turing-police kernel: [29600.175535] usb 1-8.3: USB disconnect, address 25
Jul 19 04:44:13 turing-police kernel: [30689.388720] usb 1-8.3: USB disconnect, address 26
Jul 19 05:54:54 turing-police kernel: [34930.068836] usb 1-8.3: USB disconnect, address 27
Jul 19 06:04:20 turing-police kernel: [35496.470907] usb 1-8.3: USB disconnect, address 30
Jul 19 06:24:10 turing-police kernel: [36686.240777] usb 1-8.3: USB disconnect, address 32
Jul 19 06:43:30 turing-police kernel: [37846.332557] usb 1-8.3: USB disconnect, address 34
Jul 19 08:10:54 turing-police kernel: [43090.536690] usb 1-8.3: USB disconnect, address 35
Jul 19 10:12:07 turing-police kernel: [50362.758575] usb 1-8.3: USB disconnect, address 37
Jul 19 10:26:29 turing-police kernel: [51224.705710] usb 1-8.3: USB disconnect, address 42
Jul 19 10:45:52 turing-police kernel: [52387.922763] usb 1-8.3: USB disconnect, address 47
Jul 19 12:29:31 turing-police kernel: [58606.687039] usb 1-8.3: USB disconnect, address 51
Jul 19 15:41:37 turing-police kernel: [ 9546.144532] usb 1-8.3: USB disconnect, address 6
Jul 20 10:27:45 turing-police kernel: [ 337.102606] usb 1-8.3: USB disconnect, address 6
Jul 20 16:00:29 turing-police kernel: [17718.907516] usb 1-8.3: USB disconnect, address 7
Jul 20 18:38:17 turing-police kernel: [27187.565715] usb 1-8.3: USB disconnect, address 8
Jul 20 23:50:39 turing-police kernel: [ 9143.247247] usb 1-8.3: USB disconnect, address 6
Jul 21 00:13:46 turing-police kernel: [ 177.370154] usb 1-8.3: USB disconnect, address 6
Jul 21 00:13:46 turing-police kernel: [ 177.882155] usb 1-8.3: USB disconnect, address 7
Jul 21 00:35:47 turing-police kernel: [ 1498.840131] usb 1-8.3: USB disconnect, address 8
Jul 21 11:29:25 turing-police kernel: [ 4938.192870] usb 1-8.3: USB disconnect, address 6
Jul 21 11:29:40 turing-police kernel: [ 4953.552882] usb 1-8.3: USB disconnect, address 7
Jul 21 14:40:27 turing-police kernel: [16401.091948] usb 1-8.3: USB disconnect, address 8
Jul 21 14:40:50 turing-police kernel: [16423.875944] usb 1-8.3: USB disconnect, address 15
Jul 21 15:23:05 turing-police kernel: [18958.272869] usb 1-8.3: USB disconnect, address 17
Jul 21 16:58:44 turing-police kernel: [24697.784315] usb 1-8.3: USB disconnect, address 22
Jul 21 16:59:13 turing-police kernel: [24726.456264] usb 1-8.3: USB disconnect, address 25
Jul 21 16:59:34 turing-police kernel: [24747.704236] usb 1-8.3: USB disconnect, address 30
Jul 22 14:20:55 turing-police kernel: [ 305.300116] usb 1-8.3: USB disconnect, address 6
Jul 22 14:20:58 turing-police kernel: [ 308.116101] usb 1-8.3: USB disconnect, address 7
Jul 22 15:05:21 turing-police kernel: [ 2971.280561] usb 1-8.3: USB disconnect, address 8
Jul 22 15:11:26 turing-police kernel: [ 3336.335856] usb 1-8.3: USB disconnect, address 9
Jul 22 15:40:31 turing-police kernel: [ 5081.229340] usb 1-8.3: USB disconnect, address 10
Jul 22 16:12:04 turing-police kernel: [ 6973.834721] usb 1-8.3: USB disconnect, address 13
Jul 22 16:12:08 turing-police kernel: [ 6978.186714] usb 1-8.3: USB disconnect, address 16
Jul 23 11:10:29 turing-police kernel: [ 571.965568] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 11:10:29 turing-police kernel: [ 571.981570] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 11:10:29 turing-police kernel: [ 571.997698] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 11:10:29 turing-police kernel: [ 572.013568] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 11:10:29 turing-police kernel: [ 572.029694] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 11:10:29 turing-police kernel: [ 572.045696] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 11:10:29 turing-police kernel: [ 572.061567] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 11:10:29 turing-police kernel: [ 572.077698] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 11:10:29 turing-police kernel: [ 572.088910] usb 1-8.3: USB disconnect, address 6
Jul 23 13:37:45 turing-police kernel: [ 8344.568219] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 13:37:45 turing-police kernel: [ 8344.584389] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 13:37:45 turing-police kernel: [ 8344.600383] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 13:37:45 turing-police kernel: [ 8344.616382] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 13:37:45 turing-police kernel: [ 8344.632382] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 13:37:45 turing-police kernel: [ 8344.648374] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 13:37:45 turing-police kernel: [ 8344.664386] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 13:37:45 turing-police kernel: [ 8344.680360] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 13:37:45 turing-police kernel: [ 8344.683602] usb 1-8.3: USB disconnect, address 6
Jul 23 15:44:33 turing-police kernel: [ 1488.250528] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
Jul 23 15:44:33 turing-police kernel: [ 1488.261742] usb 1-8.3: USB disconnect, address 6


Attachments:
(No filename) (226.00 B)

2009-07-24 14:29:52

by Alan Stern

[permalink] [raw]
Subject: Re: 31-rc3-mmotm0716 - dead USB trackball mouse kills entire system

On Thu, 23 Jul 2009 [email protected] wrote:

> On Thu, 23 Jul 2009 14:19:59 EDT, Alan Stern said:
>
> > > 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.
> >
> > I don't think it is new. You might try using an older kernel with your
> > decaying trackball to see.
>
> Umm.. I've *been* using it with older kernels for *months*. Not a *single*
> hit in my logs, which go back till June 10. Except for today, when I started
> running -0716, and now I've gotten hit by the same messages, and then
> the same hang 4 times today.

I repeat: The code that logs those messages is not new.

> So either the codepath in -0716 is different from -0702 and -0604 and -0517 and
> every other -mm before, or the trackball spontaneously developed a *different*
> behavior overnight at the same time I upgraded the kernel.
>
> See the logs below...

You're talking about messages like this:

> Jul 23 11:10:29 turing-police kernel: [ 571.965568] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71

Those messages are produced by the following statement in
drivers/hid/usbhid/hid-core.c:hid_reset():

err_hid("can't reset device, %s-%s/input%d, status %d",
hid_to_usb_dev(hid)->bus->bus_name,
hid_to_usb_dev(hid)->devpath,
usbhid->ifnum, rc);

I don't know how long that subroutine and in particular that line have
been present, but it has been quite a while. Certainly since 2.6.20.

> > This is a bug. For more discussion see this thread:
> >
> > http://marc.info/?t=124807676700001&r=1&w=2
> >
> > You should try the patch given there.
>
> OK, will do that, see if it improves things...

Let me know what happens.

Alan Stern

2009-07-27 23:59:37

by Valdis Klētnieks

[permalink] [raw]
Subject: Re: 31-rc3-mmotm0716 - dead USB trackball mouse kills entire system

On Fri, 24 Jul 2009 10:29:51 EDT, Alan Stern said:

> You're talking about messages like this:
>
> > Jul 23 11:10:29 turing-police kernel: [ 571.965568] drivers/hid/usbhid/hid-core.c: can't reset device, 0000:00:1d.7-8.3/input0, status -71
>
> Those messages are produced by the following statement in
> drivers/hid/usbhid/hid-core.c:hid_reset():
>
> err_hid("can't reset device, %s-%s/input%d, status %d",
> hid_to_usb_dev(hid)->bus->bus_name,
> hid_to_usb_dev(hid)->devpath,
> usbhid->ifnum, rc);
>
> I don't know how long that subroutine and in particular that line have
> been present, but it has been quite a while. Certainly since 2.6.20.

That code may have been there for a long time, but apparently something
*else* in the USB/HID pile of code changed, that we're now calling hid_reset()
where we didn't used to before, or hid_reset() never reached that err_hid()
call before, or something.

> > > This is a bug. For more discussion see this thread:
> > >
> > > http://marc.info/?t=124807676700001&r=1&w=2
> > >
> > > You should try the patch given there.
> >
> > OK, will do that, see if it improves things...
>
> Let me know what happens.

Confirming - the patch in that thread prevents the system lockup I was
seeing.

So it looks like hid_reset() getting more chatty sometime in the last 2 weeks
was a red herring, and one I can't actually complain about - it was quite
legitimately whinging about not being able to reset a device that was in fact
dead in the water at the time. Given that, and a working patch for ehci-hcd.c,
I'm having a hard time finding the enthusiasm to track down what exactly
changed in hid-core.c. :)

The change in hid-core.c behavior just had the bad luck to land in -mmotm at
the exact same time the bug in ehci-hcd.c landed. So we had two user-visible
behavior changes in the same area of code at the same time. Hilarity ensues. :)

Thanks for pointing me at the actual fix. ;)


Attachments:
(No filename) (226.00 B)

2009-07-28 14:33:48

by Alan Stern

[permalink] [raw]
Subject: Re: 31-rc3-mmotm0716 - dead USB trackball mouse kills entire system

On Mon, 27 Jul 2009 [email protected] wrote:

> Confirming - the patch in that thread prevents the system lockup I was
> seeing.
>
> So it looks like hid_reset() getting more chatty sometime in the last 2 weeks
> was a red herring, and one I can't actually complain about - it was quite
> legitimately whinging about not being able to reset a device that was in fact
> dead in the water at the time. Given that, and a working patch for ehci-hcd.c,
> I'm having a hard time finding the enthusiasm to track down what exactly
> changed in hid-core.c. :)
>
> The change in hid-core.c behavior just had the bad luck to land in -mmotm at
> the exact same time the bug in ehci-hcd.c landed. So we had two user-visible
> behavior changes in the same area of code at the same time. Hilarity ensues. :)
>
> Thanks for pointing me at the actual fix. ;)

A question for you: Do you now observe any warnings in the dmesg log if
you rmmod ehci-hcd after the trackball mouse is gone? Apparently the
patch you tested isn't perfect and some stuff gets leaked. I'm trying
to track down the problem.

Alan Stern

2009-07-28 16:49:22

by Valdis Klētnieks

[permalink] [raw]
Subject: Re: 31-rc3-mmotm0716 - dead USB trackball mouse kills entire system

On Tue, 28 Jul 2009 10:33:46 EDT, Alan Stern said:
> A question for you: Do you now observe any warnings in the dmesg log if
> you rmmod ehci-hcd after the trackball mouse is gone? Apparently the
> patch you tested isn't perfect and some stuff gets leaked. I'm trying
> to track down the problem.

Hmm.. Let me go cook up a test kernel - I have ehci-hcd built-in rather
than a module. Might take a day or two...


Attachments:
(No filename) (226.00 B)