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:   Fri, 9 Aug 2019 14:07:21 -0400
From:   Joel Fernandes <joel@joelfernandes.org>
To:     "Paul E. McKenney" <paulmck@linux.ibm.com>
Cc:     Peter Zijlstra <peterz@infradead.org>, rcu@vger.kernel.org,
        linux-kernel@vger.kernel.org, mingo@kernel.org,
        jiangshanlai@gmail.com, dipankar@in.ibm.com,
        akpm@linux-foundation.org, mathieu.desnoyers@efficios.com,
        josh@joshtriplett.org, tglx@linutronix.de, rostedt@goodmis.org,
        dhowells@redhat.com, edumazet@google.com, fweisbec@gmail.com,
        oleg@redhat.com
Subject: Re: [PATCH RFC tip/core/rcu 14/14] rcu/nohz: Make multi_cpu_stop()
 enable tick on all online CPUs
Message-ID: <20190809180721.GA255533@google.com>
References: <20190804184159.GC28441@linux.ibm.com>
 <20190805080531.GH2349@hirez.programming.kicks-ass.net>
 <20190805145448.GI28441@linux.ibm.com>
 <20190805155024.GK2332@hirez.programming.kicks-ass.net>
 <20190805174800.GK28441@linux.ibm.com>
 <20190806180824.GA28448@linux.ibm.com>
 <20190807214131.GA15124@linux.ibm.com>
 <20190808203541.GA8160@linux.ibm.com>
 <20190808213012.GA28773@linux.ibm.com>
 <20190809165120.GA5668@linux.ibm.com>
MIME-Version: 1.0
Content-Type: text/plain; charset=us-ascii
Content-Disposition: inline
In-Reply-To: <20190809165120.GA5668@linux.ibm.com>
User-Agent: Mutt/1.10.1 (2018-07-13)
Sender: linux-kernel-owner@vger.kernel.org
Precedence: bulk

On Fri, Aug 09, 2019 at 09:51:20AM -0700, Paul E. McKenney wrote:
> > > > And of course I forgot to dump out the online CPUs, so I really had no
> > > > idea whether or not all the CPUs were accounted for.  I added tracing
> > > > to dump out the online CPUs at the beginning of __stop_cpus() and then
> > > > reworked it a few times to get the problem to happen in reasonable time.
> > > > Please see below for the resulting annotated trace.
> > > > 
> > > > I was primed to expect a lost IPI, perhaps due to yet another qemu bug,
> > > > but all the migration threads are running within about 2 milliseconds.
> > > > It is then almost two minutes(!) until the next trace message.
> > > > 
> > > > Looks like time to (very carefully!) instrument multi_cpu_stop().
> > > > 
> > > > Of course, if you have any ideas, please do not keep them a secret!
> > > 
> > > Functionally, multi_cpu_stop() is working fine, according to the trace
> > > below (search for a line beginning with TAB).  But somehow CPU 2 took
> > > almost three -minutes- to do one iteration of the loop.  The prime suspect
> > > in that loop is cpu_relax() due to the hypervisor having an opportunity
> > > to do something at that point.  The commentary below (again, search for
> > > a line beginning with TAB) gives my analysis.
> > > 
> > > Of course, if I am correct, it should be possible to catch cpu_relax()
> > > in the act.  That is the next step, give or take the Heisenbuggy nature
> > > of this beast.
> > > 
> > > Another thing for me to try is to run longer with !NO_HZ_FULL, just in
> > > case the earlier runs just got lucky.
> > > 
> > > Thoughts?
> > 
> > And it really can happen:
> > 
> > [ 1881.467922] migratio-33      4...1 1879530317us : stop_machine_yield: cpu_relax() took 756140 ms
> > 
> > The previous timestamp was 1123391100us, so the cpu_relax() is almost
> > exactly the full delay.
> > 
> > But another instance stalled for many minutes without a ten-second
> > cpu_relax().  So it is not just cpu_relax() causing trouble.  I could
> > rationalize that vCPU preemption being at fault...
> > 
> > And my diagnostic patch is below, just in case I am doing something
> > stupid with that.
> 
> I did a 12-hour run with the same configuration except for leaving out the
> "nohz_full=1-7" kernel parameter without problems (aside from the RCU CPU
> stall warnings due to the ftrace_dump() at the end of the run -- isn't
> there some way to clear the ftrace buffer without actually printing it?).

I think if tracing_reset_all_online_cpus() is exposed, then calling that with
the appropriate locks held can reset the ftrace ring buffer and clear the
trace. Steve, is there a better way?

thanks,

 - Joel