From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753037AbdF0N3f (ORCPT ); Tue, 27 Jun 2017 09:29:35 -0400 Received: from mail.kernel.org ([198.145.29.99]:59822 "EHLO mail.kernel.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752654AbdF0N3a (ORCPT ); Tue, 27 Jun 2017 09:29:30 -0400 DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 0A9CA22B5C Authentication-Results: mail.kernel.org; dmarc=none (p=none dis=none) header.from=goodmis.org Authentication-Results: mail.kernel.org; spf=none smtp.mailfrom=rostedt@goodmis.org Date: Tue, 27 Jun 2017 09:29:26 -0400 From: Steven Rostedt To: Masami Hiramatsu Cc: linux-kernel@vger.kernel.org, "Paul E. McKenney" Subject: Re: [BUG] ftrace: WARNING: suspicious RCU usage Message-ID: <20170627092926.0d712e3a@gandalf.local.home> In-Reply-To: <20170627205126.6c5261d10472539b528ca144@kernel.org> References: <20170627205126.6c5261d10472539b528ca144@kernel.org> X-Mailer: Claws Mail 3.14.0 (GTK+ 2.24.31; x86_64-pc-linux-gnu) MIME-Version: 1.0 Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Tue, 27 Jun 2017 20:51:26 +0900 Masami Hiramatsu wrote: > Hello Steve, > > I've faced the following RCU warning while I ran ftracetest testcase > "ftrace - function graph filters with stack tracer" on qemu. > The kernel is ftrace/core branch. > > [ 10.919174] ============================= > [ 10.920077] WARNING: suspicious RCU usage > [ 10.920977] 4.12.0-rc5+ #1 Not tainted > [ 10.921828] ----------------------------- > [ 10.922748] /home/mhiramat/ksrc/linux/include/trace/events/rcu.h:454 suspicious rcu_dereference_check() usage! > [ 10.924761] > [ 10.924761] other info that might help us debug this: > [ 10.924761] > [ 10.926775] > [ 10.926775] RCU used illegally from idle CPU! > [ 10.926775] rcu_scheduler_active = 2, debug_locks = 1 > [ 10.929176] RCU used illegally from extended quiescent state! > [ 10.930525] no locks held by swapper/7/0. > [ 10.931547] > [ 10.931547] stack backtrace: > [ 10.932777] CPU: 7 PID: 0 Comm: swapper/7 Not tainted 4.12.0-rc5+ #1 > [ 10.934025] Hardware name: QEMU Standard PC (i440FX + PIIX, 1996), BIOS 1.9.3-1.fc25 04/01/2014 > [ 10.935869] Call Trace: > [ 10.936550] dump_stack+0x86/0xcf > [ 10.937359] lockdep_rcu_suspicious+0xc5/0x100 > [ 10.938327] ? rcu_eqs_exit_common.isra.53+0x5/0x150 > [ 10.939229] rcu_irq_enter+0x18d/0x1a0 Strange, it triggered in rcu_irq_enter()? > [ 10.939902] ? rcu_eqs_exit_common.isra.53+0x5/0x150 > [ 10.940683] check_stack+0xbb/0x2f0 > [ 10.941333] stack_trace_call+0x3f/0x50 > [ 10.942010] 0xffffffffa0000077 > [ 10.942620] ? ftrace_graph_caller+0x78/0xa8 > [ 10.943342] ? rcu_eqs_exit_common.isra.53+0x5/0x150 > [ 10.944214] ? rcu_idle_exit+0x5/0x90 > [ 10.944937] rcu_eqs_exit_common.isra.53+0x5/0x150 Hmm, we are tracing rcu_eqs_exit_common. Do you have this commit in this branch? Commit 03ecd3f4 "rcu/tracing: Add rcu_disabled to denote when rcu_irq_enter() will not work" -- Steve > [ 10.945754] rcu_idle_exit+0x8c/0x90 > [ 10.946612] ? rcu_eqs_exit_common.isra.53+0x5/0x150 > [ 10.947414] ? rcu_idle_exit+0x8c/0x90 > [ 10.948091] do_idle+0x116/0x1c0 > [ 10.948797] cpu_startup_entry+0x1d/0x20 > [ 10.949569] start_secondary+0xfa/0x100 > [ 10.950335] secondary_startup_64+0x9f/0x9f > [ 10.951182] > > I attached full log and kconfig. I can reproduce it with just running > following script. > > ---- > cd tools/testing/selftests/ftrace > while true; do > ./ftracetest test.d/ftrace/fgraph-filter-stack.tc > done > ---- > > Thank you, >