Re: [Bug 42754] New: BUG: sleeping function called from invalid context at mm/memory.c:3924

9 messages, 6 authors, 2012-02-16 · open the first message on its own page

Re: [Bug 42754] New: BUG: sleeping function called from invalid context at mm/memory.c:3924

From: Andrew Morton <akpm@linux-foundation.org>
Date: 2012-02-10 03:12:26 

(switched to email.  Please respond via emailed reply-to-all, not via the
bugzilla web interface).

(It's 3.3-rc2)

On Fri, 10 Feb 2012 02:24:10 GMT bugzilla-daemon@bugzilla.kernel.org wrote:

https://bugzilla.kernel.org/show_bug.cgi?id=42754

           Summary: BUG: sleeping function called from invalid context at
                    mm/memory.c:3924
           Product: Memory Management
           Version: 2.5
    Kernel Version: 3.3.0-rc2+
          Platform: All
        OS/Version: Linux
              Tree: Mainline
            Status: NEW
          Severity: high
          Priority: P1
         Component: Other
        AssignedTo: akpm@linux-foundation.org
        ReportedBy: baryluk@smp.if.uj.edu.pl
        Regression: Yes


Created an attachment (id=72350)
 --> (https://bugzilla.kernel.org/attachment.cgi?id=72350)
Konfig file

[    0.000000] Linux version 3.3.0-rc2-t43-devel-smp-00172-g23783f8
(baryluk@sredniczarny) (gcc version 4.6.2 (Debian 4.6.2-12) ) #13 SMP Sun Feb 5
15:37:06 CET 2012


[ 1203.050623] BUG: sleeping function called from invalid context at
mm/memory.c:3924
[ 1203.054259] in_atomic(): 1, irqs_disabled(): 0, pid: 4446, name:
NetworkManager
[ 1203.057932] INFO: lockdep is turned off.
[ 1203.061685] Pid: 4446, comm: NetworkManager Tainted: G        W  O
3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13
[ 1203.065606] Call Trace:
[ 1203.069502]  [<c107e182>] __might_sleep+0x122/0x1d0
[ 1203.073506]  [<c1140b4e>] might_fault+0x2e/0xb0
[ 1203.077501]  [<c131c67b>] copy_to_user+0x3b/0x60
[ 1203.081561]  [<c158a102>] put_cmsg+0x52/0xd0
[ 1203.085624]  [<c15bc7d7>] netlink_recvmsg+0x287/0x340
[ 1203.089740]  [<c1579b43>] sock_recvmsg+0xd3/0x110
[ 1203.093902]  [<c1140b74>] ? might_fault+0x54/0xb0
[ 1203.098093]  [<c158834c>] ? verify_iovec+0x4c/0xc0
[ 1203.102336]  [<c1579a70>] ? sock_sendmsg_nosec+0x100/0x100
[ 1203.106611]  [<c157a994>] __sys_recvmsg+0x114/0x1e0
[ 1203.110942]  [<c1081dc7>] ? finish_task_switch+0x77/0x200
[ 1203.115315]  [<c11784b5>] ? fget_light+0xc5/0x410
[ 1203.119722]  [<c1081dc7>] ? finish_task_switch+0x77/0x200
[ 1203.124167]  [<c11784c9>] ? fget_light+0xd9/0x410
[ 1203.128618]  [<c1178435>] ? fget_light+0x45/0x410
[ 1203.133102]  [<c157c659>] sys_recvmsg+0x39/0x60
[ 1203.137590]  [<c157cbb3>] sys_socketcall+0x2e3/0x330
[ 1203.142147]  [<c17cf58d>] ? sysenter_exit+0xf/0x1a
[ 1203.146707]  [<c131be78>] ? trace_hardirqs_on_thunk+0xc/0x10
[ 1203.151358]  [<c17cf558>] sysenter_do_call+0x12/0x38
[ 1203.155980] BUG: scheduling while atomic: NetworkManager/4446/0x10000002
[ 1203.160714] INFO: lockdep is turned off.
[ 1203.165429] Modules linked in: vfat fat pci_stub vboxpci(O) vboxnetadp(O)
vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables acpi_cpufreq mperf
xt_CHECKSUM irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep rfcomm
bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 radeon
ipw2200 libipw pcmcia_rsrc pcmcia_core ttm drm_kms_helper parport_pc parport
cfbfillrect cfbcopyarea cfbimgblt raid10 raid456 async_memcpy async_pq
async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom floppy [last
unloaded: scsi_wait_scan]

OK, so we have a pile of in_atomic warnings.  I assume the above was
the first to come out?  The third and following traces have a different
trace.

It might be a bug in the netlink code or thereabouts.  Or it might be that
some random unrelated piece of kernel code forgot to release a lock and
netlink was the first place where this was detected.

Peter, is there any way in which lockdep can help us find the culprit
in the second case?

Thanks.

Re: [Bug 42754] New: BUG: sleeping function called from invalid context at mm/memory.c:3924

From: Witold Baryluk <hidden>
Date: 2012-02-10 12:32:07 

On 02-09 19:13, Andrew Morton wrote:
(switched to email.  Please respond via emailed reply-to-all, not via the
bugzilla web interface).

(It's 3.3-rc2)

On Fri, 10 Feb 2012 02:24:10 GMT bugzilla-daemon@bugzilla.kernel.org wrote:
quoted
https://bugzilla.kernel.org/show_bug.cgi?id=42754

           Summary: BUG: sleeping function called from invalid context at
                    mm/memory.c:3924
           Product: Memory Management
           Version: 2.5
    Kernel Version: 3.3.0-rc2+
          Platform: All
        OS/Version: Linux
              Tree: Mainline
            Status: NEW
          Severity: high
          Priority: P1
         Component: Other
        AssignedTo: akpm@linux-foundation.org
        ReportedBy: baryluk@smp.if.uj.edu.pl
        Regression: Yes


Created an attachment (id=72350)
 --> (https://bugzilla.kernel.org/attachment.cgi?id=72350)
Konfig file

[    0.000000] Linux version 3.3.0-rc2-t43-devel-smp-00172-g23783f8
(baryluk@sredniczarny) (gcc version 4.6.2 (Debian 4.6.2-12) ) #13 SMP Sun Feb 5
15:37:06 CET 2012


[ 1203.050623] BUG: sleeping function called from invalid context at
mm/memory.c:3924
[ 1203.054259] in_atomic(): 1, irqs_disabled(): 0, pid: 4446, name:
NetworkManager
[ 1203.057932] INFO: lockdep is turned off.
[ 1203.061685] Pid: 4446, comm: NetworkManager Tainted: G        W  O
3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13
[ 1203.065606] Call Trace:
[ 1203.069502]  [<c107e182>] __might_sleep+0x122/0x1d0
[ 1203.073506]  [<c1140b4e>] might_fault+0x2e/0xb0
[ 1203.077501]  [<c131c67b>] copy_to_user+0x3b/0x60
[ 1203.081561]  [<c158a102>] put_cmsg+0x52/0xd0
[ 1203.085624]  [<c15bc7d7>] netlink_recvmsg+0x287/0x340
[ 1203.089740]  [<c1579b43>] sock_recvmsg+0xd3/0x110
[ 1203.093902]  [<c1140b74>] ? might_fault+0x54/0xb0
[ 1203.098093]  [<c158834c>] ? verify_iovec+0x4c/0xc0
[ 1203.102336]  [<c1579a70>] ? sock_sendmsg_nosec+0x100/0x100
[ 1203.106611]  [<c157a994>] __sys_recvmsg+0x114/0x1e0
[ 1203.110942]  [<c1081dc7>] ? finish_task_switch+0x77/0x200
[ 1203.115315]  [<c11784b5>] ? fget_light+0xc5/0x410
[ 1203.119722]  [<c1081dc7>] ? finish_task_switch+0x77/0x200
[ 1203.124167]  [<c11784c9>] ? fget_light+0xd9/0x410
[ 1203.128618]  [<c1178435>] ? fget_light+0x45/0x410
[ 1203.133102]  [<c157c659>] sys_recvmsg+0x39/0x60
[ 1203.137590]  [<c157cbb3>] sys_socketcall+0x2e3/0x330
[ 1203.142147]  [<c17cf58d>] ? sysenter_exit+0xf/0x1a
[ 1203.146707]  [<c131be78>] ? trace_hardirqs_on_thunk+0xc/0x10
[ 1203.151358]  [<c17cf558>] sysenter_do_call+0x12/0x38
[ 1203.155980] BUG: scheduling while atomic: NetworkManager/4446/0x10000002
[ 1203.160714] INFO: lockdep is turned off.
[ 1203.165429] Modules linked in: vfat fat pci_stub vboxpci(O) vboxnetadp(O)
vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables acpi_cpufreq mperf
xt_CHECKSUM irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep rfcomm
bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 radeon
ipw2200 libipw pcmcia_rsrc pcmcia_core ttm drm_kms_helper parport_pc parport
cfbfillrect cfbcopyarea cfbimgblt raid10 raid456 async_memcpy async_pq
async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom floppy [last
unloaded: scsi_wait_scan]

OK, so we have a pile of in_atomic warnings.  I assume the above was
the first to come out?  The third and following traces have a different
trace.

It might be a bug in the netlink code or thereabouts.  Or it might be that
some random unrelated piece of kernel code forgot to release a lock and
netlink was the first place where this was detected.

Peter, is there any way in which lockdep can help us find the culprit
in the second case?

Thanks.

Well, there is few problems before this message, they are already reported:

https://bugzilla.kernel.org/show_bug.cgi?id=42742  (cpu_idle warning)
https://bugzilla.kernel.org/show_bug.cgi?id=42741  (sirdev DEADLOCK - second one is DEADLOCK warning, and it actually triggers real deadlock, but not on this boot)

but they are somehow unreleated.

Immiedietly before BUG I have
[  592.952374] PM: Adding info for No Bus:0:52

so pretty nothing for long time. System wasn't really loaded or anything,
it just happened. There was not suspend/resume cycles or anything.

This is IBM ThinkPad T43 (Pentium-M 32 bit), and it had fresh boot 20
minutes before this happened.

Bellow dmesg are same as boot above

cpuidle looks like this:

[   16.960579] Testing event cpu_idle: 
[   16.961306] ------------[ cut here ]------------
[   16.961316] WARNING: at include/linux/rcupdate.h:242 __atomic_notifier_call_chain+0xbc/0xf0()
[   16.961319] Hardware name: 2669UYD
[   16.961321] Modules linked in:
[   16.961326] Pid: 0, comm: swapper/0 Not tainted 3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13
[   16.961329] Call Trace:
[   16.961337]  [<c104a372>] warn_slowpath_common+0x72/0xa0
[   16.961341]  [<c17cb41c>] ? __atomic_notifier_call_chain+0xbc/0xf0
[   16.961346]  [<c17cb41c>] ? __atomic_notifier_call_chain+0xbc/0xf0
[   16.961350]  [<c104a3c0>] warn_slowpath_null+0x20/0x30
[   16.961355]  [<c17cb41c>] __atomic_notifier_call_chain+0xbc/0xf0
[   16.961360]  [<c136056e>] ? vgacon_scroll+0x5e/0x60
[   16.961365]  [<c17cb46f>] atomic_notifier_call_chain+0x1f/0x30
[   16.961371]  [<c13cdf23>] notify_write+0x23/0x30
[   16.961375]  [<c13cdf7f>] lf+0x4f/0x70
[   16.961379]  [<c13cefb9>] vt_console_print+0x249/0x380
[   16.961384]  [<c13ced70>] ? con_shutdown+0x40/0x40
[   16.961389]  [<c104a4fd>] __call_console_drivers+0x7d/0xa0
[   16.961393]  [<c104a6ec>] _call_console_drivers+0x4c/0x90
[   16.961398]  [<c104a94d>] call_console_drivers+0xdd/0x110
[   16.961402]  [<c104aa47>] console_unlock+0x77/0x170
[   16.961407]  [<c104accb>] vprintk+0x18b/0x490
[   16.961414]  [<c17b11a8>] printk+0x1d/0x1f
[   16.961420]  [<c10af9e2>] lockdep_rcu_suspicious+0x22/0xe0
[   16.961427]  [<c150db78>] cpuidle_idle_call+0x238/0x300
[   16.961433]  [<c10158df>] cpu_idle+0x6f/0xc0
[   16.961439]  [<c1795caa>] rest_init+0x11e/0x124
[   16.961443]  [<c1795bf3>] ? rest_init+0x67/0x124
[   16.961450]  [<c1b5a76e>] start_kernel+0x325/0x32b
[   16.961454]  [<c1b5a25a>] ? obsolete_checksetup+0x95/0x95
[   16.961459]  [<c1b5a11e>] ? reserve_ebda_region+0x6b/0x6d
[   16.961463]  [<c1b5a0ac>] i386_start_kernel+0x9b/0xa2
[   16.961466] ---[ end trace d284d408f7ee228c ]---
[   16.961468] ------------[ cut here ]------------
[   16.961472] WARNING: at include/linux/rcupdate.h:248 __atomic_notifier_call_chain+0xe0/0xf0()
[   16.961475] Hardware name: 2669UYD
[   16.961477] Modules linked in:
[   16.961481] Pid: 0, comm: swapper/0 Tainted: G        W    3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13
[   16.961483] Call Trace:
[   16.961488]  [<c104a372>] warn_slowpath_common+0x72/0xa0
[   16.961492]  [<c17cb440>] ? __atomic_notifier_call_chain+0xe0/0xf0
[   16.961496]  [<c17cb440>] ? __atomic_notifier_call_chain+0xe0/0xf0
[   16.961501]  [<c104a3c0>] warn_slowpath_null+0x20/0x30
[   16.961505]  [<c17cb440>] __atomic_notifier_call_chain+0xe0/0xf0
[   16.961509]  [<c17cb387>] ? __atomic_notifier_call_chain+0x27/0xf0
[   16.961514]  [<c17cb46f>] atomic_notifier_call_chain+0x1f/0x30
[   16.961518]  [<c13cdf23>] notify_write+0x23/0x30
[   16.961522]  [<c13cdf7f>] lf+0x4f/0x70
[   16.961527]  [<c13cefb9>] vt_console_print+0x249/0x380
[   16.961532]  [<c13ced70>] ? con_shutdown+0x40/0x40
[   16.961536]  [<c104a4fd>] __call_console_drivers+0x7d/0xa0
[   16.961540]  [<c104a6ec>] _call_console_drivers+0x4c/0x90
[   16.961545]  [<c104a94d>] call_console_drivers+0xdd/0x110
[   16.961549]  [<c104aa47>] console_unlock+0x77/0x170
[   16.961554]  [<c104accb>] vprintk+0x18b/0x490
[   16.961559]  [<c17b11a8>] printk+0x1d/0x1f
[   16.961563]  [<c10af9e2>] lockdep_rcu_suspicious+0x22/0xe0
[   16.961568]  [<c150db78>] cpuidle_idle_call+0x238/0x300
[   16.961573]  [<c10158df>] cpu_idle+0x6f/0xc0
[   16.961577]  [<c1795caa>] rest_init+0x11e/0x124
[   16.961581]  [<c1795bf3>] ? rest_init+0x67/0x124
[   16.961585]  [<c1b5a76e>] start_kernel+0x325/0x32b
[   16.961590]  [<c1b5a25a>] ? obsolete_checksetup+0x95/0x95
[   16.961594]  [<c1b5a11e>] ? reserve_ebda_region+0x6b/0x6d
[   16.961599]  [<c1b5a0ac>] i386_start_kernel+0x9b/0xa2
[   16.961601] ---[ end trace d284d408f7ee228d ]---
[   16.965103] ===============================
[   16.965156] [ INFO: suspicious RCU usage. ]
[   16.965209] 3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13 Tainted: G        W   
[   16.965268] -------------------------------
[   16.965321] include/trace/events/power.h:35 suspicious rcu_dereference_check() usage!
[   16.965409] 
[   16.965410] other info that might help us debug this:
[   16.965411] 
[   16.965556] 
[   16.965556] rcu_scheduler_active = 1, debug_locks = 1
[   16.965656] RCU used illegally from extended quiescent state!
[   16.965711] no locks held by swapper/0/0.
[   16.965764] 
[   16.965764] stack backtrace:
[   16.965861] Pid: 0, comm: swapper/0 Tainted: G        W    3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13
[   16.965951] Call Trace:
[   16.966003]  [<c17b11a8>] ? printk+0x1d/0x1f
[   16.966059]  [<c10afa78>] lockdep_rcu_suspicious+0xb8/0xe0
[   16.966118]  [<c150db78>] cpuidle_idle_call+0x238/0x300
[   16.966175]  [<c10158df>] cpu_idle+0x6f/0xc0
[   16.966231]  [<c1795caa>] rest_init+0x11e/0x124
[   16.966287]  [<c1795bf3>] ? rest_init+0x67/0x124
[   16.966344]  [<c1b5a76e>] start_kernel+0x325/0x32b
[   16.966400]  [<c1b5a25a>] ? obsolete_checksetup+0x95/0x95
[   16.966458]  [<c1b5a11e>] ? reserve_ebda_region+0x6b/0x6d
[   16.966516]  [<c1b5a0ac>] i386_start_kernel+0x9b/0xa2
[   16.980655] OK
[   16.980705] Testing event cpu_frequency: OK



And sirdev problem looks like this:


[  177.805346] irda_init()
[  177.805617] NET: Registered protocol family 23
[  177.853523] warning: `hipd' uses 32-bit capabilities (legacy support in use)
[  178.014559] sirdev_get_instance - ttyS1
[  178.014689] device: 'irda0': device_add
[  178.014943] PM: Adding info for No Bus:irda0
[  178.060888] irtty_open - ttyS1: irda line discipline opened
[  178.412690] alg: No test for authenc(hmac(sha1),cbc(aes)) (authenc(hmac(sha1-generic),cbc(aes-asm)))
[  179.070690] irlap_change_speed(), setting speed to 9600
[  182.070664] 
[  182.073284] ======================================================
[  182.075969] [ INFO: possible circular locking dependency detected ]
[  182.078702] 3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13 Tainted: G        W   
[  182.080017] -------------------------------------------------------
[  182.080017] irq/3-serial/5887 is trying to acquire lock:
[  182.080017]  (&(&dev->tx_lock)->rlock){..-...}, at: [<f869a883>] sirdev_write_complete+0x23/0x280 [sir_dev]
[  182.080017] 
[  182.080017] but task is already holding lock:
[  182.080017]  (&port_lock_key){..-...}, at: [<c13dc0f7>] serial8250_handle_irq+0x37/0xa0
[  182.080017] 
[  182.080017] which lock already depends on the new lock.
[  182.080017] 
[  182.080017] 
[  182.080017] the existing dependency chain (in reverse order) is:
[  182.080017] 
[  182.080017] -> #1 (&port_lock_key){..-...}:
[  182.080017]        [<c10b0f1b>] check_prevs_add+0xcb/0x120
[  182.080017]        [<c10b14c7>] validate_chain.isra.34+0x557/0x6d0
[  182.080017]        [<c10b3945>] __lock_acquire+0x355/0x820
[  182.080017]        [<c10b4467>] lock_acquire+0x87/0x1b0
[  182.080017]        [<c17c762e>] _raw_spin_lock_irqsave+0x5e/0xa0
[  182.080017]        [<c13d5f32>] uart_write_room+0x22/0x60
[  182.080017]        [<c13c1c19>] tty_write_room+0x19/0x20
[  182.080017]        [<f876b512>] irtty_do_write+0x42/0xa0 [irtty_sir]
[  182.080017]        [<f869a455>] sirdev_hard_xmit+0xc5/0x280 [sir_dev]
[  182.080017]        [<c159586f>] dev_hard_start_xmit+0x22f/0x690
[  182.080017]        [<c15ba331>] sch_direct_xmit+0xa1/0x220
[  182.080017]        [<c1595e45>] dev_queue_xmit+0x175/0x770
[  182.080017]        [<f878e62a>] irlap_queue_xmit+0x9a/0xe0 [irda]
[  182.080017]        [<f878ebeb>] irlap_send_discovery_xid_frame+0xdb/0x360 [irda]
[  182.080017]        [<f878ca68>] irlap_state_ndm+0x308/0x4e0 [irda]
[  182.080017]        [<f878cd7b>] irlap_do_event+0x4b/0xb0 [irda]
[  182.080017]        [<f878964a>] irlap_discovery_request+0xda/0x230 [irda]
[  182.080017]        [<f8786168>] irlmp_state_standby+0x78/0x170 [irda]
[  182.080017]        [<f8786b59>] irlmp_do_lap_event+0x39/0xe0 [irda]
[  182.080017]        [<f878546c>] irlmp_do_discovery+0xac/0x140 [irda]
[  182.080017]        [<f8787603>] irlmp_discovery_timer_expired+0x23/0x60 [irda]
[  182.080017]        [<c105abad>] call_timer_fn+0x6d/0x2e0
[  182.080017]        [<c105af0a>] run_timer_softirq+0xea/0x260
[  182.080017]        [<c10524cf>] __do_softirq+0x9f/0x360
[  182.080017]        [<c1052887>] run_ksoftirqd+0xf7/0x1b0
[  182.080017]        [<c10721f2>] kthread+0x72/0x80
[  182.080017]        [<c17cfafa>] kernel_thread_helper+0x6/0x10
[  182.080017] 
[  182.080017] -> #0 (&(&dev->tx_lock)->rlock){..-...}:
[  182.080017]        [<c10b0e45>] check_prev_add+0x605/0x610
[  182.080017]        [<c10b0f1b>] check_prevs_add+0xcb/0x120
[  182.080017]        [<c10b14c7>] validate_chain.isra.34+0x557/0x6d0
[  182.080017]        [<c10b3945>] __lock_acquire+0x355/0x820
[  182.080017]        [<c10b4467>] lock_acquire+0x87/0x1b0
[  182.080017]        [<c17c762e>] _raw_spin_lock_irqsave+0x5e/0xa0
[  182.080017]        [<f869a883>] sirdev_write_complete+0x23/0x280 [sir_dev]
[  182.080017]        [<f876b671>] irtty_write_wakeup+0x31/0x90 [irtty_sir]
[  182.080017]        [<c13ba332>] tty_wakeup+0x62/0x70
[  182.080017]        [<c13d7686>] uart_write_wakeup+0x16/0x20
[  182.080017]        [<c13daffe>] serial8250_tx_chars+0x8e/0x110
[  182.080017]        [<c13dc157>] serial8250_handle_irq+0x97/0xa0
[  182.080017]        [<c13dc17c>] serial8250_default_handle_irq+0x1c/0x20
[  182.080017]        [<c13da1e5>] serial8250_interrupt+0x65/0xd0
[  182.080017]        [<c10dfa26>] irq_forced_thread_fn+0x26/0x50
[  182.080017]        [<c10df932>] irq_thread+0x152/0x1e0
[  182.080017]        [<c10721f2>] kthread+0x72/0x80
[  182.080017]        [<c17cfafa>] kernel_thread_helper+0x6/0x10
[  182.080017] 
[  182.080017] other info that might help us debug this:
[  182.080017] 
[  182.080017]  Possible unsafe locking scenario:
[  182.080017] 
[  182.080017]        CPU0                    CPU1
[  182.080017]        ----                    ----
[  182.080017]   lock(&port_lock_key);
[  182.080017]                                lock(&(&dev->tx_lock)->rlock);
[  182.080017]                                lock(&port_lock_key);
[  182.080017]   lock(&(&dev->tx_lock)->rlock);
[  182.080017] 
[  182.080017]  *** DEADLOCK ***
[  182.080017] 
[  182.080017] 2 locks held by irq/3-serial/5887:
[  182.080017]  #0:  (&(&i->lock)->rlock){+.....}, at: [<c13da1a3>] serial8250_interrupt+0x23/0xd0
[  182.080017]  #1:  (&port_lock_key){..-...}, at: [<c13dc0f7>] serial8250_handle_irq+0x37/0xa0
[  182.080017] 
[  182.080017] stack backtrace:
[  182.080017] Pid: 5887, comm: irq/3-serial Tainted: G        W    3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13
[  182.080017] Call Trace:
[  182.080017]  [<c17b11a8>] ? printk+0x1d/0x1f
[  182.080017]  [<c17b2506>] print_circular_bug+0xa7/0xb1
[  182.080017]  [<c10b0e45>] check_prev_add+0x605/0x610
[  182.080017]  [<c10b0f1b>] check_prevs_add+0xcb/0x120
[  182.080017]  [<c10b14c7>] validate_chain.isra.34+0x557/0x6d0
[  182.080017]  [<c10b3945>] __lock_acquire+0x355/0x820
[  182.080017]  [<c10b4467>] lock_acquire+0x87/0x1b0
[  182.080017]  [<f869a883>] ? sirdev_write_complete+0x23/0x280 [sir_dev]
[  182.080017]  [<c17c75f9>] ? _raw_spin_lock_irqsave+0x29/0xa0
[  182.080017]  [<c17c762e>] _raw_spin_lock_irqsave+0x5e/0xa0
[  182.080017]  [<f869a883>] ? sirdev_write_complete+0x23/0x280 [sir_dev]
[  182.080017]  [<f869a883>] sirdev_write_complete+0x23/0x280 [sir_dev]
[  182.080017]  [<c10aea1b>] ? trace_hardirqs_off+0xb/0x10
[  182.080017]  [<f876b671>] irtty_write_wakeup+0x31/0x90 [irtty_sir]
[  182.080017]  [<c13c2991>] ? tty_ldisc_try+0x41/0x50
[  182.080017]  [<c13c29ad>] ? tty_ldisc_ref+0xd/0x10
[  182.080017]  [<c13ba332>] tty_wakeup+0x62/0x70
[  182.080017]  [<c13d7686>] uart_write_wakeup+0x16/0x20
[  182.080017]  [<c13daffe>] serial8250_tx_chars+0x8e/0x110
[  182.080017]  [<c13dc157>] serial8250_handle_irq+0x97/0xa0
[  182.080017]  [<c13dc17c>] serial8250_default_handle_irq+0x1c/0x20
[  182.080017]  [<c13da1e5>] serial8250_interrupt+0x65/0xd0
[  182.080017]  [<c108580b>] ? get_parent_ip+0xb/0x40
[  182.080017]  [<c10dfa26>] irq_forced_thread_fn+0x26/0x50
[  182.080017]  [<c10df932>] irq_thread+0x152/0x1e0
[  182.080017]  [<c10dfa00>] ? irq_thread_fn+0x40/0x40
[  182.080017]  [<c10df7e0>] ? irq_finalize_oneshot+0x20/0x20
[  182.080017]  [<c10721f2>] kthread+0x72/0x80
[  182.080017]  [<c1072180>] ? __init_kthread_worker+0x60/0x60
[  182.080017]  [<c17cfafa>] kernel_thread_helper+0x6/0x10


But I do not see how this locks can any problem.

I do not know why lockdep is disabled, because I configured kernel to
keep telling my about lock dependency problems even after showing first
one. AFAIK.

As of VirtualBox modules, they were not used for anything, just loaded.

Regards,
Witek




-- 
Witold Baryluk

Re: [Bug 42754] New: BUG: sleeping function called from invalid context at mm/memory.c:3924

From: Peter Zijlstra <hidden>
Date: 2012-02-10 15:38:18 

On Thu, 2012-02-09 at 19:13 -0800, Andrew Morton wrote:
quoted
[ 1203.050623] BUG: sleeping function called from invalid context at
mm/memory.c:3924
[ 1203.054259] in_atomic(): 1, irqs_disabled(): 0, pid: 4446, name:
NetworkManager
[ 1203.057932] INFO: lockdep is turned off.
This here should have been a listing of all held locks when this
happened, however due to an earlier error lockdep has already been
disabled (means it stops tracking state and printing anything would be
printing nonsense).

This suggests this isn't the first error hit.
quoted
[ 1203.061685] Pid: 4446, comm: NetworkManager Tainted: G        W  O
3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13
[ 1203.065606] Call Trace:
[ 1203.069502]  [<c107e182>] __might_sleep+0x122/0x1d0
[ 1203.073506]  [<c1140b4e>] might_fault+0x2e/0xb0
[ 1203.077501]  [<c131c67b>] copy_to_user+0x3b/0x60
[ 1203.081561]  [<c158a102>] put_cmsg+0x52/0xd0
[ 1203.085624]  [<c15bc7d7>] netlink_recvmsg+0x287/0x340
[ 1203.089740]  [<c1579b43>] sock_recvmsg+0xd3/0x110
[ 1203.093902]  [<c1140b74>] ? might_fault+0x54/0xb0
[ 1203.098093]  [<c158834c>] ? verify_iovec+0x4c/0xc0
[ 1203.102336]  [<c1579a70>] ? sock_sendmsg_nosec+0x100/0x100
[ 1203.106611]  [<c157a994>] __sys_recvmsg+0x114/0x1e0
[ 1203.110942]  [<c1081dc7>] ? finish_task_switch+0x77/0x200
[ 1203.115315]  [<c11784b5>] ? fget_light+0xc5/0x410
[ 1203.119722]  [<c1081dc7>] ? finish_task_switch+0x77/0x200
[ 1203.124167]  [<c11784c9>] ? fget_light+0xd9/0x410
[ 1203.128618]  [<c1178435>] ? fget_light+0x45/0x410
[ 1203.133102]  [<c157c659>] sys_recvmsg+0x39/0x60
[ 1203.137590]  [<c157cbb3>] sys_socketcall+0x2e3/0x330
[ 1203.142147]  [<c17cf58d>] ? sysenter_exit+0xf/0x1a
[ 1203.146707]  [<c131be78>] ? trace_hardirqs_on_thunk+0xc/0x10
[ 1203.151358]  [<c17cf558>] sysenter_do_call+0x12/0x38
Peter, is there any way in which lockdep can help us find the culprit
in the second case? 





  

    
Re: [Bug 42754] New: BUG: sleeping function called from invalid context at mm/memory.c:3924

    

      From: Peter Zijlstra <hidden>

      Date: 2012-02-10 15:39:48 
    

  

  
On Fri, 2012-02-10 at 13:26 +0100, Witold Baryluk wrote:
Well, there is few problems before this message, they are already
reported:
Never report a bug if it isn't the first -- yes it might be a real
problem, but once we go splat you simply shouldn't trust the state of
your system. Fix that problem, then get on with the next.





  

    
Re: [Bug 42754] New: BUG: sleeping function called from invalid context at mm/memory.c:3924

    

      From: Francois Romieu <romieu@fr.zoreil.com>

      Date: 2012-02-10 16:42:39 
    

  

  
Witold Baryluk [off-list ref] :
On 02-09 19:13, Andrew Morton wrote:
[...]
https://bugzilla.kernel.org/show_bug.cgi?id=42754
For the sirdev part:

[...]
[  182.080017] -> #1 (&port_lock_key){..-...}:
[  182.080017]        [<c10b0f1b>] check_prevs_add+0xcb/0x120
[  182.080017]        [<c10b14c7>] validate_chain.isra.34+0x557/0x6d0
[  182.080017]        [<c10b3945>] __lock_acquire+0x355/0x820
[  182.080017]        [<c10b4467>] lock_acquire+0x87/0x1b0
[  182.080017]        [<c17c762e>] _raw_spin_lock_irqsave+0x5e/0xa0
[  182.080017]        [<c13d5f32>] uart_write_room+0x22/0x60
[  182.080017]        [<c13c1c19>] tty_write_room+0x19/0x20
[  182.080017]        [<f876b512>] irtty_do_write+0x42/0xa0 [irtty_sir]
[  182.080017]        [<f869a455>] sirdev_hard_xmit+0xc5/0x280 [sir_dev]
This is dev->drv->do_write in sirdev_hard_xmit.

[  182.080017]        [<c159586f>] dev_hard_start_xmit+0x22f/0x690
[  182.080017]        [<c15ba331>] sch_direct_xmit+0xa1/0x220
[  182.080017]        [<c1595e45>] dev_queue_xmit+0x175/0x770
[  182.080017]        [<f878e62a>] irlap_queue_xmit+0x9a/0xe0 [irda]
[...]
[  182.080017]        [<f8787603>] irlmp_discovery_timer_expired+0x23/0x60 [irda]
[  182.080017]        [<c105abad>] call_timer_fn+0x6d/0x2e0
[  182.080017]        [<c105af0a>] run_timer_softirq+0xea/0x260
[  182.080017]        [<c10524cf>] __do_softirq+0x9f/0x360
[...]
[  182.080017] -> #0 (&(&dev->tx_lock)->rlock){..-...}:
[  182.080017]        [<c10b0e45>] check_prev_add+0x605/0x610
[  182.080017]        [<c10b0f1b>] check_prevs_add+0xcb/0x120
[  182.080017]        [<c10b14c7>] validate_chain.isra.34+0x557/0x6d0
[  182.080017]        [<c10b3945>] __lock_acquire+0x355/0x820
[  182.080017]        [<c10b4467>] lock_acquire+0x87/0x1b0
[  182.080017]        [<c17c762e>] _raw_spin_lock_irqsave+0x5e/0xa0
[  182.080017]        [<f869a883>] sirdev_write_complete+0x23/0x280 [sir_dev]
[  182.080017]        [<f876b671>] irtty_write_wakeup+0x31/0x90 [irtty_sir]
[  182.080017]        [<c13ba332>] tty_wakeup+0x62/0x70
[  182.080017]        [<c13d7686>] uart_write_wakeup+0x16/0x20
[  182.080017]        [<c13daffe>] serial8250_tx_chars+0x8e/0x110
[  182.080017]        [<c13dc157>] serial8250_handle_irq+0x97/0xa0
[  182.080017]        [<c13dc17c>] serial8250_default_handle_irq+0x1c/0x20
[  182.080017]        [<c13da1e5>] serial8250_interrupt+0x65/0xd0
[  182.080017]        [<c10dfa26>] irq_forced_thread_fn+0x26/0x50
[  182.080017]        [<c10df932>] irq_thread+0x152/0x1e0
[  182.080017]        [<c10721f2>] kthread+0x72/0x80
[  182.080017]        [<c17cfafa>] kernel_thread_helper+0x6/0x10
[...]
[  182.080017]  Possible unsafe locking scenario:
[  182.080017] 
[  182.080017]        CPU0                    CPU1
[  182.080017]        ----                    ----
[  182.080017]   lock(&port_lock_key);
[  182.080017]                                lock(&(&dev->tx_lock)->rlock);
[  182.080017]                                lock(&port_lock_key);
[  182.080017]   lock(&(&dev->tx_lock)->rlock);
[  182.080017] 
[  182.080017]  *** DEADLOCK ***
Once this tx_lock vs port_lock_key deadlock is fixed, there should be
a recursive port_lock_key deadlock through sirdev_write_complete own
dev->drv->do_write.

Paul, Alan, any hindsight about what the sirdev layer should do (or
avoid) regarding the latter ?

-- 
Ueimor





  

    
Re: [Bug 42754] New: BUG: sleeping function called from invalid context at mm/memory.c:3924

    

      From: Paul E. McKenney <hidden>

      Date: 2012-02-12 17:50:12 
    

  

  
On Fri, Feb 10, 2012 at 01:26:57PM +0100, Witold Baryluk wrote:
On 02-09 19:13, Andrew Morton wrote:
quoted
(switched to email.  Please respond via emailed reply-to-all, not via the
bugzilla web interface).

(It's 3.3-rc2)

On Fri, 10 Feb 2012 02:24:10 GMT bugzilla-daemon@bugzilla.kernel.org wrote:

quoted
https://bugzilla.kernel.org/show_bug.cgi?id=42754

           Summary: BUG: sleeping function called from invalid context at
                    mm/memory.c:3924
           Product: Memory Management
           Version: 2.5
    Kernel Version: 3.3.0-rc2+
          Platform: All
        OS/Version: Linux
              Tree: Mainline
            Status: NEW
          Severity: high
          Priority: P1
         Component: Other
        AssignedTo: akpm@linux-foundation.org
        ReportedBy: baryluk@smp.if.uj.edu.pl
        Regression: Yes


Created an attachment (id=72350)
 --> (https://bugzilla.kernel.org/attachment.cgi?id=72350)
Konfig file

[    0.000000] Linux version 3.3.0-rc2-t43-devel-smp-00172-g23783f8
(baryluk@sredniczarny) (gcc version 4.6.2 (Debian 4.6.2-12) ) #13 SMP Sun Feb 5
15:37:06 CET 2012


[ 1203.050623] BUG: sleeping function called from invalid context at
mm/memory.c:3924
[ 1203.054259] in_atomic(): 1, irqs_disabled(): 0, pid: 4446, name:
NetworkManager
[ 1203.057932] INFO: lockdep is turned off.
[ 1203.061685] Pid: 4446, comm: NetworkManager Tainted: G        W  O
3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13
[ 1203.065606] Call Trace:
[ 1203.069502]  [<c107e182>] __might_sleep+0x122/0x1d0
[ 1203.073506]  [<c1140b4e>] might_fault+0x2e/0xb0
[ 1203.077501]  [<c131c67b>] copy_to_user+0x3b/0x60
[ 1203.081561]  [<c158a102>] put_cmsg+0x52/0xd0
[ 1203.085624]  [<c15bc7d7>] netlink_recvmsg+0x287/0x340
[ 1203.089740]  [<c1579b43>] sock_recvmsg+0xd3/0x110
[ 1203.093902]  [<c1140b74>] ? might_fault+0x54/0xb0
[ 1203.098093]  [<c158834c>] ? verify_iovec+0x4c/0xc0
[ 1203.102336]  [<c1579a70>] ? sock_sendmsg_nosec+0x100/0x100
[ 1203.106611]  [<c157a994>] __sys_recvmsg+0x114/0x1e0
[ 1203.110942]  [<c1081dc7>] ? finish_task_switch+0x77/0x200
[ 1203.115315]  [<c11784b5>] ? fget_light+0xc5/0x410
[ 1203.119722]  [<c1081dc7>] ? finish_task_switch+0x77/0x200
[ 1203.124167]  [<c11784c9>] ? fget_light+0xd9/0x410
[ 1203.128618]  [<c1178435>] ? fget_light+0x45/0x410
[ 1203.133102]  [<c157c659>] sys_recvmsg+0x39/0x60
[ 1203.137590]  [<c157cbb3>] sys_socketcall+0x2e3/0x330
[ 1203.142147]  [<c17cf58d>] ? sysenter_exit+0xf/0x1a
[ 1203.146707]  [<c131be78>] ? trace_hardirqs_on_thunk+0xc/0x10
[ 1203.151358]  [<c17cf558>] sysenter_do_call+0x12/0x38
[ 1203.155980] BUG: scheduling while atomic: NetworkManager/4446/0x10000002
[ 1203.160714] INFO: lockdep is turned off.
[ 1203.165429] Modules linked in: vfat fat pci_stub vboxpci(O) vboxnetadp(O)
vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables acpi_cpufreq mperf
xt_CHECKSUM irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep rfcomm
bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 radeon
ipw2200 libipw pcmcia_rsrc pcmcia_core ttm drm_kms_helper parport_pc parport
cfbfillrect cfbcopyarea cfbimgblt raid10 raid456 async_memcpy async_pq
async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom floppy [last
unloaded: scsi_wait_scan]

OK, so we have a pile of in_atomic warnings.  I assume the above was
the first to come out?  The third and following traces have a different
trace.

It might be a bug in the netlink code or thereabouts.  Or it might be that
some random unrelated piece of kernel code forgot to release a lock and
netlink was the first place where this was detected.

Peter, is there any way in which lockdep can help us find the culprit
in the second case?

Thanks.

Well, there is few problems before this message, they are already reported:

https://bugzilla.kernel.org/show_bug.cgi?id=42742  (cpu_idle warning)
https://bugzilla.kernel.org/show_bug.cgi?id=42741  (sirdev DEADLOCK - second one is DEADLOCK warning, and it actually triggers real deadlock, but not on this boot)

but they are somehow unreleated.

Immiedietly before BUG I have
[  592.952374] PM: Adding info for No Bus:0:52

so pretty nothing for long time. System wasn't really loaded or anything,
it just happened. There was not suspend/resume cycles or anything.

This is IBM ThinkPad T43 (Pentium-M 32 bit), and it had fresh boot 20
minutes before this happened.

Bellow dmesg are same as boot above

cpuidle looks like this:
If you had tracing enabled, Steven Rostedt's patchset at
https://lkml.org/lkml/2012/2/7/231 might help here.

							Thanx, Paul

[   16.960579] Testing event cpu_idle: 
[   16.961306] ------------[ cut here ]------------
[   16.961316] WARNING: at include/linux/rcupdate.h:242 __atomic_notifier_call_chain+0xbc/0xf0()
[   16.961319] Hardware name: 2669UYD
[   16.961321] Modules linked in:
[   16.961326] Pid: 0, comm: swapper/0 Not tainted 3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13
[   16.961329] Call Trace:
[   16.961337]  [<c104a372>] warn_slowpath_common+0x72/0xa0
[   16.961341]  [<c17cb41c>] ? __atomic_notifier_call_chain+0xbc/0xf0
[   16.961346]  [<c17cb41c>] ? __atomic_notifier_call_chain+0xbc/0xf0
[   16.961350]  [<c104a3c0>] warn_slowpath_null+0x20/0x30
[   16.961355]  [<c17cb41c>] __atomic_notifier_call_chain+0xbc/0xf0
[   16.961360]  [<c136056e>] ? vgacon_scroll+0x5e/0x60
[   16.961365]  [<c17cb46f>] atomic_notifier_call_chain+0x1f/0x30
[   16.961371]  [<c13cdf23>] notify_write+0x23/0x30
[   16.961375]  [<c13cdf7f>] lf+0x4f/0x70
[   16.961379]  [<c13cefb9>] vt_console_print+0x249/0x380
[   16.961384]  [<c13ced70>] ? con_shutdown+0x40/0x40
[   16.961389]  [<c104a4fd>] __call_console_drivers+0x7d/0xa0
[   16.961393]  [<c104a6ec>] _call_console_drivers+0x4c/0x90
[   16.961398]  [<c104a94d>] call_console_drivers+0xdd/0x110
[   16.961402]  [<c104aa47>] console_unlock+0x77/0x170
[   16.961407]  [<c104accb>] vprintk+0x18b/0x490
[   16.961414]  [<c17b11a8>] printk+0x1d/0x1f
[   16.961420]  [<c10af9e2>] lockdep_rcu_suspicious+0x22/0xe0
[   16.961427]  [<c150db78>] cpuidle_idle_call+0x238/0x300
[   16.961433]  [<c10158df>] cpu_idle+0x6f/0xc0
[   16.961439]  [<c1795caa>] rest_init+0x11e/0x124
[   16.961443]  [<c1795bf3>] ? rest_init+0x67/0x124
[   16.961450]  [<c1b5a76e>] start_kernel+0x325/0x32b
[   16.961454]  [<c1b5a25a>] ? obsolete_checksetup+0x95/0x95
[   16.961459]  [<c1b5a11e>] ? reserve_ebda_region+0x6b/0x6d
[   16.961463]  [<c1b5a0ac>] i386_start_kernel+0x9b/0xa2
[   16.961466] ---[ end trace d284d408f7ee228c ]---
[   16.961468] ------------[ cut here ]------------
[   16.961472] WARNING: at include/linux/rcupdate.h:248 __atomic_notifier_call_chain+0xe0/0xf0()
[   16.961475] Hardware name: 2669UYD
[   16.961477] Modules linked in:
[   16.961481] Pid: 0, comm: swapper/0 Tainted: G        W    3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13
[   16.961483] Call Trace:
[   16.961488]  [<c104a372>] warn_slowpath_common+0x72/0xa0
[   16.961492]  [<c17cb440>] ? __atomic_notifier_call_chain+0xe0/0xf0
[   16.961496]  [<c17cb440>] ? __atomic_notifier_call_chain+0xe0/0xf0
[   16.961501]  [<c104a3c0>] warn_slowpath_null+0x20/0x30
[   16.961505]  [<c17cb440>] __atomic_notifier_call_chain+0xe0/0xf0
[   16.961509]  [<c17cb387>] ? __atomic_notifier_call_chain+0x27/0xf0
[   16.961514]  [<c17cb46f>] atomic_notifier_call_chain+0x1f/0x30
[   16.961518]  [<c13cdf23>] notify_write+0x23/0x30
[   16.961522]  [<c13cdf7f>] lf+0x4f/0x70
[   16.961527]  [<c13cefb9>] vt_console_print+0x249/0x380
[   16.961532]  [<c13ced70>] ? con_shutdown+0x40/0x40
[   16.961536]  [<c104a4fd>] __call_console_drivers+0x7d/0xa0
[   16.961540]  [<c104a6ec>] _call_console_drivers+0x4c/0x90
[   16.961545]  [<c104a94d>] call_console_drivers+0xdd/0x110
[   16.961549]  [<c104aa47>] console_unlock+0x77/0x170
[   16.961554]  [<c104accb>] vprintk+0x18b/0x490
[   16.961559]  [<c17b11a8>] printk+0x1d/0x1f
[   16.961563]  [<c10af9e2>] lockdep_rcu_suspicious+0x22/0xe0
[   16.961568]  [<c150db78>] cpuidle_idle_call+0x238/0x300
[   16.961573]  [<c10158df>] cpu_idle+0x6f/0xc0
[   16.961577]  [<c1795caa>] rest_init+0x11e/0x124
[   16.961581]  [<c1795bf3>] ? rest_init+0x67/0x124
[   16.961585]  [<c1b5a76e>] start_kernel+0x325/0x32b
[   16.961590]  [<c1b5a25a>] ? obsolete_checksetup+0x95/0x95
[   16.961594]  [<c1b5a11e>] ? reserve_ebda_region+0x6b/0x6d
[   16.961599]  [<c1b5a0ac>] i386_start_kernel+0x9b/0xa2
[   16.961601] ---[ end trace d284d408f7ee228d ]---
[   16.965103] ===============================
[   16.965156] [ INFO: suspicious RCU usage. ]
[   16.965209] 3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13 Tainted: G        W   
[   16.965268] -------------------------------
[   16.965321] include/trace/events/power.h:35 suspicious rcu_dereference_check() usage!
[   16.965409] 
[   16.965410] other info that might help us debug this:
[   16.965411] 
[   16.965556] 
[   16.965556] rcu_scheduler_active = 1, debug_locks = 1
[   16.965656] RCU used illegally from extended quiescent state!
[   16.965711] no locks held by swapper/0/0.
[   16.965764] 
[   16.965764] stack backtrace:
[   16.965861] Pid: 0, comm: swapper/0 Tainted: G        W    3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13
[   16.965951] Call Trace:
[   16.966003]  [<c17b11a8>] ? printk+0x1d/0x1f
[   16.966059]  [<c10afa78>] lockdep_rcu_suspicious+0xb8/0xe0
[   16.966118]  [<c150db78>] cpuidle_idle_call+0x238/0x300
[   16.966175]  [<c10158df>] cpu_idle+0x6f/0xc0
[   16.966231]  [<c1795caa>] rest_init+0x11e/0x124
[   16.966287]  [<c1795bf3>] ? rest_init+0x67/0x124
[   16.966344]  [<c1b5a76e>] start_kernel+0x325/0x32b
[   16.966400]  [<c1b5a25a>] ? obsolete_checksetup+0x95/0x95
[   16.966458]  [<c1b5a11e>] ? reserve_ebda_region+0x6b/0x6d
[   16.966516]  [<c1b5a0ac>] i386_start_kernel+0x9b/0xa2
[   16.980655] OK
[   16.980705] Testing event cpu_frequency: OK



And sirdev problem looks like this:


[  177.805346] irda_init()
[  177.805617] NET: Registered protocol family 23
[  177.853523] warning: `hipd' uses 32-bit capabilities (legacy support in use)
[  178.014559] sirdev_get_instance - ttyS1
[  178.014689] device: 'irda0': device_add
[  178.014943] PM: Adding info for No Bus:irda0
[  178.060888] irtty_open - ttyS1: irda line discipline opened
[  178.412690] alg: No test for authenc(hmac(sha1),cbc(aes)) (authenc(hmac(sha1-generic),cbc(aes-asm)))
[  179.070690] irlap_change_speed(), setting speed to 9600
[  182.070664] 
[  182.073284] ======================================================
[  182.075969] [ INFO: possible circular locking dependency detected ]
[  182.078702] 3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13 Tainted: G        W   
[  182.080017] -------------------------------------------------------
[  182.080017] irq/3-serial/5887 is trying to acquire lock:
[  182.080017]  (&(&dev->tx_lock)->rlock){..-...}, at: [<f869a883>] sirdev_write_complete+0x23/0x280 [sir_dev]
[  182.080017] 
[  182.080017] but task is already holding lock:
[  182.080017]  (&port_lock_key){..-...}, at: [<c13dc0f7>] serial8250_handle_irq+0x37/0xa0
[  182.080017] 
[  182.080017] which lock already depends on the new lock.
[  182.080017] 
[  182.080017] 
[  182.080017] the existing dependency chain (in reverse order) is:
[  182.080017] 
[  182.080017] -> #1 (&port_lock_key){..-...}:
[  182.080017]        [<c10b0f1b>] check_prevs_add+0xcb/0x120
[  182.080017]        [<c10b14c7>] validate_chain.isra.34+0x557/0x6d0
[  182.080017]        [<c10b3945>] __lock_acquire+0x355/0x820
[  182.080017]        [<c10b4467>] lock_acquire+0x87/0x1b0
[  182.080017]        [<c17c762e>] _raw_spin_lock_irqsave+0x5e/0xa0
[  182.080017]        [<c13d5f32>] uart_write_room+0x22/0x60
[  182.080017]        [<c13c1c19>] tty_write_room+0x19/0x20
[  182.080017]        [<f876b512>] irtty_do_write+0x42/0xa0 [irtty_sir]
[  182.080017]        [<f869a455>] sirdev_hard_xmit+0xc5/0x280 [sir_dev]
[  182.080017]        [<c159586f>] dev_hard_start_xmit+0x22f/0x690
[  182.080017]        [<c15ba331>] sch_direct_xmit+0xa1/0x220
[  182.080017]        [<c1595e45>] dev_queue_xmit+0x175/0x770
[  182.080017]        [<f878e62a>] irlap_queue_xmit+0x9a/0xe0 [irda]
[  182.080017]        [<f878ebeb>] irlap_send_discovery_xid_frame+0xdb/0x360 [irda]
[  182.080017]        [<f878ca68>] irlap_state_ndm+0x308/0x4e0 [irda]
[  182.080017]        [<f878cd7b>] irlap_do_event+0x4b/0xb0 [irda]
[  182.080017]        [<f878964a>] irlap_discovery_request+0xda/0x230 [irda]
[  182.080017]        [<f8786168>] irlmp_state_standby+0x78/0x170 [irda]
[  182.080017]        [<f8786b59>] irlmp_do_lap_event+0x39/0xe0 [irda]
[  182.080017]        [<f878546c>] irlmp_do_discovery+0xac/0x140 [irda]
[  182.080017]        [<f8787603>] irlmp_discovery_timer_expired+0x23/0x60 [irda]
[  182.080017]        [<c105abad>] call_timer_fn+0x6d/0x2e0
[  182.080017]        [<c105af0a>] run_timer_softirq+0xea/0x260
[  182.080017]        [<c10524cf>] __do_softirq+0x9f/0x360
[  182.080017]        [<c1052887>] run_ksoftirqd+0xf7/0x1b0
[  182.080017]        [<c10721f2>] kthread+0x72/0x80
[  182.080017]        [<c17cfafa>] kernel_thread_helper+0x6/0x10
[  182.080017] 
[  182.080017] -> #0 (&(&dev->tx_lock)->rlock){..-...}:
[  182.080017]        [<c10b0e45>] check_prev_add+0x605/0x610
[  182.080017]        [<c10b0f1b>] check_prevs_add+0xcb/0x120
[  182.080017]        [<c10b14c7>] validate_chain.isra.34+0x557/0x6d0
[  182.080017]        [<c10b3945>] __lock_acquire+0x355/0x820
[  182.080017]        [<c10b4467>] lock_acquire+0x87/0x1b0
[  182.080017]        [<c17c762e>] _raw_spin_lock_irqsave+0x5e/0xa0
[  182.080017]        [<f869a883>] sirdev_write_complete+0x23/0x280 [sir_dev]
[  182.080017]        [<f876b671>] irtty_write_wakeup+0x31/0x90 [irtty_sir]
[  182.080017]        [<c13ba332>] tty_wakeup+0x62/0x70
[  182.080017]        [<c13d7686>] uart_write_wakeup+0x16/0x20
[  182.080017]        [<c13daffe>] serial8250_tx_chars+0x8e/0x110
[  182.080017]        [<c13dc157>] serial8250_handle_irq+0x97/0xa0
[  182.080017]        [<c13dc17c>] serial8250_default_handle_irq+0x1c/0x20
[  182.080017]        [<c13da1e5>] serial8250_interrupt+0x65/0xd0
[  182.080017]        [<c10dfa26>] irq_forced_thread_fn+0x26/0x50
[  182.080017]        [<c10df932>] irq_thread+0x152/0x1e0
[  182.080017]        [<c10721f2>] kthread+0x72/0x80
[  182.080017]        [<c17cfafa>] kernel_thread_helper+0x6/0x10
[  182.080017] 
[  182.080017] other info that might help us debug this:
[  182.080017] 
[  182.080017]  Possible unsafe locking scenario:
[  182.080017] 
[  182.080017]        CPU0                    CPU1
[  182.080017]        ----                    ----
[  182.080017]   lock(&port_lock_key);
[  182.080017]                                lock(&(&dev->tx_lock)->rlock);
[  182.080017]                                lock(&port_lock_key);
[  182.080017]   lock(&(&dev->tx_lock)->rlock);
[  182.080017] 
[  182.080017]  *** DEADLOCK ***
[  182.080017] 
[  182.080017] 2 locks held by irq/3-serial/5887:
[  182.080017]  #0:  (&(&i->lock)->rlock){+.....}, at: [<c13da1a3>] serial8250_interrupt+0x23/0xd0
[  182.080017]  #1:  (&port_lock_key){..-...}, at: [<c13dc0f7>] serial8250_handle_irq+0x37/0xa0
[  182.080017] 
[  182.080017] stack backtrace:
[  182.080017] Pid: 5887, comm: irq/3-serial Tainted: G        W    3.3.0-rc2-t43-devel-smp-00172-g23783f8 #13
[  182.080017] Call Trace:
[  182.080017]  [<c17b11a8>] ? printk+0x1d/0x1f
[  182.080017]  [<c17b2506>] print_circular_bug+0xa7/0xb1
[  182.080017]  [<c10b0e45>] check_prev_add+0x605/0x610
[  182.080017]  [<c10b0f1b>] check_prevs_add+0xcb/0x120
[  182.080017]  [<c10b14c7>] validate_chain.isra.34+0x557/0x6d0
[  182.080017]  [<c10b3945>] __lock_acquire+0x355/0x820
[  182.080017]  [<c10b4467>] lock_acquire+0x87/0x1b0
[  182.080017]  [<f869a883>] ? sirdev_write_complete+0x23/0x280 [sir_dev]
[  182.080017]  [<c17c75f9>] ? _raw_spin_lock_irqsave+0x29/0xa0
[  182.080017]  [<c17c762e>] _raw_spin_lock_irqsave+0x5e/0xa0
[  182.080017]  [<f869a883>] ? sirdev_write_complete+0x23/0x280 [sir_dev]
[  182.080017]  [<f869a883>] sirdev_write_complete+0x23/0x280 [sir_dev]
[  182.080017]  [<c10aea1b>] ? trace_hardirqs_off+0xb/0x10
[  182.080017]  [<f876b671>] irtty_write_wakeup+0x31/0x90 [irtty_sir]
[  182.080017]  [<c13c2991>] ? tty_ldisc_try+0x41/0x50
[  182.080017]  [<c13c29ad>] ? tty_ldisc_ref+0xd/0x10
[  182.080017]  [<c13ba332>] tty_wakeup+0x62/0x70
[  182.080017]  [<c13d7686>] uart_write_wakeup+0x16/0x20
[  182.080017]  [<c13daffe>] serial8250_tx_chars+0x8e/0x110
[  182.080017]  [<c13dc157>] serial8250_handle_irq+0x97/0xa0
[  182.080017]  [<c13dc17c>] serial8250_default_handle_irq+0x1c/0x20
[  182.080017]  [<c13da1e5>] serial8250_interrupt+0x65/0xd0
[  182.080017]  [<c108580b>] ? get_parent_ip+0xb/0x40
[  182.080017]  [<c10dfa26>] irq_forced_thread_fn+0x26/0x50
[  182.080017]  [<c10df932>] irq_thread+0x152/0x1e0
[  182.080017]  [<c10dfa00>] ? irq_thread_fn+0x40/0x40
[  182.080017]  [<c10df7e0>] ? irq_finalize_oneshot+0x20/0x20
[  182.080017]  [<c10721f2>] kthread+0x72/0x80
[  182.080017]  [<c1072180>] ? __init_kthread_worker+0x60/0x60
[  182.080017]  [<c17cfafa>] kernel_thread_helper+0x6/0x10


But I do not see how this locks can any problem.

I do not know why lockdep is disabled, because I configured kernel to
keep telling my about lock dependency problems even after showing first
one. AFAIK.

As of VirtualBox modules, they were not used for anything, just loaded.

Regards,
Witek




-- 
Witold Baryluk
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to majordomo@vger.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html





  

    
Re: [Bug 42754] New: BUG: sleeping function called from invalid context at mm/memory.c:3924

    

      From: Peter Zijlstra <hidden>

      Date: 2012-02-15 13:02:40 
    

  

  
On Sun, 2012-02-12 at 09:50 -0800, Paul E. McKenney wrote:
quoted
I do not know why lockdep is disabled, because I configured kernel to
keep telling my about lock dependency problems even after showing first
one. AFAIK. 
That setting is only relevant to RCU, normal lockdep reports will always
disable lockdep.





  

    
Re: [Bug 42754] New: BUG: sleeping function called from invalid context at mm/memory.c:3924

    

      From: Witold Baryluk <hidden>

      Date: 2012-02-16 15:10:26 
    

  

  
On 02-15 14:02, Peter Zijlstra wrote:
On Sun, 2012-02-12 at 09:50 -0800, Paul E. McKenney wrote:
quoted
quoted
I do not know why lockdep is disabled, because I configured kernel to
keep telling my about lock dependency problems even after showing first
one. AFAIK. 
That setting is only relevant to RCU, normal lockdep reports will always
disable lockdep.
One more thing about a bug.

I was able to reproduce bug yestarday , and again today.

First one is again in NetworkManager process (just after loging in to
gnome, exactly like previously), and again NetworkManager process is
killed. And again restarting NM manually make it happy (and works
without further problems). So indeed it looks to be problem with
netlink, because netlink_recvmsg is common call here.

Second one is also in netlink, but process is this time ip, and message
is

[ 9136.204156] BUG: sleeping function called from invalid context at kernel/mutex.c:271

full stacks bellow.

Regards,
Witek

1)

[    0.000000] Linux version 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty (baryluk@sredniczarny) (gcc version 4.6.2 (Debian 4.6.2-14) ) #22 SMP Sat Feb 11 23:16:44 CET 2012
..
[ 1078.282836] BUG: sleeping function called from invalid context at mm/memory.c:3924
[ 1078.282843] in_atomic(): 1, irqs_disabled(): 0, pid: 3953, name: NetworkManager
[ 1078.282847] INFO: lockdep is turned off.
[ 1078.282852] Pid: 3953, comm: NetworkManager Tainted: G        W  O 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty #22
[ 1078.282856] Call Trace:
[ 1078.282868]  [<c107d554>] __might_sleep+0x124/0x1d0
[ 1078.282875]  [<c11400ee>] might_fault+0x2e/0xb0
[ 1078.282882]  [<c131d3ab>] copy_to_user+0x3b/0x60
[ 1078.282889]  [<c1568172>] put_cmsg+0x52/0xd0
[ 1078.282903]  [<c159a917>] netlink_recvmsg+0x287/0x340
[ 1078.282910]  [<c1557aa3>] sock_recvmsg+0xd3/0x110
[ 1078.282916]  [<c1140114>] ? might_fault+0x54/0xb0
[ 1078.282921]  [<c15663bc>] ? verify_iovec+0x4c/0xc0
[ 1078.282926]  [<c15579d0>] ? sock_sendmsg_nosec+0x100/0x100
[ 1078.282931]  [<c15588f4>] __sys_recvmsg+0x114/0x1e0
[ 1078.282938]  [<c1082752>] ? check_preempt_curr+0x72/0x90
[ 1078.282943]  [<c1082be2>] ? ttwu_queue+0x42/0xc0
[ 1078.282949]  [<c10b26f1>] ? __lock_acquired+0x2e1/0x330
[ 1078.282956]  [<c1177a65>] ? fget_light+0xc5/0x410
[ 1078.282961]  [<c1177a79>] ? fget_light+0xd9/0x410
[ 1078.282965]  [<c11779e5>] ? fget_light+0x45/0x410
[ 1078.282971]  [<c155a5b9>] sys_recvmsg+0x39/0x60
[ 1078.282976]  [<c155ab13>] sys_socketcall+0x2e3/0x330
[ 1078.282982]  [<c17adacd>] ? sysenter_exit+0xf/0x1a
[ 1078.282988]  [<c131cba8>] ? trace_hardirqs_on_thunk+0xc/0x10
[ 1078.282993]  [<c17ada98>] sysenter_do_call+0x12/0x38
[ 1078.282999]  [<c17a007b>] ? trace_packet+0x104/0x154
[ 1078.283003] BUG: scheduling while atomic: NetworkManager/3953/0x10000002
[ 1078.283006] INFO: lockdep is turned off.
[ 1078.283009] Modules linked in: pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables xt_CHECKSUM acpi_cpufreq mperf irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 ipw2200 pcmcia_rsrc pcmcia_core radeon libipw floppy video parport_pc parport ttm drm_kms_helper drm i2c_algo_bit cfbfillrect cfbcopyarea cfbimgblt intel_agp intel_gtt agpgart raid10 raid456 async_memcpy async_pq async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom [last unloaded: scsi_wait_scan]
[ 1078.283103] Pid: 3953, comm: NetworkManager Tainted: G        W  O 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty #22
[ 1078.283106] Call Trace:
[ 1078.283112]  [<c178fb87>] __schedule_bug+0x7d/0x84
[ 1078.283118]  [<c17a3eea>] __schedule+0x6ca/0x780
[ 1078.283125]  [<c101995c>] ? show_trace_log_lvl+0x4c/0x60
[ 1078.283132]  [<c178da7f>] ? dump_stack+0x73/0x7a
[ 1078.283137]  [<c107d554>] ? __might_sleep+0x124/0x1d0
[ 1078.283142]  [<c1082a8b>] __cond_resched+0x1b/0x30
[ 1078.283146]  [<c17a4019>] _cond_resched+0x29/0x30
[ 1078.283151]  [<c11400f3>] might_fault+0x33/0xb0
[ 1078.283156]  [<c131d3ab>] copy_to_user+0x3b/0x60
[ 1078.283161]  [<c1568172>] put_cmsg+0x52/0xd0
[ 1078.283166]  [<c159a917>] netlink_recvmsg+0x287/0x340
[ 1078.283172]  [<c1557aa3>] sock_recvmsg+0xd3/0x110
[ 1078.283177]  [<c1140114>] ? might_fault+0x54/0xb0
[ 1078.283183]  [<c15663bc>] ? verify_iovec+0x4c/0xc0
[ 1078.283188]  [<c15579d0>] ? sock_sendmsg_nosec+0x100/0x100
[ 1078.283192]  [<c15588f4>] __sys_recvmsg+0x114/0x1e0
[ 1078.283198]  [<c1082752>] ? check_preempt_curr+0x72/0x90
[ 1078.283219]  [<c1082be2>] ? ttwu_queue+0x42/0xc0
[ 1078.283224]  [<c10b26f1>] ? __lock_acquired+0x2e1/0x330
[ 1078.283229]  [<c1177a65>] ? fget_light+0xc5/0x410
[ 1078.283234]  [<c1177a79>] ? fget_light+0xd9/0x410
[ 1078.283239]  [<c11779e5>] ? fget_light+0x45/0x410
[ 1078.283244]  [<c155a5b9>] sys_recvmsg+0x39/0x60
[ 1078.283249]  [<c155ab13>] sys_socketcall+0x2e3/0x330
[ 1078.283254]  [<c17adacd>] ? sysenter_exit+0xf/0x1a
[ 1078.283259]  [<c131cba8>] ? trace_hardirqs_on_thunk+0xc/0x10
[ 1078.283264]  [<c17ada98>] sysenter_do_call+0x12/0x38
[ 1078.283270]  [<c17a007b>] ? trace_packet+0x104/0x154
[ 1078.289513] BUG: scheduling while atomic: NetworkManager/3953/0x10000002
[ 1078.289519] INFO: lockdep is turned off.
[ 1078.289522] Modules linked in: pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables xt_CHECKSUM acpi_cpufreq mperf irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 ipw2200 pcmcia_rsrc pcmcia_core radeon libipw floppy video parport_pc parport ttm drm_kms_helper drm i2c_algo_bit cfbfillrect cfbcopyarea cfbimgblt intel_agp intel_gtt agpgart raid10 raid456 async_memcpy async_pq async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom [last unloaded: scsi_wait_scan]
[ 1078.289616] Pid: 3953, comm: NetworkManager Tainted: G        W  O 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty #22
[ 1078.289620] Call Trace:
[ 1078.289631]  [<c178fb87>] __schedule_bug+0x7d/0x84
[ 1078.289637]  [<c17a3eea>] __schedule+0x6ca/0x780
[ 1078.289644]  [<c1083242>] ? try_to_wake_up+0x152/0x1d0
[ 1078.289651]  [<c10b26f1>] ? __lock_acquired+0x2e1/0x330
[ 1078.289658]  [<c10d0fb8>] ? audit_buffer_free+0x28/0x70
[ 1078.289663]  [<c107d465>] ? __might_sleep+0x35/0x1d0
[ 1078.289668]  [<c1082a8b>] __cond_resched+0x1b/0x30
[ 1078.289673]  [<c17a4019>] _cond_resched+0x29/0x30
[ 1078.289680]  [<c11631a3>] kmem_cache_alloc+0x43/0x2b0
[ 1078.289685]  [<c10b13ab>] ? trace_hardirqs_on+0xb/0x10
[ 1078.289692]  [<c10790ba>] ? prepare_creds+0x2a/0x100
[ 1078.289697]  [<c10790ba>] prepare_creds+0x2a/0x100
[ 1078.289704]  [<c117ebd5>] do_coredump+0x85/0x440
[ 1078.289709]  [<c1162e5d>] ? kmem_cache_free+0x12d/0x1e0
[ 1078.289715]  [<c105c602>] ? __sigqueue_free+0x32/0x40
[ 1078.289719]  [<c105c602>] ? __sigqueue_free+0x32/0x40
[ 1078.289724]  [<c105c602>] ? __sigqueue_free+0x32/0x40
[ 1078.289728]  [<c105c6c2>] ? collect_signal+0xb2/0x190
[ 1078.289734]  [<c10609d5>] ? get_signal_to_deliver+0x185/0x470
[ 1078.289739]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.289744]  [<c10b13ab>] ? trace_hardirqs_on+0xb/0x10
[ 1078.289751]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.289756]  [<c1060a0c>] get_signal_to_deliver+0x1bc/0x470
[ 1078.289760]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.289766]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.289773]  [<c10169df>] do_signal+0x3f/0xd0
[ 1078.289777]  [<c1060e43>] ? set_current_blocked+0x43/0x50
[ 1078.289782]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.289788]  [<c178ee99>] ? bad_area_nosemaphore+0x17/0x19
[ 1078.289793]  [<c17a96dc>] ? do_page_fault+0x3fc/0x4f0
[ 1078.289800]  [<c155ab13>] ? sys_socketcall+0x2e3/0x330
[ 1078.289805]  [<c17a5d56>] ? work_notifysig+0x11/0x2b
[ 1078.289810]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.289815]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.289820]  [<c1016ccd>] do_notify_resume+0x5d/0x80
[ 1078.289825]  [<c17a5d6a>] work_notifysig+0x25/0x2b
[ 1078.289830]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.293674] BUG: scheduling while atomic: NetworkManager/3953/0x10000002
[ 1078.293680] INFO: lockdep is turned off.
[ 1078.293682] Modules linked in: pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables xt_CHECKSUM acpi_cpufreq mperf irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 ipw2200 pcmcia_rsrc pcmcia_core radeon libipw floppy video parport_pc parport ttm drm_kms_helper drm i2c_algo_bit cfbfillrect cfbcopyarea cfbimgblt intel_agp intel_gtt agpgart raid10 raid456 async_memcpy async_pq async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom [last unloaded: scsi_wait_scan]
[ 1078.293851] Pid: 3953, comm: NetworkManager Tainted: G        W  O 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty #22
[ 1078.293855] Call Trace:
[ 1078.293865]  [<c178fb87>] __schedule_bug+0x7d/0x84
[ 1078.293871]  [<c17a3eea>] __schedule+0x6ca/0x780
[ 1078.293879]  [<c1083242>] ? try_to_wake_up+0x152/0x1d0
[ 1078.293884]  [<c17a5585>] ? _raw_spin_unlock_irqrestore+0x65/0x70
[ 1078.293890]  [<c10adcef>] ? trace_hardirqs_off_caller+0x1f/0x130
[ 1078.293908]  [<c107d465>] ? __might_sleep+0x35/0x1d0
[ 1078.293913]  [<c17a5585>] ? _raw_spin_unlock_irqrestore+0x65/0x70
[ 1078.293918]  [<c1082a8b>] __cond_resched+0x1b/0x30
[ 1078.293923]  [<c17a4019>] _cond_resched+0x29/0x30
[ 1078.293927]  [<c17a404e>] wait_for_common+0x2e/0x120
[ 1078.293934]  [<c117d7b0>] ? coredump_wait+0x2d0/0x350
[ 1078.293939]  [<c17a4217>] wait_for_completion+0x17/0x20
[ 1078.293944]  [<c117d793>] coredump_wait+0x2b3/0x350
[ 1078.293950]  [<c10790ba>] ? prepare_creds+0x2a/0x100
[ 1078.293955]  [<c10790ba>] ? prepare_creds+0x2a/0x100
[ 1078.293960]  [<c117ec08>] do_coredump+0xb8/0x440
[ 1078.293967]  [<c1162e5d>] ? kmem_cache_free+0x12d/0x1e0
[ 1078.293973]  [<c105c602>] ? __sigqueue_free+0x32/0x40
[ 1078.293977]  [<c105c602>] ? __sigqueue_free+0x32/0x40
[ 1078.293983]  [<c10609d5>] ? get_signal_to_deliver+0x185/0x470
[ 1078.293989]  [<c10b13ab>] ? trace_hardirqs_on+0xb/0x10
[ 1078.293995]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.294000]  [<c1060a0c>] get_signal_to_deliver+0x1bc/0x470
[ 1078.294005]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.294010]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.294016]  [<c10169df>] do_signal+0x3f/0xd0
[ 1078.294021]  [<c1060e43>] ? set_current_blocked+0x43/0x50
[ 1078.294026]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.294031]  [<c178ee99>] ? bad_area_nosemaphore+0x17/0x19
[ 1078.294036]  [<c17a96dc>] ? do_page_fault+0x3fc/0x4f0
[ 1078.294043]  [<c155ab13>] ? sys_socketcall+0x2e3/0x330
[ 1078.294048]  [<c17a5d56>] ? work_notifysig+0x11/0x2b
[ 1078.294053]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.294058]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.294063]  [<c1016ccd>] do_notify_resume+0x5d/0x80
[ 1078.294068]  [<c17a5d6a>] work_notifysig+0x25/0x2b
[ 1078.294073]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.294105] BUG: scheduling while atomic: NetworkManager/3953/0x10000002
[ 1078.294108] INFO: lockdep is turned off.
[ 1078.294111] Modules linked in: pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables xt_CHECKSUM acpi_cpufreq mperf irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 ipw2200 pcmcia_rsrc pcmcia_core radeon libipw floppy video parport_pc parport ttm drm_kms_helper drm i2c_algo_bit cfbfillrect cfbcopyarea cfbimgblt intel_agp intel_gtt agpgart raid10 raid456 async_memcpy async_pq async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom [last unloaded: scsi_wait_scan]
[ 1078.294193] Pid: 3953, comm: NetworkManager Tainted: G        W  O 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty #22
[ 1078.294196] Call Trace:
[ 1078.294201]  [<c178fb87>] __schedule_bug+0x7d/0x84
[ 1078.294206]  [<c17a3eea>] __schedule+0x6ca/0x780
[ 1078.294212]  [<c10e5e19>] ? __call_rcu+0xd9/0x3a0
[ 1078.294217]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.294222]  [<c10b13ab>] ? trace_hardirqs_on+0xb/0x10
[ 1078.294227]  [<c10b13ab>] ? trace_hardirqs_on+0xb/0x10
[ 1078.294233]  [<c10791c0>] ? release_tgcred.isra.10+0x30/0x30
[ 1078.294238]  [<c107d465>] ? __might_sleep+0x35/0x1d0
[ 1078.294242]  [<c1079274>] ? __put_cred+0x34/0x40
[ 1078.294247]  [<c1082a8b>] __cond_resched+0x1b/0x30
[ 1078.294252]  [<c17a4019>] _cond_resched+0x29/0x30
[ 1078.294256]  [<c17a3548>] down_read+0x28/0x8a
[ 1078.294261]  [<c1060cde>] exit_signals+0x1e/0x110
[ 1078.294268]  [<c104e342>] do_exit+0x92/0x450
[ 1078.294273]  [<c10609d5>] ? get_signal_to_deliver+0x185/0x470
[ 1078.294278]  [<c104e848>] do_group_exit+0x38/0xa0
[ 1078.294284]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.294288]  [<c1060a16>] get_signal_to_deliver+0x1c6/0x470
[ 1078.294293]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.294299]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.294304]  [<c10169df>] do_signal+0x3f/0xd0
[ 1078.294309]  [<c1060e43>] ? set_current_blocked+0x43/0x50
[ 1078.294314]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.294318]  [<c178ee99>] ? bad_area_nosemaphore+0x17/0x19
[ 1078.294323]  [<c17a96dc>] ? do_page_fault+0x3fc/0x4f0
[ 1078.294329]  [<c155ab13>] ? sys_socketcall+0x2e3/0x330
[ 1078.294334]  [<c17a5d56>] ? work_notifysig+0x11/0x2b
[ 1078.294339]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.294344]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.294349]  [<c1016ccd>] do_notify_resume+0x5d/0x80
[ 1078.294354]  [<c17a5d6a>] work_notifysig+0x25/0x2b
[ 1078.294359]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.298522] note: NetworkManager[3953] exited with preempt_count 1
[ 1078.299425] BUG: scheduling while atomic: NetworkManager/3953/0x10000002
[ 1078.299429] INFO: lockdep is turned off.
[ 1078.299432] Modules linked in: pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables xt_CHECKSUM acpi_cpufreq mperf irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 ipw2200 pcmcia_rsrc pcmcia_core radeon libipw floppy video parport_pc parport ttm drm_kms_helper drm i2c_algo_bit cfbfillrect cfbcopyarea cfbimgblt intel_agp intel_gtt agpgart raid10 raid456 async_memcpy async_pq async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom [last unloaded: scsi_wait_scan]
[ 1078.299525] Pid: 3953, comm: NetworkManager Tainted: G        W  O 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty #22
[ 1078.299529] Call Trace:
[ 1078.299539]  [<c178fb87>] __schedule_bug+0x7d/0x84
[ 1078.299545]  [<c17a3eea>] __schedule+0x6ca/0x780
[ 1078.299551]  [<c156069d>] ? skb_dequeue+0x4d/0x70
[ 1078.299556]  [<c17a5556>] ? _raw_spin_unlock_irqrestore+0x36/0x70
[ 1078.299563]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.299569]  [<c10e5e19>] ? __call_rcu+0xd9/0x3a0
[ 1078.299574]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.299579]  [<c10b13ab>] ? trace_hardirqs_on+0xb/0x10
[ 1078.299584]  [<c107d465>] ? __might_sleep+0x35/0x1d0
[ 1078.299590]  [<c1082a8b>] __cond_resched+0x1b/0x30
[ 1078.299594]  [<c17a4019>] _cond_resched+0x29/0x30
[ 1078.299601]  [<c118d316>] dput+0x176/0x220
[ 1078.299606]  [<c11783ac>] __fput+0x12c/0x1d0
[ 1078.299611]  [<c117846d>] fput+0x1d/0x30
[ 1078.299616]  [<c1173834>] filp_close+0x54/0x80
[ 1078.299622]  [<c104c1f8>] close_files+0xf8/0x1f0
[ 1078.299627]  [<c104c128>] ? close_files+0x28/0x1f0
[ 1078.299633]  [<c104c304>] put_files_struct.part.12+0x14/0x180
[ 1078.299639]  [<c132d4ce>] ? do_raw_spin_unlock+0x4e/0x90
[ 1078.299644]  [<c104de8d>] put_files_struct+0x1d/0x30
[ 1078.299649]  [<c104df43>] exit_files+0x43/0x50
[ 1078.299654]  [<c104e3fd>] do_exit+0x14d/0x450
[ 1078.299659]  [<c104e848>] do_group_exit+0x38/0xa0
[ 1078.299666]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.299671]  [<c1060a16>] get_signal_to_deliver+0x1c6/0x470
[ 1078.299676]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.299682]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.299689]  [<c10169df>] do_signal+0x3f/0xd0
[ 1078.299694]  [<c1060e43>] ? set_current_blocked+0x43/0x50
[ 1078.299698]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.299704]  [<c178ee99>] ? bad_area_nosemaphore+0x17/0x19
[ 1078.299709]  [<c17a96dc>] ? do_page_fault+0x3fc/0x4f0
[ 1078.299715]  [<c155ab13>] ? sys_socketcall+0x2e3/0x330
[ 1078.299720]  [<c17a5d56>] ? work_notifysig+0x11/0x2b
[ 1078.299725]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.299730]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.299735]  [<c1016ccd>] do_notify_resume+0x5d/0x80
[ 1078.299740]  [<c17a5d6a>] work_notifysig+0x25/0x2b
[ 1078.299745]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.308465] BUG: scheduling while atomic: NetworkManager/3953/0x10000002
[ 1078.308471] INFO: lockdep is turned off.
[ 1078.308474] Modules linked in: pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables xt_CHECKSUM acpi_cpufreq mperf irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 ipw2200 pcmcia_rsrc pcmcia_core radeon libipw floppy video parport_pc parport ttm drm_kms_helper drm i2c_algo_bit cfbfillrect cfbcopyarea cfbimgblt intel_agp intel_gtt agpgart raid10 raid456 async_memcpy async_pq async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom [last unloaded: scsi_wait_scan]
[ 1078.308650] Pid: 3953, comm: NetworkManager Tainted: G        W  O 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty #22
[ 1078.308655] Call Trace:
[ 1078.308666]  [<c178fb87>] __schedule_bug+0x7d/0x84
[ 1078.308672]  [<c17a3eea>] __schedule+0x6ca/0x780
[ 1078.308678]  [<c1088b87>] ? __enqueue_entity+0x77/0x80
[ 1078.308685]  [<c1081474>] ? resched_task+0x24/0x70
[ 1078.308690]  [<c108d2be>] ? check_preempt_wakeup+0x19e/0x230
[ 1078.308696]  [<c1082752>] ? check_preempt_curr+0x72/0x90
[ 1078.308701]  [<c1082be2>] ? ttwu_queue+0x42/0xc0
[ 1078.308705]  [<c107d465>] ? __might_sleep+0x35/0x1d0
[ 1078.308710]  [<c1082a8b>] __cond_resched+0x1b/0x30
[ 1078.308715]  [<c17a4019>] _cond_resched+0x29/0x30
[ 1078.308722]  [<c11631a3>] kmem_cache_alloc+0x43/0x2b0
[ 1078.308729]  [<c10ade0b>] ? trace_hardirqs_off+0xb/0x10
[ 1078.308734]  [<c17a5585>] ? _raw_spin_unlock_irqrestore+0x65/0x70
[ 1078.308740]  [<c11b7511>] ? fsnotify_create_event+0x31/0x170
[ 1078.308744]  [<c11b7511>] fsnotify_create_event+0x31/0x170
[ 1078.308749]  [<c107c5d4>] ? __wake_up+0x44/0x50
[ 1078.308754]  [<c17a5556>] ? _raw_spin_unlock_irqrestore+0x36/0x70
[ 1078.308760]  [<c11b9dc3>] inotify_ignored_and_remove_idr+0x43/0xc0
[ 1078.308765]  [<c11b902d>] inotify_freeing_mark+0xd/0x10
[ 1078.308770]  [<c11b7faa>] fsnotify_destroy_mark+0xda/0x140
[ 1078.308775]  [<c11b832b>] fsnotify_clear_marks_by_group_flags+0xbb/0xe0
[ 1078.308780]  [<c11b8362>] fsnotify_clear_marks_by_group+0x12/0x20
[ 1078.308785]  [<c11b9375>] inotify_release+0x25/0x60
[ 1078.308791]  [<c117832f>] __fput+0xaf/0x1d0
[ 1078.308795]  [<c117846d>] fput+0x1d/0x30
[ 1078.308800]  [<c1173834>] filp_close+0x54/0x80
[ 1078.308807]  [<c104c1f8>] close_files+0xf8/0x1f0
[ 1078.308812]  [<c104c128>] ? close_files+0x28/0x1f0
[ 1078.308817]  [<c104c304>] put_files_struct.part.12+0x14/0x180
[ 1078.308824]  [<c132d4ce>] ? do_raw_spin_unlock+0x4e/0x90
[ 1078.308829]  [<c104de8d>] put_files_struct+0x1d/0x30
[ 1078.308834]  [<c104df43>] exit_files+0x43/0x50
[ 1078.308839]  [<c104e3fd>] do_exit+0x14d/0x450
[ 1078.308844]  [<c104e848>] do_group_exit+0x38/0xa0
[ 1078.308851]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.308856]  [<c1060a16>] get_signal_to_deliver+0x1c6/0x470
[ 1078.308861]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.308867]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.308873]  [<c10169df>] do_signal+0x3f/0xd0
[ 1078.308878]  [<c1060e43>] ? set_current_blocked+0x43/0x50
[ 1078.308883]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.308888]  [<c178ee99>] ? bad_area_nosemaphore+0x17/0x19
[ 1078.308893]  [<c17a96dc>] ? do_page_fault+0x3fc/0x4f0
[ 1078.308901]  [<c155ab13>] ? sys_socketcall+0x2e3/0x330
[ 1078.308906]  [<c17a5d56>] ? work_notifysig+0x11/0x2b
[ 1078.308911]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.308916]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.308921]  [<c1016ccd>] do_notify_resume+0x5d/0x80
[ 1078.308926]  [<c17a5d6a>] work_notifysig+0x25/0x2b
[ 1078.308931]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.308954] BUG: scheduling while atomic: NetworkManager/3953/0x10000002
[ 1078.308957] INFO: lockdep is turned off.
[ 1078.308960] Modules linked in: pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables xt_CHECKSUM acpi_cpufreq mperf irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 ipw2200 pcmcia_rsrc pcmcia_core radeon libipw floppy video parport_pc parport ttm drm_kms_helper drm i2c_algo_bit cfbfillrect cfbcopyarea cfbimgblt intel_agp intel_gtt agpgart raid10 raid456 async_memcpy async_pq async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom [last unloaded: scsi_wait_scan]
[ 1078.309042] Pid: 3953, comm: NetworkManager Tainted: G        W  O 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty #22
[ 1078.309046] Call Trace:
[ 1078.309051]  [<c178fb87>] __schedule_bug+0x7d/0x84
[ 1078.309055]  [<c17a3eea>] __schedule+0x6ca/0x780
[ 1078.309060]  [<c1088b87>] ? __enqueue_entity+0x77/0x80
[ 1078.309065]  [<c1081474>] ? resched_task+0x24/0x70
[ 1078.309070]  [<c108d2be>] ? check_preempt_wakeup+0x19e/0x230
[ 1078.309075]  [<c1082752>] ? check_preempt_curr+0x72/0x90
[ 1078.309080]  [<c1082be2>] ? ttwu_queue+0x42/0xc0
[ 1078.309085]  [<c107d465>] ? __might_sleep+0x35/0x1d0
[ 1078.309090]  [<c1082a8b>] __cond_resched+0x1b/0x30
[ 1078.309094]  [<c17a4019>] _cond_resched+0x29/0x30
[ 1078.309099]  [<c11631a3>] kmem_cache_alloc+0x43/0x2b0
[ 1078.309104]  [<c10ade0b>] ? trace_hardirqs_off+0xb/0x10
[ 1078.309109]  [<c17a5585>] ? _raw_spin_unlock_irqrestore+0x65/0x70
[ 1078.309114]  [<c11b7511>] ? fsnotify_create_event+0x31/0x170
[ 1078.309119]  [<c11b7511>] fsnotify_create_event+0x31/0x170
[ 1078.309123]  [<c107c5d4>] ? __wake_up+0x44/0x50
[ 1078.309128]  [<c17a5556>] ? _raw_spin_unlock_irqrestore+0x36/0x70
[ 1078.309134]  [<c11b9dc3>] inotify_ignored_and_remove_idr+0x43/0xc0
[ 1078.309139]  [<c11b902d>] inotify_freeing_mark+0xd/0x10
[ 1078.309143]  [<c11b7faa>] fsnotify_destroy_mark+0xda/0x140
[ 1078.309148]  [<c11b832b>] fsnotify_clear_marks_by_group_flags+0xbb/0xe0
[ 1078.309154]  [<c11b8362>] fsnotify_clear_marks_by_group+0x12/0x20
[ 1078.309158]  [<c11b9375>] inotify_release+0x25/0x60
[ 1078.309163]  [<c117832f>] __fput+0xaf/0x1d0
[ 1078.309168]  [<c117846d>] fput+0x1d/0x30
[ 1078.309172]  [<c1173834>] filp_close+0x54/0x80
[ 1078.309178]  [<c104c1f8>] close_files+0xf8/0x1f0
[ 1078.309183]  [<c104c128>] ? close_files+0x28/0x1f0
[ 1078.309188]  [<c104c304>] put_files_struct.part.12+0x14/0x180
[ 1078.309193]  [<c132d4ce>] ? do_raw_spin_unlock+0x4e/0x90
[ 1078.309198]  [<c104de8d>] put_files_struct+0x1d/0x30
[ 1078.309203]  [<c104df43>] exit_files+0x43/0x50
[ 1078.309208]  [<c104e3fd>] do_exit+0x14d/0x450
[ 1078.309213]  [<c104e848>] do_group_exit+0x38/0xa0
[ 1078.309219]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.309223]  [<c1060a16>] get_signal_to_deliver+0x1c6/0x470
[ 1078.309228]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.309234]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.309239]  [<c10169df>] do_signal+0x3f/0xd0
[ 1078.309244]  [<c1060e43>] ? set_current_blocked+0x43/0x50
[ 1078.309248]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.309253]  [<c178ee99>] ? bad_area_nosemaphore+0x17/0x19
[ 1078.309259]  [<c17a96dc>] ? do_page_fault+0x3fc/0x4f0
[ 1078.309264]  [<c155ab13>] ? sys_socketcall+0x2e3/0x330
[ 1078.309269]  [<c17a5d56>] ? work_notifysig+0x11/0x2b
[ 1078.309274]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.309279]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.309284]  [<c1016ccd>] do_notify_resume+0x5d/0x80
[ 1078.309289]  [<c17a5d6a>] work_notifysig+0x25/0x2b
[ 1078.309294]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.309309] BUG: scheduling while atomic: NetworkManager/3953/0x10000002
[ 1078.309312] INFO: lockdep is turned off.
[ 1078.309314] Modules linked in: pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables xt_CHECKSUM acpi_cpufreq mperf irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 ipw2200 pcmcia_rsrc pcmcia_core radeon libipw floppy video parport_pc parport ttm drm_kms_helper drm i2c_algo_bit cfbfillrect cfbcopyarea cfbimgblt intel_agp intel_gtt agpgart raid10 raid456 async_memcpy async_pq async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom [last unloaded: scsi_wait_scan]
[ 1078.309396] Pid: 3953, comm: NetworkManager Tainted: G        W  O 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty #22
[ 1078.309400] Call Trace:
[ 1078.309405]  [<c178fb87>] __schedule_bug+0x7d/0x84
[ 1078.309409]  [<c17a3eea>] __schedule+0x6ca/0x780
[ 1078.309414]  [<c1088b87>] ? __enqueue_entity+0x77/0x80
[ 1078.309419]  [<c1081474>] ? resched_task+0x24/0x70
[ 1078.309424]  [<c108d2be>] ? check_preempt_wakeup+0x19e/0x230
[ 1078.309429]  [<c1082752>] ? check_preempt_curr+0x72/0x90
[ 1078.309434]  [<c1082be2>] ? ttwu_queue+0x42/0xc0
[ 1078.309439]  [<c107d465>] ? __might_sleep+0x35/0x1d0
[ 1078.309444]  [<c1082a8b>] __cond_resched+0x1b/0x30
[ 1078.309448]  [<c17a4019>] _cond_resched+0x29/0x30
[ 1078.309453]  [<c11631a3>] kmem_cache_alloc+0x43/0x2b0
[ 1078.309458]  [<c10ade0b>] ? trace_hardirqs_off+0xb/0x10
[ 1078.309463]  [<c17a5585>] ? _raw_spin_unlock_irqrestore+0x65/0x70
[ 1078.309468]  [<c11b7511>] ? fsnotify_create_event+0x31/0x170
[ 1078.309473]  [<c11b7511>] fsnotify_create_event+0x31/0x170
[ 1078.309477]  [<c107c5d4>] ? __wake_up+0x44/0x50
[ 1078.309482]  [<c17a5556>] ? _raw_spin_unlock_irqrestore+0x36/0x70
[ 1078.309488]  [<c11b9dc3>] inotify_ignored_and_remove_idr+0x43/0xc0
[ 1078.309493]  [<c11b902d>] inotify_freeing_mark+0xd/0x10
[ 1078.309497]  [<c11b7faa>] fsnotify_destroy_mark+0xda/0x140
[ 1078.309502]  [<c11b832b>] fsnotify_clear_marks_by_group_flags+0xbb/0xe0
[ 1078.309508]  [<c11b8362>] fsnotify_clear_marks_by_group+0x12/0x20
[ 1078.309512]  [<c11b9375>] inotify_release+0x25/0x60
[ 1078.309517]  [<c117832f>] __fput+0xaf/0x1d0
[ 1078.309522]  [<c117846d>] fput+0x1d/0x30
[ 1078.309526]  [<c1173834>] filp_close+0x54/0x80
[ 1078.309531]  [<c104c1f8>] close_files+0xf8/0x1f0
[ 1078.309536]  [<c104c128>] ? close_files+0x28/0x1f0
[ 1078.309542]  [<c104c304>] put_files_struct.part.12+0x14/0x180
[ 1078.309547]  [<c132d4ce>] ? do_raw_spin_unlock+0x4e/0x90
[ 1078.309552]  [<c104de8d>] put_files_struct+0x1d/0x30
[ 1078.309557]  [<c104df43>] exit_files+0x43/0x50
[ 1078.309562]  [<c104e3fd>] do_exit+0x14d/0x450
[ 1078.309567]  [<c104e848>] do_group_exit+0x38/0xa0
[ 1078.309573]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.309577]  [<c1060a16>] get_signal_to_deliver+0x1c6/0x470
[ 1078.309582]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.309588]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.309593]  [<c10169df>] do_signal+0x3f/0xd0
[ 1078.309598]  [<c1060e43>] ? set_current_blocked+0x43/0x50
[ 1078.309602]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.309607]  [<c178ee99>] ? bad_area_nosemaphore+0x17/0x19
[ 1078.309613]  [<c17a96dc>] ? do_page_fault+0x3fc/0x4f0
[ 1078.309618]  [<c155ab13>] ? sys_socketcall+0x2e3/0x330
[ 1078.309623]  [<c17a5d56>] ? work_notifysig+0x11/0x2b
[ 1078.309628]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.309633]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.309638]  [<c1016ccd>] do_notify_resume+0x5d/0x80
[ 1078.309643]  [<c17a5d6a>] work_notifysig+0x25/0x2b
[ 1078.309648]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.309663] BUG: scheduling while atomic: NetworkManager/3953/0x10000002
[ 1078.309666] INFO: lockdep is turned off.
[ 1078.309668] Modules linked in: pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables xt_CHECKSUM acpi_cpufreq mperf irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 ipw2200 pcmcia_rsrc pcmcia_core radeon libipw floppy video parport_pc parport ttm drm_kms_helper drm i2c_algo_bit cfbfillrect cfbcopyarea cfbimgblt intel_agp intel_gtt agpgart raid10 raid456 async_memcpy async_pq async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom [last unloaded: scsi_wait_scan]
[ 1078.309750] Pid: 3953, comm: NetworkManager Tainted: G        W  O 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty #22
[ 1078.309753] Call Trace:
[ 1078.309758]  [<c178fb87>] __schedule_bug+0x7d/0x84
[ 1078.309763]  [<c17a3eea>] __schedule+0x6ca/0x780
[ 1078.309768]  [<c1088b87>] ? __enqueue_entity+0x77/0x80
[ 1078.309773]  [<c1081474>] ? resched_task+0x24/0x70
[ 1078.309778]  [<c108d2be>] ? check_preempt_wakeup+0x19e/0x230
[ 1078.309783]  [<c1082752>] ? check_preempt_curr+0x72/0x90
[ 1078.309788]  [<c1082be2>] ? ttwu_queue+0x42/0xc0
[ 1078.309862]  [<c107d465>] ? __might_sleep+0x35/0x1d0
[ 1078.309867]  [<c1082a8b>] __cond_resched+0x1b/0x30
[ 1078.309872]  [<c17a4019>] _cond_resched+0x29/0x30
[ 1078.309877]  [<c11631a3>] kmem_cache_alloc+0x43/0x2b0
[ 1078.309882]  [<c10ade0b>] ? trace_hardirqs_off+0xb/0x10
[ 1078.309887]  [<c17a5585>] ? _raw_spin_unlock_irqrestore+0x65/0x70
[ 1078.309892]  [<c11b7511>] ? fsnotify_create_event+0x31/0x170
[ 1078.309897]  [<c11b7511>] fsnotify_create_event+0x31/0x170
[ 1078.309901]  [<c107c5d4>] ? __wake_up+0x44/0x50
[ 1078.309906]  [<c17a5556>] ? _raw_spin_unlock_irqrestore+0x36/0x70
[ 1078.309912]  [<c11b9dc3>] inotify_ignored_and_remove_idr+0x43/0xc0
[ 1078.309917]  [<c11b902d>] inotify_freeing_mark+0xd/0x10
[ 1078.309921]  [<c11b7faa>] fsnotify_destroy_mark+0xda/0x140
[ 1078.309926]  [<c11b832b>] fsnotify_clear_marks_by_group_flags+0xbb/0xe0
[ 1078.309932]  [<c11b8362>] fsnotify_clear_marks_by_group+0x12/0x20
[ 1078.309936]  [<c11b9375>] inotify_release+0x25/0x60
[ 1078.309941]  [<c117832f>] __fput+0xaf/0x1d0
[ 1078.309946]  [<c117846d>] fput+0x1d/0x30
[ 1078.309950]  [<c1173834>] filp_close+0x54/0x80
[ 1078.309955]  [<c104c1f8>] close_files+0xf8/0x1f0
[ 1078.309960]  [<c104c128>] ? close_files+0x28/0x1f0
[ 1078.309966]  [<c104c304>] put_files_struct.part.12+0x14/0x180
[ 1078.309971]  [<c132d4ce>] ? do_raw_spin_unlock+0x4e/0x90
[ 1078.309976]  [<c104de8d>] put_files_struct+0x1d/0x30
[ 1078.309981]  [<c104df43>] exit_files+0x43/0x50
[ 1078.309986]  [<c104e3fd>] do_exit+0x14d/0x450
[ 1078.309991]  [<c104e848>] do_group_exit+0x38/0xa0
[ 1078.309997]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.310001]  [<c1060a16>] get_signal_to_deliver+0x1c6/0x470
[ 1078.310006]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.310012]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.310017]  [<c10169df>] do_signal+0x3f/0xd0
[ 1078.310022]  [<c1060e43>] ? set_current_blocked+0x43/0x50
[ 1078.310026]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.310031]  [<c178ee99>] ? bad_area_nosemaphore+0x17/0x19
[ 1078.310037]  [<c17a96dc>] ? do_page_fault+0x3fc/0x4f0
[ 1078.310042]  [<c155ab13>] ? sys_socketcall+0x2e3/0x330
[ 1078.310047]  [<c17a5d56>] ? work_notifysig+0x11/0x2b
[ 1078.310052]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.310057]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.310062]  [<c1016ccd>] do_notify_resume+0x5d/0x80
[ 1078.310067]  [<c17a5d6a>] work_notifysig+0x25/0x2b
[ 1078.310072]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.310088] BUG: scheduling while atomic: NetworkManager/3953/0x10000002
[ 1078.310091] INFO: lockdep is turned off.
[ 1078.310094] Modules linked in: pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables xt_CHECKSUM acpi_cpufreq mperf irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 ipw2200 pcmcia_rsrc pcmcia_core radeon libipw floppy video parport_pc parport ttm drm_kms_helper drm i2c_algo_bit cfbfillrect cfbcopyarea cfbimgblt intel_agp intel_gtt agpgart raid10 raid456 async_memcpy async_pq async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom [last unloaded: scsi_wait_scan]
[ 1078.310176] Pid: 3953, comm: NetworkManager Tainted: G        W  O 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty #22
[ 1078.310179] Call Trace:
[ 1078.310184]  [<c178fb87>] __schedule_bug+0x7d/0x84
[ 1078.310189]  [<c17a3eea>] __schedule+0x6ca/0x780
[ 1078.310193]  [<c1088b87>] ? __enqueue_entity+0x77/0x80
[ 1078.310199]  [<c1081474>] ? resched_task+0x24/0x70
[ 1078.310203]  [<c108d2be>] ? check_preempt_wakeup+0x19e/0x230
[ 1078.310209]  [<c1082752>] ? check_preempt_curr+0x72/0x90
[ 1078.310213]  [<c1082be2>] ? ttwu_queue+0x42/0xc0
[ 1078.310218]  [<c107d465>] ? __might_sleep+0x35/0x1d0
[ 1078.310223]  [<c1082a8b>] __cond_resched+0x1b/0x30
[ 1078.310227]  [<c17a4019>] _cond_resched+0x29/0x30
[ 1078.310233]  [<c11631a3>] kmem_cache_alloc+0x43/0x2b0
[ 1078.310238]  [<c10ade0b>] ? trace_hardirqs_off+0xb/0x10
[ 1078.310242]  [<c17a5585>] ? _raw_spin_unlock_irqrestore+0x65/0x70
[ 1078.310247]  [<c11b7511>] ? fsnotify_create_event+0x31/0x170
[ 1078.310252]  [<c11b7511>] fsnotify_create_event+0x31/0x170
[ 1078.310257]  [<c107c5d4>] ? __wake_up+0x44/0x50
[ 1078.310262]  [<c17a5556>] ? _raw_spin_unlock_irqrestore+0x36/0x70
[ 1078.310267]  [<c11b9dc3>] inotify_ignored_and_remove_idr+0x43/0xc0
[ 1078.310272]  [<c11b902d>] inotify_freeing_mark+0xd/0x10
[ 1078.310277]  [<c11b7faa>] fsnotify_destroy_mark+0xda/0x140
[ 1078.310282]  [<c11b832b>] fsnotify_clear_marks_by_group_flags+0xbb/0xe0
[ 1078.310287]  [<c11b8362>] fsnotify_clear_marks_by_group+0x12/0x20
[ 1078.310292]  [<c11b9375>] inotify_release+0x25/0x60
[ 1078.310297]  [<c117832f>] __fput+0xaf/0x1d0
[ 1078.310301]  [<c117846d>] fput+0x1d/0x30
[ 1078.310306]  [<c1173834>] filp_close+0x54/0x80
[ 1078.310311]  [<c104c1f8>] close_files+0xf8/0x1f0
[ 1078.310316]  [<c104c128>] ? close_files+0x28/0x1f0
[ 1078.310321]  [<c104c304>] put_files_struct.part.12+0x14/0x180
[ 1078.310326]  [<c132d4ce>] ? do_raw_spin_unlock+0x4e/0x90
[ 1078.310331]  [<c104de8d>] put_files_struct+0x1d/0x30
[ 1078.310336]  [<c104df43>] exit_files+0x43/0x50
[ 1078.310341]  [<c104e3fd>] do_exit+0x14d/0x450
[ 1078.310347]  [<c104e848>] do_group_exit+0x38/0xa0
[ 1078.310352]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.310357]  [<c1060a16>] get_signal_to_deliver+0x1c6/0x470
[ 1078.310362]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.310367]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.310372]  [<c10169df>] do_signal+0x3f/0xd0
[ 1078.310377]  [<c1060e43>] ? set_current_blocked+0x43/0x50
[ 1078.310382]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.310387]  [<c178ee99>] ? bad_area_nosemaphore+0x17/0x19
[ 1078.310392]  [<c17a96dc>] ? do_page_fault+0x3fc/0x4f0
[ 1078.310398]  [<c155ab13>] ? sys_socketcall+0x2e3/0x330
[ 1078.310402]  [<c17a5d56>] ? work_notifysig+0x11/0x2b
[ 1078.310407]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.310413]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.310418]  [<c1016ccd>] do_notify_resume+0x5d/0x80
[ 1078.310422]  [<c17a5d6a>] work_notifysig+0x25/0x2b
[ 1078.310428]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.310494] BUG: scheduling while atomic: NetworkManager/3953/0x10000002
[ 1078.310497] INFO: lockdep is turned off.
[ 1078.310499] Modules linked in: pci_stub vboxpci(O) vboxnetadp(O) vboxnetflt(O) vboxdrv(O) pktcdvd ebtable_nat ebtables xt_CHECKSUM acpi_cpufreq mperf irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia yenta_socket i2c_i801 ipw2200 pcmcia_rsrc pcmcia_core radeon libipw floppy video parport_pc parport ttm drm_kms_helper drm i2c_algo_bit cfbfillrect cfbcopyarea cfbimgblt intel_agp intel_gtt agpgart raid10 raid456 async_memcpy async_pq async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom [last unloaded: scsi_wait_scan]
[ 1078.310581] Pid: 3953, comm: NetworkManager Tainted: G        W  O 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty #22
[ 1078.310585] Call Trace:
[ 1078.310590]  [<c178fb87>] __schedule_bug+0x7d/0x84
[ 1078.310595]  [<c17a3eea>] __schedule+0x6ca/0x780
[ 1078.310599]  [<c1088b87>] ? __enqueue_entity+0x77/0x80
[ 1078.310605]  [<c1081474>] ? resched_task+0x24/0x70
[ 1078.310609]  [<c108d2be>] ? check_preempt_wakeup+0x19e/0x230
[ 1078.310615]  [<c1082752>] ? check_preempt_curr+0x72/0x90
[ 1078.310619]  [<c1082be2>] ? ttwu_queue+0x42/0xc0
[ 1078.310624]  [<c107d465>] ? __might_sleep+0x35/0x1d0
[ 1078.310629]  [<c1082a8b>] __cond_resched+0x1b/0x30
[ 1078.310633]  [<c17a4019>] _cond_resched+0x29/0x30
[ 1078.310639]  [<c11631a3>] kmem_cache_alloc+0x43/0x2b0
[ 1078.310644]  [<c10ade0b>] ? trace_hardirqs_off+0xb/0x10
[ 1078.310648]  [<c17a5585>] ? _raw_spin_unlock_irqrestore+0x65/0x70
[ 1078.310653]  [<c11b7511>] ? fsnotify_create_event+0x31/0x170
[ 1078.310658]  [<c11b7511>] fsnotify_create_event+0x31/0x170
[ 1078.310663]  [<c107c5d4>] ? __wake_up+0x44/0x50
[ 1078.310668]  [<c17a5556>] ? _raw_spin_unlock_irqrestore+0x36/0x70
[ 1078.310673]  [<c11b9dc3>] inotify_ignored_and_remove_idr+0x43/0xc0
[ 1078.310678]  [<c11b902d>] inotify_freeing_mark+0xd/0x10
[ 1078.310683]  [<c11b7faa>] fsnotify_destroy_mark+0xda/0x140
[ 1078.310688]  [<c11b832b>] fsnotify_clear_marks_by_group_flags+0xbb/0xe0
[ 1078.310693]  [<c11b8362>] fsnotify_clear_marks_by_group+0x12/0x20
[ 1078.310698]  [<c11b9375>] inotify_release+0x25/0x60
[ 1078.310703]  [<c117832f>] __fput+0xaf/0x1d0
[ 1078.310708]  [<c117846d>] fput+0x1d/0x30
[ 1078.310712]  [<c1173834>] filp_close+0x54/0x80
[ 1078.310717]  [<c104c1f8>] close_files+0xf8/0x1f0
[ 1078.310722]  [<c104c128>] ? close_files+0x28/0x1f0
[ 1078.310727]  [<c104c304>] put_files_struct.part.12+0x14/0x180
[ 1078.310732]  [<c132d4ce>] ? do_raw_spin_unlock+0x4e/0x90
[ 1078.310738]  [<c104de8d>] put_files_struct+0x1d/0x30
[ 1078.310743]  [<c104df43>] exit_files+0x43/0x50
[ 1078.310747]  [<c104e3fd>] do_exit+0x14d/0x450
[ 1078.310753]  [<c104e848>] do_group_exit+0x38/0xa0
[ 1078.310758]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.310763]  [<c1060a16>] get_signal_to_deliver+0x1c6/0x470
[ 1078.310768]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.310774]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.310779]  [<c10169df>] do_signal+0x3f/0xd0
[ 1078.310783]  [<c1060e43>] ? set_current_blocked+0x43/0x50
[ 1078.310788]  [<c17a5507>] ? _raw_spin_unlock_irq+0x27/0x40
[ 1078.310793]  [<c178ee99>] ? bad_area_nosemaphore+0x17/0x19
[ 1078.310798]  [<c17a96dc>] ? do_page_fault+0x3fc/0x4f0
[ 1078.310804]  [<c155ab13>] ? sys_socketcall+0x2e3/0x330
[ 1078.310809]  [<c17a5d56>] ? work_notifysig+0x11/0x2b
[ 1078.310814]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.310819]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.310824]  [<c1016ccd>] do_notify_resume+0x5d/0x80
[ 1078.310829]  [<c17a5d6a>] work_notifysig+0x25/0x2b
[ 1078.310834]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190



2)

this is after suspend/resume cycle on laptop

[    0.000000] Linux version 3.3.0-rc3-t43-devel-smp-00272-g7ada1dd-dirty (baryluk@sredniczarny) (gcc version 4.6.2 (Debian 4.6.2-14) ) #25 SMP Wed Feb 15 16:57:40 CET 2012
...
suspend
...
resume
...
[ 9136.204156] BUG: sleeping function called from invalid context at kernel/mutex.c:271
[ 9136.204162] in_atomic(): 1, irqs_disabled(): 0, pid: 11404, name: ip
[ 9136.204166] INFO: lockdep is turned off.
[ 9136.204170] Pid: 11404, comm: ip Tainted: G        W    3.3.0-rc3-t43-devel-smp-00272-g7ada1dd-dirty #25
[ 9136.204174] Call Trace:
[ 9136.204182]  [<c107f2d4>] __might_sleep+0x124/0x1d0
[ 9136.204188]  [<c17b2cfa>] mutex_lock_nested+0x2a/0x310
[ 9136.204194]  [<c15a9f28>] ? netlink_dump+0x1b8/0x200
[ 9136.204200]  [<c15ab2b8>] ? netlink_dump_start+0xb8/0x150
[ 9136.204206]  [<c16689f0>] ? fib6_net_init+0x1f0/0x1f0
[ 9136.204211]  [<c1590ab4>] rtnl_lock+0x14/0x20
[ 9136.204216]  [<c1592a42>] rtnetlink_rcv_msg+0x2a2/0x330
[ 9136.204221]  [<c16689f0>] ? fib6_net_init+0x1f0/0x1f0
[ 9136.204226]  [<c1590ab4>] ? rtnl_lock+0x14/0x20
[ 9136.204231]  [<c16689f0>] ? fib6_net_init+0x1f0/0x1f0
[ 9136.204235]  [<c15927a0>] ? __rtnl_unlock+0x20/0x20
[ 9136.204240]  [<c15acdae>] netlink_rcv_skb+0x8e/0xb0
[ 9136.204245]  [<c1590ae0>] rtnetlink_rcv+0x20/0x30
[ 9136.204250]  [<c15ac55b>] netlink_unicast+0x17b/0x1c0
[ 9136.204255]  [<c15ac8cc>] netlink_sendmsg+0x32c/0x3d0
[ 9136.204262]  [<c1567d95>] sock_sendmsg+0xc5/0x100
[ 9136.204267]  [<c1089aad>] ? cpuacct_charge+0xdd/0x1f0
[ 9136.204273]  [<c1184f1d>] ? fget_light+0x18d/0x410
[ 9136.204278]  [<c156a257>] sys_sendto+0xb7/0xe0
[ 9136.204284]  [<c1082f17>] ? finish_task_switch+0x77/0x200
[ 9136.204289]  [<c17b5f07>] ? _raw_spin_unlock_irq+0x27/0x40
[ 9136.204295]  [<c10b3038>] ? trace_hardirqs_on_caller+0x18/0x120
[ 9136.204300]  [<c10b314b>] ? trace_hardirqs_on+0xb/0x10
[ 9136.204305]  [<c17b5f07>] ? _raw_spin_unlock_irq+0x27/0x40
[ 9136.204310]  [<c1082f17>] ? finish_task_switch+0x77/0x200
[ 9136.204322]  [<c114d3d4>] ? might_fault+0x54/0xb0
[ 9136.204328]  [<c156a2b7>] sys_send+0x37/0x40
[ 9136.204333]  [<c156ab8a>] sys_socketcall+0x1ba/0x330
[ 9136.204339]  [<c17be518>] sysenter_do_call+0x12/0x38
[ 9136.204343] BUG: scheduling while atomic: ip/11404/0x10000002
[ 9136.204346] INFO: lockdep is turned off.
[ 9136.204349] Modules linked in: pktcdvd ebtable_nat ebtables xt_CHECKSUM irtty_sir sir_dev irda crc_ccitt dummy ppdev lp bnep bluetooth lib80211_crypt_ccmp uinput nfsd pcmcia radeon ipw2200 i2c_i801 yenta_socket libipw pcmcia_rsrc pcmcia_core ttm parport_pc drm_kms_helper video floppy parport drm i2c_algo_bit cfbfillrect cfbcopyarea intel_agp cfbimgblt intel_gtt agpgart raid10 raid456 async_memcpy async_pq async_xor xor async_raid6_recov async_tx raid6_pq sr_mod cdrom [last unloaded: scsi_wait_scan]
[ 9136.204424] Pid: 11404, comm: ip Tainted: G        W    3.3.0-rc3-t43-devel-smp-00272-g7ada1dd-dirty #25
[ 9136.204427] Call Trace:
[ 9136.204432]  [<c17a0446>] __schedule_bug+0x7d/0x84
[ 9136.204437]  [<c17b48ea>] __schedule+0x6ca/0x780
[ 9136.204443]  [<c101998c>] ? show_trace_log_lvl+0x4c/0x60
[ 9136.204448]  [<c179e311>] ? dump_stack+0x73/0x7a
[ 9136.204454]  [<c107f2d4>] ? __might_sleep+0x124/0x1d0
[ 9136.204459]  [<c108480b>] __cond_resched+0x1b/0x30
[ 9136.204463]  [<c17b4a19>] _cond_resched+0x29/0x30
[ 9136.204468]  [<c17b2cff>] mutex_lock_nested+0x2f/0x310
[ 9136.204473]  [<c15a9f28>] ? netlink_dump+0x1b8/0x200
[ 9136.204478]  [<c15ab2b8>] ? netlink_dump_start+0xb8/0x150
[ 9136.204484]  [<c16689f0>] ? fib6_net_init+0x1f0/0x1f0
[ 9136.204488]  [<c1590ab4>] rtnl_lock+0x14/0x20
[ 9136.204493]  [<c1592a42>] rtnetlink_rcv_msg+0x2a2/0x330
[ 9136.204498]  [<c16689f0>] ? fib6_net_init+0x1f0/0x1f0
[ 9136.204503]  [<c1590ab4>] ? rtnl_lock+0x14/0x20
[ 9136.204508]  [<c16689f0>] ? fib6_net_init+0x1f0/0x1f0
[ 9136.204512]  [<c15927a0>] ? __rtnl_unlock+0x20/0x20
[ 9136.204517]  [<c15acdae>] netlink_rcv_skb+0x8e/0xb0
[ 9136.204522]  [<c1590ae0>] rtnetlink_rcv+0x20/0x30
[ 9136.204527]  [<c15ac55b>] netlink_unicast+0x17b/0x1c0
[ 9136.204532]  [<c15ac8cc>] netlink_sendmsg+0x32c/0x3d0
[ 9136.204538]  [<c1567d95>] sock_sendmsg+0xc5/0x100
[ 9136.204543]  [<c1089aad>] ? cpuacct_charge+0xdd/0x1f0
[ 9136.204548]  [<c1184f1d>] ? fget_light+0x18d/0x410
[ 9136.204554]  [<c156a257>] sys_sendto+0xb7/0xe0
[ 9136.204559]  [<c1082f17>] ? finish_task_switch+0x77/0x200
[ 9136.204564]  [<c17b5f07>] ? _raw_spin_unlock_irq+0x27/0x40
[ 9136.204569]  [<c10b3038>] ? trace_hardirqs_on_caller+0x18/0x120
[ 9136.204574]  [<c10b314b>] ? trace_hardirqs_on+0xb/0x10
[ 9136.204579]  [<c17b5f07>] ? _raw_spin_unlock_irq+0x27/0x40
[ 9136.204584]  [<c1082f17>] ? finish_task_switch+0x77/0x200
[ 9136.204590]  [<c114d3d4>] ? might_fault+0x54/0xb0
[ 9136.204595]  [<c156a2b7>] sys_send+0x37/0x40
[ 9136.204600]  [<c156ab8a>] sys_socketcall+0x1ba/0x330
[ 9136.204605]  [<c17be518>] sysenter_do_call+0x12/0x38
[ 9136.204684] ip[11404]: segfault at b7637a60 ip b7637a60 sp bf8cbe2c error 14
[ 9136.204700] note: ip[11404] exited with preempt_count 1


I'm going to didable IRDA initscripts, so I can check if this
is actually a problem.

It actually looks like this bug actually:

https://bugzilla.kernel.org/show_bug.cgi?id=42629
http://marc.info/?l=linux-kernel&m=132647921304184&w=2



-- 
Witold Baryluk





  

    
Re: [Bug 42754] New: BUG: sleeping function called from invalid context at mm/memory.c:3924

    

      From: Eric Dumazet <hidden>

      Date: 2012-02-16 15:25:04 
    

  

  
Le jeudi 16 février 2012 à 16:10 +0100, Witold Baryluk a écrit :
On 02-15 14:02, Peter Zijlstra wrote:
quoted
On Sun, 2012-02-12 at 09:50 -0800, Paul E. McKenney wrote:
quoted
quoted
I do not know why lockdep is disabled, because I configured kernel to
keep telling my about lock dependency problems even after showing first
one. AFAIK. 
That setting is only relevant to RCU, normal lockdep reports will always
disable lockdep.
One more thing about a bug.

I was able to reproduce bug yestarday , and again today.

First one is again in NetworkManager process (just after loging in to
gnome, exactly like previously), and again NetworkManager process is
killed. And again restarting NM manually make it happy (and works
without further problems). So indeed it looks to be problem with
netlink, because netlink_recvmsg is common call here.

Second one is also in netlink, but process is this time ip, and message
is

[ 9136.204156] BUG: sleeping function called from invalid context at kernel/mutex.c:271

full stacks bellow.

Regards,
Witek

1)

[    0.000000] Linux version 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty (baryluk@sredniczarny) (gcc version 4.6.2 (Debian 4.6.2-14) ) #22 SMP Sat Feb 11 23:16:44 CET 2012
..
[ 1078.282836] BUG: sleeping function called from invalid context at mm/memory.c:3924
[ 1078.282843] in_atomic(): 1, irqs_disabled(): 0, pid: 3953, name: NetworkManager
[ 1078.282847] INFO: lockdep is turned off.
[ 1078.282852] Pid: 3953, comm: NetworkManager Tainted: G        W  O 3.3.0-rc3-t43-devel-smp-00188-g3ec1e88-dirty #22
[ 1078.282856] Call Trace:
[ 1078.282868]  [<c107d554>] __might_sleep+0x124/0x1d0
[ 1078.282875]  [<c11400ee>] might_fault+0x2e/0xb0
[ 1078.282882]  [<c131d3ab>] copy_to_user+0x3b/0x60
[ 1078.282889]  [<c1568172>] put_cmsg+0x52/0xd0
[ 1078.282903]  [<c159a917>] netlink_recvmsg+0x287/0x340
[ 1078.282910]  [<c1557aa3>] sock_recvmsg+0xd3/0x110
[ 1078.282916]  [<c1140114>] ? might_fault+0x54/0xb0
[ 1078.282921]  [<c15663bc>] ? verify_iovec+0x4c/0xc0
[ 1078.282926]  [<c15579d0>] ? sock_sendmsg_nosec+0x100/0x100
[ 1078.282931]  [<c15588f4>] __sys_recvmsg+0x114/0x1e0
[ 1078.282938]  [<c1082752>] ? check_preempt_curr+0x72/0x90
[ 1078.282943]  [<c1082be2>] ? ttwu_queue+0x42/0xc0
[ 1078.282949]  [<c10b26f1>] ? __lock_acquired+0x2e1/0x330
[ 1078.282956]  [<c1177a65>] ? fget_light+0xc5/0x410
[ 1078.282961]  [<c1177a79>] ? fget_light+0xd9/0x410
[ 1078.282965]  [<c11779e5>] ? fget_light+0x45/0x410
[ 1078.282971]  [<c155a5b9>] sys_recvmsg+0x39/0x60
[ 1078.282976]  [<c155ab13>] sys_socketcall+0x2e3/0x330
[ 1078.282982]  [<c17adacd>] ? sysenter_exit+0xf/0x1a
[ 1078.282988]  [<c131cba8>] ? trace_hardirqs_on_thunk+0xc/0x10
[ 1078.282993]  [<c17ada98>] sysenter_do_call+0x12/0x38
[ 1078.282999]  [<c17a007b>] ? trace_packet+0x104/0x154
[ 1078.294339]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
[ 1078.294344]  [<c10b1298>] ? trace_hardirqs_on_caller+0x18/0x120
[ 1078.294349]  [<c1016ccd>] do_notify_resume+0x5d/0x80
[ 1078.294354]  [<c17a5d6a>] work_notifysig+0x25/0x2b
[ 1078.294359]  [<c17a92e0>] ? vmalloc_fault+0x190/0x190
Yes, I am aware of this and I'll take a look.

Thanks




    
  

  
    

      

        Keyboard shortcuts
      

      

        
          
hback out one level

          
jnext message in thread

          
kprevious message in thread

          
ldrill in

          
Escclose help / fold thread tree

          
?toggle this help