Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1758419Ab3HIRiz (ORCPT ); Fri, 9 Aug 2013 13:38:55 -0400 Received: from e39.co.us.ibm.com ([32.97.110.160]:39656 "EHLO e39.co.us.ibm.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1758369Ab3HIRix (ORCPT ); Fri, 9 Aug 2013 13:38:53 -0400 Date: Fri, 9 Aug 2013 10:38:31 -0700 From: "Paul E. McKenney" To: Vince Weaver Cc: Will Deacon , "linux-kernel@vger.kernel.org" , Dave Jones , cl@linux-foundation.org, penberg@kernel.org, mpm@selenic.com Subject: Re: arm,perf fuzzer and rcu_sched lockup Message-ID: <20130809173831.GA29406@linux.vnet.ibm.com> Reply-To: paulmck@linux.vnet.ibm.com References: MIME-Version: 1.0 Content-Type: text/plain; charset=us-ascii Content-Disposition: inline In-Reply-To: User-Agent: Mutt/1.5.21 (2010-09-15) X-TM-AS-MML: No X-Content-Scanned: Fidelis XPS MAILER x-cbid: 13080917-3620-0000-0000-000003E17F51 Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 18301 Lines: 211 On Fri, Aug 09, 2013 at 11:13:04AM -0400, Vince Weaver wrote: > > This is on a 3.11-rc4 kernel with the two perf/ARM oops patches applied. > > I let the fuzzer run overnight with a serial console hooked up and it was > crashed in the morning. Here's the bug log. > > I'm cc-ing Dave Jones as I think he's seeing similar traces on x86 with > trinity when fuzzing. Looks like CPU 0 is stuck trying to acquire a lock in kmem_cache_alloc(). Adding the slab allocators guys on CC for their insight. Thanx, Paul > Vince > > [17591.214660] hrtimer: interrupt took 91552 ns > [17591.231292] NOHZ: local_softirq_pending 100 > [17596.596801] NOHZ: local_softirq_pending 100 > [17629.444610] INFO: rcu_sched detected stalls on CPUs/tasks: { 0} (detected by 1, t=2102 jiffies, g=4545, c=4544, q=10) > [17629.455963] Task dump for CPU 0: > [17629.455963] perf_fuzzer R running 0 4985 4228 0x00000000 > [17629.459411] [] (__schedule+0x4c4/0x748) from [] (no_work_pending+0x8/0x2c) > > ... repeated several hundred times over the course of a few hours > > [79294.544586] INFO: rcu_sched detected stalls on CPUs/tasks: { 0} (detected by 1, t=6168611 jiffies, g=4545, c=4544, q=10) > [79294.544586] Task dump for CPU 0: > [79294.556213] perf_fuzzer R running 0 4985 4228 0x00000000 > [79294.566467] [] (__schedule+0x4c4/0x748) from [] (no_work_pending+0x8/0x2c) > [79357.584686] INFO: rcu_sched detected stalls on CPUs/tasks: { 0} (detected by 1, t=6174916 jiffies, g=4545, c=4544, q=10) > [79357.596313] Task dump for CPU 0: > [79357.599761] perf_fuzzer R running 0 4985 4228 0x00000000 > [79357.599761] [] (__schedule+0x4c4/0x748) from [] (no_work_pending+0x8/0x2c) > [79423.164642] INFO: rcu_sched self-detected stall on CPU { 0} (t=2100 jiffies g=4905 c=4904 q=56) > [79423.174041] CPU: 0 PID: 4228 Comm: perf_fuzzer Not tainted 3.11.0-rc4 #7 > [79423.181182] [] (unwind_backtrace+0x0/0xe0) from [] (show_stack+0x10/0x14) > [79423.190277] [] (show_stack+0x10/0x14) from [] (dump_stack+0x70/0x8c) > [79423.198913] [] (dump_stack+0x70/0x8c) from [] (rcu_check_callbacks+0x1e4/0x66c) > [79423.208557] [] (rcu_check_callbacks+0x1e4/0x66c) from [] (update_process_times+0x38/0x64) > [79423.219116] [] (update_process_times+0x38/0x64) from [] (tick_sched_handle.isra.9+0x48/0x54) > [79423.229980] [] (tick_sched_handle.isra.9+0x48/0x54) from [] (tick_sched_timer+0x44/0x74) > [79423.240447] [] (tick_sched_timer+0x44/0x74) from [] (__run_hrtimer+0x104/0x1cc) > [79423.250091] [] (__run_hrtimer+0x104/0x1cc) from [] (hrtimer_interrupt+0x120/0x270) > [79423.259979] [] (hrtimer_interrupt+0x120/0x270) from [] (twd_handler+0x34/0x48) > [79423.269561] [] (twd_handler+0x34/0x48) from [] (handle_percpu_devid_irq+0xa8/0x114) > [79423.279571] [] (handle_percpu_devid_irq+0xa8/0x114) from [] (generic_handle_irq+0x20/0x30) > [79423.290222] [] (generic_handle_irq+0x20/0x30) from [] (handle_IRQ+0x68/0x90) > [79423.299591] [] (handle_IRQ+0x68/0x90) from [] (gic_handle_irq+0x3c/0x60) > [79423.308593] [] (gic_handle_irq+0x3c/0x60) from [] (__irq_svc+0x44/0x58) > [79423.317474] Exception stack(0xedf5fd68 to 0xedf5fdb0) > [79423.322845] fd60: 00000001 00000110 00000000 ed9b0a00 00000002 00000000 > [79423.331542] fd80: edf5e030 c06ee0c0 c00428cc ece65920 0000000a 3f911f7c c0859eb8 edf5fdb0 > [79423.340240] fda0: c00881b0 c0042378 60000113 ffffffff > [79423.345642] [] (__irq_svc+0x44/0x58) from [] (__do_softirq+0xa0/0x26c) > [79423.354461] [] (__do_softirq+0xa0/0x26c) from [] (irq_exit+0x84/0xd0) > [79423.363159] [] (irq_exit+0x84/0xd0) from [] (handle_IRQ+0x6c/0x90) > [79423.371582] [] (handle_IRQ+0x6c/0x90) from [] (gic_handle_irq+0x3c/0x60) > [79423.380584] [] (gic_handle_irq+0x3c/0x60) from [] (__irq_svc+0x44/0x58) > [79423.389465] Exception stack(0xedf5fe20 to 0xedf5fe68) > [79423.394866] fe20: 00000001 00000110 00000000 ed9b0a00 edf5e000 60000113 000000d0 000000d0 > [79423.403564] fe40: c00e9c64 ece65920 00000001 edf288b8 c0859eb8 edf5fe68 c00881b0 c008aefc > [79423.412261] fe60: 60000113 ffffffff > [79423.416015] [] (__irq_svc+0x44/0x58) from [] (lockdep_trace_alloc+0xd0/0xf8) > [79423.425354] [] (lockdep_trace_alloc+0xd0/0xf8) from [] (kmem_cache_alloc+0x24/0x168) > [79423.435455] [] (kmem_cache_alloc+0x24/0x168) from [] (anon_vma_fork+0x54/0x118) > [79423.445098] [] (anon_vma_fork+0x54/0x118) from [] (dup_mm+0x180/0x3c0) > [79423.453887] [] (dup_mm+0x180/0x3c0) from [] (copy_process.part.59+0x808/0xf0c) > [79423.463439] [] (copy_process.part.59+0x808/0xf0c) from [] (do_fork+0xc0/0x314) > [79423.472991] [] (do_fork+0xc0/0x314) from [] (ret_fast_syscall+0x0/0x48) > [79486.194641] INFO: rcu_sched self-detected stall on CPU { 0} (t=8403 jiffies g=4905 c=4904 q=56) > [79486.194641] CPU: 0 PID: 4228 Comm: perf_fuzzer Not tainted 3.11.0-rc4 #7 > [79486.205200] [] (unwind_backtrace+0x0/0xe0) from [] (show_stack+0x10/0x14) > [79486.214630] [] (show_stack+0x10/0x14) from [] (dump_stack+0x70/0x8c) > [79486.224639] [] (dump_stack+0x70/0x8c) from [] (rcu_check_callbacks+0x1e4/0x66c) > [79486.238555] [] (rcu_check_callbacks+0x1e4/0x66c) from [] (update_process_times+0x38/0x64) > [79486.249114] [] (update_process_times+0x38/0x64) from [] (tick_sched_handle.isra.9+0x48/0x54) > [79486.259979] [] (tick_sched_handle.isra.9+0x48/0x54) from [] (tick_sched_timer+0x44/0x74) > [79486.270446] [] (tick_sched_timer+0x44/0x74) from [] (__run_hrtimer+0x104/0x1cc) > [79486.280059] [] (__run_hrtimer+0x104/0x1cc) from [] (hrtimer_interrupt+0x120/0x270) > [79486.289978] [] (hrtimer_interrupt+0x120/0x270) from [] (twd_handler+0x34/0x48) > [79486.299530] [] (twd_handler+0x34/0x48) from [] (handle_percpu_devid_irq+0xa8/0x114) > [79486.309539] [] (handle_percpu_devid_irq+0xa8/0x114) from [] (generic_handle_irq+0x20/0x30) > [79486.320190] [] (generic_handle_irq+0x20/0x30) from [] (handle_IRQ+0x68/0x90) > [79486.329559] [] (handle_IRQ+0x68/0x90) from [] (gic_handle_irq+0x3c/0x60) > [79486.338562] [] (gic_handle_irq+0x3c/0x60) from [] (__irq_svc+0x44/0x58) > [79486.347442] Exception stack(0xedf5fd68 to 0xedf5fdb0) > [79486.352844] fd60: 00000001 00000110 00000000 ed9b0a00 00000002 00000000 > [79486.361541] fd80: edf5e030 c06ee0c0 c00428cc ece65920 0000000a 3f911f7c c0859eb8 edf5fdb0 > [79486.370239] fda0: c00881b0 c0042378 60000113 ffffffff > [79486.375640] [] (__irq_svc+0x44/0x58) from [] (__do_softirq+0xa0/0x26c) > [79486.384460] [] (__do_softirq+0xa0/0x26c) from [] (irq_exit+0x84/0xd0) > [79486.393157] [] (irq_exit+0x84/0xd0) from [] (handle_IRQ+0x6c/0x90) > [79486.401580] [] (handle_IRQ+0x6c/0x90) from [] (gic_handle_irq+0x3c/0x60) > [79486.410583] [] (gic_handle_irq+0x3c/0x60) from [] (__irq_svc+0x44/0x58) > [79486.419464] Exception stack(0xedf5fe20 to 0xedf5fe68) > [79486.424835] fe20: 00000001 00000110 00000000 ed9b0a00 edf5e000 60000113 000000d0 000000d0 > [79486.433563] fe40: c00e9c64 ece65920 00000001 edf288b8 c0859eb8 edf5fe68 c00881b0 c008aefc > [79486.442260] fe60: 60000113 ffffffff > [79486.445983] [] (__irq_svc+0x44/0x58) from [] (lockdep_trace_alloc+0xd0/0xf8) > [79486.455352] [] (lockdep_trace_alloc+0xd0/0xf8) from [] (kmem_cache_alloc+0x24/0x168) > [79486.465454] [] (kmem_cache_alloc+0x24/0x168) from [] (anon_vma_fork+0x54/0x118) > [79486.475097] [] (anon_vma_fork+0x54/0x118) from [] (dup_mm+0x180/0x3c0) > [79486.483917] [] (dup_mm+0x180/0x3c0) from [] (copy_process.part.59+0x808/0xf0c) > [79486.493438] [] (copy_process.part.59+0x808/0xf0c) from [] (do_fork+0xc0/0x314) > [79486.502990] [] (do_fork+0xc0/0x314) from [] (ret_fast_syscall+0x0/0x48) > [79549.224609] INFO: rcu_sched self-detected stall on CPU { 0} (t=14706 jiffies g=4905 c=4904 q=56) > [79549.224670] CPU: 0 PID: 4228 Comm: perf_fuzzer Not tainted 3.11.0-rc4 #7 > [79549.234588] [] (unwind_backtrace+0x0/0xe0) from [] (show_stack+0x10/0x14) > [79549.244720] [] (show_stack+0x10/0x14) from [] (dump_stack+0x70/0x8c) > [79549.259002] [] (dump_stack+0x70/0x8c) from [] (rcu_check_callbacks+0x1e4/0x66c) > [79549.264617] [] (rcu_check_callbacks+0x1e4/0x66c) from [] (update_process_times+0x38/0x64) > [79549.274627] [] (update_process_times+0x38/0x64) from [] (tick_sched_handle.isra.9+0x48/0x54) > [79549.290039] [] (tick_sched_handle.isra.9+0x48/0x54) from [] (tick_sched_timer+0x44/0x74) > [79549.300506] [] (tick_sched_timer+0x44/0x74) from [] (__run_hrtimer+0x104/0x1cc) > [79549.304626] [] (__run_hrtimer+0x104/0x1cc) from [] (hrtimer_interrupt+0x120/0x270) > [79549.320068] [] (hrtimer_interrupt+0x120/0x270) from [] (twd_handler+0x34/0x48) > [79549.329132] [] (twd_handler+0x34/0x48) from [] (handle_percpu_devid_irq+0xa8/0x114) > [79549.339630] [] (handle_percpu_devid_irq+0xa8/0x114) from [] (generic_handle_irq+0x20/0x30) > [79549.349548] [] (generic_handle_irq+0x20/0x30) from [] (handle_IRQ+0x68/0x90) > [79549.359649] [] (handle_IRQ+0x68/0x90) from [] (gic_handle_irq+0x3c/0x60) > [79549.364624] [] (gic_handle_irq+0x3c/0x60) from [] (__irq_svc+0x44/0x58) > [79549.374572] Exception stack(0xedf5fd68 to 0xedf5fdb0) > [79549.374572] fd60: 00000001 00000110 00000000 ed9b0a00 00000002 00000000 > [79549.384613] fd80: edf5e030 c06ee0c0 c00428cc ece65920 0000000a 3f911f7c c0859eb8 edf5fdb0 > [79549.394622] fda0: c00881b0 c0042378 60000113 ffffffff > [79549.404571] [] (__irq_svc+0x44/0x58) from [] (__do_softirq+0xa0/0x26c) > [79549.408813] [] (__do_softirq+0xa0/0x26c) from [] (irq_exit+0x84/0xd0) > [79549.420379] [] (irq_exit+0x84/0xd0) from [] (handle_IRQ+0x6c/0x90) > [79549.424621] [] (handle_IRQ+0x6c/0x90) from [] (gic_handle_irq+0x3c/0x60) > [79549.440704] [] (gic_handle_irq+0x3c/0x60) from [] (__irq_svc+0x44/0x58) > [79549.449584] Exception stack(0xedf5fe20 to 0xedf5fe68) > [79549.454589] fe20: 00000001 00000110 00000000 ed9b0a00 edf5e000 60000113 000000d0 000000d0 > [79549.459594] fe40: c00e9c64 ece65920 00000001 edf288b8 c0859eb8 edf5fe68 c00881b0 c008aefc > [79549.472381] fe60: 60000113 ffffffff > [79549.476104] [] (__irq_svc+0x44/0x58) from [] (lockdep_trace_alloc+0xd0/0xf8) > [79549.484588] [] (lockdep_trace_alloc+0xd0/0xf8) from [] (kmem_cache_alloc+0x24/0x168) > [79549.495574] [] (kmem_cache_alloc+0x24/0x168) from [] (anon_vma_fork+0x54/0x118) > [79549.504638] [] (anon_vma_fork+0x54/0x118) from [] (dup_mm+0x180/0x3c0) > [79549.504638] [] (dup_mm+0x180/0x3c0) from [] (copy_process.part.59+0x808/0xf0c) > [79549.514617] [] (copy_process.part.59+0x808/0xf0c) from [] (do_fork+0xc0/0x314) > [79549.524627] [] (do_fork+0xc0/0x314) from [] (ret_fast_syscall+0x0/0x48) > [79612.254608] INFO: rcu_sched self-detected stall on CPU { 0} (t=21009 jiffies g=4905 c=4904 q=56) > [79612.254669] CPU: 0 PID: 4228 Comm: perf_fuzzer Not tainted 3.11.0-rc4 #7 > [79612.264587] [] (unwind_backtrace+0x0/0xe0) from [] (show_stack+0x10/0x14) > [79612.274627] [] (show_stack+0x10/0x14) from [] (dump_stack+0x70/0x8c) > [79612.274627] [] (dump_stack+0x70/0x8c) from [] (rcu_check_callbacks+0x1e4/0x66c) > [79612.298645] [] (rcu_check_callbacks+0x1e4/0x66c) from [] (update_process_times+0x38/0x64) > [79612.306060] [] (update_process_times+0x38/0x64) from [] (tick_sched_handle.isra.9+0x48/0x54) > [79612.319946] [] (tick_sched_handle.isra.9+0x48/0x54) from [] (tick_sched_timer+0x44/0x74) > [79612.329254] [] (tick_sched_timer+0x44/0x74) from [] (__run_hrtimer+0x104/0x1cc) > [79612.340179] [] (__run_hrtimer+0x104/0x1cc) from [] (hrtimer_interrupt+0x120/0x270) > [79612.344635] [] (hrtimer_interrupt+0x120/0x270) from [] (twd_handler+0x34/0x48) > [79612.354614] [] (twd_handler+0x34/0x48) from [] (handle_percpu_devid_irq+0xa8/0x114) > [79612.364624] [] (handle_percpu_devid_irq+0xa8/0x114) from [] (generic_handle_irq+0x20/0x30) > [79612.380340] [] (generic_handle_irq+0x20/0x30) from [] (handle_IRQ+0x68/0x90) > [79612.388854] [] (handle_IRQ+0x68/0x90) from [] (gic_handle_irq+0x3c/0x60) > [79612.394653] [] (gic_handle_irq+0x3c/0x60) from [] (__irq_svc+0x44/0x58) > [79612.407592] Exception stack(0xedf5fd68 to 0xedf5fdb0) > [79612.407592] fd60: 00000001 00000110 00000000 ed9b0a00 00000002 00000000 > [79612.421691] fd80: edf5e030 c06ee0c0 c00428cc ece65920 0000000a 3f911f7c c0859eb8 edf5fdb0 > [79612.427490] fda0: c00881b0 c0042378 60000113 ffffffff > [79612.434600] [] (__irq_svc+0x44/0x58) from [] (__do_softirq+0xa0/0x26c) > [79612.444580] [] (__do_softirq+0xa0/0x26c) from [] (irq_exit+0x84/0xd0) > [79612.453308] [] (irq_exit+0x84/0xd0) from [] (handle_IRQ+0x6c/0x90) > [79612.455871] [] (handle_IRQ+0x6c/0x90) from [] (gic_handle_irq+0x3c/0x60) > [79612.464599] [] (gic_handle_irq+0x3c/0x60) from [] (__irq_svc+0x44/0x58) > [79612.479644] Exception stack(0xedf5fe20 to 0xedf5fe68) > [79612.484588] fe20: 00000001 00000110 00000000 ed9b0a00 edf5e000 60000113 000000d0 000000d0 > [79612.489532] fe40: c00e9c64 ece65920 00000001 edf288b8 c0859eb8 edf5fe68 c00881b0 c008aefc > [79612.494598] fe60: 60000113 ffffffff > [79612.504638] [] (__irq_svc+0x44/0x58) from [] (lockdep_trace_alloc+0xd0/0xf8) > [79612.514617] [] (lockdep_trace_alloc+0xd0/0xf8) from [] (kmem_cache_alloc+0x24/0x168) > [79612.524627] [] (kmem_cache_alloc+0x24/0x168) from [] (anon_vma_fork+0x54/0x118) > [79612.534606] [] (anon_vma_fork+0x54/0x118) from [] (dup_mm+0x180/0x3c0) > [79612.544097] [] (dup_mm+0x180/0x3c0) from [] (copy_process.part.59+0x808/0xf0c) > [79612.553649] [] (copy_process.part.59+0x808/0xf0c) from [] (do_fork+0xc0/0x314) > [79612.555541] [] (do_fork+0xc0/0x314) from [] (ret_fast_syscall+0x0/0x48) > [79675.284637] INFO: rcu_sched self-detected stall on CPU { 0} (t=27312 jiffies g=4905 c=4904 q=56) > [79675.294128] CPU: 0 PID: 4228 Comm: perf_fuzzer Not tainted 3.11.0-rc4 #7 > [79675.301269] [] (unwind_backtrace+0x0/0xe0) from [] (show_stack+0x10/0x14) > [79675.310363] [] (show_stack+0x10/0x14) from [] (dump_stack+0x70/0x8c) > [79675.319000] [] (dump_stack+0x70/0x8c) from [] (rcu_check_callbacks+0x1e4/0x66c) > [79675.328643] [] (rcu_check_callbacks+0x1e4/0x66c) from [] (update_process_times+0x38/0x64) > [79675.339233] [] (update_process_times+0x38/0x64) from [] (tick_sched_handle.isra.9+0x48/0x54) > [79675.350067] [] (tick_sched_handle.isra.9+0x48/0x54) from [] (tick_sched_timer+0x44/0x74) > [79675.360534] [] (tick_sched_timer+0x44/0x74) from [] (__run_hrtimer+0x104/0x1cc) > [79675.370178] [] (__run_hrtimer+0x104/0x1cc) from [] (hrtimer_interrupt+0x120/0x270) > [79675.380096] [] (hrtimer_interrupt+0x120/0x270) from [] (twd_handler+0x34/0x48) > [79675.389617] [] (twd_handler+0x34/0x48) from [] (handle_percpu_devid_irq+0xa8/0x114) > [79675.399658] [] (handle_percpu_devid_irq+0xa8/0x114) from [] (generic_handle_irq+0x20/0x30) > [79675.410308] [] (generic_handle_irq+0x20/0x30) from [] (handle_IRQ+0x68/0x90) > [79675.419677] [] (handle_IRQ+0x68/0x90) from [] (gic_handle_irq+0x3c/0x60) > [79675.428680] [] (gic_handle_irq+0x3c/0x60) from [] (__irq_svc+0x44/0x58) > [79675.437561] Exception stack(0xedf5fd68 to 0xedf5fdb0) > [79675.442962] fd60: 00000001 00000110 00000000 ed9b0a00 00000002 00000000 > [79675.451660] fd80: edf5e030 c06ee0c0 c00428cc ece65920 0000000a 3f911f7c c0859eb8 edf5fdb0 > [79675.460357] fda0: c00881b0 c0042378 60000113 ffffffff > [79675.465759] [] (__irq_svc+0x44/0x58) from [] (__do_softirq+0xa0/0x26c) > [79675.474548] [] (__do_softirq+0xa0/0x26c) from [] (irq_exit+0x84/0xd0) > [79675.483276] [] (irq_exit+0x84/0xd0) from [] (handle_IRQ+0x6c/0x90) > [79675.491699] [] (handle_IRQ+0x6c/0x90) from [] (gic_handle_irq+0x3c/0x60) > [79675.500701] [] (gic_handle_irq+0x3c/0x60) from [] (__irq_svc+0x44/0x58) > -- 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/