Problem starting HVM guest in Xen 4.3 RC6 when NOT using device_model_version="qemu-xen-traditional"

[Ian Murray <murrayie@yahoo.co.uk>]

Hi,

I've just tried to start a previously created Windows XP domU only to 
discover that it won't start by default under Xen 4.3 RC 5 & RC 6. This 
started with no problems under 4.2.2

I haven't been following the changes to the qemu elements of Xen, so I 
might have missed something or am doing something wrong... but I assumed 
that a basic HVM guest would start and operate in pretty much the same 
way as it used to.

Anyway, under 4.3 RC 6 when I start it, I get....

root@xen6:/etc/xen# xl create win
Parsing config from win
xc: info: VIRTUAL MEMORY ARRANGEMENT:
   Loader:        0000000000100000->000000000019eac8
   Modules:       0000000000000000->0000000000000000
   TOTAL:         0000000000000000->000000007f800000
   ENTRY ADDRESS: 0000000000100000
xc: info: PHYSICAL MEMORY ALLOCATION:
   4KB PAGES: 0x0000000000000200
   2MB PAGES: 0x00000000000003fb
   1GB PAGES: 0x0000000000000000
libxl: error: libxl_dm.c:1275:device_model_spawn_outcome: domain 14 
device model: spawn failed (rc=-3)
libxl: error: libxl_create.c:1075:domcreate_devmodel_started: device 
model did not start: -3
libxl: error: libxl_dm.c:1306:libxl__destroy_device_model: Device Model 
already exited


Having had a read, I gather I can re-enable the previous behaviour by 
adding the line: device_model_version="qemu-xen-traditional". The domain 
starts as it used to:-

root@xen6:/etc/xen# xl create win
Parsing config from win
xc: info: VIRTUAL MEMORY ARRANGEMENT:
   Loader:        0000000000100000->000000000019eac8
   Modules:       0000000000000000->0000000000000000
   TOTAL:         0000000000000000->000000007f800000
   ENTRY ADDRESS: 0000000000100000
xc: info: PHYSICAL MEMORY ALLOCATION:
   4KB PAGES: 0x0000000000000200
   2MB PAGES: 0x00000000000003fb
   1GB PAGES: 0x0000000000000000
Daemon running with PID 3712

The only interesting thing that I did that I can recall is that to build 
it, I used ./configure --prefix=/usr because I was too lazy to track 
down all the previous installed stuff.

The config file is as follows:-

#path='/usr/lib/xen'
#kernel = path+'/boot/hvmloader'
#kernel = '/usr/lib/xen/boot/hvmloader'
builder='hvm'
memory = '2048'
name = 'win'
#device_model_version="qemu-xen-traditional"
# boot on floppy (a), hard disk (c) or CD-ROM (d)
boot='c'
disk = [ 'phy:/dev/xen6/win-root,hda,w' ]
vcpus=2
vnc=1
vncviewer=0
vnclisten="0.0.0.0"
vncpasswd='win'
vif=['mac=00:16:31:01:01:01,bridge=eth0']
on_poweroff = 'destroy'
on_reboot   = 'restart'
on_crash    = 'restart'
usbdevice='tablet'

I tried commenting out bits of it (usb,vnc,etc) but that didn't help. 
/dev/xen6/win-root is an lvm logical volume. I even tried commenting the 
disk line out.


Below is a verbose version of the failed creation:-

root@xen6:/etc/xen# xl -vvvvv create win
Parsing config from win
libxl: debug: libxl_create.c:1230:do_domain_create: ao 0x22f6690: 
create: how=(nil) callback=(nil) poller=0x22f66f0
libxl: debug: libxl_device.c:257:libxl__device_disk_set_backend: Disk 
vdev=hda spec.backend=unknown
libxl: debug: libxl_device.c:296:libxl__device_disk_set_backend: Disk 
vdev=hda, using backend phy
libxl: debug: libxl_create.c:675: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:608:libxl__ev_xswatch_deregister: watch 
w=0x22ec1d8: deregister unregistered
libxl: debug: libxl_numa.c:475:libxl__get_numa_candidate: New best NUMA 
placement candidate found: nr_nodes=1, nr_cpus=2, nr_vcpus=4, 
free_memkb=15035
libxl: detail: libxl_dom.c:195:numa_place_domain: NUMA placement 
candidate with 1 nodes, 2 cpus and 15035 KB free selected
xc: detail: elf_parse_binary: phdr: paddr=0x100000 memsz=0x9eac8
xc: detail: elf_parse_binary: memory: 0x100000 -> 0x19eac8
xc: info: VIRTUAL MEMORY ARRANGEMENT:
   Loader:        0000000000100000->000000000019eac8
   Modules:       0000000000000000->0000000000000000
   TOTAL:         0000000000000000->000000007f800000
   ENTRY ADDRESS: 0000000000100000
xc: info: PHYSICAL MEMORY ALLOCATION:
   4KB PAGES: 0x0000000000000200
   2MB PAGES: 0x00000000000003fb
   1GB PAGES: 0x0000000000000000
xc: detail: elf_load_binary: phdr 0 at 0x7eff81b8c000 -> 0x7eff81c2194d
libxl: debug: libxl_device.c:257:libxl__device_disk_set_backend: Disk 
vdev=hda spec.backend=phy
libxl: debug: libxl_event.c:559:libxl__ev_xswatch_register: watch 
w=0x22f2858 wpath=/local/domain/0/backend/vbd/16/768/state token=3/0: 
register slotnum=3
libxl: debug: libxl_create.c:1243:do_domain_create: ao 0x22f6690: 
inprogress: poller=0x22f66f0, flags=i
libxl: debug: libxl_event.c:503:watchfd_callback: watch w=0x22f2858 
wpath=/local/domain/0/backend/vbd/16/768/state token=3/0: event 
epath=/local/domain/0/backend/vbd/16/768/state
libxl: debug: libxl_event.c:647:devstate_watch_callback: backend 
/local/domain/0/backend/vbd/16/768/state wanted state 2 still waiting 
state 1
libxl: debug: libxl_event.c:503:watchfd_callback: watch w=0x22f2858 
wpath=/local/domain/0/backend/vbd/16/768/state token=3/0: event 
epath=/local/domain/0/backend/vbd/16/768/state
libxl: debug: libxl_event.c:643:devstate_watch_callback: backend 
/local/domain/0/backend/vbd/16/768/state wanted state 2 ok
libxl: debug: libxl_event.c:596:libxl__ev_xswatch_deregister: watch 
w=0x22f2858 wpath=/local/domain/0/backend/vbd/16/768/state token=3/0: 
deregister slotnum=3
libxl: debug: libxl_event.c:608:libxl__ev_xswatch_deregister: watch 
w=0x22f2858: deregister unregistered
libxl: debug: libxl_device.c:959:device_hotplug: calling hotplug script: 
/etc/xen/scripts/block add
libxl: debug: libxl_dm.c:1206:libxl__spawn_local_dm: Spawning 
device-model /usr/lib/xen/bin/qemu-system-i386 with arguments:
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm: 
/usr/lib/xen/bin/qemu-system-i386
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -xen-domid
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   16
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -chardev
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm: 
socket,id=libxl-cmd,path=/var/run/xen/qmp-libxl-16,server,nowait
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -mon
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm: 
chardev=libxl-cmd,mode=control
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -name
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   win
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -vnc
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm: 
0.0.0.0:0,password,to=99
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -global
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm: isa-fdc.driveA=
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -vga
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   cirrus
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -global
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm: vga.vram_size_mb=8
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -boot
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   order=c
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -usb
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -usbdevice
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   tablet
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -smp
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   2,maxcpus=2
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -device
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm: 
rtl8139,id=nic0,netdev=net0,mac=00:16:31:01:01:01
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -netdev
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm: 
type=tap,id=net0,ifname=vif16.0-emu,script=no,downscript=no
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -M
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   xenfv
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -m
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   2040
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm:   -drive
libxl: debug: libxl_dm.c:1208:libxl__spawn_local_dm: 
file=/dev/xen6/win-root,if=ide,index=0,media=disk,format=raw,cache=writeback
libxl: debug: libxl_event.c:559:libxl__ev_xswatch_register: watch 
w=0x22ec410 wpath=/local/domain/0/device-model/16/state token=3/1: 
register slotnum=3
libxl: debug: libxl_event.c:503:watchfd_callback: watch w=0x22ec410 
wpath=/local/domain/0/device-model/16/state token=3/1: event 
epath=/local/domain/0/device-model/16/state
libxl: debug: libxl_event.c:596:libxl__ev_xswatch_deregister: watch 
w=0x22ec410 wpath=/local/domain/0/device-model/16/state token=3/1: 
deregister slotnum=3
libxl: error: libxl_dm.c:1275:device_model_spawn_outcome: domain 16 
device model: spawn failed (rc=-3)
libxl: error: libxl_create.c:1075:domcreate_devmodel_started: device 
model did not start: -3
libxl: error: libxl_dm.c:1306:libxl__destroy_device_model: Device Model 
already exited
libxl: debug: libxl_event.c:559:libxl__ev_xswatch_register: watch 
w=0x22f5ed8 wpath=/local/domain/0/backend/vbd/16/768/state token=3/2: 
register slotnum=3
libxl: debug: libxl_event.c:503:watchfd_callback: watch w=0x22f5ed8 
wpath=/local/domain/0/backend/vbd/16/768/state token=3/2: event 
epath=/local/domain/0/backend/vbd/16/768/state
libxl: debug: libxl_event.c:643:devstate_watch_callback: backend 
/local/domain/0/backend/vbd/16/768/state wanted state 6 ok
libxl: debug: libxl_event.c:596:libxl__ev_xswatch_deregister: watch 
w=0x22f5ed8 wpath=/local/domain/0/backend/vbd/16/768/state token=3/2: 
deregister slotnum=3
libxl: debug: libxl_event.c:608:libxl__ev_xswatch_deregister: watch 
w=0x22f5ed8: deregister unregistered
libxl: debug: libxl_device.c:959:device_hotplug: calling hotplug script: 
/etc/xen/scripts/block remove
libxl: debug: libxl_event.c:472:watchfd_callback: watch 
epath=/local/domain/0/backend/vbd/16/768/state token=3/2: empty slot
libxl: debug: libxl_event.c:1569:libxl__ao_complete: ao 0x22f6690: 
complete, rc=-3
libxl: debug: libxl_event.c:1541:libxl__ao__destroy: ao 0x22f6690: destroy
xc: debug: hypercall buffer: total allocations:1216 total releases:1216
xc: debug: hypercall buffer: current allocations:0 maximum allocations:4
xc: debug: hypercall buffer: cache current size:4
xc: debug: hypercall buffer: cache hits:1208 misses:4 toobig:4

Any suggestions would be greatly received.

Thanks for reading,

Ian.