From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1756045Ab2AXQxn (ORCPT ); Tue, 24 Jan 2012 11:53:43 -0500 Received: from e34.co.us.ibm.com ([32.97.110.152]:38943 "EHLO e34.co.us.ibm.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1752274Ab2AXQxl (ORCPT ); Tue, 24 Jan 2012 11:53:41 -0500 Date: Tue, 24 Jan 2012 08:53:13 -0800 From: "Paul E. McKenney" To: Eric Dumazet Cc: Ingo Molnar , Linus Torvalds , linux-kernel@vger.kernel.org, =?iso-8859-1?Q?Fr=E9d=E9ric?= Weisbecker , Thomas Gleixner , Peter Zijlstra , Andrew Morton Subject: Re: [GIT PULL] RCU changes for v3.3 Message-ID: <20120124165312.GG2531@linux.vnet.ibm.com> Reply-To: paulmck@linux.vnet.ibm.com References: <20120105135432.GA31450@elte.hu> <1327422312.7231.22.camel@edumazet-HP-Compaq-6005-Pro-SFF-PC> MIME-Version: 1.0 Content-Type: text/plain; charset=iso-8859-1 Content-Disposition: inline Content-Transfer-Encoding: 8bit In-Reply-To: <1327422312.7231.22.camel@edumazet-HP-Compaq-6005-Pro-SFF-PC> User-Agent: Mutt/1.5.21 (2010-09-15) X-Content-Scanned: Fidelis XPS MAILER x-cbid: 12012416-1780-0000-0000-00000297256A X-IBM-ISS-SpamDetectors: X-IBM-ISS-DetailInfo: BY=3.00000245; HX=3.00000181; KW=3.00000007; PH=3.00000001; SC=3.00000001; SDB=6.00107753; UDB=6.00026991; UTC=2012-01-24 16:53:39 Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org On Tue, Jan 24, 2012 at 05:25:12PM +0100, Eric Dumazet wrote: > Le jeudi 05 janvier 2012 à 14:54 +0100, Ingo Molnar a écrit : > > Linus, > > > > Please pull the latest core-rcu-for-linus git tree from: > > > > git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip.git core-rcu-for-linus > > > > Thanks, > > Hi guys > > New lockdep warning here : Hmmm... Looks like tracing from within the inner idle loop. Because RCU ignores CPUs in the inner idle loop (after the call to rcu_idle_enter()), RCU read-side critical sections are not legal there. One approach would be to delay the call to rcu_idle_enter() until after the tracing is done, and to ensure that the call to rcu_idle_exit() happens before any tracing. I am not seeing perf_trace_power(), so need to update and look again. Or are you looking at -next rather than mainline? Thanx, Paul > [ 850.464548] > [ 850.464550] =============================== > [ 850.464553] [ INFO: suspicious RCU usage. ] > [ 850.464555] 3.3.0-rc1+ #569 Not tainted > [ 850.464557] ------------------------------- > [ 850.464559] include/trace/events/power.h:102 suspicious rcu_dereference_check() usage! > [ 850.464562] > [ 850.464562] other info that might help us debug this: > [ 850.464564] > [ 850.464566] > [ 850.464567] rcu_scheduler_active = 1, debug_locks = 1 > [ 850.464569] RCU used illegally from extended quiescent state! > [ 850.464571] no locks held by swapper/1/0. > [ 850.464572] > [ 850.464572] stack backtrace: > [ 850.464575] Pid: 0, comm: swapper/1 Not tainted 3.3.0-rc1+ #569 > [ 850.464578] Call Trace: > [ 850.464584] [] lockdep_rcu_suspicious+0xca/0xf0 > [ 850.464588] [] mwait_idle+0x499/0x4c0 > [ 850.464592] [] cpu_idle+0x96/0xe0 > [ 850.464597] [] start_secondary+0x1df/0x1e3 > [ 850.464765] ------------[ cut here ]------------ > [ 850.464769] WARNING: at include/linux/rcupdate.h:242 __perf_event_overflow+0x27c/0x2c0() > [ 850.464771] Hardware name: ProLiant BL460c G6 > [ 850.464772] Modules linked in: ipmi_devintf nfsd exportfs ipmi_si hpilo bnx2x crc32c libcrc32c mdio [last unloaded: scsi_wait_scan] > [ 850.464783] Pid: 0, comm: swapper/1 Not tainted 3.3.0-rc1+ #569 > [ 850.464784] Call Trace: > [ 850.464788] [] warn_slowpath_common+0x7f/0xc0 > [ 850.464791] [] warn_slowpath_null+0x1a/0x20 > [ 850.464794] [] __perf_event_overflow+0x27c/0x2c0 > [ 850.464797] [] ? printk+0x41/0x43 > [ 850.464801] [] ? __module_text_address+0x16/0x80 > [ 850.464804] [] perf_swevent_overflow+0xa9/0xc0 > [ 850.464806] [] perf_swevent_event+0x6f/0x90 > [ 850.464809] [] perf_tp_event+0x76/0xf0 > [ 850.464813] [] perf_trace_power+0xbe/0xe0 > [ 850.464816] [] ? mwait_idle+0x40f/0x4c0 > [ 850.464818] [] mwait_idle+0x40f/0x4c0 > [ 850.464821] [] cpu_idle+0x96/0xe0 > [ 850.464824] [] start_secondary+0x1df/0x1e3 > [ 850.464826] ---[ end trace d3b6df8c2cde8681 ]--- > [ 850.464828] ------------[ cut here ]------------ > [ 850.464831] WARNING: at include/linux/rcupdate.h:242 perf_output_begin+0x2f6/0x330() > [ 850.464832] Hardware name: ProLiant BL460c G6 > [ 850.464833] Modules linked in: ipmi_devintf nfsd exportfs ipmi_si hpilo bnx2x crc32c libcrc32c mdio [last unloaded: scsi_wait_scan] > [ 850.464842] Pid: 0, comm: swapper/1 Tainted: G W 3.3.0-rc1+ #569 > [ 850.464844] Call Trace: > [ 850.464846] [] warn_slowpath_common+0x7f/0xc0 > [ 850.464849] [] warn_slowpath_null+0x1a/0x20 > [ 850.464852] [] perf_output_begin+0x2f6/0x330 > [ 850.464855] [] ? sched_clock_cpu+0xc5/0x120 > [ 850.464858] [] ? trace_hardirqs_off+0xd/0x10 > [ 850.464860] [] ? local_clock+0x4f/0x60 > [ 850.464863] [] ? __perf_event_header__init_id+0xad/0xf0 > [ 850.464866] [] ? perf_prepare_sample+0x63/0x110 > [ 850.464869] [] __perf_event_overflow+0x18d/0x2c0 > [ 850.464871] [] ? __perf_event_overflow+0x145/0x2c0 > [ 850.464874] [] ? printk+0x41/0x43 > [ 850.464876] [] perf_swevent_overflow+0xa9/0xc0 > [ 850.464879] [] perf_swevent_event+0x6f/0x90 > [ 850.464881] [] perf_tp_event+0x76/0xf0 > [ 850.464884] [] perf_trace_power+0xbe/0xe0 > [ 850.464887] [] ? mwait_idle+0x40f/0x4c0 > [ 850.464890] [] mwait_idle+0x40f/0x4c0 > [ 850.464893] [] cpu_idle+0x96/0xe0 > [ 850.464895] [] start_secondary+0x1df/0x1e3 > [ 850.464897] ---[ end trace d3b6df8c2cde8682 ]--- > [ 850.464899] > [ 850.464900] =============================== > [ 850.464901] [ INFO: suspicious RCU usage. ] > [ 850.464902] 3.3.0-rc1+ #569 Tainted: G W > [ 850.464904] ------------------------------- > [ 850.464905] kernel/events/ring_buffer.c:120 suspicious rcu_dereference_check() usage! > [ 850.464907] > [ 850.464907] other info that might help us debug this: > [ 850.464908] > [ 850.464909] > [ 850.464910] rcu_scheduler_active = 1, debug_locks = 1 > [ 850.464911] RCU used illegally from extended quiescent state! > [ 850.464913] 2 locks held by swapper/1/0: > [ 850.464914] #0: (rcu_read_lock){.+.+..}, at: [] __perf_event_overflow+0x145/0x2c0 > [ 850.464920] #1: (rcu_read_lock){.+.+..}, at: [] perf_output_begin+0x3f/0x330 > [ 850.464924] > [ 850.464925] stack backtrace: > [ 850.464927] Pid: 0, comm: swapper/1 Tainted: G W 3.3.0-rc1+ #569 > [ 850.464928] Call Trace: > [ 850.464931] [] lockdep_rcu_suspicious+0xca/0xf0 > [ 850.464933] [] perf_output_begin+0x268/0x330 > [ 850.464936] [] ? perf_output_begin+0x3f/0x330 > [ 850.464938] [] ? sched_clock_cpu+0xc5/0x120 > [ 850.464941] [] ? trace_hardirqs_off+0xd/0x10 > [ 850.464943] [] ? local_clock+0x4f/0x60 > [ 850.464946] [] ? __perf_event_header__init_id+0xad/0xf0 > [ 850.464949] [] ? perf_prepare_sample+0x63/0x110 > [ 850.464952] [] __perf_event_overflow+0x18d/0x2c0 > [ 850.464954] [] ? __perf_event_overflow+0x145/0x2c0 > [ 850.464957] [] ? printk+0x41/0x43 > [ 850.464959] [] perf_swevent_overflow+0xa9/0xc0 > [ 850.464962] [] perf_swevent_event+0x6f/0x90 > [ 850.464964] [] perf_tp_event+0x76/0xf0 > [ 850.464967] [] perf_trace_power+0xbe/0xe0 > [ 850.464970] [] ? mwait_idle+0x40f/0x4c0 > [ 850.464973] [] mwait_idle+0x40f/0x4c0 > [ 850.464975] [] cpu_idle+0x96/0xe0 > [ 850.464978] [] start_secondary+0x1df/0x1e3 > [ 850.464980] ------------[ cut here ]------------ > [ 850.464983] WARNING: at include/linux/rcupdate.h:248 perf_output_end+0x5b/0x70() > [ 850.464984] Hardware name: ProLiant BL460c G6 > [ 850.464985] Modules linked in: ipmi_devintf nfsd exportfs ipmi_si hpilo bnx2x crc32c libcrc32c mdio [last unloaded: scsi_wait_scan] > [ 850.464994] Pid: 0, comm: swapper/1 Tainted: G W 3.3.0-rc1+ #569 > [ 850.464995] Call Trace: > [ 850.464998] [] warn_slowpath_common+0x7f/0xc0 > [ 850.465001] [] warn_slowpath_null+0x1a/0x20 > [ 850.465003] [] perf_output_end+0x5b/0x70 > [ 850.465006] [] __perf_event_overflow+0x22c/0x2c0 > [ 850.465008] [] ? __perf_event_overflow+0x145/0x2c0 > [ 850.465011] [] perf_swevent_overflow+0xa9/0xc0 > [ 850.465014] [] perf_swevent_event+0x6f/0x90 > [ 850.465016] [] perf_tp_event+0x76/0xf0 > [ 850.465019] [] perf_trace_power+0xbe/0xe0 > [ 850.465022] [] ? mwait_idle+0x40f/0x4c0 > [ 850.465025] [] mwait_idle+0x40f/0x4c0 > [ 850.465027] [] cpu_idle+0x96/0xe0 > [ 850.465030] [] start_secondary+0x1df/0x1e3 > [ 850.465032] ---[ end trace d3b6df8c2cde8683 ]--- > [ 850.465033] ------------[ cut here ]------------ > [ 850.465036] WARNING: at include/linux/rcupdate.h:248 __perf_event_overflow+0x2a6/0x2c0() > [ 850.465037] Hardware name: ProLiant BL460c G6 > [ 850.465038] Modules linked in: ipmi_devintf nfsd exportfs ipmi_si hpilo bnx2x crc32c libcrc32c mdio [last unloaded: scsi_wait_scan] > [ 850.465047] Pid: 0, comm: swapper/1 Tainted: G W 3.3.0-rc1+ #569 > [ 850.465048] Call Trace: > [ 850.465051] [] warn_slowpath_common+0x7f/0xc0 > [ 850.465054] [] warn_slowpath_null+0x1a/0x20 > [ 850.465056] [] __perf_event_overflow+0x2a6/0x2c0 > [ 850.465059] [] ? __perf_event_overflow+0x145/0x2c0 > [ 850.465061] [] perf_swevent_overflow+0xa9/0xc0 > [ 850.465064] [] perf_swevent_event+0x6f/0x90 > [ 850.465066] [] perf_tp_event+0x76/0xf0 > [ 850.465069] [] perf_trace_power+0xbe/0xe0 > [ 850.465072] [] ? mwait_idle+0x40f/0x4c0 > [ 850.465075] [] mwait_idle+0x40f/0x4c0 > [ 850.465077] [] cpu_idle+0x96/0xe0 > [ 850.465080] [] start_secondary+0x1df/0x1e3 > [ 850.465082] ---[ end trace d3b6df8c2cde8684 ]--- > [ 850.467615] > [ 850.467617] =============================== > [ 850.467619] [ INFO: suspicious RCU usage. ] > [ 850.467621] 3.3.0-rc1+ #569 Tainted: G W > [ 850.467624] ------------------------------- > [ 850.467626] include/trace/events/power.h:127 suspicious rcu_dereference_check() usage! > [ 850.467629] > [ 850.467629] other info that might help us debug this: > [ 850.467630] > [ 850.467632] > [ 850.467632] rcu_scheduler_active = 1, debug_locks = 1 > [ 850.467634] RCU used illegally from extended quiescent state! > [ 850.467636] no locks held by swapper/1/0. > [ 850.467637] > [ 850.467638] stack backtrace: > [ 850.467640] Pid: 0, comm: swapper/1 Tainted: G W 3.3.0-rc1+ #569 > [ 850.467642] Call Trace: > [ 850.467646] [] lockdep_rcu_suspicious+0xca/0xf0 > [ 850.467650] [] mwait_idle+0x2ad/0x4c0 > [ 850.467653] [] cpu_idle+0x96/0xe0 > [ 850.467656] [] start_secondary+0x1df/0x1e3 > >