From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753989AbdF0Wwb (ORCPT ); Tue, 27 Jun 2017 18:52:31 -0400 Received: from mail.kernel.org ([198.145.29.99]:50962 "EHLO mail.kernel.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753845AbdF0WwZ (ORCPT ); Tue, 27 Jun 2017 18:52:25 -0400 DMARC-Filter: OpenDMARC Filter v1.3.2 mail.kernel.org 121A1217C3 Authentication-Results: mail.kernel.org; dmarc=none (p=none dis=none) header.from=kernel.org Authentication-Results: mail.kernel.org; spf=none smtp.mailfrom=mhiramat@kernel.org Date: Wed, 28 Jun 2017 07:52:22 +0900 From: Masami Hiramatsu To: Masami Hiramatsu Cc: Steven Rostedt , linux-kernel@vger.kernel.org, "Paul E. McKenney" Subject: Re: [BUG] ftrace: WARNING: suspicious RCU usage Message-Id: <20170628075222.03ebbcd22036e8e27d7c7a04@kernel.org> In-Reply-To: <20170627225356.318f81d3c687973b7f4f49b1@kernel.org> References: <20170627205126.6c5261d10472539b528ca144@kernel.org> <20170627092926.0d712e3a@gandalf.local.home> <20170627225356.318f81d3c687973b7f4f49b1@kernel.org> X-Mailer: Sylpheed 3.5.0 (GTK+ 2.24.31; x86_64-redhat-linux-gnu) Mime-Version: 1.0 Content-Type: multipart/mixed; boundary="Multipart=_Wed__28_Jun_2017_07_52_22_+0900_jzgGhh=cvuZd+4qj" Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org This is a multi-part message in MIME format. --Multipart=_Wed__28_Jun_2017_07_52_22_+0900_jzgGhh=cvuZd+4qj Content-Type: text/plain; charset=US-ASCII Content-Transfer-Encoding: 7bit Hi, On Tue, 27 Jun 2017 22:53:56 +0900 Masami Hiramatsu wrote: > > > [ 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. Yes, the Commit 03ecd3f4 fixed only rcu_eqs_enter_common() path, but not rcu_eqs_exit(). > > > > > > Do you have this commit in this branch? > > > > Commit 03ecd3f4 "rcu/tracing: Add rcu_disabled to denote when > > rcu_irq_enter() will not work" > > Yes, that is merged. > > Hmm, I'll check this is correctly enabled again, since this time > I couldn't reproduce it. I could reproduce it again with running full ftracetest (not sure why, but with only fgraph-filter-stack.tc, it is hard to be reproduced. Please see attached patch, after applying that, I didn't see this problem. Thank you, -- Masami Hiramatsu --Multipart=_Wed__28_Jun_2017_07_52_22_+0900_jzgGhh=cvuZd+4qj Content-Type: application/octet-stream; name="rcu-tracing-set" Content-Disposition: attachment; filename="rcu-tracing-set" Content-Transfer-Encoding: base64 cmN1L3RyYWNpbmc6IFNldCBkaXNhYmxlX3JjdV9pcnFfZW50ZXIgb24gcmN1X2Vxc19leGl0IHRv bwoKRnJvbTogTWFzYW1pIEhpcmFtYXRzdSA8bWhpcmFtYXRAa2VybmVsLm9yZz4KClNldCBkaXNh YmxlX3JjdV9pcnFfZW50ZXIgb24gbm90IG9ubHkgcmN1X2Vxc19lbnRlcl9jb21tb24oKQpidXQg YWxzbyByY3VfZXFzX2V4aXQoKSwgc2luY2UgdGhlcmUgaXMgc2FtZSBpc3N1ZSBhcwpjb21taXQg MDNlY2QzZjQ4ZTU3ICgicmN1L3RyYWNpbmc6IEFkZCByY3VfZGlzYWJsZWQgdG8KZGVub3RlIHdo ZW4gcmN1X2lycV9lbnRlcigpIHdpbGwgbm90IHdvcmsiKSBmaXhlZCB0aGVyZS4KClNpZ25lZC1v ZmYtYnk6IE1hc2FtaSBIaXJhbWF0c3UgPG1oaXJhbWF0QGtlcm5lbC5vcmc+Ci0tLQoga2VybmVs L3JjdS90cmVlLmMgfCAgICAyICsrCiAxIGZpbGUgY2hhbmdlZCwgMiBpbnNlcnRpb25zKCspCgpk aWZmIC0tZ2l0IGEva2VybmVsL3JjdS90cmVlLmMgYi9rZXJuZWwvcmN1L3RyZWUuYwppbmRleCBl MzU0ZTQ3Li40NDJiNDA5IDEwMDY0NAotLS0gYS9rZXJuZWwvcmN1L3RyZWUuYworKysgYi9rZXJu ZWwvcmN1L3RyZWUuYwpAQCAtOTczLDggKzk3MywxMCBAQCBzdGF0aWMgdm9pZCByY3VfZXFzX2V4 aXQoYm9vbCB1c2VyKQogCWlmIChvbGR2YWwgJiBEWU5USUNLX1RBU0tfTkVTVF9NQVNLKSB7CiAJ CXJkdHAtPmR5bnRpY2tzX25lc3RpbmcgKz0gRFlOVElDS19UQVNLX05FU1RfVkFMVUU7CiAJfSBl bHNlIHsKKwkJX190aGlzX2NwdV9pbmMoZGlzYWJsZV9yY3VfaXJxX2VudGVyKTsKIAkJcmR0cC0+ ZHludGlja3NfbmVzdGluZyA9IERZTlRJQ0tfVEFTS19FWElUX0lETEU7CiAJCXJjdV9lcXNfZXhp dF9jb21tb24ob2xkdmFsLCB1c2VyKTsKKwkJX190aGlzX2NwdV9kZWMoZGlzYWJsZV9yY3VfaXJx X2VudGVyKTsKIAl9CiB9CiAK --Multipart=_Wed__28_Jun_2017_07_52_22_+0900_jzgGhh=cvuZd+4qj--