From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752520AbbGMNSq (ORCPT ); Mon, 13 Jul 2015 09:18:46 -0400 Received: from mta-out1.inet.fi ([62.71.2.229]:38166 "EHLO johanna2.inet.fi" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751614AbbGMNSn (ORCPT ); Mon, 13 Jul 2015 09:18:43 -0400 RazorGate-KAS: Rate: 5 RazorGate-KAS: {RECEIVED: dynamic ip detected} RazorGate-KAS: Envelope from: RazorGate-KAS: Version: 5.5.3 RazorGate-KAS: LuaCore: 80 2014-11-10_18-01-23 260f8afb9361da3c7edfd3a8e3a4ca908191ad29 RazorGate-KAS: Method: none RazorGate-KAS: Lua profiles 69136 [Nov 12 2014] RazorGate-KAS: Status: not_detected Date: Mon, 13 Jul 2015 16:18:25 +0300 From: "Kirill A. Shutemov" To: "David S. Miller" Cc: netdev@vger.kernel.org, linux-kernel@vger.kernel.org Subject: mmap()ed AF_NETLINK: lockdep and sleep-in-atomic warnings Message-ID: <20150713131825.GA16186@node.dhcp.inet.fi> MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline User-Agent: Mutt/1.5.23.1 (2014-03-12) Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Hi, This simple test-case trigers few locking asserts in kernel: #define _GNU_SOURCE #include #include #include #include #include #include #include #define SOL_NETLINK 270 int main(int argc, char **argv) { unsigned int block_size = 16 * 4096; struct nl_mmap_req req = { .nm_block_size = block_size, .nm_block_nr = 64, .nm_frame_size = 16384, .nm_frame_nr = 64 * block_size / 16384, }; unsigned int ring_size; int fd; fd = socket(AF_NETLINK, SOCK_RAW, NETLINK_GENERIC); if (setsockopt(fd, SOL_NETLINK, NETLINK_RX_RING, &req, sizeof(req)) < 0) exit(1); if (setsockopt(fd, SOL_NETLINK, NETLINK_TX_RING, &req, sizeof(req)) < 0) exit(1); ring_size = req.nm_block_nr * req.nm_block_size; mmap(NULL, 2 * ring_size, PROT_READ|PROT_WRITE, MAP_SHARED, fd, 0); return 0; } +++ exited with 0 +++ [ 2.500126] BUG: sleeping function called from invalid context at /home/kas/git/public/linux-mm/kernel/locking/mutex.c:616 [ 2.501328] in_atomic(): 1, irqs_disabled(): 0, pid: 1, name: init [ 2.501997] 3 locks held by init/1: [ 2.502380] #0: (reboot_mutex){+.+...}, at: [] SyS_reboot+0xa9/0x220 [ 2.503328] #1: ((reboot_notifier_list).rwsem){.+.+..}, at: [] __blocking_notifier_call_chain+0x39/0x70 [ 2.504659] #2: (rcu_callback){......}, at: [] rcu_do_batch.isra.49+0x160/0x10c0 [ 2.505724] Preemption disabled at:[] __delay+0xf/0x20 [ 2.506443] [ 2.506612] CPU: 1 PID: 1 Comm: init Not tainted 4.1.0-00009-gbddf4c4818e0 #253 [ 2.507378] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS Debian-1.8.2-1 04/01/2014 [ 2.508386] ffff88017b3d8000 ffff88027bc03c38 ffffffff81929ceb 0000000000000102 [ 2.509233] 0000000000000000 ffff88027bc03c68 ffffffff81085a9d 0000000000000002 [ 2.510057] ffffffff81ca2a20 0000000000000268 0000000000000000 ffff88027bc03c98 [ 2.510882] Call Trace: [ 2.511146] [] dump_stack+0x4f/0x7b [ 2.511763] [] ___might_sleep+0x16d/0x270 [ 2.512476] [] __might_sleep+0x4d/0x90 [ 2.513071] [] mutex_lock_nested+0x2f/0x430 [ 2.513683] [] ? _raw_spin_unlock_irqrestore+0x5d/0x80 [ 2.514385] [] ? __this_cpu_preempt_check+0x13/0x20 [ 2.515066] [] netlink_set_ring+0x1ed/0x350 [ 2.515694] [] ? netlink_undo_bind+0x70/0x70 [ 2.516411] [] netlink_sock_destruct+0x80/0x150 [ 2.517070] [] __sk_free+0x1d/0x160 [ 2.517607] [] sk_free+0x19/0x20 [ 2.518118] [] deferred_put_nlk_sk+0x20/0x30 [ 2.518735] [] rcu_do_batch.isra.49+0x79c/0x10c0 [ 2.519386] [] ? rcu_do_batch.isra.49+0x160/0x10c0 [ 2.520101] [] rcu_process_callbacks+0xdb/0x6d0 [ 2.520790] [] __do_softirq+0x152/0x630 [ 2.521370] [] irq_exit+0x8e/0xb0 [ 2.521895] [] smp_apic_timer_interrupt+0x46/0x60 [ 2.522558] [] ? __delay+0xf/0x20 [ 2.523079] [] apic_timer_interrupt+0x70/0x80 [ 2.523705] [] ? __delay+0xf/0x20 [ 2.524366] [] ? in_lock_functions+0x1b/0x20 [ 2.524995] [] get_parent_ip+0x11/0x50 [ 2.525562] [] preempt_count_sub+0x9f/0xf0 [ 2.526179] [] delay_tsc+0x68/0xc0 [ 2.526706] [] __delay+0xf/0x20 [ 2.527207] [] __const_udelay+0x2a/0x30 [ 2.527781] [] md_notify_reboot+0xea/0x100 [ 2.528489] [] ? __blocking_notifier_call_chain+0x39/0x70 [ 2.529236] [] notifier_call_chain+0x66/0x90 [ 2.529856] [] __blocking_notifier_call_chain+0x51/0x70 [ 2.530570] [] ? __lock_acquire+0x606/0xf50 [ 2.531172] [] blocking_notifier_call_chain+0x16/0x20 [ 2.531869] [] kernel_restart_prepare+0x1d/0x40 [ 2.532593] [] kernel_restart+0x16/0x60 [ 2.533183] [] SyS_reboot+0x157/0x220 [ 2.533738] [] ? __restore_xstate_sig+0xf8/0x720 [ 2.534390] [] ? debug_smp_processor_id+0x17/0x20 [ 2.535051] [] ? put_lock_stats.isra.19+0xe/0x30 [ 2.535707] [] ? _raw_spin_unlock_irq+0x30/0x60 [ 2.536446] [] ? preempt_count_sub+0xab/0xf0 [ 2.537112] [] ? syscall_return+0x11/0x54 [ 2.537709] [] ? __this_cpu_preempt_check+0x13/0x20 [ 2.538399] [] ? trace_hardirqs_on_caller+0xf3/0x240 [ 2.539094] [] ? trace_hardirqs_on_thunk+0x17/0x19 [ 2.539764] [] system_call_fastpath+0x12/0x6f [ 2.540523] [ 2.540695] ================================= [ 2.541161] [ INFO: inconsistent lock state ] [ 2.541618] 4.1.0-00009-gbddf4c4818e0 #253 Not tainted [ 2.542154] --------------------------------- [ 2.542610] inconsistent {SOFTIRQ-ON-W} -> {IN-SOFTIRQ-W} usage. [ 2.543236] init/1 [HC0[0]:SC1[1]:HE1:SE0] takes: [ 2.543729] (&nlk->pg_vec_lock){+.?.+.}, at: [] netlink_set_ring+0x1ed/0x350 [ 2.544503] {SOFTIRQ-ON-W} state was registered at: [ 2.544503] [] __lock_acquire+0xb0e/0xf50 [ 2.544503] [] lock_acquire+0xd2/0x2b0 [ 2.544503] [] mutex_lock_nested+0x71/0x430 [ 2.544503] [] netlink_set_ring+0x1ed/0x350 [ 2.544503] [] netlink_setsockopt+0x1b0/0x300 [ 2.544503] [] SyS_setsockopt+0x63/0xc0 [ 2.544503] [] tracesys_phase2+0x84/0x89 [ 2.544503] irq event stamp: 1159264 [ 2.544503] hardirqs last enabled at (1159264): [] vprintk_emit+0x2c5/0x600 [ 2.544503] hardirqs last disabled at (1159263): [] vprintk_emit+0x4e/0x600 [ 2.544503] softirqs last enabled at (1159014): [] __do_softirq+0x22e/0x630 [ 2.544503] softirqs last disabled at (1159017): [] irq_exit+0x8e/0xb0 [ 2.544503] [ 2.544503] other info that might help us debug this: [ 2.544503] Possible unsafe locking scenario: [ 2.544503] [ 2.544503] CPU0 [ 2.544503] ---- [ 2.544503] lock(&nlk->pg_vec_lock); [ 2.544503] [ 2.544503] lock(&nlk->pg_vec_lock); [ 2.544503] [ 2.544503] *** DEADLOCK *** [ 2.544503] [ 2.544503] 3 locks held by init/1: [ 2.544503] #0: (reboot_mutex){+.+...}, at: [] SyS_reboot+0xa9/0x220 [ 2.544503] #1: ((reboot_notifier_list).rwsem){.+.+..}, at: [] __blocking_notifier_call_chain+0x39/0x70 [ 2.544503] #2: (rcu_callback){......}, at: [] rcu_do_batch.isra.49+0x160/0x10c0 [ 2.544503] [ 2.544503] stack backtrace: [ 2.544503] CPU: 1 PID: 1 Comm: init Not tainted 4.1.0-00009-gbddf4c4818e0 #253 [ 2.544503] Hardware name: QEMU Standard PC (Q35 + ICH9, 2009), BIOS Debian-1.8.2-1 04/01/2014 [ 2.544503] ffff88017b3d8000 ffff88027bc03af8 ffffffff81929ceb 0000000000000103 [ 2.544503] ffffffff82ad2ed0 ffff88027bc03b38 ffffffff819279f8 0000000000000001 [ 2.544503] ffff88017b3d8810 0000000000000004 0000000000000004 0000000000000006 [ 2.544503] Call Trace: [ 2.544503] [] dump_stack+0x4f/0x7b [ 2.544503] [] print_usage_bug.part.35+0x281/0x290 [ 2.544503] [] mark_lock+0x22c/0x760 [ 2.544503] [] ? check_usage_backwards+0x150/0x150 [ 2.544503] [] __lock_acquire+0xab7/0xf50 [ 2.544503] [] lock_acquire+0xd2/0x2b0 [ 2.544503] [] ? netlink_set_ring+0x1ed/0x350 [ 2.544503] [] ? ___might_sleep+0x16d/0x270 [ 2.544503] [] ? netlink_set_ring+0x1ed/0x350 [ 2.544503] [] mutex_lock_nested+0x71/0x430 [ 2.544503] [] ? netlink_set_ring+0x1ed/0x350 [ 2.544503] [] ? netlink_set_ring+0x1ed/0x350 [ 2.544503] [] ? __this_cpu_preempt_check+0x13/0x20 [ 2.544503] [] netlink_set_ring+0x1ed/0x350 [ 2.544503] [] ? netlink_undo_bind+0x70/0x70 [ 2.544503] [] netlink_sock_destruct+0x80/0x150 [ 2.544503] [] __sk_free+0x1d/0x160 [ 2.544503] [] sk_free+0x19/0x20 [ 2.544503] [] deferred_put_nlk_sk+0x20/0x30 [ 2.544503] [] rcu_do_batch.isra.49+0x79c/0x10c0 [ 2.544503] [] ? rcu_do_batch.isra.49+0x160/0x10c0 [ 2.544503] [] rcu_process_callbacks+0xdb/0x6d0 [ 2.544503] [] __do_softirq+0x152/0x630 [ 2.544503] [] irq_exit+0x8e/0xb0 [ 2.544503] [] smp_apic_timer_interrupt+0x46/0x60 [ 2.544503] [] ? __delay+0xf/0x20 [ 2.544503] [] apic_timer_interrupt+0x70/0x80 [ 2.544503] [] ? __delay+0xf/0x20 [ 2.544503] [] ? in_lock_functions+0x1b/0x20 [ 2.544503] [] get_parent_ip+0x11/0x50 [ 2.544503] [] preempt_count_sub+0x9f/0xf0 [ 2.544503] [] delay_tsc+0x68/0xc0 [ 2.544503] [] __delay+0xf/0x20 [ 2.544503] [] __const_udelay+0x2a/0x30 [ 2.544503] [] md_notify_reboot+0xea/0x100 [ 2.544503] [] ? __blocking_notifier_call_chain+0x39/0x70 [ 2.544503] [] notifier_call_chain+0x66/0x90 [ 2.544503] [] __blocking_notifier_call_chain+0x51/0x70 [ 2.544503] [] ? __lock_acquire+0x606/0xf50 [ 2.544503] [] blocking_notifier_call_chain+0x16/0x20 [ 2.544503] [] kernel_restart_prepare+0x1d/0x40 [ 2.544503] [] kernel_restart+0x16/0x60 [ 2.544503] [] SyS_reboot+0x157/0x220 [ 2.544503] [] ? __restore_xstate_sig+0xf8/0x720 [ 2.544503] [] ? debug_smp_processor_id+0x17/0x20 [ 2.544503] [] ? put_lock_stats.isra.19+0xe/0x30 [ 2.544503] [] ? _raw_spin_unlock_irq+0x30/0x60 [ 2.544503] [] ? preempt_count_sub+0xab/0xf0 [ 2.544503] [] ? syscall_return+0x11/0x54 [ 2.544503] [] ? __this_cpu_preempt_check+0x13/0x20 [ 2.544503] [] ? trace_hardirqs_on_caller+0xf3/0x240 [ 2.544503] [] ? trace_hardirqs_on_thunk+0x17/0x19 [ 2.544503] [] system_call_fastpath+0x12/0x6f -- Kirill A. Shutemov