Received-SPF: pass (google.com: best guess record for domain of linux-kernel-owner@vger.kernel.org designates 209.132.180.67 as permitted sender) client-ip=209.132.180.67;
Date:   Tue, 7 May 2019 15:16:13 -0700
From:   "Paul E. McKenney" <paulmck@linux.ibm.com>
To:     Steven Rostedt <rostedt@goodmis.org>
Cc:     Peter Zijlstra <peterz@infradead.org>,
        linux-kernel@vger.kernel.org, andrea.parri@amarulasolutions.com
Subject: Re: Question about sched_setaffinity()
Reply-To: paulmck@linux.ibm.com
References: <20190427180246.GA15502@linux.ibm.com>
 <20190430100318.GP2623@hirez.programming.kicks-ass.net>
 <20190430105129.GA3923@linux.ibm.com>
 <20190430115551.GT2623@hirez.programming.kicks-ass.net>
 <20190501191213.GX3923@linux.ibm.com>
 <20190501151655.51469a4c@gandalf.local.home>
 <20190501202713.GY3923@linux.ibm.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <20190501202713.GY3923@linux.ibm.com>
User-Agent: Mutt/1.5.21 (2010-09-15)
Message-Id: <20190507221613.GA11057@linux.ibm.com>
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

On Wed, May 01, 2019 at 01:27:13PM -0700, Paul E. McKenney wrote:
> On Wed, May 01, 2019 at 03:16:55PM -0400, Steven Rostedt wrote:
> > On Wed, 1 May 2019 12:12:13 -0700
> > "Paul E. McKenney" <paulmck@linux.ibm.com> wrote:
> > 
> > 
> > > OK, what I did was to apply the patch at the end of this email to -rcu
> > > branch dev, then run rcutorture as follows:
> > > 
> > > nohup tools/testing/selftests/rcutorture/bin/kvm.sh --cpus 8 --duration 2 --configs "TRIVIAL" --bootargs "trace_event=sched:sched_switch,sched:sched_wakeup ftrace=function_graph ftrace_graph_filter=sched_setaffinity,migration_cpu_stop"
> > > 
> > > This resulted in the console output that I placed here:
> > > 
> > > http://www2.rdrop.com/~paulmck/submission/console.log.gz
> > > 
> > > But I don't see calls to sched_setaffinity() or migration_cpu_stop().
> > > Steve, is something else needed on the kernel command line in addition to
> > > the following?
> > > 
> > > ftrace=function_graph ftrace_graph_filter=sched_setaffinity,migration_cpu_stop
> > 
> > Do you have function graph enabled in the config?
> > 
> > [    2.098303] ftrace bootup tracer 'function_graph' not registered.
> 
> I guess I don't!  Thank you, will fix.
> 
> Let's see...
> 
> My .config has CONFIG_HAVE_FUNCTION_GRAPH_TRACER=y.  It looks like I
> need CONFIG_FUNCTION_GRAPH_TRACER=y, which I don't have.  And it looks
> like that needs CONFIG_FUNCTION_TRACER=y, which I also don't have.
> But I do have CONFIG_HAVE_FUNCTION_TRACER=y.  So I should add this
> to my rcutorture command line:
> 
> --kconfig "CONFIG_FUNCTION_TRACER=y CONFIG_FUNCTION_GRAPH_TRACER=y".
> 
> I fired this up.  Here is hoping!  ;-)
> 
> And it does have sched_setaffinity(), woo-hoo!!!  I overwrote the old file:
> 
> 	http://www2.rdrop.com/~paulmck/submission/console.log.gz

And I reran after adding a trace_printk(), which shows up as follows:

[  211.409565]  6)               |  /* On unexpected CPU 6, expected 4!!! */

I placed the console log here:

	http://www2.rdrop.com/~paulmck/submission/console.tpk.log.gz

Just in case the earlier log proves useful.

And it is acting as if the destination CPU proved to be offline.  Except
that this rcutorture scenario doesn't offline anything, and I don't see
any CPU-hotplug removal messages.  So I added another trace_printk() to
print out cpu_online_mask.  This gets me the following:

[   31.565605]  0)               |  /* On unexpected CPU 0, expected 1!!! */
[   31.565605]  0)               |  /* Online CPUs: 0-7 */

So we didn't make it to CPU 1 despite its being online.  I placed the
console log here:

	http://www2.rdrop.com/~paulmck/submission/console.tpkol.log.gz

Thoughts?

Updated patch against -rcu below in case it is useful.

							Thanx, Paul

------------------------------------------------------------------------

diff --git a/kernel/rcu/rcutorture.c b/kernel/rcu/rcutorture.c
index da04b5073dc3..23ec8ec7eddd 100644
--- a/kernel/rcu/rcutorture.c
+++ b/kernel/rcu/rcutorture.c
@@ -680,12 +680,24 @@ static struct rcu_torture_ops tasks_ops = {
 static void synchronize_rcu_trivial(void)
 {
 	int cpu;
+	int destcpu;
+	static int dont_trace;
 
 	for_each_online_cpu(cpu) {
-		while (raw_smp_processor_id() != cpu)
-			rcutorture_sched_setaffinity(current->pid,
-						     cpumask_of(cpu));
-		WARN_ON_ONCE(raw_smp_processor_id() != cpu);
+		if (!READ_ONCE(dont_trace))
+			tracing_on();
+		rcutorture_sched_setaffinity(current->pid, cpumask_of(cpu));
+		destcpu = raw_smp_processor_id();
+		if (destcpu == cpu) {
+			tracing_off();
+		} else {
+			trace_printk("On unexpected CPU %d, expected %d!!!\n", destcpu, cpu);
+			trace_printk("Online CPUs: %*pbl\n", cpumask_pr_args(cpu_online_mask));
+			tracing_stop();
+			WRITE_ONCE(dont_trace, 1);
+			WARN_ON_ONCE(1);
+			rcu_ftrace_dump(DUMP_ALL);
+		}
 	}
 }
 
diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c
index caffee644932..edaf0ca22ff7 100644
--- a/kernel/rcu/tree.c
+++ b/kernel/rcu/tree.c
@@ -3495,6 +3495,7 @@ void __init rcu_init(void)
 	rcu_par_gp_wq = alloc_workqueue("rcu_par_gp", WQ_MEM_RECLAIM, 0);
 	WARN_ON(!rcu_par_gp_wq);
 	srcu_init();
+	tracing_off();
 }
 
 #include "tree_stall.h"