Bisected oops regression between v3.7-rc8 and v3.7: nmi_watchdog

Hello,

I was a bit surprised by v3.7 hanging "all the time", usually just freezing but sometimes with a stack dump pointing to timerqueue_del calling rb_erase and oopsing there. Of course I could never make it dump anything when prepared to capture it via netconsole, so the best I have is this picture: http://www.mork.no/~bjorn/20121213_203557.jpg

I discovered that the freeze was related to plugging AC power and started bisecting from v3.7-rc3, which I had been running for quite a while and therefore was confident did not have this problem. The bisect log ended up as this:

bjorn@canardo:/usr/local/src/build-tmp/linux$ git bisect log
# bad: [29594404d7fe73cd80eaa4ee8c43dcc53970c60e] Linux 3.7
# good: [8f0d8163b50e01f398b14bcd4dc039ac5ab18d64] Linux 3.7-rc3
git bisect start 'v3.7' 'v3.7-rc3'
# good: [29282fde80d44e587f8c152b10049a56e61659f0] KVM: x86: Fix invalid secondary exec controls in vmx_cpuid_update()
git bisect good 29282fde80d44e587f8c152b10049a56e61659f0
# good: [2654ad44b5f7a5f1b12d722a37d9b9df69d57899] Merge branch 'x86-urgent-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect good 2654ad44b5f7a5f1b12d722a37d9b9df69d57899
# good: [086486e46e4206cfa1140fb9682ad67c8a4502fb] Merge branch 'for-linus' of git://git.samba.org/sfrench/cifs-2.6
git bisect good 086486e46e4206cfa1140fb9682ad67c8a4502fb
# good: [25a3bc6bd1ca03ab504b8c55c98f8d0135644d53] [parisc] open(2) compat bug
git bisect good 25a3bc6bd1ca03ab504b8c55c98f8d0135644d53
# bad: [cfd1f032f98e5ab3a04f23a0adbd53ff8744827d] Merge branch 'core-urgent-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/tip
git bisect bad cfd1f032f98e5ab3a04f23a0adbd53ff8744827d
# good: [b69f0859dc8e633c5d8c06845811588fe17e68b3] Linux 3.7-rc8
git bisect good b69f0859dc8e633c5d8c06845811588fe17e68b3
# good: [ca50496eb487b639de1f502e77a48dde84152fb9] Merge branch 'for-3.7-fixes' of git://git.kernel.org/pub/scm/linux/kernel/git/tj/wq
git bisect good ca50496eb487b639de1f502e77a48dde84152fb9
# good: [70dcc535bdf30ffaef58b867fbde45c0287f34c6] Merge tag 'upstream-3.7-rc9' of git://git.infradead.org/linux-ubi
git bisect good 70dcc535bdf30ffaef58b867fbde45c0287f34c6
# good: [df2fc246c8ee8b6067af1fa55d3bc23107457f61] Merge branch 'fixes' of git://git.kernel.org/pub/scm/linux/kernel/git/rusty/linux
git bisect good df2fc246c8ee8b6067af1fa55d3bc23107457f61
# bad: [8d4516904b39507458bee8115793528e12b1d8dd] watchdog: Fix CPU hotplug regression
git bisect bad 8d4516904b39507458bee8115793528e12b1d8dd

and I can confirm that reverting 8d451690 does fix the problem. After having found this, it became clearer to me why the freeze was related to plugging AC power: I use laptop-mode-tools in its default Debian configuration, which will disable the nmi_watchdog on battery power and enable it on AC power.

So the simple test case which will hang my (and presumably also your) PC on plain v3.7 is:

echo 0 > /proc/sys/kernel/nmi_watchdog
echo 1 > /proc/sys/kernel/nmi_watchdog

without any cmdline nmi_watchdog parameters, i.e. enabled.

I'll followup with a proposed revert patch, but I guess you will want to come up with something which fixes the original problem as well. But given the serious effect of the bug, causing a 100% reproducable freeze on a standard distro laptop setup, I hope that the revert will go into v3.7.1 unless a real fix can be prepared in time.

Thanks,
Bjørn

This reverts commit 8d4516904b39507458bee8115793528e12b1d8dd.

commit 8d451690 ("watchdog: Fix CPU hotplug regression") cause a hard lockup when I connect AC power on my laptop. The indirect reason is that laptop-mode-tools is configured to do

echo 0 > /proc/sys/kernel/nmi_watchdog

when AC power is disconnected and

echo 1 > /proc/sys/kernel/nmi_watchdog

when AC power is connected. This is the default configuration of the Debian laptop-mode-tools package.

---
 kernel/watchdog.c |    3 ---
 1 files changed, 0 insertions(+), 3 deletions(-)

index c8c21be..dd4b80a 100644
@@ -368,9 +368,6 @@ static void watchdog_disable(unsigned int cpu)
 {
 	struct hrtimer *hrtimer = &__raw_get_cpu_var(watchdog_hrtimer);
 
-	if (!watchdog_enabled)
-		return;
-
 	watchdog_set_prio(SCHED_NORMAL, 0);
 	hrtimer_cancel(hrtimer);
 	/* disable the perf event */

1.7.2.5

commit 8d451690 ("watchdog: Fix CPU hotplug regression") cause an oops or hard lockup when doing

echo 0 > /proc/sys/kernel/nmi_watchdog
echo 1 > /proc/sys/kernel/nmi_watchdog

and the kernel is booted with nmi_watchdog=1 (default)

Running laptop-mode-tools and disconnecting/connecting AC power will cause this to trigger, making it a common failure scenario on laptops.

Instead of bailing out of watchdog_disable() when !watchdog_enabled we can initialize the hrtimer regardless of watchdog_enabled status. This makes it safe to call watchdog_disable() in the nmi_watchdog=0 case, without the negative effect on the enabled => disabled => enabled case.

All these tests pass with this patch:
- nmi_watchdog=1
echo 0 > /proc/sys/kernel/nmi_watchdog
echo 1 > /proc/sys/kernel/nmi_watchdog

- nmi_watchdog=0
echo 0 > /sys/devices/system/cpu/cpu1/online

- nmi_watchdog=0
echo mem > /sys/power/state

---
v2:
implemented an alternate workaround for the original problem.

Hello Thomas,

I will not claim to understand this code, but it seemed to me like the original problem was caused by the missing initialization of the hrtimer in the disabled case. Calling hrtimer_cancel() on an initialized timer not running should be perfectly OK. And watchdog_nmi_disable() will not do anything unless the event is initialized. So this patch looks like a fix.

Bjørn

 kernel/watchdog.c |   11 ++++-------
 1 files changed, 4 insertions(+), 7 deletions(-)

index c8c21be..762081c 100644
@@ -343,6 +343,10 @@ static void watchdog_enable(unsigned int cpu)
 {
 	struct hrtimer *hrtimer = &__raw_get_cpu_var(watchdog_hrtimer);
 
+	/* kick off the timer for the hardlockup detector */
+	hrtimer_init(hrtimer, CLOCK_MONOTONIC, HRTIMER_MODE_REL);
+	hrtimer->function = watchdog_timer_fn;
+
 	if (!watchdog_enabled) {
 		kthread_park(current);
 		return;

@@ -351,10 +355,6 @@ static void watchdog_enable(unsigned int cpu)
 	/* Enable the perf event */
 	watchdog_nmi_enable(cpu);
 
-	/* kick off the timer for the hardlockup detector */
-	hrtimer_init(hrtimer, CLOCK_MONOTONIC, HRTIMER_MODE_REL);
-	hrtimer->function = watchdog_timer_fn;
-
 	/* done here because hrtimer_start can only pin to smp_processor_id() */
 	hrtimer_start(hrtimer, ns_to_ktime(get_sample_period()),
 		      HRTIMER_MODE_REL_PINNED);

@@ -368,9 +368,6 @@ static void watchdog_disable(unsigned int cpu)
 {
 	struct hrtimer *hrtimer = &__raw_get_cpu_var(watchdog_hrtimer);
 
-	if (!watchdog_enabled)
-		return;
-
 	watchdog_set_prio(SCHED_NORMAL, 0);
 	hrtimer_cancel(hrtimer);
 	/* disable the perf event */

1.7.2.5

Confirm similar behaviour (I didn't do bisection): kernel sometimes opps when plug in AC adapter.

Regards

Maciej Rutecki
http://www.mrutecki.pl

commit 8d451690 ("watchdog: Fix CPU hotplug regression") cause an oops or hard lockup when doing

echo 0 > /proc/sys/kernel/nmi_watchdog
echo 1 > /proc/sys/kernel/nmi_watchdog

and the kernel is booted with nmi_watchdog=1 (default)

Running laptop-mode-tools and disconnecting/connecting AC power will cause this to trigger, making it a common failure scenario on laptops.

Instead of bailing out of watchdog_disable() when !watchdog_enabled we can initialize the hrtimer regardless of watchdog_enabled status. This makes it safe to call watchdog_disable() in the nmi_watchdog=0 case, without the negative effect on the enabled => disabled => enabled case.

All these tests pass with this patch:
- nmi_watchdog=1
echo 0 > /proc/sys/kernel/nmi_watchdog
echo 1 > /proc/sys/kernel/nmi_watchdog

- nmi_watchdog=0
echo 0 > /sys/devices/system/cpu/cpu1/online

- nmi_watchdog=0
echo mem > /sys/power/state

Bugzilla: https://bugzilla.kernel.org/show_bug.cgi?id=51661

---
v3:
added Bugzilla reference and additional recipients rebased on current mainline
v2:
implemented an alternate workaround for the original problem.

Hello,

Sorry for nagging, but this patch or some other fix should be applied to mainline ASAP so it can be included in the 3.7 stable series. 3.7.0 and 3.7.1 dies when plugging AC power on a large number of laptop systems.

I will not claim to understand this code, but it seemed to me like the original problem was caused by the missing initialization of the hrtimer in the disabled case. Calling hrtimer_cancel() on an initialized timer not running should be perfectly OK. And watchdog_nmi_disable() will not do anything unless the event is initialized. So this patch looks like a fix.

At least it survives both the original test cases and the post v3.7-rc8 regression test case.

Bjørn

 kernel/watchdog.c |   11 ++++-------
 1 file changed, 4 insertions(+), 7 deletions(-)

index 997c6a1..75a2ab3 100644
@@ -344,6 +344,10 @@ static void watchdog_enable(unsigned int cpu)
 {
 	struct hrtimer *hrtimer = &__raw_get_cpu_var(watchdog_hrtimer);
 
+	/* kick off the timer for the hardlockup detector */
+	hrtimer_init(hrtimer, CLOCK_MONOTONIC, HRTIMER_MODE_REL);
+	hrtimer->function = watchdog_timer_fn;
+
 	if (!watchdog_enabled) {
 		kthread_park(current);
 		return;

@@ -352,10 +356,6 @@ static void watchdog_enable(unsigned int cpu)
 	/* Enable the perf event */
 	watchdog_nmi_enable(cpu);
 
-	/* kick off the timer for the hardlockup detector */
-	hrtimer_init(hrtimer, CLOCK_MONOTONIC, HRTIMER_MODE_REL);
-	hrtimer->function = watchdog_timer_fn;
-
 	/* done here because hrtimer_start can only pin to smp_processor_id() */
 	hrtimer_start(hrtimer, ns_to_ktime(sample_period),
 		      HRTIMER_MODE_REL_PINNED);

@@ -369,9 +369,6 @@ static void watchdog_disable(unsigned int cpu)
 {
 	struct hrtimer *hrtimer = &__raw_get_cpu_var(watchdog_hrtimer);
 
-	if (!watchdog_enabled)
-		return;
-
 	watchdog_set_prio(SCHED_NORMAL, 0);
 	hrtimer_cancel(hrtimer);
 	/* disable the perf event */

1.7.10.4

commit 8d451690 ("watchdog: Fix CPU hotplug regression") cause an oops or hard lockup when doing

echo 0 > /proc/sys/kernel/nmi_watchdog
echo 1 > /proc/sys/kernel/nmi_watchdog

and the kernel is booted with nmi_watchdog=1 (default)

Running laptop-mode-tools and disconnecting/connecting AC power will cause this to trigger, making it a common failure scenario on laptops.

Instead of bailing out of watchdog_disable() when !watchdog_enabled we can initialize the hrtimer regardless of watchdog_enabled status. This makes it safe to call watchdog_disable() in the nmi_watchdog=0 case, without the negative effect on the enabled => disabled => enabled case.

All these tests pass with this patch:
- nmi_watchdog=1
echo 0 > /proc/sys/kernel/nmi_watchdog
echo 1 > /proc/sys/kernel/nmi_watchdog

- nmi_watchdog=0
echo 0 > /sys/devices/system/cpu/cpu1/online

- nmi_watchdog=0
echo mem > /sys/power/state

Bugzilla: https://bugzilla.kernel.org/show_bug.cgi?id=51661

---
Hello Linus,

This post v3.7-rc8 regression kills any machine with laptop-mode-tools using default config, making it somewhat critical to get a fix into the v3.7.x stable series ASAP. I was hoping for some response from Thomas or the reporters of the original bug, either verifying that my proposal is OK or providing a better fix. But I believe that this cannot wait much longer.

Please apply. Thanks,

Bjørn

Patch history:

v3:
added Bugzilla reference and additional recipients rebased on current mainline
v2:
implemented an alternate workaround for the original problem.
v1:
plain revert of 8d451690

 kernel/watchdog.c |   11 ++++-------
 1 file changed, 4 insertions(+), 7 deletions(-)

index 997c6a1..75a2ab3 100644
@@ -344,6 +344,10 @@ static void watchdog_enable(unsigned int cpu)
 {
 	struct hrtimer *hrtimer = &__raw_get_cpu_var(watchdog_hrtimer);
 
+	/* kick off the timer for the hardlockup detector */
+	hrtimer_init(hrtimer, CLOCK_MONOTONIC, HRTIMER_MODE_REL);
+	hrtimer->function = watchdog_timer_fn;
+
 	if (!watchdog_enabled) {
 		kthread_park(current);
 		return;

@@ -352,10 +356,6 @@ static void watchdog_enable(unsigned int cpu)
 	/* Enable the perf event */
 	watchdog_nmi_enable(cpu);
 
-	/* kick off the timer for the hardlockup detector */
-	hrtimer_init(hrtimer, CLOCK_MONOTONIC, HRTIMER_MODE_REL);
-	hrtimer->function = watchdog_timer_fn;
-
 	/* done here because hrtimer_start can only pin to smp_processor_id() */
 	hrtimer_start(hrtimer, ns_to_ktime(sample_period),
 		      HRTIMER_MODE_REL_PINNED);

@@ -369,9 +369,6 @@ static void watchdog_disable(unsigned int cpu)
 {
 	struct hrtimer *hrtimer = &__raw_get_cpu_var(watchdog_hrtimer);
 
-	if (!watchdog_enabled)
-		return;
-
 	watchdog_set_prio(SCHED_NORMAL, 0);
 	hrtimer_cancel(hrtimer);
 	/* disable the perf event */

1.7.10.4

What about the opposite cases?
nmi_watchdog=1
echo 1 > /sys/devices/system/cpu/cpu1/online

Are we going to leak memory by re-initing hrtimer? Or is that caught somewhere?

Other than that, the patch seems reasonable to me. Basically just forcing the init of hrtimer so there is something to cancel on the disable side. Then again, I don't fully understand the original problem.

Cheers,
Don

I don't see why not. But verifying it would be nice. I thought that it would be a simple thing to test using qemu-kvm, but it seems that the CPU hotplugging support there isn't quite ready. The guest just dies with "Assertion `bus->allow_hotplug' failed."

I'll go digging for alternatives, but if anyone else could verify this then I'd appreciate it.

There are no allocations in hrtimer_init() AFAICS? It just initializes the preallocated hrtimer struct.

I believe the original problem was calling hrtimer_cancel on an uninitialized hrtimer. That is likely to blow up here:

static inline
void unlock_hrtimer_base(const struct hrtimer *timer, unsigned long *flags)

{
        raw_spin_unlock_irqrestore(&timer->base->cpu_base->lock, *flags);
}

Note that the lock_hrtimer_base() function protects access to timer->base with a NULL test. That should probably be done in unlock as well, for symmetry? But this is another issue and not at all urgent.

Bjørn

I just realized that you might not really want/need hotplugging, but just booting with some cores initially offline?

That's easier to test at least:

qmitest:~# cat /proc/cmdline 
initrd=/initrd.img.test root=/dev/sda1 ro console=tty0 console=ttyS0,9600n8 maxcpus=1 BOOT_IMAGE=/vmlinuz.test 
qmitest:~#  grep . /sys/devices/system/cpu/o*line
/sys/devices/system/cpu/offline:1-3
/sys/devices/system/cpu/online:0
qmitest:~# grep . /sys/devices/system/cpu/cpu?/online 
/sys/devices/system/cpu/cpu1/online:0
/sys/devices/system/cpu/cpu2/online:0
/sys/devices/system/cpu/cpu3/online:0
qmitest:~# grep . /sys/devices/system/cpu/o*line
/sys/devices/system/cpu/offline:1-3
/sys/devices/system/cpu/online:0
qmitest:~# grep . /proc/sys/kernel/nmi_watchdog 
1

qmitest:~#  echo 1 > /sys/devices/system/cpu/cpu1/online
qmitest:~#  echo 1 > /sys/devices/system/cpu/cpu2/online
qmitest:~# grep . /sys/devices/system/cpu/cpu?/online 
/sys/devices/system/cpu/cpu1/online:1
/sys/devices/system/cpu/cpu2/online:1
/sys/devices/system/cpu/cpu3/online:0

No problem observed. As expected.

Bjørn

Actually, I did a poor job explaining myself but your previous email answered my question.

The original problem was that hrtimer_cancel was being called on an un-initialized object. I was wondering what happens if watchdog_enable was called multiple times, would it re-initialize a new object causing a memory leak?

But as you pointed out that couldn't happen.

So I am fine with your changes. Thanks for the initial and follow up testing.