diff mbox

[BUG] pci-passthrough generates "xen:events: Failed to obtain physical IRQ" for some devices

Message ID 20160203202801.GA30532@char.us.oracle.com
State New, archived
Headers show

Commit Message

Konrad Rzeszutek Wilk Feb. 3, 2016, 8:28 p.m. UTC
> > And I wonder if the XEN_DOMCTL_irq_permission aka, xc_domain_irq_permission
> > had been called. I remember that at some point we missed it for Xend..
> >

False alarm.

It was all in Linux. Attached are four patches (the first two
are for your issue you discovered).
I was wondering if there is a way for you to test them?
From 9b8c92f9535ca9af672facd05360570730a33e05 Mon Sep 17 00:00:00 2001
From: Konrad Rzeszutek Wilk <konrad.wilk@oracle.com>
Date: Wed, 3 Feb 2016 10:18:18 -0500
Subject: [PATCH 1/4] xen/pciback: Check PF instead of VF for
 PCI_COMMAND_MEMORY

c/s 408fb0e5aa7fda0059db282ff58c3b2a4278baa0
"xen/pciback: Don't allow MSI-X ops if PCI_COMMAND_MEMORY is not set."
would check the device for PCI_COMMAND_MEMORY which is great.
Except that VF devices are unique - for example they have no
legacy interrupts, and also any writes to PCI_COMMAND_MEMORY
are silently ignored (by the hardware).

CC: stable@vger.kernel.org
Signed-off-by: Konrad Rzeszutek Wilk <konrad.wilk@oracle.com>
---
 drivers/xen/xen-pciback/pciback_ops.c | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)

Comments

Ian Campbell Feb. 4, 2016, 9:37 a.m. UTC | #1
On Wed, 2016-02-03 at 15:28 -0500, Konrad Rzeszutek Wilk wrote:
> > > And I wonder if the XEN_DOMCTL_irq_permission aka,
> > > xc_domain_irq_permission
> > > had been called. I remember that at some point we missed it for
> > > Xend..
> > > 
> 
> False alarm.
> 
> It was all in Linux. Attached are four patches (the first two
> are for your issue you discovered).
> I was wondering if there is a way for you to test them?

Tommy,

Please see the Debian Kernel Handbook and in particular
https://www.debian.org/doc/manuals/debian-kernel-handbook/ch-common-tasks.html#s-common-official
for instructions on rebuilding the Debian kernel with additional patches.

Ian.
Tommi Airikka Feb. 4, 2016, 11:35 p.m. UTC | #2
Hi,

I patched the deb8u2 source with all four patches and built a new deb.

As two of the patches make some changes on the pcifront, I thought it could
be a good idea to first upgrade the domU 'bug' with the new linux-image.

domU 'bug' "uname -a":
Linux bug 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u2a~test
(2016-02-04) x86_64 GNU/Linux

dom0 "uname -a":
Linux dom0 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u2 (2016-01-02)
x86_64 GNU/Linux

At first, all seemed to be as expected. I still got the "Failed to obtain
physical IRQ" as the dom0 is not upgraded with the new linux-image.
But after a couple of minutes, I got "INFO: task khubd:205 blocked for more
than 120 seconds." with a call trace in dmesg (and there is a new call
trace periodically every 120 seconds).

domU 'bug' "dmesg":
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 3.16.0-4-amd64 (debian-kernel@lists.debian.org)
(gcc version 4.8.4 (Debian 4.8.4-1) ) #1 SMP Debian
3.16.7-ckt20-1+deb8u2a~test (2016-02-04)
[    0.000000] Command line: root=/dev/xvda2 ro elevator=noop
root=/dev/xvda2 ro
[    0.000000] ACPI in unprivileged domain disabled
[    0.000000] 1-1 mapping on 8000->100000
[    0.000000] Set 1015808 page(s) to 1-1 mapping
[    0.000000] 1-1 mapping on 100000->8000000
[    0.000000] e820: BIOS-provided physical RAM map:
[    0.000000] Xen: [mem 0x0000000000000000-0x000000000009ffff] usable
[    0.000000] Xen: [mem 0x00000000000a0000-0x00000000000fffff] reserved
[    0.000000] Xen: [mem 0x0000000000100000-0x0000000007ffffff] usable
[    0.000000] Xen: [mem 0x0000000008000000-0x00000000f1de3fff] unusable
[    0.000000] Xen: [mem 0x00000000f1de4000-0x00000000f1dedfff] ACPI data
[    0.000000] Xen: [mem 0x00000000f1dee000-0x00000000f7ffffff] reserved
[    0.000000] Xen: [mem 0x00000000fec00000-0x00000000feefffff] reserved
[    0.000000] Xen: [mem 0x00000000ff800000-0x00000000ffffffff] reserved
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] DMI not present or invalid.
[    0.000000] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.000000] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.000000] AGP: No AGP bridge found
[    0.000000] e820: last_pfn = 0x8000 max_arch_pfn = 0x400000000
[    0.000000] Base memory trampoline at [ffff88000009a000] 9a000 size 24576
[    0.000000] init_memory_mapping: [mem 0x00000000-0x000fffff]
[    0.000000]  [mem 0x00000000-0x000fffff] page 4k
[    0.000000] init_memory_mapping: [mem 0x07e00000-0x07ffffff]
[    0.000000]  [mem 0x07e00000-0x07ffffff] page 4k
[    0.000000] BRK [0x01b02000, 0x01b02fff] PGTABLE
[    0.000000] init_memory_mapping: [mem 0x04000000-0x07dfffff]
[    0.000000]  [mem 0x04000000-0x07dfffff] page 4k
[    0.000000] BRK [0x01b03000, 0x01b03fff] PGTABLE
[    0.000000] BRK [0x01b04000, 0x01b04fff] PGTABLE
[    0.000000] BRK [0x01b05000, 0x01b05fff] PGTABLE
[    0.000000] BRK [0x01b06000, 0x01b06fff] PGTABLE
[    0.000000] BRK [0x01b07000, 0x01b07fff] PGTABLE
[    0.000000] init_memory_mapping: [mem 0x00100000-0x03ffffff]
[    0.000000]  [mem 0x00100000-0x03ffffff] page 4k
[    0.000000] RAMDISK: [mem 0x01f18000-0x04a4efff]
[    0.000000] NUMA turned off
[    0.000000] Faking a node at [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] Initmem setup node 0 [mem 0x00000000-0x07ffffff]
[    0.000000]   NODE_DATA [mem 0x07fe7000-0x07febfff]
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x00001000-0x00ffffff]
[    0.000000]   DMA32    [mem 0x01000000-0xffffffff]
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x00001000-0x0009ffff]
[    0.000000]   node   0: [mem 0x00100000-0x07ffffff]
[    0.000000] On node 0 totalpages: 32671
[    0.000000]   DMA zone: 56 pages used for memmap
[    0.000000]   DMA zone: 21 pages reserved
[    0.000000]   DMA zone: 3999 pages, LIFO batch:0
[    0.000000]   DMA32 zone: 392 pages used for memmap
[    0.000000]   DMA32 zone: 28672 pages, LIFO batch:7
[    0.000000] SFI: Simple Firmware Interface v0.81
http://simplefirmware.org
[    0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
[    0.000000] nr_irqs_gsi: 16
[    0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000fffff]
[    0.000000] e820: [mem 0xf8000000-0xfebfffff] available for PCI devices
[    0.000000] Booting paravirtualized kernel on Xen
[    0.000000] Xen version: 4.4.1 (preserve-AD)
[    0.000000] setup_percpu: NR_CPUS:512 nr_cpumask_bits:512 nr_cpu_ids:1
nr_node_ids:1
[    0.000000] PERCPU: Embedded 27 pages/cpu @ffff880007c00000 s80896 r8192
d21504 u2097152
[    0.000000] pcpu-alloc: s80896 r8192 d21504 u2097152 alloc=1*2097152
[    0.000000] pcpu-alloc: [0] 0
[    0.000000] Built 1 zonelists in Node order, mobility grouping on.
Total pages: 32202
[    0.000000] Policy zone: DMA32
[    0.000000] Kernel command line: root=/dev/xvda2 ro elevator=noop
root=/dev/xvda2 ro
[    0.000000] PID hash table entries: 512 (order: 0, 4096 bytes)
[    0.000000] xsave: enabled xstate_bv 0x3, cntxt size 0x240
[    0.000000] AGP: Checking aperture...
[    0.000000] AGP: No AGP bridge found
[    0.000000] Calgary: detecting Calgary via BIOS EBDA area
[    0.000000] Calgary: Unable to locate Rio Grande table in EBDA - bailing!
[    0.000000] Memory: 72396K/130684K available (5219K kernel code, 947K
rwdata, 1836K rodata, 1204K init, 840K bss, 58288K reserved)
[    0.000000] Hierarchical RCU implementation.
[    0.000000]  RCU dyntick-idle grace-period acceleration is enabled.
[    0.000000]  RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=1.
[    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[    0.000000] NR_IRQS:33024 nr_irqs:256 16
[    0.000000] xen:events: Using FIFO-based ABI
[    0.000000] Console: colour dummy device 80x25
[    0.000000] console [tty0] enabled
[    0.000000] console [hvc0] enabled
[    0.000000] Xen: using vcpuop timer interface
[    0.000000] installing Xen timer for CPU 0
[    0.000000] tsc: Detected 2294.880 MHz processor
[    0.004000] Calibrating delay loop (skipped), value calculated using
timer frequency.. 4589.76 BogoMIPS (lpj=9179520)
[    0.004000] pid_max: default: 32768 minimum: 301
[    0.004000] Security Framework initialized
[    0.004000] AppArmor: AppArmor disabled by boot time parameter
[    0.004000] Yama: disabled by default; enable with sysctl kernel.yama.*
[    0.004000] Dentry cache hash table entries: 16384 (order: 5, 131072
bytes)
[    0.004000] Inode-cache hash table entries: 8192 (order: 4, 65536 bytes)
[    0.004000] Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
[    0.004000] Mountpoint-cache hash table entries: 512 (order: 0, 4096
bytes)
[    0.004000] Initializing cgroup subsys memory
[    0.004000] Initializing cgroup subsys devices
[    0.004000] Initializing cgroup subsys freezer
[    0.004000] Initializing cgroup subsys net_cls
[    0.004000] Initializing cgroup subsys blkio
[    0.004000] Initializing cgroup subsys perf_event
[    0.004000] Initializing cgroup subsys net_prio
[    0.004000] ENERGY_PERF_BIAS: Set to 'normal', was 'performance'
ENERGY_PERF_BIAS: View and update with x86_energy_perf_policy(8)
[    0.004000] CPU: Physical Processor ID: 0
[    0.004000] CPU: Processor Core ID: 1
[    0.004000] Last level iTLB entries: 4KB 512, 2MB 8, 4MB 8
Last level dTLB entries: 4KB 512, 2MB 32, 4MB 32, 1GB 0
tlb_flushall_shift: 2
[    0.035851] Freeing SMP alternatives memory: 20K (ffffffff81a1b000 -
ffffffff81a20000)
[    0.039467] ftrace: allocating 21679 entries in 85 pages
[    0.048176] Performance Events: unsupported p6 CPU model 58 no PMU
driver, software events only.
[    0.050760] x86: Booted up 1 node, 1 CPUs
[    0.050949] NMI watchdog: disabled (cpu0): hardware events not enabled
[    0.051055] devtmpfs: initialized
[    0.055826] pinctrl core: initialized pinctrl subsystem
[    0.056120] NET: Registered protocol family 16
[    0.056143] xen:grant_table: Grant tables using version 1 layout
[    0.056167] Grant table initialized
[    0.056748] PCI: setting up Xen PCI frontend stub
[    0.056757] PCI: pci_cache_line_size set to 64 bytes
[    0.060893] ACPI: Interpreter disabled.
[    0.060924] xen:balloon: Initialising balloon driver
[    0.060946] xen_balloon: Initialising balloon driver
[    0.060946] vgaarb: loaded
[    0.060946] PCI: System does not support PCI
[    0.060946] PCI: System does not support PCI
[    0.060946] Switched to clocksource xen
[    0.066106] pnp: PnP ACPI: disabled
[    0.068130] NET: Registered protocol family 2
[    0.068357] TCP established hash table entries: 1024 (order: 1, 8192
bytes)
[    0.068371] TCP bind hash table entries: 1024 (order: 2, 16384 bytes)
[    0.068379] TCP: Hash tables configured (established 1024 bind 1024)
[    0.068398] TCP: reno registered
[    0.068406] UDP hash table entries: 256 (order: 1, 8192 bytes)
[    0.068416] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
[    0.068467] NET: Registered protocol family 1
[    0.068488] PCI: CLS 0 bytes, default 64
[    0.068553] Unpacking initramfs...
[    0.111279] Freeing initrd memory: 44252K (ffff880001f18000 -
ffff880004a4f000)
[    0.113621] platform rtc_cmos: registered platform RTC device (no PNP
device found)
[    0.113824] RAPL PMU detected, hw unit 2^-16 Joules, API unit is 2^-32
Joules, 3 fixed counters 163840 ms ovfl timer
[    0.113861] microcode: CPU0 sig=0x306a9, pf=0x2, revision=0x19
[    0.113914] microcode: Microcode Update Driver: v2.00 <
tigran@aivazian.fsnet.co.uk>, Peter Oruba
[    0.114130] futex hash table entries: 256 (order: 2, 16384 bytes)
[    0.114158] audit: initializing netlink subsys (disabled)
[    0.114176] audit: type=2000 audit(1454626961.628:1): initialized
[    0.114464] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[    0.114489] zbud: loaded
[    0.114637] VFS: Disk quotas dquot_6.5.2
[    0.114650] Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.114703] msgmni has been set to 227
[    0.115097] alg: No test for stdrng (krng)
[    0.115123] Block layer SCSI generic (bsg) driver version 0.4 loaded
(major 252)
[    0.115164] io scheduler noop registered (default)
[    0.115169] io scheduler deadline registered
[    0.115195] io scheduler cfq registered
[    0.115253] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[    0.115271] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
[    0.115301] intel_idle: does not run on family 6 model 58
[    0.115590] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    0.115841] Linux agpgart interface v0.103
[    0.115913] i8042: PNP: No PS/2 controller found. Probing ports directly.
[    1.337539] i8042: No controller found
[    1.337715] mousedev: PS/2 mouse device common for all mice
[    1.398030] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0
[    1.398084] rtc_cmos: probe of rtc_cmos failed with error -38
[    1.398117] ledtrig-cpu: registered to indicate activity on CPUs
[    1.398136] AMD IOMMUv2 driver by Joerg Roedel <joerg.roedel@amd.com>
[    1.398139] AMD IOMMUv2 functionality not available on this system
[    1.398235] TCP: cubic registered
[    1.398254] NET: Registered protocol family 10
[    1.398432] mip6: Mobile IPv6
[    1.398439] NET: Registered protocol family 17
[    1.398448] mpls_gso: MPLS GSO support
[    1.398454] mce: Unable to init device /dev/mcelog (rc: -5)
[    1.398596] registered taskstats version 1
[    1.398647] xenbus_probe_frontend: Device with no driver:
device/vbd/51714
[    1.398652] xenbus_probe_frontend: Device with no driver:
device/vbd/51713
[    1.398655] xenbus_probe_frontend: Device with no driver: device/vif/0
[    1.398658] xenbus_probe_frontend: Device with no driver: device/pci/0
[    1.398693] rtc_hctosys: unable to open rtc device (rtc0)
[    1.398742] PM: Hibernation image not present or could not be loaded.
[    1.399253] Freeing unused kernel memory: 1204K (ffffffff818ee000 -
ffffffff81a1b000)
[    1.399263] Write protecting the kernel read-only data: 8192k
[    1.401793] Freeing unused kernel memory: 912K (ffff88000151c000 -
ffff880001600000)
[    1.401905] Freeing unused kernel memory: 212K (ffff8800017cb000 -
ffff880001800000)
[    1.420329] systemd-udevd[58]: starting version 215
[    1.420858] random: systemd-udevd urandom read with 3 bits of entropy
available
[    1.443892] xen_netfront: Initialising Xen virtual ethernet driver
[    1.511482] blkfront: xvda2: flush diskcache: enabled; persistent
grants: enabled; indirect descriptors: enabled;
[    1.514156] blkfront: xvda1: flush diskcache: enabled; persistent
grants: enabled; indirect descriptors: enabled;
[    2.104730] PM: Starting manual resume from disk
[    2.104745] PM: Hibernation image partition 202:1 present
[    2.104746] PM: Looking for hibernation image.
[    2.105114] PM: Image not found (code -22)
[    2.105118] PM: Hibernation image not present or could not be loaded.
[    4.299926] EXT4-fs (xvda2): mounted filesystem with ordered data mode.
Opts: (null)
[    4.386272] random: nonblocking pool is initialized
[    5.569639] systemd[1]: systemd 215 running in system mode. (+PAM +AUDIT
+SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ -SECCOMP -APPARMOR)
[    5.569746] systemd[1]: Detected virtualization 'xen'.
[    5.569766] systemd[1]: Detected architecture 'x86-64'.
[    6.733819] systemd[1]: Inserted module 'autofs4'
[    6.750629] systemd[1]: Set hostname to <bug>.
[    9.533126] systemd[1]: Cannot add dependency job for unit dbus.socket,
ignoring: Unit dbus.socket failed to load: No such file or directory.
[    9.533160] systemd[1]: Cannot add dependency job for unit
display-manager.service, ignoring: Unit display-manager.service failed to
load: No such file or directory.
[    9.533670] systemd[1]: Starting Forward Password Requests to Wall
Directory Watch.
[    9.533836] systemd[1]: Started Forward Password Requests to Wall
Directory Watch.
[    9.533865] systemd[1]: Expecting device dev-hvc0.device...
[    9.534044] systemd[1]: Starting Remote File Systems (Pre).
[    9.534129] systemd[1]: Reached target Remote File Systems (Pre).
[    9.534183] systemd[1]: Starting Arbitrary Executable File Formats File
System Automount Point.
[    9.534402] systemd[1]: Set up automount Arbitrary Executable File
Formats File System Automount Point.
[    9.534443] systemd[1]: Starting Dispatch Password Requests to Console
Directory Watch.
[    9.534524] systemd[1]: Started Dispatch Password Requests to Console
Directory Watch.
[    9.534546] systemd[1]: Starting Paths.
[    9.534632] systemd[1]: Reached target Paths.
[    9.534661] systemd[1]: Starting Encrypted Volumes.
[    9.534741] systemd[1]: Reached target Encrypted Volumes.
[    9.534763] systemd[1]: Expecting device dev-xvda1.device...
[    9.534845] systemd[1]: Starting Root Slice.
[    9.534953] systemd[1]: Created slice Root Slice.
[    9.534977] systemd[1]: Starting User and Session Slice.
[    9.535108] systemd[1]: Created slice User and Session Slice.
[    9.535132] systemd[1]: Starting Delayed Shutdown Socket.
[    9.535538] systemd[1]: Listening on Delayed Shutdown Socket.
[    9.535565] systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
[    9.535709] systemd[1]: Listening on /dev/initctl Compatibility Named
Pipe.
[    9.535733] systemd[1]: Starting Journal Socket (/dev/log).
[    9.535872] systemd[1]: Listening on Journal Socket (/dev/log).
[    9.535907] systemd[1]: Starting udev Kernel Socket.
[    9.536043] systemd[1]: Listening on udev Kernel Socket.
[    9.536073] systemd[1]: Starting udev Control Socket.
[    9.536187] systemd[1]: Listening on udev Control Socket.
[    9.536214] systemd[1]: Starting Journal Socket.
[    9.536351] systemd[1]: Listening on Journal Socket.
[    9.536388] systemd[1]: Starting System Slice.
[    9.536531] systemd[1]: Created slice System Slice.
[    9.536572] systemd[1]: Starting File System Check on Root Device...
[    9.538068] systemd[1]: Starting system-getty.slice.
[    9.538314] systemd[1]: Created slice system-getty.slice.
[    9.538341] systemd[1]: Starting system-serial\x2dgetty.slice.
[    9.538483] systemd[1]: Created slice system-serial\x2dgetty.slice.
[    9.538565] systemd[1]: Starting Increase datagram queue length...
[    9.542353] systemd[1]: Mounting POSIX Message Queue File System...
[    9.546880] systemd[1]: Mounting Debug File System...
[    9.578669] systemd[1]: Started Set Up Additional Binary Formats.
[    9.578747] systemd[1]: Mounting Huge Pages File System...
[    9.580657] systemd[1]: Starting Create list of required static device
nodes for the current kernel...
[    9.587373] systemd[1]: Starting Load Kernel Modules...
[    9.589167] systemd[1]: Starting udev Coldplug all Devices...
[    9.590713] systemd[1]: Starting Slices.
[    9.590778] systemd[1]: Reached target Slices.
[    9.658770] systemd[1]: Started Increase datagram queue length.
[    9.659677] systemd[1]: Starting Syslog Socket.
[    9.659768] systemd[1]: Listening on Syslog Socket.
[    9.659794] systemd[1]: Starting Sockets.
[    9.659824] systemd[1]: Reached target Sockets.
[    9.659842] systemd[1]: Starting Journal Service...
[    9.661017] systemd[1]: Started Journal Service.
[   10.686460] systemd-udevd[137]: starting version 215
[   11.087720] EXT4-fs (xvda2): re-mounted. Opts: errors=remount-ro
[   11.257117] systemd-journald[124]: Received request to flush runtime
journal from PID 1
[   12.525672] input: PC Speaker as /devices/platform/pcspkr/input/input0
[   12.526446] pcifront pci-0: Installing PCI frontend
[   12.526468] xen:swiotlb_xen: Warning: only able to allocate 4 MB for
software IO TLB
[   12.530788] software IO TLB [mem 0x02000000-0x02400000] (4MB) mapped at
[ffff880002000000-ffff8800023fffff]
[   12.531162] pcifront pci-0: Creating PCI Frontend Bus 0000:00
[   12.531224] pcifront pci-0: PCI host bridge to bus 0000:00
[   12.531231] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
[   12.531236] pci_bus 0000:00: root bus resource [mem
0x00000000-0xfffffffff]
[   12.531242] pci_bus 0000:00: root bus resource [bus 00-ff]
[   12.531509] pci 0000:00:01.0: [1912:0014] type 00 class 0x0c0330
[   12.531897] pci 0000:00:01.0: reg 0x10: [mem 0xfbff0000-0xfbff1fff 64bit]
[   12.536917] pci 0000:00:00.1: [14e4:165f] type 00 class 0x020000
[   12.537273] pci 0000:00:00.1: reg 0x10: [mem 0xfabc0000-0xfabcffff 64bit
pref]
[   12.537651] pci 0000:00:00.1: reg 0x18: [mem 0xfabb0000-0xfabbffff 64bit
pref]
[   12.537903] pci 0000:00:00.1: reg 0x20: [mem 0xfaba0000-0xfabaffff 64bit
pref]
[   12.539995] pcifront pci-0: New device on 0000:00:00.1 found.
[   12.542275] pcifront pci-0: claiming resource 0000:00:01.0/0
[   12.542285] pcifront pci-0: claiming resource 0000:00:00.1/0
[   12.542290] pcifront pci-0: claiming resource 0000:00:00.1/2
[   12.542294] pcifront pci-0: claiming resource 0000:00:00.1/4
[   12.542405] pci 0000:00:01.0: Xen PCI mapped GSI18 to IRQ29
[   12.656749] alg: No test for crc32 (crc32-pclmul)
[   12.905693] intel_rapl: Found RAPL domain package
[   12.905708] intel_rapl: Found RAPL domain core
[   12.956320] Adding 262140k swap on /dev/xvda1.  Priority:-1 extents:1
across:262140k SSFS
[   13.033326] pps_core: LinuxPPS API ver. 1 registered
[   13.033340] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo
Giometti <giometti@linux.it>
[   13.034413] PTP clock support registered
[   13.107656] tg3.c:v3.137 (May 11, 2014)
[   13.107885] tg3 0000:00:00.1: Xen PCI mapped GSI17 to IRQ30
[   13.120967] usbcore: registered new interface driver usbfs
[   13.121269] usbcore: registered new interface driver hub
[   13.121327] usbcore: registered new device driver usb
[   13.136707] tg3 0000:00:00.1 eth1: Tigon3 [partno(N/A) rev 5720000] (PCI
Express) MAC address 34:64:a9:9a:a8:b1
[   13.136726] tg3 0000:00:00.1 eth1: attached PHY is 5720C
(10/100/1000Base-T Ethernet) (WireSpeed[1], EEE[1])
[   13.136734] tg3 0000:00:00.1 eth1: RXcsums[1] LinkChgREG[0] MIirq[0]
ASF[1] TSOcap[1]
[   13.136740] tg3 0000:00:00.1 eth1: dma_rwctrl[00000001] dma_mask[64-bit]
[   13.143564] xen:events: xen_bind_pirq_gsi_to_irq: returning irq 29 for
gsi 18
[   13.143579] xhci_hcd 0000:00:01.0: Xen PCI mapped GSI18 to IRQ29
[   13.143886] xhci_hcd 0000:00:01.0: xHCI Host Controller
[   13.143899] xhci_hcd 0000:00:01.0: new USB bus registered, assigned bus
number 1
[   13.150842] xen:events: Failed to obtain physical IRQ 31
[   13.150863] xen:events: Failed to obtain physical IRQ 32
[   13.150953] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[   13.150961] usb usb1: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[   13.150967] usb usb1: Product: xHCI Host Controller
[   13.150971] usb usb1: Manufacturer: Linux 3.16.0-4-amd64 xhci_hcd
[   13.150976] usb usb1: SerialNumber: 0000:00:01.0
[   13.151281] hub 1-0:1.0: USB hub found
[   13.151303] hub 1-0:1.0: 2 ports detected
[   13.151437] xhci_hcd 0000:00:01.0: xHCI Host Controller
[   13.151446] xhci_hcd 0000:00:01.0: new USB bus registered, assigned bus
number 2
[   13.155915] usb usb2: We don't know the algorithms for LPM for this
host, disabling LPM.
[   13.155962] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003
[   13.155969] usb usb2: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[   13.155975] usb usb2: Product: xHCI Host Controller
[   13.155979] usb usb2: Manufacturer: Linux 3.16.0-4-amd64 xhci_hcd
[   13.155984] usb usb2: SerialNumber: 0000:00:01.0
[   13.157061] hub 2-0:1.0: USB hub found
[   13.157084] hub 2-0:1.0: 2 ports detected
[  240.060071] INFO: task khubd:205 blocked for more than 120 seconds.
[  240.060086]       Not tainted 3.16.0-4-amd64 #1
[  240.060090] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
[  240.060095] khubd           D ffff880001d20e78     0   205      2
0x00000000
[  240.060104]  ffff880001d20a20 0000000000000246 0000000000012f00
ffff8800062f3fd8
[  240.060112]  0000000000012f00 ffff880001d20a20 ffff880005dc8148
ffff8800062f3d00
[  240.060119]  ffff880005dc8140 ffff880001d20a20 0000000000000200
ffff880004f83c60
[  240.060126] Call Trace:
[  240.060138]  [<ffffffff8150f969>] ? schedule_timeout+0x229/0x2a0
[  240.060146]  [<ffffffff8118e5a8>] ? kfree+0x118/0x220
[  240.060153]  [<ffffffff815137c6>] ? _raw_spin_lock_irqsave+0x16/0x50
[  240.060162]  [<ffffffff81072d56>] ? lock_timer_base.isra.35+0x26/0x50
[  240.060168]  [<ffffffff810725da>] ? internal_add_timer+0x2a/0x70
[  240.060174]  [<ffffffff81074817>] ? mod_timer+0x127/0x1e0
[  240.060180]  [<ffffffff81510e68>] ? wait_for_completion+0xa8/0x120
[  240.060188]  [<ffffffff81096de0>] ? wake_up_state+0x10/0x10
[  240.060198]  [<ffffffffa0199ecc>] ? xhci_alloc_dev+0xac/0x250 [xhci_hcd]
[  240.060208]  [<ffffffffa016378b>] ? usb_alloc_dev+0x6b/0x2f0 [usbcore]
[  240.060217]  [<ffffffffa016a561>] ? hub_thread+0xcb1/0x1740 [usbcore]
[  240.060225]  [<ffffffff810a7ba0>] ? prepare_to_wait_event+0xf0/0xf0
[  240.060234]  [<ffffffffa01698b0>] ? hub_port_debounce+0x130/0x130
[usbcore]
[  240.060242]  [<ffffffff8108805d>] ? kthread+0xbd/0xe0
[  240.060248]  [<ffffffff81087fa0>] ? kthread_create_on_node+0x180/0x180
[  240.060254]  [<ffffffff81513c18>] ? ret_from_fork+0x58/0x90
[  240.060260]  [<ffffffff81087fa0>] ? kthread_create_on_node+0x180/0x180
[  360.060060] INFO: task khubd:205 blocked for more than 120 seconds.
[  360.060075]       Not tainted 3.16.0-4-amd64 #1
[  360.060080] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
this message.
[  360.060086] khubd           D ffff880001d20e78     0   205      2
0x00000000
[  360.060095]  ffff880001d20a20 0000000000000246 0000000000012f00
ffff8800062f3fd8
[  360.060104]  0000000000012f00 ffff880001d20a20 ffff880005dc8148
ffff8800062f3d00
[  360.060112]  ffff880005dc8140 ffff880001d20a20 0000000000000200
ffff880004f83c60
[  360.060119] Call Trace:
[  360.060131]  [<ffffffff8150f969>] ? schedule_timeout+0x229/0x2a0
[  360.060139]  [<ffffffff8118e5a8>] ? kfree+0x118/0x220
[  360.060145]  [<ffffffff815137c6>] ? _raw_spin_lock_irqsave+0x16/0x50
[  360.060155]  [<ffffffff81072d56>] ? lock_timer_base.isra.35+0x26/0x50
[  360.060161]  [<ffffffff810725da>] ? internal_add_timer+0x2a/0x70
[  360.060167]  [<ffffffff81074817>] ? mod_timer+0x127/0x1e0
[  360.060173]  [<ffffffff81510e68>] ? wait_for_completion+0xa8/0x120
[  360.060181]  [<ffffffff81096de0>] ? wake_up_state+0x10/0x10
[  360.060190]  [<ffffffffa0199ecc>] ? xhci_alloc_dev+0xac/0x250 [xhci_hcd]
[  360.060200]  [<ffffffffa016378b>] ? usb_alloc_dev+0x6b/0x2f0 [usbcore]
[  360.060209]  [<ffffffffa016a561>] ? hub_thread+0xcb1/0x1740 [usbcore]
[  360.060217]  [<ffffffff810a7ba0>] ? prepare_to_wait_event+0xf0/0xf0
[  360.060225]  [<ffffffffa01698b0>] ? hub_port_debounce+0x130/0x130
[usbcore]
[  360.060233]  [<ffffffff8108805d>] ? kthread+0xbd/0xe0
[  360.060239]  [<ffffffff81087fa0>] ? kthread_create_on_node+0x180/0x180
[  360.060245]  [<ffffffff81513c18>] ? ret_from_fork+0x58/0x90
[  360.060251]  [<ffffffff81087fa0>] ? kthread_create_on_node+0x180/0x180



Next, I upgraded dom0 with the new linux-image deb and rebooted the machine.

dom0 "uname -a":
Linux dom0 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u2a~test
(2016-02-04) x86_64 GNU/Linux

domU 'bug' "uname -a":
Linux bug 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u2a~test
(2016-02-04) x86_64 GNU/Linux

And now everything seems to work. No more "Failed to obtain physical IRQ",
I can mount my usb flash stick using the passthroughed usb controller. No
call traces in dmesg.

domU 'bug' "dmesg":
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Initializing cgroup subsys cpuacct
[    0.000000] Linux version 3.16.0-4-amd64 (debian-kernel@lists.debian.org)
(gcc version 4.8.4 (Debian 4.8.4-1) ) #1 SMP Debian
3.16.7-ckt20-1+deb8u2a~test (2016-02-04)
[    0.000000] Command line: root=/dev/xvda2 ro elevator=noop
root=/dev/xvda2 ro
[    0.000000] ACPI in unprivileged domain disabled
[    0.000000] 1-1 mapping on 8000->100000
[    0.000000] Set 1015808 page(s) to 1-1 mapping
[    0.000000] 1-1 mapping on 100000->8000000
[    0.000000] e820: BIOS-provided physical RAM map:
[    0.000000] Xen: [mem 0x0000000000000000-0x000000000009ffff] usable
[    0.000000] Xen: [mem 0x00000000000a0000-0x00000000000fffff] reserved
[    0.000000] Xen: [mem 0x0000000000100000-0x0000000007ffffff] usable
[    0.000000] Xen: [mem 0x0000000008000000-0x00000000f1de3fff] unusable
[    0.000000] Xen: [mem 0x00000000f1de4000-0x00000000f1dedfff] ACPI data
[    0.000000] Xen: [mem 0x00000000f1dee000-0x00000000f7ffffff] reserved
[    0.000000] Xen: [mem 0x00000000fec00000-0x00000000feefffff] reserved
[    0.000000] Xen: [mem 0x00000000ff800000-0x00000000ffffffff] reserved
[    0.000000] NX (Execute Disable) protection: active
[    0.000000] DMI not present or invalid.
[    0.000000] e820: update [mem 0x00000000-0x00000fff] usable ==> reserved
[    0.000000] e820: remove [mem 0x000a0000-0x000fffff] usable
[    0.000000] AGP: No AGP bridge found
[    0.000000] e820: last_pfn = 0x8000 max_arch_pfn = 0x400000000
[    0.000000] Base memory trampoline at [ffff88000009a000] 9a000 size 24576
[    0.000000] init_memory_mapping: [mem 0x00000000-0x000fffff]
[    0.000000]  [mem 0x00000000-0x000fffff] page 4k
[    0.000000] init_memory_mapping: [mem 0x07e00000-0x07ffffff]
[    0.000000]  [mem 0x07e00000-0x07ffffff] page 4k
[    0.000000] BRK [0x01b02000, 0x01b02fff] PGTABLE
[    0.000000] init_memory_mapping: [mem 0x04000000-0x07dfffff]
[    0.000000]  [mem 0x04000000-0x07dfffff] page 4k
[    0.000000] BRK [0x01b03000, 0x01b03fff] PGTABLE
[    0.000000] BRK [0x01b04000, 0x01b04fff] PGTABLE
[    0.000000] BRK [0x01b05000, 0x01b05fff] PGTABLE
[    0.000000] BRK [0x01b06000, 0x01b06fff] PGTABLE
[    0.000000] BRK [0x01b07000, 0x01b07fff] PGTABLE
[    0.000000] init_memory_mapping: [mem 0x00100000-0x03ffffff]
[    0.000000]  [mem 0x00100000-0x03ffffff] page 4k
[    0.000000] RAMDISK: [mem 0x01f18000-0x04a4efff]
[    0.000000] NUMA turned off
[    0.000000] Faking a node at [mem 0x0000000000000000-0x0000000007ffffff]
[    0.000000] Initmem setup node 0 [mem 0x00000000-0x07ffffff]
[    0.000000]   NODE_DATA [mem 0x07fe7000-0x07febfff]
[    0.000000] Zone ranges:
[    0.000000]   DMA      [mem 0x00001000-0x00ffffff]
[    0.000000]   DMA32    [mem 0x01000000-0xffffffff]
[    0.000000]   Normal   empty
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x00001000-0x0009ffff]
[    0.000000]   node   0: [mem 0x00100000-0x07ffffff]
[    0.000000] On node 0 totalpages: 32671
[    0.000000]   DMA zone: 56 pages used for memmap
[    0.000000]   DMA zone: 21 pages reserved
[    0.000000]   DMA zone: 3999 pages, LIFO batch:0
[    0.000000]   DMA32 zone: 392 pages used for memmap
[    0.000000]   DMA32 zone: 28672 pages, LIFO batch:7
[    0.000000] SFI: Simple Firmware Interface v0.81
http://simplefirmware.org
[    0.000000] smpboot: Allowing 1 CPUs, 0 hotplug CPUs
[    0.000000] nr_irqs_gsi: 16
[    0.000000] PM: Registered nosave memory: [mem 0x000a0000-0x000fffff]
[    0.000000] e820: [mem 0xf8000000-0xfebfffff] available for PCI devices
[    0.000000] Booting paravirtualized kernel on Xen
[    0.000000] Xen version: 4.4.1 (preserve-AD)
[    0.000000] setup_percpu: NR_CPUS:512 nr_cpumask_bits:512 nr_cpu_ids:1
nr_node_ids:1
[    0.000000] PERCPU: Embedded 27 pages/cpu @ffff880007c00000 s80896 r8192
d21504 u2097152
[    0.000000] pcpu-alloc: s80896 r8192 d21504 u2097152 alloc=1*2097152
[    0.000000] pcpu-alloc: [0] 0
[    0.000000] Built 1 zonelists in Node order, mobility grouping on.
Total pages: 32202
[    0.000000] Policy zone: DMA32
[    0.000000] Kernel command line: root=/dev/xvda2 ro elevator=noop
root=/dev/xvda2 ro
[    0.000000] PID hash table entries: 512 (order: 0, 4096 bytes)
[    0.000000] xsave: enabled xstate_bv 0x3, cntxt size 0x240
[    0.000000] AGP: Checking aperture...
[    0.000000] AGP: No AGP bridge found
[    0.000000] Calgary: detecting Calgary via BIOS EBDA area
[    0.000000] Calgary: Unable to locate Rio Grande table in EBDA - bailing!
[    0.000000] Memory: 72396K/130684K available (5219K kernel code, 947K
rwdata, 1836K rodata, 1204K init, 840K bss, 58288K reserved)
[    0.000000] Hierarchical RCU implementation.
[    0.000000]  RCU dyntick-idle grace-period acceleration is enabled.
[    0.000000]  RCU restricting CPUs from NR_CPUS=512 to nr_cpu_ids=1.
[    0.000000] RCU: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=1
[    0.000000] NR_IRQS:33024 nr_irqs:256 16
[    0.000000] xen:events: Using FIFO-based ABI
[    0.000000] Console: colour dummy device 80x25
[    0.000000] console [tty0] enabled
[    0.000000] console [hvc0] enabled
[    0.000000] Xen: using vcpuop timer interface
[    0.000000] installing Xen timer for CPU 0
[    0.000000] tsc: Detected 2294.850 MHz processor
[    0.004000] Calibrating delay loop (skipped), value calculated using
timer frequency.. 4589.70 BogoMIPS (lpj=9179400)
[    0.004000] pid_max: default: 32768 minimum: 301
[    0.004000] Security Framework initialized
[    0.004000] AppArmor: AppArmor disabled by boot time parameter
[    0.004000] Yama: disabled by default; enable with sysctl kernel.yama.*
[    0.004000] Dentry cache hash table entries: 16384 (order: 5, 131072
bytes)
[    0.004000] Inode-cache hash table entries: 8192 (order: 4, 65536 bytes)
[    0.004000] Mount-cache hash table entries: 512 (order: 0, 4096 bytes)
[    0.004000] Mountpoint-cache hash table entries: 512 (order: 0, 4096
bytes)
[    0.004000] Initializing cgroup subsys memory
[    0.004000] Initializing cgroup subsys devices
[    0.004000] Initializing cgroup subsys freezer
[    0.004000] Initializing cgroup subsys net_cls
[    0.004000] Initializing cgroup subsys blkio
[    0.004000] Initializing cgroup subsys perf_event
[    0.004000] Initializing cgroup subsys net_prio
[    0.004000] ENERGY_PERF_BIAS: Set to 'normal', was 'performance'
ENERGY_PERF_BIAS: View and update with x86_energy_perf_policy(8)
[    0.004000] CPU: Physical Processor ID: 0
[    0.004000] CPU: Processor Core ID: 0
[    0.004000] Last level iTLB entries: 4KB 512, 2MB 8, 4MB 8
Last level dTLB entries: 4KB 512, 2MB 32, 4MB 32, 1GB 0
tlb_flushall_shift: 2
[    0.034866] Freeing SMP alternatives memory: 20K (ffffffff81a1b000 -
ffffffff81a20000)
[    0.037443] ftrace: allocating 21679 entries in 85 pages
[    0.044144] Performance Events: unsupported p6 CPU model 58 no PMU
driver, software events only.
[    0.045610] x86: Booted up 1 node, 1 CPUs
[    0.045660] NMI watchdog: disabled (cpu0): hardware events not enabled
[    0.045739] devtmpfs: initialized
[    0.049008] pinctrl core: initialized pinctrl subsystem
[    0.049089] NET: Registered protocol family 16
[    0.049124] xen:grant_table: Grant tables using version 1 layout
[    0.049147] Grant table initialized
[    0.049432] PCI: setting up Xen PCI frontend stub
[    0.049432] PCI: pci_cache_line_size set to 64 bytes
[    0.049786] ACPI: Interpreter disabled.
[    0.049808] xen:balloon: Initialising balloon driver
[    0.052037] xen_balloon: Initialising balloon driver
[    0.052061] vgaarb: loaded
[    0.052133] PCI: System does not support PCI
[    0.052137] PCI: System does not support PCI
[    0.052288] Switched to clocksource xen
[    0.056226] pnp: PnP ACPI: disabled
[    0.057990] NET: Registered protocol family 2
[    0.058160] TCP established hash table entries: 1024 (order: 1, 8192
bytes)
[    0.058172] TCP bind hash table entries: 1024 (order: 2, 16384 bytes)
[    0.058178] TCP: Hash tables configured (established 1024 bind 1024)
[    0.058193] TCP: reno registered
[    0.058200] UDP hash table entries: 256 (order: 1, 8192 bytes)
[    0.058207] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes)
[    0.058247] NET: Registered protocol family 1
[    0.058262] PCI: CLS 0 bytes, default 64
[    0.058310] Unpacking initramfs...
[    0.097449] Freeing initrd memory: 44252K (ffff880001f18000 -
ffff880004a4f000)
[    0.099078] platform rtc_cmos: registered platform RTC device (no PNP
device found)
[    0.099138] RAPL PMU detected, hw unit 2^-16 Joules, API unit is 2^-32
Joules, 3 fixed counters 163840 ms ovfl timer
[    0.099170] microcode: CPU0 sig=0x306a9, pf=0x2, revision=0x19
[    0.099218] microcode: Microcode Update Driver: v2.00 <
tigran@aivazian.fsnet.co.uk>, Peter Oruba
[    0.099429] futex hash table entries: 256 (order: 2, 16384 bytes)
[    0.099456] audit: initializing netlink subsys (disabled)
[    0.099475] audit: type=2000 audit(1454627953.001:1): initialized
[    0.099755] HugeTLB registered 2 MB page size, pre-allocated 0 pages
[    0.099779] zbud: loaded
[    0.099917] VFS: Disk quotas dquot_6.5.2
[    0.099930] Dquot-cache hash table entries: 512 (order 0, 4096 bytes)
[    0.099981] msgmni has been set to 227
[    0.100254] alg: No test for stdrng (krng)
[    0.100275] Block layer SCSI generic (bsg) driver version 0.4 loaded
(major 252)
[    0.100314] io scheduler noop registered (default)
[    0.100319] io scheduler deadline registered
[    0.100346] io scheduler cfq registered
[    0.100405] pci_hotplug: PCI Hot Plug PCI Core version: 0.5
[    0.100423] pciehp: PCI Express Hot Plug Controller Driver version: 0.4
[    0.100451] intel_idle: does not run on family 6 model 58
[    0.102533] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    0.102816] Linux agpgart interface v0.103
[    0.102897] i8042: PNP: No PS/2 controller found. Probing ports directly.
[    1.282113] i8042: No controller found
[    1.282447] mousedev: PS/2 mouse device common for all mice
[    1.342255] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0
[    1.342308] rtc_cmos: probe of rtc_cmos failed with error -38
[    1.342341] ledtrig-cpu: registered to indicate activity on CPUs
[    1.342361] AMD IOMMUv2 driver by Joerg Roedel <joerg.roedel@amd.com>
[    1.342364] AMD IOMMUv2 functionality not available on this system
[    1.342459] TCP: cubic registered
[    1.342478] NET: Registered protocol family 10
[    1.342654] mip6: Mobile IPv6
[    1.342662] NET: Registered protocol family 17
[    1.342671] mpls_gso: MPLS GSO support
[    1.342678] mce: Unable to init device /dev/mcelog (rc: -5)
[    1.342820] registered taskstats version 1
[    1.342878] xenbus_probe_frontend: Device with no driver:
device/vbd/51714
[    1.342883] xenbus_probe_frontend: Device with no driver:
device/vbd/51713
[    1.342886] xenbus_probe_frontend: Device with no driver: device/vif/0
[    1.342889] xenbus_probe_frontend: Device with no driver: device/pci/0
[    1.342925] rtc_hctosys: unable to open rtc device (rtc0)
[    1.342973] PM: Hibernation image not present or could not be loaded.
[    1.343486] Freeing unused kernel memory: 1204K (ffffffff818ee000 -
ffffffff81a1b000)
[    1.343495] Write protecting the kernel read-only data: 8192k
[    1.346220] Freeing unused kernel memory: 912K (ffff88000151c000 -
ffff880001600000)
[    1.346355] Freeing unused kernel memory: 212K (ffff8800017cb000 -
ffff880001800000)
[    1.368373] systemd-udevd[58]: starting version 215
[    1.369126] random: systemd-udevd urandom read with 3 bits of entropy
available
[    1.395026] xen_netfront: Initialising Xen virtual ethernet driver
[    1.462872] blkfront: xvda2: flush diskcache: enabled; persistent
grants: enabled; indirect descriptors: enabled;
[    1.465338] Setting capacity to 20971520
[    1.465352] xvda2: detected capacity change from 0 to 10737418240
[    1.466851] blkfront: xvda1: flush diskcache: enabled; persistent
grants: enabled; indirect descriptors: enabled;
[    2.927311] PM: Starting manual resume from disk
[    2.927327] PM: Hibernation image partition 202:1 present
[    2.927329] PM: Looking for hibernation image.
[    2.927847] PM: Image not found (code -22)
[    2.927850] PM: Hibernation image not present or could not be loaded.
[    5.327133] random: nonblocking pool is initialized
[    6.193668] EXT4-fs (xvda2): mounted filesystem with ordered data mode.
Opts: (null)
[    9.539459] systemd[1]: systemd 215 running in system mode. (+PAM +AUDIT
+SELINUX +IMA +SYSVINIT +LIBCRYPTSETUP +GCRYPT +ACL +XZ -SECCOMP -APPARMOR)
[    9.539564] systemd[1]: Detected virtualization 'xen'.
[    9.539579] systemd[1]: Detected architecture 'x86-64'.
[   10.339528] systemd[1]: Inserted module 'autofs4'
[   10.396195] systemd[1]: Set hostname to <bug>.
[   11.949956] systemd[1]: Cannot add dependency job for unit dbus.socket,
ignoring: Unit dbus.socket failed to load: No such file or directory.
[   11.949986] systemd[1]: Cannot add dependency job for unit
display-manager.service, ignoring: Unit display-manager.service failed to
load: No such file or directory.
[   11.950446] systemd[1]: Starting Forward Password Requests to Wall
Directory Watch.
[   11.950588] systemd[1]: Started Forward Password Requests to Wall
Directory Watch.
[   11.950615] systemd[1]: Expecting device dev-hvc0.device...
[   11.950786] systemd[1]: Starting Remote File Systems (Pre).
[   11.950883] systemd[1]: Reached target Remote File Systems (Pre).
[   11.950934] systemd[1]: Starting Arbitrary Executable File Formats File
System Automount Point.
[   11.951149] systemd[1]: Set up automount Arbitrary Executable File
Formats File System Automount Point.
[   11.951187] systemd[1]: Starting Dispatch Password Requests to Console
Directory Watch.
[   11.951267] systemd[1]: Started Dispatch Password Requests to Console
Directory Watch.
[   11.951288] systemd[1]: Starting Paths.
[   11.951371] systemd[1]: Reached target Paths.
[   11.951394] systemd[1]: Starting Encrypted Volumes.
[   11.951471] systemd[1]: Reached target Encrypted Volumes.
[   11.951493] systemd[1]: Expecting device dev-xvda1.device...
[   11.951570] systemd[1]: Starting Root Slice.
[   11.951673] systemd[1]: Created slice Root Slice.
[   11.951695] systemd[1]: Starting User and Session Slice.
[   11.951819] systemd[1]: Created slice User and Session Slice.
[   11.951842] systemd[1]: Starting Delayed Shutdown Socket.
[   11.952330] systemd[1]: Listening on Delayed Shutdown Socket.
[   11.952357] systemd[1]: Starting /dev/initctl Compatibility Named Pipe.
[   11.952491] systemd[1]: Listening on /dev/initctl Compatibility Named
Pipe.
[   11.952514] systemd[1]: Starting Journal Socket (/dev/log).
[   11.952651] systemd[1]: Listening on Journal Socket (/dev/log).
[   11.952684] systemd[1]: Starting udev Kernel Socket.
[   11.952790] systemd[1]: Listening on udev Kernel Socket.
[   11.952819] systemd[1]: Starting udev Control Socket.
[   11.952930] systemd[1]: Listening on udev Control Socket.
[   11.952957] systemd[1]: Starting Journal Socket.
[   11.953089] systemd[1]: Listening on Journal Socket.
[   11.953127] systemd[1]: Starting System Slice.
[   11.953270] systemd[1]: Created slice System Slice.
[   11.953311] systemd[1]: Starting File System Check on Root Device...
[   11.954749] systemd[1]: Starting system-getty.slice.
[   11.954968] systemd[1]: Created slice system-getty.slice.
[   11.954992] systemd[1]: Starting system-serial\x2dgetty.slice.
[   11.955134] systemd[1]: Created slice system-serial\x2dgetty.slice.
[   11.955226] systemd[1]: Starting Increase datagram queue length...
[   11.956709] systemd[1]: Mounting POSIX Message Queue File System...
[   11.959557] systemd[1]: Mounting Debug File System...
[   12.135725] systemd[1]: Started Set Up Additional Binary Formats.
[   12.135808] systemd[1]: Mounting Huge Pages File System...
[   12.137545] systemd[1]: Starting Create list of required static device
nodes for the current kernel...
[   12.224465] systemd[1]: Starting Load Kernel Modules...
[   12.226092] systemd[1]: Starting udev Coldplug all Devices...
[   12.227596] systemd[1]: Starting Slices.
[   12.227728] systemd[1]: Reached target Slices.
[   12.233385] systemd[1]: Started Increase datagram queue length.
[   12.233708] systemd[1]: Starting Syslog Socket.
[   12.233859] systemd[1]: Listening on Syslog Socket.
[   12.233889] systemd[1]: Starting Sockets.
[   12.233969] systemd[1]: Reached target Sockets.
[   12.233995] systemd[1]: Starting Journal Service...
[   12.235536] systemd[1]: Started Journal Service.
[   14.527439] systemd-udevd[142]: starting version 215
[   14.879135] EXT4-fs (xvda2): re-mounted. Opts: errors=remount-ro
[   15.060743] systemd-journald[124]: Received request to flush runtime
journal from PID 1
[   15.138443] input: PC Speaker as /devices/platform/pcspkr/input/input0
[   15.140288] pcifront pci-0: Installing PCI frontend
[   15.140314] xen:swiotlb_xen: Warning: only able to allocate 4 MB for
software IO TLB
[   15.143506] software IO TLB [mem 0x02400000-0x02800000] (4MB) mapped at
[ffff880002400000-ffff8800027fffff]
[   15.143821] pcifront pci-0: Creating PCI Frontend Bus 0000:00
[   15.144654] pcifront pci-0: PCI host bridge to bus 0000:00
[   15.144666] pci_bus 0000:00: root bus resource [io  0x0000-0xffff]
[   15.144672] pci_bus 0000:00: root bus resource [mem
0x00000000-0xfffffffff]
[   15.144679] pci_bus 0000:00: root bus resource [bus 00-ff]
[   15.145145] pci 0000:00:01.0: [1912:0014] type 00 class 0x0c0330
[   15.145589] pci 0000:00:01.0: reg 0x10: [mem 0xfbff0000-0xfbff1fff 64bit]
[   15.150664] pci 0000:00:00.1: [14e4:165f] type 00 class 0x020000
[   15.151307] pci 0000:00:00.1: reg 0x10: [mem 0xfabc0000-0xfabcffff 64bit
pref]
[   15.151733] pci 0000:00:00.1: reg 0x18: [mem 0xfabb0000-0xfabbffff 64bit
pref]
[   15.152192] pci 0000:00:00.1: reg 0x20: [mem 0xfaba0000-0xfabaffff 64bit
pref]
[   15.155084] pcifront pci-0: New device on 0000:00:00.1 found.
[   15.157304] pcifront pci-0: claiming resource 0000:00:01.0/0
[   15.157316] pcifront pci-0: claiming resource 0000:00:00.1/0
[   15.157321] pcifront pci-0: claiming resource 0000:00:00.1/2
[   15.157326] pcifront pci-0: claiming resource 0000:00:00.1/4
[   15.157608] pci 0000:00:01.0: Xen PCI mapped GSI18 to IRQ29
[   15.226457] alg: No test for crc32 (crc32-pclmul)
[   15.365920] intel_rapl: Found RAPL domain package
[   15.365934] intel_rapl: Found RAPL domain core
[   15.416601] usbcore: registered new interface driver usbfs
[   15.416868] usbcore: registered new interface driver hub
[   15.416932] usbcore: registered new device driver usb
[   15.448763] xen:events: xen_bind_pirq_gsi_to_irq: returning irq 29 for
gsi 18
[   15.448783] xhci_hcd 0000:00:01.0: Xen PCI mapped GSI18 to IRQ29
[   15.449088] xhci_hcd 0000:00:01.0: xHCI Host Controller
[   15.449105] xhci_hcd 0000:00:01.0: new USB bus registered, assigned bus
number 1
[   15.461222] usb usb1: New USB device found, idVendor=1d6b, idProduct=0002
[   15.461245] usb usb1: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[   15.461265] usb usb1: Product: xHCI Host Controller
[   15.461271] usb usb1: Manufacturer: Linux 3.16.0-4-amd64 xhci_hcd
[   15.461276] usb usb1: SerialNumber: 0000:00:01.0
[   15.461635] hub 1-0:1.0: USB hub found
[   15.461660] hub 1-0:1.0: 2 ports detected
[   15.461796] xhci_hcd 0000:00:01.0: xHCI Host Controller
[   15.461808] xhci_hcd 0000:00:01.0: new USB bus registered, assigned bus
number 2
[   15.461855] usb usb2: We don't know the algorithms for LPM for this
host, disabling LPM.
[   15.461885] usb usb2: New USB device found, idVendor=1d6b, idProduct=0003
[   15.461891] usb usb2: New USB device strings: Mfr=3, Product=2,
SerialNumber=1
[   15.461897] usb usb2: Product: xHCI Host Controller
[   15.461901] usb usb2: Manufacturer: Linux 3.16.0-4-amd64 xhci_hcd
[   15.461906] usb usb2: SerialNumber: 0000:00:01.0
[   15.462175] hub 2-0:1.0: USB hub found
[   15.462194] hub 2-0:1.0: 2 ports detected
[   15.523663] pps_core: LinuxPPS API ver. 1 registered
[   15.523676] pps_core: Software ver. 5.3.6 - Copyright 2005-2007 Rodolfo
Giometti <giometti@linux.it>
[   15.557171] PTP clock support registered
[   15.642442] tg3.c:v3.137 (May 11, 2014)
[   15.642549] tg3 0000:00:00.1: Xen PCI mapped GSI17 to IRQ32
[   15.673476] tg3 0000:00:00.1 eth1: Tigon3 [partno(N/A) rev 5720000] (PCI
Express) MAC address 34:64:a9:9a:a8:b1
[   15.673494] tg3 0000:00:00.1 eth1: attached PHY is 5720C
(10/100/1000Base-T Ethernet) (WireSpeed[1], EEE[1])
[   15.673502] tg3 0000:00:00.1 eth1: RXcsums[1] LinkChgREG[0] MIirq[0]
ASF[1] TSOcap[1]
[   15.673508] tg3 0000:00:00.1 eth1: dma_rwctrl[00000001] dma_mask[64-bit]
[   15.727471] Adding 262140k swap on /dev/xvda1.  Priority:-1 extents:1
across:262140k SSFS
[   15.776043] usb 1-1: new high-speed USB device number 2 using xhci_hcd
[   15.908336] usb 1-1: New USB device found, idVendor=1307, idProduct=0163
[   15.908350] usb 1-1: New USB device strings: Mfr=1, Product=2,
SerialNumber=3
[   15.908356] usb 1-1: Product: USB Mass Storage Device
[   15.908361] usb 1-1: Manufacturer: USBest Technology
[   15.908366] usb 1-1: SerialNumber: 081104644414d4
[   15.996660] SCSI subsystem initialized
[   16.008836] usb-storage 1-1:1.0: USB Mass Storage device detected
[   16.008940] scsi0 : usb-storage 1-1:1.0
[   16.009037] usbcore: registered new interface driver usb-storage
[   17.009371] scsi 0:0:0:0: Direct-Access
0.00 PQ: 0 ANSI: 2
[   17.011432] scsi 0:0:0:1: CD-ROM
0.00 PQ: 0 ANSI: 0 CCS
[   17.075703] sr0: scsi3-mmc drive: 93x/93x cd/rw xa/form2 cdda tray
[   17.075720] cdrom: Uniform CD-ROM driver Revision: 3.20
[   17.076299] sr 0:0:0:1: Attached scsi CD-ROM sr0
[   17.092662] scsi 0:0:0:0: Attached scsi generic sg0 type 0
[   17.092787] sr 0:0:0:1: Attached scsi generic sg1 type 5
[   17.149685] sd 0:0:0:0: [sda] 1968127 512-byte logical blocks: (1.00
GB/960 MiB)
[   17.151230] sd 0:0:0:0: [sda] Write Protect is off
[   17.151242] sd 0:0:0:0: [sda] Mode Sense: 00 00 00 00
[   17.154123] sd 0:0:0:0: [sda] Asking for cache data failed
[   17.154139] sd 0:0:0:0: [sda] Assuming drive cache: write through
[   17.269987]  sda: sda1 sda2
[   17.272430] sd 0:0:0:0: [sda] Attached SCSI removable disk


dom0 "xl dmesg":
(XEN) Xen version 4.4.1 (Debian 4.4.1-9+deb8u3) (ultrotter@debian.org) (gcc
(Debian 4.9.2-10) 4.9.2) debug=n Wed Nov 25 15:46:22 EET 2015
(XEN) Bootloader: GRUB 2.02~beta2-22+deb8u1
(XEN) Command line: placeholder dom0_mem=1024M,max:1024M
(XEN) Video information:
(XEN)  VGA is text mode 80x25, font 8x16
(XEN)  VBE/DDC methods: none; EDID transfer time: 0 seconds
(XEN)  EDID info not retrieved because no DDC retrieval method detected
(XEN) Disc information:
(XEN)  Found 4 MBR signatures
(XEN)  Found 2 EDD information structures
(XEN) Xen-e820 RAM map:
(XEN)  0000000000000000 - 0000000000099800 (usable)
(XEN)  0000000000099800 - 0000000000099c00 (reserved)
(XEN)  000000000009e000 - 00000000000a0000 (reserved)
(XEN)  00000000000f0000 - 0000000000100000 (reserved)
(XEN)  0000000000100000 - 00000000f1de4000 (usable)
(XEN)  00000000f1de4000 - 00000000f1dee000 (ACPI data)
(XEN)  00000000f1dee000 - 00000000f8000000 (reserved)
(XEN)  00000000fec00000 - 00000000fee10000 (reserved)
(XEN)  00000000ff800000 - 0000000100000000 (reserved)
(XEN)  0000000100000000 - 000000028bfff000 (usable)
(XEN) ACPI: RSDP 000F4F00, 0024 (r2 HP    )
(XEN) ACPI: XSDT F1DE6400, 00B4 (r1 HP     ProLiant        2   ?     162E)
(XEN) ACPI: FACP F1DE6540, 00F4 (r3 HP     ProLiant        2   ?     162E)
(XEN) ACPI: DSDT F1DE6640, 1C1A (r1 HP         DSDT        1 INTL 20030228)
(XEN) ACPI: FACS F1DE4140, 0040
(XEN) ACPI: SPCR F1DE4180, 0050 (r1 HP     SPCRRBSU        1   ?     162E)
(XEN) ACPI: MCFG F1DE4200, 003C (r1 HP     ProLiant        1             0)
(XEN) ACPI: HPET F1DE4240, 0038 (r1 HP     ProLiant        2   ?     162E)
(XEN) ACPI: FFFF F1DE4280, 0064 (r2 HP     ProLiant        2   ?     162E)
(XEN) ACPI: SPMI F1DE4300, 0040 (r5 HP     ProLiant        1   ?     162E)
(XEN) ACPI: ERST F1DE4340, 0230 (r1 HP     ProLiant        1   ?     162E)
(XEN) ACPI: APIC F1DE4580, 0252 (r1 HP     ProLiant        2             0)
(XEN) ACPI: FFFF F1DE4800, 0176 (r1 HP     ProLiant        1   ?     162E)
(XEN) ACPI: BERT F1DE4980, 0030 (r1 HP     ProLiant        1   ?     162E)
(XEN) ACPI: HEST F1DE49C0, 00BC (r1 HP     ProLiant        1   ?     162E)
(XEN) ACPI: FFFF F1DE4A80, 1914 (r1 HP     ProLiant        1   ?     162E)
(XEN) ACPI: FFFF F1DE63C0, 002D (r1 HP     ProLiant        1             0)
(XEN) ACPI: SSDT F1DE8280, 0137 (r3     HP  CRSPCI0        2   HP        1)
(XEN) ACPI: SSDT F1DE83C0, 0177 (r3     HP   riser0        2 INTL 20030228)
(XEN) ACPI: SSDT F1DE8540, 01E1 (r1     HP      pcc        1 INTL 20090625)
(XEN) ACPI: SSDT F1DE8740, 0377 (r1     HP     pmab        1 INTL 20090625)
(XEN) ACPI: SSDT F1DE8AC0, 0504 (r1 INTEL  PPM RCM  80000001 INTL 20061109)
(XEN) System RAM: 10205MB (10450416kB)
(XEN) Domain heap initialised
(XEN) Processor #0 7:10 APIC version 21
(XEN) Processor #2 7:10 APIC version 21
(XEN) IOAPIC[0]: apic_id 8, version 32, address 0xfec00000, GSI 0-23
(XEN) Enabling APIC mode:  Flat.  Using 1 I/O APICs
(XEN) Using scheduler: SMP Credit Scheduler (credit)
(XEN) Detected 2294.851 MHz processor.
(XEN) Initing memory sharing.
(XEN) xstate_init: using cntxt_size: 0x240 and states: 0x3
(XEN) I/O virtualisation disabled
(XEN) Enabled directed EOI with ioapic_ack_old on!
(XEN) ENABLING IO-APIC IRQs
(XEN)  -> Using old ACK method
(XEN) Platform timer is 14.318MHz HPET
(XEN) Allocated console ring of 16 KiB.
(XEN) VMX: Supported advanced features:
(XEN)  - APIC MMIO access virtualisation
(XEN)  - APIC TPR shadow
(XEN)  - Extended Page Tables (EPT)
(XEN)  - Virtual-Processor Identifiers (VPID)
(XEN)  - Virtual NMI
(XEN)  - MSR direct-access bitmap
(XEN)  - Unrestricted Guest
(XEN) HVM: ASIDs enabled.
(XEN) HVM: VMX enabled
(XEN) HVM: Hardware Assisted Paging (HAP) detected
(XEN) HVM: HAP page sizes: 4kB, 2MB
(XEN) Brought up 2 CPUs
(XEN) *** LOADING DOMAIN 0 ***
(XEN)  Xen  kernel: 64-bit, lsb, compat32
(XEN)  Dom0 kernel: 64-bit, PAE, lsb, paddr 0x1000000 -> 0x1f18000
(XEN) PHYSICAL MEMORY ARRANGEMENT:
(XEN)  Dom0 alloc.:   000000023c000000->0000000240000000 (241834 pages to
be allocated)
(XEN)  Init. ramdisk: 000000028aeaa000->000000028bdffc27
(XEN) VIRTUAL MEMORY ARRANGEMENT:
(XEN)  Loaded kernel: ffffffff81000000->ffffffff81f18000
(XEN)  Init. ramdisk: ffffffff81f18000->ffffffff82e6dc27
(XEN)  Phys-Mach map: ffffffff82e6e000->ffffffff8306e000
(XEN)  Start info:    ffffffff8306e000->ffffffff8306e4b4
(XEN)  Page tables:   ffffffff8306f000->ffffffff8308c000
(XEN)  Boot stack:    ffffffff8308c000->ffffffff8308d000
(XEN)  TOTAL:         ffffffff80000000->ffffffff83400000
(XEN)  ENTRY ADDRESS: ffffffff819021f0
(XEN) Dom0 has maximum 2 VCPUs
(XEN) Scrubbing Free RAM:
..........................................................................................done.
(XEN) Initial low memory virq threshold set at 0x4000 pages.
(XEN) Std. Loglevel: Errors and warnings
(XEN) Guest Loglevel: Nothing (Rate-limited: Errors and warnings)
(XEN) Xen is relinquishing VGA console.
(XEN) *** Serial input -> DOM0 (type 'CTRL-a' three times to switch input
to Xen)
(XEN) Freed 284kB init memory.
(XEN) mm.c:812: d13: Forcing read-only access to MFN fbff1
(XEN) mm.c:812: d13: Forcing read-only access to MFN fbff1
(XEN) mm.c:812: d13: Forcing read-only access to MFN fbff1
(XEN) mm.c:812: d0: Forcing read-only access to MFN fbff1



Br,
Tommi Airikka


On Thu, Feb 4, 2016 at 10:37 AM, Ian Campbell <ian.campbell@citrix.com>
wrote:

> On Wed, 2016-02-03 at 15:28 -0500, Konrad Rzeszutek Wilk wrote:
> > > > And I wonder if the XEN_DOMCTL_irq_permission aka,
> > > > xc_domain_irq_permission
> > > > had been called. I remember that at some point we missed it for
> > > > Xend..
> > > >
> >
> > False alarm.
> >
> > It was all in Linux. Attached are four patches (the first two
> > are for your issue you discovered).
> > I was wondering if there is a way for you to test them?
>
> Tommy,
>
> Please see the Debian Kernel Handbook and in particular
>
> https://www.debian.org/doc/manuals/debian-kernel-handbook/ch-common-tasks.html#s-common-official
> for instructions on rebuilding the Debian kernel with additional patches.
>
> Ian.
>
>
Konrad Rzeszutek Wilk Feb. 12, 2016, 9:36 p.m. UTC | #3
On Fri, Feb 05, 2016 at 12:35:10AM +0100, Tommi Airikka wrote:
> Hi,
> 
> I patched the deb8u2 source with all four patches and built a new deb.
.. snip..
> 
> Next, I upgraded dom0 with the new linux-image deb and rebooted the machine.
> 
> dom0 "uname -a":
> Linux dom0 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u2a~test
> (2016-02-04) x86_64 GNU/Linux
> 
> domU 'bug' "uname -a":
> Linux bug 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u2a~test
> (2016-02-04) x86_64 GNU/Linux
> 
> And now everything seems to work. No more "Failed to obtain physical IRQ",
> I can mount my usb flash stick using the passthroughed usb controller. No
> call traces in dmesg.

Awesome!

Are you OK if I put 'Tested-by' on the patches from you?
Tommi Airikka Feb. 12, 2016, 9:53 p.m. UTC | #4
Yes, you can put the 'Tested-by' from me, I'm perfectly fine with that.

Thank you for your help!

Br,
Tommi
On Fri, Feb 05, 2016 at 12:35:10AM +0100, Tommi Airikka wrote:
> Hi,
>
> I patched the deb8u2 source with all four patches and built a new deb.
.. snip..
>
> Next, I upgraded dom0 with the new linux-image deb and rebooted the
machine.
>
> dom0 "uname -a":
> Linux dom0 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u2a~test
> (2016-02-04) x86_64 GNU/Linux
>
> domU 'bug' "uname -a":
> Linux bug 3.16.0-4-amd64 #1 SMP Debian 3.16.7-ckt20-1+deb8u2a~test
> (2016-02-04) x86_64 GNU/Linux
>
> And now everything seems to work. No more "Failed to obtain physical IRQ",
> I can mount my usb flash stick using the passthroughed usb controller. No
> call traces in dmesg.

Awesome!

Are you OK if I put 'Tested-by' on the patches from you?
diff mbox

Patch

diff --git a/drivers/xen/xen-pciback/pciback_ops.c b/drivers/xen/xen-pciback/pciback_ops.c
index 73dafdc..8c86a53 100644
--- a/drivers/xen/xen-pciback/pciback_ops.c
+++ b/drivers/xen/xen-pciback/pciback_ops.c
@@ -213,6 +213,7 @@  int xen_pcibk_enable_msix(struct xen_pcibk_device *pdev,
 	int i, result;
 	struct msix_entry *entries;
 	u16 cmd;
+	struct pci_dev *phys_dev;
 
 	if (unlikely(verbose_request))
 		printk(KERN_DEBUG DRV_NAME ": %s: enable MSI-X\n",
@@ -227,8 +228,10 @@  int xen_pcibk_enable_msix(struct xen_pcibk_device *pdev,
 	/*
 	 * PCI_COMMAND_MEMORY must be enabled, otherwise we may not be able
 	 * to access the BARs where the MSI-X entries reside.
+	 * But VF devices are unique in which the PF needs to be checked.
 	 */
-	pci_read_config_word(dev, PCI_COMMAND, &cmd);
+	phys_dev = pci_physfn(dev);
+	pci_read_config_word(phys_dev, PCI_COMMAND, &cmd);
 	if (dev->msi_enabled || !(cmd & PCI_COMMAND_MEMORY))
 		return -ENXIO;