Re: Warnings and Oops on 2.6.23-rc6 while activily using rfcomm links (mm/slab.c)

["Dave Young" <hidave.darkstar@gmail.com>]

[-- Attachment #1: Type: text/plain, Size: 4731 bytes --]

On 10/1/07, Cornelia Huck <cornelia.huck@de.ibm.com> wrote:
> On Fri, 28 Sep 2007 18:32:32 +0200,
> Pierre-Yves Paulus <py@idlum.be> wrote:
>
> This looks more informational, thanks.
>
> > DEV: Unregistering device. ID = 'rfcomm0'
> > PM: Removing info for No Bus:rfcomm0
> > kobject_uevent_env
> > fill_kobj_path: path = '/class/tty/rfcomm0'
> > fill_kobj_path: path =
> > '/devices/pci0000:00/0000:00:0f.4/usb1/1-1/1-1.5/1-1.5.1/1-1.5.1:1.0/hci2/acl00126253F906'
> > kobject rfcomm0: cleaning up
> > device_create_release called for rfcomm0
>
> Here rfcomm0 was unregistered and released.
>
> > bus bluetooth: remove device acl00126253F906
> > PM: Removing info for bluetooth:acl00126253F906
> > kobject_uevent_env
> > fill_kobj_path: path =
> > '/devices/pci0000:00/0000:00:0f.4/usb1/1-1/1-1.5/1-1.5.1/1-1.5.1:1.0/hci2/acl00126253F906'
> > kobject acl00126253F906: cleaning up
>
> And here the corresponding physdev.
>
> > BUG: unable to handle kernel NULL pointer dereference at virtual address
> > 00000000
> >   printing eip:
> > c0249e29
> > *pde = 00000000
> > Oops: 0000 [#1]
> > Modules linked in: rfcomm l2cap battery ipv6 dm_snapshot dm_mirror
> > dm_mod softdog loop parport_pc parport floppy rtc pcspkr ac button
> > psmouse serio_raw snd_cs5535audio snd_ac97_codec ac97_bus snd_pcm
> > snd_timer snd soundcore snd_page_alloc geode_rng cs5535_gpio hci_usb
> > bluetooth geode_aes blkcipher tsdev evdev usbhid hid reiserfs ide_disk
> > generic amd74xx ide_core ohci_hcd sata_via ata_generic 8139cp libata
> > 8139too usbcore mii scsi_mod thermal processor fan
> > CPU:    0
> > EIP:    0060:[<c0249e29>]    Not tainted VLI
> > EFLAGS: 00010017   (2.6.23-rc8 #1)
> > EIP is at skb_dequeue+0x23/0x4a
> > eax: 00000282   ebx: 00000282   ecx: 00000000   edx: caf8ab8c
> > esi: c8428d48   edi: c8428c00   ebp: c8428c0c   esp: c124ff60
> > ds: 007b   es: 007b   fs: 0000  gs: 0000  ss: 0068
> > Process events/0 (pid: 5, ti=c124e000 task=c1243500 task.ti=c124e000)
> > Stack: caf8ab8c c024b0a1 c8428c00 d02f4075 c8428d60 c020eb8d c08978a8
> > 00000000
> >         00000000 00000000 cf7ab680 c8428d48 c020eac4 00000000 c01279a9
> > c124ffb4
> >         00000046 c1243500 cf7ab680 cf7ab680 c0127ffe c124ffd0 c01280b0
> > 00000000
> > Call Trace:
> >   [<c024b0a1>] skb_queue_purge+0x11/0x17
> >   [<d02f4075>] rfcomm_tty_flush_buffer+0x1c/0x33 [rfcomm]
> >   [<c020eb8d>] do_tty_hangup+0xc9/0x2d0
> >   [<c020eac4>] do_tty_hangup+0x0/0x2d0
> >   [<c01279a9>] run_workqueue+0x7d/0x103
> >   [<c0127ffe>] worker_thread+0x0/0xbe
> >   [<c01280b0>] worker_thread+0xb2/0xbe
> >   [<c012a510>] autoremove_wake_function+0x0/0x35
> >   [<c012a363>] kthread+0x36/0x5b
> >   [<c012a32d>] kthread+0x0/0x5b
> >   [<c0104e17>] kernel_thread_helper+0x7/0x10
> >   =======================
>
> rfcomm0 is already freed, maybe this code is still trying to access it?
>
> > Code: 89 42 0a 5b 5e 5f 5d c3 53 89 c2 9c 58 90 8d b4 26 00 00 00 00 89
> > c3 fa 90 8d b4 26 00 00 00 00 90 8b 0a 39 d1 75 04 31 c9 eb 17 <8b> 01
> > ff 4a 08 89 02 89 50 04 c7 01 00 00 00 00 c7 41 04 00 00
> > EIP: [<c0249e29>] skb_dequeue+0x23/0x4a SS:ESP 0068:c124ff60
> > WARNING: at lib/kref.c:33 kref_get()
> >   [<c01c6db7>] kref_get+0x34/0x3d
> >   [<c01c61a9>] kobject_get+0xf/0x13
> >   [<c022578d>] get_device+0xe/0x14
> >   [<c02257a6>] device_move+0x13/0x114
> >   [<d02f4b7c>] rfcomm_tty_close+0x23/0x61 [rfcomm]
> >   [<c020f88d>] release_dev+0x1c0/0x54e
> >   [<d02f40e5>] rfcomm_dev_destruct+0x59/0x65 [rfcomm]
> >   [<d02f4725>] rfcomm_dev_ioctl+0x329/0x4d0 [rfcomm]
> >   [<c0130c96>] tick_program_event+0x2a/0x49
> >   [<c0248124>] release_sock+0xc/0x74
> >   [<c020fc22>] tty_release+0x7/0xa
> >   [<c015dabd>] __fput+0x93/0x147
> >   [<c015b66a>] filp_close+0x51/0x58
> >   [<c02a8b0e>] __sched_text_start+0x1d6/0x245
> >   [<c015c70b>] sys_close+0x54/0x83
> >   [<c0103c72>] syscall_call+0x7/0xb
> >   =======================
> > DEVICE: moving 'rfcomm0' to '<NULL>'
> > kobject <NULL>: cleaning up
> > device_create_release called for rfcomm0
>
> But here someone still tries to move rfcomm0 around? It already is gone
> and released... The code path has no reference on rfcomm0. (Well,
> device_move() tries to get a reference on the device to be moved, but
> that doesn't help since the device is already gone.)
>
> This looks like a race inside rfcomm. The device_unregister() either
> needs to be delayed until after device_move() has finished, or the
> thread calling device_move() needs to have a reference. (device_move()
> on an unregistered device should just fail but not oops.) Marcel?
> -
Hi,
please try the attached patch.
or the one by marcel in http://lkml.org/lkml/2007/11/5/111

Please tell me the result, thanks.

Regards
dave

[-- Attachment #2: diff.rfcomm --]
[-- Type: application/octet-stream, Size: 742 bytes --]

Signed-off-by: Dave Young <hidave.darkstar@gmail.com> 

---
net/bluetooth/rfcomm/tty.c |    7 -------
1 file changed, 7 deletions(-)

diff -upr linux/net/bluetooth/rfcomm/tty.c linux.new/net/bluetooth/rfcomm/tty.c
--- linux/net/bluetooth/rfcomm/tty.c	2007-11-05 11:28:49.000000000 +0800
+++ linux.new/net/bluetooth/rfcomm/tty.c	2007-11-05 11:30:59.000000000 +0800
@@ -1018,13 +1018,6 @@ static void rfcomm_tty_hangup(struct tty
 		return;
 
 	rfcomm_tty_flush_buffer(tty);
-
-	if (test_bit(RFCOMM_RELEASE_ONHUP, &dev->flags)) {
-		if (rfcomm_dev_get(dev->id) == NULL)
-			return;
-		rfcomm_dev_del(dev);
-		rfcomm_dev_put(dev);
-	}
 }
 
 static int rfcomm_tty_read_proc(char *buf, char **start, off_t offset, int len, int *eof, void *unused)