[PATCH] hrtimer: Reset hrtimer cpu base proper on CPU hotplug

[PATCH] hrtimer: Reset hrtimer cpu base proper on CPU hotplug

[Thomas Gleixner]

The hrtimer interrupt code contains a hang detection and mitigation
mechanism, which prevents that a long delayed hrtimer interrupt causes a
continous retriggering of interrupts which prevent the system from making
progress. If a hang is detected then the timer hardware is programmed with
a certain delay into the future and a flag is set in the hrtimer cpu base
which prevents newly enqueued timers from reprogramming the timer hardware
prior to the chosen delay. The subsequent hrtimer interrupt after the delay
clears the flag and resumes normal operation.

If such a hang happens in the last hrtimer interrupt before a CPU is
unplugged then the hang_detected flag is set and stays that way when the
CPU is plugged in again. At that point the timer hardware is not armed and
it cannot be armed because the hang_detected flag is still active, so
nothing clears that flag. As a consequence the CPU does not receive hrtimer
interrupts and no timers expire on that CPU which results in RCU stalls and
other malfunctions.

Clear the flag along with some other less critical members of the hrtimer
cpu base to ensure starting from a clean state when a CPU is plugged in.

Thanks to Paul, Sebastian and Anna-Maria for their help to get down to the
root cause of that hard to reproduce heisenbug. Once understood it's
trivial and certainly justifies a brown paperbag.

Fixes: 41d2e4949377 ("hrtimer: Tune hrtimer_interrupt hang logic")
Reported-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Cc: stable@vger.kernel.org
---
 kernel/time/hrtimer.c |    3 +++
 1 file changed, 3 insertions(+)

--- a/kernel/time/hrtimer.c
+++ b/kernel/time/hrtimer.c
@@ -655,7 +655,9 @@ static void hrtimer_reprogram(struct hrt
 static inline void hrtimer_init_hres(struct hrtimer_cpu_base *base)
 {
 	base->expires_next = KTIME_MAX;
+	base->hang_detected = 0;
 	base->hres_active = 0;
+	base->next_timer = NULL;
 }
 
 /*
@@ -1589,6 +1591,7 @@ int hrtimers_prepare_cpu(unsigned int cp
 		timerqueue_init_head(&cpu_base->clock_base[i].active);
 	}
 
+	cpu_base->active_bases = 0;
 	cpu_base->cpu = cpu;
 	hrtimer_init_hres(cpu_base);
 	return 0;

Re: [PATCH] hrtimer: Reset hrtimer cpu base proper on CPU hotplug

[Paul E. McKenney]

On Fri, Jan 26, 2018 at 02:54:32PM +0100, Thomas Gleixner wrote:
> The hrtimer interrupt code contains a hang detection and mitigation
> mechanism, which prevents that a long delayed hrtimer interrupt causes a
> continous retriggering of interrupts which prevent the system from making
> progress. If a hang is detected then the timer hardware is programmed with
> a certain delay into the future and a flag is set in the hrtimer cpu base
> which prevents newly enqueued timers from reprogramming the timer hardware
> prior to the chosen delay. The subsequent hrtimer interrupt after the delay
> clears the flag and resumes normal operation.
> 
> If such a hang happens in the last hrtimer interrupt before a CPU is
> unplugged then the hang_detected flag is set and stays that way when the
> CPU is plugged in again. At that point the timer hardware is not armed and
> it cannot be armed because the hang_detected flag is still active, so
> nothing clears that flag. As a consequence the CPU does not receive hrtimer
> interrupts and no timers expire on that CPU which results in RCU stalls and
> other malfunctions.
> 
> Clear the flag along with some other less critical members of the hrtimer
> cpu base to ensure starting from a clean state when a CPU is plugged in.
> 
> Thanks to Paul, Sebastian and Anna-Maria for their help to get down to the
> root cause of that hard to reproduce heisenbug. Once understood it's
> trivial and certainly justifies a brown paperbag.

Thank you very much, and I do know that feeling!  After reading the
commit log, I feel significantly less incompetent for having failed to
find this one.  ;-)  But it did pass rcutorture testing for a great many
years, didn't it?  :-/

I have started an eight-hour seven-way test on the dreaded rcutorture
TREE01 scenario.  In the meantime, off to the train!

							Thanx, Paul

> Fixes: 41d2e4949377 ("hrtimer: Tune hrtimer_interrupt hang logic")
> Reported-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
> Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
> Cc: stable@vger.kernel.org
> ---
>  kernel/time/hrtimer.c |    3 +++
>  1 file changed, 3 insertions(+)
> 
> --- a/kernel/time/hrtimer.c
> +++ b/kernel/time/hrtimer.c
> @@ -655,7 +655,9 @@ static void hrtimer_reprogram(struct hrt
>  static inline void hrtimer_init_hres(struct hrtimer_cpu_base *base)
>  {
>  	base->expires_next = KTIME_MAX;
> +	base->hang_detected = 0;
>  	base->hres_active = 0;
> +	base->next_timer = NULL;
>  }
> 
>  /*
> @@ -1589,6 +1591,7 @@ int hrtimers_prepare_cpu(unsigned int cp
>  		timerqueue_init_head(&cpu_base->clock_base[i].active);
>  	}
> 
> +	cpu_base->active_bases = 0;
>  	cpu_base->cpu = cpu;
>  	hrtimer_init_hres(cpu_base);
>  	return 0;
> 

Re: [PATCH] hrtimer: Reset hrtimer cpu base proper on CPU hotplug

[Paul E. McKenney]

On Fri, Jan 26, 2018 at 02:09:17PM -0800, Paul E. McKenney wrote:
> On Fri, Jan 26, 2018 at 02:54:32PM +0100, Thomas Gleixner wrote:
> > The hrtimer interrupt code contains a hang detection and mitigation
> > mechanism, which prevents that a long delayed hrtimer interrupt causes a
> > continous retriggering of interrupts which prevent the system from making
> > progress. If a hang is detected then the timer hardware is programmed with
> > a certain delay into the future and a flag is set in the hrtimer cpu base
> > which prevents newly enqueued timers from reprogramming the timer hardware
> > prior to the chosen delay. The subsequent hrtimer interrupt after the delay
> > clears the flag and resumes normal operation.
> > 
> > If such a hang happens in the last hrtimer interrupt before a CPU is
> > unplugged then the hang_detected flag is set and stays that way when the
> > CPU is plugged in again. At that point the timer hardware is not armed and
> > it cannot be armed because the hang_detected flag is still active, so
> > nothing clears that flag. As a consequence the CPU does not receive hrtimer
> > interrupts and no timers expire on that CPU which results in RCU stalls and
> > other malfunctions.
> > 
> > Clear the flag along with some other less critical members of the hrtimer
> > cpu base to ensure starting from a clean state when a CPU is plugged in.
> > 
> > Thanks to Paul, Sebastian and Anna-Maria for their help to get down to the
> > root cause of that hard to reproduce heisenbug. Once understood it's
> > trivial and certainly justifies a brown paperbag.
> 
> Thank you very much, and I do know that feeling!  After reading the
> commit log, I feel significantly less incompetent for having failed to
> find this one.  ;-)  But it did pass rcutorture testing for a great many
> years, didn't it?  :-/
> 
> I have started an eight-hour seven-way test on the dreaded rcutorture
> TREE01 scenario.  In the meantime, off to the train!

And bozo here forgot to disable tracing, so the runs take much longer
than the stated time.  And because I applied against v4.15-rc9, which
lacks the recent code to suppress stalls when dumping the trace log,
all runs get RCU CPU stall warnings.  :-/

But I can filter out those tracing-induced stall warnings easily enough,
and thus far there have been 84 successful 30-minute runs out of 112
total, for no failures in 42 hours of TREE01 execution.  Given the base
failure rate of 0.33 per hour, the probability of this happening by
chance is something like ten to the minus sixth power, so:

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

I will be running longer runs without tracing, but looking extremely
good thus far!  Thank you all very much!!!

							Thanx, Paul

Re: [PATCH] hrtimer: Reset hrtimer cpu base proper on CPU hotplug

[Sebastian Sewior]

On 2018-01-26 14:09:17 [-0800], Paul E. McKenney wrote:
> find this one.  ;-)  But it did pass rcutorture testing for a great many
> years, didn't it?  :-/

It started to trigger better (or at all) on our test box with
	modprobe kvm_intel preemption_timer=n

on the host kernel so maybe a completely unrelated change helped to
trigger this.

Sebastian

Re: [PATCH] hrtimer: Reset hrtimer cpu base proper on CPU hotplug

[Paul E. McKenney]

On Mon, Jan 29, 2018 at 09:20:48AM +0100, Sebastian Sewior wrote:
> On 2018-01-26 14:09:17 [-0800], Paul E. McKenney wrote:
> > find this one.  ;-)  But it did pass rcutorture testing for a great many
> > years, didn't it?  :-/
> 
> It started to trigger better (or at all) on our test box with
> 	modprobe kvm_intel preemption_timer=n
> 
> on the host kernel so maybe a completely unrelated change helped to
> trigger this.

Good point!

And testing continues, currently at 108 hours of TREE01 without any
waylayed timers, so looking good!  ;-)

Just kicked off another 70 hours worth.

							Thanx, Paul

Re: [PATCH] hrtimer: Reset hrtimer cpu base proper on CPU hotplug

[Paul E. McKenney]

On Mon, Jan 29, 2018 at 01:57:38AM -0800, Paul E. McKenney wrote:
> On Mon, Jan 29, 2018 at 09:20:48AM +0100, Sebastian Sewior wrote:
> > On 2018-01-26 14:09:17 [-0800], Paul E. McKenney wrote:
> > > find this one.  ;-)  But it did pass rcutorture testing for a great many
> > > years, didn't it?  :-/
> > 
> > It started to trigger better (or at all) on our test box with
> > 	modprobe kvm_intel preemption_timer=n
> > 
> > on the host kernel so maybe a completely unrelated change helped to
> > trigger this.
> 
> Good point!
> 
> And testing continues, currently at 108 hours of TREE01 without any
> waylayed timers, so looking good!  ;-)
> 
> Just kicked off another 70 hours worth.

And those completed without incident for a total of 178 hours.  I believe
we can call this one fixed.  Thank you all!!!

One question...  Is the patch shown below needed, or is this just yet
another case of me being confused?  (The lack of it is not triggering,
but...)

							Thanx, Paul

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

commit accb0edb85526a05b934eac49658d05ea0216fc4
Author: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
Date:   Thu Dec 7 13:18:44 2017 -0800

    timers: Ensure that timer_base ->clk accounts for time offline
    
    The timer_base ->must_forward_clk is set to indicate that the next timer
    operation on that timer_base must check for passage of time.  One instance
    of time passage is when the timer wheel goes idle, and another is when
    the corresponding CPU is offline.  Note that it is not appropriate to set
    ->is_idle because that could result in IPIing an offline CPU.  Therefore,
    this commit instead sets ->must_forward_clk at CPU-offline time.
    
    Signed-off-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>

diff --git a/kernel/time/timer.c b/kernel/time/timer.c
index ffebcf878fba..94cce780c574 100644
--- a/kernel/time/timer.c
+++ b/kernel/time/timer.c
@@ -1875,6 +1875,7 @@ int timers_dead_cpu(unsigned int cpu)
 
 		BUG_ON(old_base->running_timer);
 
+		old_base->must_forward_clk = true;
 		for (i = 0; i < WHEEL_SIZE; i++)
 			migrate_timer_list(new_base, old_base->vectors + i);
 

Re: [PATCH] hrtimer: Reset hrtimer cpu base proper on CPU hotplug

[Thomas Gleixner]

On Mon, 29 Jan 2018, Paul E. McKenney wrote:

> On Mon, Jan 29, 2018 at 01:57:38AM -0800, Paul E. McKenney wrote:
> > On Mon, Jan 29, 2018 at 09:20:48AM +0100, Sebastian Sewior wrote:
> > > On 2018-01-26 14:09:17 [-0800], Paul E. McKenney wrote:
> > > > find this one.  ;-)  But it did pass rcutorture testing for a great many
> > > > years, didn't it?  :-/
> > > 
> > > It started to trigger better (or at all) on our test box with
> > > 	modprobe kvm_intel preemption_timer=n
> > > 
> > > on the host kernel so maybe a completely unrelated change helped to
> > > trigger this.
> > 
> > Good point!
> > 
> > And testing continues, currently at 108 hours of TREE01 without any
> > waylayed timers, so looking good!  ;-)
> > 
> > Just kicked off another 70 hours worth.
> 
> And those completed without incident for a total of 178 hours.  I believe
> we can call this one fixed.  Thank you all!!!
> 
> One question...  Is the patch shown below needed, or is this just yet
> another case of me being confused?  (The lack of it is not triggering,
> but...)

See commit 26456f87aca7

Re: [PATCH] hrtimer: Reset hrtimer cpu base proper on CPU hotplug

[Paul E. McKenney]

On Tue, Jan 30, 2018 at 10:03:17PM +0100, Thomas Gleixner wrote:
> On Mon, 29 Jan 2018, Paul E. McKenney wrote:
> 
> > On Mon, Jan 29, 2018 at 01:57:38AM -0800, Paul E. McKenney wrote:
> > > On Mon, Jan 29, 2018 at 09:20:48AM +0100, Sebastian Sewior wrote:
> > > > On 2018-01-26 14:09:17 [-0800], Paul E. McKenney wrote:
> > > > > find this one.  ;-)  But it did pass rcutorture testing for a great many
> > > > > years, didn't it?  :-/
> > > > 
> > > > It started to trigger better (or at all) on our test box with
> > > > 	modprobe kvm_intel preemption_timer=n
> > > > 
> > > > on the host kernel so maybe a completely unrelated change helped to
> > > > trigger this.
> > > 
> > > Good point!
> > > 
> > > And testing continues, currently at 108 hours of TREE01 without any
> > > waylayed timers, so looking good!  ;-)
> > > 
> > > Just kicked off another 70 hours worth.
> > 
> > And those completed without incident for a total of 178 hours.  I believe
> > we can call this one fixed.  Thank you all!!!
> > 
> > One question...  Is the patch shown below needed, or is this just yet
> > another case of me being confused?  (The lack of it is not triggering,
> > but...)
> 
> See commit 26456f87aca7

Got it, thank you!  I will remove my patch from my queue.

							Thanx, Paul

[tip:timers/urgent] hrtimer: Reset hrtimer cpu base proper on CPU hotplug

[tip-bot for Thomas Gleixner]

Commit-ID:  d5421ea43d30701e03cadc56a38854c36a8b4433
Gitweb:     https://git.kernel.org/tip/d5421ea43d30701e03cadc56a38854c36a8b4433
Author:     Thomas Gleixner <tglx@linutronix.de>
AuthorDate: Fri, 26 Jan 2018 14:54:32 +0100
Committer:  Thomas Gleixner <tglx@linutronix.de>
CommitDate: Sat, 27 Jan 2018 15:12:22 +0100

hrtimer: Reset hrtimer cpu base proper on CPU hotplug

The hrtimer interrupt code contains a hang detection and mitigation
mechanism, which prevents that a long delayed hrtimer interrupt causes a
continous retriggering of interrupts which prevent the system from making
progress. If a hang is detected then the timer hardware is programmed with
a certain delay into the future and a flag is set in the hrtimer cpu base
which prevents newly enqueued timers from reprogramming the timer hardware
prior to the chosen delay. The subsequent hrtimer interrupt after the delay
clears the flag and resumes normal operation.

If such a hang happens in the last hrtimer interrupt before a CPU is
unplugged then the hang_detected flag is set and stays that way when the
CPU is plugged in again. At that point the timer hardware is not armed and
it cannot be armed because the hang_detected flag is still active, so
nothing clears that flag. As a consequence the CPU does not receive hrtimer
interrupts and no timers expire on that CPU which results in RCU stalls and
other malfunctions.

Clear the flag along with some other less critical members of the hrtimer
cpu base to ensure starting from a clean state when a CPU is plugged in.

Thanks to Paul, Sebastian and Anna-Maria for their help to get down to the
root cause of that hard to reproduce heisenbug. Once understood it's
trivial and certainly justifies a brown paperbag.

Fixes: 41d2e4949377 ("hrtimer: Tune hrtimer_interrupt hang logic")
Reported-by: Paul E. McKenney <paulmck@linux.vnet.ibm.com>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
Cc: Peter Zijlstra <peterz@infradead.org>
Cc: Sebastian Sewior <bigeasy@linutronix.de>
Cc: Anna-Maria Gleixner <anna-maria@linutronix.de>
Cc: stable@vger.kernel.org
Link: https://lkml.kernel.org/r/alpine.DEB.2.20.1801261447590.2067@nanos

---
 kernel/time/hrtimer.c | 3 +++
 1 file changed, 3 insertions(+)

diff --git a/kernel/time/hrtimer.c b/kernel/time/hrtimer.c
index d325208..aa9d2a2b 100644
--- a/kernel/time/hrtimer.c
+++ b/kernel/time/hrtimer.c
@@ -655,7 +655,9 @@ static void hrtimer_reprogram(struct hrtimer *timer,
 static inline void hrtimer_init_hres(struct hrtimer_cpu_base *base)
 {
 	base->expires_next = KTIME_MAX;
+	base->hang_detected = 0;
 	base->hres_active = 0;
+	base->next_timer = NULL;
 }
 
 /*
@@ -1589,6 +1591,7 @@ int hrtimers_prepare_cpu(unsigned int cpu)
 		timerqueue_init_head(&cpu_base->clock_base[i].active);
 	}
 
+	cpu_base->active_bases = 0;
 	cpu_base->cpu = cpu;
 	hrtimer_init_hres(cpu_base);
 	return 0;