Groups | Search | Server Info | Keyboard shortcuts | Login | Register [http] [https] [nntp] [nntps]

Groups > linux.kernel > #1360929 > unrolled thread

Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17

Back to article view | Back to linux.kernel

This discussion starts older than the indexed window; earlier articles aren't shown. The article labeled Started by below is the oldest one visible, not the original post.

Contents

  Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Josh Triplett <josh@joshtriplett.org> - 2016-03-18 22:10 +0100
    Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-19 01:00 +0100
      Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Jacob Pan <jacob.jun.pan@linux.intel.com> - 2016-03-21 17:30 +0100
        Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-21 18:30 +0100
          Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-22 18:50 +0100
            RE: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Chatre, Reinette" <reinette.chatre@intel.com> - 2016-03-22 22:10 +0100
              Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-22 22:20 +0100
                RE: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Chatre, Reinette" <reinette.chatre@intel.com> - 2016-03-23 18:20 +0100
                  RE: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Chatre, Reinette" <reinette.chatre@intel.com> - 2016-03-23 19:30 +0100
                    Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-23 21:00 +0100
                  Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-23 19:30 +0100
                    Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-25 22:50 +0100
                      Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Mathieu Desnoyers <mathieu.desnoyers@efficios.com> - 2016-03-26 13:30 +0100
                        Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-26 16:30 +0100
                          Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-26 19:50 +0100
                            Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Mathieu Desnoyers <mathieu.desnoyers@efficios.com> - 2016-03-26 23:30 +0100
                              Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-27 03:40 +0200
                                Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Mathieu Desnoyers <mathieu.desnoyers@efficios.com> - 2016-03-27 15:50 +0200
                                  Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-27 17:50 +0200
                                    Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-27 22:10 +0200
                                    Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Peter Zijlstra <peterz@infradead.org> - 2016-03-27 22:50 +0200
                                      Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-27 23:10 +0200
                                        Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Peter Zijlstra <peterz@infradead.org> - 2016-03-28 08:30 +0200
                                          Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-28 15:10 +0200
                                            Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-29 02:30 +0200
                                              Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-29 15:50 +0200
                                                Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-30 17:00 +0200
                                                  Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-31 17:50 +0200
                                            Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-29 02:30 +0200
                                      Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Mathieu Desnoyers <mathieu.desnoyers@efficios.com> - 2016-03-28 03:50 +0200
                                        Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Mathieu Desnoyers <mathieu.desnoyers@efficios.com> - 2016-03-28 04:30 +0200
                                          Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Peter Zijlstra <peterz@infradead.org> - 2016-03-28 08:20 +0200
                                            Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-28 16:00 +0200
                                            Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Mathieu Desnoyers <mathieu.desnoyers@efficios.com> - 2016-03-28 16:20 +0200
                                    Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Peter Zijlstra <peterz@infradead.org> - 2016-03-27 23:00 +0200
                                      Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-27 23:10 +0200
        Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Peter Zijlstra <peterz@infradead.org> - 2016-03-27 23:00 +0200
          Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-27 23:10 +0200
            Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Peter Zijlstra <peterz@infradead.org> - 2016-03-28 08:40 +0200
              Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-28 15:30 +0200
                Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Mathieu Desnoyers <mathieu.desnoyers@efficios.com> - 2016-03-28 17:10 +0200
                  Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-28 18:10 +0200
                    Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 Mathieu Desnoyers <mathieu.desnoyers@efficios.com> - 2016-03-28 18:20 +0200
                      Re: rcu_preempt self-detected stall on CPU from 4.5-rc3, since 3.17 "Paul E. McKenney" <paulmck@linux.vnet.ibm.com> - 2016-03-28 18:40 +0200

Page 2 of 3 — ← Prev page 1 [2] 3  Next page →

#1365184

On Sun, Mar 27, 2016 at 08:40:18AM -0700, Paul E. McKenney wrote:
> Oh, and the patch I am running with is below.  I am running x86, and so
> some other architectures would of course need the corresponding patch
> on that architecture.

> -#define TIF_POLLING_NRFLAG	21	/* idle is polling for TIF_NEED_RESCHED */
> +/* #define TIF_POLLING_NRFLAG	21	 idle is polling for TIF_NEED_RESCHED */

x86 is the only arch that really uses this heavily IIRC.

Most of the other archs need interrupts to wake up remote cores.

So what we try to do is avoid sending IPIs when the CPU is idle, for the
remote wakeup case we use set_nr_if_polling() which sets
TIF_NEED_RESCHED if TIF_POLLING_NRFLAG was set. If it wasn't, we'll send
the IPI. Otherwise we rely on the idle loop to do sched_ttwu_pending()
when it breaks out of loop due to TIF_NEED_RESCHED.

But, you need hotplug for this to happen, right?

We should not be migrating towards, or waking on, CPUs no longer present
in cpu_active_map, and there is a rcu/sched_sync() after clearing that
bit. Furthermore, migration_call() does a sched_ttwu_pending() (waking
any remaining stragglers) before we migrate all runnable tasks off the
dying CPU.



The other interesting case would be resched_cpu(), which uses
set_nr_and_not_polling() to kick a remote cpu to call schedule(). It
atomically sets TIF_NEED_RESCHED and returns if TIF_POLLING_NRFLAG was
not set. If indeed not, it will send an IPI.

This assumes the idle 'exit' path will do the same as the IPI does; and
if you look at cpu_idle_loop() it does indeed do both
preempt_fold_need_resched() and sched_ttwu_pending().

Note that one cannot rely on irq_enter()/irq_exit() being called for the
scheduler IPI.

[toc] | [prev] | [next] | [standalone]

#1365189

On Sun, Mar 27, 2016 at 10:45:59PM +0200, Peter Zijlstra wrote:
> On Sun, Mar 27, 2016 at 08:40:18AM -0700, Paul E. McKenney wrote:
> > Oh, and the patch I am running with is below.  I am running x86, and so
> > some other architectures would of course need the corresponding patch
> > on that architecture.
> 
> > -#define TIF_POLLING_NRFLAG	21	/* idle is polling for TIF_NEED_RESCHED */
> > +/* #define TIF_POLLING_NRFLAG	21	 idle is polling for TIF_NEED_RESCHED */
> 
> x86 is the only arch that really uses this heavily IIRC.
> 
> Most of the other archs need interrupts to wake up remote cores.
> 
> So what we try to do is avoid sending IPIs when the CPU is idle, for the
> remote wakeup case we use set_nr_if_polling() which sets
> TIF_NEED_RESCHED if TIF_POLLING_NRFLAG was set. If it wasn't, we'll send
> the IPI. Otherwise we rely on the idle loop to do sched_ttwu_pending()
> when it breaks out of loop due to TIF_NEED_RESCHED.
> 
> But, you need hotplug for this to happen, right?

I do, but Ross Green is seeing something that looks similar, and without
CPU hotplug.

> We should not be migrating towards, or waking on, CPUs no longer present
> in cpu_active_map, and there is a rcu/sched_sync() after clearing that
> bit. Furthermore, migration_call() does a sched_ttwu_pending() (waking
> any remaining stragglers) before we migrate all runnable tasks off the
> dying CPU.

OK, so I should instrument migration_call() if I get the repro rate up?

> The other interesting case would be resched_cpu(), which uses
> set_nr_and_not_polling() to kick a remote cpu to call schedule(). It
> atomically sets TIF_NEED_RESCHED and returns if TIF_POLLING_NRFLAG was
> not set. If indeed not, it will send an IPI.
> 
> This assumes the idle 'exit' path will do the same as the IPI does; and
> if you look at cpu_idle_loop() it does indeed do both
> preempt_fold_need_resched() and sched_ttwu_pending().
> 
> Note that one cannot rely on irq_enter()/irq_exit() being called for the
> scheduler IPI.

OK, thank you for the info!  Any specific debug actions?

							Thanx, Paul

[toc] | [prev] | [next] | [standalone]

#1365347

On Sun, Mar 27, 2016 at 02:06:41PM -0700, Paul E. McKenney wrote:

> > But, you need hotplug for this to happen, right?
> 
> I do, but Ross Green is seeing something that looks similar, and without
> CPU hotplug.

Yes, but that's two differences so far, you need hotplug and he's on ARM
(which doesn't have TIF_POLLING_NR).

So either we're all looking at the wrong thing or these really are two
different issues.

> > We should not be migrating towards, or waking on, CPUs no longer present
> > in cpu_active_map, and there is a rcu/sched_sync() after clearing that
> > bit. Furthermore, migration_call() does a sched_ttwu_pending() (waking
> > any remaining stragglers) before we migrate all runnable tasks off the
> > dying CPU.
> 
> OK, so I should instrument migration_call() if I get the repro rate up?

Can do, maybe try the below first. (yes I know how long it all takes :/)

> > The other interesting case would be resched_cpu(), which uses
> > set_nr_and_not_polling() to kick a remote cpu to call schedule(). It
> > atomically sets TIF_NEED_RESCHED and returns if TIF_POLLING_NRFLAG was
> > not set. If indeed not, it will send an IPI.
> > 
> > This assumes the idle 'exit' path will do the same as the IPI does; and
> > if you look at cpu_idle_loop() it does indeed do both
> > preempt_fold_need_resched() and sched_ttwu_pending().
> > 
> > Note that one cannot rely on irq_enter()/irq_exit() being called for the
> > scheduler IPI.
> 
> OK, thank you for the info!  Any specific debug actions?

Dunno, something like the below should bring visibility into the
(lockless) wake_list thingy.

So these trace_printk()s should happen between trace_sched_waking() and
trace_sched_wakeup() (I've not fully read the thread, but ISTR you had
some traces with these here thingies on).

---
 arch/x86/include/asm/bitops.h | 6 ++++--
 kernel/sched/core.c           | 9 +++++++++
 2 files changed, 13 insertions(+), 2 deletions(-)

diff --git a/arch/x86/include/asm/bitops.h b/arch/x86/include/asm/bitops.h
index 7766d1cf096e..5345784d5e41 100644
--- a/arch/x86/include/asm/bitops.h
+++ b/arch/x86/include/asm/bitops.h
@@ -112,11 +112,13 @@ clear_bit(long nr, volatile unsigned long *addr)
 	if (IS_IMMEDIATE(nr)) {
 		asm volatile(LOCK_PREFIX "andb %1,%0"
 			: CONST_MASK_ADDR(nr, addr)
-			: "iq" ((u8)~CONST_MASK(nr)));
+			: "iq" ((u8)~CONST_MASK(nr))
+			: "memory");
 	} else {
 		asm volatile(LOCK_PREFIX "btr %1,%0"
 			: BITOP_ADDR(addr)
-			: "Ir" (nr));
+			: "Ir" (nr)
+			: "memory");
 	}
 }
 
diff --git a/kernel/sched/core.c b/kernel/sched/core.c
index 0b21e7a724e1..b446f73c530d 100644
--- a/kernel/sched/core.c
+++ b/kernel/sched/core.c
@@ -1669,6 +1669,7 @@ void sched_ttwu_pending(void)
 	while (llist) {
 		p = llist_entry(llist, struct task_struct, wake_entry);
 		llist = llist_next(llist);
+		trace_printk("waking %d\n", p->pid);
 		ttwu_do_activate(rq, p, 0);
 	}
 
@@ -1719,6 +1720,7 @@ static void ttwu_queue_remote(struct task_struct *p, int cpu)
 	struct rq *rq = cpu_rq(cpu);
 
 	if (llist_add(&p->wake_entry, &cpu_rq(cpu)->wake_list)) {
+		trace_printk("queued %d for waking on %d\n", p->pid, cpu);
 		if (!set_nr_if_polling(rq->idle))
 			smp_send_reschedule(cpu);
 		else
@@ -5397,10 +5399,17 @@ migration_call(struct notifier_block *nfb, unsigned long action, void *hcpu)
 		migrate_tasks(rq);
 		BUG_ON(rq->nr_running != 1); /* the migration thread */
 		raw_spin_unlock_irqrestore(&rq->lock, flags);
+
+		/* really bad m'kay */
+		WARN_ON(!llist_empty(&rq->wake_list));
+
 		break;
 
 	case CPU_DEAD:
 		calc_load_migrate(rq);
+
+		/* more bad */
+		WARN_ON(!llist_empty(&rq->wake_list));
 		break;
 #endif
 	}

[toc] | [prev] | [next] | [standalone]

#1365478

On Mon, Mar 28, 2016 at 08:25:47AM +0200, Peter Zijlstra wrote:
> On Sun, Mar 27, 2016 at 02:06:41PM -0700, Paul E. McKenney wrote:
> 
> > > But, you need hotplug for this to happen, right?
> > 
> > I do, but Ross Green is seeing something that looks similar, and without
> > CPU hotplug.
> 
> Yes, but that's two differences so far, you need hotplug and he's on ARM
> (which doesn't have TIF_POLLING_NR).
> 
> So either we're all looking at the wrong thing or these really are two
> different issues.

Given that this failure has grown more probable over the past several
releases, it does seem quite likely that we have more than one bug.
Or maybe a few bugs and additional innocent-bystander commits that make
one or more of the bugs more probable.

> > > We should not be migrating towards, or waking on, CPUs no longer present
> > > in cpu_active_map, and there is a rcu/sched_sync() after clearing that
> > > bit. Furthermore, migration_call() does a sched_ttwu_pending() (waking
> > > any remaining stragglers) before we migrate all runnable tasks off the
> > > dying CPU.
> > 
> > OK, so I should instrument migration_call() if I get the repro rate up?
> 
> Can do, maybe try the below first. (yes I know how long it all takes :/)

OK, will run this today, then run calibration for last night's run this
evening.

Speaking of which, last night's run (disabling TIF_POLLING_NRFLAG)
consisted of 24 two-hour runs.  Six of them had hard hangs, and another
had a hang that eventually unhung of its own accord.  I believe that this
is significantly fewer failures than from a stock kernel, but I could
be wrong, and it will take some serious testing to give statistical
confidence for whatever conclusion is correct.

> > > The other interesting case would be resched_cpu(), which uses
> > > set_nr_and_not_polling() to kick a remote cpu to call schedule(). It
> > > atomically sets TIF_NEED_RESCHED and returns if TIF_POLLING_NRFLAG was
> > > not set. If indeed not, it will send an IPI.
> > > 
> > > This assumes the idle 'exit' path will do the same as the IPI does; and
> > > if you look at cpu_idle_loop() it does indeed do both
> > > preempt_fold_need_resched() and sched_ttwu_pending().
> > > 
> > > Note that one cannot rely on irq_enter()/irq_exit() being called for the
> > > scheduler IPI.
> > 
> > OK, thank you for the info!  Any specific debug actions?
> 
> Dunno, something like the below should bring visibility into the
> (lockless) wake_list thingy.
> 
> So these trace_printk()s should happen between trace_sched_waking() and
> trace_sched_wakeup() (I've not fully read the thread, but ISTR you had
> some traces with these here thingies on).
> 
> ---
>  arch/x86/include/asm/bitops.h | 6 ++++--
>  kernel/sched/core.c           | 9 +++++++++
>  2 files changed, 13 insertions(+), 2 deletions(-)
> 
> diff --git a/arch/x86/include/asm/bitops.h b/arch/x86/include/asm/bitops.h
> index 7766d1cf096e..5345784d5e41 100644
> --- a/arch/x86/include/asm/bitops.h
> +++ b/arch/x86/include/asm/bitops.h
> @@ -112,11 +112,13 @@ clear_bit(long nr, volatile unsigned long *addr)
>  	if (IS_IMMEDIATE(nr)) {
>  		asm volatile(LOCK_PREFIX "andb %1,%0"
>  			: CONST_MASK_ADDR(nr, addr)
> -			: "iq" ((u8)~CONST_MASK(nr)));
> +			: "iq" ((u8)~CONST_MASK(nr))
> +			: "memory");
>  	} else {
>  		asm volatile(LOCK_PREFIX "btr %1,%0"
>  			: BITOP_ADDR(addr)
> -			: "Ir" (nr));
> +			: "Ir" (nr)
> +			: "memory");
>  	}
>  }

Is the above addition of "memory" strictly for the debug below, or is
it also a potential fix?

Starting it up regardless, but figured I should ask!

							Thanx, Paul

> diff --git a/kernel/sched/core.c b/kernel/sched/core.c
> index 0b21e7a724e1..b446f73c530d 100644
> --- a/kernel/sched/core.c
> +++ b/kernel/sched/core.c
> @@ -1669,6 +1669,7 @@ void sched_ttwu_pending(void)
>  	while (llist) {
>  		p = llist_entry(llist, struct task_struct, wake_entry);
>  		llist = llist_next(llist);
> +		trace_printk("waking %d\n", p->pid);
>  		ttwu_do_activate(rq, p, 0);
>  	}
> 
> @@ -1719,6 +1720,7 @@ static void ttwu_queue_remote(struct task_struct *p, int cpu)
>  	struct rq *rq = cpu_rq(cpu);
> 
>  	if (llist_add(&p->wake_entry, &cpu_rq(cpu)->wake_list)) {
> +		trace_printk("queued %d for waking on %d\n", p->pid, cpu);
>  		if (!set_nr_if_polling(rq->idle))
>  			smp_send_reschedule(cpu);
>  		else
> @@ -5397,10 +5399,17 @@ migration_call(struct notifier_block *nfb, unsigned long action, void *hcpu)
>  		migrate_tasks(rq);
>  		BUG_ON(rq->nr_running != 1); /* the migration thread */
>  		raw_spin_unlock_irqrestore(&rq->lock, flags);
> +
> +		/* really bad m'kay */
> +		WARN_ON(!llist_empty(&rq->wake_list));
> +
>  		break;
> 
>  	case CPU_DEAD:
>  		calc_load_migrate(rq);
> +
> +		/* more bad */
> +		WARN_ON(!llist_empty(&rq->wake_list));
>  		break;
>  #endif
>  	}
> 

[toc] | [prev] | [next] | [standalone]

#1365728

On Mon, Mar 28, 2016 at 05:25:18PM -0700, Paul E. McKenney wrote:
> On Mon, Mar 28, 2016 at 06:08:41AM -0700, Paul E. McKenney wrote:
> > On Mon, Mar 28, 2016 at 08:25:47AM +0200, Peter Zijlstra wrote:
> > > On Sun, Mar 27, 2016 at 02:06:41PM -0700, Paul E. McKenney wrote:
> 
> [ . . . ]
> 
> > > > OK, so I should instrument migration_call() if I get the repro rate up?
> > > 
> > > Can do, maybe try the below first. (yes I know how long it all takes :/)
> > 
> > OK, will run this today, then run calibration for last night's run this
> > evening.
> 
> And there was one failure out of ten runs.  If last night's failure rate
> was typical (7 of 24), then I believe we can be about 87% confident that
> this change helped.  That isn't all that confident, but...

And, as Murphy would have it, the instrumentation didn't trigger.  I just
got the usual stall-warning messages with a starving RCU grace-period
kthread.

							Thanx, Paul

> Tested-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> 
> So what to run tonight?
> 
> The most sane approach would be to run stock in order to get a baseline
> failure rate.  It is tempting to run more of Peter's patch, but part of
> the problem is that we don't know the current baseline.
> 
> So baseline it is...
> 
> 							Thanx, Paul
> 
> > Speaking of which, last night's run (disabling TIF_POLLING_NRFLAG)
> > consisted of 24 two-hour runs.  Six of them had hard hangs, and another
> > had a hang that eventually unhung of its own accord.  I believe that this
> > is significantly fewer failures than from a stock kernel, but I could
> > be wrong, and it will take some serious testing to give statistical
> > confidence for whatever conclusion is correct.
> > 
> > > > > The other interesting case would be resched_cpu(), which uses
> > > > > set_nr_and_not_polling() to kick a remote cpu to call schedule(). It
> > > > > atomically sets TIF_NEED_RESCHED and returns if TIF_POLLING_NRFLAG was
> > > > > not set. If indeed not, it will send an IPI.
> > > > > 
> > > > > This assumes the idle 'exit' path will do the same as the IPI does; and
> > > > > if you look at cpu_idle_loop() it does indeed do both
> > > > > preempt_fold_need_resched() and sched_ttwu_pending().
> > > > > 
> > > > > Note that one cannot rely on irq_enter()/irq_exit() being called for the
> > > > > scheduler IPI.
> > > > 
> > > > OK, thank you for the info!  Any specific debug actions?
> > > 
> > > Dunno, something like the below should bring visibility into the
> > > (lockless) wake_list thingy.
> > > 
> > > So these trace_printk()s should happen between trace_sched_waking() and
> > > trace_sched_wakeup() (I've not fully read the thread, but ISTR you had
> > > some traces with these here thingies on).
> > > 
> > > ---
> > >  arch/x86/include/asm/bitops.h | 6 ++++--
> > >  kernel/sched/core.c           | 9 +++++++++
> > >  2 files changed, 13 insertions(+), 2 deletions(-)
> > > 
> > > diff --git a/arch/x86/include/asm/bitops.h b/arch/x86/include/asm/bitops.h
> > > index 7766d1cf096e..5345784d5e41 100644
> > > --- a/arch/x86/include/asm/bitops.h
> > > +++ b/arch/x86/include/asm/bitops.h
> > > @@ -112,11 +112,13 @@ clear_bit(long nr, volatile unsigned long *addr)
> > >  	if (IS_IMMEDIATE(nr)) {
> > >  		asm volatile(LOCK_PREFIX "andb %1,%0"
> > >  			: CONST_MASK_ADDR(nr, addr)
> > > -			: "iq" ((u8)~CONST_MASK(nr)));
> > > +			: "iq" ((u8)~CONST_MASK(nr))
> > > +			: "memory");
> > >  	} else {
> > >  		asm volatile(LOCK_PREFIX "btr %1,%0"
> > >  			: BITOP_ADDR(addr)
> > > -			: "Ir" (nr));
> > > +			: "Ir" (nr)
> > > +			: "memory");
> > >  	}
> > >  }
> > 
> > Is the above addition of "memory" strictly for the debug below, or is
> > it also a potential fix?
> > 
> > Starting it up regardless, but figured I should ask!
> > 
> > 							Thanx, Paul
> > 
> > > diff --git a/kernel/sched/core.c b/kernel/sched/core.c
> > > index 0b21e7a724e1..b446f73c530d 100644
> > > --- a/kernel/sched/core.c
> > > +++ b/kernel/sched/core.c
> > > @@ -1669,6 +1669,7 @@ void sched_ttwu_pending(void)
> > >  	while (llist) {
> > >  		p = llist_entry(llist, struct task_struct, wake_entry);
> > >  		llist = llist_next(llist);
> > > +		trace_printk("waking %d\n", p->pid);
> > >  		ttwu_do_activate(rq, p, 0);
> > >  	}
> > > 
> > > @@ -1719,6 +1720,7 @@ static void ttwu_queue_remote(struct task_struct *p, int cpu)
> > >  	struct rq *rq = cpu_rq(cpu);
> > > 
> > >  	if (llist_add(&p->wake_entry, &cpu_rq(cpu)->wake_list)) {
> > > +		trace_printk("queued %d for waking on %d\n", p->pid, cpu);
> > >  		if (!set_nr_if_polling(rq->idle))
> > >  			smp_send_reschedule(cpu);
> > >  		else
> > > @@ -5397,10 +5399,17 @@ migration_call(struct notifier_block *nfb, unsigned long action, void *hcpu)
> > >  		migrate_tasks(rq);
> > >  		BUG_ON(rq->nr_running != 1); /* the migration thread */
> > >  		raw_spin_unlock_irqrestore(&rq->lock, flags);
> > > +
> > > +		/* really bad m'kay */
> > > +		WARN_ON(!llist_empty(&rq->wake_list));
> > > +
> > >  		break;
> > > 
> > >  	case CPU_DEAD:
> > >  		calc_load_migrate(rq);
> > > +
> > > +		/* more bad */
> > > +		WARN_ON(!llist_empty(&rq->wake_list));
> > >  		break;
> > >  #endif
> > >  	}
> > > 

[toc] | [prev] | [next] | [standalone]

#1366301

On Mon, Mar 28, 2016 at 05:28:14PM -0700, Paul E. McKenney wrote:
> On Mon, Mar 28, 2016 at 05:25:18PM -0700, Paul E. McKenney wrote:
> > On Mon, Mar 28, 2016 at 06:08:41AM -0700, Paul E. McKenney wrote:
> > > On Mon, Mar 28, 2016 at 08:25:47AM +0200, Peter Zijlstra wrote:
> > > > On Sun, Mar 27, 2016 at 02:06:41PM -0700, Paul E. McKenney wrote:
> > 
> > [ . . . ]
> > 
> > > > > OK, so I should instrument migration_call() if I get the repro rate up?
> > > > 
> > > > Can do, maybe try the below first. (yes I know how long it all takes :/)
> > > 
> > > OK, will run this today, then run calibration for last night's run this
> > > evening.

And of 18 two-hour runs, there were five failures, or about 28%.
That said, I don't have even one significant digit on the failure rate,
as 5 of 18 is within the 95% confidence limits for a failure probability
as low as 12.5% and as high as 47%.

However, the previous night's runs gave 7 failures in 24 two-hour runs,
for about a 29% failure rate.  There is thus a good probability that my
disabling of TIF_POLLING_NRFLAG had no effect whatsoever, tantalizing
though that possibility might have been.

(FWIW, I use the pdf_binomial() and quantile_binomial() functions in
maxima for computing this stuff.  Similar stuff is no doubt available
in other math/stat packages as well.)

So we have bugs, but not much idea where they are.  Situation normal.

Other thoughts?

							Thanx, Paul

> > And there was one failure out of ten runs.  If last night's failure rate
> > was typical (7 of 24), then I believe we can be about 87% confident that
> > this change helped.  That isn't all that confident, but...
> 
> And, as Murphy would have it, the instrumentation didn't trigger.  I just
> got the usual stall-warning messages with a starving RCU grace-period
> kthread.
> 
> 							Thanx, Paul
> 
> > Tested-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> > 
> > So what to run tonight?
> > 
> > The most sane approach would be to run stock in order to get a baseline
> > failure rate.  It is tempting to run more of Peter's patch, but part of
> > the problem is that we don't know the current baseline.
> > 
> > So baseline it is...
> > 
> > 							Thanx, Paul
> > 
> > > Speaking of which, last night's run (disabling TIF_POLLING_NRFLAG)
> > > consisted of 24 two-hour runs.  Six of them had hard hangs, and another
> > > had a hang that eventually unhung of its own accord.  I believe that this
> > > is significantly fewer failures than from a stock kernel, but I could
> > > be wrong, and it will take some serious testing to give statistical
> > > confidence for whatever conclusion is correct.
> > > 
> > > > > > The other interesting case would be resched_cpu(), which uses
> > > > > > set_nr_and_not_polling() to kick a remote cpu to call schedule(). It
> > > > > > atomically sets TIF_NEED_RESCHED and returns if TIF_POLLING_NRFLAG was
> > > > > > not set. If indeed not, it will send an IPI.
> > > > > > 
> > > > > > This assumes the idle 'exit' path will do the same as the IPI does; and
> > > > > > if you look at cpu_idle_loop() it does indeed do both
> > > > > > preempt_fold_need_resched() and sched_ttwu_pending().
> > > > > > 
> > > > > > Note that one cannot rely on irq_enter()/irq_exit() being called for the
> > > > > > scheduler IPI.
> > > > > 
> > > > > OK, thank you for the info!  Any specific debug actions?
> > > > 
> > > > Dunno, something like the below should bring visibility into the
> > > > (lockless) wake_list thingy.
> > > > 
> > > > So these trace_printk()s should happen between trace_sched_waking() and
> > > > trace_sched_wakeup() (I've not fully read the thread, but ISTR you had
> > > > some traces with these here thingies on).
> > > > 
> > > > ---
> > > >  arch/x86/include/asm/bitops.h | 6 ++++--
> > > >  kernel/sched/core.c           | 9 +++++++++
> > > >  2 files changed, 13 insertions(+), 2 deletions(-)
> > > > 
> > > > diff --git a/arch/x86/include/asm/bitops.h b/arch/x86/include/asm/bitops.h
> > > > index 7766d1cf096e..5345784d5e41 100644
> > > > --- a/arch/x86/include/asm/bitops.h
> > > > +++ b/arch/x86/include/asm/bitops.h
> > > > @@ -112,11 +112,13 @@ clear_bit(long nr, volatile unsigned long *addr)
> > > >  	if (IS_IMMEDIATE(nr)) {
> > > >  		asm volatile(LOCK_PREFIX "andb %1,%0"
> > > >  			: CONST_MASK_ADDR(nr, addr)
> > > > -			: "iq" ((u8)~CONST_MASK(nr)));
> > > > +			: "iq" ((u8)~CONST_MASK(nr))
> > > > +			: "memory");
> > > >  	} else {
> > > >  		asm volatile(LOCK_PREFIX "btr %1,%0"
> > > >  			: BITOP_ADDR(addr)
> > > > -			: "Ir" (nr));
> > > > +			: "Ir" (nr)
> > > > +			: "memory");
> > > >  	}
> > > >  }
> > > 
> > > Is the above addition of "memory" strictly for the debug below, or is
> > > it also a potential fix?
> > > 
> > > Starting it up regardless, but figured I should ask!
> > > 
> > > 							Thanx, Paul
> > > 
> > > > diff --git a/kernel/sched/core.c b/kernel/sched/core.c
> > > > index 0b21e7a724e1..b446f73c530d 100644
> > > > --- a/kernel/sched/core.c
> > > > +++ b/kernel/sched/core.c
> > > > @@ -1669,6 +1669,7 @@ void sched_ttwu_pending(void)
> > > >  	while (llist) {
> > > >  		p = llist_entry(llist, struct task_struct, wake_entry);
> > > >  		llist = llist_next(llist);
> > > > +		trace_printk("waking %d\n", p->pid);
> > > >  		ttwu_do_activate(rq, p, 0);
> > > >  	}
> > > > 
> > > > @@ -1719,6 +1720,7 @@ static void ttwu_queue_remote(struct task_struct *p, int cpu)
> > > >  	struct rq *rq = cpu_rq(cpu);
> > > > 
> > > >  	if (llist_add(&p->wake_entry, &cpu_rq(cpu)->wake_list)) {
> > > > +		trace_printk("queued %d for waking on %d\n", p->pid, cpu);
> > > >  		if (!set_nr_if_polling(rq->idle))
> > > >  			smp_send_reschedule(cpu);
> > > >  		else
> > > > @@ -5397,10 +5399,17 @@ migration_call(struct notifier_block *nfb, unsigned long action, void *hcpu)
> > > >  		migrate_tasks(rq);
> > > >  		BUG_ON(rq->nr_running != 1); /* the migration thread */
> > > >  		raw_spin_unlock_irqrestore(&rq->lock, flags);
> > > > +
> > > > +		/* really bad m'kay */
> > > > +		WARN_ON(!llist_empty(&rq->wake_list));
> > > > +
> > > >  		break;
> > > > 
> > > >  	case CPU_DEAD:
> > > >  		calc_load_migrate(rq);
> > > > +
> > > > +		/* more bad */
> > > > +		WARN_ON(!llist_empty(&rq->wake_list));
> > > >  		break;
> > > >  #endif
> > > >  	}
> > > > 

[toc] | [prev] | [next] | [standalone]

#1367264

On Tue, Mar 29, 2016 at 06:49:08AM -0700, Paul E. McKenney wrote:
> On Mon, Mar 28, 2016 at 05:28:14PM -0700, Paul E. McKenney wrote:
> > On Mon, Mar 28, 2016 at 05:25:18PM -0700, Paul E. McKenney wrote:
> > > On Mon, Mar 28, 2016 at 06:08:41AM -0700, Paul E. McKenney wrote:
> > > > On Mon, Mar 28, 2016 at 08:25:47AM +0200, Peter Zijlstra wrote:
> > > > > On Sun, Mar 27, 2016 at 02:06:41PM -0700, Paul E. McKenney wrote:
> > > 
> > > [ . . . ]
> > > 
> > > > > > OK, so I should instrument migration_call() if I get the repro rate up?
> > > > > 
> > > > > Can do, maybe try the below first. (yes I know how long it all takes :/)
> > > > 
> > > > OK, will run this today, then run calibration for last night's run this
> > > > evening.
> 
> And of 18 two-hour runs, there were five failures, or about 28%.
> That said, I don't have even one significant digit on the failure rate,
> as 5 of 18 is within the 95% confidence limits for a failure probability
> as low as 12.5% and as high as 47%.

And after last night's run, this is narrowed down to between 23% and 38%,
which is close enough.  Average is 30%, 18 failures in 60 runs.

Next step is to test Peter's patch some more.  Might take a couple of
night's worth of runs to get statistical significance.  After which
it will be time to rebase to 4.6-rc1.

							Thanx, Paul

> However, the previous night's runs gave 7 failures in 24 two-hour runs,
> for about a 29% failure rate.  There is thus a good probability that my
> disabling of TIF_POLLING_NRFLAG had no effect whatsoever, tantalizing
> though that possibility might have been.
> 
> (FWIW, I use the pdf_binomial() and quantile_binomial() functions in
> maxima for computing this stuff.  Similar stuff is no doubt available
> in other math/stat packages as well.)
> 
> So we have bugs, but not much idea where they are.  Situation normal.
> 
> Other thoughts?
> 
> 							Thanx, Paul
> 
> > > And there was one failure out of ten runs.  If last night's failure rate
> > > was typical (7 of 24), then I believe we can be about 87% confident that
> > > this change helped.  That isn't all that confident, but...
> > 
> > And, as Murphy would have it, the instrumentation didn't trigger.  I just
> > got the usual stall-warning messages with a starving RCU grace-period
> > kthread.
> > 
> > 							Thanx, Paul
> > 
> > > Tested-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> > > 
> > > So what to run tonight?
> > > 
> > > The most sane approach would be to run stock in order to get a baseline
> > > failure rate.  It is tempting to run more of Peter's patch, but part of
> > > the problem is that we don't know the current baseline.
> > > 
> > > So baseline it is...
> > > 
> > > 							Thanx, Paul
> > > 
> > > > Speaking of which, last night's run (disabling TIF_POLLING_NRFLAG)
> > > > consisted of 24 two-hour runs.  Six of them had hard hangs, and another
> > > > had a hang that eventually unhung of its own accord.  I believe that this
> > > > is significantly fewer failures than from a stock kernel, but I could
> > > > be wrong, and it will take some serious testing to give statistical
> > > > confidence for whatever conclusion is correct.
> > > > 
> > > > > > > The other interesting case would be resched_cpu(), which uses
> > > > > > > set_nr_and_not_polling() to kick a remote cpu to call schedule(). It
> > > > > > > atomically sets TIF_NEED_RESCHED and returns if TIF_POLLING_NRFLAG was
> > > > > > > not set. If indeed not, it will send an IPI.
> > > > > > > 
> > > > > > > This assumes the idle 'exit' path will do the same as the IPI does; and
> > > > > > > if you look at cpu_idle_loop() it does indeed do both
> > > > > > > preempt_fold_need_resched() and sched_ttwu_pending().
> > > > > > > 
> > > > > > > Note that one cannot rely on irq_enter()/irq_exit() being called for the
> > > > > > > scheduler IPI.
> > > > > > 
> > > > > > OK, thank you for the info!  Any specific debug actions?
> > > > > 
> > > > > Dunno, something like the below should bring visibility into the
> > > > > (lockless) wake_list thingy.
> > > > > 
> > > > > So these trace_printk()s should happen between trace_sched_waking() and
> > > > > trace_sched_wakeup() (I've not fully read the thread, but ISTR you had
> > > > > some traces with these here thingies on).
> > > > > 
> > > > > ---
> > > > >  arch/x86/include/asm/bitops.h | 6 ++++--
> > > > >  kernel/sched/core.c           | 9 +++++++++
> > > > >  2 files changed, 13 insertions(+), 2 deletions(-)
> > > > > 
> > > > > diff --git a/arch/x86/include/asm/bitops.h b/arch/x86/include/asm/bitops.h
> > > > > index 7766d1cf096e..5345784d5e41 100644
> > > > > --- a/arch/x86/include/asm/bitops.h
> > > > > +++ b/arch/x86/include/asm/bitops.h
> > > > > @@ -112,11 +112,13 @@ clear_bit(long nr, volatile unsigned long *addr)
> > > > >  	if (IS_IMMEDIATE(nr)) {
> > > > >  		asm volatile(LOCK_PREFIX "andb %1,%0"
> > > > >  			: CONST_MASK_ADDR(nr, addr)
> > > > > -			: "iq" ((u8)~CONST_MASK(nr)));
> > > > > +			: "iq" ((u8)~CONST_MASK(nr))
> > > > > +			: "memory");
> > > > >  	} else {
> > > > >  		asm volatile(LOCK_PREFIX "btr %1,%0"
> > > > >  			: BITOP_ADDR(addr)
> > > > > -			: "Ir" (nr));
> > > > > +			: "Ir" (nr)
> > > > > +			: "memory");
> > > > >  	}
> > > > >  }
> > > > 
> > > > Is the above addition of "memory" strictly for the debug below, or is
> > > > it also a potential fix?
> > > > 
> > > > Starting it up regardless, but figured I should ask!
> > > > 
> > > > 							Thanx, Paul
> > > > 
> > > > > diff --git a/kernel/sched/core.c b/kernel/sched/core.c
> > > > > index 0b21e7a724e1..b446f73c530d 100644
> > > > > --- a/kernel/sched/core.c
> > > > > +++ b/kernel/sched/core.c
> > > > > @@ -1669,6 +1669,7 @@ void sched_ttwu_pending(void)
> > > > >  	while (llist) {
> > > > >  		p = llist_entry(llist, struct task_struct, wake_entry);
> > > > >  		llist = llist_next(llist);
> > > > > +		trace_printk("waking %d\n", p->pid);
> > > > >  		ttwu_do_activate(rq, p, 0);
> > > > >  	}
> > > > > 
> > > > > @@ -1719,6 +1720,7 @@ static void ttwu_queue_remote(struct task_struct *p, int cpu)
> > > > >  	struct rq *rq = cpu_rq(cpu);
> > > > > 
> > > > >  	if (llist_add(&p->wake_entry, &cpu_rq(cpu)->wake_list)) {
> > > > > +		trace_printk("queued %d for waking on %d\n", p->pid, cpu);
> > > > >  		if (!set_nr_if_polling(rq->idle))
> > > > >  			smp_send_reschedule(cpu);
> > > > >  		else
> > > > > @@ -5397,10 +5399,17 @@ migration_call(struct notifier_block *nfb, unsigned long action, void *hcpu)
> > > > >  		migrate_tasks(rq);
> > > > >  		BUG_ON(rq->nr_running != 1); /* the migration thread */
> > > > >  		raw_spin_unlock_irqrestore(&rq->lock, flags);
> > > > > +
> > > > > +		/* really bad m'kay */
> > > > > +		WARN_ON(!llist_empty(&rq->wake_list));
> > > > > +
> > > > >  		break;
> > > > > 
> > > > >  	case CPU_DEAD:
> > > > >  		calc_load_migrate(rq);
> > > > > +
> > > > > +		/* more bad */
> > > > > +		WARN_ON(!llist_empty(&rq->wake_list));
> > > > >  		break;
> > > > >  #endif
> > > > >  	}
> > > > > 

[toc] | [prev] | [next] | [standalone]

#1368411

On Wed, Mar 30, 2016 at 07:55:47AM -0700, Paul E. McKenney wrote:
> On Tue, Mar 29, 2016 at 06:49:08AM -0700, Paul E. McKenney wrote:
> > On Mon, Mar 28, 2016 at 05:28:14PM -0700, Paul E. McKenney wrote:
> > > On Mon, Mar 28, 2016 at 05:25:18PM -0700, Paul E. McKenney wrote:
> > > > On Mon, Mar 28, 2016 at 06:08:41AM -0700, Paul E. McKenney wrote:
> > > > > On Mon, Mar 28, 2016 at 08:25:47AM +0200, Peter Zijlstra wrote:
> > > > > > On Sun, Mar 27, 2016 at 02:06:41PM -0700, Paul E. McKenney wrote:
> > > > 
> > > > [ . . . ]
> > > > 
> > > > > > > OK, so I should instrument migration_call() if I get the repro rate up?
> > > > > > 
> > > > > > Can do, maybe try the below first. (yes I know how long it all takes :/)
> > > > > 
> > > > > OK, will run this today, then run calibration for last night's run this
> > > > > evening.
> > 
> > And of 18 two-hour runs, there were five failures, or about 28%.
> > That said, I don't have even one significant digit on the failure rate,
> > as 5 of 18 is within the 95% confidence limits for a failure probability
> > as low as 12.5% and as high as 47%.
> 
> And after last night's run, this is narrowed down to between 23% and 38%,
> which is close enough.  Average is 30%, 18 failures in 60 runs.
> 
> Next step is to test Peter's patch some more.  Might take a couple of
> night's worth of runs to get statistical significance.  After which
> it will be time to rebase to 4.6-rc1.

And the first night was not so good: 6 failures out of 24 runs.  Adding
this to the 1-of-10 earlier gets 7 failures of 34.  Here are how things
stack up given the range of base failure estimates:

Low 95% bound of 23%:		84% confidence.

Actual measurement of 30%:	92% confidence.

High 95% bound of 38%:		98% confidence.

So there is still some chance that Peter's patch is helping.  I will
run for one more evening, after which it will be time to move forward
to 4.6-rc1.

							Thanx, Paul

> > However, the previous night's runs gave 7 failures in 24 two-hour runs,
> > for about a 29% failure rate.  There is thus a good probability that my
> > disabling of TIF_POLLING_NRFLAG had no effect whatsoever, tantalizing
> > though that possibility might have been.
> > 
> > (FWIW, I use the pdf_binomial() and quantile_binomial() functions in
> > maxima for computing this stuff.  Similar stuff is no doubt available
> > in other math/stat packages as well.)
> > 
> > So we have bugs, but not much idea where they are.  Situation normal.
> > 
> > Other thoughts?
> > 
> > 							Thanx, Paul
> > 
> > > > And there was one failure out of ten runs.  If last night's failure rate
> > > > was typical (7 of 24), then I believe we can be about 87% confident that
> > > > this change helped.  That isn't all that confident, but...
> > > 
> > > And, as Murphy would have it, the instrumentation didn't trigger.  I just
> > > got the usual stall-warning messages with a starving RCU grace-period
> > > kthread.
> > > 
> > > 							Thanx, Paul
> > > 
> > > > Tested-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> > > > 
> > > > So what to run tonight?
> > > > 
> > > > The most sane approach would be to run stock in order to get a baseline
> > > > failure rate.  It is tempting to run more of Peter's patch, but part of
> > > > the problem is that we don't know the current baseline.
> > > > 
> > > > So baseline it is...
> > > > 
> > > > 							Thanx, Paul
> > > > 
> > > > > Speaking of which, last night's run (disabling TIF_POLLING_NRFLAG)
> > > > > consisted of 24 two-hour runs.  Six of them had hard hangs, and another
> > > > > had a hang that eventually unhung of its own accord.  I believe that this
> > > > > is significantly fewer failures than from a stock kernel, but I could
> > > > > be wrong, and it will take some serious testing to give statistical
> > > > > confidence for whatever conclusion is correct.
> > > > > 
> > > > > > > > The other interesting case would be resched_cpu(), which uses
> > > > > > > > set_nr_and_not_polling() to kick a remote cpu to call schedule(). It
> > > > > > > > atomically sets TIF_NEED_RESCHED and returns if TIF_POLLING_NRFLAG was
> > > > > > > > not set. If indeed not, it will send an IPI.
> > > > > > > > 
> > > > > > > > This assumes the idle 'exit' path will do the same as the IPI does; and
> > > > > > > > if you look at cpu_idle_loop() it does indeed do both
> > > > > > > > preempt_fold_need_resched() and sched_ttwu_pending().
> > > > > > > > 
> > > > > > > > Note that one cannot rely on irq_enter()/irq_exit() being called for the
> > > > > > > > scheduler IPI.
> > > > > > > 
> > > > > > > OK, thank you for the info!  Any specific debug actions?
> > > > > > 
> > > > > > Dunno, something like the below should bring visibility into the
> > > > > > (lockless) wake_list thingy.
> > > > > > 
> > > > > > So these trace_printk()s should happen between trace_sched_waking() and
> > > > > > trace_sched_wakeup() (I've not fully read the thread, but ISTR you had
> > > > > > some traces with these here thingies on).
> > > > > > 
> > > > > > ---
> > > > > >  arch/x86/include/asm/bitops.h | 6 ++++--
> > > > > >  kernel/sched/core.c           | 9 +++++++++
> > > > > >  2 files changed, 13 insertions(+), 2 deletions(-)
> > > > > > 
> > > > > > diff --git a/arch/x86/include/asm/bitops.h b/arch/x86/include/asm/bitops.h
> > > > > > index 7766d1cf096e..5345784d5e41 100644
> > > > > > --- a/arch/x86/include/asm/bitops.h
> > > > > > +++ b/arch/x86/include/asm/bitops.h
> > > > > > @@ -112,11 +112,13 @@ clear_bit(long nr, volatile unsigned long *addr)
> > > > > >  	if (IS_IMMEDIATE(nr)) {
> > > > > >  		asm volatile(LOCK_PREFIX "andb %1,%0"
> > > > > >  			: CONST_MASK_ADDR(nr, addr)
> > > > > > -			: "iq" ((u8)~CONST_MASK(nr)));
> > > > > > +			: "iq" ((u8)~CONST_MASK(nr))
> > > > > > +			: "memory");
> > > > > >  	} else {
> > > > > >  		asm volatile(LOCK_PREFIX "btr %1,%0"
> > > > > >  			: BITOP_ADDR(addr)
> > > > > > -			: "Ir" (nr));
> > > > > > +			: "Ir" (nr)
> > > > > > +			: "memory");
> > > > > >  	}
> > > > > >  }
> > > > > 
> > > > > Is the above addition of "memory" strictly for the debug below, or is
> > > > > it also a potential fix?
> > > > > 
> > > > > Starting it up regardless, but figured I should ask!
> > > > > 
> > > > > 							Thanx, Paul
> > > > > 
> > > > > > diff --git a/kernel/sched/core.c b/kernel/sched/core.c
> > > > > > index 0b21e7a724e1..b446f73c530d 100644
> > > > > > --- a/kernel/sched/core.c
> > > > > > +++ b/kernel/sched/core.c
> > > > > > @@ -1669,6 +1669,7 @@ void sched_ttwu_pending(void)
> > > > > >  	while (llist) {
> > > > > >  		p = llist_entry(llist, struct task_struct, wake_entry);
> > > > > >  		llist = llist_next(llist);
> > > > > > +		trace_printk("waking %d\n", p->pid);
> > > > > >  		ttwu_do_activate(rq, p, 0);
> > > > > >  	}
> > > > > > 
> > > > > > @@ -1719,6 +1720,7 @@ static void ttwu_queue_remote(struct task_struct *p, int cpu)
> > > > > >  	struct rq *rq = cpu_rq(cpu);
> > > > > > 
> > > > > >  	if (llist_add(&p->wake_entry, &cpu_rq(cpu)->wake_list)) {
> > > > > > +		trace_printk("queued %d for waking on %d\n", p->pid, cpu);
> > > > > >  		if (!set_nr_if_polling(rq->idle))
> > > > > >  			smp_send_reschedule(cpu);
> > > > > >  		else
> > > > > > @@ -5397,10 +5399,17 @@ migration_call(struct notifier_block *nfb, unsigned long action, void *hcpu)
> > > > > >  		migrate_tasks(rq);
> > > > > >  		BUG_ON(rq->nr_running != 1); /* the migration thread */
> > > > > >  		raw_spin_unlock_irqrestore(&rq->lock, flags);
> > > > > > +
> > > > > > +		/* really bad m'kay */
> > > > > > +		WARN_ON(!llist_empty(&rq->wake_list));
> > > > > > +
> > > > > >  		break;
> > > > > > 
> > > > > >  	case CPU_DEAD:
> > > > > >  		calc_load_migrate(rq);
> > > > > > +
> > > > > > +		/* more bad */
> > > > > > +		WARN_ON(!llist_empty(&rq->wake_list));
> > > > > >  		break;
> > > > > >  #endif
> > > > > >  	}
> > > > > > 

[toc] | [prev] | [next] | [standalone]

#1365729

On Mon, Mar 28, 2016 at 06:08:41AM -0700, Paul E. McKenney wrote:
> On Mon, Mar 28, 2016 at 08:25:47AM +0200, Peter Zijlstra wrote:
> > On Sun, Mar 27, 2016 at 02:06:41PM -0700, Paul E. McKenney wrote:

[ . . . ]

> > > OK, so I should instrument migration_call() if I get the repro rate up?
> > 
> > Can do, maybe try the below first. (yes I know how long it all takes :/)
> 
> OK, will run this today, then run calibration for last night's run this
> evening.

And there was one failure out of ten runs.  If last night's failure rate
was typical (7 of 24), then I believe we can be about 87% confident that
this change helped.  That isn't all that confident, but...

Tested-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>

So what to run tonight?

The most sane approach would be to run stock in order to get a baseline
failure rate.  It is tempting to run more of Peter's patch, but part of
the problem is that we don't know the current baseline.

So baseline it is...

							Thanx, Paul

> Speaking of which, last night's run (disabling TIF_POLLING_NRFLAG)
> consisted of 24 two-hour runs.  Six of them had hard hangs, and another
> had a hang that eventually unhung of its own accord.  I believe that this
> is significantly fewer failures than from a stock kernel, but I could
> be wrong, and it will take some serious testing to give statistical
> confidence for whatever conclusion is correct.
> 
> > > > The other interesting case would be resched_cpu(), which uses
> > > > set_nr_and_not_polling() to kick a remote cpu to call schedule(). It
> > > > atomically sets TIF_NEED_RESCHED and returns if TIF_POLLING_NRFLAG was
> > > > not set. If indeed not, it will send an IPI.
> > > > 
> > > > This assumes the idle 'exit' path will do the same as the IPI does; and
> > > > if you look at cpu_idle_loop() it does indeed do both
> > > > preempt_fold_need_resched() and sched_ttwu_pending().
> > > > 
> > > > Note that one cannot rely on irq_enter()/irq_exit() being called for the
> > > > scheduler IPI.
> > > 
> > > OK, thank you for the info!  Any specific debug actions?
> > 
> > Dunno, something like the below should bring visibility into the
> > (lockless) wake_list thingy.
> > 
> > So these trace_printk()s should happen between trace_sched_waking() and
> > trace_sched_wakeup() (I've not fully read the thread, but ISTR you had
> > some traces with these here thingies on).
> > 
> > ---
> >  arch/x86/include/asm/bitops.h | 6 ++++--
> >  kernel/sched/core.c           | 9 +++++++++
> >  2 files changed, 13 insertions(+), 2 deletions(-)
> > 
> > diff --git a/arch/x86/include/asm/bitops.h b/arch/x86/include/asm/bitops.h
> > index 7766d1cf096e..5345784d5e41 100644
> > --- a/arch/x86/include/asm/bitops.h
> > +++ b/arch/x86/include/asm/bitops.h
> > @@ -112,11 +112,13 @@ clear_bit(long nr, volatile unsigned long *addr)
> >  	if (IS_IMMEDIATE(nr)) {
> >  		asm volatile(LOCK_PREFIX "andb %1,%0"
> >  			: CONST_MASK_ADDR(nr, addr)
> > -			: "iq" ((u8)~CONST_MASK(nr)));
> > +			: "iq" ((u8)~CONST_MASK(nr))
> > +			: "memory");
> >  	} else {
> >  		asm volatile(LOCK_PREFIX "btr %1,%0"
> >  			: BITOP_ADDR(addr)
> > -			: "Ir" (nr));
> > +			: "Ir" (nr)
> > +			: "memory");
> >  	}
> >  }
> 
> Is the above addition of "memory" strictly for the debug below, or is
> it also a potential fix?
> 
> Starting it up regardless, but figured I should ask!
> 
> 							Thanx, Paul
> 
> > diff --git a/kernel/sched/core.c b/kernel/sched/core.c
> > index 0b21e7a724e1..b446f73c530d 100644
> > --- a/kernel/sched/core.c
> > +++ b/kernel/sched/core.c
> > @@ -1669,6 +1669,7 @@ void sched_ttwu_pending(void)
> >  	while (llist) {
> >  		p = llist_entry(llist, struct task_struct, wake_entry);
> >  		llist = llist_next(llist);
> > +		trace_printk("waking %d\n", p->pid);
> >  		ttwu_do_activate(rq, p, 0);
> >  	}
> > 
> > @@ -1719,6 +1720,7 @@ static void ttwu_queue_remote(struct task_struct *p, int cpu)
> >  	struct rq *rq = cpu_rq(cpu);
> > 
> >  	if (llist_add(&p->wake_entry, &cpu_rq(cpu)->wake_list)) {
> > +		trace_printk("queued %d for waking on %d\n", p->pid, cpu);
> >  		if (!set_nr_if_polling(rq->idle))
> >  			smp_send_reschedule(cpu);
> >  		else
> > @@ -5397,10 +5399,17 @@ migration_call(struct notifier_block *nfb, unsigned long action, void *hcpu)
> >  		migrate_tasks(rq);
> >  		BUG_ON(rq->nr_running != 1); /* the migration thread */
> >  		raw_spin_unlock_irqrestore(&rq->lock, flags);
> > +
> > +		/* really bad m'kay */
> > +		WARN_ON(!llist_empty(&rq->wake_list));
> > +
> >  		break;
> > 
> >  	case CPU_DEAD:
> >  		calc_load_migrate(rq);
> > +
> > +		/* more bad */
> > +		WARN_ON(!llist_empty(&rq->wake_list));
> >  		break;
> >  #endif
> >  	}
> > 

[toc] | [prev] | [next] | [standalone]

#1365259

----- On Mar 27, 2016, at 4:45 PM, Peter Zijlstra peterz@infradead.org wrote:

> On Sun, Mar 27, 2016 at 08:40:18AM -0700, Paul E. McKenney wrote:
>> Oh, and the patch I am running with is below.  I am running x86, and so
>> some other architectures would of course need the corresponding patch
>> on that architecture.
> 
>> -#define TIF_POLLING_NRFLAG	21	/* idle is polling for TIF_NEED_RESCHED */
>> +/* #define TIF_POLLING_NRFLAG	21	 idle is polling for TIF_NEED_RESCHED */
> 
> x86 is the only arch that really uses this heavily IIRC.
> 
> Most of the other archs need interrupts to wake up remote cores.
> 
> So what we try to do is avoid sending IPIs when the CPU is idle, for the
> remote wakeup case we use set_nr_if_polling() which sets
> TIF_NEED_RESCHED if TIF_POLLING_NRFLAG was set. If it wasn't, we'll send
> the IPI. Otherwise we rely on the idle loop to do sched_ttwu_pending()
> when it breaks out of loop due to TIF_NEED_RESCHED.
> 
> But, you need hotplug for this to happen, right?

My understanding is that this seems to be detection of failures to be
awakened for a long time on idle CPUs. It therefore seems to be more
idle-related than cpu hotplug-related. I'm not saying that there is
no issue with hotplug, just that the investigation so far seems to
target mostly idle systems, AFAIK without stressing hotplug.

> 
> We should not be migrating towards, or waking on, CPUs no longer present
> in cpu_active_map, and there is a rcu/sched_sync() after clearing that
> bit. Furthermore, migration_call() does a sched_ttwu_pending() (waking
> any remaining stragglers) before we migrate all runnable tasks off the
> dying CPU.
> 
> 
> 
> The other interesting case would be resched_cpu(), which uses
> set_nr_and_not_polling() to kick a remote cpu to call schedule(). It
> atomically sets TIF_NEED_RESCHED and returns if TIF_POLLING_NRFLAG was
> not set. If indeed not, it will send an IPI.
> 
> This assumes the idle 'exit' path will do the same as the IPI does; and
> if you look at cpu_idle_loop() it does indeed do both
> preempt_fold_need_resched() and sched_ttwu_pending().
> 
> Note that one cannot rely on irq_enter()/irq_exit() being called for the
> scheduler IPI.

Looking at commit e3baac47f0e82c4be632f4f97215bb93bf16b342 :

set_nr_if_polling() returns true if the ti->flags read has the
_TIF_NEED_RESCHED bit set, which will skip the IPI.

But it seems weird. The side that calls set_nr_if_polling()
does the following:
1) llist_add(&p->wake_entry, &cpu_rq(cpu)->wake_list)
2) set_nr_if_polling(rq->idle)
3) (don't do smp_send_reschedule(cpu) since set_nr_if_polling() returned
   true)

The idle loop does:
1) __current_set_polling()
2) __current_clr_polling()
3) smp_mb__after_atomic()
4) sched_ttwu_pending()
5) schedule_preempt_disabled()
   -> This will clear the TIF_NEED_RESCHED flag

While the idle loop is in sched_ttwu_pending(), after
it has done the llist_del_all() (thus has grabbed all the
list entries), TIF_NEED_RESCHED is still set. If both list_all and
set_nr_if_polling() are called right after the llist_del_all(), we
will end up in a situation where we have an entry in the list, but
there won't be any reschedule sent on the idle CPU until something
else awakens it. On a _very_ idle CPU, this could take some time.

set_nr_and_not_polling() don't seem to have the same issue, because
it does not return true if TIF_NEED_RESCHED is observed as being
already set: it really just depends on the state of the TIF_POLLING_NRFLAG
bit.

Am I missing something important ?

Thanks,

Mathieu

-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

[toc] | [prev] | [next] | [standalone]

#1365266

----- On Mar 27, 2016, at 9:44 PM, Mathieu Desnoyers mathieu.desnoyers@efficios.com wrote:

> ----- On Mar 27, 2016, at 4:45 PM, Peter Zijlstra peterz@infradead.org wrote:
> 
>> On Sun, Mar 27, 2016 at 08:40:18AM -0700, Paul E. McKenney wrote:
>>> Oh, and the patch I am running with is below.  I am running x86, and so
>>> some other architectures would of course need the corresponding patch
>>> on that architecture.
>> 
>>> -#define TIF_POLLING_NRFLAG	21	/* idle is polling for TIF_NEED_RESCHED */
>>> +/* #define TIF_POLLING_NRFLAG	21	 idle is polling for TIF_NEED_RESCHED */
>> 
>> x86 is the only arch that really uses this heavily IIRC.
>> 
>> Most of the other archs need interrupts to wake up remote cores.
>> 
>> So what we try to do is avoid sending IPIs when the CPU is idle, for the
>> remote wakeup case we use set_nr_if_polling() which sets
>> TIF_NEED_RESCHED if TIF_POLLING_NRFLAG was set. If it wasn't, we'll send
>> the IPI. Otherwise we rely on the idle loop to do sched_ttwu_pending()
>> when it breaks out of loop due to TIF_NEED_RESCHED.
>> 
>> But, you need hotplug for this to happen, right?
> 
> My understanding is that this seems to be detection of failures to be
> awakened for a long time on idle CPUs. It therefore seems to be more
> idle-related than cpu hotplug-related. I'm not saying that there is
> no issue with hotplug, just that the investigation so far seems to
> target mostly idle systems, AFAIK without stressing hotplug.
> 
>> 
>> We should not be migrating towards, or waking on, CPUs no longer present
>> in cpu_active_map, and there is a rcu/sched_sync() after clearing that
>> bit. Furthermore, migration_call() does a sched_ttwu_pending() (waking
>> any remaining stragglers) before we migrate all runnable tasks off the
>> dying CPU.
>> 
>> 
>> 
>> The other interesting case would be resched_cpu(), which uses
>> set_nr_and_not_polling() to kick a remote cpu to call schedule(). It
>> atomically sets TIF_NEED_RESCHED and returns if TIF_POLLING_NRFLAG was
>> not set. If indeed not, it will send an IPI.
>> 
>> This assumes the idle 'exit' path will do the same as the IPI does; and
>> if you look at cpu_idle_loop() it does indeed do both
>> preempt_fold_need_resched() and sched_ttwu_pending().
>> 
>> Note that one cannot rely on irq_enter()/irq_exit() being called for the
>> scheduler IPI.
> 
> Looking at commit e3baac47f0e82c4be632f4f97215bb93bf16b342 :
> 
> set_nr_if_polling() returns true if the ti->flags read has the
> _TIF_NEED_RESCHED bit set, which will skip the IPI.
> 
> But it seems weird. The side that calls set_nr_if_polling()
> does the following:
> 1) llist_add(&p->wake_entry, &cpu_rq(cpu)->wake_list)
> 2) set_nr_if_polling(rq->idle)
> 3) (don't do smp_send_reschedule(cpu) since set_nr_if_polling() returned
>   true)
> 
> The idle loop does:
> 1) __current_set_polling()
> 2) __current_clr_polling()
> 3) smp_mb__after_atomic()
> 4) sched_ttwu_pending()
> 5) schedule_preempt_disabled()
>   -> This will clear the TIF_NEED_RESCHED flag
> 
> While the idle loop is in sched_ttwu_pending(), after
> it has done the llist_del_all() (thus has grabbed all the
> list entries), TIF_NEED_RESCHED is still set. If both list_all and
> set_nr_if_polling() are called right after the llist_del_all(), we
> will end up in a situation where we have an entry in the list, but
> there won't be any reschedule sent on the idle CPU until something
> else awakens it. On a _very_ idle CPU, this could take some time.
> 
> set_nr_and_not_polling() don't seem to have the same issue, because
> it does not return true if TIF_NEED_RESCHED is observed as being
> already set: it really just depends on the state of the TIF_POLLING_NRFLAG
> bit.
> 
> Am I missing something important ?

Well, it seems that the test for _TIF_POLLING_NRFLAG in set_nr_if_polling()
just before the test for _TIF_NEED_RESCHED should take care of it: while in
sched_ttwu_pending within the idle loop, the TIF_POLLING_NRFLAG should be
cleared, thus causing set_nr_if_polling to return false.

I'm slightly concerned about the lack of smp_mb__after_atomic()
between the TIF_NEED_RESCHED flag being cleared within schedule_preempt_disabled
and the TIF_POLLING_NRFLAG being set in the following loop. Indeed, clear_bit()
does not have a compiler barrier, nor processor-level memory barriers
(of course, the processor memory barrier should not really matter on
x86-64 due to lock prefix). Moreover, TIF_NEED_RESCHED is bit 3 on x86-64,
whereas TIF_POLLING_NRFLAG is bit 21. Those are in two different bytes of
the thread flags, and thus set/cleared as different addresses by clear_bit()
acting on an immediate "nr" argument.

If we have any state where TIF_POLLING_NRFLAG is set before TIF_NEED_RESCHED
is cleared within the idle thread, we could end up missing a needed resched IPI.

Another question: why are set_nr_if_polling and set_nr_and_not_polling two
different implementations ? Could they be combined ?

Thanks,

Mathieu


> 
> Thanks,
> 
> Mathieu
> 
> --
> Mathieu Desnoyers
> EfficiOS Inc.
> http://www.efficios.com

-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

[toc] | [prev] | [next] | [standalone]

#1365343

On Mon, Mar 28, 2016 at 02:23:45AM +0000, Mathieu Desnoyers wrote:

> >> But, you need hotplug for this to happen, right?
> > 
> > My understanding is that this seems to be detection of failures to be
> > awakened for a long time on idle CPUs. It therefore seems to be more
> > idle-related than cpu hotplug-related. I'm not saying that there is
> > no issue with hotplug, just that the investigation so far seems to
> > target mostly idle systems, AFAIK without stressing hotplug.

Paul has stated that without hotplug he cannot trigger this.

> > set_nr_if_polling() returns true if the ti->flags read has the
> > _TIF_NEED_RESCHED bit set, which will skip the IPI.

POLLING_NR, as per your later comment

> > But it seems weird. The side that calls set_nr_if_polling()
> > does the following:
> > 1) llist_add(&p->wake_entry, &cpu_rq(cpu)->wake_list)
> > 2) set_nr_if_polling(rq->idle)
> > 3) (don't do smp_send_reschedule(cpu) since set_nr_if_polling() returned
> >   true)
> > 
> > The idle loop does:
> > 1) __current_set_polling()
> > 2) __current_clr_polling()
> > 3) smp_mb__after_atomic()
> > 4) sched_ttwu_pending()
> > 5) schedule_preempt_disabled()
> >   -> This will clear the TIF_NEED_RESCHED flag
> > 
> > While the idle loop is in sched_ttwu_pending(), after
> > it has done the llist_del_all() (thus has grabbed all the
> > list entries), TIF_NEED_RESCHED is still set.

> > If both list_all and

llist_add() ?

> > set_nr_if_polling() are called right after the llist_del_all(), we
> > will end up in a situation where we have an entry in the list, but
> > there won't be any reschedule sent on the idle CPU until something
> > else awakens it. On a _very_ idle CPU, this could take some time.

Can't happen, as per clearing of POLLING_NR before doing llist_del_all()
and the latter being a full memory barrier.

> > set_nr_and_not_polling() don't seem to have the same issue, because
> > it does not return true if TIF_NEED_RESCHED is observed as being
> > already set: it really just depends on the state of the TIF_POLLING_NRFLAG
> > bit.
> > 
> > Am I missing something important ?
> 
> Well, it seems that the test for _TIF_POLLING_NRFLAG in set_nr_if_polling()
> just before the test for _TIF_NEED_RESCHED should take care of it: while in
> sched_ttwu_pending within the idle loop, the TIF_POLLING_NRFLAG should be
> cleared, thus causing set_nr_if_polling to return false.

Right, clue in the name: Set NEED_RESCHED _IF_ POLLING_NR (is set).

> I'm slightly concerned about the lack of smp_mb__after_atomic()
> between the TIF_NEED_RESCHED flag being cleared within schedule_preempt_disabled
> and the TIF_POLLING_NRFLAG being set in the following loop. Indeed, clear_bit()
> does not have a compiler barrier,

Urgh, it really should, as all atomic ops. set_bit() very much has a
memory clobber in, see below.

> nor processor-level memory barriers
> (of course, the processor memory barrier should not really matter on
> x86-64 due to lock prefix).

Right.

> Moreover, TIF_NEED_RESCHED is bit 3 on x86-64,
> whereas TIF_POLLING_NRFLAG is bit 21. Those are in two different bytes of
> the thread flags, and thus set/cleared as different addresses by clear_bit()
> acting on an immediate "nr" argument.
> 
> If we have any state where TIF_POLLING_NRFLAG is set before TIF_NEED_RESCHED
> is cleared within the idle thread, we could end up missing a needed resched IPI.

Yes, that would be bad. No objection to adding smp_mb__before_atomic()
before the initial __current_set_polling(). Although that's not going to
make a difference for x86_64 as you already noted.

> Another question: why are set_nr_if_polling and set_nr_and_not_polling two
> different implementations ?

Because they're fundamentally two different things. The one
conditionally sets NEED_RESCHED, the other unconditionally sets it.

> Could they be combined ?

Can, yes, will not be pretty nor clear code though.


---
 arch/x86/include/asm/bitops.h | 6 ++++--
 1 file changed, 4 insertions(+), 2 deletions(-)

diff --git a/arch/x86/include/asm/bitops.h b/arch/x86/include/asm/bitops.h
index 7766d1cf096e..5345784d5e41 100644
--- a/arch/x86/include/asm/bitops.h
+++ b/arch/x86/include/asm/bitops.h
@@ -112,11 +112,13 @@ clear_bit(long nr, volatile unsigned long *addr)
 	if (IS_IMMEDIATE(nr)) {
 		asm volatile(LOCK_PREFIX "andb %1,%0"
 			: CONST_MASK_ADDR(nr, addr)
-			: "iq" ((u8)~CONST_MASK(nr)));
+			: "iq" ((u8)~CONST_MASK(nr))
+			: "memory");
 	} else {
 		asm volatile(LOCK_PREFIX "btr %1,%0"
 			: BITOP_ADDR(addr)
-			: "Ir" (nr));
+			: "Ir" (nr)
+			: "memory");
 	}
 }
 

[toc] | [prev] | [next] | [standalone]

#1365508

On Mon, Mar 28, 2016 at 08:13:51AM +0200, Peter Zijlstra wrote:
> On Mon, Mar 28, 2016 at 02:23:45AM +0000, Mathieu Desnoyers wrote:
> 
> > >> But, you need hotplug for this to happen, right?
> > > 
> > > My understanding is that this seems to be detection of failures to be
> > > awakened for a long time on idle CPUs. It therefore seems to be more
> > > idle-related than cpu hotplug-related. I'm not saying that there is
> > > no issue with hotplug, just that the investigation so far seems to
> > > target mostly idle systems, AFAIK without stressing hotplug.
> 
> Paul has stated that without hotplug he cannot trigger this.

Which means either that hotplug is absolutely necessary or that
hotplug increases the probability of failure.  Ross's experience is
without hotplug on a mostly idle system, so I am currently betting on
"increases the probability".  The set of bugs does seem to have gotten
worse somewhere between v4.1 and v4.2, but not sufficiently to allow
reasonble bisection (yes, I did try, several times).

> > > set_nr_if_polling() returns true if the ti->flags read has the
> > > _TIF_NEED_RESCHED bit set, which will skip the IPI.
> 
> POLLING_NR, as per your later comment
> 
> > > But it seems weird. The side that calls set_nr_if_polling()
> > > does the following:
> > > 1) llist_add(&p->wake_entry, &cpu_rq(cpu)->wake_list)
> > > 2) set_nr_if_polling(rq->idle)
> > > 3) (don't do smp_send_reschedule(cpu) since set_nr_if_polling() returned
> > >   true)
> > > 
> > > The idle loop does:
> > > 1) __current_set_polling()
> > > 2) __current_clr_polling()
> > > 3) smp_mb__after_atomic()
> > > 4) sched_ttwu_pending()
> > > 5) schedule_preempt_disabled()
> > >   -> This will clear the TIF_NEED_RESCHED flag
> > > 
> > > While the idle loop is in sched_ttwu_pending(), after
> > > it has done the llist_del_all() (thus has grabbed all the
> > > list entries), TIF_NEED_RESCHED is still set.
> 
> > > If both list_all and
> 
> llist_add() ?
> 
> > > set_nr_if_polling() are called right after the llist_del_all(), we
> > > will end up in a situation where we have an entry in the list, but
> > > there won't be any reschedule sent on the idle CPU until something
> > > else awakens it. On a _very_ idle CPU, this could take some time.
> 
> Can't happen, as per clearing of POLLING_NR before doing llist_del_all()
> and the latter being a full memory barrier.
> 
> > > set_nr_and_not_polling() don't seem to have the same issue, because
> > > it does not return true if TIF_NEED_RESCHED is observed as being
> > > already set: it really just depends on the state of the TIF_POLLING_NRFLAG
> > > bit.
> > > 
> > > Am I missing something important ?
> > 
> > Well, it seems that the test for _TIF_POLLING_NRFLAG in set_nr_if_polling()
> > just before the test for _TIF_NEED_RESCHED should take care of it: while in
> > sched_ttwu_pending within the idle loop, the TIF_POLLING_NRFLAG should be
> > cleared, thus causing set_nr_if_polling to return false.
> 
> Right, clue in the name: Set NEED_RESCHED _IF_ POLLING_NR (is set).
> 
> > I'm slightly concerned about the lack of smp_mb__after_atomic()
> > between the TIF_NEED_RESCHED flag being cleared within schedule_preempt_disabled
> > and the TIF_POLLING_NRFLAG being set in the following loop. Indeed, clear_bit()
> > does not have a compiler barrier,
> 
> Urgh, it really should, as all atomic ops. set_bit() very much has a
> memory clobber in, see below.

And this is one of the changes in your patch that I am now testing, correct?
(Looks that way to me, but..)

							Thanx, Paul

> > nor processor-level memory barriers
> > (of course, the processor memory barrier should not really matter on
> > x86-64 due to lock prefix).
> 
> Right.
> 
> > Moreover, TIF_NEED_RESCHED is bit 3 on x86-64,
> > whereas TIF_POLLING_NRFLAG is bit 21. Those are in two different bytes of
> > the thread flags, and thus set/cleared as different addresses by clear_bit()
> > acting on an immediate "nr" argument.
> > 
> > If we have any state where TIF_POLLING_NRFLAG is set before TIF_NEED_RESCHED
> > is cleared within the idle thread, we could end up missing a needed resched IPI.
> 
> Yes, that would be bad. No objection to adding smp_mb__before_atomic()
> before the initial __current_set_polling(). Although that's not going to
> make a difference for x86_64 as you already noted.
> 
> > Another question: why are set_nr_if_polling and set_nr_and_not_polling two
> > different implementations ?
> 
> Because they're fundamentally two different things. The one
> conditionally sets NEED_RESCHED, the other unconditionally sets it.
> 
> > Could they be combined ?
> 
> Can, yes, will not be pretty nor clear code though.
> 
> 
> ---
>  arch/x86/include/asm/bitops.h | 6 ++++--
>  1 file changed, 4 insertions(+), 2 deletions(-)
> 
> diff --git a/arch/x86/include/asm/bitops.h b/arch/x86/include/asm/bitops.h
> index 7766d1cf096e..5345784d5e41 100644
> --- a/arch/x86/include/asm/bitops.h
> +++ b/arch/x86/include/asm/bitops.h
> @@ -112,11 +112,13 @@ clear_bit(long nr, volatile unsigned long *addr)
>  	if (IS_IMMEDIATE(nr)) {
>  		asm volatile(LOCK_PREFIX "andb %1,%0"
>  			: CONST_MASK_ADDR(nr, addr)
> -			: "iq" ((u8)~CONST_MASK(nr)));
> +			: "iq" ((u8)~CONST_MASK(nr))
> +			: "memory");
>  	} else {
>  		asm volatile(LOCK_PREFIX "btr %1,%0"
>  			: BITOP_ADDR(addr)
> -			: "Ir" (nr));
> +			: "Ir" (nr)
> +			: "memory");
>  	}
>  }
> 
> 

[toc] | [prev] | [next] | [standalone]

#1365514

----- On Mar 28, 2016, at 2:13 AM, Peter Zijlstra peterz@infradead.org wrote:

> On Mon, Mar 28, 2016 at 02:23:45AM +0000, Mathieu Desnoyers wrote:
> 
>> >> But, you need hotplug for this to happen, right?
>> > 
>> > My understanding is that this seems to be detection of failures to be
>> > awakened for a long time on idle CPUs. It therefore seems to be more
>> > idle-related than cpu hotplug-related. I'm not saying that there is
>> > no issue with hotplug, just that the investigation so far seems to
>> > target mostly idle systems, AFAIK without stressing hotplug.
> 
> Paul has stated that without hotplug he cannot trigger this.
> 
>> > set_nr_if_polling() returns true if the ti->flags read has the
>> > _TIF_NEED_RESCHED bit set, which will skip the IPI.
> 
> POLLING_NR, as per your later comment
> 
>> > But it seems weird. The side that calls set_nr_if_polling()
>> > does the following:
>> > 1) llist_add(&p->wake_entry, &cpu_rq(cpu)->wake_list)
>> > 2) set_nr_if_polling(rq->idle)
>> > 3) (don't do smp_send_reschedule(cpu) since set_nr_if_polling() returned
>> >   true)
>> > 
>> > The idle loop does:
>> > 1) __current_set_polling()
>> > 2) __current_clr_polling()
>> > 3) smp_mb__after_atomic()
>> > 4) sched_ttwu_pending()
>> > 5) schedule_preempt_disabled()
>> >   -> This will clear the TIF_NEED_RESCHED flag
>> > 
>> > While the idle loop is in sched_ttwu_pending(), after
>> > it has done the llist_del_all() (thus has grabbed all the
>> > list entries), TIF_NEED_RESCHED is still set.
> 
>> > If both list_all and
> 
> llist_add() ?

Yes, indeed.

> 
>> > set_nr_if_polling() are called right after the llist_del_all(), we
>> > will end up in a situation where we have an entry in the list, but
>> > there won't be any reschedule sent on the idle CPU until something
>> > else awakens it. On a _very_ idle CPU, this could take some time.
> 
> Can't happen, as per clearing of POLLING_NR before doing llist_del_all()
> and the latter being a full memory barrier.
> 
>> > set_nr_and_not_polling() don't seem to have the same issue, because
>> > it does not return true if TIF_NEED_RESCHED is observed as being
>> > already set: it really just depends on the state of the TIF_POLLING_NRFLAG
>> > bit.
>> > 
>> > Am I missing something important ?
>> 
>> Well, it seems that the test for _TIF_POLLING_NRFLAG in set_nr_if_polling()
>> just before the test for _TIF_NEED_RESCHED should take care of it: while in
>> sched_ttwu_pending within the idle loop, the TIF_POLLING_NRFLAG should be
>> cleared, thus causing set_nr_if_polling to return false.
> 
> Right, clue in the name: Set NEED_RESCHED _IF_ POLLING_NR (is set).
> 
>> I'm slightly concerned about the lack of smp_mb__after_atomic()
>> between the TIF_NEED_RESCHED flag being cleared within schedule_preempt_disabled
>> and the TIF_POLLING_NRFLAG being set in the following loop. Indeed, clear_bit()
>> does not have a compiler barrier,
> 
> Urgh, it really should, as all atomic ops. set_bit() very much has a
> memory clobber in, see below.

Yes, I'd be more comfortable with the memory clobber in the clear_bit
too, but theoretically it *should* not matter, because we have a clobber
in set_bit, and clear_bit has a +m memory operand.

> 
>> nor processor-level memory barriers
>> (of course, the processor memory barrier should not really matter on
>> x86-64 due to lock prefix).
> 
> Right.
> 
>> Moreover, TIF_NEED_RESCHED is bit 3 on x86-64,
>> whereas TIF_POLLING_NRFLAG is bit 21. Those are in two different bytes of
>> the thread flags, and thus set/cleared as different addresses by clear_bit()
>> acting on an immediate "nr" argument.
>> 
>> If we have any state where TIF_POLLING_NRFLAG is set before TIF_NEED_RESCHED
>> is cleared within the idle thread, we could end up missing a needed resched IPI.
> 
> Yes, that would be bad. No objection to adding smp_mb__before_atomic()
> before the initial __current_set_polling(). Although that's not going to
> make a difference for x86_64 as you already noted.

Yep.

> 
>> Another question: why are set_nr_if_polling and set_nr_and_not_polling two
>> different implementations ?
> 
> Because they're fundamentally two different things. The one
> conditionally sets NEED_RESCHED, the other unconditionally sets it.

Got it, makes sense.

Thanks!

Mathieu

> 
>> Could they be combined ?
> 
> Can, yes, will not be pretty nor clear code though.
> 
> 
> ---
> arch/x86/include/asm/bitops.h | 6 ++++--
> 1 file changed, 4 insertions(+), 2 deletions(-)
> 
> diff --git a/arch/x86/include/asm/bitops.h b/arch/x86/include/asm/bitops.h
> index 7766d1cf096e..5345784d5e41 100644
> --- a/arch/x86/include/asm/bitops.h
> +++ b/arch/x86/include/asm/bitops.h
> @@ -112,11 +112,13 @@ clear_bit(long nr, volatile unsigned long *addr)
> 	if (IS_IMMEDIATE(nr)) {
> 		asm volatile(LOCK_PREFIX "andb %1,%0"
> 			: CONST_MASK_ADDR(nr, addr)
> -			: "iq" ((u8)~CONST_MASK(nr)));
> +			: "iq" ((u8)~CONST_MASK(nr))
> +			: "memory");
> 	} else {
> 		asm volatile(LOCK_PREFIX "btr %1,%0"
> 			: BITOP_ADDR(addr)
> -			: "Ir" (nr));
> +			: "Ir" (nr)
> +			: "memory");
> 	}
>  }

-- 
Mathieu Desnoyers
EfficiOS Inc.
http://www.efficios.com

[toc] | [prev] | [next] | [standalone]

#1365186

On Sun, Mar 27, 2016 at 08:40:18AM -0700, Paul E. McKenney wrote:
> Oh, and the patch I am running with is below.  I am running x86, and so
> some other architectures would of course need the corresponding patch
> on that architecture.

> -#define TIF_POLLING_NRFLAG	21	/* idle is polling for TIF_NEED_RESCHED */

Also note that ARM (v7) which Ross is running doesn't have this to begin
with.

[toc] | [prev] | [next] | [standalone]

#1365188

On Sun, Mar 27, 2016 at 10:53:18PM +0200, Peter Zijlstra wrote:
> On Sun, Mar 27, 2016 at 08:40:18AM -0700, Paul E. McKenney wrote:
> > Oh, and the patch I am running with is below.  I am running x86, and so
> > some other architectures would of course need the corresponding patch
> > on that architecture.
> 
> > -#define TIF_POLLING_NRFLAG	21	/* idle is polling for TIF_NEED_RESCHED */
> 
> Also note that ARM (v7) which Ross is running doesn't have this to begin
> with.

He might well be seeing some other bug, then.  Reinette might be instead
seeing time-synchronization issues, perhaps that is also Ross's problem.

Or maybe there is more than one bug.  ;-)

							Thanx, Paul

[toc] | [prev] | [next] | [standalone]

#1365185

On Mon, Mar 21, 2016 at 09:22:30AM -0700, Jacob Pan wrote:
> > > We're seeing a similar stall (~60 seconds) on an x86 development
> > > system here.  Any luck tracking down the cause of this?  If not, any
> > > suggestions for traces that might be helpful?

> +Reinette, she has the system that can reproduce the issue. I
> believe she is having some other problems with it at the moment. But
> the .config should be available. Version is v4.5.

Does that system have MONITOR/MWAIT errata?

[toc] | [prev] | [next] | [standalone]

#1365187

On Sun, Mar 27, 2016 at 10:54:39PM +0200, Peter Zijlstra wrote:
> On Mon, Mar 21, 2016 at 09:22:30AM -0700, Jacob Pan wrote:
> > > > We're seeing a similar stall (~60 seconds) on an x86 development
> > > > system here.  Any luck tracking down the cause of this?  If not, any
> > > > suggestions for traces that might be helpful?
> 
> > +Reinette, she has the system that can reproduce the issue. I
> > believe she is having some other problems with it at the moment. But
> > the .config should be available. Version is v4.5.
> 
> Does that system have MONITOR/MWAIT errata?

On the off-chance that this question was also directed at me, here is
what I am running on.  I am running in a qemu/KVM virtual machine, in
case that matters.

							Thanx, Paul

processor       : 63
vendor_id       : GenuineIntel
cpu family      : 6
model           : 47
model name      : Intel(R) Xeon(R) CPU E7- 4820  @ 2.00GHz
stepping        : 2
microcode       : 0x37
cpu MHz         : 1064.000
cache size      : 18432 KB
physical id     : 3
siblings        : 16
core id         : 25
cpu cores       : 8
apicid          : 243
initial apicid  : 243
fpu             : yes
fpu_exception   : yes
cpuid level     : 11
wp              : yes
flags           : fpu vme de pse tsc msr pae mce cx8 apic sep mtrr pge mca cmov pat pse36 clflush dts acpi mmx fxsr sse sse2 ss ht tm pbe syscall nx pdpe1gb rdtscp lm constant_tsc arch_perfmon pebs bts rep_good nopl xtopology nonstop_tsc aperfmperf pni pclmulqdq dtes64 monitor ds_cpl vmx smx est tm2 ssse3 cx16 xtpr pdcm pcid dca sse4_1 sse4_2 x2apic popcnt aes lahf_lm ida arat epb dtherm tpr_shadow vnmi flexpriority ept vpid
bogomips        : 3990.01
clflush size    : 64
cache_alignment : 64
address sizes   : 44 bits physical, 48 bits virtual
power management:

[toc] | [prev] | [next] | [standalone]

#1365352

On Sun, Mar 27, 2016 at 02:09:14PM -0700, Paul E. McKenney wrote:

> > Does that system have MONITOR/MWAIT errata?
> 
> On the off-chance that this question was also directed at me,

Hehe, it wasn't, however, since we're here..

> here is
> what I am running on.  I am running in a qemu/KVM virtual machine, in
> case that matters.

Have you actually tried on real proper hardware? Does it still reproduce
there?

[toc] | [prev] | [next] | [standalone]

#1365487

On Mon, Mar 28, 2016 at 08:28:51AM +0200, Peter Zijlstra wrote:
> On Sun, Mar 27, 2016 at 02:09:14PM -0700, Paul E. McKenney wrote:
> 
> > > Does that system have MONITOR/MWAIT errata?
> > 
> > On the off-chance that this question was also directed at me,
> 
> Hehe, it wasn't, however, since we're here..
> 
> > here is
> > what I am running on.  I am running in a qemu/KVM virtual machine, in
> > case that matters.
> 
> Have you actually tried on real proper hardware? Does it still reproduce
> there?

Ross has, but I have not, given that I have a shared system on the one
hand and a single-socket (four core, eight hardware thread) laptop on
the other that has even longer reproduction times.  The repeat-by is
as follows:

o	Build a kernel with the following Kconfigs:

	CONFIG_SMP=y
	CONFIG_NR_CPUS=16
	CONFIG_PREEMPT_NONE=n
	CONFIG_PREEMPT_VOLUNTARY=n
	CONFIG_PREEMPT=y
	# This should result in CONFIG_PREEMPT_RCU=y
	CONFIG_HZ_PERIODIC=y
	CONFIG_NO_HZ_IDLE=n
	CONFIG_NO_HZ_FULL=n
	CONFIG_RCU_TRACE=y
	CONFIG_HOTPLUG_CPU=y
	CONFIG_RCU_FANOUT=2
	CONFIG_RCU_FANOUT_LEAF=2
	CONFIG_RCU_NOCB_CPU=n
	CONFIG_DEBUG_LOCK_ALLOC=n
	CONFIG_RCU_BOOST=y
	CONFIG_RCU_KTHREAD_PRIO=2
	CONFIG_DEBUG_OBJECTS_RCU_HEAD=n
	CONFIG_RCU_EXPERT=y
	CONFIG_RCU_TORTURE_TEST=y
	CONFIG_PRINTK_TIME=y
	CONFIG_RCU_TORTURE_TEST_SLOW_CLEANUP=y
	CONFIG_RCU_TORTURE_TEST_SLOW_INIT=y
	CONFIG_RCU_TORTURE_TEST_SLOW_PREINIT=y

	If desired, you can instead build with CONFIG_RCU_TORTURE_TEST=m
	and modprobe/insmod the module manually.

o	Find a two-socket x86 system or larger, with at least 16 CPUs.

o	Boot the kernel with the following kernel boot parameters:

	rcutorture.onoff_interval=1 rcutorture.onoff_holdoff=30

	The onoff_holdoff is only needed for CONFIG_RCU_TORTURE_TEST=y.
	When manually setting up the module, you get the holdoff for
	free, courtesy of human timescales.

In the absence of instrumentation, I get failures usually within a
couple of hours, though sometimes much longer.  With instrumentation,
the sky appears to be the limit.  :-/

Ross is running on bare metal with no CPU hotplug, so perhaps his setup
is of more immediate interest.  He is seeing the same symptoms that I am,
namely a task being repeatedly awakened without actually coming out of
TASK_INTERRUPTIBLE state, let alone running.  As you pointed out earlier,
he cannot be seeing the same bug that my crude patch suppresses, but
given that I still see a few failures with that crude patch, it is quite
possible that there is still a common bug.

							Thanx, Paul

[toc] | [prev] | [next] | [standalone]

Page 2 of 3 — ← Prev page 1 [2] 3  Next page →

Back to top | Article view | linux.kernel

csiph-web