From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S932882Ab2GYJGs (ORCPT ); Wed, 25 Jul 2012 05:06:48 -0400 Received: from e23smtp04.au.ibm.com ([202.81.31.146]:40513 "EHLO e23smtp04.au.ibm.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S932782Ab2GYJGq (ORCPT ); Wed, 25 Jul 2012 05:06:46 -0400 Message-ID: <500FB71C.9030206@linux.vnet.ibm.com> Date: Wed, 25 Jul 2012 17:06:36 +0800 From: Michael Wang User-Agent: Mozilla/5.0 (X11; Linux i686; rv:13.0) Gecko/20120615 Thunderbird/13.0.1 MIME-Version: 1.0 To: Sasha Levin CC: paulmck@linux.vnet.ibm.com, "linux-kernel@vger.kernel.org" Subject: Re: rcu: INFO: rcu_preempt detected stalls on CPUs/tasks on v3.6 References: <500ED719.2010002@gmail.com> In-Reply-To: <500ED719.2010002@gmail.com> Content-Type: text/plain; charset=ISO-8859-1 Content-Transfer-Encoding: 7bit x-cbid: 12072509-9264-0000-0000-000001FE53AA Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On 07/25/2012 01:10 AM, Sasha Levin wrote: > Hi all, > > I was fuzzing with trinity inside a KVM tools guest, on the current 3.6, and stumbled on the following: And is this a host dmesg or from the guest? Could you please provide more details about your testing environment? Thanks, Michael Wang > > (Note that it also happens on -next). > > [ 215.034674] INFO: rcu_preempt detected stalls on CPUs/tasks: > [ 215.035641] 1: (0 ticks this GP) idle=3f5/140000000000001/0 drain=0 . timer=18446744073709551615 > [ 215.035641] (detected by 3, t=111886 jiffies) > [ 215.035641] sending NMI to all CPUs: > [ 214.959504] NMI backtrace for cpu 2 > [ 214.959504] CPU 2 > [ 214.959504] Pid: 6583, comm: trinity-child6 Tainted: G W 3.5.0-sasha-01644-g824681b #267 > [ 214.959504] RIP: 0010:[] [] check_flags+0x93/0x1d0 > [ 214.959504] RSP: 0018:ffff880025175b58 EFLAGS: 00000046 > [ 214.959504] RAX: ffff880027910000 RBX: ffff880027910000 RCX: 0000000000000000 > [ 214.959504] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 0000000000000001 > [ 214.959504] RBP: ffff880025175b58 R08: 0000000000000000 R09: 0000000000000000 > [ 214.959504] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000 > [ 214.959504] R13: 0000000000000002 R14: 0000000000000000 R15: 0000000000000000 > [ 214.959504] FS: 00007f754d198700(0000) GS:ffff880029800000(0000) knlGS:0000000000000000 > [ 214.959504] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [ 214.959504] CR2: 0000000000000008 CR3: 00000000251aa000 CR4: 00000000000406e0 > [ 214.959504] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 > [ 214.959504] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 > [ 214.959504] Process trinity-child6 (pid: 6583, threadinfo ffff880025174000, task ffff880027910000) > [ 214.959504] Stack: > [ 214.959504] ffff880025175be8 ffffffff8114e610 ffff880027910000 0000000000000000 > [ 214.959504] 0000000000000286 ffffffffffffff10 ffffffff8114e51d 0000000000000010 > [ 214.959504] 0000000000000286 0000000025175bb8 ffff880019a767c8 0000000000000286 > [ 214.959504] Call Trace: > [ 214.959504] [] lock_acquire+0x80/0x270 > [ 214.959504] [] ? lock_release+0x1ad/0x220 > [ 214.959504] [] _raw_spin_lock+0x3b/0x70 > [ 214.959504] [] ? __d_lookup+0x145/0x2e0 > [ 214.959504] [] __d_lookup+0x145/0x2e0 > [ 214.959504] [] lookup_fast+0x136/0x240 > [ 214.959504] [] ? __inode_permission+0xbb/0xd0 > [ 214.959504] [] ? inode_permission+0x9/0x50 > [ 214.959504] [] link_path_walk+0x22c/0x8f0 > [ 214.959504] [] ? path_init+0x213/0x550 > [ 214.959504] [] ? __raw_spin_lock_init+0x38/0x70 > [ 214.959504] [] path_openat+0x98/0x400 > [ 214.959504] [] ? retint_restore_args+0x13/0x13 > [ 214.959504] [] do_filp_open+0x3d/0xa0 > [ 214.959504] [] ? do_raw_spin_unlock+0xc8/0xe0 > [ 214.959504] [] ? alloc_fd+0x1d3/0x1f0 > [ 214.959504] [] ? alloc_fd+0x1/0x1f0 > [ 214.959504] [] do_sys_open+0x115/0x1b0 > [ 214.959504] [] sys_open+0x1c/0x20 > [ 214.959504] [] system_call_fastpath+0x1a/0x1f > [ 214.959504] Code: a4 26 84 e8 70 e2 f8 ff e9 25 01 00 00 0f 1f 00 44 8b 05 61 1c 1e 04 45 85 c0 75 4c 65 48 8b 04 25 00 da 00 00 8b b8 b0 08 00 00 <85> ff 75 39 e8 64 b4 81 00 85 c0 0f 84 09 01 00 00 83 3d 45 bf > [ 215.026612] NMI backtrace for cpu 1 > [ 215.026612] CPU 1 > [ 215.026612] Pid: 2395, comm: pageattr-test Tainted: G W 3.5.0-sasha-01644-g824681b #267 > [ 215.026612] RIP: 0010:[] [] native_write_msr_safe+0xa/0x10 > [ 215.026612] RSP: 0018:ffff88001b803f70 EFLAGS: 00000046 > [ 215.026612] RAX: 0000000000000000 RBX: 000000000000ef80 RCX: 000000000000080b > [ 215.026612] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 000000000000080b > [ 215.026612] RBP: ffff88001b803f70 R08: 00003ffffffff000 R09: ffff880000000000 > [ 215.026612] R10: 0000000000000001 R11: 0000000000000000 R12: 0000000000000000 > [ 215.026612] R13: ffff880007a98000 R14: ffff88001fc3a4b8 R15: ffff880000000000 > [ 215.026612] FS: 0000000000000000(0000) GS:ffff88001b800000(0000) knlGS:0000000000000000 > [ 215.026612] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b > [ 215.026612] CR2: 000000000000000c CR3: 0000000019dcf000 CR4: 00000000000406e0 > [ 215.026612] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 > [ 215.026612] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 > [ 215.026612] Process pageattr-test (pid: 2395, threadinfo ffff88000ced0000, task ffff88000d773000) > [ 215.026612] Stack: > [ 215.026612] ffff88001b803f88 ffffffff81095d07 000000000000ef80 ffff88001b803fa8 > [ 215.026612] ffffffff810901c4 ffff88000ced1db0 0000000000007a98 ffff88000ced1d00 > [ 215.026612] ffffffff8369c4af ffff88000ced1c78 ffff88000ced1d00 ffffffff8369aeb4 > [ 215.026612] Call Trace: > [ 215.026612] > [ 215.026612] [] native_apic_msr_eoi_write+0x27/0x30 > [ 215.026612] [] smp_apic_timer_interrupt+0x34/0xa0 > [ 215.026612] [] apic_timer_interrupt+0x6f/0x80 > [ 215.026612] > [ 215.026612] [] ? retint_restore_args+0x13/0x13 > [ 215.026612] [] ? lookup_address+0x112/0x170 > [ 215.026612] [] print_split+0x7e/0x200 > [ 215.026612] [] pageattr_test+0x80/0x4a0 > [ 215.026612] [] ? trace_hardirqs_on_caller+0x118/0x140 > [ 215.026612] [] ? schedule_timeout+0x2ce/0x370 > [ 215.026612] [] ? retint_restore_args+0x13/0x13 > [ 215.026612] [] ? pageattr_test+0x4a0/0x4a0 > [ 215.026612] [] do_pageattr_test+0x1f/0x50 > [ 215.026612] [] kthread+0xad/0xc0 > [ 215.026612] [] kernel_thread_helper+0x4/0x10 > [ 215.026612] [] ? retint_restore_args+0x13/0x13 > [ 215.026612] [] ? kthread_flush_work_fn+0x10/0x10 > [ 215.026612] [] ? gs_change+0x13/0x13 > [ 215.026612] Code: 00 55 89 f9 48 89 e5 0f 32 45 31 c0 89 c7 48 89 d0 44 89 06 48 c1 e0 20 89 f9 5d 48 09 c8 c3 66 90 55 89 f0 89 f9 48 89 e5 0f 30 <31> c0 5d c3 66 90 55 89 f9 48 89 e5 0f 33 89 c7 48 89 d0 5d 48 > [ 215.035641] NMI backtrace for cpu 3 > [ 215.035641] CPU 3 > [ 215.035641] Pid: 0, comm: swapper/3 Tainted: G W 3.5.0-sasha-01644-g824681b #267 > [ 215.035641] RIP: 0010:[] [] native_write_msr_safe+0xa/0x10 > [ 215.035641] RSP: 0018:ffff88000d5b5ce8 EFLAGS: 00000086 > [ 215.035641] RAX: 0000000000000400 RBX: 0000000000000003 RCX: 0000000000000830 > [ 215.035641] RDX: 0000000000000003 RSI: 0000000000000400 RDI: 0000000000000830 > [ 215.035641] RBP: ffff88000d5b5ce8 R08: ffffffff84edc9c0 R09: 0000000000000000 > [ 215.035641] R10: 000000000000739d R11: 0000000000025370 R12: ffffffff84edc9c0 > [ 215.035641] R13: 0000000000000003 R14: 000000000000f042 R15: 0000000000000002 > [ 215.035641] FS: 0000000000000000(0000) GS:ffff880035a00000(0000) knlGS:0000000000000000 > [ 215.035641] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b > [ 215.035641] CR2: 0000000000bc5958 CR3: 00000000278b0000 CR4: 00000000000406e0 > [ 215.035641] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 > [ 215.035641] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 > [ 215.035641] Process swapper/3 (pid: 0, threadinfo ffff88000d5b4000, task ffff88000d5b8000) > [ 215.035641] Stack: > [ 215.035641] ffff88000d5b5d48 ffffffff81095e0d ffff88000d5b5d58 0000000000000086 > [ 215.035641] 0000000000000002 0008000000000008 ffff88000d5b5d68 0000000000002710 > [ 215.035641] 000000000001b50e 0000000000000001 ffffffff84966008 0000000000000086 > [ 215.035641] Call Trace: > [ 215.035641] [] __x2apic_send_IPI_mask+0xcd/0x190 > [ 215.035641] [] x2apic_send_IPI_all+0x17/0x20 > [ 215.035641] [] arch_trigger_all_cpu_backtrace+0x63/0xa0 > [ 215.035641] [] print_other_cpu_stall+0x223/0x290 > [ 215.035641] [] __rcu_pending+0x80/0x200 > [ 215.035641] [] ? __atomic_notifier_call_chain+0xe8/0x120 > [ 215.035641] [] rcu_pending+0x3f/0x70 > [ 215.035641] [] rcu_prepare_for_idle+0x1d4/0x430 > [ 215.035641] [] rcu_idle_enter_common+0x24c/0x400 > [ 215.035641] [] ? __atomic_notifier_call_chain+0x105/0x120 > [ 215.035641] [] ? atomic_notifier_chain_unregister+0x90/0x90 > [ 215.035641] [] rcu_idle_enter+0xdb/0x130 > [ 215.035641] [] cpu_idle+0x106/0x160 > [ 215.035641] [] start_secondary+0xd0/0xd7 > [ 215.035641] Code: 00 55 89 f9 48 89 e5 0f 32 45 31 c0 89 c7 48 89 d0 44 89 06 48 c1 e0 20 89 f9 5d 48 09 c8 c3 66 90 55 89 f0 89 f9 48 89 e5 0f 30 <31> c0 5d c3 66 90 55 89 f9 48 89 e5 0f 33 89 c7 48 89 d0 5d 48 > [ 214.997077] NMI backtrace for cpu 0 > [ 214.997077] CPU 0 > [ 214.997077] Pid: 2277, comm: kworker/0:2 Tainted: G W 3.5.0-sasha-01644-g824681b #267 > [ 214.997077] RIP: 0010:[] [] native_write_msr_safe+0xa/0x10 > [ 214.997077] RSP: 0018:ffff88000d803f70 EFLAGS: 00000046 > [ 214.997077] RAX: 0000000000000000 RBX: 000000000000ef80 RCX: 000000000000080b > [ 214.997077] RDX: 0000000000000000 RSI: 0000000000000000 RDI: 000000000000080b > [ 214.997077] RBP: ffff88000d803f70 R08: 0000000000000000 R09: 0000000000000000 > [ 214.997077] R10: 0000000000000001 R11: 0000000000000001 R12: 0000000000000000 > [ 214.997077] R13: ffffffff84854840 R14: 0000000000000286 R15: 00000000000493e0 > [ 214.997077] FS: 0000000000000000(0000) GS:ffff88000d800000(0000) knlGS:0000000000000000 > [ 214.997077] CS: 0010 DS: 0000 ES: 0000 CR0: 000000008005003b > [ 214.997077] CR2: 0000000000000000 CR3: 0000000012f58000 CR4: 00000000000406f0 > [ 214.997077] DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000 > [ 214.997077] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400 > [ 214.997077] Process kworker/0:2 (pid: 2277, threadinfo ffff88000d782000, task ffff88000d653000) > [ 214.997077] Stack: > [ 214.997077] ffff88000d803f88 ffffffff81095d07 000000000000ef80 ffff88000d803fa8 > [ 214.997077] ffffffff810901c4 0000000000000002 ffff88000d653000 ffff88000d783cf0 > [ 214.997077] ffffffff8369c4af ffff88000d783c48 ffff88000d783cf0 ffffffff8369aeb4 > [ 214.997077] Call Trace: > [ 214.997077] > [ 214.997077] [] native_apic_msr_eoi_write+0x27/0x30 > [ 214.997077] [] smp_apic_timer_interrupt+0x34/0xa0 > [ 214.997077] [] apic_timer_interrupt+0x6f/0x80 > [ 214.997077] > [ 214.997077] [] ? retint_restore_args+0x13/0x13 > [ 214.997077] [] ? lock_is_held+0xed/0x110 > [ 214.997077] [] rt_check_expire+0x117/0x300 > [ 214.997077] [] rt_worker_func+0x9/0x20 > [ 214.997077] [] process_one_work+0x376/0x700 > [ 214.997077] [] ? process_one_work+0x230/0x700 > [ 214.997077] [] ? rt_check_expire+0x300/0x300 > [ 214.997077] [] ? worker_thread+0x48/0x320 > [ 214.997077] [] worker_thread+0x1dc/0x320 > [ 214.997077] [] ? manage_workers.isra.11+0x120/0x120 > [ 214.997077] [] kthread+0xad/0xc0 > [ 214.997077] [] kernel_thread_helper+0x4/0x10 > [ 214.997077] [] ? retint_restore_args+0x13/0x13 > [ 214.997077] [] ? kthread_flush_work_fn+0x10/0x10 > [ 214.997077] [] ? gs_change+0x13/0x13 > [ 214.997077] Code: 00 55 89 f9 48 89 e5 0f 32 45 31 c0 89 c7 48 89 d0 44 89 06 48 c1 e0 20 89 f9 5d 48 09 c8 c3 66 90 55 89 f0 89 f9 48 89 e5 0f 30 <31> c0 5d c3 66 90 55 89 f9 48 89 e5 0f 33 89 c7 48 89 d0 5d 48 > -- > To unsubscribe from this list: send the line "unsubscribe linux-kernel" in > the body of a message to majordomo@vger.kernel.org > More majordomo info at http://vger.kernel.org/majordomo-info.html > Please read the FAQ at http://www.tux.org/lkml/ >