Message-ID: <alpine.LNX.2.00.1009182135000.26813@pobox.suse.cz>
Date:	Sat, 18 Sep 2010 21:36:04 +0200 (CEST)
From:	Jiri Kosina <jkosina@...e.cz>
To:	Mat <jackdachef@...il.com>
Cc:	raa.lkml@...il.com, Arnd Bergmann <arnd@...db.de>,
	linux-usb@...r.kernel.org, linux-input@...r.kernel.org,
	Linux Kernel Mailing List <linux-kernel@...r.kernel.org>,
	Guillaume Chazarain <guichaz@...il.com>
Subject: Re: OOPS in hiddev_open on connecting "Logitech MX620 Laser Cordless
 Mouse"

On Sat, 18 Sep 2010, Mat wrote:

> >> I've been noticing this also since a few days and have the same mouse
> >> model. For me it's getting triggered when hald (which seemingly still
> >> is needed by KDE4) is started:
> >>
> >>    50.778558] BUG: unable to handle kernel NULL pointer dereference at (null)
> >> [   50.779448] IP: [<ffffffff8159c4b3>] hiddev_open+0xa3/0x1b0
> >> [   50.780371] PGD 0
> >> [   50.781480] Oops: 0000 [#1] PREEMPT SMP
> >> [   50.782671] last sysfs file:
> >> /sys/devices/pci0000:00/0000:00:1f.2/host5/target5:0:0/5:0:0:0/block/sdd/size
> >> [   50.783649] CPU 7
> >> [   50.783659] Modules linked in: fglrx(P) firewire_ohci i2c_i801
> >> firewire_core e1000e wmi shpchp tg3 libphy e1000 scsi_wait_scan
> >> sl811_hcd ohci_hcd ssb usb_storage ehci_hcd
> >> [   50.785661]
> >> [   50.786647] Pid: 5576, comm: hald-probe-hidd Tainted: P
> >> 2.6.36-rc4_plus_v2+ #2 FMP55/ipower G3710
> >> [   50.787712] RIP: 0010:[<ffffffff8159c4b3>]  [<ffffffff8159c4b3>]
> >> hiddev_open+0xa3/0x1b0
> >> [   50.788784] RSP: 0018:ffff8801bafe9ca8  EFLAGS: 00010296
> >> [   50.789889] RAX: 0000000000000000 RBX: ffff8801bb155400 RCX: 0000000000000004
> >> [   50.790998] RDX: ffffffff81de4008 RSI: ffffffff81a03638 RDI: ffff8801bb1fc030
> >> [   50.792105] RBP: ffff8801bb1f0000 R08: ffffea00060eec88 R09: 0000000000000000
> >> [   50.793266] R10: 0000000000000004 R11: 0000000000000000 R12: 0000000000000000
> >> [   50.794478] R13: 00000000ffffffed R14: ffffffff818f24e0 R15: ffff8801bfa8abd0
> >> [   50.795639] FS:  00007f17699ba700(0000) GS:ffff8800023c0000(0000)
> >> knlGS:0000000000000000
> >> [   50.796810] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> >> [   50.798021] CR2: 0000000000000000 CR3: 00000001bc3e5000 CR4: 00000000000006e0
> >> [   50.799250] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> >> [   50.800541] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> >> [   50.801786] Process hald-probe-hidd (pid: 5576, threadinfo
> >> ffff8801bafe8000, task ffff8801bc3c5dc0)
> >> [   50.803057] Stack:
> >> [   50.804341]  ffff8801bafe9d24 0000000000000000 ffff8801bb155400
> >> ffffffff818e2b00
> >> [   50.804378] <0> ffff8801bb0fb850 ffffffff814d9a74 ffff8801bb0fb850
> >> ffff8801bb155400
> >> [   50.805709] <0> ffff8801bfdd4900 0000000000000000 ffffffff810daf10
> >> ffffffff810db035
> >> [   50.808363] Call Trace:
> >> [   50.809664]  [<ffffffff814d9a74>] ? usb_open+0xf4/0x1d0
> >> [   50.811008]  [<ffffffff810daf10>] ? chrdev_open+0x0/0x210
> >> [   50.812387]  [<ffffffff810db035>] ? chrdev_open+0x125/0x210
> >> [   50.813721]  [<ffffffff810d5730>] ? __dentry_open.clone.16+0x100/0x320
> >> [   50.815010]  [<ffffffff810e3ed0>] ? do_last.clone.45+0x3f0/0x690
> >> [   50.816367]  [<ffffffff810e4363>] ? do_filp_open+0x1f3/0x5f0
> >> [   50.817662]  [<ffffffff816b90a5>] ? unix_getname+0x65/0xe0
> >> [   50.818947]  [<ffffffff81742609>] ? _raw_spin_unlock+0x9/0x40
> >> [   50.820280]  [<ffffffff810ef5f4>] ? alloc_fd+0xe4/0x140
> >> [   50.821639]  [<ffffffff810d6896>] ? do_sys_open+0x66/0x130
> >> [   50.822931]  [<ffffffff810026ab>] ? system_call_fastpath+0x16/0x1b
> >> [   50.824283] Code: c0 00 00 48 c7 c2 08 40 de 81 48 c7 c6 38 36 a0
> >> 81 e8 d2 8a ac ff 4c 89 a5 18 c0 00 00 48 89 ab c0 00 00 00 48 8b 85
> >> 18 c0 00 00 <44> 8b 00 45 85 c0 0f 84 e1 00 00 00 8b 50 04 8d 4a 01 85
> >> d2 89
> >> [   50.827599] RIP  [<ffffffff8159c4b3>] hiddev_open+0xa3/0x1b0
> >> [   50.829040]  RSP <ffff8801bafe9ca8>
> >> [   50.830557] CR2: 0000000000000000
> >> [   50.831998] ---[ end trace e966fc680b209e8f ]---
> >>
> >> the first significant related change that catches my eye is:
> >>
> >> http://git.eu.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=8fe294caf8c868edd9046251824a0af91991bf43
> >> HID: fix hiddev's use of usb_find_interface
> >>
> >> Could this be the cause ?
> >>
> >> @Alex Riesen:
> >>
> >> maybe you could try to revert that commit
> >> (http://git.eu.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=patch;h=8fe294caf8c868edd9046251824a0af91991bf43)
> >> and see whether that fixes it, I'll do the same in my free time
> >
> > Yeah, please let me know whether reverting that commit fixes the problem
> > you are seeing. It would mean that intfdata is NULL, which'd be a little
> > bit strange, as it is set in usbhid_probe() already.
> >
> > Thanks,
> >
> > --
> > Jiri Kosina
> > SUSE Labs, Novell Inc.
> >
> 
> Hi Jiri,
> 
> sorry for the delay :(
> 
> yeah, it definitely fixes it for me: grepping for BUG or hiddev
> doesn't show up anything anymore (I rebooted into a kernel without the
> fglrx so that results wouldn't get falsified)
> 
> it now only shows:
> 
> dmesg | grep hiddev[    2.560945] usbcore: registered new interface
> driver hiddev
> [    8.449492] generic-usb 0003:046D:C521.0002: input,hiddev0,hidraw1:
> USB HID v1.11 Device [Logitech USB Receiver] on
> usb-0000:00:1a.0-1.3/input1
> 
> 
> FWIW:
> 
> I removed the transmitter of the mouse (it's a wireless mouse) and
> during insert (after the boot was finished) it showed a different
> error message - perhaps it's useful in tracking down the culprit [I
> hope that the fglrx-module was loaded doesn't make any change in its
> usefulness]:
> 
> [  130.065747] hub 1-1:1.0: state 7 ports 6 chg 0000 evt 0008
> [  130.066025] hub 1-1:1.0: port 3, status 0101, change 0001, 12 Mb/s
> [  130.170281] hub 1-1:1.0: debounce: port 3: total 100ms stable 100ms
> status 0x101
> [  130.181259] hub 1-1:1.0: port 3 not reset yet, waiting 10ms
> [  130.243163] usb 1-1.3: new low speed USB device using ehci_hcd and address 4
> [  130.254993] hub 1-1:1.0: port 3 not reset yet, waiting 10ms
> [  130.332878] usb 1-1.3: skipped 1 descriptor after interface
> [  130.332884] usb 1-1.3: skipped 1 descriptor after interface
> [  130.333438] usb 1-1.3: default language 0x0409
> [  130.335534] usb 1-1.3: udev 4, busnum 1, minor = 3
> [  130.335540] usb 1-1.3: New USB device found, idVendor=046d, idProduct=c521
> [  130.335545] usb 1-1.3: New USB device strings: Mfr=1, Product=2,
> SerialNumber=0
> [  130.335550] usb 1-1.3: Product: USB Receiver
> [  130.335554] usb 1-1.3: Manufacturer: Logitech
> [  130.335709] usb 1-1.3: usb_probe_device
> [  130.335716] usb 1-1.3: configuration #1 chosen from 1 choice
> [  130.337653] usb 1-1.3: adding 1-1.3:1.0 (config #1, interface 0)
> [  130.337761] usbhid 1-1.3:1.0: usb_probe_interface
> [  130.337765] usbhid 1-1.3:1.0: usb_probe_interface - got id
> [  130.341047] input: Logitech USB Receiver as
> /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.3/1-1.3:1.0/input/input4
> [  130.341148] usb 1-1.3: link qh8-0e01/ffff8801bf421580 start 4 [1/2 us]
> [  130.341261] generic-usb 0003:046D:C521.0004: input,hidraw2: USB HID
> v1.11 Mouse [Logitech USB Receiver] on usb-0000:00:1a.0-1.3/input0
> [  130.341303] usb 1-1.3: adding 1-1.3:1.1 (config #1, interface 1)
> [  130.341373] usbhid 1-1.3:1.1: usb_probe_interface
> [  130.341378] usbhid 1-1.3:1.1: usb_probe_interface - got id
> [  130.347635] input: Logitech USB Receiver as
> /devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.3/1-1.3:1.1/input/input5
> [  130.347664] usb 1-1.3: link qh8-0e01/ffff8801bf421900 start 5 [1/2 us]
> [  130.347698] drivers/usb/core/file.c: looking for a minor, starting at 0
> [  130.347758] generic-usb 0003:046D:C521.0005: input,hiddev0,hidraw3:
> USB HID v1.11 Device [Logitech USB Receiver] on
> usb-0000:00:1a.0-1.3/input1
> [  130.347805] drivers/usb/core/inode.c: creating file '004'
> [  130.368286] BUG: unable to handle kernel NULL pointer dereference at (null)
> [  130.368288] IP: [<ffffffff8159c4b3>] hiddev_open+0xa3/0x1b0
> [  130.368293] PGD 0
> [  130.368294] Oops: 0000 [#1] PREEMPT SMP
> [  130.368295] last sysfs file:
> /sys/devices/pci0000:00/0000:00:1a.0/usb1/1-1/1-1.3/1-1.3:1.0/input/input4/capabilities/sw
> [  130.368297] CPU 4
> [  130.368298] Modules linked in: it87 hwmon_vid hwmon fglrx(P)
> i2c_i801 firewire_ohci firewire_core e1000e wmi shpchp tg3 libphy
> e1000 scsi_wait_scan sl811_hcd ohci_hcd ssb usb_storage ehci_hcd
> [  130.368304]
> [  130.368306] Pid: 5776, comm: hald-probe-hidd Tainted: P
> 2.6.36-rc4_plus_v2+ #2 FMP55/ipower G3710
> [  130.368307] RIP: 0010:[<ffffffff8159c4b3>]  [<ffffffff8159c4b3>]
> hiddev_open+0xa3/0x1b0
> [  130.368310] RSP: 0018:ffff8801bb06fca8  EFLAGS: 00010296
> [  130.368311] RAX: 0000000000000000 RBX: ffff8801baf27400 RCX: 0000000000000004
> [  130.368312] RDX: ffffffff81de4008 RSI: ffffffff81a03638 RDI: ffff8801bb28c030
> [  130.368313] RBP: ffff8801bb280000 R08: ffffea00060f0c08 R09: 0000000000000000
> [  130.368314] R10: 0000000000000004 R11: 0000000000000000 R12: 0000000000000000
> [  130.368315] R13: 00000000ffffffed R14: ffffffff818f24e0 R15: ffff8801bd1ba1b0
> [  130.368316] FS:  00007f9ba9f78700(0000) GS:ffff880002300000(0000)
> knlGS:0000000000000000
> [  130.368317] CS:  0010 DS: 0000 ES: 0000 CR0: 0000000080050033
> [  130.368318] CR2: 0000000000000000 CR3: 00000001bad83000 CR4: 00000000000006e0
> [  130.368319] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> [  130.368320] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> [  130.368322] Process hald-probe-hidd (pid: 5776, threadinfo
> ffff8801bb06e000, task ffff8801bafb9770)
> [  130.368323] Stack:
> [  130.368323]  ffff8801bb06fd24 0000000000000000 ffff8801baf27400
> ffffffff818e2b00
> [  130.368325] <0> ffff8801bc8e87c0 ffffffff814d9a74 ffff8801bc8e87c0
> ffff8801baf27400
> [  130.368327] <0> ffff8801bfdd4900 0000000000000000 ffffffff810daf10
> ffffffff810db035
> [  130.368329] Call Trace:
> [  130.368332]  [<ffffffff814d9a74>] ? usb_open+0xf4/0x1d0
> [  130.368335]  [<ffffffff810daf10>] ? chrdev_open+0x0/0x210
> [  130.368336]  [<ffffffff810db035>] ? chrdev_open+0x125/0x210
> [  130.368339]  [<ffffffff810d5730>] ? __dentry_open.clone.16+0x100/0x320
> [  130.368341]  [<ffffffff810e3ed0>] ? do_last.clone.45+0x3f0/0x690
> [  130.368342]  [<ffffffff810e4363>] ? do_filp_open+0x1f3/0x5f0
> [  130.368346]  [<ffffffff816b90a5>] ? unix_getname+0x65/0xe0
> [  130.368349]  [<ffffffff81742609>] ? _raw_spin_unlock+0x9/0x40
> [  130.368352]  [<ffffffff810ef5f4>] ? alloc_fd+0xe4/0x140
> [  130.368354]  [<ffffffff810d6896>] ? do_sys_open+0x66/0x130
> [  130.368356]  [<ffffffff810026ab>] ? system_call_fastpath+0x16/0x1b
> [  130.368357] Code: c0 00 00 48 c7 c2 08 40 de 81 48 c7 c6 38 36 a0
> 81 e8 d2 8a ac ff 4c 89 a5 18 c0 00 00 48 89 ab c0 00 00 00 48 8b 85
> 18 c0 00 00 <44> 8b 00 45 85 c0 0f 84 e1 00 00 00 8b 50 04 8d 4a 01 85
> d2 89
> [  130.368368] RIP  [<ffffffff8159c4b3>] hiddev_open+0xa3/0x1b0
> [  130.368370]  RSP <ffff8801bb06fca8>
> [  130.368370] CR2: 0000000000000000
> [  130.368372] ---[ end trace 56b8e483c48eb892 ]---

Actually this looks very similar to the BUG reported previously (EIP at 
hiddev_open(), reached through usb_open()), so reverting 
8fe294caf8c868edd9046251824a0af91991bf43 doesn't really seem to make 
things any better in fact, right? Or did I misunderstand what you did?

Thanks,

-- 
Jiri Kosina
SUSE Labs, Novell Inc.
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Powered by blists - more mailing lists