[Xen-devel] [PATCH] x86: fix the potential of encountering panic "IO-APIC + timer doesn't work! ..."

["Jan Beulich" <jbeulich@xxxxxxxxxx>]

>From all I can tell, the below reproduced full description of the
original Linux patch applies to Xen, too - at least in the watchdog
enabled case IRQs can be enabled when entering setup_IO_APIC(). My
attention to this change really got caught just by the fact that it got
added to our (2.6.16-based) SLE10 kernel pretty recently.

I modified it a little (mainly not using goto-s, but also restoring
interrupts a little earlier at the return points of check_timer()). And
it requires local_save_flags() added by a patch submitted a moment ago.

I have to admit that in addition I find it quite disturbing that there
is a dependency on the side effect of smp_prepare_cpus()
(check_nmi_watchdog() or until now setup_IO_APIC()) or init_xen_time()
(init_platform_timer() -> plt_overflow()) enabling interrupts: c/s 5604
removed the explicit local_irq_enable() from start_of_day() (which is
__start_xen() now), putting it into init_xen_time(). There it got
removed by c/s 18698, without an explicit replacement. I'd think there
should be an explicit local_irq_enable() in __start_xen() in any case,
and as early as reasonable (i.e. the latest before smp_prepare_cpus()).

Signed-off-by: Jan Beulich <jbeulich@xxxxxxxxxx>

Linux commit:
http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commitdiff;h=4aae07025265151e3f7041dfbf0f529e122de1d8
 

From: Ingo Molnar <mingo@xxxxxxx>

x86: fix "Kernel panic - not syncing: IO-APIC + timer doesn't work!"

this is the tale of a full day spent debugging an ancient but elusive bug.

after booting up thousands of random .config kernels, i finally happened
to generate a .config that produced the following rare bootup failure
on 32-bit x86:

| ..TIMER: vector=0x31 apic1=0 pin1=2 apic2=-1 pin2=-1
| ..MP-BIOS bug: 8254 timer not connected to IO-APIC
| ...trying to set up timer (IRQ0) through the 8259A ...  failed.
| ...trying to set up timer as Virtual Wire IRQ... failed.
| ...trying to set up timer as ExtINT IRQ... failed :(.
| Kernel panic - not syncing: IO-APIC + timer doesn't work!  Boot with 
apic=debug
| and send a report.  Then try booting with the 'noapic' option

this bug has been reported many times during the years, but it was never
reproduced nor fixed.

the bug that i hit was extremely sensitive to .config details.

First i did a .config-bisection - suspecting some .config detail.
That led to CONFIG_X86_MCE: enabling X86_MCE magically made the bug disappear
and the system would boot up just fine.

Debugging my way through the MCE code ended up identifying two unlikely
candidates: the thing that made a real difference to the hang was that
X86_MCE did two printks:

 Intel machine check architecture supported.
 Intel machine check reporting enabled on CPU#1.

Adding the same printks to a !CONFIG_X86_MCE kernel made the bug go away!

this left timing as the main suspect: i experimented with adding various
udelay()s to the arch/x86/kernel/io_apic_32.c:check_timer() function, and
the race window turned out to be narrower than 30 microseconds (!).

That made debugging especially funny, debugging without having printk
ability before the bug hits is ... interesting ;-)

eventually i started suspecting IRQ activities - those are pretty much the
only thing that happen this early during bootup and have the timescale of
a few dozen microseconds. Also, check_timer() changes the IRQ hardware
in various creative ways, so the main candidate became IRQ0 interaction.

i've added a counter to track timer irqs (on which core they arrived, at
what exact time, etc.) and found that no timer IRQ would arrive after the
bug condition hits - even if we re-enable IRQ0 and re-initialize the i8259A,
but that we'd get a small number of timer irqs right around the time when we
call the check_timer() function.

Eventually i got the following backtrace triggered from debug code in the
timer interrupt:

...trying to set up timer as Virtual Wire IRQ... failed.
...trying to set up timer as ExtINT IRQ...
Pid: 1, comm: swapper Not tainted (2.6.24-rc5 #57)
EIP: 0060:[<c044d57e>] EFLAGS: 00000246 CPU: 0
EIP is at _spin_unlock_irqrestore+0x5/0x1c
EAX: c0634178 EBX: 00000000 ECX: c4947d63 EDX: 00000246
ESI: 00000002 EDI: 00010031 EBP: c04e0f2e ESP: f7c41df4
 DS: 007b ES: 007b FS: 00d8 GS: 0000 SS: 0068
 CR0: 8005003b CR2: ffe04000 CR3: 00630000 CR4: 000006d0
 DR0: 00000000 DR1: 00000000 DR2: 00000000 DR3: 00000000
 DR6: ffff0ff0 DR7: 00000400
  [<c05f5784>] setup_IO_APIC+0x9c3/0xc5c

the spin_unlock() was called from init_8259A(). Wait ... we have an IRQ0
entry while we are in the middle of setting up the local APIC, the i8259A
and the PIT??

That is certainly not how it's supposed to work! check_timer() was supposed
to be called with irqs turned off - but this eroded away sometime in the
past. This code would still work most of the time because this code runs
very quickly, but just the right timing conditions are present and IRQ0
hits in this small, ~30 usecs window, timer irqs stop and the system does
not boot up. Also, given how early this is during bootup, the hang is
very deterministic - but it would only occur on certain machines (and
certain configs).

The fix was quite simple: disable/restore interrupts properly in this
function. With that in place the test-system now boots up just fine.

(64-bit x86 io_apic_64.c had the same bug.)

Phew! One down, only 1500 other kernel bugs are left ;-)

Signed-off-by: Ingo Molnar <mingo@xxxxxxx>
Signed-off-by: Thomas Gleixner <tglx@xxxxxxxxxxxxx>

--- 2008-11-20.orig/xen/arch/x86/io_apic.c      2008-11-20 08:47:52.000000000 
+0100
+++ 2008-11-20/xen/arch/x86/io_apic.c   2008-12-11 09:24:22.000000000 +0100
@@ -1257,14 +1257,16 @@ static void __init setup_ioapic_ids_from
 static int __init timer_irq_works(void)
 {
     extern unsigned long pit0_ticks;
-    unsigned long t1;
+    unsigned long t1, flags;
 
     t1 = pit0_ticks;
     mb();
 
+    local_save_flags(flags);
     local_irq_enable();
     /* Let ten ticks pass... */
     mdelay((10 * 1000) / HZ);
+    local_irq_restore(flags);
 
     /*
      * Expect a few ticks at least, to be sure some possible
@@ -1707,6 +1709,9 @@ static inline void check_timer(void)
 {
     int apic1, pin1, apic2, pin2;
     int vector;
+    unsigned long flags;
+
+    local_irq_save(flags);
 
     /*
      * get/set the timer IRQ vector:
@@ -1748,6 +1753,7 @@ static inline void check_timer(void)
          */
         unmask_IO_APIC_irq(0);
         if (timer_irq_works()) {
+            local_irq_restore(flags);
             if (disable_timer_pin_1 > 0)
                 clear_IO_APIC_pin(apic1, pin1);
             return;
@@ -1765,6 +1771,7 @@ static inline void check_timer(void)
          */
         setup_ExtINT_IRQ0_pin(apic2, pin2, vector);
         if (timer_irq_works()) {
+            local_irq_restore(flags);
             printk("works.\n");
             if (pin1 != -1)
                 replace_pin_at_irq(0, apic1, pin1, apic2, pin2);
@@ -1792,6 +1799,7 @@ static inline void check_timer(void)
     enable_8259A_irq(0);
 
     if (timer_irq_works()) {
+        local_irq_restore(flags);
         printk(" works.\n");
         return;
     }
@@ -1807,6 +1815,8 @@ static inline void check_timer(void)
 
     unlock_ExtINT_logic();
 
+    local_irq_restore(flags);
+
     if (timer_irq_works()) {
         printk(" works.\n");
         return;



_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxxxxxxxx
http://lists.xensource.com/xen-devel