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

>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@novell.com>

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

From: Ingo Molnar <mingo@elte.hu>

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@elte.hu>
Signed-off-by: Thomas Gleixner <tglx@linutronix.de>

--- 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@lists.xensource.com
http://lists.xensource.com/xen-devel

On 11/12/2008 10:39, "Jan Beulich" <jbeulich@novell.com> wrote:
> 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()).
Sounds reasonable. Send a patch.

 -- Keir



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

* Jan Beulich <jbeulich@novell.com> wrote:
> >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.
note that we had to revert that eventually. The real solution is an array 
of fixes from Maciej spread out over many months.

	Ingo

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

On 12/12/2008 09:13, "Ingo Molnar" <mingo@elte.hu> wrote:
>>> 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.
> 
> note that we had to revert that eventually. The real solution is an array
> of fixes from Maciej spread out over many months.
Does it do more harm than good on some systems, or is it simply not a
comprehensive fix?

 -- Keir



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

* Keir Fraser <keir.fraser@eu.citrix.com> wrote:
> On 12/12/2008 09:13, "Ingo Molnar" <mingo@elte.hu> wrote:
> 
> >>> 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.
> > 
> > note that we had to revert that eventually. The real solution is an 
> > array of fixes from Maciej spread out over many months.
> 
> Does it do more harm than good on some systems, or is it simply not a 
> comprehensive fix?
more harm than good - fixes some, breaks others. Have a look at the 
latest upstream io_apic.c, that has it all settled down reasonably well.

	Ingo

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

On 12/12/2008 09:24, "Ingo Molnar" <mingo@elte.hu> wrote:
>>> note that we had to revert that eventually. The real solution is an
>>> array of fixes from Maciej spread out over many months.
>> 
>> Does it do more harm than good on some systems, or is it simply not a
>> comprehensive fix?
> 
> more harm than good - fixes some, breaks others. Have a look at the
> latest upstream io_apic.c, that has it all settled down reasonably well.
Thanks, Ingo.

Jan: Do you agree we should revert the io_apic.c changes, but keep your
addition of an explicit local_irq_enable() to __start_xen()?

 -- Keir



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

>>> Ingo Molnar <mingo@elte.hu> 12.12.08 10:13 >>>
>
>* Jan Beulich <jbeulich@novell.com> wrote:
>
>> >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.
>
>note that we had to revert that eventually. The real solution is an array 
>of fixes from Maciej spread out over many months.
What do you mean by ''eventually''? 2.6.28-rc8 still has this
code, and so
does -tip.

Confused, Jan


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

>>> Keir Fraser <keir.fraser@eu.citrix.com> 12.12.08 10:37
>>>
>On 12/12/2008 09:24, "Ingo Molnar" <mingo@elte.hu> wrote:
>
>>>> note that we had to revert that eventually. The real solution
is an
>>>> array of fixes from Maciej spread out over many months.
>>> 
>>> Does it do more harm than good on some systems, or is it simply not
a
>>> comprehensive fix?
>> 
>> more harm than good - fixes some, breaks others. Have a look at the
>> latest upstream io_apic.c, that has it all settled down reasonably
well.
>
>Thanks, Ingo.
>
>Jan: Do you agree we should revert the io_apic.c changes, but keep your
>addition of an explicit local_irq_enable() to __start_xen()?
No, please don''t until Ingo clarified his indication of this having got
reverted (see my other response to him). I really can''t see why
properly
enabling/disabling interrupts in that code could do any harm.

Jan


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

* Jan Beulich <jbeulich@novell.com> wrote:
> >>> Ingo Molnar <mingo@elte.hu> 12.12.08 10:13 >>>
> >
> >* Jan Beulich <jbeulich@novell.com> wrote:
> >
> >> >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.
> >
> >note that we had to revert that eventually. The real solution is an 
> >array of fixes from Maciej spread out over many months.
> 
> What do you mean by ''eventually''? 2.6.28-rc8 still has
this code, and
> so does -tip.
argh. Different io-apic breakage. I shouldnt remember patches by their 
subject lines ;-)

Sorry about the confusion - Jan is right and my fix ported to Xen is good 
;-)

the point about the other breakages remains: for the best bootup ratio 
you''ll want to pick up everything from the (now unified) 
arch/x86/kernel/io_apic.c.

	Ingo

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

On 12/12/2008 10:06, "Ingo Molnar" <mingo@elte.hu> wrote:
>>> note that we had to revert that eventually. The real solution is an
>>> array of fixes from Maciej spread out over many months.
>> 
>> What do you mean by ''eventually''? 2.6.28-rc8 still
has this code, and
>> so does -tip.
> 
> argh. Different io-apic breakage. I shouldnt remember patches by their
> subject lines ;-)
> 
> Sorry about the confusion - Jan is right and my fix ported to Xen is good
> ;-)
Ah, no worries. I was concerned we were about to descend into a start-of-day
interrupt breakage nightmare we haven''t seen in a long while!
> the point about the other breakages remains: for the best bootup ratio
> you''ll want to pick up everything from the (now unified)
> arch/x86/kernel/io_apic.c.
Yes, we haven''t done a sync with upstream in quite a while.

 Thanks,
 Keir



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