Re: [Xen-devel] [xen-unstable test] 11946: regressions - FAIL

[Ian Campbell <Ian.Campbell@xxxxxxxxxx>]

On Tue, 2012-02-14 at 10:44 +0000, Ian Campbell wrote:
> On Mon, 2012-02-13 at 20:16 +0000, xen.org wrote:
> > flight 11946 xen-unstable real [real]
> > http://www.chiark.greenend.org.uk/~xensrcts/logs/11946/
> > 
> > Regressions :-(
> > 
> > Tests which did not succeed and are blocking,
> > including tests which could not be run:
> >  test-amd64-i386-xl-credit2    7 debian-install            fail REGR. vs. 
> > 11944
> 
> Host crash:
> http://www.chiark.greenend.org.uk/~xensrcts/logs/11946/test-amd64-i386-xl-credit2/serial-woodlouse.log
> 
> This is the debug Andrew Cooper added recently to track down the IRQ
> assertion we've been seeing, sadly it looks like the debug code tries to
> call xfree from interrupt context and therefore doesn't produce full
> output :-(

Are we still seeing the issue this debugging was intended to address? We
don't seem to be seeing the host crashes any more. Should the debug code
be patched up as in the following patch, otherwise when we do see it it
doesn't end up printing any useful info.

Someone recently reported bugs.debian.org/665433 to Debian, is this the
same underlying issue? That report is with Xen 4.0 FWIW.

> Or is 24675:d82a1e3d3c65 ("xsm: Add security label to IRQ debug output")
> at fault for adding the xfree in what may be an IRQ context? (are
> keyhandlers run in IRQ context?)
> 
> A skanky quick "fix" follows.
> 
>         Feb 13 17:17:29.777522 (XEN) *** IRQ BUG found ***
>         Feb 13 17:19:32.594539 (XEN) CPU0 -Testing vector 229 from bitmap 
> 34,48,57,64,72,75,80,83,88,97,104-105,113,120-121,129,136,144,152,160,168,176,184,192,202
>         Feb 13 17:19:32.617515 (XEN) Guest interrupt information:
>         Feb 13 17:19:32.617536 (XEN)    IRQ:   0 affinity:001 vec:f0 
> type=IO-APIC-edge    status=00000000 mapped, unbound
>         Feb 13 17:19:32.617567 (XEN) Assertion '!in_irq()' failed at 
> xmalloc_tlsf.c:607
>         Feb 13 17:19:32.626489 (XEN) ----[ Xen-4.2-unstable  x86_64  debug=y  
> Not tainted ]----
>         Feb 13 17:19:32.626512 (XEN) CPU:    0
>         Feb 13 17:19:32.626525 (XEN) RIP:    e008:[<ffff82c48012c842>] 
> xfree+0x33/0x121
>         Feb 13 17:19:32.641496 (XEN) RFLAGS: 0000000000010002   CONTEXT: 
> hypervisor
>         Feb 13 17:19:32.641519 (XEN) rax: ffff82c4802d0800   rbx: 
> ffff8301a7e00080   rcx: 0000000000000000
>         Feb 13 17:19:32.650560 (XEN) rdx: 0000000000000000   rsi: 
> 0000000000000083   rdi: 0000000000000000
>         Feb 13 17:19:32.665510 (XEN) rbp: ffff82c4802afd18   rsp: 
> ffff82c4802afcf8   r8:  0000000000000004
>         Feb 13 17:19:32.665550 (XEN) r9:  0000000000000000   r10: 
> 0000000000000006   r11: ffff82c480224aa0
>         Feb 13 17:19:32.673509 (XEN) r12: ffff8301a7e00580   r13: 
> 0000000000000005   r14: ffff82c4802aff18
>         Feb 13 17:19:32.685503 (XEN) r15: 0000000000000000   cr0: 
> 000000008005003b   cr4: 00000000000006f0
>         Feb 13 17:19:32.685537 (XEN) cr3: 00000001a7f54000   cr2: 
> 00000000c4b4ee84
>         Feb 13 17:19:32.697505 (XEN) ds: 007b   es: 007b   fs: 00d8   gs: 
> 0000   ss: 0000   cs: e008
>         Feb 13 17:19:32.697540 (XEN) Xen stack trace from 
> rsp=ffff82c4802afcf8:
>         Feb 13 17:19:32.706513 (XEN)    ffff8301a7e00080 ffff8301a7e00580 
> 0000000000000005 ffff82c4802aff18
>         Feb 13 17:19:32.721495 (XEN)    ffff82c4802afd88 ffff82c4801658ee 
> ffff82c4802afd38 ffff82c48010098a
>         Feb 13 17:19:32.721531 (XEN)    00000400802afd68 0000000000000083 
> ffff8301a7e000a8 0000000000000000
>         Feb 13 17:19:32.729495 (XEN)    00000000fffffffa 00000000000000e5 
> ffff8301a7e00580 0000000000000005
>         Feb 13 17:19:32.738490 (XEN)    ffff82c4802aff18 ffff8301a7e005a8 
> ffff82c4802afe28 ffff82c480167781
>         Feb 13 17:19:32.738515 (XEN)    ffff8301a7ece000 ffff82c4802afde8 
> 0000000000000000 ffff82c4802aff18
>         Feb 13 17:19:32.750497 (XEN)    ffff82c4802aff18 0000000000000002 
> ffff82c4802aff18 ffff82c4802fa060
>         Feb 13 17:19:32.762568 (XEN)    000000e500000000 ffff82c4802fa060 
> ffff82c4802afe08 ffff82c48017bd51
>         Feb 13 17:19:32.762596 (XEN)    ffff82c4802aff18 ffff82c4802aff18 
> ffff82c48025e380 ffff82c4802aff18
>         Feb 13 17:19:32.773513 (XEN)    00000000ffffffff 0000000000000002 
> 00007d3b7fd501a7 ffff82c4801525d0
>         Feb 13 17:19:32.785503 (XEN)    0000000000000002 00000000ffffffff 
> ffff82c4802aff18 ffff82c48025e380
>         Feb 13 17:19:32.785539 (XEN)    ffff82c4802afee0 ffff82c4802aff18 
> 0000001863058413 00000000000c0000
>         Feb 13 17:19:32.794514 (XEN)    000000000e1ff99c 000000000000c701 
> ffff82c4802f9a90 0000000000000000
>         Feb 13 17:19:32.809503 (XEN)    0000000000000000 ffff8301a7f5dc80 
> 0000000000000000 0000002000000000
>         Feb 13 17:19:32.809529 (XEN)    ffff82c4801581a9 000000000000e008 
> 0000000000000246 ffff82c4802afee0
>         Feb 13 17:19:32.814513 (XEN)    0000000000000000 ffff82c4802aff10 
> ffff82c48015a647 0000000000000000
>         Feb 13 17:19:32.829506 (XEN)    ffff8300d7cfb000 ffff8300d7af9000 
> 0000000000000000 ffff82c4802afd88
>         Feb 13 17:19:32.829549 (XEN)    0000000000000000 0000000000000000 
> 0000000000000000 0000000000000000
>         Feb 13 17:19:32.841510 (XEN)    00000000dfc91f90 00000000deadbeef 
> 0000000000000000 0000000000000000
>         Feb 13 17:19:32.853508 (XEN)    0000000000000000 0000000000000000 
> 0000000000000000 00000000deadbeef
>         Feb 13 17:19:32.858496 (XEN) Xen call trace:
>         Feb 13 17:19:32.858518 (XEN)    [<ffff82c48012c842>] xfree+0x33/0x121
>         Feb 13 17:19:32.858547 (XEN)    [<ffff82c4801658ee>] 
> dump_irqs+0x2a3/0x2ca
>         Feb 13 17:19:32.870500 (XEN)    [<ffff82c480167781>] 
> smp_irq_move_cleanup_interrupt+0x303/0x37b
>         Feb 13 17:19:32.870554 (XEN)    [<ffff82c4801525d0>] 
> irq_move_cleanup_interrupt+0x30/0x40
>         Feb 13 17:19:32.885510 (XEN)    [<ffff82c4801581a9>] 
> default_idle+0x99/0x9e
>         Feb 13 17:19:32.885541 (XEN)    [<ffff82c48015a647>] 
> idle_loop+0x6c/0x7c
>         Feb 13 17:19:32.897496 (XEN)    
>         Feb 13 17:19:32.897510 (XEN) 
>         Feb 13 17:19:32.897520 (XEN) ****************************************
>         Feb 13 17:19:32.897537 (XEN) Panic on CPU 0:
>         Feb 13 17:19:32.905499 (XEN) Assertion '!in_irq()' failed at 
> xmalloc_tlsf.c:607
>         Feb 13 17:19:32.905522 (XEN) ****************************************
>         Feb 13 17:19:32.913488 (XEN) 
>         Feb 13 17:19:32.913506 (XEN) Reboot in five seconds...
> 
> # HG changeset patch
> # User Ian Campbell <ian.campbell@xxxxxxxxxx>
> # Date 1329216241 0
> # Node ID 738424a5e5a5053c75cfbe64f6675b5d756daf1b
> # Parent  0ba87b95e80bae059fe70b4b117dcc409f2471ef
> xen: don't try to print IRQ SSID in IRQ debug from irq context.
> 
> It is not possible to call xfree() in that context.
> 
> Signed-off-by: Ian Campbell <ian.campbell@xxxxxxxxxx>
> 
> diff -r 0ba87b95e80b -r 738424a5e5a5 xen/arch/x86/irq.c
> --- a/xen/arch/x86/irq.c      Mon Feb 13 17:26:08 2012 +0000
> +++ b/xen/arch/x86/irq.c      Tue Feb 14 10:44:01 2012 +0000
> @@ -2026,7 +2026,7 @@ static void dump_irqs(unsigned char key)
>          if ( !irq_desc_initialized(desc) || desc->handler == &no_irq_type )
>              continue;
>  
> -        ssid = xsm_show_irq_sid(irq);
> +        ssid = in_irq() ? NULL : xsm_show_irq_sid(irq);
>  
>          spin_lock_irqsave(&desc->lock, flags);
>  
> @@ -2073,7 +2073,8 @@ static void dump_irqs(unsigned char key)
>  
>          spin_unlock_irqrestore(&desc->lock, flags);
>  
> -        xfree(ssid);
> +        if ( ssid )
> +                xfree(ssid);
>      }
>  
>      dump_ioapic_irq_info();
> 
> 
> 
> 
> _______________________________________________
> Xen-devel mailing list
> Xen-devel@xxxxxxxxxxxxxxxxxxx
> http://lists.xensource.com/xen-devel



_______________________________________________
Xen-devel mailing list
Xen-devel@xxxxxxxxxxxxx
http://lists.xen.org/xen-devel