Skip to contentSkip to conversation

New: BUG: sleeping function called from invalid context at mm/memory.c:3924

Bug 42754 Andrew Morton 6 participants 9 messages Feb 10, 2012 – Feb 16, 2012 1 message not in the archive

Subsystems (2)
lore
Share & tools
lore

A message that is not in the archive (sent off-list or not yet received): [email protected]/

#1 lore raw

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

(It's 3.3-rc2)

Quoted 59 lines · On Fri, 10 Feb 2012 02:24:10 GMT [email protected] 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: [email protected]
        ReportedBy: [email protected]
        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)
Quoted 7 lines

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.

#2 lore raw
Quoted 80 lines · Andrew Morton

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

(It's 3.3-rc2)

Quoted 59 lines · On Fri, 10 Feb 2012 02:24:10 GMT [email protected] 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: [email protected]
        ReportedBy: [email protected]
        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)
Quoted 7 lines

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.

Quoted 8 lines

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

Signature · 1 line
Witold Baryluk
#3 lore raw
Quoted 2 lines · Witold Baryluk

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.

#4 lore raw
In reply to Witold Baryluk

Witold Baryluk <[email protected]> :

Quoted 1 line · Andrew Morton

[...]

Quoted 1 line

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

For the sirdev part:

[...]

Quoted 10 lines
[  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.

Quoted 4 lines
[  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]

[...]

Quoted 4 lines
[  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

[...]

Quoted 19 lines
[  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

[...]

Quoted 10 lines
[  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 ?

Signature · 1 line
Ueimor
#5 lore raw
In reply to Witold Baryluk
Quoted 104 lines · Witold Baryluk
Quoted 80 lines · Andrew Morton

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

(It's 3.3-rc2)

Quoted 59 lines · On Fri, 10 Feb 2012 02:24:10 GMT [email protected] 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: [email protected]
        ReportedBy: [email protected]
        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)
Quoted 7 lines

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.

Quoted 8 lines

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.

Quoted 6 lines

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

Quoted 248 lines
[   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

Signature · 5 lines
Witold Baryluk
--
To unsubscribe from this list: send the line "unsubscribe netdev" in
the body of a message to [email protected]
More majordomo info at  http://vger.kernel.org/majordomo-info.html
#6 lore raw
Quoted 3 lines · Paul E. McKenney
Quoted 3 lines

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.

#7 lore raw
Quoted 7 lines · Peter Zijlstra
Quoted 3 lines · Paul E. McKenney
Quoted 3 lines

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

Signature · 1 line
Witold Baryluk
#8 lore raw
Quoted 57 lines · Witold Baryluk
Quoted 7 lines · Peter Zijlstra
Quoted 3 lines · Paul E. McKenney
Quoted 3 lines

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
Quoted 8 lines
[ 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

#9 lore raw
In reply to Andrew Morton
Quoted 5 lines · Andrew Morton
Quoted 5 lines
[ 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 26 lines
Quoted 15 lines
[ 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
Quoted 8 lines
[ 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?