thr3ads.net - Xen devel - (XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq == pirq'' failed at vmsi.c [Aug 2013]

If this information is useful, please help other people find it:
Share via:

Sander Eikelenboom

2013-Aug-23 12:34 UTC

(XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq == pirq'' failed at vmsi.c

Hi Jan,

Starting a new thread for this sub-problem.

After manually adding the iommu mapping for the southbridge ioapic,
passthrough seems to work fine for all devices accept one usb-controller which
enables MSI-x.

It fails the ''entry->pirq == pirq'' assertion in function
msixtbl_pt_register.

I have put some extra printk''s around there:

@@ -431,14 +439,36 @@ int msixtbl_pt_register(struct domain *d, struct pirq
*pirq, uint64_t gtable)
     spin_lock(&d->arch.hvm_domain.msixtbl_list_lock);

     list_for_each_entry( entry, &d->arch.hvm_domain.msixtbl_list, list )
-        if ( pdev == entry->pdev )
+        if ( pdev == entry->pdev ){
+           printk(XENLOG_WARNING "SEIK - msixtbl_pt_register "
+                   " [%04x:%02x:%02x.%01x] pdev == entry->pdev, no need
to add_msixtbl_entry ?? \n",
+                  entry->pdev->seg, entry->pdev->bus,
+                   PCI_SLOT(entry->pdev->devfn),
+                   PCI_FUNC(entry->pdev->devfn));
             goto found;
+       }

     entry = new_entry;
     new_entry = NULL;
     add_msixtbl_entry(d, pdev, gtable, entry, pirq);

 found:
+    printk(XENLOG_WARNING "SEIK - msixtbl_pt_register "
+                   " [%04x:%02x:%02x.%01x] entry_pirq:%d entry_evtchn:%#x
masked:%d  || pirq:%d evtchn:%#x masked:%d\n",
+                  entry->pdev->seg, entry->pdev->bus,
+                   PCI_SLOT(entry->pdev->devfn),
+                  
PCI_FUNC(entry->pdev->devfn),entry->pirq->pirq,entry->pirq->evtchn,entry->pirq->masked,pirq->pirq,pirq->evtchn,pirq->masked);
+
     ASSERT(entry->pirq == pirq);
     atomic_inc(&entry->refcnt);
     spin_unlock(&d->arch.hvm_domain.msixtbl_list_lock);



Which results in:


(XEN) [2013-08-23 12:23:06] AMD-Vi: Share p2m table with iommu: p2m table =
0x5445a1
[  169.027745] device vif1.0 entered promiscuous mode
[  169.268879] device vif1.0-emu entered promiscuous mode
[  169.282945] xen_bridge: port 2(vif1.0-emu) entered forwarding state
[  169.293694] xen_bridge: port 2(vif1.0-emu) entered forwarding state
[  169.517510] pciback 0000:04:00.0: restoring config space at offset 0x3c (was
0x100, writing 0x10a)
[  169.530863] pciback 0000:04:00.0: restoring config space at offset 0x10 (was
0x4, writing 0xf97fe004)
[  169.543245] pciback 0000:04:00.0: restoring config space at offset 0xc (was
0x0, writing 0x10)
(XEN) [2013-08-23 12:23:07] io.c:280: d1: bind: m_gsi=40 g_gsi=36 device=5
intx=0
(XEN) [2013-08-23 12:23:07] AMD-Vi: Disable: device id = 0x400, domain = 0,
paging mode = 3
(XEN) [2013-08-23 12:23:07] AMD-Vi: Setup I/O page table: device id = 0
(0004:00:00.1024), root table = 0x5445a1000, domain = 1, paging mode = 4
(XEN) [2013-08-23 12:23:07] AMD-Vi: Re-assign 0000:04:00.0 from dom0 to dom1
[  169.570282] xen-pciback: vpci: 0000:04:00.0: assign to virtual slot 0
(XEN) [2013-08-23 12:23:07] HVM1: HVM Loader
(XEN) [2013-08-23 12:23:07] HVM1: Detected Xen v4.4-unstable
(XEN) [2013-08-23 12:23:07] HVM1: Xenbus rings @0xfeffc000, event channel 6
(XEN) [2013-08-23 12:23:07] HVM1: System requested SeaBIOS
(XEN) [2013-08-23 12:23:07] HVM1: CPU speed is 3200 MHz
(XEN) [2013-08-23 12:23:07] HVM1: Relocating guest memory for lowmem MMIO space
disabled
(XEN) [2013-08-23 12:23:07] irq.c:270: Dom1 PCI link 0 changed 0 -> 5
(XEN) [2013-08-23 12:23:07] HVM1: PCI-ISA link 0 routed to IRQ5
(XEN) [2013-08-23 12:23:07] irq.c:270: Dom1 PCI link 1 changed 0 -> 10
(XEN) [2013-08-23 12:23:07] HVM1: PCI-ISA link 1 routed to IRQ10
(XEN) [2013-08-23 12:23:07] irq.c:270: Dom1 PCI link 2 changed 0 -> 11
(XEN) [2013-08-23 12:23:07] HVM1: PCI-ISA link 2 routed to IRQ11
(XEN) [2013-08-23 12:23:07] irq.c:270: Dom1 PCI link 3 changed 0 -> 5
(XEN) [2013-08-23 12:23:07] HVM1: PCI-ISA link 3 routed to IRQ5
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 01:3 INTA->IRQ10
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 03:0 INTA->IRQ5
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 04:0 INTA->IRQ5
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 05:0 INTA->IRQ10
(XEN) [2013-08-23 12:23:07] HVM1: No RAM in high memory; setting high_mem
resource base to 100000000
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 02:0 bar 10 size 002000000: 0f0000008
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 03:0 bar 14 size 001000000: 0f2000008
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 04:0 bar 10 size 000020000: 0f3000000
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 04:0 bar 30 size 000020000: 0f3020000
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 02:0 bar 30 size 000010000: 0f3040000
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 05:0 bar 10 size 000002000: 0f3050004
(XEN) [2013-08-23 12:23:07] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 02:0 bar 14 size 000001000: 0f3052000
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 03:0 bar 10 size 000000100: 00000c001
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 04:0 bar 14 size 000000040: 00000c101
(XEN) [2013-08-23 12:23:07] HVM1: pci dev 01:1 bar 20 size 000000010: 00000c141
(XEN) [2013-08-23 12:23:07] HVM1: Multiprocessor initialisation:
(XEN) [2013-08-23 12:23:07] HVM1:  - CPU0 ... 48-bit phys ... fixed MTRRs ...
var MTRRs [2/8] ... done.
(XEN) [2013-08-23 12:23:07] HVM1:  - CPU1 ... 48-bit phys ... fixed MTRRs ...
var MTRRs [2/8] ... done.
(XEN) [2013-08-23 12:23:07] HVM1:  - CPU2 ... 48-bit phys ... fixed MTRRs ...
var MTRRs [2/8] ... done.
(XEN) [2013-08-23 12:23:07] HVM1:  - CPU3 ... 48-bit phys ... fixed MTRRs ...
var MTRRs [2/8] ... done.
(XEN) [2013-08-23 12:23:07] HVM1: Testing HVM environment:
(XEN) [2013-08-23 12:23:07] HVM1:  - REP INSB across page boundaries ... passed
(XEN) [2013-08-23 12:23:07] HVM1:  - GS base MSRs and SWAPGS ... passed
(XEN) [2013-08-23 12:23:07] HVM1: Passed 2 of 2 tests
(XEN) [2013-08-23 12:23:07] HVM1: Writing SMBIOS tables ...
(XEN) [2013-08-23 12:23:07] HVM1: Loading SeaBIOS ...
(XEN) [2013-08-23 12:23:07] HVM1: Creating MP tables ...
(XEN) [2013-08-23 12:23:07] HVM1: Loading ACPI ...
(XEN) [2013-08-23 12:23:07] HVM1: vm86 TSS at fc00a100
(XEN) [2013-08-23 12:23:07] HVM1: BIOS map:
(XEN) [2013-08-23 12:23:07] HVM1:  10000-100d3: Scratch space
(XEN) [2013-08-23 12:23:07] HVM1:  e0000-fffff: Main BIOS
(XEN) [2013-08-23 12:23:07] HVM1: E820 table:
(XEN) [2013-08-23 12:23:07] HVM1:  [00]: 00000000:00000000 - 00000000:000a0000:
RAM
(XEN) [2013-08-23 12:23:07] HVM1:  HOLE: 00000000:000a0000 - 00000000:000e0000
(XEN) [2013-08-23 12:23:07] HVM1:  [01]: 00000000:000e0000 - 00000000:00100000:
RESERVED
(XEN) [2013-08-23 12:23:07] HVM1:  [02]: 00000000:00100000 - 00000000:3f800000:
RAM
(XEN) [2013-08-23 12:23:07] HVM1:  HOLE: 00000000:3f800000 - 00000000:fc000000
(XEN) [2013-08-23 12:23:07] HVM1:  [03]: 00000000:fc000000 - 00000001:00000000:
RESERVED
(XEN) [2013-08-23 12:23:07] HVM1: Invoking SeaBIOS ...
(XEN) [2013-08-23 12:23:07] HVM1: SeaBIOS (version
rel-1.7.1-3-g3a28511-20130822_222210-serveerstertje)
(XEN) [2013-08-23 12:23:07] HVM1: 
(XEN) [2013-08-23 12:23:07] HVM1: Found Xen hypervisor signature at 40000000
(XEN) [2013-08-23 12:23:07] HVM1: xen: copy e820...
(XEN) [2013-08-23 12:23:07] HVM1: Ram Size=0x3f800000 (0x0000000000000000 high)
(XEN) [2013-08-23 12:23:07] HVM1: Relocating low data from 0x000e42d0 to
0x000ef790 (size 2153)
(XEN) [2013-08-23 12:23:07] HVM1: Relocating init from 0x000e4b39 to 0x3f7e2e80
(size 53335)
(XEN) [2013-08-23 12:23:07] HVM1: CPU Mhz=3200
(XEN) [2013-08-23 12:23:07] HVM1: Found 8 PCI devices (max PCI bus is 00)
(XEN) [2013-08-23 12:23:07] HVM1: Allocated Xen hypercall page at 3f7ff000
(XEN) [2013-08-23 12:23:07] HVM1: Detected Xen v4.4-unstable
(XEN) [2013-08-23 12:23:07] HVM1: xen: copy BIOS tables...
(XEN) [2013-08-23 12:23:07] HVM1: Copying SMBIOS entry point from 0x00010010 to
0x000fdbd0
(XEN) [2013-08-23 12:23:07] HVM1: Copying MPTABLE from 0xfc0011b0/fc0011c0 to
0x000fdab0
(XEN) [2013-08-23 12:23:07] HVM1: Copying PIR from 0x00010030 to 0x000fda30
(XEN) [2013-08-23 12:23:07] HVM1: Copying ACPI RSDP from 0x000100b0 to
0x000fda00
(XEN) [2013-08-23 12:23:07] HVM1: Scan for VGA option rom
(XEN) [2013-08-23 12:23:07] HVM1: Running option rom at c000:0003
(XEN) [2013-08-23 12:23:07] stdvga.c:147:d1 entering stdvga and caching modes
(XEN) [2013-08-23 12:23:07] HVM1: Turning on vga text mode console
(XEN) [2013-08-23 12:23:07] HVM1: SeaBIOS (version
rel-1.7.1-3-g3a28511-20130822_222210-serveerstertje)
(XEN) [2013-08-23 12:23:07] HVM1: 
(XEN) [2013-08-23 12:23:07] HVM1: Found 1 lpt ports
(XEN) [2013-08-23 12:23:07] HVM1: Found 1 serial ports
(XEN) [2013-08-23 12:23:07] HVM1: ATA controller 1 at 1f0/3f4/c140 (irq 14 dev
9)
(XEN) [2013-08-23 12:23:07] HVM1: ATA controller 2 at 170/374/c148 (irq 15 dev
9)
(XEN) [2013-08-23 12:23:07] HVM1: ata0-0: QEMU HARDDISK ATA-7 Hard-Disk (10240
MiBytes)
(XEN) [2013-08-23 12:23:07] HVM1: Searching bootorder for:
/pci@i0cf8/*@1,1/drive@0/disk@0
(XEN) [2013-08-23 12:23:07] HVM1: ata0-1: QEMU HARDDISK ATA-7 Hard-Disk (300
GiBytes)
(XEN) [2013-08-23 12:23:07] HVM1: Searching bootorder for:
/pci@i0cf8/*@1,1/drive@0/disk@1
(XEN) [2013-08-23 12:23:07] HVM1: DVD/CD [ata1-0: QEMU DVD-ROM ATAPI-4 DVD/CD]
(XEN) [2013-08-23 12:23:07] HVM1: Searching bootorder for:
/pci@i0cf8/*@1,1/drive@1/disk@0
(XEN) [2013-08-23 12:23:07] HVM1: PS2 keyboard initialized
(XEN) [2013-08-23 12:23:07] HVM1: All threads complete.
(XEN) [2013-08-23 12:23:07] HVM1: Scan for option roms
(XEN) [2013-08-23 12:23:07] HVM1: Running option rom at c900:0003
(XEN) [2013-08-23 12:23:07] HVM1: pmm call arg1=1
(XEN) [2013-08-23 12:23:07] HVM1: pmm call arg1=0
(XEN) [2013-08-23 12:23:07] HVM1: pmm call arg1=1
(XEN) [2013-08-23 12:23:07] HVM1: pmm call arg1=0
(XEN) [2013-08-23 12:23:07] HVM1: Searching bootorder for: /pci@i0cf8/*@4
(XEN) [2013-08-23 12:23:07] HVM1: Press F12 for boot menu.
(XEN) [2013-08-23 12:23:07] HVM1: 
(XEN) [2013-08-23 12:23:10] HVM1: drive 0x000fd9b0: PCHS=16383/16/63
translation=lba LCHS=1024/255/63 s=20971520
(XEN) [2013-08-23 12:23:10] HVM1: 
(XEN) [2013-08-23 12:23:10] HVM1: drive 0x000fd980: PCHS=16383/16/63
translation=lba LCHS=1024/255/63 s=62914560
(XEN) [2013-08-23 12:23:10] HVM1: 0
(XEN) [2013-08-23 12:23:10] HVM1: Space available for UMB: 000ca000-000ee800
(XEN) [2013-08-23 12:23:10] HVM1: Returned 61440 bytes of ZoneHigh
(XEN) [2013-08-23 12:23:10] HVM1: e820 map has 6 items:
(XEN) [2013-08-23 12:23:10] HVM1:   0: 0000000000000000 - 000000000009fc00 = 1
RAM
(XEN) [2013-08-23 12:23:10] HVM1:   1: 000000000009fc00 - 00000000000a0000 = 2
RESERVED
(XEN) [2013-08-23 12:23:10] HVM1:   2: 00000000000f0000 - 0000000000100000 = 2
RESERVED
(XEN) [2013-08-23 12:23:10] HVM1:   3: 0000000000100000 - 000000003f7ff000 = 1
RAM
(XEN) [2013-08-23 12:23:10] HVM1:   4: 000000003f7ff000 - 000000003f800000 = 2
RESERVED
(XEN) [2013-08-23 12:23:10] HVM1:   5: 00000000fc000000 - 0000000100000000 = 2
RESERVED
(XEN) [2013-08-23 12:23:10] HVM1: enter handle_19:
(XEN) [2013-08-23 12:23:10] HVM1:   NULL
(XEN) [2013-08-23 12:23:10] HVM1: Booting from Hard Disk...
(XEN) [2013-08-23 12:23:10] HVM1: Booting from 0000:7c00
[  184.333348] xen_bridge: port 2(vif1.0-emu) entered forwarding state
(XEN) [2013-08-23 12:23:22] irq.c:375: Dom1 callback via changed to Direct
Vector 0xf3
(XEN) [2013-08-23 12:23:25] memory_map:remove: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 12:23:25] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 12:23:25] memory_map:remove: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 12:23:25] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 12:23:25] memory_map:remove: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 12:23:25] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 12:23:25] memory_map:remove: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 12:23:25] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 12:23:25] memory_map:remove: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 12:23:25] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 12:23:25] memory_map:remove: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 12:23:25] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 12:23:25] irq.c:270: Dom1 PCI link 0 changed 5 -> 0
(XEN) [2013-08-23 12:23:25] irq.c:270: Dom1 PCI link 1 changed 10 -> 0
(XEN) [2013-08-23 12:23:25] irq.c:270: Dom1 PCI link 2 changed 11 -> 0
(XEN) [2013-08-23 12:23:25] irq.c:270: Dom1 PCI link 3 changed 5 -> 0
[  188.391148] xen-blkback:ring-ref 8, event-channel 32, protocol 1 (x86_64-abi)
persistent grants
[  188.407733] xen-blkback:ring-ref 9, event-channel 33, protocol 1 (x86_64-abi)
persistent grants
[  188.518424] xen_bridge: port 1(vif1.0) entered forwarding state
[  188.528407] xen_bridge: port 1(vif1.0) entered forwarding state
(XEN) [2013-08-23 12:23:26] SEIK - msixtbl_pt_register  [0000:04:00.0]
entry_pirq:87 entry_evtchn:0 masked:0  || pirq:87 evtchn:0 masked:0
(XEN) [2013-08-23 12:23:26] SEIK - msixtbl_pt_register  [0000:04:00.0] pdev ==
entry->pdev, no need to add_msixtbl_entry ??
(XEN) [2013-08-23 12:23:26] SEIK - msixtbl_pt_register  [0000:04:00.0]
entry_pirq:87 entry_evtchn:0 masked:0  || pirq:86 evtchn:0 masked:0
(XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq == pirq''
failed at vmsi.c:472
(XEN) [2013-08-23 12:23:26] ----[ Xen-4.4-unstable  x86_64  debug=y  Not tainted
]----
(XEN) [2013-08-23 12:23:26] CPU:    0
(XEN) [2013-08-23 12:23:26] RIP:    e008:[<ffff82d0801c7b97>]
msixtbl_pt_register+0x28a/0x2dd
(XEN) [2013-08-23 12:23:26] RFLAGS: 0000000000010002   CONTEXT: hypervisor
(XEN) [2013-08-23 12:23:26] rax: 0000000000000000   rbx: ffff83054774f3f0   rcx:
0000000000000000
(XEN) [2013-08-23 12:23:26] rdx: ffff82d080311220   rsi: 000000000000000a   rdi:
ffff82d0802826e0
(XEN) [2013-08-23 12:23:26] rbp: ffff82d0802cfc18   rsp: ffff82d0802cfb98   r8: 
ffff83055d620000
(XEN) [2013-08-23 12:23:26] r9:  0000000000000002   r10: 000000000000001a   r11:
0000000000000002
(XEN) [2013-08-23 12:23:26] r12: ffff83054774f0a0   r13: ffff83055d6613d0   r14:
ffff8304b5190700
(XEN) [2013-08-23 12:23:26] r15: ffff8305444e5000   cr0: 000000008005003b   cr4:
00000000000006f0
(XEN) [2013-08-23 12:23:26] cr3: 000000054582c000   cr2: 00007f42b71b4ff8
(XEN) [2013-08-23 12:23:26] ds: 0000   es: 0000   fs: 0000   gs: 0000   ss: e010
cs: e008
(XEN) [2013-08-23 12:23:26] Xen stack trace from rsp=ffff82d0802cfb98:
(XEN) [2013-08-23 12:23:26]    ffff830500000000 ffff830500000000
ffff830500000056 ffff830400000000
(XEN) [2013-08-23 12:23:26]    ffff830500000000 ffff83009faef000
ffff82d0802cfc18 00000000f3051000
(XEN) [2013-08-23 12:23:26]    ffff8305444e5ab0 ffff83055d684e00
ffff82d00000416a ffff8304b519c240
(XEN) [2013-08-23 12:23:26]    ffff8304b5190700 ffff8305444e5000
ffff82d0802cfe48 0000000000000000
(XEN) [2013-08-23 12:23:26]    ffff82d0802cfc98 ffff82d0801457da
ffff83054774f2e0 ffff83055d74fe70
(XEN) [2013-08-23 12:23:26]    0000000000000246 ffff82d0802cfc58
ffff8305444e5198 000000565d619df8
(XEN) [2013-08-23 12:23:26]    ffff82d0802cfc88 ffff82d080119328
00007fda95d9b004 00007fda95d9b004
(XEN) [2013-08-23 12:23:26]    fffffffffffffffd 00007fda95d9b004
00007fff89087580 0000000000000001
(XEN) [2013-08-23 12:23:26]    ffff82d0802cfd98 ffff82d08015a9db
ffff82d0802cfcf8 ffff82d080168329
(XEN) [2013-08-23 12:23:26]    000000000000004e 0000000000000008
ffff82d0802cfcf8 ffff83054774f2e0
(XEN) [2013-08-23 12:23:26]    ffff83055d684e00 000000000000004e
0000000000000000 ffff83055d684e00
(XEN) [2013-08-23 12:23:26]    ffff82d0802cfd28 ffff82d080169455
ffff82d0802cfd18 ffff82d080138f18
(XEN) [2013-08-23 12:23:26]    ffff82d0802cfd48 ffff82d08016a949
ffff82d0802cfe38 ffff8305444e5000
(XEN) [2013-08-23 12:23:26]    ffff8305444e5000 0000000000000246
ffff82d0802cfde8 ffff82d08016db33
(XEN) [2013-08-23 12:23:26]    ffff82d0802cfda8 ffff82d0801190d5
0000000000000202 fffffffffffffff3
(XEN) [2013-08-23 12:23:26]    ffff8305444e5000 00007fda95d9b004
00007fff89087580 0000000000000001
(XEN) [2013-08-23 12:23:26]    ffff82d0802cfef8 ffff82d0801042b7
ffff83054774f2e0 ffff8304b5190700
(XEN) [2013-08-23 12:23:26]    ffff82d0802cfde8 ffff8305444e5000
ffff82d0802cfe88 0000000000000000
(XEN) [2013-08-23 12:23:26]    ffff82d0802cfea8 ffff82d0802cfeac
ffff82d0802cfe68 ffff82d080180fef
(XEN) [2013-08-23 12:23:26]    0000000000000cfe 0000000000000cfe
ffff82d0802cff18 0000000000000086
(XEN) [2013-08-23 12:23:26] Xen call trace:
(XEN) [2013-08-23 12:23:26]    [<ffff82d0801c7b97>]
msixtbl_pt_register+0x28a/0x2dd
(XEN) [2013-08-23 12:23:26]    [<ffff82d0801457da>]
pt_irq_create_bind+0x155/0x4e7
(XEN) [2013-08-23 12:23:26]    [<ffff82d08015a9db>]
arch_do_domctl+0x125f/0x24ae
(XEN) [2013-08-23 12:23:26]    [<ffff82d0801042b7>]
do_domctl+0x1146/0x13bf
(XEN) [2013-08-23 12:23:26]    [<ffff82d08022b56b>]
syscall_enter+0xeb/0x145
(XEN) [2013-08-23 12:23:26]    
(XEN) [2013-08-23 12:23:27] 
(XEN) [2013-08-23 12:23:27] ****************************************
(XEN) [2013-08-23 12:23:27] Panic on CPU 0:
(XEN) [2013-08-23 12:23:27] Assertion ''entry->pirq == pirq''
failed at vmsi.c:472
(XEN) [2013-08-23 12:23:27] ****************************************
(XEN) [2013-08-23 12:23:27] 
(XEN) [2013-08-23 12:23:27] Reboot in five seconds...



Any idea what is going on (or how to find out) ?


--

Sander

Jan Beulich

2013-Aug-23 12:56 UTC

head link

Re: (XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq == pirq'' failed at vmsi.c

>>> On 23.08.13 at 14:34, Sander Eikelenboom
<linux@eikelenboom.it> wrote:
> After manually adding the iommu mapping for the southbridge ioapic,
> passthrough seems to work fine for all devices accept one usb-controller 
> which enables MSI-x.
> 
> It fails the ''entry->pirq == pirq'' assertion in
function msixtbl_pt_register.
First of all - why do you mail me about this rather than (or at least
not along with) the offending changset''s author? While it was indeed
me who added the assertion, I did so for the very reason that I
didn''t trust the author''s vague statement that these would
always
match. And you proved that I was right with that. So Joby - should
I revert the commit, or will you be able to come up with a fix within
the next few days?
> (XEN) [2013-08-23 12:23:26] SEIK - msixtbl_pt_register  [0000:04:00.0] 
> entry_pirq:87 entry_evtchn:0 masked:0  || pirq:87 evtchn:0 masked:0
> (XEN) [2013-08-23 12:23:26] SEIK - msixtbl_pt_register  [0000:04:00.0] pdev
==
> entry->pdev, no need to add_msixtbl_entry ?? 
> (XEN) [2013-08-23 12:23:26] SEIK - msixtbl_pt_register  [0000:04:00.0] 
> entry_pirq:87 entry_evtchn:0 masked:0  || pirq:86 evtchn:0 masked:0
> (XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq ==
pirq'' failed at vmsi.c:472
One possibly important piece of information missing here is how
many MSI-X vectors that device has.

And if you comment out the offending assertion, what is the resulting
output from your debugging changes plus subsequent ''M'' and
''i'' debug
key output (i.e. I''m interested in finding the association between IRQs
and MSI-X table entries; for that purpose it would be helpful if you
could also print the two involved pointers [entry and pirq]). It might
well be that there was something broken already prior to Joby''s
patch...

Jan

Sander Eikelenboom

2013-Aug-23 13:26 UTC

head link

Re: (XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq == pirq'' failed at vmsi.c

Friday, August 23, 2013, 2:56:05 PM, you wrote:
>>>> On 23.08.13 at 14:34, Sander Eikelenboom
<linux@eikelenboom.it> wrote:
>> After manually adding the iommu mapping for the southbridge ioapic,
>> passthrough seems to work fine for all devices accept one
usb-controller
>> which enables MSI-x.
>> 
>> It fails the ''entry->pirq == pirq'' assertion in
function msixtbl_pt_register.
> First of all - why do you mail me about this rather than (or at least
> not along with) the offending changset''s author? While it was
indeed
> me who added the assertion, I did so for the very reason that I
> didn''t trust the author''s vague statement that these
would always
> match. And you proved that I was right with that. So Joby - should
> I revert the commit, or will you be able to come up with a fix within
> the next few days?
Sorry, I did saw your discussion around that patched, but failed to link it to
my issue and picked you since you were on the hook with my other issue around
the boot stalls.
(which are still present, but since it seems possible to get the iommu working
properly (with the manual hack) that seemed worth pursuing first)
>> (XEN) [2013-08-23 12:23:26] SEIK - msixtbl_pt_register  [0000:04:00.0] 
>> entry_pirq:87 entry_evtchn:0 masked:0  || pirq:87 evtchn:0 masked:0
>> (XEN) [2013-08-23 12:23:26] SEIK - msixtbl_pt_register  [0000:04:00.0]
pdev ==
>> entry->pdev, no need to add_msixtbl_entry ?? 
>> (XEN) [2013-08-23 12:23:26] SEIK - msixtbl_pt_register  [0000:04:00.0] 
>> entry_pirq:87 entry_evtchn:0 masked:0  || pirq:86 evtchn:0 masked:0
>> (XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq ==
pirq'' failed at vmsi.c:472
> One possibly important piece of information missing here is how
> many MSI-X vectors that device has.
> And if you comment out the offending assertion, what is the resulting
> output from your debugging changes plus subsequent ''M''
and ''i'' debug
> key output (i.e. I''m interested in finding the association between
IRQs
> and MSI-X table entries; for that purpose it would be helpful if you
> could also print the two involved pointers [entry and pirq]). It might
> well be that there was something broken already prior to Joby''s
patch...
I have adjusted the debug patch, only letting it reuse the entry if ( pdev ==
entry->pdev && entry->pirq == pirq){
so the assertion should be always true now, would this perhaps be the proper fix
or should it also check if it is also masked ?

 int msixtbl_pt_register(struct domain *d, struct pirq *pirq, uint64_t gtable)
 {
@@ -413,49 +421,81 @@ int msixtbl_pt_register(struct domain *d, struct pirq
*pirq, uint64_t gtable)
         return -ENOMEM;

     irq_desc = pirq_spin_lock_irq_desc(pirq, NULL);
     if ( !irq_desc )
     {
         xfree(new_entry);
         return r;
     }

     if ( !irq_desc->msi_desc )
         goto out;

     msi_desc = irq_desc->msi_desc;
     if ( !msi_desc )
         goto out;

     pdev = msi_desc->dev;

     spin_lock(&d->arch.hvm_domain.msixtbl_list_lock);

-    list_for_each_entry( entry, &d->arch.hvm_domain.msixtbl_list, list )
-        if ( pdev == entry->pdev )
-            goto found;
+    list_for_each_entry( entry, &d->arch.hvm_domain.msixtbl_list, list
){
+           printk(XENLOG_WARNING "SEIK - msixtbl_pt_register - dumping
whole list:"
+                   " [%04x:%02x:%02x.%01x] entry_pirq:%d entry_evtchn:%#x
masked:%d  || pirq:%d evtchn:%#x masked:%d\n",
+                  entry->pdev->seg, entry->pdev->bus,
+                   PCI_SLOT(entry->pdev->devfn),
+                  
PCI_FUNC(entry->pdev->devfn),entry->pirq->pirq,entry->pirq->evtchn,entry->pirq->masked,pirq->pirq,pirq->evtchn,pirq->masked);
+    }
+
+

+    list_for_each_entry( entry, &d->arch.hvm_domain.msixtbl_list, list
){
+        if ( pdev == entry->pdev && entry->pirq == pirq){
+           printk(XENLOG_WARNING "SEIK - msixtbl_pt_register "
+                   " [%04x:%02x:%02x.%01x] pdev == entry->pdev, no need
to add_msixtbl_entry ?? \n",
+                  entry->pdev->seg, entry->pdev->bus,
+                   PCI_SLOT(entry->pdev->devfn),
+                   PCI_FUNC(entry->pdev->devfn));
+            goto found;
+       }
+    }
     entry = new_entry;
     new_entry = NULL;
     add_msixtbl_entry(d, pdev, gtable, entry, pirq);

 found:
+    printk(XENLOG_WARNING "SEIK - msixtbl_pt_register "
+                   " [%04x:%02x:%02x.%01x] entry_pirq:%d entry_evtchn:%#x
masked:%d  || pirq:%d evtchn:%#x masked:%d\n",
+                  entry->pdev->seg, entry->pdev->bus,
+                   PCI_SLOT(entry->pdev->devfn),
+                  
PCI_FUNC(entry->pdev->devfn),entry->pirq->pirq,entry->pirq->evtchn,entry->pirq->masked,pirq->pirq,pirq->evtchn,pirq->masked);
+
     ASSERT(entry->pirq == pirq);
     atomic_inc(&entry->refcnt);
     spin_unlock(&d->arch.hvm_domain.msixtbl_list_lock);
     r = 0;






and this resulted in (with the requested info from the debug keys M & i):

(XEN) [2013-08-23 13:03:35] AMD-Vi: Share p2m table with iommu: p2m table =
0x546da1
[  240.972341] device vif1.0 entered promiscuous mode
[  241.252054] device vif1.0-emu entered promiscuous mode
[  241.266097] xen_bridge: port 2(vif1.0-emu) entered forwarding state
[  241.277237] xen_bridge: port 2(vif1.0-emu) entered forwarding state
[  241.500886] pciback 0000:04:00.0: restoring config space at offset 0x3c (was
0x100, writing 0x10a)
[  241.514597] pciback 0000:04:00.0: restoring config space at offset 0x10 (was
0x4, writing 0xf97fe004)
[  241.526480] pciback 0000:04:00.0: restoring config space at offset 0xc (was
0x0, writing 0x10)
(XEN) [2013-08-23 13:03:36] io.c:280: d1: bind: m_gsi=40 g_gsi=36 device=5
intx=0
(XEN) [2013-08-23 13:03:36] AMD-Vi: Disable: device id = 0x400, domain = 0,
paging mode = 3
(XEN) [2013-08-23 13:03:36] AMD-Vi: Setup I/O page table: device id = 0
(0004:00:00.1024), root table = 0x546da1000, domain = 1, paging mode = 4
(XEN) [2013-08-23 13:03:36] AMD-Vi: Re-assign 0000:04:00.0 from dom0 to dom1
(XEN) [2013-08-23 13:03:36] HVM1: HVM Loader
(XEN) [2013-08-23 13:03:36] HVM1: Detected Xen v4.4-unstable
(XEN) [2013-08-23 13:03:36] HVM1: Xenbus rings @0xfeffc000, event channel 6
(XEN) [2013-08-23 13:03:36] HVM1: System requested SeaBIOS
(XEN) [2013-08-23 13:03:36] HVM1: CPU speed is 3200 MHz
(XEN) [2013-08-23 13:03:36] HVM1: Relocating guest memory for lowmem MMIO space
disabled
(XEN) [2013-08-23 13:03:36] irq.c:270: Dom1 PCI link 0 changed 0 -> 5
(XEN) [2013-08-23 13:03:36] HVM1: PCI-ISA link 0 routed to IRQ5
(XEN) [2013-08-23 13:03:36] irq.c:270: Dom1 PCI link 1 changed 0 -> 10
(XEN) [2013-08-23 13:03:36] HVM1: PCI-ISA link 1 routed to IRQ10
(XEN) [2013-08-23 13:03:36] irq.c:270: Dom1 PCI link 2 changed 0 -> 11
(XEN) [2013-08-23 13:03:36] HVM1: PCI-ISA link 2 routed to IRQ11
(XEN) [2013-08-23 13:03:36] irq.c:270: Dom1 PCI link 3 changed 0 -> 5
(XEN) [2013-08-23 13:03:36] HVM1: PCI-ISA link 3 routed to IRQ5
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 01:3 INTA->IRQ10
[  241.556018] xen-pciback: vpci: 0000:04:00.0: assign to virtual slot 0
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 03:0 INTA->IRQ5
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 04:0 INTA->IRQ5
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 05:0 INTA->IRQ10
(XEN) [2013-08-23 13:03:36] HVM1: No RAM in high memory; setting high_mem
resource base to 100000000
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 02:0 bar 10 size 002000000: 0f0000008
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 03:0 bar 14 size 001000000: 0f2000008
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 04:0 bar 10 size 000020000: 0f3000000
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 04:0 bar 30 size 000020000: 0f3020000
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 02:0 bar 30 size 000010000: 0f3040000
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 05:0 bar 10 size 000002000: 0f3050004
(XEN) [2013-08-23 13:03:36] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 02:0 bar 14 size 000001000: 0f3052000
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 03:0 bar 10 size 000000100: 00000c001
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 04:0 bar 14 size 000000040: 00000c101
(XEN) [2013-08-23 13:03:36] HVM1: pci dev 01:1 bar 20 size 000000010: 00000c141
(XEN) [2013-08-23 13:03:36] HVM1: Multiprocessor initialisation:
(XEN) [2013-08-23 13:03:36] HVM1:  - CPU0 ... 48-bit phys ... fixed MTRRs ...
var MTRRs [2/8] ... done.
(XEN) [2013-08-23 13:03:36] HVM1:  - CPU1 ... 48-bit phys ... fixed MTRRs ...
var MTRRs [2/8] ... done.
(XEN) [2013-08-23 13:03:36] HVM1:  - CPU2 ... 48-bit phys ... fixed MTRRs ...
var MTRRs [2/8] ... done.
(XEN) [2013-08-23 13:03:36] HVM1:  - CPU3 ... 48-bit phys ... fixed MTRRs ...
var MTRRs [2/8] ... done.
(XEN) [2013-08-23 13:03:36] HVM1: Testing HVM environment:
(XEN) [2013-08-23 13:03:36] HVM1:  - REP INSB across page boundaries ... passed
(XEN) [2013-08-23 13:03:36] HVM1:  - GS base MSRs and SWAPGS ... passed
(XEN) [2013-08-23 13:03:36] HVM1: Passed 2 of 2 tests
(XEN) [2013-08-23 13:03:36] HVM1: Writing SMBIOS tables ...
(XEN) [2013-08-23 13:03:36] HVM1: Loading SeaBIOS ...
(XEN) [2013-08-23 13:03:36] HVM1: Creating MP tables ...
(XEN) [2013-08-23 13:03:36] HVM1: Loading ACPI ...
(XEN) [2013-08-23 13:03:36] HVM1: vm86 TSS at fc00a100
(XEN) [2013-08-23 13:03:36] HVM1: BIOS map:
(XEN) [2013-08-23 13:03:36] HVM1:  10000-100d3: Scratch space
(XEN) [2013-08-23 13:03:36] HVM1:  e0000-fffff: Main BIOS
(XEN) [2013-08-23 13:03:36] HVM1: E820 table:
(XEN) [2013-08-23 13:03:36] HVM1:  [00]: 00000000:00000000 - 00000000:000a0000:
RAM
(XEN) [2013-08-23 13:03:36] HVM1:  HOLE: 00000000:000a0000 - 00000000:000e0000
(XEN) [2013-08-23 13:03:36] HVM1:  [01]: 00000000:000e0000 - 00000000:00100000:
RESERVED
(XEN) [2013-08-23 13:03:36] HVM1:  [02]: 00000000:00100000 - 00000000:3f800000:
RAM
(XEN) [2013-08-23 13:03:36] HVM1:  HOLE: 00000000:3f800000 - 00000000:fc000000
(XEN) [2013-08-23 13:03:36] HVM1:  [03]: 00000000:fc000000 - 00000001:00000000:
RESERVED
(XEN) [2013-08-23 13:03:36] HVM1: Invoking SeaBIOS ...
(XEN) [2013-08-23 13:03:36] HVM1: SeaBIOS (version
rel-1.7.1-3-g3a28511-20130822_222210-serveerstertje)
(XEN) [2013-08-23 13:03:36] HVM1: 
(XEN) [2013-08-23 13:03:36] HVM1: Found Xen hypervisor signature at 40000000
(XEN) [2013-08-23 13:03:36] HVM1: xen: copy e820...
(XEN) [2013-08-23 13:03:36] HVM1: Ram Size=0x3f800000 (0x0000000000000000 high)
(XEN) [2013-08-23 13:03:36] HVM1: Relocating low data from 0x000e42d0 to
0x000ef790 (size 2153)
(XEN) [2013-08-23 13:03:36] HVM1: Relocating init from 0x000e4b39 to 0x3f7e2e80
(size 53335)
(XEN) [2013-08-23 13:03:36] HVM1: CPU Mhz=3200
(XEN) [2013-08-23 13:03:36] HVM1: Found 8 PCI devices (max PCI bus is 00)
(XEN) [2013-08-23 13:03:36] HVM1: Allocated Xen hypercall page at 3f7ff000
(XEN) [2013-08-23 13:03:36] HVM1: Detected Xen v4.4-unstable
(XEN) [2013-08-23 13:03:36] HVM1: xen: copy BIOS tables...
(XEN) [2013-08-23 13:03:36] HVM1: Copying SMBIOS entry point from 0x00010010 to
0x000fdbd0
(XEN) [2013-08-23 13:03:36] HVM1: Copying MPTABLE from 0xfc0011b0/fc0011c0 to
0x000fdab0
(XEN) [2013-08-23 13:03:36] HVM1: Copying PIR from 0x00010030 to 0x000fda30
(XEN) [2013-08-23 13:03:36] HVM1: Copying ACPI RSDP from 0x000100b0 to
0x000fda00
(XEN) [2013-08-23 13:03:36] HVM1: Scan for VGA option rom
(XEN) [2013-08-23 13:03:36] HVM1: Running option rom at c000:0003
(XEN) [2013-08-23 13:03:36] stdvga.c:147:d1 entering stdvga and caching modes
(XEN) [2013-08-23 13:03:36] HVM1: Turning on vga text mode console
(XEN) [2013-08-23 13:03:36] HVM1: SeaBIOS (version
rel-1.7.1-3-g3a28511-20130822_222210-serveerstertje)
(XEN) [2013-08-23 13:03:36] HVM1: 
(XEN) [2013-08-23 13:03:36] HVM1: Found 1 lpt ports
(XEN) [2013-08-23 13:03:36] HVM1: Found 1 serial ports
(XEN) [2013-08-23 13:03:36] HVM1: ATA controller 1 at 1f0/3f4/c140 (irq 14 dev
9)
(XEN) [2013-08-23 13:03:36] HVM1: ATA controller 2 at 170/374/c148 (irq 15 dev
9)
(XEN) [2013-08-23 13:03:36] HVM1: ata0-0: QEMU HARDDISK ATA-7 Hard-Disk (10240
MiBytes)
(XEN) [2013-08-23 13:03:36] HVM1: Searching bootorder for:
/pci@i0cf8/*@1,1/drive@0/disk@0
(XEN) [2013-08-23 13:03:36] HVM1: ata0-1: QEMU HARDDISK ATA-7 Hard-Disk (300
GiBytes)
(XEN) [2013-08-23 13:03:36] HVM1: Searching bootorder for:
/pci@i0cf8/*@1,1/drive@0/disk@1
(XEN) [2013-08-23 13:03:36] HVM1: DVD/CD [ata1-0: QEMU DVD-ROM ATAPI-4 DVD/CD]
(XEN) [2013-08-23 13:03:36] HVM1: Searching bootorder for:
/pci@i0cf8/*@1,1/drive@1/disk@0
(XEN) [2013-08-23 13:03:36] HVM1: PS2 keyboard initialized
(XEN) [2013-08-23 13:03:36] HVM1: All threads complete.
(XEN) [2013-08-23 13:03:36] HVM1: Scan for option roms
(XEN) [2013-08-23 13:03:36] HVM1: Running option rom at c900:0003
(XEN) [2013-08-23 13:03:36] HVM1: pmm call arg1=1
(XEN) [2013-08-23 13:03:36] HVM1: pmm call arg1=0
(XEN) [2013-08-23 13:03:36] HVM1: pmm call arg1=1
(XEN) [2013-08-23 13:03:36] HVM1: pmm call arg1=0
(XEN) [2013-08-23 13:03:36] HVM1: Searching bootorder for: /pci@i0cf8/*@4
(XEN) [2013-08-23 13:03:36] HVM1: Press F12 for boot menu.
(XEN) [2013-08-23 13:03:36] HVM1: 
(XEN) [2013-08-23 13:03:39] HVM1: drive 0x000fd9b0: PCHS=16383/16/63
translation=lba LCHS=1024/255/63 s=20971520
(XEN) [2013-08-23 13:03:39] HVM1: 
(XEN) [2013-08-23 13:03:39] HVM1: drive 0x000fd980: PCHS=16383/16/63
translation=lba LCHS=1024/255/63 s=62914560
(XEN) [2013-08-23 13:03:39] HVM1: 0
(XEN) [2013-08-23 13:03:39] HVM1: Space available for UMB: 000ca000-000ee800
(XEN) [2013-08-23 13:03:39] HVM1: Returned 61440 bytes of ZoneHigh
(XEN) [2013-08-23 13:03:39] HVM1: e820 map has 6 items:
(XEN) [2013-08-23 13:03:39] HVM1:   0: 0000000000000000 - 000000000009fc00 = 1
RAM
(XEN) [2013-08-23 13:03:39] HVM1:   1: 000000000009fc00 - 00000000000a0000 = 2
RESERVED
(XEN) [2013-08-23 13:03:39] HVM1:   2: 00000000000f0000 - 0000000000100000 = 2
RESERVED
(XEN) [2013-08-23 13:03:39] HVM1:   3: 0000000000100000 - 000000003f7ff000 = 1
RAM
(XEN) [2013-08-23 13:03:39] HVM1:   4: 000000003f7ff000 - 000000003f800000 = 2
RESERVED
(XEN) [2013-08-23 13:03:39] HVM1:   5: 00000000fc000000 - 0000000100000000 = 2
RESERVED
(XEN) [2013-08-23 13:03:39] HVM1: enter handle_19:
(XEN) [2013-08-23 13:03:39] HVM1:   NULL
(XEN) [2013-08-23 13:03:39] HVM1: Booting from Hard Disk...
(XEN) [2013-08-23 13:03:39] HVM1: Booting from 0000:7c00
[  256.293359] xen_bridge: port 2(vif1.0-emu) entered forwarding state
(XEN) [2013-08-23 13:03:51] irq.c:375: Dom1 callback via changed to Direct
Vector 0xf3
(XEN) [2013-08-23 13:03:54] memory_map:remove: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 13:03:54] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 13:03:54] memory_map:remove: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 13:03:54] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 13:03:54] memory_map:remove: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 13:03:54] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 13:03:54] memory_map:remove: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 13:03:54] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 13:03:54] memory_map:remove: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 13:03:54] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 13:03:54] memory_map:remove: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 13:03:54] memory_map:add: dom1 gfn=f3050 mfn=f97fe nr=1
(XEN) [2013-08-23 13:03:54] irq.c:270: Dom1 PCI link 0 changed 5 -> 0
(XEN) [2013-08-23 13:03:54] irq.c:270: Dom1 PCI link 1 changed 10 -> 0
(XEN) [2013-08-23 13:03:54] irq.c:270: Dom1 PCI link 2 changed 11 -> 0
(XEN) [2013-08-23 13:03:54] irq.c:270: Dom1 PCI link 3 changed 5 -> 0
[  260.399472] xen-blkback:ring-ref 8, event-channel 32, protocol 1 (x86_64-abi)
persistent grants
[  260.415708] xen-blkback:ring-ref 9, event-channel 33, protocol 1 (x86_64-abi)
persistent grants
[  260.524239] xen_bridge: port 1(vif1.0) entered forwarding state
[  260.534695] xen_bridge: port 1(vif1.0) entered forwarding state
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register  [0000:04:00.0]
entry_pirq:87 entry_evtchn:0 masked:0  || pirq:87 evtchn:0 masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register - dumping whole list:
[0000:04:00.0] entry_pirq:87 entry_evtchn:0 masked:0  || pirq:86 evtchn:0
masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register  [0000:04:00.0]
entry_pirq:86 entry_evtchn:0 masked:0  || pirq:86 evtchn:0 masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register - dumping whole list:
[0000:04:00.0] entry_pirq:86 entry_evtchn:0 masked:0  || pirq:85 evtchn:0
masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register - dumping whole list:
[0000:04:00.0] entry_pirq:87 entry_evtchn:0 masked:0  || pirq:85 evtchn:0
masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register  [0000:04:00.0]
entry_pirq:85 entry_evtchn:0 masked:0  || pirq:85 evtchn:0 masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register - dumping whole list:
[0000:04:00.0] entry_pirq:85 entry_evtchn:0 masked:0  || pirq:84 evtchn:0
masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register - dumping whole list:
[0000:04:00.0] entry_pirq:86 entry_evtchn:0 masked:0  || pirq:84 evtchn:0
masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register - dumping whole list:
[0000:04:00.0] entry_pirq:87 entry_evtchn:0 masked:0  || pirq:84 evtchn:0
masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register  [0000:04:00.0]
entry_pirq:84 entry_evtchn:0 masked:0  || pirq:84 evtchn:0 masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register - dumping whole list:
[0000:04:00.0] entry_pirq:84 entry_evtchn:0 masked:0  || pirq:83 evtchn:0
masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register - dumping whole list:
[0000:04:00.0] entry_pirq:85 entry_evtchn:0 masked:0  || pirq:83 evtchn:0
masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register - dumping whole list:
[0000:04:00.0] entry_pirq:86 entry_evtchn:0 masked:0  || pirq:83 evtchn:0
masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register - dumping whole list:
[0000:04:00.0] entry_pirq:87 entry_evtchn:0 masked:0  || pirq:83 evtchn:0
masked:0
(XEN) [2013-08-23 13:03:55] SEIK - msixtbl_pt_register  [0000:04:00.0]
entry_pirq:83 entry_evtchn:0 masked:0  || pirq:83 evtchn:0 masked:0
[  275.537256] xen_bridge: port 1(vif1.0) entered forwarding state
[  275.774529] FW: ipmasq, Forward .. EoC: IN=eth0 OUT=eth0
MAC=40:61:86:f4:67:d9:00:08:ae:10:46:60:08:00 SRC=31.162.137.59
DST=88.159.77.216 LEN=118 TOS=0x00 PREC=0x00 TTL=111 ID=12384 PROTO=UDP
SPT=23772 DPT=30614 LEN=98
(XEN) [2013-08-23 13:04:27] *** Serial input -> Xen (type
''CTRL-a'' three times to switch input to DOM0)
(XEN) [2013-08-23 13:04:29] MSI information:
(XEN) [2013-08-23 13:04:29]  MSI     56 vec=28 lowest  edge   assert  log lowest
dest=00000001 mask=0/0/?
(XEN) [2013-08-23 13:04:29]  MSI     57 vec=39 lowest  edge   assert  log lowest
dest=0000003f mask=0/1/?
(XEN) [2013-08-23 13:04:29]  MSI     58 vec=41 lowest  edge   assert  log lowest
dest=0000003f mask=0/1/?
(XEN) [2013-08-23 13:04:29]  MSI     59 vec=49 lowest  edge   assert  log lowest
dest=0000003f mask=0/1/?
(XEN) [2013-08-23 13:04:29]  MSI     60 vec=51 lowest  edge   assert  log lowest
dest=0000003f mask=0/1/?
(XEN) [2013-08-23 13:04:29]  MSI     61 vec=59 lowest  edge   assert  log lowest
dest=0000003f mask=0/1/?
(XEN) [2013-08-23 13:04:29]  MSI     62 vec=61 lowest  edge   assert  log lowest
dest=0000003f mask=0/1/?
(XEN) [2013-08-23 13:04:29]  MSI     63 vec=69 lowest  edge   assert  log lowest
dest=0000003f mask=0/1/?
(XEN) [2013-08-23 13:04:29]  MSI     64 vec=71 lowest  edge   assert  log lowest
dest=0000003f mask=0/1/?
(XEN) [2013-08-23 13:04:29]  MSI     65 vec=79 lowest  edge   assert  log lowest
dest=0000003f mask=0/1/?
(XEN) [2013-08-23 13:04:29]  MSI     66 vec=81 lowest  edge   assert  log lowest
dest=0000003f mask=0/1/?
(XEN) [2013-08-23 13:04:29]  MSI     67 vec=c1 lowest  edge   assert  log lowest
dest=00000001 mask=0/1/?
(XEN) [2013-08-23 13:04:29]  MSI     68 vec=d1 lowest  edge   assert  log lowest
dest=00000001 mask=0/1/?
(XEN) [2013-08-23 13:04:29]  MSI     69 vec=22 lowest  edge   assert  log lowest
dest=00000001 mask=0/1/?
(XEN) [2013-08-23 13:04:29]  MSI-X   70 vec=2a lowest  edge   assert  log lowest
dest=00000001 mask=1/0/0
(XEN) [2013-08-23 13:04:29]  MSI-X   71 vec=32 lowest  edge   assert  log lowest
dest=00000001 mask=1/0/0
(XEN) [2013-08-23 13:04:29]  MSI-X   72 vec=3a lowest  edge   assert  log lowest
dest=00000001 mask=1/0/0
(XEN) [2013-08-23 13:04:29]  MSI-X   73 vec=42 lowest  edge   assert  log lowest
dest=00000001 mask=1/0/0
(XEN) [2013-08-23 13:04:29]  MSI-X   74 vec=4a lowest  edge   assert  log lowest
dest=00000001 mask=1/0/0
(XEN) [2013-08-23 13:04:29]  MSI-X   75 vec=52 lowest  edge   assert  log lowest
dest=00000001 mask=1/0/0
(XEN) [2013-08-23 13:04:29]  MSI-X   76 vec=5a lowest  edge   assert  log lowest
dest=00000001 mask=1/0/0
(XEN) [2013-08-23 13:04:29]  MSI-X   77 vec=62 lowest  edge   assert  log lowest
dest=00000020 mask=1/0/0
(XEN) [2013-08-23 13:04:29]  MSI-X   78 vec=6a lowest  edge   assert  log lowest
dest=00000002 mask=1/0/0
(XEN) [2013-08-23 13:04:29]  MSI-X   79 vec=72 lowest  edge   assert  log lowest
dest=00000002 mask=1/0/0
(XEN) [2013-08-23 13:04:29]  MSI-X   80 vec=7a lowest  edge   assert  log lowest
dest=00000002 mask=1/0/0
(XEN) [2013-08-23 13:04:29]  MSI-X   81 vec=8a lowest  edge   assert  log lowest
dest=00000002 mask=1/0/0
(XEN) [2013-08-23 13:04:32] Guest interrupt information:
(XEN) [2013-08-23 13:04:32]    IRQ:   0 affinity:01 vec:f0 type=IO-APIC-edge   
status=00000000 timer_interrupt+0/0x14a
(XEN) [2013-08-23 13:04:32]    IRQ:   1 affinity:01 vec:30 type=IO-APIC-edge   
status=00000034 in-flight=0 domain-list=0:  1(----),
(XEN) [2013-08-23 13:04:32]    IRQ:   3 affinity:01 vec:38 type=IO-APIC-edge   
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:   4 affinity:01 vec:f1 type=IO-APIC-edge   
status=00000000 ns16550_interrupt+0/0x68
(XEN) [2013-08-23 13:04:32]    IRQ:   5 affinity:01 vec:40 type=IO-APIC-edge   
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:   6 affinity:01 vec:48 type=IO-APIC-edge   
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:   7 affinity:01 vec:50 type=IO-APIC-edge   
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:   8 affinity:01 vec:58 type=IO-APIC-edge   
status=00000030 in-flight=0 domain-list=0:  8(----),
(XEN) [2013-08-23 13:04:32]    IRQ:   9 affinity:01 vec:60 type=IO-APIC-level  
status=00000030 in-flight=0 domain-list=0:  9(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  10 affinity:01 vec:68 type=IO-APIC-edge   
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  11 affinity:01 vec:70 type=IO-APIC-edge   
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  12 affinity:01 vec:78 type=IO-APIC-edge   
status=00000030 in-flight=0 domain-list=0: 12(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  13 affinity:3f vec:88 type=IO-APIC-edge   
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  14 affinity:01 vec:90 type=IO-APIC-edge   
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  15 affinity:01 vec:98 type=IO-APIC-edge   
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  16 affinity:3f vec:b8 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  17 affinity:01 vec:c8 type=IO-APIC-level  
status=00000030 in-flight=0 domain-list=0: 17(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  18 affinity:01 vec:c0 type=IO-APIC-level  
status=00000030 in-flight=0 domain-list=0: 18(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  19 affinity:3f vec:b9 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  22 affinity:3f vec:89 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  28 affinity:3f vec:b1 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  29 affinity:3f vec:a9 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  32 affinity:3f vec:99 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  33 affinity:3f vec:91 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  37 affinity:3f vec:d8 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  38 affinity:3f vec:21 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  39 affinity:3f vec:29 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  40 affinity:02 vec:31 type=IO-APIC-level  
status=00000010 in-flight=0 domain-list=1: 40(--M-),
(XEN) [2013-08-23 13:04:32]    IRQ:  46 affinity:3f vec:c9 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  47 affinity:3f vec:a1 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  48 affinity:3f vec:d0 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  51 affinity:3f vec:d9 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  52 affinity:3f vec:a0 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  53 affinity:3f vec:a8 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  54 affinity:3f vec:b0 type=IO-APIC-level  
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  56 affinity:01 vec:28 type=AMD-IOMMU-MSI  
status=00000000 iommu_interrupt_handler+0/0x54
(XEN) [2013-08-23 13:04:32]    IRQ:  57 affinity:3f vec:39 type=PCI-MSI        
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  58 affinity:3f vec:41 type=PCI-MSI        
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  59 affinity:3f vec:49 type=PCI-MSI        
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  60 affinity:3f vec:51 type=PCI-MSI        
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  61 affinity:3f vec:59 type=PCI-MSI        
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  62 affinity:3f vec:61 type=PCI-MSI        
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  63 affinity:3f vec:69 type=PCI-MSI        
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  64 affinity:3f vec:71 type=PCI-MSI        
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  65 affinity:3f vec:79 type=PCI-MSI        
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  66 affinity:3f vec:81 type=PCI-MSI        
status=00000002 mapped, unbound
(XEN) [2013-08-23 13:04:32]    IRQ:  67 affinity:01 vec:c1 type=PCI-MSI        
status=00000010 in-flight=0 domain-list=0:301(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  68 affinity:01 vec:d1 type=PCI-MSI        
status=00000010 in-flight=0 domain-list=0:300(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  69 affinity:01 vec:22 type=PCI-MSI        
status=00000010 in-flight=0 domain-list=0:299(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  70 affinity:01 vec:2a type=PCI-MSI/-X     
status=00000030 in-flight=0 domain-list=0:298(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  71 affinity:01 vec:32 type=PCI-MSI/-X     
status=00000030 in-flight=0 domain-list=0:297(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  72 affinity:01 vec:3a type=PCI-MSI/-X     
status=00000030 in-flight=0 domain-list=0:296(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  73 affinity:01 vec:42 type=PCI-MSI/-X     
status=00000030 in-flight=0 domain-list=0:295(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  74 affinity:01 vec:4a type=PCI-MSI/-X     
status=00000030 in-flight=0 domain-list=0:294(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  75 affinity:01 vec:52 type=PCI-MSI/-X     
status=00000030 in-flight=0 domain-list=0:293(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  76 affinity:01 vec:5a type=PCI-MSI/-X     
status=00000030 in-flight=0 domain-list=0:292(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  77 affinity:20 vec:62 type=PCI-MSI/-X     
status=00000010 in-flight=0 domain-list=1: 87(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  78 affinity:02 vec:6a type=PCI-MSI/-X     
status=00000030 in-flight=0 domain-list=1: 86(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  79 affinity:02 vec:72 type=PCI-MSI/-X     
status=00000030 in-flight=0 domain-list=1: 85(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  80 affinity:02 vec:7a type=PCI-MSI/-X     
status=00000030 in-flight=0 domain-list=1: 84(----),
(XEN) [2013-08-23 13:04:32]    IRQ:  81 affinity:02 vec:8a type=PCI-MSI/-X     
status=00000030 in-flight=0 domain-list=1: 83(----),
(XEN) [2013-08-23 13:04:32] IO-APIC interrupt information:
(XEN) [2013-08-23 13:04:32]     IRQ  0 Vec240:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin  2: vec=f0 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ  1 Vec 48:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin  1: vec=30 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ  3 Vec 56:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin  3: vec=38 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ  4 Vec241:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin  4: vec=f1 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ  5 Vec 64:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin  5: vec=40 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ  6 Vec 72:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin  6: vec=48 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ  7 Vec 80:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin  7: vec=50 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ  8 Vec 88:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin  8: vec=58 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ  9 Vec 96:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin  9: vec=60 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ 10 Vec104:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin 10: vec=68 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ 11 Vec112:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin 11: vec=70 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ 12 Vec120:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin 12: vec=78 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ 13 Vec136:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin 13: vec=88 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 14 Vec144:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin 14: vec=90 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ 15 Vec152:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin 15: vec=98 delivery=LoPri
dest=L status=0 polarity=0 irr=0 trig=E mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ 16 Vec184:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin 16: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 17 Vec200:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin 17: vec=c8 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ 18 Vec192:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin 18: vec=c0 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=0 dest_id:1
(XEN) [2013-08-23 13:04:32]     IRQ 19 Vec185:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin 19: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 22 Vec137:
(XEN) [2013-08-23 13:04:32]       Apic 0x00, Pin 22: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 28 Vec177:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin  4: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 29 Vec169:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin  5: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 32 Vec153:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin  8: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 33 Vec145:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin  9: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 37 Vec216:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin 13: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 38 Vec 33:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin 14: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 39 Vec 41:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin 15: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 40 Vec 49:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin 16: vec=31 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=0 dest_id:2
(XEN) [2013-08-23 13:04:32]     IRQ 46 Vec201:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin 22: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 47 Vec161:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin 23: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 48 Vec208:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin 24: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 51 Vec217:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin 27: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 52 Vec160:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin 28: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 53 Vec168:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin 29: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63
(XEN) [2013-08-23 13:04:32]     IRQ 54 Vec176:
(XEN) [2013-08-23 13:04:32]       Apic 0x01, Pin 30: vec=00 delivery=Fixed
dest=L status=0 polarity=1 irr=0 trig=L mask=1 dest_id:63



After which the pci device and attached usb device seem to work ok in the guest
(with the following lspci -vvv output):

00:05.0 USB controller: NEC Corporation uPD720200 USB 3.0 Host Controller (rev
03) (prog-if 30 [XHCI])
        Subsystem: Micro-Star International Co., Ltd. Device 4257
        Physical Slot: 5
        Control: I/O- Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop- ParErr-
Stepping- SERR- FastB2B- DisINTx+
        Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort-
<TAbort- <MAbort- >SERR- <PERR- INTx-
        Latency: 0, Cache Line Size: 64 bytes
        Interrupt: pin A routed to IRQ 36
        Region 0: Memory at f3050000 (64-bit, non-prefetchable) [size=8K]
        Capabilities: [50] Power Management version 3
                Flags: PMEClk- DSI- D1- D2- AuxCurrent=0mA
PME(D0-,D1-,D2-,D3hot-,D3cold-)
                Status: D0 NoSoftRst+ PME-Enable- DSel=0 DScale=0 PME-
        Capabilities: [70] MSI: Enable- Count=1/1 Maskable- 64bit+
                Address: 0000000000000000  Data: 0000
        Capabilities: [90] MSI-X: Enable+ Count=8 Masked-
                Vector table: BAR=0 offset=00001000
                PBA: BAR=0 offset=00001080
        Capabilities: [a0] Express (v2) Endpoint, MSI 00
                DevCap: MaxPayload 128 bytes, PhantFunc 0, Latency L0s
unlimited, L1 unlimited
                        ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset-
                DevCtl: Report errors: Correctable- Non-Fatal- Fatal-
Unsupported-
                        RlxdOrd+ ExtTag- PhantFunc- AuxPwr- NoSnoop+
                        MaxPayload 128 bytes, MaxReadReq 512 bytes
                DevSta: CorrErr- UncorrErr- FatalErr- UnsuppReq- AuxPwr+
TransPend-
                LnkCap: Port #0, Speed 5GT/s, Width x1, ASPM L0s L1, Latency L0
<4us, L1 unlimited
                        ClockPM+ Surprise- LLActRep- BwNot-
                LnkCtl: ASPM Disabled; RCB 64 bytes Disabled- Retrain- CommClk-
                        ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
                LnkSta: Speed 5GT/s, Width x1, TrErr- Train- SlotClk+ DLActive-
BWMgmt- ABWMgmt-
                DevCap2: Completion Timeout: Not Supported, TimeoutDis+
                DevCtl2: Completion Timeout: 50us to 50ms, TimeoutDis-
                LnkCtl2: Target Link Speed: 5GT/s, EnterCompliance- SpeedDis-,
Selectable De-emphasis: -6dB
                         Transmit Margin: Normal Operating Range,
EnterModifiedCompliance- ComplianceSOS-
                         Compliance De-emphasis: -6dB
                LnkSta2: Current De-emphasis Level: -3.5dB,
EqualizationComplete-, EqualizationPhase1-
                         EqualizationPhase2-, EqualizationPhase3-,
LinkEqualizationRequest-
        Capabilities: [100 v4] #1033
        Kernel driver in use: xhci_hcd


--
Sander
> Jan

Jan Beulich

2013-Aug-23 13:55 UTC

head link

Re: (XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq == pirq'' failed at vmsi.c

>>> On 23.08.13 at 15:26, Sander Eikelenboom
<linux@eikelenboom.it> wrote:
> I have adjusted the debug patch, only letting it reuse the entry if ( pdev 
> == entry->pdev && entry->pirq == pirq){
> so the assertion should be always true now, would this perhaps be the
proper
> fix or should it also check if it is also masked ?
Yes, that might be a possible solution, albeit I don''t like it - it
points
out that the original patch from Joby is - beyond the bug here - at
least inefficient (in that we''d then allocate an entry per MSI-X table
entry, i.e. per IRQ, instead of per device). I therefore think we
rather ought to revert that change, and have him redo it properly.

Jan

Joby Poriyath

2013-Aug-23 20:58 UTC

head link

Re: (XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq == pirq'' failed at vmsi.c

On Fri, Aug 23, 2013 at 02:55:32PM +0100, Jan Beulich
wrote:> >>> On 23.08.13 at 15:26, Sander Eikelenboom
<linux@eikelenboom.it> wrote:
> > I have adjusted the debug patch, only letting it reuse the entry if (
pdev
> > == entry->pdev && entry->pirq == pirq){
> > so the assertion should be always true now, would this perhaps be the
proper
> > fix or should it also check if it is also masked ?
> 
> Yes, that might be a possible solution, albeit I don''t like it -
it points
> out that the original patch from Joby is - beyond the bug here - at
> least inefficient (in that we''d then allocate an entry per MSI-X
table
> entry, i.e. per IRQ, instead of per device). I therefore think we
> rather ought to revert that change, and have him redo it properly.
Ok, we ought to revisit the original patch. Let us revert the code for now.

Thanks Sander for spotting this.
It''s a certainly an oversight from my side.

A PCIe function can have multiple MSIx entries.

I''m on holidays. I''ll be back on 29th Aug. I shall pick this
up, then.

Thanks,
Joby

Xen devel - Aug 2013 - (XEN) [2013-08-23 12:23:26] Assertion 'entry->pirq == pirq' failed at vmsi.c

(XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq == pirq'' failed at vmsi.c

Re: (XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq == pirq'' failed at vmsi.c

Re: (XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq == pirq'' failed at vmsi.c

Re: (XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq == pirq'' failed at vmsi.c

Re: (XEN) [2013-08-23 12:23:26] Assertion ''entry->pirq == pirq'' failed at vmsi.c