New: BUG: sleeping function called from invalid context at mm/memory.c:3924
Subsystems (2)
A message that is not in the archive (sent off-list or not yet received): [email protected]/
(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: YesCreated 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_natebtablesacpi_cpufreqmperfxt_CHECKSUMirtty_sirsir_devirdacrc_ccittdummy ppdev lp bnep rfcomm bluetoothlib80211_crypt_ccmpuinput nfsd pcmciayenta_socketi2c_i801radeon ipw2200 libipwpcmcia_rsrcpcmcia_corettmdrm_kms_helperparport_pcparport cfbfillrect cfbcopyarea cfbimgblt raid10 raid456async_memcpyasync_pqasync_xorxorasync_raid6_recovasync_txraid6_pqsr_modcdrom 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.
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: YesCreated 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_natebtablesacpi_cpufreqmperfxt_CHECKSUMirtty_sirsir_devirdacrc_ccittdummy ppdev lp bnep rfcomm bluetoothlib80211_crypt_ccmpuinput nfsd pcmciayenta_socketi2c_i801radeon ipw2200 libipwpcmcia_rsrcpcmcia_corettmdrm_kms_helperparport_pcparport cfbfillrect cfbcopyarea cfbimgblt raid10 raid456async_memcpyasync_pqasync_xorxorasync_raid6_recovasync_txraid6_pqsr_modcdrom floppy [last
unloaded:scsi_wait_scan]OK, so we have a pile of
in_atomicwarnings. 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/0x10But 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
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.
Witold Baryluk <[email protected]> :
Quoted 1 line · Andrew Morton
[...]
Quoted 1 line
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
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: YesCreated 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_natebtablesacpi_cpufreqmperfxt_CHECKSUMirtty_sirsir_devirdacrc_ccittdummy ppdev lp bnep rfcomm bluetoothlib80211_crypt_ccmpuinput nfsd pcmciayenta_socketi2c_i801radeon ipw2200 libipwpcmcia_rsrcpcmcia_corettmdrm_kms_helperparport_pcparport cfbfillrect cfbcopyarea cfbimgblt raid10 raid456async_memcpyasync_pqasync_xorxorasync_raid6_recovasync_txraid6_pqsr_modcdrom floppy [last
unloaded:scsi_wait_scan]OK, so we have a pile of
in_atomicwarnings. 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_idlewarning)
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:52so 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: OKAnd 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/0x10But 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,
WitekSignature · 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
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.
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
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_recvmsgis 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:271full stacks bellow.
Regards,
Witek1)
[ 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
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/0x410Quoted 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/0x38Peter, is there any way in which lockdep can help us find the culprit in the second case?