Re: Soft lockup regression from today's sched.git merge.

[Ingo Molnar <mingo@elte.hu>]

* David Miller <davem@davemloft.net> wrote:

> The following commit:
> 
> commit 27ec4407790d075c325e1f4da0a19c56953cce23
> Author: Ingo Molnar <mingo@elte.hu>
> Date:   Thu Feb 28 21:00:21 2008 +0100
> 
>     sched: make cpu_clock() globally synchronous
>     
>     Alexey Zaytsev reported (and bisected) that the introduction of
>     cpu_clock() in printk made the timestamps jump back and forth.
>     
>     Make cpu_clock() more reliable while still keeping it fast when it's
>     called frequently.
>     
>     Signed-off-by: Ingo Molnar <mingo@elte.hu>
> 
> causes watchdog triggers when a cpu exits NOHZ state when it has been 
> there for >= the soft lockup threshold, for example here are some 
> messages from a 128 cpu Niagara2 box:
> 
> [  168.106406] BUG: soft lockup - CPU#11 stuck for 128s! [dd:3239]
> [  168.989592] BUG: soft lockup - CPU#21 stuck for 86s! [swapper:0]
> [  168.999587] BUG: soft lockup - CPU#29 stuck for 91s! [make:4511]
> [  168.999615] BUG: soft lockup - CPU#2 stuck for 85s! [swapper:0]
> [  169.020514] BUG: soft lockup - CPU#37 stuck for 91s! [swapper:0]
> [  169.020514] BUG: soft lockup - CPU#45 stuck for 91s! [sh:4515]
> [  169.020515] BUG: soft lockup - CPU#69 stuck for 92s! [swapper:0]
> [  169.020515] BUG: soft lockup - CPU#77 stuck for 92s! [swapper:0]
> [  169.020515] BUG: soft lockup - CPU#61 stuck for 92s! [swapper:0]
> [  169.112554] BUG: soft lockup - CPU#85 stuck for 92s! [swapper:0]
> [  169.112554] BUG: soft lockup - CPU#101 stuck for 92s! [swapper:0]
> [  169.112554] BUG: soft lockup - CPU#109 stuck for 92s! [swapper:0]
> [  169.112554] BUG: soft lockup - CPU#117 stuck for 92s! [swapper:0]
> [  169.171483] BUG: soft lockup - CPU#40 stuck for 80s! [dd:3239]
> [  169.331483] BUG: soft lockup - CPU#13 stuck for 86s! [swapper:0]
> [  169.351500] BUG: soft lockup - CPU#43 stuck for 101s! [dd:3239]
> [  169.531482] BUG: soft lockup - CPU#9 stuck for 129s! [mkdir:4565]
> [  169.595754] BUG: soft lockup - CPU#20 stuck for 93s! [swapper:0]
> [  169.626787] BUG: soft lockup - CPU#52 stuck for 93s! [swapper:0]
> [  169.626787] BUG: soft lockup - CPU#84 stuck for 92s! [swapper:0]
> [  169.636812] BUG: soft lockup - CPU#116 stuck for 94s! [swapper:0]
> 
> It's simple enough to trigger this by doing a 10 minute sleep after a 
> fresh bootup then starting a parallel kernel build.
> 
> I suspect this might be reintroducing a problem we've had and fixed 
> before, see the thread:
> 
> http://marc.info/?l=linux-kernel&m=119546414004065&w=2

yeah, it looks very similar.

> Please have a look, thank you.

thanks for reporting it. I havent seen this false positive happen in a 
long time - but then again, PC CPUs are a lot less idle than a 128-CPU 
Niagara2 :-/ I'm wondering what the best method would be to provoke a 
CPU to stay idle that long - to make sure this bug is fixed.

so i only have the untested patch below for now - does it fix the bug 
for you?

	Ingo

----------------------------------->
Subject: softlockup: fix NOHZ wakeup
From: Ingo Molnar <mingo@elte.hu>

David Miller reported:

|--------------->
the following commit:

| commit 27ec4407790d075c325e1f4da0a19c56953cce23
| Author: Ingo Molnar <mingo@elte.hu>
| Date:   Thu Feb 28 21:00:21 2008 +0100
|
|     sched: make cpu_clock() globally synchronous
|
|     Alexey Zaytsev reported (and bisected) that the introduction of
|     cpu_clock() in printk made the timestamps jump back and forth.
|
|     Make cpu_clock() more reliable while still keeping it fast when it's
|     called frequently.
|
|     Signed-off-by: Ingo Molnar <mingo@elte.hu>

causes watchdog triggers when a cpu exits NOHZ state when it has been
there for >= the soft lockup threshold, for example here are some
messages from a 128 cpu Niagara2 box:

[  168.106406] BUG: soft lockup - CPU#11 stuck for 128s! [dd:3239]
[  168.989592] BUG: soft lockup - CPU#21 stuck for 86s! [swapper:0]
[  168.999587] BUG: soft lockup - CPU#29 stuck for 91s! [make:4511]
[  168.999615] BUG: soft lockup - CPU#2 stuck for 85s! [swapper:0]
[  169.020514] BUG: soft lockup - CPU#37 stuck for 91s! [swapper:0]
[  169.020514] BUG: soft lockup - CPU#45 stuck for 91s! [sh:4515]
[  169.020515] BUG: soft lockup - CPU#69 stuck for 92s! [swapper:0]
[  169.020515] BUG: soft lockup - CPU#77 stuck for 92s! [swapper:0]
[  169.020515] BUG: soft lockup - CPU#61 stuck for 92s! [swapper:0]
[  169.112554] BUG: soft lockup - CPU#85 stuck for 92s! [swapper:0]
[  169.112554] BUG: soft lockup - CPU#101 stuck for 92s! [swapper:0]
[  169.112554] BUG: soft lockup - CPU#109 stuck for 92s! [swapper:0]
[  169.112554] BUG: soft lockup - CPU#117 stuck for 92s! [swapper:0]
[  169.171483] BUG: soft lockup - CPU#40 stuck for 80s! [dd:3239]
[  169.331483] BUG: soft lockup - CPU#13 stuck for 86s! [swapper:0]
[  169.351500] BUG: soft lockup - CPU#43 stuck for 101s! [dd:3239]
[  169.531482] BUG: soft lockup - CPU#9 stuck for 129s! [mkdir:4565]
[  169.595754] BUG: soft lockup - CPU#20 stuck for 93s! [swapper:0]
[  169.626787] BUG: soft lockup - CPU#52 stuck for 93s! [swapper:0]
[  169.626787] BUG: soft lockup - CPU#84 stuck for 92s! [swapper:0]
[  169.636812] BUG: soft lockup - CPU#116 stuck for 94s! [swapper:0]

It's simple enough to trigger this by doing a 10 minute sleep after a
fresh bootup then starting a parallel kernel build.

I suspect this might be reintroducing a problem we've had and fixed
before, see the thread:

http://marc.info/?l=linux-kernel&m=119546414004065&w=2
<---------------|

touch the softlockup watchdog when exiting NOHZ state - we are
obviously not locked up.

Signed-off-by: Ingo Molnar <mingo@elte.hu>
---
 kernel/time/tick-sched.c |    1 +
 1 file changed, 1 insertion(+)

Index: linux/kernel/time/tick-sched.c
===================================================================
--- linux.orig/kernel/time/tick-sched.c
+++ linux/kernel/time/tick-sched.c
@@ -393,6 +393,7 @@ void tick_nohz_restart_sched_tick(void)
 		sub_preempt_count(HARDIRQ_OFFSET);
 	}
 
+	touch_softlockup_watchdog();
 	/*
 	 * Cancel the scheduled timer and restore the tick
 	 */