2009-10-02 06:28:26

by Oliver Hartkopp

[permalink] [raw]
Subject: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

Hello Marcel,

with current net-2.6 tree ...

While starting my PPP Bluetooth dialup networking, i got this:

[ 722.461549] PPP generic driver version 2.4.2
[ 722.477519] BUG: sleeping function called from invalid context at
mm/slub.c:1719
[ 722.477530] in_atomic(): 1, irqs_disabled(): 0, pid: 4677, name: pppd
[ 722.477537] 3 locks held by pppd/4677:
[ 722.477542] #0: (rfcomm_mutex){+.+.+.}, at: [<fa5df2a1>]
rfcomm_dlc_open+0x28/0x2d6 [rfcomm]
[ 722.477568] #1: (sk_lock-AF_BLUETOOTH-BTPROTO_L2CAP){+.+.+.}, at:
[<fa5414f8>] l2cap_sock_connect+0x62/0x2c6 [l2cap]
[ 722.477589] #2: (&hdev->lock){+...+.}, at: [<fa5415b4>]
l2cap_sock_connect+0x11e/0x2c6 [l2cap]
[ 722.477613] Pid: 4677, comm: pppd Not tainted 2.6.31-08939-gdb8abec-dirty #21
[ 722.477619] Call Trace:
[ 722.477633] [<c1042a2b>] ? __debug_show_held_locks+0x1e/0x20
[ 722.477644] [<c10212a1>] __might_sleep+0xc9/0xce
[ 722.477655] [<c1078b62>] __kmalloc+0x6d/0xfb
[ 722.477666] [<c119e739>] ? kzalloc+0xb/0xd
[ 722.477674] [<c119e739>] kzalloc+0xb/0xd
[ 722.477683] [<c119ef1a>] device_private_init+0x15/0x3d
[ 722.477693] [<c11a0e1b>] dev_set_drvdata+0x18/0x26
[ 722.477718] [<f8b7ca1b>] hci_conn_init_sysfs+0x3d/0xc7 [bluetooth]
[ 722.477737] [<f8b791b3>] hci_conn_add+0x1c0/0x1d5 [bluetooth]
[ 722.477756] [<f8b79360>] hci_connect+0x71/0x17d [bluetooth]
[ 722.477769] [<fa54162c>] l2cap_sock_connect+0x196/0x2c6 [l2cap]
[ 722.477782] [<c1246e3d>] kernel_connect+0xd/0x12
[ 722.477795] [<fa5df3c3>] rfcomm_dlc_open+0x14a/0x2d6 [rfcomm]
[ 722.477810] [<fa5e10fa>] ? rfcomm_tty_open+0x73/0x227 [rfcomm]
[ 722.477825] [<fa5e1130>] rfcomm_tty_open+0xa9/0x227 [rfcomm]
[ 722.477836] [<c1022e3f>] ? default_wake_function+0x0/0xd
[ 722.477847] [<c1180c79>] tty_open+0x29e/0x399
[ 722.477858] [<c107e9bd>] chrdev_open+0x13f/0x156
[ 722.477868] [<c107b0d3>] __dentry_open+0x11b/0x20f
[ 722.477878] [<c107b261>] nameidata_to_filp+0x2c/0x43
[ 722.477888] [<c107e87e>] ? chrdev_open+0x0/0x156
[ 722.477898] [<c1084e9e>] do_filp_open+0x3c6/0x70a
[ 722.477910] [<c108d3e4>] ? alloc_fd+0xc8/0xd2
[ 722.477920] [<c108d3e4>] ? alloc_fd+0xc8/0xd2
[ 722.477930] [<c107aebc>] do_sys_open+0x4a/0xe7
[ 722.477940] [<c1002acc>] ? restore_all_notrace+0x0/0x18
[ 722.477950] [<c107af9b>] sys_open+0x1e/0x26
[ 722.477959] [<c1002a18>] sysenter_do_call+0x12/0x36
[ 729.658613] PPP BSD Compression module registered
[ 729.684789] PPP Deflate Compression module registered

Any idea?

Regards,
Oliver


2009-10-11 02:39:36

by Dave Young

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

On Sat, Oct 10, 2009 at 9:45 PM, Dave Young <[email protected]> wro=
te:
> On Sat, Oct 10, 2009 at 12:38:32PM +0200, Marcel Holtmann wrote:
>> Hi Dave,
>>
>> > > * Dave Young <[email protected]> [2009-10-04 11:26:17 +0800]=
:
>> > >
>> > > >
>> > > > I can reproduce the bug.
>> > > >
>> > > > It's probably caused by the l2cap changes by =C2=A0Gustavo F. Pado=
van
>> > > > <[email protected]>, I didn't see such problem after rever=
ting
>> > > > Gustavo's patch series.
>> > >
>> > > I can't reproduce the bug. I'm trying to reproduce it to figure out =
what of
>> > > my changes cause it.
>> > >
>> > > I' running
>> > >
>> > > $ dund -snu -i 00:11:67:CD:0F:CB # to pretend to be dialup/telephone
>> > >
>> > > and on the other side
>> > >
>> > > $ rfcomm bind 0 00:11:67:CD:0F:CB 1
>> > > $ wvdial =C2=A0# wvdial to /dev/rfcomm0
>> > >
>> > > Both sides are on the same machine. Do you see any real difference
>> > > between my try and the call that get the bug?
>> > >
>> >
>> > Hi oliver
>> >
>> > Could try following patch?
>> > ---
>> >
>> > When shutdown ppp connection, lockdep waring about non-static key
>> > will happen, it is caused by the lock is not initialized properly
>> > at that time.
>> >
>> > Fix with tuning the lock/skb_queue_head init order
>> >
>> > [ =C2=A0 94.339261] INFO: trying to register non-static key.
>> > [ =C2=A0 94.342509] the code is fine but needs lockdep annotation.
>> > [ =C2=A0 94.342509] turning off the locking correctness validator.
>> > [ =C2=A0 94.342509] Pid: 0, comm: swapper Not tainted 2.6.31-mm1 #2
>> > [ =C2=A0 94.342509] Call Trace:
>> > [ =C2=A0 94.342509] =C2=A0[<c0248fbe>] register_lock_class+0x58/0x241
>> > [ =C2=A0 94.342509] =C2=A0[<c024b5df>] ? __lock_acquire+0xb57/0xb73
>> > [ =C2=A0 94.342509] =C2=A0[<c024ab34>] __lock_acquire+0xac/0xb73
>> > [ =C2=A0 94.342509] =C2=A0[<c024b7fa>] ? lock_release_non_nested+0x17b=
/0x1de
>> > [ =C2=A0 94.342509] =C2=A0[<c024b662>] lock_acquire+0x67/0x84
>> > [ =C2=A0 94.342509] =C2=A0[<c04cd1eb>] ? skb_dequeue+0x15/0x41
>> > [ =C2=A0 94.342509] =C2=A0[<c054a857>] _spin_lock_irqsave+0x2f/0x3f
>> > [ =C2=A0 94.342509] =C2=A0[<c04cd1eb>] ? skb_dequeue+0x15/0x41
>> > [ =C2=A0 94.342509] =C2=A0[<c04cd1eb>] skb_dequeue+0x15/0x41
>> > [ =C2=A0 94.342509] =C2=A0[<c054a648>] ? _read_unlock+0x1d/0x20
>> > [ =C2=A0 94.342509] =C2=A0[<c04cd641>] skb_queue_purge+0x14/0x1b
>> > [ =C2=A0 94.342509] =C2=A0[<fab94fdc>] l2cap_recv_frame+0xea1/0x115a [=
l2cap]
>> > [ =C2=A0 94.342509] =C2=A0[<c024b5df>] ? __lock_acquire+0xb57/0xb73
>> > [ =C2=A0 94.342509] =C2=A0[<c0249c04>] ? mark_lock+0x1e/0x1c7
>> > [ =C2=A0 94.342509] =C2=A0[<f8364963>] ? hci_rx_task+0xd2/0x1bc [bluet=
ooth]
>> > [ =C2=A0 94.342509] =C2=A0[<fab95346>] l2cap_recv_acldata+0xb1/0x1c6 [=
l2cap]
>> > [ =C2=A0 94.342509] =C2=A0[<f8364997>] hci_rx_task+0x106/0x1bc [blueto=
oth]
>> > [ =C2=A0 94.342509] =C2=A0[<fab95295>] ? l2cap_recv_acldata+0x0/0x1c6 =
[l2cap]
>> > [ =C2=A0 94.342509] =C2=A0[<c02302c4>] tasklet_action+0x69/0xc1
>> > [ =C2=A0 94.342509] =C2=A0[<c022fbef>] __do_softirq+0x94/0x11e
>> > [ =C2=A0 94.342509] =C2=A0[<c022fcaf>] do_softirq+0x36/0x5a
>> > [ =C2=A0 94.342509] =C2=A0[<c022fe14>] irq_exit+0x35/0x68
>> > [ =C2=A0 94.342509] =C2=A0[<c0204ced>] do_IRQ+0x72/0x89
>> > [ =C2=A0 94.342509] =C2=A0[<c02038ee>] common_interrupt+0x2e/0x34
>> > [ =C2=A0 94.342509] =C2=A0[<c024007b>] ? pm_qos_add_requirement+0x63/0=
x9d
>> > [ =C2=A0 94.342509] =C2=A0[<c038e8a5>] ? acpi_idle_enter_bm+0x209/0x23=
8
>> > [ =C2=A0 94.342509] =C2=A0[<c049d238>] cpuidle_idle_call+0x5c/0x94
>> > [ =C2=A0 94.342509] =C2=A0[<c02023f8>] cpu_idle+0x4e/0x6f
>> > [ =C2=A0 94.342509] =C2=A0[<c0534153>] rest_init+0x53/0x55
>> > [ =C2=A0 94.342509] =C2=A0[<c0781894>] start_kernel+0x2f0/0x2f5
>> > [ =C2=A0 94.342509] =C2=A0[<c0781091>] i386_start_kernel+0x91/0x96
>> >
>> > Reported-by: Oliver Hartkopp <[email protected]>
>> > Signed-off-by: Dave Young <[email protected]>
>>
>> actually Gustavo send a patch titled "Initialize variables and timers
>> for both channel's sides" that should fix this, too. Can we test that
>> patch before I include this one.

Marcel, I tested Gustavo's latest patch series including
the "Initialize variables and timers for both channel". Lockdep
warning still happen.

>>
>
> Hi, marcel, of course.
>
>> Regards
>>
>> Marcel
>>
>>
>> --
>> To unsubscribe from this list: send the line "unsubscribe linux-bluetoot=
h" in
>> the body of a message to [email protected]
>> More majordomo info at =C2=A0http://vger.kernel.org/majordomo-info.html
>



--=20
Regards
dave

2009-10-10 13:45:17

by Dave Young

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

On Sat, Oct 10, 2009 at 12:38:32PM +0200, Marcel Holtmann wrote:
> Hi Dave,
>
> > > * Dave Young <[email protected]> [2009-10-04 11:26:17 +0800]:
> > >
> > > >
> > > > I can reproduce the bug.
> > > >
> > > > It's probably caused by the l2cap changes by Gustavo F. Padovan
> > > > <[email protected]>, I didn't see such problem after reverting
> > > > Gustavo's patch series.
> > >
> > > I can't reproduce the bug. I'm trying to reproduce it to figure out what of
> > > my changes cause it.
> > >
> > > I' running
> > >
> > > $ dund -snu -i 00:11:67:CD:0F:CB # to pretend to be dialup/telephone
> > >
> > > and on the other side
> > >
> > > $ rfcomm bind 0 00:11:67:CD:0F:CB 1
> > > $ wvdial # wvdial to /dev/rfcomm0
> > >
> > > Both sides are on the same machine. Do you see any real difference
> > > between my try and the call that get the bug?
> > >
> >
> > Hi oliver
> >
> > Could try following patch?
> > ---
> >
> > When shutdown ppp connection, lockdep waring about non-static key
> > will happen, it is caused by the lock is not initialized properly
> > at that time.
> >
> > Fix with tuning the lock/skb_queue_head init order
> >
> > [ 94.339261] INFO: trying to register non-static key.
> > [ 94.342509] the code is fine but needs lockdep annotation.
> > [ 94.342509] turning off the locking correctness validator.
> > [ 94.342509] Pid: 0, comm: swapper Not tainted 2.6.31-mm1 #2
> > [ 94.342509] Call Trace:
> > [ 94.342509] [<c0248fbe>] register_lock_class+0x58/0x241
> > [ 94.342509] [<c024b5df>] ? __lock_acquire+0xb57/0xb73
> > [ 94.342509] [<c024ab34>] __lock_acquire+0xac/0xb73
> > [ 94.342509] [<c024b7fa>] ? lock_release_non_nested+0x17b/0x1de
> > [ 94.342509] [<c024b662>] lock_acquire+0x67/0x84
> > [ 94.342509] [<c04cd1eb>] ? skb_dequeue+0x15/0x41
> > [ 94.342509] [<c054a857>] _spin_lock_irqsave+0x2f/0x3f
> > [ 94.342509] [<c04cd1eb>] ? skb_dequeue+0x15/0x41
> > [ 94.342509] [<c04cd1eb>] skb_dequeue+0x15/0x41
> > [ 94.342509] [<c054a648>] ? _read_unlock+0x1d/0x20
> > [ 94.342509] [<c04cd641>] skb_queue_purge+0x14/0x1b
> > [ 94.342509] [<fab94fdc>] l2cap_recv_frame+0xea1/0x115a [l2cap]
> > [ 94.342509] [<c024b5df>] ? __lock_acquire+0xb57/0xb73
> > [ 94.342509] [<c0249c04>] ? mark_lock+0x1e/0x1c7
> > [ 94.342509] [<f8364963>] ? hci_rx_task+0xd2/0x1bc [bluetooth]
> > [ 94.342509] [<fab95346>] l2cap_recv_acldata+0xb1/0x1c6 [l2cap]
> > [ 94.342509] [<f8364997>] hci_rx_task+0x106/0x1bc [bluetooth]
> > [ 94.342509] [<fab95295>] ? l2cap_recv_acldata+0x0/0x1c6 [l2cap]
> > [ 94.342509] [<c02302c4>] tasklet_action+0x69/0xc1
> > [ 94.342509] [<c022fbef>] __do_softirq+0x94/0x11e
> > [ 94.342509] [<c022fcaf>] do_softirq+0x36/0x5a
> > [ 94.342509] [<c022fe14>] irq_exit+0x35/0x68
> > [ 94.342509] [<c0204ced>] do_IRQ+0x72/0x89
> > [ 94.342509] [<c02038ee>] common_interrupt+0x2e/0x34
> > [ 94.342509] [<c024007b>] ? pm_qos_add_requirement+0x63/0x9d
> > [ 94.342509] [<c038e8a5>] ? acpi_idle_enter_bm+0x209/0x238
> > [ 94.342509] [<c049d238>] cpuidle_idle_call+0x5c/0x94
> > [ 94.342509] [<c02023f8>] cpu_idle+0x4e/0x6f
> > [ 94.342509] [<c0534153>] rest_init+0x53/0x55
> > [ 94.342509] [<c0781894>] start_kernel+0x2f0/0x2f5
> > [ 94.342509] [<c0781091>] i386_start_kernel+0x91/0x96
> >
> > Reported-by: Oliver Hartkopp <[email protected]>
> > Signed-off-by: Dave Young <[email protected]>
>
> actually Gustavo send a patch titled "Initialize variables and timers
> for both channel's sides" that should fix this, too. Can we test that
> patch before I include this one.
>

Hi, marcel, of course.

> Regards
>
> Marcel
>
>
> --
> To unsubscribe from this list: send the line "unsubscribe linux-bluetooth" in
> the body of a message to [email protected]
> More majordomo info at http://vger.kernel.org/majordomo-info.html

2009-10-10 10:38:32

by Marcel Holtmann

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

Hi Dave,

> > * Dave Young <[email protected]> [2009-10-04 11:26:17 +0800]:
> >
> > >
> > > I can reproduce the bug.
> > >
> > > It's probably caused by the l2cap changes by Gustavo F. Padovan
> > > <[email protected]>, I didn't see such problem after reverting
> > > Gustavo's patch series.
> >
> > I can't reproduce the bug. I'm trying to reproduce it to figure out what of
> > my changes cause it.
> >
> > I' running
> >
> > $ dund -snu -i 00:11:67:CD:0F:CB # to pretend to be dialup/telephone
> >
> > and on the other side
> >
> > $ rfcomm bind 0 00:11:67:CD:0F:CB 1
> > $ wvdial # wvdial to /dev/rfcomm0
> >
> > Both sides are on the same machine. Do you see any real difference
> > between my try and the call that get the bug?
> >
>
> Hi oliver
>
> Could try following patch?
> ---
>
> When shutdown ppp connection, lockdep waring about non-static key
> will happen, it is caused by the lock is not initialized properly
> at that time.
>
> Fix with tuning the lock/skb_queue_head init order
>
> [ 94.339261] INFO: trying to register non-static key.
> [ 94.342509] the code is fine but needs lockdep annotation.
> [ 94.342509] turning off the locking correctness validator.
> [ 94.342509] Pid: 0, comm: swapper Not tainted 2.6.31-mm1 #2
> [ 94.342509] Call Trace:
> [ 94.342509] [<c0248fbe>] register_lock_class+0x58/0x241
> [ 94.342509] [<c024b5df>] ? __lock_acquire+0xb57/0xb73
> [ 94.342509] [<c024ab34>] __lock_acquire+0xac/0xb73
> [ 94.342509] [<c024b7fa>] ? lock_release_non_nested+0x17b/0x1de
> [ 94.342509] [<c024b662>] lock_acquire+0x67/0x84
> [ 94.342509] [<c04cd1eb>] ? skb_dequeue+0x15/0x41
> [ 94.342509] [<c054a857>] _spin_lock_irqsave+0x2f/0x3f
> [ 94.342509] [<c04cd1eb>] ? skb_dequeue+0x15/0x41
> [ 94.342509] [<c04cd1eb>] skb_dequeue+0x15/0x41
> [ 94.342509] [<c054a648>] ? _read_unlock+0x1d/0x20
> [ 94.342509] [<c04cd641>] skb_queue_purge+0x14/0x1b
> [ 94.342509] [<fab94fdc>] l2cap_recv_frame+0xea1/0x115a [l2cap]
> [ 94.342509] [<c024b5df>] ? __lock_acquire+0xb57/0xb73
> [ 94.342509] [<c0249c04>] ? mark_lock+0x1e/0x1c7
> [ 94.342509] [<f8364963>] ? hci_rx_task+0xd2/0x1bc [bluetooth]
> [ 94.342509] [<fab95346>] l2cap_recv_acldata+0xb1/0x1c6 [l2cap]
> [ 94.342509] [<f8364997>] hci_rx_task+0x106/0x1bc [bluetooth]
> [ 94.342509] [<fab95295>] ? l2cap_recv_acldata+0x0/0x1c6 [l2cap]
> [ 94.342509] [<c02302c4>] tasklet_action+0x69/0xc1
> [ 94.342509] [<c022fbef>] __do_softirq+0x94/0x11e
> [ 94.342509] [<c022fcaf>] do_softirq+0x36/0x5a
> [ 94.342509] [<c022fe14>] irq_exit+0x35/0x68
> [ 94.342509] [<c0204ced>] do_IRQ+0x72/0x89
> [ 94.342509] [<c02038ee>] common_interrupt+0x2e/0x34
> [ 94.342509] [<c024007b>] ? pm_qos_add_requirement+0x63/0x9d
> [ 94.342509] [<c038e8a5>] ? acpi_idle_enter_bm+0x209/0x238
> [ 94.342509] [<c049d238>] cpuidle_idle_call+0x5c/0x94
> [ 94.342509] [<c02023f8>] cpu_idle+0x4e/0x6f
> [ 94.342509] [<c0534153>] rest_init+0x53/0x55
> [ 94.342509] [<c0781894>] start_kernel+0x2f0/0x2f5
> [ 94.342509] [<c0781091>] i386_start_kernel+0x91/0x96
>
> Reported-by: Oliver Hartkopp <[email protected]>
> Signed-off-by: Dave Young <[email protected]>

actually Gustavo send a patch titled "Initialize variables and timers
for both channel's sides" that should fix this, too. Can we test that
patch before I include this one.

Regards

Marcel



2009-10-10 09:54:40

by Oliver Hartkopp

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

Dave Young wrote:
> On Sun, Oct 04, 2009 at 06:06:35PM +0000, Gustavo F. Padovan wrote:
>> Hi all,
>>
>> * Dave Young <[email protected]> [2009-10-04 11:26:17 +0800]:
>>
>>> I can reproduce the bug.
>>>
>>> It's probably caused by the l2cap changes by Gustavo F. Padovan
>>> <[email protected]>, I didn't see such problem after reverting
>>> Gustavo's patch series.
>> I can't reproduce the bug. I'm trying to reproduce it to figure out what of
>> my changes cause it.
>>
>> I' running
>>
>> $ dund -snu -i 00:11:67:CD:0F:CB # to pretend to be dialup/telephone
>>
>> and on the other side
>>
>> $ rfcomm bind 0 00:11:67:CD:0F:CB 1
>> $ wvdial # wvdial to /dev/rfcomm0
>>
>> Both sides are on the same machine. Do you see any real difference
>> between my try and the call that get the bug?
>>
>
> Hi oliver
>
> Could try following patch?

I did. It fixed it on the base of the latest net-2.6 tree :-)

Tested-by: Oliver Hartkopp <[email protected]>

Together with the previous patch from http://patchwork.kernel.org/patch/51326/
the reported bluetooth/rfcomm regressions should be fixed IMO.

Thanks for your continuous work on this, Dave!

Regards,
Oliver

>
> ---
>
> When shutdown ppp connection, lockdep waring about non-static key
> will happen, it is caused by the lock is not initialized properly
> at that time.
>
> Fix with tuning the lock/skb_queue_head init order
>
> [ 94.339261] INFO: trying to register non-static key.
> [ 94.342509] the code is fine but needs lockdep annotation.
> [ 94.342509] turning off the locking correctness validator.
> [ 94.342509] Pid: 0, comm: swapper Not tainted 2.6.31-mm1 #2
> [ 94.342509] Call Trace:
> [ 94.342509] [<c0248fbe>] register_lock_class+0x58/0x241
> [ 94.342509] [<c024b5df>] ? __lock_acquire+0xb57/0xb73
> [ 94.342509] [<c024ab34>] __lock_acquire+0xac/0xb73
> [ 94.342509] [<c024b7fa>] ? lock_release_non_nested+0x17b/0x1de
> [ 94.342509] [<c024b662>] lock_acquire+0x67/0x84
> [ 94.342509] [<c04cd1eb>] ? skb_dequeue+0x15/0x41
> [ 94.342509] [<c054a857>] _spin_lock_irqsave+0x2f/0x3f
> [ 94.342509] [<c04cd1eb>] ? skb_dequeue+0x15/0x41
> [ 94.342509] [<c04cd1eb>] skb_dequeue+0x15/0x41
> [ 94.342509] [<c054a648>] ? _read_unlock+0x1d/0x20
> [ 94.342509] [<c04cd641>] skb_queue_purge+0x14/0x1b
> [ 94.342509] [<fab94fdc>] l2cap_recv_frame+0xea1/0x115a [l2cap]
> [ 94.342509] [<c024b5df>] ? __lock_acquire+0xb57/0xb73
> [ 94.342509] [<c0249c04>] ? mark_lock+0x1e/0x1c7
> [ 94.342509] [<f8364963>] ? hci_rx_task+0xd2/0x1bc [bluetooth]
> [ 94.342509] [<fab95346>] l2cap_recv_acldata+0xb1/0x1c6 [l2cap]
> [ 94.342509] [<f8364997>] hci_rx_task+0x106/0x1bc [bluetooth]
> [ 94.342509] [<fab95295>] ? l2cap_recv_acldata+0x0/0x1c6 [l2cap]
> [ 94.342509] [<c02302c4>] tasklet_action+0x69/0xc1
> [ 94.342509] [<c022fbef>] __do_softirq+0x94/0x11e
> [ 94.342509] [<c022fcaf>] do_softirq+0x36/0x5a
> [ 94.342509] [<c022fe14>] irq_exit+0x35/0x68
> [ 94.342509] [<c0204ced>] do_IRQ+0x72/0x89
> [ 94.342509] [<c02038ee>] common_interrupt+0x2e/0x34
> [ 94.342509] [<c024007b>] ? pm_qos_add_requirement+0x63/0x9d
> [ 94.342509] [<c038e8a5>] ? acpi_idle_enter_bm+0x209/0x238
> [ 94.342509] [<c049d238>] cpuidle_idle_call+0x5c/0x94
> [ 94.342509] [<c02023f8>] cpu_idle+0x4e/0x6f
> [ 94.342509] [<c0534153>] rest_init+0x53/0x55
> [ 94.342509] [<c0781894>] start_kernel+0x2f0/0x2f5
> [ 94.342509] [<c0781091>] i386_start_kernel+0x91/0x96
>
> Reported-by: Oliver Hartkopp <[email protected]>
> Signed-off-by: Dave Young <[email protected]>
> ---
> net/bluetooth/l2cap.c | 9 ++++++---
> 1 file changed, 6 insertions(+), 3 deletions(-)
>
> --- linux-2.6.31.orig/net/bluetooth/l2cap.c 2009-10-09 08:32:46.000000000 +0800
> +++ linux-2.6.31/net/bluetooth/l2cap.c 2009-10-09 08:33:57.000000000 +0800
> @@ -555,12 +555,12 @@ static struct l2cap_conn *l2cap_conn_add
>
> conn->feat_mask = 0;
>
> - setup_timer(&conn->info_timer, l2cap_info_timeout,
> - (unsigned long) conn);
> -
> spin_lock_init(&conn->lock);
> rwlock_init(&conn->chan_list.lock);
>
> + setup_timer(&conn->info_timer, l2cap_info_timeout,
> + (unsigned long) conn);
> +
> conn->disc_reason = 0x13;
>
> return conn;
> @@ -783,6 +783,9 @@ static void l2cap_sock_init(struct sock
> /* Default config options */
> pi->conf_len = 0;
> pi->flush_to = L2CAP_DEFAULT_FLUSH_TO;
> + skb_queue_head_init(TX_QUEUE(sk));
> + skb_queue_head_init(SREJ_QUEUE(sk));
> + INIT_LIST_HEAD(SREJ_LIST(sk));
> }
>
> static struct proto l2cap_proto = {

2009-10-09 00:44:53

by Dave Young

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

On Sun, Oct 04, 2009 at 06:06:35PM +0000, Gustavo F. Padovan wrote:
>
> Hi all,
>
> * Dave Young <[email protected]> [2009-10-04 11:26:17 +0800]:
>
> >
> > I can reproduce the bug.
> >
> > It's probably caused by the l2cap changes by Gustavo F. Padovan
> > <[email protected]>, I didn't see such problem after reverting
> > Gustavo's patch series.
>
> I can't reproduce the bug. I'm trying to reproduce it to figure out what of
> my changes cause it.
>
> I' running
>
> $ dund -snu -i 00:11:67:CD:0F:CB # to pretend to be dialup/telephone
>
> and on the other side
>
> $ rfcomm bind 0 00:11:67:CD:0F:CB 1
> $ wvdial # wvdial to /dev/rfcomm0
>
> Both sides are on the same machine. Do you see any real difference
> between my try and the call that get the bug?
>

Hi oliver

Could try following patch?
---

When shutdown ppp connection, lockdep waring about non-static key
will happen, it is caused by the lock is not initialized properly
at that time.

Fix with tuning the lock/skb_queue_head init order

[ 94.339261] INFO: trying to register non-static key.
[ 94.342509] the code is fine but needs lockdep annotation.
[ 94.342509] turning off the locking correctness validator.
[ 94.342509] Pid: 0, comm: swapper Not tainted 2.6.31-mm1 #2
[ 94.342509] Call Trace:
[ 94.342509] [<c0248fbe>] register_lock_class+0x58/0x241
[ 94.342509] [<c024b5df>] ? __lock_acquire+0xb57/0xb73
[ 94.342509] [<c024ab34>] __lock_acquire+0xac/0xb73
[ 94.342509] [<c024b7fa>] ? lock_release_non_nested+0x17b/0x1de
[ 94.342509] [<c024b662>] lock_acquire+0x67/0x84
[ 94.342509] [<c04cd1eb>] ? skb_dequeue+0x15/0x41
[ 94.342509] [<c054a857>] _spin_lock_irqsave+0x2f/0x3f
[ 94.342509] [<c04cd1eb>] ? skb_dequeue+0x15/0x41
[ 94.342509] [<c04cd1eb>] skb_dequeue+0x15/0x41
[ 94.342509] [<c054a648>] ? _read_unlock+0x1d/0x20
[ 94.342509] [<c04cd641>] skb_queue_purge+0x14/0x1b
[ 94.342509] [<fab94fdc>] l2cap_recv_frame+0xea1/0x115a [l2cap]
[ 94.342509] [<c024b5df>] ? __lock_acquire+0xb57/0xb73
[ 94.342509] [<c0249c04>] ? mark_lock+0x1e/0x1c7
[ 94.342509] [<f8364963>] ? hci_rx_task+0xd2/0x1bc [bluetooth]
[ 94.342509] [<fab95346>] l2cap_recv_acldata+0xb1/0x1c6 [l2cap]
[ 94.342509] [<f8364997>] hci_rx_task+0x106/0x1bc [bluetooth]
[ 94.342509] [<fab95295>] ? l2cap_recv_acldata+0x0/0x1c6 [l2cap]
[ 94.342509] [<c02302c4>] tasklet_action+0x69/0xc1
[ 94.342509] [<c022fbef>] __do_softirq+0x94/0x11e
[ 94.342509] [<c022fcaf>] do_softirq+0x36/0x5a
[ 94.342509] [<c022fe14>] irq_exit+0x35/0x68
[ 94.342509] [<c0204ced>] do_IRQ+0x72/0x89
[ 94.342509] [<c02038ee>] common_interrupt+0x2e/0x34
[ 94.342509] [<c024007b>] ? pm_qos_add_requirement+0x63/0x9d
[ 94.342509] [<c038e8a5>] ? acpi_idle_enter_bm+0x209/0x238
[ 94.342509] [<c049d238>] cpuidle_idle_call+0x5c/0x94
[ 94.342509] [<c02023f8>] cpu_idle+0x4e/0x6f
[ 94.342509] [<c0534153>] rest_init+0x53/0x55
[ 94.342509] [<c0781894>] start_kernel+0x2f0/0x2f5
[ 94.342509] [<c0781091>] i386_start_kernel+0x91/0x96

Reported-by: Oliver Hartkopp <[email protected]>
Signed-off-by: Dave Young <[email protected]>
---
net/bluetooth/l2cap.c | 9 ++++++---
1 file changed, 6 insertions(+), 3 deletions(-)

--- linux-2.6.31.orig/net/bluetooth/l2cap.c 2009-10-09 08:32:46.000000000 +0800
+++ linux-2.6.31/net/bluetooth/l2cap.c 2009-10-09 08:33:57.000000000 +0800
@@ -555,12 +555,12 @@ static struct l2cap_conn *l2cap_conn_add

conn->feat_mask = 0;

- setup_timer(&conn->info_timer, l2cap_info_timeout,
- (unsigned long) conn);
-
spin_lock_init(&conn->lock);
rwlock_init(&conn->chan_list.lock);

+ setup_timer(&conn->info_timer, l2cap_info_timeout,
+ (unsigned long) conn);
+
conn->disc_reason = 0x13;

return conn;
@@ -783,6 +783,9 @@ static void l2cap_sock_init(struct sock
/* Default config options */
pi->conf_len = 0;
pi->flush_to = L2CAP_DEFAULT_FLUSH_TO;
+ skb_queue_head_init(TX_QUEUE(sk));
+ skb_queue_head_init(SREJ_QUEUE(sk));
+ INIT_LIST_HEAD(SREJ_LIST(sk));
}

static struct proto l2cap_proto = {

2009-10-08 01:25:07

by Dave Young

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

On Thu, Oct 8, 2009 at 1:16 AM, Oliver Hartkopp <[email protected]> wrote=
:
> Oliver Hartkopp wrote:
>> Dave Young wrote:
>>> On Fri, Oct 2, 2009 at 2:28 PM, Oliver Hartkopp <[email protected]> w=
rote:
>>>> Hello Marcel,
>>>>
>>>> with current net-2.6 tree ...
>>>>
>>>> While starting my PPP Bluetooth dialup networking, i got this:
>>> Hi, oliver
>>>
>>> please try following patch:
>>> http://patchwork.kernel.org/patch/51326/
>>
>> Hi Dave,
>>
>> that fixed it at ppp startup!
>>
>> Tested-by: Oliver Hartkopp <[email protected]>
>
> Hi Dave,
>
> what's the state of this patch?
>
> Has it gone upstream?

Not yet.

Marcel, could you pick it? If there's potential problem please tell.

>
> Regards,
> Oliver
>
>>
>> Btw. when shutting down the ppp connection i still get this:
>>
>> [ =C2=A0361.996887] INFO: trying to register non-static key.
>> [ =C2=A0361.996897] the code is fine but needs lockdep annotation.
>> [ =C2=A0361.996902] turning off the locking correctness validator.
>> [ =C2=A0361.996912] Pid: 0, comm: swapper Not tainted 2.6.31-08939-gdb8a=
bec-dirty #22
>> [ =C2=A0361.996919] Call Trace:
>> [ =C2=A0361.996933] =C2=A0[<c12e4fb2>] ? printk+0xf/0x11
>> [ =C2=A0361.996947] =C2=A0[<c1042214>] register_lock_class+0x5a/0x295
>> [ =C2=A0361.996957] =C2=A0[<c1043af2>] __lock_acquire+0x9b/0xc03
>> [ =C2=A0361.996967] =C2=A0[<c104464b>] ? __lock_acquire+0xbf4/0xc03
>> [ =C2=A0361.996985] =C2=A0[<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x4=
3 [l2cap]
>> [ =C2=A0361.996995] =C2=A0[<c104491f>] ? lock_release_non_nested+0x17b/0=
x1db
>> [ =C2=A0361.997008] =C2=A0[<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x4=
3 [l2cap]
>> [ =C2=A0361.997018] =C2=A0[<c10426fd>] ? trace_hardirqs_off+0xb/0xd
>> [ =C2=A0361.997028] =C2=A0[<c10446b6>] lock_acquire+0x5c/0x73
>> [ =C2=A0361.997039] =C2=A0[<c124cd14>] ? skb_dequeue+0x12/0x4c
>> [ =C2=A0361.997049] =C2=A0[<c12e6e23>] _spin_lock_irqsave+0x24/0x34
>> [ =C2=A0361.997058] =C2=A0[<c124cd14>] ? skb_dequeue+0x12/0x4c
>> [ =C2=A0361.997066] =C2=A0[<c124cd14>] skb_dequeue+0x12/0x4c
>> [ =C2=A0361.997075] =C2=A0[<c124d579>] skb_queue_purge+0x14/0x1b
>> [ =C2=A0361.997088] =C2=A0[<fa59ce3f>] l2cap_recv_frame+0xe9e/0x129a [l2=
cap]
>> [ =C2=A0361.997099] =C2=A0[<c10421d1>] ? register_lock_class+0x17/0x295
>> [ =C2=A0361.997110] =C2=A0[<c104464b>] ? __lock_acquire+0xbf4/0xc03
>> [ =C2=A0361.997128] =C2=A0[<c104464b>] ? __lock_acquire+0xbf4/0xc03
>> [ =C2=A0361.997139] =C2=A0[<c120de74>] ? uhci_giveback_urb+0xf2/0x162
>> [ =C2=A0361.997163] =C2=A0[<f8bb4c45>] ? hci_rx_task+0xfe/0x1f8 [bluetoo=
th]
>> [ =C2=A0361.997177] =C2=A0[<fa59d2e4>] l2cap_recv_acldata+0xa9/0x1be [l2=
cap]
>> [ =C2=A0361.997190] =C2=A0[<fa59d23b>] ? l2cap_recv_acldata+0x0/0x1be [l=
2cap]
>> [ =C2=A0361.997208] =C2=A0[<f8bb4c77>] hci_rx_task+0x130/0x1f8 [bluetoot=
h]
>> [ =C2=A0361.997219] =C2=A0[<c102a098>] tasklet_action+0x6b/0xb2
>> [ =C2=A0361.997228] =C2=A0[<c102a46b>] __do_softirq+0x82/0x101
>> [ =C2=A0361.997237] =C2=A0[<c102a515>] do_softirq+0x2b/0x43
>> [ =C2=A0361.997246] =C2=A0[<c102a619>] irq_exit+0x35/0x68
>> [ =C2=A0361.997256] =C2=A0[<c1004513>] do_IRQ+0x80/0x96
>> [ =C2=A0361.997265] =C2=A0[<c10030ae>] common_interrupt+0x2e/0x34
>> [ =C2=A0361.997275] =C2=A0[<c104007b>] ? tick_device_uses_broadcast+0x71=
/0x7c
>> [ =C2=A0361.997286] =C2=A0[<c11747a8>] ? acpi_idle_enter_simple+0x103/0x=
12e
>> [ =C2=A0361.997296] =C2=A0[<c1174515>] acpi_idle_enter_bm+0xc3/0x253
>> [ =C2=A0361.997306] =C2=A0[<c1238b6f>] cpuidle_idle_call+0x60/0x91
>> [ =C2=A0361.997315] =C2=A0[<c1001d44>] cpu_idle+0x49/0x65
>> [ =C2=A0361.997324] =C2=A0[<c12e2f0e>] start_secondary+0x190/0x195
>>
>>
>> Thanks,
>> Oliver
>>
>>
>
>



--=20
Regards
dave

2009-10-07 17:16:37

by Oliver Hartkopp

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

Oliver Hartkopp wrote:
> Dave Young wrote:
>> On Fri, Oct 2, 2009 at 2:28 PM, Oliver Hartkopp <[email protected]> wrote:
>>> Hello Marcel,
>>>
>>> with current net-2.6 tree ...
>>>
>>> While starting my PPP Bluetooth dialup networking, i got this:
>> Hi, oliver
>>
>> please try following patch:
>> http://patchwork.kernel.org/patch/51326/
>
> Hi Dave,
>
> that fixed it at ppp startup!
>
> Tested-by: Oliver Hartkopp <[email protected]>

Hi Dave,

what's the state of this patch?

Has it gone upstream?

Regards,
Oliver

>
> Btw. when shutting down the ppp connection i still get this:
>
> [ 361.996887] INFO: trying to register non-static key.
> [ 361.996897] the code is fine but needs lockdep annotation.
> [ 361.996902] turning off the locking correctness validator.
> [ 361.996912] Pid: 0, comm: swapper Not tainted 2.6.31-08939-gdb8abec-dirty #22
> [ 361.996919] Call Trace:
> [ 361.996933] [<c12e4fb2>] ? printk+0xf/0x11
> [ 361.996947] [<c1042214>] register_lock_class+0x5a/0x295
> [ 361.996957] [<c1043af2>] __lock_acquire+0x9b/0xc03
> [ 361.996967] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
> [ 361.996985] [<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
> [ 361.996995] [<c104491f>] ? lock_release_non_nested+0x17b/0x1db
> [ 361.997008] [<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
> [ 361.997018] [<c10426fd>] ? trace_hardirqs_off+0xb/0xd
> [ 361.997028] [<c10446b6>] lock_acquire+0x5c/0x73
> [ 361.997039] [<c124cd14>] ? skb_dequeue+0x12/0x4c
> [ 361.997049] [<c12e6e23>] _spin_lock_irqsave+0x24/0x34
> [ 361.997058] [<c124cd14>] ? skb_dequeue+0x12/0x4c
> [ 361.997066] [<c124cd14>] skb_dequeue+0x12/0x4c
> [ 361.997075] [<c124d579>] skb_queue_purge+0x14/0x1b
> [ 361.997088] [<fa59ce3f>] l2cap_recv_frame+0xe9e/0x129a [l2cap]
> [ 361.997099] [<c10421d1>] ? register_lock_class+0x17/0x295
> [ 361.997110] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
> [ 361.997128] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
> [ 361.997139] [<c120de74>] ? uhci_giveback_urb+0xf2/0x162
> [ 361.997163] [<f8bb4c45>] ? hci_rx_task+0xfe/0x1f8 [bluetooth]
> [ 361.997177] [<fa59d2e4>] l2cap_recv_acldata+0xa9/0x1be [l2cap]
> [ 361.997190] [<fa59d23b>] ? l2cap_recv_acldata+0x0/0x1be [l2cap]
> [ 361.997208] [<f8bb4c77>] hci_rx_task+0x130/0x1f8 [bluetooth]
> [ 361.997219] [<c102a098>] tasklet_action+0x6b/0xb2
> [ 361.997228] [<c102a46b>] __do_softirq+0x82/0x101
> [ 361.997237] [<c102a515>] do_softirq+0x2b/0x43
> [ 361.997246] [<c102a619>] irq_exit+0x35/0x68
> [ 361.997256] [<c1004513>] do_IRQ+0x80/0x96
> [ 361.997265] [<c10030ae>] common_interrupt+0x2e/0x34
> [ 361.997275] [<c104007b>] ? tick_device_uses_broadcast+0x71/0x7c
> [ 361.997286] [<c11747a8>] ? acpi_idle_enter_simple+0x103/0x12e
> [ 361.997296] [<c1174515>] acpi_idle_enter_bm+0xc3/0x253
> [ 361.997306] [<c1238b6f>] cpuidle_idle_call+0x60/0x91
> [ 361.997315] [<c1001d44>] cpu_idle+0x49/0x65
> [ 361.997324] [<c12e2f0e>] start_secondary+0x190/0x195
>
>
> Thanks,
> Oliver
>
>

2009-10-05 04:08:53

by Dave Young

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

On Mon, Oct 5, 2009 at 2:06 AM, Gustavo F. Padovan <[email protected]> wr=
ote:
>
> Hi all,
>
> * Dave Young <[email protected]> [2009-10-04 11:26:17 +0800]:
>
>>
>> I can reproduce the bug.
>>
>> It's probably caused by the l2cap changes by =C2=A0Gustavo F. Padovan
>> <[email protected]>, I didn't see such problem after reverting
>> Gustavo's patch series.
>
> I can't reproduce the bug. I'm trying to reproduce it to figure out what =
of
> my changes cause it.
>
> I' running
>
> $ dund -snu -i 00:11:67:CD:0F:CB # to pretend to be dialup/telephone
>
> and on the other side
>
> $ rfcomm bind 0 00:11:67:CD:0F:CB 1
> $ wvdial =C2=A0# wvdial to /dev/rfcomm0
>
> Both sides are on the same machine. Do you see any real difference
> between my try and the call that get the bug?

Just try connecting to a mobile phone with bluetooth on, then set rfcomm.co=
nf

I did:
rfcomm connect 0;
after connection ok, press ctrl+C to hangup

>
>
> --
> Gustavo F. Padovan
>



--=20
Regards
dave

2009-10-04 18:06:35

by Gustavo Padovan

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719


Hi all,

* Dave Young <[email protected]> [2009-10-04 11:26:17 +0800]:

>
> I can reproduce the bug.
>
> It's probably caused by the l2cap changes by Gustavo F. Padovan
> <[email protected]>, I didn't see such problem after reverting
> Gustavo's patch series.

I can't reproduce the bug. I'm trying to reproduce it to figure out what of
my changes cause it.

I' running

$ dund -snu -i 00:11:67:CD:0F:CB # to pretend to be dialup/telephone

and on the other side

$ rfcomm bind 0 00:11:67:CD:0F:CB 1
$ wvdial # wvdial to /dev/rfcomm0

Both sides are on the same machine. Do you see any real difference
between my try and the call that get the bug?


--
Gustavo F. Padovan

2009-10-04 03:26:17

by Dave Young

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

On Sat, Oct 3, 2009 at 5:43 PM, Oliver Hartkopp <[email protected]> wrote=
:
> Dave Young wrote:
>> On Fri, Oct 02, 2009 at 06:04:14PM +0200, Oliver Hartkopp wrote:
>>> Dave Young wrote:
>>>> On Fri, Oct 2, 2009 at 2:28 PM, Oliver Hartkopp <[email protected]> =
wrote:
>>>>> Hello Marcel,
>>>>>
>>>>> with current net-2.6 tree ...
>>>>>
>>>>> While starting my PPP Bluetooth dialup networking, i got this:
>>>> Hi, oliver
>>>>
>>>> please try following patch:
>>>> http://patchwork.kernel.org/patch/51326/
>>> Hi Dave,
>>>
>>> that fixed it at ppp startup!
>>>
>>> Tested-by: Oliver Hartkopp <[email protected]>
>>>
>>> Btw. when shutting down the ppp connection i still get this:
>>>
>>> [ =C2=A0361.996887] INFO: trying to register non-static key.
>>> [ =C2=A0361.996897] the code is fine but needs lockdep annotation.
>>> [ =C2=A0361.996902] turning off the locking correctness validator.
>>> [ =C2=A0361.996912] Pid: 0, comm: swapper Not tainted 2.6.31-08939-gdb8=
abec-dirty #22
>>> [ =C2=A0361.996919] Call Trace:
>>> [ =C2=A0361.996933] =C2=A0[<c12e4fb2>] ? printk+0xf/0x11
>>> [ =C2=A0361.996947] =C2=A0[<c1042214>] register_lock_class+0x5a/0x295
>>> [ =C2=A0361.996957] =C2=A0[<c1043af2>] __lock_acquire+0x9b/0xc03
>>> [ =C2=A0361.996967] =C2=A0[<c104464b>] ? __lock_acquire+0xbf4/0xc03
>>> [ =C2=A0361.996985] =C2=A0[<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x=
43 [l2cap]
>>> [ =C2=A0361.996995] =C2=A0[<c104491f>] ? lock_release_non_nested+0x17b/=
0x1db
>>> [ =C2=A0361.997008] =C2=A0[<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x=
43 [l2cap]
>>> [ =C2=A0361.997018] =C2=A0[<c10426fd>] ? trace_hardirqs_off+0xb/0xd
>>> [ =C2=A0361.997028] =C2=A0[<c10446b6>] lock_acquire+0x5c/0x73
>>> [ =C2=A0361.997039] =C2=A0[<c124cd14>] ? skb_dequeue+0x12/0x4c
>>> [ =C2=A0361.997049] =C2=A0[<c12e6e23>] _spin_lock_irqsave+0x24/0x34
>>> [ =C2=A0361.997058] =C2=A0[<c124cd14>] ? skb_dequeue+0x12/0x4c
>>> [ =C2=A0361.997066] =C2=A0[<c124cd14>] skb_dequeue+0x12/0x4c
>>> [ =C2=A0361.997075] =C2=A0[<c124d579>] skb_queue_purge+0x14/0x1b
>>> [ =C2=A0361.997088] =C2=A0[<fa59ce3f>] l2cap_recv_frame+0xe9e/0x129a [l=
2cap]
>>> [ =C2=A0361.997099] =C2=A0[<c10421d1>] ? register_lock_class+0x17/0x295
>>> [ =C2=A0361.997110] =C2=A0[<c104464b>] ? __lock_acquire+0xbf4/0xc03
>>> [ =C2=A0361.997128] =C2=A0[<c104464b>] ? __lock_acquire+0xbf4/0xc03
>>> [ =C2=A0361.997139] =C2=A0[<c120de74>] ? uhci_giveback_urb+0xf2/0x162
>>> [ =C2=A0361.997163] =C2=A0[<f8bb4c45>] ? hci_rx_task+0xfe/0x1f8 [blueto=
oth]
>>> [ =C2=A0361.997177] =C2=A0[<fa59d2e4>] l2cap_recv_acldata+0xa9/0x1be [l=
2cap]
>>> [ =C2=A0361.997190] =C2=A0[<fa59d23b>] ? l2cap_recv_acldata+0x0/0x1be [=
l2cap]
>>> [ =C2=A0361.997208] =C2=A0[<f8bb4c77>] hci_rx_task+0x130/0x1f8 [bluetoo=
th]
>>> [ =C2=A0361.997219] =C2=A0[<c102a098>] tasklet_action+0x6b/0xb2
>>> [ =C2=A0361.997228] =C2=A0[<c102a46b>] __do_softirq+0x82/0x101
>>> [ =C2=A0361.997237] =C2=A0[<c102a515>] do_softirq+0x2b/0x43
>>> [ =C2=A0361.997246] =C2=A0[<c102a619>] irq_exit+0x35/0x68
>>> [ =C2=A0361.997256] =C2=A0[<c1004513>] do_IRQ+0x80/0x96
>>> [ =C2=A0361.997265] =C2=A0[<c10030ae>] common_interrupt+0x2e/0x34
>>> [ =C2=A0361.997275] =C2=A0[<c104007b>] ? tick_device_uses_broadcast+0x7=
1/0x7c
>>> [ =C2=A0361.997286] =C2=A0[<c11747a8>] ? acpi_idle_enter_simple+0x103/0=
x12e
>>> [ =C2=A0361.997296] =C2=A0[<c1174515>] acpi_idle_enter_bm+0xc3/0x253
>>> [ =C2=A0361.997306] =C2=A0[<c1238b6f>] cpuidle_idle_call+0x60/0x91
>>> [ =C2=A0361.997315] =C2=A0[<c1001d44>] cpu_idle+0x49/0x65
>>> [ =C2=A0361.997324] =C2=A0[<c12e2f0e>] start_secondary+0x190/0x195
>>>
>>>
>>> Thanks,
>>> Oliver
>>>
>>
>> Oliver, does following patch fix the non-static lock problem?
>> --
>>
>> now l2cap conn locks will be initialized after setup l2cap conn timer,
>> it will introduce following problem:
>>
>> [ =C2=A0361.996887] INFO: trying to register non-static key.
>> [ =C2=A0361.996897] the code is fine but needs lockdep annotation.
>> [ =C2=A0361.996902] turning off the locking correctness validator.
>> [ =C2=A0361.996912] Pid: 0, comm: swapper Not tainted 2.6.31-08939-gdb8a=
bec-dirty #22
>> [ =C2=A0361.996919] Call Trace:
>> [ =C2=A0361.996933] =C2=A0[<c12e4fb2>] ? printk+0xf/0x11
>> [ =C2=A0361.996947] =C2=A0[<c1042214>] register_lock_class+0x5a/0x295
>> [ =C2=A0361.996957] =C2=A0[<c1043af2>] __lock_acquire+0x9b/0xc03
>> [ =C2=A0361.996967] =C2=A0[<c104464b>] ? __lock_acquire+0xbf4/0xc03
>> [ =C2=A0361.996985] =C2=A0[<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x4=
3 [l2cap]
>> [ =C2=A0361.996995] =C2=A0[<c104491f>] ? lock_release_non_nested+0x17b/0=
x1db
>> [ =C2=A0361.997008] =C2=A0[<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x4=
3 [l2cap]
>> [ =C2=A0361.997018] =C2=A0[<c10426fd>] ? trace_hardirqs_off+0xb/0xd
>> [ =C2=A0361.997028] =C2=A0[<c10446b6>] lock_acquire+0x5c/0x73
>> [ =C2=A0361.997039] =C2=A0[<c124cd14>] ? skb_dequeue+0x12/0x4c
>> [ =C2=A0361.997049] =C2=A0[<c12e6e23>] _spin_lock_irqsave+0x24/0x34
>> [ =C2=A0361.997058] =C2=A0[<c124cd14>] ? skb_dequeue+0x12/0x4c
>> [ =C2=A0361.997066] =C2=A0[<c124cd14>] skb_dequeue+0x12/0x4c
>> [ =C2=A0361.997075] =C2=A0[<c124d579>] skb_queue_purge+0x14/0x1b
>> [ =C2=A0361.997088] =C2=A0[<fa59ce3f>] l2cap_recv_frame+0xe9e/0x129a [l2=
cap]
>> [ =C2=A0361.997099] =C2=A0[<c10421d1>] ? register_lock_class+0x17/0x295
>> [ =C2=A0361.997110] =C2=A0[<c104464b>] ? __lock_acquire+0xbf4/0xc03
>> [ =C2=A0361.997128] =C2=A0[<c104464b>] ? __lock_acquire+0xbf4/0xc03
>> [ =C2=A0361.997139] =C2=A0[<c120de74>] ? uhci_giveback_urb+0xf2/0x162
>> [ =C2=A0361.997163] =C2=A0[<f8bb4c45>] ? hci_rx_task+0xfe/0x1f8 [bluetoo=
th]
>> [ =C2=A0361.997177] =C2=A0[<fa59d2e4>] l2cap_recv_acldata+0xa9/0x1be [l2=
cap]
>> [ =C2=A0361.997190] =C2=A0[<fa59d23b>] ? l2cap_recv_acldata+0x0/0x1be [l=
2cap]
>> [ =C2=A0361.997208] =C2=A0[<f8bb4c77>] hci_rx_task+0x130/0x1f8 [bluetoot=
h]
>> [ =C2=A0361.997219] =C2=A0[<c102a098>] tasklet_action+0x6b/0xb2
>> [ =C2=A0361.997228] =C2=A0[<c102a46b>] __do_softirq+0x82/0x101
>> [ =C2=A0361.997237] =C2=A0[<c102a515>] do_softirq+0x2b/0x43
>> [ =C2=A0361.997246] =C2=A0[<c102a619>] irq_exit+0x35/0x68
>> [ =C2=A0361.997256] =C2=A0[<c1004513>] do_IRQ+0x80/0x96
>> [ =C2=A0361.997265] =C2=A0[<c10030ae>] common_interrupt+0x2e/0x34
>> [ =C2=A0361.997275] =C2=A0[<c104007b>] ? tick_device_uses_broadcast+0x71=
/0x7c
>> [ =C2=A0361.997286] =C2=A0[<c11747a8>] ? acpi_idle_enter_simple+0x103/0x=
12e
>> [ =C2=A0361.997296] =C2=A0[<c1174515>] acpi_idle_enter_bm+0xc3/0x253
>> [ =C2=A0361.997306] =C2=A0[<c1238b6f>] cpuidle_idle_call+0x60/0x91
>> [ =C2=A0361.997315] =C2=A0[<c1001d44>] cpu_idle+0x49/0x65
>> [ =C2=A0361.997324] =C2=A0[<c12e2f0e>] start_secondary+0x190/0x195
>>
>> Here move lock init things before setup_timer to avoid misuse
>> uninitialized locks.
>>
>> Reported-by: Oliver Hartkopp <[email protected]>
>> Signed-off-by: Dave Young <[email protected]>
>> ---
>> net/bluetooth/l2cap.c | =C2=A0 =C2=A06 +++---
>> 1 file changed, 3 insertions(+), 3 deletions(-)
>>
>> --- linux-2.6.31.orig/net/bluetooth/l2cap.c =C2=A0 2009-09-30 16:36:10.0=
00000000 +0800
>> +++ linux-2.6.31/net/bluetooth/l2cap.c =C2=A0 =C2=A0 =C2=A0 =C2=A02009-1=
0-03 14:44:51.000000000 +0800
>> @@ -555,12 +555,12 @@ static struct l2cap_conn *l2cap_conn_add
>>
>> =C2=A0 =C2=A0 =C2=A0 conn->feat_mask =3D 0;
>>
>> - =C2=A0 =C2=A0 setup_timer(&conn->info_timer, l2cap_info_timeout,
>> - =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=
=A0 =C2=A0 (unsigned long) conn);
>> -
>> =C2=A0 =C2=A0 =C2=A0 spin_lock_init(&conn->lock);
>> =C2=A0 =C2=A0 =C2=A0 rwlock_init(&conn->chan_list.lock);
>>
>> + =C2=A0 =C2=A0 setup_timer(&conn->info_timer, l2cap_info_timeout,
>> + =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =
=C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=A0 =C2=
=A0 =C2=A0 (unsigned long) conn);
>> +
>> =C2=A0 =C2=A0 =C2=A0 conn->disc_reason =3D 0x13;
>>
>> =C2=A0 =C2=A0 =C2=A0 return conn;
>
> No, it does not have any effect.
>

I can reproduce the bug.

It's probably caused by the l2cap changes by Gustavo F. Padovan
<[email protected]>, I didn't see such problem after reverting
Gustavo's patch series.

Add gustavo to cc-list.

BTW, my above patch fix similar things. I need rewrite the patch descriptio=
n.

> As the lockdep annotation only appears when shutting down the ppp connect=
ion,
> i wonder whether it should help to change things in a _conn_add() functio=
n.
> :-)
>
> Or didn't i made it clear before, that this annotation one only happens a=
t ppp
> shutdown?
>
> Best regards,
> Oliver
>
>



--=20
Regards
dave

2009-10-03 09:43:06

by Oliver Hartkopp

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

Dave Young wrote:
> On Fri, Oct 02, 2009 at 06:04:14PM +0200, Oliver Hartkopp wrote:
>> Dave Young wrote:
>>> On Fri, Oct 2, 2009 at 2:28 PM, Oliver Hartkopp <[email protected]> wrote:
>>>> Hello Marcel,
>>>>
>>>> with current net-2.6 tree ...
>>>>
>>>> While starting my PPP Bluetooth dialup networking, i got this:
>>> Hi, oliver
>>>
>>> please try following patch:
>>> http://patchwork.kernel.org/patch/51326/
>> Hi Dave,
>>
>> that fixed it at ppp startup!
>>
>> Tested-by: Oliver Hartkopp <[email protected]>
>>
>> Btw. when shutting down the ppp connection i still get this:
>>
>> [ 361.996887] INFO: trying to register non-static key.
>> [ 361.996897] the code is fine but needs lockdep annotation.
>> [ 361.996902] turning off the locking correctness validator.
>> [ 361.996912] Pid: 0, comm: swapper Not tainted 2.6.31-08939-gdb8abec-dirty #22
>> [ 361.996919] Call Trace:
>> [ 361.996933] [<c12e4fb2>] ? printk+0xf/0x11
>> [ 361.996947] [<c1042214>] register_lock_class+0x5a/0x295
>> [ 361.996957] [<c1043af2>] __lock_acquire+0x9b/0xc03
>> [ 361.996967] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
>> [ 361.996985] [<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
>> [ 361.996995] [<c104491f>] ? lock_release_non_nested+0x17b/0x1db
>> [ 361.997008] [<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
>> [ 361.997018] [<c10426fd>] ? trace_hardirqs_off+0xb/0xd
>> [ 361.997028] [<c10446b6>] lock_acquire+0x5c/0x73
>> [ 361.997039] [<c124cd14>] ? skb_dequeue+0x12/0x4c
>> [ 361.997049] [<c12e6e23>] _spin_lock_irqsave+0x24/0x34
>> [ 361.997058] [<c124cd14>] ? skb_dequeue+0x12/0x4c
>> [ 361.997066] [<c124cd14>] skb_dequeue+0x12/0x4c
>> [ 361.997075] [<c124d579>] skb_queue_purge+0x14/0x1b
>> [ 361.997088] [<fa59ce3f>] l2cap_recv_frame+0xe9e/0x129a [l2cap]
>> [ 361.997099] [<c10421d1>] ? register_lock_class+0x17/0x295
>> [ 361.997110] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
>> [ 361.997128] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
>> [ 361.997139] [<c120de74>] ? uhci_giveback_urb+0xf2/0x162
>> [ 361.997163] [<f8bb4c45>] ? hci_rx_task+0xfe/0x1f8 [bluetooth]
>> [ 361.997177] [<fa59d2e4>] l2cap_recv_acldata+0xa9/0x1be [l2cap]
>> [ 361.997190] [<fa59d23b>] ? l2cap_recv_acldata+0x0/0x1be [l2cap]
>> [ 361.997208] [<f8bb4c77>] hci_rx_task+0x130/0x1f8 [bluetooth]
>> [ 361.997219] [<c102a098>] tasklet_action+0x6b/0xb2
>> [ 361.997228] [<c102a46b>] __do_softirq+0x82/0x101
>> [ 361.997237] [<c102a515>] do_softirq+0x2b/0x43
>> [ 361.997246] [<c102a619>] irq_exit+0x35/0x68
>> [ 361.997256] [<c1004513>] do_IRQ+0x80/0x96
>> [ 361.997265] [<c10030ae>] common_interrupt+0x2e/0x34
>> [ 361.997275] [<c104007b>] ? tick_device_uses_broadcast+0x71/0x7c
>> [ 361.997286] [<c11747a8>] ? acpi_idle_enter_simple+0x103/0x12e
>> [ 361.997296] [<c1174515>] acpi_idle_enter_bm+0xc3/0x253
>> [ 361.997306] [<c1238b6f>] cpuidle_idle_call+0x60/0x91
>> [ 361.997315] [<c1001d44>] cpu_idle+0x49/0x65
>> [ 361.997324] [<c12e2f0e>] start_secondary+0x190/0x195
>>
>>
>> Thanks,
>> Oliver
>>
>
> Oliver, does following patch fix the non-static lock problem?
> --
>
> now l2cap conn locks will be initialized after setup l2cap conn timer,
> it will introduce following problem:
>
> [ 361.996887] INFO: trying to register non-static key.
> [ 361.996897] the code is fine but needs lockdep annotation.
> [ 361.996902] turning off the locking correctness validator.
> [ 361.996912] Pid: 0, comm: swapper Not tainted 2.6.31-08939-gdb8abec-dirty #22
> [ 361.996919] Call Trace:
> [ 361.996933] [<c12e4fb2>] ? printk+0xf/0x11
> [ 361.996947] [<c1042214>] register_lock_class+0x5a/0x295
> [ 361.996957] [<c1043af2>] __lock_acquire+0x9b/0xc03
> [ 361.996967] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
> [ 361.996985] [<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
> [ 361.996995] [<c104491f>] ? lock_release_non_nested+0x17b/0x1db
> [ 361.997008] [<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
> [ 361.997018] [<c10426fd>] ? trace_hardirqs_off+0xb/0xd
> [ 361.997028] [<c10446b6>] lock_acquire+0x5c/0x73
> [ 361.997039] [<c124cd14>] ? skb_dequeue+0x12/0x4c
> [ 361.997049] [<c12e6e23>] _spin_lock_irqsave+0x24/0x34
> [ 361.997058] [<c124cd14>] ? skb_dequeue+0x12/0x4c
> [ 361.997066] [<c124cd14>] skb_dequeue+0x12/0x4c
> [ 361.997075] [<c124d579>] skb_queue_purge+0x14/0x1b
> [ 361.997088] [<fa59ce3f>] l2cap_recv_frame+0xe9e/0x129a [l2cap]
> [ 361.997099] [<c10421d1>] ? register_lock_class+0x17/0x295
> [ 361.997110] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
> [ 361.997128] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
> [ 361.997139] [<c120de74>] ? uhci_giveback_urb+0xf2/0x162
> [ 361.997163] [<f8bb4c45>] ? hci_rx_task+0xfe/0x1f8 [bluetooth]
> [ 361.997177] [<fa59d2e4>] l2cap_recv_acldata+0xa9/0x1be [l2cap]
> [ 361.997190] [<fa59d23b>] ? l2cap_recv_acldata+0x0/0x1be [l2cap]
> [ 361.997208] [<f8bb4c77>] hci_rx_task+0x130/0x1f8 [bluetooth]
> [ 361.997219] [<c102a098>] tasklet_action+0x6b/0xb2
> [ 361.997228] [<c102a46b>] __do_softirq+0x82/0x101
> [ 361.997237] [<c102a515>] do_softirq+0x2b/0x43
> [ 361.997246] [<c102a619>] irq_exit+0x35/0x68
> [ 361.997256] [<c1004513>] do_IRQ+0x80/0x96
> [ 361.997265] [<c10030ae>] common_interrupt+0x2e/0x34
> [ 361.997275] [<c104007b>] ? tick_device_uses_broadcast+0x71/0x7c
> [ 361.997286] [<c11747a8>] ? acpi_idle_enter_simple+0x103/0x12e
> [ 361.997296] [<c1174515>] acpi_idle_enter_bm+0xc3/0x253
> [ 361.997306] [<c1238b6f>] cpuidle_idle_call+0x60/0x91
> [ 361.997315] [<c1001d44>] cpu_idle+0x49/0x65
> [ 361.997324] [<c12e2f0e>] start_secondary+0x190/0x195
>
> Here move lock init things before setup_timer to avoid misuse
> uninitialized locks.
>
> Reported-by: Oliver Hartkopp <[email protected]>
> Signed-off-by: Dave Young <[email protected]>
> ---
> net/bluetooth/l2cap.c | 6 +++---
> 1 file changed, 3 insertions(+), 3 deletions(-)
>
> --- linux-2.6.31.orig/net/bluetooth/l2cap.c 2009-09-30 16:36:10.000000000 +0800
> +++ linux-2.6.31/net/bluetooth/l2cap.c 2009-10-03 14:44:51.000000000 +0800
> @@ -555,12 +555,12 @@ static struct l2cap_conn *l2cap_conn_add
>
> conn->feat_mask = 0;
>
> - setup_timer(&conn->info_timer, l2cap_info_timeout,
> - (unsigned long) conn);
> -
> spin_lock_init(&conn->lock);
> rwlock_init(&conn->chan_list.lock);
>
> + setup_timer(&conn->info_timer, l2cap_info_timeout,
> + (unsigned long) conn);
> +
> conn->disc_reason = 0x13;
>
> return conn;

No, it does not have any effect.

As the lockdep annotation only appears when shutting down the ppp connection,
i wonder whether it should help to change things in a _conn_add() function.
:-)

Or didn't i made it clear before, that this annotation one only happens at ppp
shutdown?

Best regards,
Oliver

2009-10-03 07:06:22

by Dave Young

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

On Fri, Oct 02, 2009 at 06:04:14PM +0200, Oliver Hartkopp wrote:
> Dave Young wrote:
> > On Fri, Oct 2, 2009 at 2:28 PM, Oliver Hartkopp <[email protected]> wrote:
> >> Hello Marcel,
> >>
> >> with current net-2.6 tree ...
> >>
> >> While starting my PPP Bluetooth dialup networking, i got this:
> >
> > Hi, oliver
> >
> > please try following patch:
> > http://patchwork.kernel.org/patch/51326/
>
> Hi Dave,
>
> that fixed it at ppp startup!
>
> Tested-by: Oliver Hartkopp <[email protected]>
>
> Btw. when shutting down the ppp connection i still get this:
>
> [ 361.996887] INFO: trying to register non-static key.
> [ 361.996897] the code is fine but needs lockdep annotation.
> [ 361.996902] turning off the locking correctness validator.
> [ 361.996912] Pid: 0, comm: swapper Not tainted 2.6.31-08939-gdb8abec-dirty #22
> [ 361.996919] Call Trace:
> [ 361.996933] [<c12e4fb2>] ? printk+0xf/0x11
> [ 361.996947] [<c1042214>] register_lock_class+0x5a/0x295
> [ 361.996957] [<c1043af2>] __lock_acquire+0x9b/0xc03
> [ 361.996967] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
> [ 361.996985] [<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
> [ 361.996995] [<c104491f>] ? lock_release_non_nested+0x17b/0x1db
> [ 361.997008] [<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
> [ 361.997018] [<c10426fd>] ? trace_hardirqs_off+0xb/0xd
> [ 361.997028] [<c10446b6>] lock_acquire+0x5c/0x73
> [ 361.997039] [<c124cd14>] ? skb_dequeue+0x12/0x4c
> [ 361.997049] [<c12e6e23>] _spin_lock_irqsave+0x24/0x34
> [ 361.997058] [<c124cd14>] ? skb_dequeue+0x12/0x4c
> [ 361.997066] [<c124cd14>] skb_dequeue+0x12/0x4c
> [ 361.997075] [<c124d579>] skb_queue_purge+0x14/0x1b
> [ 361.997088] [<fa59ce3f>] l2cap_recv_frame+0xe9e/0x129a [l2cap]
> [ 361.997099] [<c10421d1>] ? register_lock_class+0x17/0x295
> [ 361.997110] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
> [ 361.997128] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
> [ 361.997139] [<c120de74>] ? uhci_giveback_urb+0xf2/0x162
> [ 361.997163] [<f8bb4c45>] ? hci_rx_task+0xfe/0x1f8 [bluetooth]
> [ 361.997177] [<fa59d2e4>] l2cap_recv_acldata+0xa9/0x1be [l2cap]
> [ 361.997190] [<fa59d23b>] ? l2cap_recv_acldata+0x0/0x1be [l2cap]
> [ 361.997208] [<f8bb4c77>] hci_rx_task+0x130/0x1f8 [bluetooth]
> [ 361.997219] [<c102a098>] tasklet_action+0x6b/0xb2
> [ 361.997228] [<c102a46b>] __do_softirq+0x82/0x101
> [ 361.997237] [<c102a515>] do_softirq+0x2b/0x43
> [ 361.997246] [<c102a619>] irq_exit+0x35/0x68
> [ 361.997256] [<c1004513>] do_IRQ+0x80/0x96
> [ 361.997265] [<c10030ae>] common_interrupt+0x2e/0x34
> [ 361.997275] [<c104007b>] ? tick_device_uses_broadcast+0x71/0x7c
> [ 361.997286] [<c11747a8>] ? acpi_idle_enter_simple+0x103/0x12e
> [ 361.997296] [<c1174515>] acpi_idle_enter_bm+0xc3/0x253
> [ 361.997306] [<c1238b6f>] cpuidle_idle_call+0x60/0x91
> [ 361.997315] [<c1001d44>] cpu_idle+0x49/0x65
> [ 361.997324] [<c12e2f0e>] start_secondary+0x190/0x195
>
>
> Thanks,
> Oliver
>

Oliver, does following patch fix the non-static lock problem?
--

now l2cap conn locks will be initialized after setup l2cap conn timer,
it will introduce following problem:

[ 361.996887] INFO: trying to register non-static key.
[ 361.996897] the code is fine but needs lockdep annotation.
[ 361.996902] turning off the locking correctness validator.
[ 361.996912] Pid: 0, comm: swapper Not tainted 2.6.31-08939-gdb8abec-dirty #22
[ 361.996919] Call Trace:
[ 361.996933] [<c12e4fb2>] ? printk+0xf/0x11
[ 361.996947] [<c1042214>] register_lock_class+0x5a/0x295
[ 361.996957] [<c1043af2>] __lock_acquire+0x9b/0xc03
[ 361.996967] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
[ 361.996985] [<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
[ 361.996995] [<c104491f>] ? lock_release_non_nested+0x17b/0x1db
[ 361.997008] [<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
[ 361.997018] [<c10426fd>] ? trace_hardirqs_off+0xb/0xd
[ 361.997028] [<c10446b6>] lock_acquire+0x5c/0x73
[ 361.997039] [<c124cd14>] ? skb_dequeue+0x12/0x4c
[ 361.997049] [<c12e6e23>] _spin_lock_irqsave+0x24/0x34
[ 361.997058] [<c124cd14>] ? skb_dequeue+0x12/0x4c
[ 361.997066] [<c124cd14>] skb_dequeue+0x12/0x4c
[ 361.997075] [<c124d579>] skb_queue_purge+0x14/0x1b
[ 361.997088] [<fa59ce3f>] l2cap_recv_frame+0xe9e/0x129a [l2cap]
[ 361.997099] [<c10421d1>] ? register_lock_class+0x17/0x295
[ 361.997110] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
[ 361.997128] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
[ 361.997139] [<c120de74>] ? uhci_giveback_urb+0xf2/0x162
[ 361.997163] [<f8bb4c45>] ? hci_rx_task+0xfe/0x1f8 [bluetooth]
[ 361.997177] [<fa59d2e4>] l2cap_recv_acldata+0xa9/0x1be [l2cap]
[ 361.997190] [<fa59d23b>] ? l2cap_recv_acldata+0x0/0x1be [l2cap]
[ 361.997208] [<f8bb4c77>] hci_rx_task+0x130/0x1f8 [bluetooth]
[ 361.997219] [<c102a098>] tasklet_action+0x6b/0xb2
[ 361.997228] [<c102a46b>] __do_softirq+0x82/0x101
[ 361.997237] [<c102a515>] do_softirq+0x2b/0x43
[ 361.997246] [<c102a619>] irq_exit+0x35/0x68
[ 361.997256] [<c1004513>] do_IRQ+0x80/0x96
[ 361.997265] [<c10030ae>] common_interrupt+0x2e/0x34
[ 361.997275] [<c104007b>] ? tick_device_uses_broadcast+0x71/0x7c
[ 361.997286] [<c11747a8>] ? acpi_idle_enter_simple+0x103/0x12e
[ 361.997296] [<c1174515>] acpi_idle_enter_bm+0xc3/0x253
[ 361.997306] [<c1238b6f>] cpuidle_idle_call+0x60/0x91
[ 361.997315] [<c1001d44>] cpu_idle+0x49/0x65
[ 361.997324] [<c12e2f0e>] start_secondary+0x190/0x195

Here move lock init things before setup_timer to avoid misuse
uninitialized locks.

Reported-by: Oliver Hartkopp <[email protected]>
Signed-off-by: Dave Young <[email protected]>
---
net/bluetooth/l2cap.c | 6 +++---
1 file changed, 3 insertions(+), 3 deletions(-)

--- linux-2.6.31.orig/net/bluetooth/l2cap.c 2009-09-30 16:36:10.000000000 +0800
+++ linux-2.6.31/net/bluetooth/l2cap.c 2009-10-03 14:44:51.000000000 +0800
@@ -555,12 +555,12 @@ static struct l2cap_conn *l2cap_conn_add

conn->feat_mask = 0;

- setup_timer(&conn->info_timer, l2cap_info_timeout,
- (unsigned long) conn);
-
spin_lock_init(&conn->lock);
rwlock_init(&conn->chan_list.lock);

+ setup_timer(&conn->info_timer, l2cap_info_timeout,
+ (unsigned long) conn);
+
conn->disc_reason = 0x13;

return conn;

2009-10-02 16:04:14

by Oliver Hartkopp

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

Dave Young wrote:
> On Fri, Oct 2, 2009 at 2:28 PM, Oliver Hartkopp <[email protected]> wrote:
>> Hello Marcel,
>>
>> with current net-2.6 tree ...
>>
>> While starting my PPP Bluetooth dialup networking, i got this:
>
> Hi, oliver
>
> please try following patch:
> http://patchwork.kernel.org/patch/51326/

Hi Dave,

that fixed it at ppp startup!

Tested-by: Oliver Hartkopp <[email protected]>

Btw. when shutting down the ppp connection i still get this:

[ 361.996887] INFO: trying to register non-static key.
[ 361.996897] the code is fine but needs lockdep annotation.
[ 361.996902] turning off the locking correctness validator.
[ 361.996912] Pid: 0, comm: swapper Not tainted 2.6.31-08939-gdb8abec-dirty #22
[ 361.996919] Call Trace:
[ 361.996933] [<c12e4fb2>] ? printk+0xf/0x11
[ 361.996947] [<c1042214>] register_lock_class+0x5a/0x295
[ 361.996957] [<c1043af2>] __lock_acquire+0x9b/0xc03
[ 361.996967] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
[ 361.996985] [<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
[ 361.996995] [<c104491f>] ? lock_release_non_nested+0x17b/0x1db
[ 361.997008] [<fa59a168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
[ 361.997018] [<c10426fd>] ? trace_hardirqs_off+0xb/0xd
[ 361.997028] [<c10446b6>] lock_acquire+0x5c/0x73
[ 361.997039] [<c124cd14>] ? skb_dequeue+0x12/0x4c
[ 361.997049] [<c12e6e23>] _spin_lock_irqsave+0x24/0x34
[ 361.997058] [<c124cd14>] ? skb_dequeue+0x12/0x4c
[ 361.997066] [<c124cd14>] skb_dequeue+0x12/0x4c
[ 361.997075] [<c124d579>] skb_queue_purge+0x14/0x1b
[ 361.997088] [<fa59ce3f>] l2cap_recv_frame+0xe9e/0x129a [l2cap]
[ 361.997099] [<c10421d1>] ? register_lock_class+0x17/0x295
[ 361.997110] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
[ 361.997128] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
[ 361.997139] [<c120de74>] ? uhci_giveback_urb+0xf2/0x162
[ 361.997163] [<f8bb4c45>] ? hci_rx_task+0xfe/0x1f8 [bluetooth]
[ 361.997177] [<fa59d2e4>] l2cap_recv_acldata+0xa9/0x1be [l2cap]
[ 361.997190] [<fa59d23b>] ? l2cap_recv_acldata+0x0/0x1be [l2cap]
[ 361.997208] [<f8bb4c77>] hci_rx_task+0x130/0x1f8 [bluetooth]
[ 361.997219] [<c102a098>] tasklet_action+0x6b/0xb2
[ 361.997228] [<c102a46b>] __do_softirq+0x82/0x101
[ 361.997237] [<c102a515>] do_softirq+0x2b/0x43
[ 361.997246] [<c102a619>] irq_exit+0x35/0x68
[ 361.997256] [<c1004513>] do_IRQ+0x80/0x96
[ 361.997265] [<c10030ae>] common_interrupt+0x2e/0x34
[ 361.997275] [<c104007b>] ? tick_device_uses_broadcast+0x71/0x7c
[ 361.997286] [<c11747a8>] ? acpi_idle_enter_simple+0x103/0x12e
[ 361.997296] [<c1174515>] acpi_idle_enter_bm+0xc3/0x253
[ 361.997306] [<c1238b6f>] cpuidle_idle_call+0x60/0x91
[ 361.997315] [<c1001d44>] cpu_idle+0x49/0x65
[ 361.997324] [<c12e2f0e>] start_secondary+0x190/0x195


Thanks,
Oliver

2009-10-02 11:01:10

by Dave Young

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

On Fri, Oct 2, 2009 at 2:28 PM, Oliver Hartkopp <[email protected]> wrote=
:
> Hello Marcel,
>
> with current net-2.6 tree ...
>
> While starting my PPP Bluetooth dialup networking, i got this:

Hi, oliver

please try following patch:
http://patchwork.kernel.org/patch/51326/

>
> [ =C2=A0722.461549] PPP generic driver version 2.4.2
> [ =C2=A0722.477519] BUG: sleeping function called from invalid context at
> mm/slub.c:1719
> [ =C2=A0722.477530] in_atomic(): 1, irqs_disabled(): 0, pid: 4677, name: =
pppd
> [ =C2=A0722.477537] 3 locks held by pppd/4677:
> [ =C2=A0722.477542] =C2=A0#0: =C2=A0(rfcomm_mutex){+.+.+.}, at: [<fa5df2a=
1>]
> rfcomm_dlc_open+0x28/0x2d6 [rfcomm]
> [ =C2=A0722.477568] =C2=A0#1: =C2=A0(sk_lock-AF_BLUETOOTH-BTPROTO_L2CAP){=
+.+.+.}, at:
> [<fa5414f8>] l2cap_sock_connect+0x62/0x2c6 [l2cap]
> [ =C2=A0722.477589] =C2=A0#2: =C2=A0(&hdev->lock){+...+.}, at: [<fa5415b4=
>]
> l2cap_sock_connect+0x11e/0x2c6 [l2cap]
> [ =C2=A0722.477613] Pid: 4677, comm: pppd Not tainted 2.6.31-08939-gdb8ab=
ec-dirty #21
> [ =C2=A0722.477619] Call Trace:
> [ =C2=A0722.477633] =C2=A0[<c1042a2b>] ? __debug_show_held_locks+0x1e/0x2=
0
> [ =C2=A0722.477644] =C2=A0[<c10212a1>] __might_sleep+0xc9/0xce
> [ =C2=A0722.477655] =C2=A0[<c1078b62>] __kmalloc+0x6d/0xfb
> [ =C2=A0722.477666] =C2=A0[<c119e739>] ? kzalloc+0xb/0xd
> [ =C2=A0722.477674] =C2=A0[<c119e739>] kzalloc+0xb/0xd
> [ =C2=A0722.477683] =C2=A0[<c119ef1a>] device_private_init+0x15/0x3d
> [ =C2=A0722.477693] =C2=A0[<c11a0e1b>] dev_set_drvdata+0x18/0x26
> [ =C2=A0722.477718] =C2=A0[<f8b7ca1b>] hci_conn_init_sysfs+0x3d/0xc7 [blu=
etooth]
> [ =C2=A0722.477737] =C2=A0[<f8b791b3>] hci_conn_add+0x1c0/0x1d5 [bluetoot=
h]
> [ =C2=A0722.477756] =C2=A0[<f8b79360>] hci_connect+0x71/0x17d [bluetooth]
> [ =C2=A0722.477769] =C2=A0[<fa54162c>] l2cap_sock_connect+0x196/0x2c6 [l2=
cap]
> [ =C2=A0722.477782] =C2=A0[<c1246e3d>] kernel_connect+0xd/0x12
> [ =C2=A0722.477795] =C2=A0[<fa5df3c3>] rfcomm_dlc_open+0x14a/0x2d6 [rfcom=
m]
> [ =C2=A0722.477810] =C2=A0[<fa5e10fa>] ? rfcomm_tty_open+0x73/0x227 [rfco=
mm]
> [ =C2=A0722.477825] =C2=A0[<fa5e1130>] rfcomm_tty_open+0xa9/0x227 [rfcomm=
]
> [ =C2=A0722.477836] =C2=A0[<c1022e3f>] ? default_wake_function+0x0/0xd
> [ =C2=A0722.477847] =C2=A0[<c1180c79>] tty_open+0x29e/0x399
> [ =C2=A0722.477858] =C2=A0[<c107e9bd>] chrdev_open+0x13f/0x156
> [ =C2=A0722.477868] =C2=A0[<c107b0d3>] __dentry_open+0x11b/0x20f
> [ =C2=A0722.477878] =C2=A0[<c107b261>] nameidata_to_filp+0x2c/0x43
> [ =C2=A0722.477888] =C2=A0[<c107e87e>] ? chrdev_open+0x0/0x156
> [ =C2=A0722.477898] =C2=A0[<c1084e9e>] do_filp_open+0x3c6/0x70a
> [ =C2=A0722.477910] =C2=A0[<c108d3e4>] ? alloc_fd+0xc8/0xd2
> [ =C2=A0722.477920] =C2=A0[<c108d3e4>] ? alloc_fd+0xc8/0xd2
> [ =C2=A0722.477930] =C2=A0[<c107aebc>] do_sys_open+0x4a/0xe7
> [ =C2=A0722.477940] =C2=A0[<c1002acc>] ? restore_all_notrace+0x0/0x18
> [ =C2=A0722.477950] =C2=A0[<c107af9b>] sys_open+0x1e/0x26
> [ =C2=A0722.477959] =C2=A0[<c1002a18>] sysenter_do_call+0x12/0x36
> [ =C2=A0729.658613] PPP BSD Compression module registered
> [ =C2=A0729.684789] PPP Deflate Compression module registered
>
> Any idea?
>
> Regards,
> Oliver
> --
> To unsubscribe from this list: send the line "unsubscribe linux-bluetooth=
" in
> the body of a message to [email protected]
> More majordomo info at =C2=A0http://vger.kernel.org/majordomo-info.html
>



--=20
Regards
dave

2009-10-02 09:52:16

by Oliver Hartkopp

[permalink] [raw]
Subject: Re: [BUG net-2.6] bluetooth/rfcomm : sleeping function called from invalid context at mm/slub.c:1719

It's a reproducible bug.

When creating a ppp dialup connection a second time there is a lockdep annotation:

[ 1477.716936] PPP generic driver version 2.4.2
[ 1477.738035] BUG: sleeping function called from invalid context at
mm/slub.c:1719
[ 1477.738046] in_atomic(): 1, irqs_disabled(): 0, pid: 5057, name: pppd
[ 1477.738053] 3 locks held by pppd/5057:
[ 1477.738058] #0: (rfcomm_mutex){+.+.+.}, at: [<fa5dd2a1>]
rfcomm_dlc_open+0x28/0x2d6 [rfcomm]
[ 1477.738083] #1: (sk_lock-AF_BLUETOOTH-BTPROTO_L2CAP){+.+.+.}, at:
[<fa53f4f8>] l2cap_sock_connect+0x62/0x2c6 [l2cap]
[ 1477.738105] #2: (&hdev->lock){+...+.}, at: [<fa53f5b4>]
l2cap_sock_connect+0x11e/0x2c6 [l2cap]
[ 1477.738129] Pid: 5057, comm: pppd Not tainted 2.6.31-08939-gdb8abec-dirty #21
[ 1477.738135] Call Trace:
[ 1477.738148] [<c1042a2b>] ? __debug_show_held_locks+0x1e/0x20
[ 1477.738160] [<c10212a1>] __might_sleep+0xc9/0xce
[ 1477.738171] [<c1078b62>] __kmalloc+0x6d/0xfb
[ 1477.738181] [<c119e739>] ? kzalloc+0xb/0xd
[ 1477.738190] [<c119e739>] kzalloc+0xb/0xd
[ 1477.738199] [<c119ef1a>] device_private_init+0x15/0x3d
[ 1477.738209] [<c11a0e1b>] dev_set_drvdata+0x18/0x26
[ 1477.738233] [<f88f9a1b>] hci_conn_init_sysfs+0x3d/0xc7 [bluetooth]
[ 1477.738253] [<f88f61b3>] hci_conn_add+0x1c0/0x1d5 [bluetooth]
[ 1477.738271] [<f88f6360>] hci_connect+0x71/0x17d [bluetooth]
[ 1477.738285] [<fa53f62c>] l2cap_sock_connect+0x196/0x2c6 [l2cap]
[ 1477.738298] [<c1246e3d>] kernel_connect+0xd/0x12
[ 1477.738311] [<fa5dd3c3>] rfcomm_dlc_open+0x14a/0x2d6 [rfcomm]
[ 1477.738326] [<fa5df0fa>] ? rfcomm_tty_open+0x73/0x227 [rfcomm]
[ 1477.738341] [<fa5df130>] rfcomm_tty_open+0xa9/0x227 [rfcomm]
[ 1477.738352] [<c1022e3f>] ? default_wake_function+0x0/0xd
[ 1477.738363] [<c1180c79>] tty_open+0x29e/0x399
[ 1477.738374] [<c107e9bd>] chrdev_open+0x13f/0x156
[ 1477.738384] [<c107b0d3>] __dentry_open+0x11b/0x20f
[ 1477.738394] [<c107b261>] nameidata_to_filp+0x2c/0x43
[ 1477.738403] [<c107e87e>] ? chrdev_open+0x0/0x156
[ 1477.738414] [<c1084e9e>] do_filp_open+0x3c6/0x70a
[ 1477.738426] [<c108d3e4>] ? alloc_fd+0xc8/0xd2
[ 1477.738436] [<c108d3e4>] ? alloc_fd+0xc8/0xd2
[ 1477.738446] [<c107aebc>] do_sys_open+0x4a/0xe7
[ 1477.738456] [<c1002acc>] ? restore_all_notrace+0x0/0x18
[ 1477.738466] [<c107af9b>] sys_open+0x1e/0x26
[ 1477.738475] [<c1002a18>] sysenter_do_call+0x12/0x36
[ 1484.844933] PPP BSD Compression module registered
[ 1484.870946] PPP Deflate Compression module registered
[ 4335.008503] CE: hpet increasing min_delta_ns to 15000 nsec
[ 7605.540870] INFO: trying to register non-static key.
[ 7605.540879] the code is fine but needs lockdep annotation.
[ 7605.540884] turning off the locking correctness validator.
[ 7605.540894] Pid: 0, comm: swapper Not tainted 2.6.31-08939-gdb8abec-dirty #21
[ 7605.540900] Call Trace:
[ 7605.540915] [<c12e4fb2>] ? printk+0xf/0x11
[ 7605.540928] [<c1042214>] register_lock_class+0x5a/0x295
[ 7605.540939] [<c1043af2>] __lock_acquire+0x9b/0xc03
[ 7605.540949] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
[ 7605.540967] [<fa53b168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
[ 7605.540977] [<c104491f>] ? lock_release_non_nested+0x17b/0x1db
[ 7605.540990] [<fa53b168>] ? l2cap_get_chan_by_scid+0x35/0x43 [l2cap]
[ 7605.541001] [<c10426fd>] ? trace_hardirqs_off+0xb/0xd
[ 7605.541010] [<c10446b6>] lock_acquire+0x5c/0x73
[ 7605.541021] [<c124cd14>] ? skb_dequeue+0x12/0x4c
[ 7605.541031] [<c12e6e23>] _spin_lock_irqsave+0x24/0x34
[ 7605.541039] [<c124cd14>] ? skb_dequeue+0x12/0x4c
[ 7605.541048] [<c124cd14>] skb_dequeue+0x12/0x4c
[ 7605.541057] [<c124d579>] skb_queue_purge+0x14/0x1b
[ 7605.541070] [<fa53de3f>] l2cap_recv_frame+0xe9e/0x129a [l2cap]
[ 7605.541080] [<c10421d1>] ? register_lock_class+0x17/0x295
[ 7605.541091] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
[ 7605.541114] [<c104464b>] ? __lock_acquire+0xbf4/0xc03
[ 7605.541125] [<c120de74>] ? uhci_giveback_urb+0xf2/0x162
[ 7605.541148] [<f88f4c45>] ? hci_rx_task+0xfe/0x1f8 [bluetooth]
[ 7605.541162] [<fa53e2e4>] l2cap_recv_acldata+0xa9/0x1be [l2cap]
[ 7605.541174] [<fa53e23b>] ? l2cap_recv_acldata+0x0/0x1be [l2cap]
[ 7605.541193] [<f88f4c77>] hci_rx_task+0x130/0x1f8 [bluetooth]
[ 7605.541204] [<c102a098>] tasklet_action+0x6b/0xb2
[ 7605.541213] [<c102a46b>] __do_softirq+0x82/0x101
[ 7605.541222] [<c102a515>] do_softirq+0x2b/0x43
[ 7605.541231] [<c102a619>] irq_exit+0x35/0x68
[ 7605.541241] [<c1004513>] do_IRQ+0x80/0x96
[ 7605.541250] [<c10030ae>] common_interrupt+0x2e/0x34
[ 7605.541260] [<c104007b>] ? tick_device_uses_broadcast+0x71/0x7c
[ 7605.541271] [<c11747a8>] ? acpi_idle_enter_simple+0x103/0x12e
[ 7605.541281] [<c1174515>] acpi_idle_enter_bm+0xc3/0x253
[ 7605.541291] [<c1238b6f>] cpuidle_idle_call+0x60/0x91
[ 7605.541300] [<c1001d44>] cpu_idle+0x49/0x65
[ 7605.541310] [<c12e2f0e>] start_secondary+0x190/0x195


Oliver Hartkopp wrote:
> Hello Marcel,
>
> with current net-2.6 tree ...
>
> While starting my PPP Bluetooth dialup networking, i got this:
>
> [ 722.461549] PPP generic driver version 2.4.2
> [ 722.477519] BUG: sleeping function called from invalid context at
> mm/slub.c:1719
> [ 722.477530] in_atomic(): 1, irqs_disabled(): 0, pid: 4677, name: pppd
> [ 722.477537] 3 locks held by pppd/4677:
> [ 722.477542] #0: (rfcomm_mutex){+.+.+.}, at: [<fa5df2a1>]
> rfcomm_dlc_open+0x28/0x2d6 [rfcomm]
> [ 722.477568] #1: (sk_lock-AF_BLUETOOTH-BTPROTO_L2CAP){+.+.+.}, at:
> [<fa5414f8>] l2cap_sock_connect+0x62/0x2c6 [l2cap]
> [ 722.477589] #2: (&hdev->lock){+...+.}, at: [<fa5415b4>]
> l2cap_sock_connect+0x11e/0x2c6 [l2cap]
> [ 722.477613] Pid: 4677, comm: pppd Not tainted 2.6.31-08939-gdb8abec-dirty #21
> [ 722.477619] Call Trace:
> [ 722.477633] [<c1042a2b>] ? __debug_show_held_locks+0x1e/0x20
> [ 722.477644] [<c10212a1>] __might_sleep+0xc9/0xce
> [ 722.477655] [<c1078b62>] __kmalloc+0x6d/0xfb
> [ 722.477666] [<c119e739>] ? kzalloc+0xb/0xd
> [ 722.477674] [<c119e739>] kzalloc+0xb/0xd
> [ 722.477683] [<c119ef1a>] device_private_init+0x15/0x3d
> [ 722.477693] [<c11a0e1b>] dev_set_drvdata+0x18/0x26
> [ 722.477718] [<f8b7ca1b>] hci_conn_init_sysfs+0x3d/0xc7 [bluetooth]
> [ 722.477737] [<f8b791b3>] hci_conn_add+0x1c0/0x1d5 [bluetooth]
> [ 722.477756] [<f8b79360>] hci_connect+0x71/0x17d [bluetooth]
> [ 722.477769] [<fa54162c>] l2cap_sock_connect+0x196/0x2c6 [l2cap]
> [ 722.477782] [<c1246e3d>] kernel_connect+0xd/0x12
> [ 722.477795] [<fa5df3c3>] rfcomm_dlc_open+0x14a/0x2d6 [rfcomm]
> [ 722.477810] [<fa5e10fa>] ? rfcomm_tty_open+0x73/0x227 [rfcomm]
> [ 722.477825] [<fa5e1130>] rfcomm_tty_open+0xa9/0x227 [rfcomm]
> [ 722.477836] [<c1022e3f>] ? default_wake_function+0x0/0xd
> [ 722.477847] [<c1180c79>] tty_open+0x29e/0x399
> [ 722.477858] [<c107e9bd>] chrdev_open+0x13f/0x156
> [ 722.477868] [<c107b0d3>] __dentry_open+0x11b/0x20f
> [ 722.477878] [<c107b261>] nameidata_to_filp+0x2c/0x43
> [ 722.477888] [<c107e87e>] ? chrdev_open+0x0/0x156
> [ 722.477898] [<c1084e9e>] do_filp_open+0x3c6/0x70a
> [ 722.477910] [<c108d3e4>] ? alloc_fd+0xc8/0xd2
> [ 722.477920] [<c108d3e4>] ? alloc_fd+0xc8/0xd2
> [ 722.477930] [<c107aebc>] do_sys_open+0x4a/0xe7
> [ 722.477940] [<c1002acc>] ? restore_all_notrace+0x0/0x18
> [ 722.477950] [<c107af9b>] sys_open+0x1e/0x26
> [ 722.477959] [<c1002a18>] sysenter_do_call+0x12/0x36
> [ 729.658613] PPP BSD Compression module registered
> [ 729.684789] PPP Deflate Compression module registered
>
> Any idea?
>
> Regards,
> Oliver
>