Re: [Qemu-devel] Commit 9e047b982452c633882b486682966c1d97097015 (piix4: add acpi pci hotplug support) seems to break Xen pci-passthrough

[Igor Mammedov <imammedo@redhat.com>]

On Tue, 4 Feb 2014 16:07:08 +0100
Sander Eikelenboom <linux@eikelenboom.it> wrote:

> 
> Tuesday, February 4, 2014, 3:32:19 PM, you wrote:
> 
> > On Tue, Feb 04, 2014 at 12:46:08AM +0100, Sander Eikelenboom wrote:
> >> Grmbll my fat fingers hit the send shortcut too soon by accident ..
> >> let's try again ..
> >> 
> >> Hi Michael,
> >> 
> >> A git bisect turned out that commit 9e047b982452c633882b486682966c1d97097015 breaks pci-passthrough on Xen.
> >> 
> >> commit 9e047b982452c633882b486682966c1d97097015
> >> Author: Michael S. Tsirkin <mst@redhat.com>
> >> Date:   Mon Oct 14 18:01:20 2013 +0300
> >> 
> >>     piix4: add acpi pci hotplug support
> >> 
> >>     Add support for acpi pci hotplug using the
> >>     new infrastructure.
> >>     PIIX4 legacy interface is maintained as is for
> >>     machine types 1.7 and older.
> >> 
> >>     Signed-off-by: Michael S. Tsirkin <mst@redhat.com>
> >> 
> >> 
> >> The error is not very verbose :
> >> 
> >> libxl: error: libxl_qmp.c:287:qmp_handle_error_response: received an error message from QMP server: Device initialization failed.
> >> libxl: error: libxl_qmp.c:287:qmp_handle_error_response: received an error message from QMP server: Device initialization failed.
> >> libxl: error: libxl_qmp.c:287:qmp_handle_error_response: received an error message from QMP server: Device initialization failed.
> >> libxl: error: libxl_qmp.c:287:qmp_handle_error_response: received an error message from QMP server: Device initialization failed.
> >> 
> >> So it seems there is an issue with preserving the legacy interface.
> 
> 
> > Which machine type is broken?
> 
> xenfv
> 
> > What's the command line used?
> 
> See below the output of the creation of the guest
> 
> Strange thing is:
> char device redirected to /dev/pts/15 (label serial0)
> vgabios-cirrus.bin: ROM id 101300b8 / PCI id 101300b8
> efi-e1000.rom: ROM id 8086100e / PCI id 8086100e
> VNC server running on `127.0.0.1:5900'
> xen_platform: changed ro/rw state of ROM memory area. now is rw state.
> [00:05.0] xen_pt_initfn: Assigning real physical device 06:01.0 to devfn 0x28
> [00:05.0] xen_pt_register_regions: IO region 0 registered (size=0x00001000 base_addr=0xfe0fd000 type: 0)
> [00:05.0] xen_pt_pci_intx: intx=1
> [00:05.0] xen_pt_initfn: Real physical device 06:01.0 registered successfully!
> [00:05.0] xen_pt_pci_intx: intx=1
> [00:05.0] xen_pt_initfn: Assigning real physical device 06:01.1 to devfn 0x28
> [00:05.0] xen_pt_register_regions: IO region 0 registered (size=0x00001000 base_addr=0xfe0fe000 type: 0)
> [00:05.0] xen_pt_pci_intx: intx=2
> [00:05.0] xen_pt_initfn: Real physical device 06:01.1 registered successfully!
> [00:05.0] xen_pt_pci_intx: intx=2
> [00:05.0] xen_pt_initfn: Assigning real physical device 06:01.2 to devfn 0x28
> [00:05.0] xen_pt_register_regions: IO region 0 registered (size=0x00000100 base_addr=0xfe0ffc00 type: 0)
> [00:05.0] xen_pt_pci_intx: intx=3
> [00:05.0] xen_pt_initfn: Real physical device 06:01.2 registered successfully!
> [00:05.0] xen_pt_pci_intx: intx=3
> [00:05.0] xen_pt_initfn: Assigning real physical device 08:00.0 to devfn 0x28
> [00:05.0] xen_pt_register_regions: IO region 0 registered (size=0x00200000 base_addr=0xfe200000 type: 0x4)
> [00:05.0] xen_pt_pci_intx: intx=1
> [00:05.0] xen_pt_initfn: Real physical device 08:00.0 registered successfully!
> [00:05.0] xen_pt_pci_intx: intx=1
> [00:05.0] xen_pt_msi_set_enable: disabling MSI.
> 
> It's does log succes for registering the pci devices .. however it returns by qmp that the device initialization failed.
> And an lspci in the guest also doesn't show the devices.
> 
> > What's the value of has_acpi_build in hw/i386/pc_piix.c?
> static bool has_acpi_build = true;
> 
> > What happens if you add
> > -global PIIX4_PM.acpi-pci-hotplug-with-bridge-support=off
> 
> That makes it work again ...
Does it still work with
http://www.mail-archive.com/qemu-devel@nongnu.org/msg213815.html


> 
> 
> >> --
> >> Sander
> >> 
> 
> 
> Parsing config from /etc/xen/domU/production/security.cfg
> libxl: debug: libxl_create.c:1348:do_domain_create: ao 0x1415900: create: how=(nil) callback=(nil) poller=0x1415960
> libxl: debug: libxl_device.c:251:libxl__device_disk_set_backend: Disk vdev=hda spec.backend=unknown
> libxl: debug: libxl_device.c:286:libxl__device_disk_set_backend: Disk vdev=hda, using backend phy
> libxl: debug: libxl_device.c:251:libxl__device_disk_set_backend: Disk vdev=hdb spec.backend=unknown
> libxl: debug: libxl_device.c:286:libxl__device_disk_set_backend: Disk vdev=hdb, using backend phy
> libxl: debug: libxl_create.c:803:initiate_domain_create: running bootloader
> libxl: debug: libxl_bootloader.c:321:libxl__bootloader_run: not a PV domain, skipping bootloader
> libxl: debug: libxl_event.c:607:libxl__ev_xswatch_deregister: watch w=0x1415ce8: deregister unregistered
> xc: detail: elf_parse_binary: phdr: paddr=0x100000 memsz=0x9efa8
> xc: detail: elf_parse_binary: memory: 0x100000 -> 0x19efa8
> xc: detail: VIRTUAL MEMORY ARRANGEMENT:
>   Loader:        0000000000100000->000000000019efa8
>   Modules:       0000000000000000->0000000000000000
>   TOTAL:         0000000000000000->000000003f800000
>   ENTRY ADDRESS: 0000000000100000
> xc: detail: PHYSICAL MEMORY ALLOCATION:
>   4KB PAGES: 0x0000000000000200
>   2MB PAGES: 0x00000000000001fb
>   1GB PAGES: 0x0000000000000000
> xc: detail: elf_load_binary: phdr 0 at 0x7fdc08ee7000 -> 0x7fdc08f7ce2d
> libxl: debug: libxl_device.c:251:libxl__device_disk_set_backend: Disk vdev=hda spec.backend=phy
> libxl: debug: libxl_event.c:559:libxl__ev_xswatch_register: watch w=0x14171e8 wpath=/local/domain/0/backend/vbd/30/768/state token=3/0: register slotnum=3
> libxl: debug: libxl_device.c:251:libxl__device_disk_set_backend: Disk vdev=hdb spec.backend=phy
> libxl: debug: libxl_device.c:251:libxl__device_disk_set_backend: Disk vdev=hdb spec.backend=phy
> libxl: debug: libxl_event.c:559:libxl__ev_xswatch_register: watch w=0x1418238 wpath=/local/domain/0/backend/vbd/30/832/state token=2/1: register slotnum=2
> libxl: debug: libxl_create.c:1362:do_domain_create: ao 0x1415900: inprogress: poller=0x1415960, flags=i
> libxl: debug: libxl_event.c:503:watchfd_callback: watch w=0x14171e8 wpath=/local/domain/0/backend/vbd/30/768/state token=3/0: event epath=/local/domain/0/backend/vbd/30/768/state
> libxl: debug: libxl_event.c:642:devstate_watch_callback: backend /local/domain/0/backend/vbd/30/768/state wanted state 2 ok
> libxl: debug: libxl_event.c:595:libxl__ev_xswatch_deregister: watch w=0x14171e8 wpath=/local/domain/0/backend/vbd/30/768/state token=3/0: deregister slotnum=3
> libxl: debug: libxl_event.c:607:libxl__ev_xswatch_deregister: watch w=0x14171e8: deregister unregistered
> libxl: debug: libxl_device.c:1022:device_hotplug: calling hotplug script: /etc/xen/scripts/block add
> libxl: debug: libxl_event.c:472:watchfd_callback: watch epath=/local/domain/0/backend/vbd/30/768/state token=3/0: empty slot
> libxl: debug: libxl_event.c:503:watchfd_callback: watch w=0x1418238 wpath=/local/domain/0/backend/vbd/30/832/state token=2/1: event epath=/local/domain/0/backend/vbd/30/832/state
> libxl: debug: libxl_event.c:642:devstate_watch_callback: backend /local/domain/0/backend/vbd/30/832/state wanted state 2 ok
> libxl: debug: libxl_event.c:595:libxl__ev_xswatch_deregister: watch w=0x1418238 wpath=/local/domain/0/backend/vbd/30/832/state token=2/1: deregister slotnum=2
> libxl: debug: libxl_event.c:607:libxl__ev_xswatch_deregister: watch w=0x1418238: deregister unregistered
> libxl: debug: libxl_device.c:1022:device_hotplug: calling hotplug script: /etc/xen/scripts/block add
> libxl: debug: libxl_event.c:472:watchfd_callback: watch epath=/local/domain/0/backend/vbd/30/832/state token=2/1: empty slot
> libxl: debug: libxl_event.c:607:libxl__ev_xswatch_deregister: watch w=0x1417270: deregister unregistered
> libxl: debug: libxl_event.c:607:libxl__ev_xswatch_deregister: watch w=0x1417270: deregister unregistered
> libxl: debug: libxl_event.c:607:libxl__ev_xswatch_deregister: watch w=0x14182c0: deregister unregistered
> libxl: debug: libxl_event.c:607:libxl__ev_xswatch_deregister: watch w=0x14182c0: deregister unregistered
> libxl: debug: libxl_dm.c:1308:libxl__spawn_local_dm: Spawning device-model /usr/local/lib/xen/bin/qemu-system-i386 with arguments:
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   /usr/local/lib/xen/bin/qemu-system-i386
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -xen-domid
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   30
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -chardev
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   socket,id=libxl-cmd,path=/var/run/xen/qmp-libxl-30,server,nowait
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -mon
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   chardev=libxl-cmd,mode=control
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -nodefaults
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -name
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   security
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -serial
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   pty
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -device
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   cirrus-vga
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -global
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   vga.vram_size_mb=8
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -boot
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   order=c
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -smp
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   4,maxcpus=4
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -device
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   e1000,id=nic0,netdev=net0,mac=00:16:3e:a0:72:69
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -netdev
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   type=tap,id=net0,ifname=vif30.0-emu,script=no,downscript=no
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -machine
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   xenfv
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -m
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   1016
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -drive
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   file=/dev/xen_vms/security,if=ide,index=0,media=disk,format=raw,cache=writeback
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   -drive
> libxl: debug: libxl_dm.c:1310:libxl__spawn_local_dm:   file=/dev/xen_vms/security_data,if=ide,index=1,media=disk,format=raw,cache=writeback
> libxl: debug: libxl_event.c:559:libxl__ev_xswatch_register: watch w=0x1415f20 wpath=/local/domain/0/device-model/30/state token=2/2: register slotnum=2
> libxl: debug: libxl_event.c:503:watchfd_callback: watch w=0x1415f20 wpath=/local/domain/0/device-model/30/state token=2/2: event epath=/local/domain/0/device-model/30/state
> libxl: debug: libxl_event.c:503:watchfd_callback: watch w=0x1415f20 wpath=/local/domain/0/device-model/30/state token=2/2: event epath=/local/domain/0/device-model/30/state
> libxl: debug: libxl_event.c:595:libxl__ev_xswatch_deregister: watch w=0x1415f20 wpath=/local/domain/0/device-model/30/state token=2/2: deregister slotnum=2
> libxl: debug: libxl_event.c:607:libxl__ev_xswatch_deregister: watch w=0x1415f20: deregister unregistered
> libxl: debug: libxl_qmp.c:696:libxl__qmp_initialize: connected to /var/run/xen/qmp-libxl-30
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: qmp
> libxl: debug: libxl_qmp.c:546:qmp_send_prepare: next qmp command: '{
>     "execute": "qmp_capabilities",
>     "id": 1
> }
> '
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: return
> libxl: debug: libxl_qmp.c:546:qmp_send_prepare: next qmp command: '{
>     "execute": "query-chardev",
>     "id": 2
> }
> '
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: return
> libxl: debug: libxl_qmp.c:546:qmp_send_prepare: next qmp command: '{
>     "execute": "query-vnc",
>     "id": 3
> }
> '
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: return
> libxl: debug: libxl_event.c:559:libxl__ev_xswatch_register: watch w=0x1419d68 wpath=/local/domain/0/backend/vif/30/0/state token=2/3: register slotnum=2
> libxl: debug: libxl_event.c:503:watchfd_callback: watch w=0x1419d68 wpath=/local/domain/0/backend/vif/30/0/state token=2/3: event epath=/local/domain/0/backend/vif/30/0/state
> libxl: debug: libxl_event.c:646:devstate_watch_callback: backend /local/domain/0/backend/vif/30/0/state wanted state 2 still waiting state 1
> libxl: debug: libxl_event.c:503:watchfd_callback: watch w=0x1419d68 wpath=/local/domain/0/backend/vif/30/0/state token=2/3: event epath=/local/domain/0/backend/vif/30/0/state
> libxl: debug: libxl_event.c:642:devstate_watch_callback: backend /local/domain/0/backend/vif/30/0/state wanted state 2 ok
> libxl: debug: libxl_event.c:595:libxl__ev_xswatch_deregister: watch w=0x1419d68 wpath=/local/domain/0/backend/vif/30/0/state token=2/3: deregister slotnum=2
> libxl: debug: libxl_event.c:607:libxl__ev_xswatch_deregister: watch w=0x1419d68: deregister unregistered
> libxl: debug: libxl_device.c:1022:device_hotplug: calling hotplug script: /etc/xen/scripts/vif-bridge online
> libxl: debug: libxl_event.c:607:libxl__ev_xswatch_deregister: watch w=0x1419df0: deregister unregistered
> libxl: debug: libxl_device.c:1022:device_hotplug: calling hotplug script: /etc/xen/scripts/vif-bridge add
> libxl: debug: libxl_event.c:607:libxl__ev_xswatch_deregister: watch w=0x1419df0: deregister unregistered
> libxl: debug: libxl_event.c:607:libxl__ev_xswatch_deregister: watch w=0x1419df0: deregister unregistered
> libxl: debug: libxl_qmp.c:696:libxl__qmp_initialize: connected to /var/run/xen/qmp-libxl-30
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: qmp
> libxl: debug: libxl_qmp.c:546:qmp_send_prepare: next qmp command: '{
>     "execute": "qmp_capabilities",
>     "id": 1
> }
> '
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: return
> libxl: debug: libxl_qmp.c:546:qmp_send_prepare: next qmp command: '{
>     "execute": "device_add",
>     "id": 2,
>     "arguments": {
>         "driver": "xen-pci-passthrough",
>         "id": "pci-pt-06_01.0",
>         "hostaddr": "0000:06:01.0"
>     }
> }
> '
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: error
> libxl: error: libxl_qmp.c:287:qmp_handle_error_response: received an error message from QMP server: Device initialization failed.
> libxl: debug: libxl_qmp.c:696:libxl__qmp_initialize: connected to /var/run/xen/qmp-libxl-30
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: qmp
> libxl: debug: libxl_qmp.c:546:qmp_send_prepare: next qmp command: '{
>     "execute": "qmp_capabilities",
>     "id": 1
> }
> '
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: return
> libxl: debug: libxl_qmp.c:546:qmp_send_prepare: next qmp command: '{
>     "execute": "device_add",
>     "id": 2,
>     "arguments": {
>         "driver": "xen-pci-passthrough",
>         "id": "pci-pt-06_01.1",
>         "hostaddr": "0000:06:01.1"
>     }
> }
> '
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: error
> libxl: error: libxl_qmp.c:287:qmp_handle_error_response: received an error message from QMP server: Device initialization failed.
> libxl: debug: libxl_qmp.c:696:libxl__qmp_initialize: connected to /var/run/xen/qmp-libxl-30
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: qmp
> libxl: debug: libxl_qmp.c:546:qmp_send_prepare: next qmp command: '{
>     "execute": "qmp_capabilities",
>     "id": 1
> }
> '
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: return
> libxl: debug: libxl_qmp.c:546:qmp_send_prepare: next qmp command: '{
>     "execute": "device_add",
>     "id": 2,
>     "arguments": {
>         "driver": "xen-pci-passthrough",
>         "id": "pci-pt-06_01.2",
>         "hostaddr": "0000:06:01.2"
>     }
> }
> '
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: error
> libxl: error: libxl_qmp.c:287:qmp_handle_error_response: received an error message from QMP server: Device initialization failed.
> libxl: debug: libxl_qmp.c:696:libxl__qmp_initialize: connected to /var/run/xen/qmp-libxl-30
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: qmp
> libxl: debug: libxl_qmp.c:546:qmp_send_prepare: next qmp command: '{
>     "execute": "qmp_capabilities",
>     "id": 1
> }
> '
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: return
> libxl: debug: libxl_qmp.c:546:qmp_send_prepare: next qmp command: '{
>     "execute": "device_add",
>     "id": 2,
>     "arguments": {
>         "driver": "xen-pci-passthrough",
>         "id": "pci-pt-08_00.0",
>         "hostaddr": "0000:08:00.0"
>     }
> }
> '
> libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: error
> libxl: error: libxl_qmp.c:287:qmp_handle_error_response: received an error message from QMP server: Device initialization failed.
> libxl: debug: libxl_pci.c:81:libxl__create_pci_backend: Creating pci backend
> libxl: debug: libxl_event.c:1729:libxl__ao_progress_report: ao 0x1415900: progress report: ignored
> libxl: debug: libxl_event.c:1559:libxl__ao_complete: ao 0x1415900: complete, rc=0
> libxl: debug: libxl_event.c:1531:libxl__ao__destroy: ao 0x1415900: destroy
> xc: debug: hypercall buffer: total allocations:530 total releases:530
> xc: debug: hypercall buffer: current allocations:0 maximum allocations:2
> xc: debug: hypercall buffer: cache current size:2
> xc: debug: hypercall buffer: cache hits:526 misses:2 toobig:2
> 
> 


-- 
Regards,
  Igor