Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1757310AbbGTWxQ (ORCPT ); Mon, 20 Jul 2015 18:53:16 -0400 Received: from aserp1040.oracle.com ([141.146.126.69]:23795 "EHLO aserp1040.oracle.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1756483AbbGTWxM (ORCPT ); Mon, 20 Jul 2015 18:53:12 -0400 Message-ID: <55AD7BB3.1090501@oracle.com> Date: Mon, 20 Jul 2015 18:52:35 -0400 From: Sasha Levin User-Agent: Mozilla/5.0 (X11; Linux x86_64; rv:31.0) Gecko/20100101 Thunderbird/31.7.0 MIME-Version: 1.0 To: Frederic Weisbecker CC: linux-kernel@vger.kernel.org, mingo@kernel.org, tglx@linutronix.de, hpa@zytor.com, torvalds@linux-foundation.org, peterz@infradead.org, "Paul E. McKenney" Subject: Re: [tip:sched/core] sched/preempt: Optimize preemption operations on __schedule() callers References: <1431441711-29753-5-git-send-email-fweisbec@gmail.com> <55AD72C3.4000300@oracle.com> <20150720224858.GD13032@lerouge> In-Reply-To: <20150720224858.GD13032@lerouge> Content-Type: text/plain; charset=windows-1252 Content-Transfer-Encoding: 7bit X-Source-IP: aserv0022.oracle.com [141.146.126.234] Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 4853 Lines: 86 On 07/20/2015 06:48 PM, Frederic Weisbecker wrote: > On Mon, Jul 20, 2015 at 06:14:27PM -0400, Sasha Levin wrote: >> > On 05/19/2015 03:17 AM, tip-bot for Frederic Weisbecker wrote: >>> > > Commit-ID: b30f0e3ffedfa52b1d67a302ae5860c49998e5e2 >>> > > Gitweb: http://git.kernel.org/tip/b30f0e3ffedfa52b1d67a302ae5860c49998e5e2 >>> > > Author: Frederic Weisbecker >>> > > AuthorDate: Tue, 12 May 2015 16:41:49 +0200 >>> > > Committer: Ingo Molnar >>> > > CommitDate: Tue, 19 May 2015 08:39:12 +0200 >>> > > >>> > > sched/preempt: Optimize preemption operations on __schedule() callers >>> > > >>> > > __schedule() disables preemption and some of its callers >>> > > (the preempt_schedule*() family) also set PREEMPT_ACTIVE. >>> > > >>> > > So we have two preempt_count() modifications that could be performed >>> > > at once. >>> > > >>> > > Lets remove the preemption disablement from __schedule() and pull >>> > > this responsibility to its callers in order to optimize preempt_count() >>> > > operations in a single place. >>> > > >>> > > Suggested-by: Linus Torvalds >>> > > Signed-off-by: Frederic Weisbecker >>> > > Signed-off-by: Peter Zijlstra (Intel) >>> > > Cc: Peter Zijlstra >>> > > Cc: Thomas Gleixner >>> > > Link: http://lkml.kernel.org/r/1431441711-29753-5-git-send-email-fweisbec@gmail.com >>> > > Signed-off-by: Ingo Molnar >> > >> > Hi all, >> > >> > I was seeing RCU stall warnings that appeared to have different backtrace >> > each time, but would reliably trigger when fuzzing and looked something like this: >> > >> > [4394886.414687] INFO: rcu_preempt detected stalls on CPUs/tasks: >> > [4394886.416717] Tasks blocked on level-0 rcu_node (CPUs 0-23): P13356 >> > [4394886.418699] (detected by 2, t=20502 jiffies, g=3548, c=3547, q=120) >> > [4394886.420712] trinity-c42 R running task 26936 13356 9574 0x10000000 >> > [4394886.422466] ffff8807d1c7fbe8 ffff8807d1c7fb88 0000000000000022 ffff8801081e1bb0 >> > [4394886.423711] ffff8801081e1b88 ffff8807d1eb8780 ffff8801081e11d8 ffff8807e2564000 >> > [4394886.424956] ffff8807d1eb8000 ffff8807d1c7fbd8 ffff8807d1c78000 0000000000000000 >> > [4394886.426196] Call Trace: >> > [4394886.426627] preempt_schedule_irq (./arch/x86/include/asm/paravirt.h:807 kernel/sched/core.c:3218) >> > [4394886.427582] ? lockdep_reset_lock (kernel/locking/lockdep.c:3105) >> > [4394886.428548] ? kill_pid_info (include/linux/rcupdate.h:857 kernel/signal.c:1340) >> > [4394886.429438] retint_kernel (arch/x86/entry/entry_64.S:578) >> > [4394886.430286] ? kill_pid_info (include/linux/rcupdate.h:857 kernel/signal.c:1340) >> > [4394886.431176] ? native_restore_fl (./arch/x86/include/asm/irqflags.h:35) >> > [4394886.432376] lock_is_held (kernel/locking/lockdep.c:3661) >> > [4394886.433241] ? kill_pid_info (include/linux/rcupdate.h:914 kernel/signal.c:1344) >> > [4394886.434135] rcu_read_lock_held (kernel/rcu/update.c:275) >> > [4394886.435012] pid_task (kernel/pid.c:440 (discriminator 5)) >> > [4394886.435656] kill_pid_info (kernel/signal.c:1341) >> > [4394886.436351] ? kill_pid_info (include/linux/rcupdate.h:857 kernel/signal.c:1340) >> > [4394886.437065] SYSC_kill (kernel/signal.c:1426 kernel/signal.c:2903) >> > [4394886.437726] ? SYSC_kill (include/linux/rcupdate.h:857 kernel/signal.c:1425 kernel/signal.c:2903) >> > [4394886.438419] ? find_get_pid (include/linux/rcupdate.h:914 kernel/pid.c:494) >> > [4394886.439134] ? kill_pid (kernel/signal.c:2894) >> > [4394886.439782] ? find_get_pid (kernel/pid.c:497) >> > [4394886.440492] ? find_get_pid (kernel/pid.c:489) >> > [4394886.441183] ? lock_is_held (kernel/locking/lockdep.c:3661) >> > [4394886.441929] ? rcu_read_lock_sched_held (kernel/rcu/update.c:109) >> > [4394886.442772] ? syscall_trace_enter_phase2 (arch/x86/entry/common.c:196) >> > [4394886.443632] SyS_kill (kernel/signal.c:2893) >> > [4394886.444255] tracesys_phase2 (arch/x86/entry/entry_64.S:270) >> > >> > I worked with Paul to rule out RCU as the cause. >> > >> > I've noticed that all traces had one thing in common: being stuck in preempt_schedule_irq(), >> > so I've looked at recent changes there and noticed this commit. >> > >> > I've tried testing the commit before that, and the problem went away. Checking out this >> > commit the problem reappeared. > Do you have any idea how to reproduce that? Beyond running trinity, no. That's why I couldn't bisect it to begin with. Thanks, Sasha -- 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/