LKML Archive on lore.kernel.org
 help / color / Atom feed
From: "Paul E. McKenney" <paulmck@linux.vnet.ibm.com>
To: Steven Rostedt <rostedt@goodmis.org>
Cc: LKML <linux-kernel@vger.kernel.org>
Subject: Re: [BUG] stack tracing causes: kernel/module.c:271 module_assert_mutex_or_preempt
Date: Wed, 5 Apr 2017 13:42:29 -0700
Message-ID: <20170405204229.GQ1600@linux.vnet.ibm.com> (raw)
In-Reply-To: <20170405155223.7b416683@gandalf.local.home>

On Wed, Apr 05, 2017 at 03:52:23PM -0400, Steven Rostedt wrote:
> On Wed, 5 Apr 2017 12:39:28 -0700
> "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> wrote:
> > > Here's the crucial part of that stack dump again:
> > > 
> > >  save_stack_trace+0x1b/0x1d
> > >  check_stack+0xec/0x24a
> > >  stack_trace_call+0x40/0x53
> > >  0xffffffffa0026077
> > >  ? ftrace_graph_caller+0x78/0xa8
> > >  ? trace_hardirqs_off+0xd/0xf
> > >  ? rcu_eqs_enter_common.constprop.71+0x5/0x108
> > >  rcu_eqs_enter_common.constprop.71+0x5/0x108
> > >  rcu_idle_enter+0x51/0x72
> > > 
> > > 
> > > The stack trace was called on rcu_eqs_enter_common() inside the
> > > rcu_idle_enter() function call.
> > > 
> > > Perhaps if I just let rcu disable stack tracing? Something like this:
> > > 
> > > diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c
> > > index 50fee76..f894fc3 100644
> > > --- a/kernel/rcu/tree.c
> > > +++ b/kernel/rcu/tree.c
> > > @@ -853,8 +853,10 @@ void rcu_idle_enter(void)
> > >  	unsigned long flags;
> > > 
> > >  	local_irq_save(flags);
> > > +	disable_stack_tracer();
> > >  	rcu_eqs_enter(false);
> > >  	rcu_sysidle_enter(0);
> > > +	enable_stack_tracer();
> > >  	local_irq_restore(flags);
> > >  }
> > >  EXPORT_SYMBOL_GPL(rcu_idle_enter);  
> > 
> > That only covers one of two code paths, and still end up with the
> > trace code thinking that RCU is paying attention to it when it really
> > is not.
> 
> OK, that sounds like a separate bug to what I'm tracking.
> 
> > 
> > But if there is a disable_stack_tracer() and enable_stack_tracer(),
> > I could use them as shown below.  (Hand-edited patch, probably doesn't
> > apply, let alone build.)
> > 
> > 							Thanx, Paul
> > 
> > ------------------------------------------------------------------------
> > 
> > commit 1a11d6fd0ae344f7dccd57d3c587d9ef2a4bf08e
> > Author: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> > Date:   Wed Apr 5 09:05:18 2017 -0700
> > 
> >     rcu: Fix dyntick-idle tracing
> >     
> >     The tracing subsystem started using rcu_irq_entry() and rcu_irq_exit()
> >     (with my blessing) to allow the current _rcuidle alternative tracepoint
> >     name to be dispensed with while still maintaining good performance.
> >     Unfortunately, this causes RCU's dyntick-idle entry code's tracing to
> >     appear to RCU like an interrupt that occurs where RCU is not designed
> >     to handle interrupts.
> >     
> >     This commit fixes this problem by moving the zeroing of ->dynticks_nesting
> >     after the offending trace_rcu_dyntick() statement, which narrows the
> >     window of vulnerability to a pair of adjacent statements that are now
> >     marked with comments to that effect.
> >     
> >     Reported-by: Steven Rostedt <rostedt@goodmis.org>
> >     Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> > 
> > diff --git a/kernel/rcu/tree.c b/kernel/rcu/tree.c
> > index 50fee7689e71..7308c88ee57a 100644
> > --- a/kernel/rcu/tree.c
> > +++ b/kernel/rcu/tree.c
> > @@ -771,25 +771,24 @@ cpu_needs_another_gp(struct rcu_state *rsp, struct rcu_data *rdp)
> >  }
> >  
> >  /*
> > - * rcu_eqs_enter_common - current CPU is moving towards extended quiescent state
> > + * rcu_eqs_enter_common - current CPU is entering an extended quiescent state
> >   *
> > - * If the new value of the ->dynticks_nesting counter now is zero,
> > - * we really have entered idle, and must do the appropriate accounting.
> > - * The caller must have disabled interrupts.
> > + * Enter idle, doing appropriate accounting.  The caller must have
> > + * disabled interrupts.
> >   */
> > -static void rcu_eqs_enter_common(long long oldval, bool user)
> > +static void rcu_eqs_enter_common(bool user)
> >  {
> >  	struct rcu_state *rsp;
> >  	struct rcu_data *rdp;
> > -	RCU_TRACE(struct rcu_dynticks *rdtp = this_cpu_ptr(&rcu_dynticks);)
> > +	struct rcu_dynticks *rdtp = this_cpu_ptr(&rcu_dynticks);
> >  
> > -	trace_rcu_dyntick(TPS("Start"), oldval, rdtp->dynticks_nesting);
> > +	trace_rcu_dyntick(TPS("Start"), rdtp->dynticks_nesting, 0);
> >  	if (IS_ENABLED(CONFIG_RCU_EQS_DEBUG) &&
> >  	    !user && !is_idle_task(current)) {
> >  		struct task_struct *idle __maybe_unused =
> >  			idle_task(smp_processor_id());
> >  
> > -		trace_rcu_dyntick(TPS("Error on entry: not idle task"), oldval, 0);
> > +		trace_rcu_dyntick(TPS("Error on entry: not idle task"), rdtp->dynticks_nesting, 0);
> >  		rcu_ftrace_dump(DUMP_ORIG);
> >  		WARN_ONCE(1, "Current pid: %d comm: %s / Idle pid: %d comm: %s",
> >  			  current->pid, current->comm,
> > @@ -800,7 +799,8 @@ static void rcu_eqs_enter_common(long long oldval, bool user)
> >  		do_nocb_deferred_wakeup(rdp);
> >  	}
> >  	rcu_prepare_for_idle();
> > -	rcu_dynticks_eqs_enter();
> > +	disable_stack_tracer();
> > +	rdtp->dynticks_nesting = 0; /* Breaks tracing momentarily. */
> > +	rcu_dynticks_eqs_enter(); /* After this, tracing works again. */
> > +	enable_stack_tracer();
> 
> OK, do you want me to send you a patch, or should I take your patch
> into my tree and add this?

Given that I don't seem to have disable_stack_tracer() and
enable_stack_tracer(), could you please add them in?

							Thanx, Paul

> -- Steve
> 
> >  	rcu_dynticks_task_enter();
> >  
> >  	/*
> > @@ -821,19 +821,15 @@ static void rcu_eqs_enter_common(long long oldval, bool user)
> >   */
> >  static void rcu_eqs_enter(bool user)
> >  {
> > -	long long oldval;
> >  	struct rcu_dynticks *rdtp;
> >  
> >  	rdtp = this_cpu_ptr(&rcu_dynticks);
> > -	oldval = rdtp->dynticks_nesting;
> >  	WARN_ON_ONCE(IS_ENABLED(CONFIG_RCU_EQS_DEBUG) &&
> > -		     (oldval & DYNTICK_TASK_NEST_MASK) == 0);
> > -	if ((oldval & DYNTICK_TASK_NEST_MASK) == DYNTICK_TASK_NEST_VALUE) {
> > -		rdtp->dynticks_nesting = 0;
> > -		rcu_eqs_enter_common(oldval, user);
> > -	} else {
> > +		     (rdtp->dynticks_nesting & DYNTICK_TASK_NEST_MASK) == 0);
> > +	if ((rdtp->dynticks_nesting & DYNTICK_TASK_NEST_MASK) == DYNTICK_TASK_NEST_VALUE)
> > +		rcu_eqs_enter_common(user);
> > +	else
> >  		rdtp->dynticks_nesting -= DYNTICK_TASK_NEST_VALUE;
> > -	}
> >  }
> >  
> >  /**
> > @@ -892,19 +888,18 @@ void rcu_user_enter(void)
> >   */
> >  void rcu_irq_exit(void)
> >  {
> > -	long long oldval;
> >  	struct rcu_dynticks *rdtp;
> >  
> >  	RCU_LOCKDEP_WARN(!irqs_disabled(), "rcu_irq_exit() invoked with irqs enabled!!!");
> >  	rdtp = this_cpu_ptr(&rcu_dynticks);
> > -	oldval = rdtp->dynticks_nesting;
> > -	rdtp->dynticks_nesting--;
> >  	WARN_ON_ONCE(IS_ENABLED(CONFIG_RCU_EQS_DEBUG) &&
> > -		     rdtp->dynticks_nesting < 0);
> > -	if (rdtp->dynticks_nesting)
> > -		trace_rcu_dyntick(TPS("--="), oldval, rdtp->dynticks_nesting);
> > -	else
> > -		rcu_eqs_enter_common(oldval, true);
> > +		     rdtp->dynticks_nesting < 1);
> > +	if (rdtp->dynticks_nesting <= 1) {
> > +		rcu_eqs_enter_common(true);
> > +	} else {
> > +		trace_rcu_dyntick(TPS("--="), rdtp->dynticks_nesting, rdtp->dynticks_nesting - 1);
> > +		rdtp->dynticks_nesting--;
> > +	}
> >  	rcu_sysidle_enter(1);
> >  }
> >  
> 

  reply index

Thread overview: 16+ messages / expand[flat|nested]  mbox.gz  Atom feed  top
2017-04-05 13:32 Steven Rostedt
2017-04-05 16:25 ` Paul E. McKenney
2017-04-05 16:45   ` Steven Rostedt
2017-04-05 17:59     ` Paul E. McKenney
2017-04-05 18:54       ` Steven Rostedt
2017-04-05 19:08         ` Paul E. McKenney
2017-04-05 19:21           ` Steven Rostedt
2017-04-05 19:39             ` Paul E. McKenney
2017-04-05 19:52               ` Steven Rostedt
2017-04-05 20:42                 ` Paul E. McKenney [this message]
2017-04-06  1:31                   ` Steven Rostedt
2017-04-06  4:07                     ` Paul E. McKenney
2017-04-06  2:12       ` Steven Rostedt
2017-04-06  4:15         ` Paul E. McKenney
2017-04-06 14:14           ` Steven Rostedt
2017-04-06 14:59             ` Paul E. McKenney

Reply instructions:

You may reply publicly to this message via plain-text email
using any one of the following methods:

* Save the following mbox file, import it into your mail client,
  and reply-to-all from there: mbox

  Avoid top-posting and favor interleaved quoting:
  https://en.wikipedia.org/wiki/Posting_style#Interleaved_style

* Reply using the --to, --cc, and --in-reply-to
  switches of git-send-email(1):

  git send-email \
    --in-reply-to=20170405204229.GQ1600@linux.vnet.ibm.com \
    --to=paulmck@linux.vnet.ibm.com \
    --cc=linux-kernel@vger.kernel.org \
    --cc=rostedt@goodmis.org \
    /path/to/YOUR_REPLY

  https://kernel.org/pub/software/scm/git/docs/git-send-email.html

* If your mail client supports setting the In-Reply-To header
  via mailto: links, try the mailto: link

LKML Archive on lore.kernel.org

Archives are clonable:
	git clone --mirror https://lore.kernel.org/lkml/0 lkml/git/0.git
	git clone --mirror https://lore.kernel.org/lkml/1 lkml/git/1.git
	git clone --mirror https://lore.kernel.org/lkml/2 lkml/git/2.git
	git clone --mirror https://lore.kernel.org/lkml/3 lkml/git/3.git
	git clone --mirror https://lore.kernel.org/lkml/4 lkml/git/4.git
	git clone --mirror https://lore.kernel.org/lkml/5 lkml/git/5.git
	git clone --mirror https://lore.kernel.org/lkml/6 lkml/git/6.git
	git clone --mirror https://lore.kernel.org/lkml/7 lkml/git/7.git
	git clone --mirror https://lore.kernel.org/lkml/8 lkml/git/8.git

	# If you have public-inbox 1.1+ installed, you may
	# initialize and index your mirror using the following commands:
	public-inbox-init -V2 lkml lkml/ https://lore.kernel.org/lkml \
		linux-kernel@vger.kernel.org
	public-inbox-index lkml

Example config snippet for mirrors

Newsgroup available over NNTP:
	nntp://nntp.lore.kernel.org/org.kernel.vger.linux-kernel


AGPL code for this site: git clone https://public-inbox.org/public-inbox.git