Xen on FreeBSD 11: Cannot boot from QCOW2 properly (waiting for XENBUS, xenbusb_nop_confighook_cb)

Alexander Nusov alexander.nusov at nfvexpress.com
Mon Jan 23 15:26:04 UTC 2017 

Hello,
Sorry for cross-posting, since it's related to Xen hypervisor I'm forwarding this message to the freebsd-xen mailing list.

I'm trying to launch a HVM DomU guest from QCOW2 image by using PV driver on FreeBSD 11 Dom0.
The issue is that guest cannot connect to the device/vbd and requires to wait for 4 minutes to proceed, it goes through the countdown and starts fine (disk, networking)

[    6.684115] XENBUS: Waiting for devices to initialise: 25s...20s...15s...10s...5s...0s...235s...230s...225s...220s...215s...210s...205s...200s...195s...190s...185s...180s...175s...170s...165s...160s...155s...150s...145s...140s...135s...130s...125s...120s...115s...110s...105s...100s...95s...90s...85s...80s...75s...70s...65s...60s...55s...50s...45s...40s...35s...30s...25s...20s...15s...10s...5s...0s...
[  271.591403] XENBUS: Timeout connecting to device: device/vbd/51712 (local state 3, remote state 1)
[  271.599963] XENBUS: Device with no driver: device/vkbd/0
[  271.604249]   Magic number: 1:453:334
...
login: 


Unlike Linux It's impossible to boot FreeBSD 11 guests from QCOW2 (xenbusb_nop_confighook_cb timeout)

Steps to reproduce:
1. Download qcow2 cirros image (small linux) 
http://download.cirros-cloud.net/0.3.4/cirros-0.3.4-x86_64-disk.img <http://download.cirros-cloud.net/0.3.4/cirros-0.3.4-x86_64-disk.img> <http://download.cirros-cloud.net/0.3.4/cirros-0.3.4-x86_64-disk.img <http://download.cirros-cloud.net/0.3.4/cirros-0.3.4-x86_64-disk.img>>
# file cirros-0.3.4-x86_64-disk.img 
cirros-0.3.4-x86_64-disk.img: QEMU QCOW Image (v2), 41126400 bytes
2. create DomU from config bellow xl create -c config.cfg

builder = "hvm"
memory = 512
vcpus = 2
name = "cirros"
disk = [ 'file:qcow2:/root/cirros-0.3.4-x86_64-disk.img,xvda,w' ]
boot = "c" 
vnc = 1
vnclisten = "0.0.0.0"
usbdevice = 'tablet'
on_poweroff = 'destroy'
on_reboot = 'restart'
on_crash = 'restart'
acpi = 1
serial = 'pty'

I've also tried multiple configurations like tap:qcow2:. tap2:qcow2:, aio:, switching from xen bus to ide. didn't work.
The only driver that had no issues was PHY but it supports only RAW images.

Is that a bug or I'm missing something?

tested both STABLE snapshot and 11.0-RELEASE

# uname -a
FreeBSD xen 11.0-STABLE FreeBSD 11.0-STABLE #0 r311441: Thu Jan  5 22:45:20 UTC 2017

# pkg info | grep xen
xen-4.7.0_2                    Xen Hypervisor meta port
xen-kernel-4.7.1_3             Hypervisor using a microkernel design
xen-tools-4.7.1_1              Xen management tool, based on LibXenlight

# cat /boot/loader.conf 
hw.pci.mcfg=0
xen_kernel="/boot/xen"
xen_cmdline="dom0_mem=8192M dom0_max_vcpus=8 dom0pvh=1 com1=115200,8n1 guest_loglvl=all loglvl=all"

# xenstore-ls -p
 4 = "" . . . . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
  vm = "/vm/94b147df-e15d-11e6-a685-002590d7eca6" . . . . .  (n0,r4)
  name = "cirros" . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
  cpu = ""  . . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   0 = "" . . . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
    availability = "online" . . . . . . . . . . . . . . . .  (n0,r4)
   1 = "" . . . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
    availability = "online" . . . . . . . . . . . . . . . .  (n0,r4)
  memory = "" . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   static-max = "4194304" . . . . . . . . . . . . . . . . .  (n0,r4)
   target = "4186112" . . . . . . . . . . . . . . . . . . .  (n0,r4)
   videoram = "8192"  . . . . . . . . . . . . . . . . . . .  (n0,r4)
  device = "" . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   suspend = "" . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
    event-channel = ""  . . . . . . . . . . . . . . . . . .  (n4)
   vbd = "" . . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
    51712 = ""  . . . . . . . . . . . . . . . . . . . . . .  (n4,r0)
     backend = "/local/domain/0/backend/qdisk/4/51712"  . .  (n4,r0)
     backend-id = "0" . . . . . . . . . . . . . . . . . . .  (n4,r0)
     state = "3"  . . . . . . . . . . . . . . . . . . . . .  (n4,r0)
     virtual-device = "51712" . . . . . . . . . . . . . . .  (n4,r0)
     device-type = "disk" . . . . . . . . . . . . . . . . .  (n4,r0)
     ring-ref = "8" . . . . . . . . . . . . . . . . . . . .  (n4,r0)
     event-channel = "18" . . . . . . . . . . . . . . . . .  (n4,r0)
     protocol = "x86_64-abi"  . . . . . . . . . . . . . . .  (n4,r0)
   vkbd = ""  . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
    0 = ""  . . . . . . . . . . . . . . . . . . . . . . . .  (n4,r0)
     backend = "/local/domain/0/backend/vkbd/4/0" . . . . .  (n4,r0)
     backend-id = "0" . . . . . . . . . . . . . . . . . . .  (n4,r0)
     state = "1"  . . . . . . . . . . . . . . . . . . . . .  (n4,r0)
  control = ""  . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   shutdown = ""  . . . . . . . . . . . . . . . . . . . . .  (n4)
   platform-feature-multiprocessor-suspend = "1"  . . . . .  (n0,r4)
   platform-feature-xs_reset_watches = "1"  . . . . . . . .  (n0,r4)
  hvmloader = ""  . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   bios = "seabios" . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   allow-memory-relocate = "0"  . . . . . . . . . . . . . .  (n0,r4)
  data = "" . . . . . . . . . . . . . . . . . . . . . . . .  (n4)
  drivers = ""  . . . . . . . . . . . . . . . . . . . . . .  (n4)
  feature = ""  . . . . . . . . . . . . . . . . . . . . . .  (n4)
  attr = "" . . . . . . . . . . . . . . . . . . . . . . . .  (n4)
  domid = "4" . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
  store = ""  . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   port = "1" . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   ring-ref = "1044476" . . . . . . . . . . . . . . . . . .  (n0,r4)
  platform = "" . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   acpi = "1" . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   acpi_s3 = "1"  . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   acpi_s4 = "1"  . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
  console = ""  . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   backend = "/local/domain/0/backend/console/4/0"  . . . .  (n0,r4)
   backend-id = "0" . . . . . . . . . . . . . . . . . . . .  (n4,r0)
   limit = "1048576"  . . . . . . . . . . . . . . . . . . .  (n0,r4)
   type = "xenconsoled" . . . . . . . . . . . . . . . . . .  (n0,r4)
   output = "pty" . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   tty = "/dev/pts/1" . . . . . . . . . . . . . . . . . . .  (n0,r4)
   port = "2" . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   ring-ref = "1044479" . . . . . . . . . . . . . . . . . .  (n0,r4)
   vnc-listen = "0.0.0.0" . . . . . . . . . . . . . . . . .  (n0,r4)
   vnc-port = "5900"  . . . . . . . . . . . . . . . . . . .  (n0,r4)
  image = ""  . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   device-model-pid = "3255"  . . . . . . . . . . . . . . .  (n0,r4)
  serial = "" . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
   0 = "" . . . . . . . . . . . . . . . . . . . . . . . . .  (n0,r4)
    tty = "/dev/pts/2"  . . . . . . . . . . . . . . . . . .  (n0,r4)


libxl: debug: libxl_create.c:1710:do_domain_create: ao 0x803247000: create: how=0x0 callback=0x0 poller=0x8032280a0
libxl: debug: libxl_device.c:347:libxl__device_disk_set_backend: Disk vdev=xvda spec.backend=unknown
libxl: debug: libxl_device.c:310:disk_try_backend: Disk vdev=xvda, backend phy unsuitable due to format qcow2
libxl: debug: libxl_device.c:382:libxl__device_disk_set_backend: Disk vdev=xvda, using backend qdisk
libxl: debug: libxl_create.c:970:initiate_domain_create: running bootloader
libxl: debug: libxl_bootloader.c:324:libxl__bootloader_run: not a PV domain, skipping bootloader
libxl: debug: libxl_event.c:686:libxl__ev_xswatch_deregister: watch w=0x80325aab8: deregister unregistered
domainbuilder: detail: xc_dom_allocate: cmdline="(null)", features="(null)"
domainbuilder: detail: xc_dom_kernel_file: filename="/usr/local/lib/xen/boot/hvmloader"
domainbuilder: detail: xc_dom_malloc_filemap    : 329 kB
domainbuilder: detail: xc_dom_boot_xen_init: ver 4.7, caps xen-3.0-x86_64 xen-3.0-x86_32p hvm-3.0-x86_32 hvm-3.0-x86_32p hvm-3.0-x86_64 
domainbuilder: detail: xc_dom_parse_image: called
domainbuilder: detail: xc_dom_find_loader: trying ELF-generic loader ... 
domainbuilder: detail: loader probe failed
domainbuilder: detail: xc_dom_find_loader: trying Linux bzImage loader ... 
domainbuilder: detail: xc_dom_probe_bzimage_kernel: kernel is not a bzImage
domainbuilder: detail: loader probe failed
domainbuilder: detail: xc_dom_find_loader: trying HVM-generic loader ... 
domainbuilder: detail: loader probe OK
xc: detail: elf_parse_binary: phdr: paddr=0x100000 memsz=0x5ae04
xc: detail: elf_parse_binary: memory: 0x100000 -> 0x15ae04
domainbuilder: detail: xc_dom_mem_init: mem 504 MB, pages 0x1f800 pages, 4k each
domainbuilder: detail: xc_dom_mem_init: 0x1f800 pages
domainbuilder: detail: xc_dom_boot_mem_init: called
domainbuilder: detail: xc_dom_malloc            : 1008 kB
xc: detail: PHYSICAL MEMORY ALLOCATION:
xc: detail:   4KB PAGES: 0x0000000000000200
xc: detail:   2MB PAGES: 0x00000000000000fb
xc: detail:   1GB PAGES: 0x0000000000000000
domainbuilder: detail: xc_dom_build_image: called
domainbuilder: detail: xc_dom_pfn_to_ptr_retcount: domU mapping: pfn 0x100+0x5b at 0x8006d0000
domainbuilder: detail: xc_dom_alloc_segment:   kernel       : 0x100000 -> 0x15b000  (pfn 0x100 + 0x5b pages)
xc: detail: elf_load_binary: phdr 0 at 0x80072b000 -> 0x80077c3a0
domainbuilder: detail: alloc_pgtables_hvm: doing nothing
domainbuilder: detail: xc_dom_build_image  : virt_alloc_end : 0x15b000
domainbuilder: detail: xc_dom_build_image  : virt_pgtab_end : 0x0
domainbuilder: detail: xc_dom_boot_image: called
domainbuilder: detail: bootearly: doing nothing
domainbuilder: detail: xc_dom_compat_check: supported guest type: xen-3.0-x86_64
domainbuilder: detail: xc_dom_compat_check: supported guest type: xen-3.0-x86_32p
domainbuilder: detail: xc_dom_compat_check: supported guest type: hvm-3.0-x86_32 <= matches
domainbuilder: detail: xc_dom_compat_check: supported guest type: hvm-3.0-x86_32p
domainbuilder: detail: xc_dom_compat_check: supported guest type: hvm-3.0-x86_64
domainbuilder: detail: clear_page: pfn 0xfefff, mfn 0xfefff
domainbuilder: detail: clear_page: pfn 0xfeffc, mfn 0xfeffc
domainbuilder: detail: domain builder memory footprint
domainbuilder: detail:    allocated
domainbuilder: detail:       malloc             : 1012 kB
domainbuilder: detail:       anon mmap          : 0 bytes
domainbuilder: detail:    mapped
domainbuilder: detail:       file mmap          : 329 kB
domainbuilder: detail:       domU mmap          : 364 kB
domainbuilder: detail: vcpu_hvm: called
domainbuilder: detail: xc_dom_gnttab_hvm_seed: called, pfn=0xff000
domainbuilder: detail: xc_dom_gnttab_hvm_seed: called, pfn=0xff001
domainbuilder: detail: xc_dom_release: called
libxl: debug: libxl_device.c:347:libxl__device_disk_set_backend: Disk vdev=xvda spec.backend=qdisk
libxl: debug: libxl_device.c:1156:device_hotplug: No hotplug script to execute
libxl: debug: libxl_event.c:686:libxl__ev_xswatch_deregister: watch w=0x80337a4d0: deregister unregistered
libxl: debug: libxl.c:3166:libxl__device_disk_find_local_path: Directly accessing local QDISK target /root/cirros-0.3.4-x86_64-disk.img
libxl: debug: libxl_dm.c:755:libxl__dm_runas_helper: sysconf(_SC_GETPW_R_SIZE_MAX) failed, setting the initial buffer size to 2048
libxl: debug: libxl_dm.c:755:libxl__dm_runas_helper: sysconf(_SC_GETPW_R_SIZE_MAX) failed, setting the initial buffer size to 2048
libxl: debug: libxl_dm.c:1498:libxl__build_device_model_args_new: Could not find user xen-qemuuser-shared, starting QEMU as root
libxl: debug: libxl_dm.c:2092:libxl__spawn_local_dm: Spawning device-model /usr/local/lib/xen/bin/qemu-system-i386 with arguments:
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   /usr/local/lib/xen/bin/qemu-system-i386
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -xen-domid
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   3
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -chardev
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   socket,id=libxl-cmd,path=/var/run/xen/qmp-libxl-3,server,nowait
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -no-shutdown
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -mon
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   chardev=libxl-cmd,mode=control
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -chardev
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   socket,id=libxenstat-cmd,path=/var/run/xen/qmp-libxenstat-3,server,nowait
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -mon
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   chardev=libxenstat-cmd,mode=control
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -nodefaults
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -no-user-config
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -name
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   vm
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -vnc
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   0.0.0.0:0,to=99
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -display
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   none
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -serial
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   pty
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -device
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   cirrus-vga,vgamem_mb=8
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -boot
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   order=c
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -usb
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -usbdevice
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   tablet
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -smp
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   2,maxcpus=2
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -net
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   none
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -machine
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   xenfv
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -m
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   504
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   -drive
libxl: debug: libxl_dm.c:2094:libxl__spawn_local_dm:   file=/root/cirros-0.3.4-x86_64-disk.img,if=ide,index=0,media=disk,format=qcow2,cache=writeback
libxl: debug: libxl_dm.c:2096:libxl__spawn_local_dm: Spawning device-model /usr/local/lib/xen/bin/qemu-system-i386 with additional environment:
libxl: debug: libxl_dm.c:2098:libxl__spawn_local_dm:   XEN_QEMU_CONSOLE_LIMIT=1048576
libxl: debug: libxl_event.c:636:libxl__ev_xswatch_register: watch w=0x80325adb0 wpath=/local/domain/0/device-model/3/state token=3/0: register slotnum=3
libxl: debug: libxl_create.c:1736:do_domain_create: ao 0x803247000: inprogress: poller=0x8032280a0, flags=i
libxl: debug: libxl_event.c:573:watchfd_callback: watch w=0x80325adb0 wpath=/local/domain/0/device-model/3/state token=3/0: event epath=/local/domain/0/device-model/3/state
libxl: debug: libxl_exec.c:398:spawn_watch_event: domain 3 device model: spawn watch p=(null)
libxl: debug: libxl_event.c:573:watchfd_callback: watch w=0x80325adb0 wpath=/local/domain/0/device-model/3/state token=3/0: event epath=/local/domain/0/device-model/3/state
libxl: debug: libxl_exec.c:398:spawn_watch_event: domain 3 device model: spawn watch p=running
libxl: debug: libxl_event.c:673:libxl__ev_xswatch_deregister: watch w=0x80325adb0 wpath=/local/domain/0/device-model/3/state token=3/0: deregister slotnum=3
libxl: debug: libxl_exec.c:129:libxl_report_child_exitstatus: domain 3 device model (dying as expected) [853] died due to fatal signal Killed
libxl: debug: libxl_event.c:686:libxl__ev_xswatch_deregister: watch w=0x80325adb0: deregister unregistered
libxl: debug: libxl_qmp.c:707:libxl__qmp_initialize: connected to /var/run/xen/qmp-libxl-3
libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: qmp
libxl: debug: libxl_qmp.c:556: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:556: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:556: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:2180:libxl__ao_progress_report: ao 0x803247000: progress report: ignored
libxl: debug: libxl_event.c:1869:libxl__ao_complete: ao 0x803247000: complete, rc=0
libxl: debug: libxl_event.c:1838:libxl__ao__destroy: ao 0x803247000: destroy
libxl: debug: libxl_qmp.c:707:libxl__qmp_initialize: connected to /var/run/xen/qmp-libxl-3
libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: qmp
libxl: debug: libxl_qmp.c:556: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:556:qmp_send_prepare: next qmp command: '{
    "execute": "cont",
    "id": 2
}
'
libxl: debug: libxl_qmp.c:296:qmp_handle_response: message type: return
xencall:buffer: debug: total allocations:285 total releases:285
xencall:buffer: debug: current allocations:0 maximum allocations:3
xencall:buffer: debug: cache current size:3
xencall:buffer: debug: cache hits:269 misses:3 toobig:13


Thanks,
Alex

More information about the freebsd-xen mailing list