From patchwork Tue Apr 26 17:52:14 2016 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: "Paul E. McKenney" X-Patchwork-Id: 8942061 Return-Path: X-Original-To: patchwork-linux-omap@patchwork.kernel.org Delivered-To: patchwork-parsemail@patchwork1.web.kernel.org Received: from mail.kernel.org (mail.kernel.org [198.145.29.136]) by patchwork1.web.kernel.org (Postfix) with ESMTP id 4AB4D9F441 for ; Tue, 26 Apr 2016 17:51:52 +0000 (UTC) Received: from mail.kernel.org (localhost [127.0.0.1]) by mail.kernel.org (Postfix) with ESMTP id 1A56A20219 for ; Tue, 26 Apr 2016 17:51:48 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.kernel.org (Postfix) with ESMTP id 15178201FE for ; Tue, 26 Apr 2016 17:51:46 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1752177AbcDZRvp (ORCPT ); Tue, 26 Apr 2016 13:51:45 -0400 Received: from e17.ny.us.ibm.com ([129.33.205.207]:40887 "EHLO e17.ny.us.ibm.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1750843AbcDZRvo (ORCPT ); Tue, 26 Apr 2016 13:51:44 -0400 Received: from localhost by e17.ny.us.ibm.com with IBM ESMTP SMTP Gateway: Authorized Use Only! Violators will be prosecuted for from ; Tue, 26 Apr 2016 13:51:43 -0400 Received: from d01dlp01.pok.ibm.com (9.56.250.166) by e17.ny.us.ibm.com (146.89.104.204) with IBM ESMTP SMTP Gateway: Authorized Use Only! Violators will be prosecuted; Tue, 26 Apr 2016 13:51:41 -0400 X-IBM-Helo: d01dlp01.pok.ibm.com X-IBM-MailFrom: paulmck@linux.vnet.ibm.com X-IBM-RcptTo: linux-kernel@vger.kernel.org;linux-omap@vger.kernel.org Received: from b01cxnp23033.gho.pok.ibm.com (b01cxnp23033.gho.pok.ibm.com [9.57.198.28]) by d01dlp01.pok.ibm.com (Postfix) with ESMTP id 22D3A38C8039; Tue, 26 Apr 2016 13:51:39 -0400 (EDT) Received: from d01av01.pok.ibm.com (d01av01.pok.ibm.com [9.56.224.215]) by b01cxnp23033.gho.pok.ibm.com (8.14.9/8.14.9/NCO v10.0) with ESMTP id u3QHpc7F28115040; Tue, 26 Apr 2016 17:51:38 GMT Received: from d01av01.pok.ibm.com (localhost [127.0.0.1]) by d01av01.pok.ibm.com (8.14.4/8.14.4/NCO v10.0 AVout) with ESMTP id u3QHpbgf005659; Tue, 26 Apr 2016 13:51:38 -0400 Received: from paulmck-ThinkPad-W541 ([9.70.82.191]) by d01av01.pok.ibm.com (8.14.4/8.14.4/NCO v10.0 AVin) with ESMTP id u3QHpb36005595; Tue, 26 Apr 2016 13:51:37 -0400 Received: by paulmck-ThinkPad-W541 (Postfix, from userid 1000) id EC5F416C3648; Tue, 26 Apr 2016 10:52:14 -0700 (PDT) Date: Tue, 26 Apr 2016 10:52:14 -0700 From: "Paul E. McKenney" To: Tony Lindgren Cc: linux-kernel@vger.kernel.org, mingo@kernel.org, Russell King , Steven Rostedt , linux-omap@vger.kernel.org, linux-arm-kernel@lists.infradead.org Subject: Re: [PATCH arm 1/1] arm: Use _rcuidle tracepoint to allow use from idle Message-ID: <20160426175214.GJ3715@linux.vnet.ibm.com> Reply-To: paulmck@linux.vnet.ibm.com References: <1461617335-22372-1-git-send-email-paulmck@linux.vnet.ibm.com> <20160426150031.GP5995@atomide.com> MIME-Version: 1.0 Content-Disposition: inline In-Reply-To: <20160426150031.GP5995@atomide.com> User-Agent: Mutt/1.5.21 (2010-09-15) X-TM-AS-MML: disable X-Content-Scanned: Fidelis XPS MAILER x-cbid: 16042617-0041-0000-0000-000003F9D068 Sender: linux-omap-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-omap@vger.kernel.org X-Spam-Status: No, score=-7.9 required=5.0 tests=BAYES_00, RCVD_IN_DNSWL_HI, RP_MATCHES_RCVD, UNPARSEABLE_RELAY autolearn=unavailable version=3.3.1 X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on mail.kernel.org X-Virus-Scanned: ClamAV using ClamSMTP On Tue, Apr 26, 2016 at 08:00:31AM -0700, Tony Lindgren wrote: > Hi, > > * Paul E. McKenney [160425 13:49]: > > Testing on ARM encountered the following pair of lockdep-RCU splats: > > > > ------------------------------------------------------------------------ > > > > =============================== > > [ INFO: suspicious RCU usage. ] > > 4.6.0-rc4-next-20160422 #1 Not tainted > > ------------------------------- > > include/trace/events/power.h:328 suspicious rcu_dereference_check() usage! > > > > other info that might help us debug this: > > > > RCU used illegally from idle CPU! > > rcu_scheduler_active = 1, debug_locks = 0 > > RCU used illegally from extended quiescent state! > > no locks held by swapper/0/0. > > > > stack backtrace: > > CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.6.0-rc4-next-20160422 #1 > > Hardware name: Generic OMAP3-GP (Flattened Device Tree) > > [] (unwind_backtrace) from [] (show_stack+0x10/0x14) > > [] (show_stack) from [] (dump_stack+0xa8/0xe0) > > [] (dump_stack) from [] (pwrdm_set_next_pwrst+0xf8/0x1cc) > > [] (pwrdm_set_next_pwrst) from [] (omap3_enter_idle_bm+0x1b8/0x1e8) > > [] (omap3_enter_idle_bm) from [] (cpuidle_enter_state+0x84/0x408) > > [] (cpuidle_enter_state) from [] (cpu_startup_entry+0x1c8/0x3f0) > > [] (cpu_startup_entry) from [] (start_kernel+0x354/0x3cc) > > > > ------------------------------------------------------------------------ > > > > [] (unwind_backtrace) from [] (show_stack+0x10/0x14) > > [] (show_stack) from [] (dump_stack+0xa8/0xe0) > > [] (dump_stack) from [] (_pwrdm_state_switch+0x188/0x32c) > > [] (_pwrdm_state_switch) from [] (_pwrdm_post_transition_cb+0xc/0x14) > > [] (_pwrdm_post_transition_cb) from [] (pwrdm_for_each+0x30/0x5c) > > [] (pwrdm_for_each) from [] (pwrdm_post_transition+0x24/0x30) > > [] (pwrdm_post_transition) from [] (omap_sram_idle+0xfc/0x240) > > [] (omap_sram_idle) from [] (omap3_enter_idle_bm+0xf0/0x1e8) > > [] (omap3_enter_idle_bm) from [] (cpuidle_enter_state+0x84/0x408) > > [] (cpuidle_enter_state) from [] (cpu_startup_entry+0x1c8/0x3f0) > > [] (cpu_startup_entry) from [] (start_kernel+0x354/0x3cc) > > > > ------------------------------------------------------------------------ > > > > These are caused by event tracing from the idle loop. This commit > > therefore adds the _rcuidle suffix to make RCU aware of this implicit > > use of RCU by event tracing, thus preventing both splats. > > Maybe also mention which patch in the RCU tree caused these? Or, more accurately, the patch that removed the false negatives that suppressed them. These lockdep-RCU splats were bugs all along, just not reported. > I'm still seeing the following warnings with next with your patch applied. Does the following patch help? It is quite possible that there are quite a few more of these. If this is the case, then one way to make the kernel list more of them on a given boot is to build with CONFIG_PROVE_RCU_REPEATEDLY=y. Thanx, Paul ------------------------------------------------------------------------ commit 99cd56ad86d2d5fbe7ceab303b47f34e4156e5e7 Author: Paul E. McKenney Date: Tue Apr 26 10:42:25 2016 -0700 rm: Use more _rcuidle tracepoints to allow use from idle Further testing with false negatives suppressed by commit 293e2421fe25 ("rcu: Remove superfluous versions of rcu_read_lock_sched_held()") identified a few more unprotected uses of RCU from the idle loop. Because RCU actively ignores idle-loop code (for energy-efficiency reasons, among other things), using RCU from the idle loop can result in too-short grace periods, in turn resulting in arbitrary misbehavior. The resulting lockdep-RCU splats are as follows: ------------------------------------------------------------------------ =============================== [ INFO: suspicious RCU usage. ] 4.6.0-rc5-next-20160426+ #1112 Not tainted ------------------------------- include/trace/events/ipi.h:35 suspicious rcu_dereference_check() usage! other info that might help us debug this: RCU used illegally from idle CPU! rcu_scheduler_active = 1, debug_locks = 0 RCU used illegally from extended quiescent state! no locks held by swapper/0/0. stack backtrace: CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.6.0-rc5-next-20160426+ #1112 Hardware name: Generic OMAP4 (Flattened Device Tree) [] (unwind_backtrace) from [] (show_stack+0x10/0x14) [] (show_stack) from [] (dump_stack+0xb0/0xe4) [] (dump_stack) from [] (smp_cross_call+0xbc/0x188) [] (smp_cross_call) from [] (generic_exec_single+0x9c/0x15c) [] (generic_exec_single) from [] (smp_call_function_single_async+0 x38/0x9c) [] (smp_call_function_single_async) from [] (cpuidle_coupled_poke_others+0x8c/0xa8) [] (cpuidle_coupled_poke_others) from [] (cpuidle_enter_state_coupled+0x26c/0x390) [] (cpuidle_enter_state_coupled) from [] (cpu_startup_entry+0x198/0x3a0) [] (cpu_startup_entry) from [] (start_kernel+0x354/0x3c8) [] (start_kernel) from [<8000807c>] (0x8000807c) ------------------------------------------------------------------------ Warning from omap3 =============================== [ INFO: suspicious RCU usage. ] 4.6.0-rc5-next-20160426+ #1112 Not tainted ------------------------------- include/trace/events/rpm.h:63 suspicious rcu_dereference_check() usage! other info that might help us debug this: RCU used illegally from idle CPU! rcu_scheduler_active = 1, debug_locks = 0 RCU used illegally from extended quiescent state! 1 lock held by swapper/0/0: #0: (&(&dev->power.lock)->rlock){-.-...}, at: [] __pm_runtime_suspend+0x54/0x84 stack backtrace: CPU: 0 PID: 0 Comm: swapper/0 Not tainted 4.6.0-rc5-next-20160426+ #1112 Hardware name: Generic OMAP36xx (Flattened Device Tree) [] (unwind_backtrace) from [] (show_stack+0x10/0x14) [] (show_stack) from [] (dump_stack+0xb0/0xe4) [] (dump_stack) from [] (rpm_suspend+0x604/0x7e4) [] (rpm_suspend) from [] (__pm_runtime_suspend+0x64/0x84) [] (__pm_runtime_suspend) from [] (omap2_gpio_prepare_for_idle+0x5c/0x70) [] (omap2_gpio_prepare_for_idle) from [] (omap_sram_idle+0x140/0x244) [] (omap_sram_idle) from [] (omap3_enter_idle_bm+0xfc/0x1ec) [] (omap3_enter_idle_bm) from [] (cpuidle_enter_state+0x80/0x3d4) [] (cpuidle_enter_state) from [] (cpu_startup_entry+0x198/0x3a0) [] (cpu_startup_entry) from [] (start_kernel+0x354/0x3c8) [] (start_kernel) from [<8000807c>] (0x8000807c) ------------------------------------------------------------------------ Reported-by: Tony Lindgren Signed-off-by: Paul E. McKenney Cc: Tony Lindgren Cc: Russell King Cc: Steven Rostedt Cc: Cc: --- To unsubscribe from this list: send the line "unsubscribe linux-omap" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html diff --git a/arch/arm/kernel/smp.c b/arch/arm/kernel/smp.c index baee70267f29..7afe48ae5d76 100644 --- a/arch/arm/kernel/smp.c +++ b/arch/arm/kernel/smp.c @@ -486,7 +486,7 @@ static const char *ipi_types[NR_IPI] __tracepoint_string = { static void smp_cross_call(const struct cpumask *target, unsigned int ipinr) { - trace_ipi_raise(target, ipi_types[ipinr]); + trace_ipi_raise_rcuidle(target, ipi_types[ipinr]); __smp_cross_call(target, ipinr); } diff --git a/drivers/base/power/runtime.c b/drivers/base/power/runtime.c index 4c7055009bd6..d9358c202763 100644 --- a/drivers/base/power/runtime.c +++ b/drivers/base/power/runtime.c @@ -419,7 +419,7 @@ static int rpm_suspend(struct device *dev, int rpmflags) struct device *parent = NULL; int retval; - trace_rpm_suspend(dev, rpmflags); + trace_rpm_suspend_rcuidle(dev, rpmflags); repeat: retval = rpm_check_suspend_allowed(dev);