NUL Test Report

Wed, 26 Sep 2012 02:35:22 CEST

7. Start of a VM via xml file (./libvirt-xml.wv)

>>> make -C /home/sojka/nul/alexb/apps/libvirt install DESTDIR=/home/sojka/nul/alexb/apps/libvirt/_install
make: Entering directory `/home/sojka/nul/alexb/apps/libvirt'
make: Nothing to be done for `install'.
make: Leaving directory `/home/sojka/nul/alexb/apps/libvirt'
! ./libvirt.wv.inc:14 make -C /home/sojka/nul/alexb/apps/libvirt install DESTDIR=/home/sojka/nul/alexb/apps/libvirt/_install ok	ok
>>> cp /home/sojka/nul/michal/imgs/passive/CAcertSrv.pem cacert.pem
! ./libvirt.wv.inc:15 cp /home/sojka/nul/michal/imgs/passive/CAcertSrv.pem cacert.pem ok	ok
+ PATH=/home/sojka/nul/alexb/apps/libvirt/_install/usr/local/bin:/home/sojka/bin:/home/sojka/bin:/home/sojka/bin:/usr/local/bin:/usr/bin:/bin
+ LD_LIBRARY_PATH=/home/sojka/nul/alexb/apps/libvirt/_install/usr/local/lib
+ set +x
wvtest: ignore exit patterns
+ WVTEST_NOKILL=1
+ WVTEST_OUTPUT=passive.log
+ /home/sojka/nul/michal/wvtest/wvnulrun /home/sojka/nul/michal/boot/passive/nova-82576 -I
Use of uninitialized value $ENV{"TERM"} in string ne at /home/sojka/nul/michal/wvtest/wvnulrun line 30.
novaboot: Connecting to IP relay... done
<iprelayd: connected>
novaboot: Entering directory `/home/sojka/nul/build'
novaboot: Created bin/apps/logdisk.nulconfig
novaboot: Created bin/apps/remote_config.nulconfig
novaboot: Created template.config
novaboot: Created diskuuid.config
novaboot: Created linux.nulconfig
novaboot: Created passive-demo.nulconfig
novaboot: Created cpuload.nulconfig
novaboot: Created reboot.nulconfig
Use of uninitialized value $ENV{"TERM"} in string ne at /home/sojka/bin/novaboot line 516, <> line 60.
novaboot: Running: rsync --progress -RLp --chmod=Dg+s,ug+w,o-w,+rX --rsync-path="umask 002 && rsync" menu.lst bin/apps/hypervisor bin/apps/sigma0.nul bin/apps/logdisk.nul bin/apps/remote_config.nul bin/apps/vancouver.nul bin/boot/munich imgs/passive/bzImage imgs/passive/initramfs imgs/passive/privkeySrv.der imgs/passive/certSrv.crt imgs/passive/CAcertSrv.crt bin/apps/logdisk.nulconfig bin/apps/remote_config.nulconfig template.config diskuuid.config linux.nulconfig passive-demo.nulconfig cpuload.nulconfig reboot.nulconfig erwin.inf.tu-dresden.de:~passive/boot
cpuload.nulconfig
285 100% 0.00kB/s 0:00:00 285 100% 0.00kB/s 0:00:00 (xfer#1, to-check=26/27)
diskuuid.config
420 100% 37.29kB/s 0:00:00 420 100% 37.29kB/s 0:00:00 (xfer#2, to-check=25/27)
linux.nulconfig
381 100% 31.01kB/s 0:00:00 381 100% 31.01kB/s 0:00:00 (xfer#3, to-check=24/27)
menu.lst
700 55% 56.97kB/s 0:00:00 1260 100% 102.54kB/s 0:00:00 (xfer#4, to-check=23/27)
passive-demo.nulconfig
282 100% 22.95kB/s 0:00:00 282 100% 22.95kB/s 0:00:00 (xfer#5, to-check=22/27)
reboot.nulconfig
284 100% 21.33kB/s 0:00:00 284 100% 21.33kB/s 0:00:00 (xfer#6, to-check=21/27)
template.config
270 100% 20.28kB/s 0:00:00 270 100% 20.28kB/s 0:00:00 (xfer#7, to-check=20/27)
bin/apps/hypervisor
700 1% 52.58kB/s 0:00:01 67346 100% 4.01MB/s 0:00:00 (xfer#8, to-check=15/27)
bin/apps/logdisk.nul
700 3% 42.72kB/s 0:00:00 18076 100% 1.01MB/s 0:00:00 (xfer#9, to-check=14/27)
bin/apps/logdisk.nulconfig
182 100% 10.45kB/s 0:00:00 182 100% 10.45kB/s 0:00:00 (xfer#10, to-check=13/27)
bin/apps/remote_config.nul
700 0% 37.98kB/s 0:00:04 170364 100% 6.77MB/s 0:00:00 (xfer#11, to-check=12/27)
bin/apps/remote_config.nulconfig
700 87% 27.34kB/s 0:00:00 803 100% 31.37kB/s 0:00:00 (xfer#12, to-check=11/27)
bin/apps/sigma0.nul
700 0% 25.32kB/s 0:00:16 417092 100% 9.47MB/s 0:00:00 (xfer#13, to-check=10/27)
bin/apps/vancouver.nul
700 0% 15.54kB/s 0:00:15 237532 100% 4.19MB/s 0:00:00 (xfer#14, to-check=9/27)
bin/boot/munich
700 29% 12.66kB/s 0:00:00 2356 100% 42.61kB/s 0:00:00 (xfer#15, to-check=7/27)
imgs/passive/CAcertSrv.crt
700 92% 12.43kB/s 0:00:00 756 100% 13.42kB/s 0:00:00 (xfer#16, to-check=4/27)
imgs/passive/bzImage
2208 0% 14.57kB/s 0:05:36 4904720 100% 13.40MB/s 0:00:00 (xfer#17, to-check=3/27)
imgs/passive/certSrv.crt
700 96% 1.95kB/s 0:00:00 726 100% 2.03kB/s 0:00:00 (xfer#18, to-check=2/27)
imgs/passive/initramfs
3008 0% 8.32kB/s 0:18:07 9054208 100% 12.34MB/s 0:00:00 (xfer#19, to-check=1/27)
imgs/passive/privkeySrv.der
608 100% 0.85kB/s 0:00:00 608 100% 0.85kB/s 0:00:00 (xfer#20, to-check=0/27)

sent 27577 bytes received 39728 bytes 44870.00 bytes/sec
total size is 14877951 speedup is 221.05
novaboot: Reseting the test box... done
NOVA Microhypervisor v5-29c6ee8 (x86_32): Sep 26 2012 01:56:33 [gcc 4.6.2]

[ 0] CORE:0:0:0 6:1a:5:1 [11] Intel(R) Core(TM) i7 CPU 920 @ 2.67GHz
[ 4] CORE:0:0:1 6:1a:5:1 [11] Intel(R) Core(TM) i7 CPU 920 @ 2.67GHz
[ 7] CORE:0:3:1 6:1a:5:1 [11] Intel(R) Core(TM) i7 CPU 920 @ 2.67GHz
[ 5] CORE:0:1:1 6:1a:5:1 [11] Intel(R) Core(TM) i7 CPU 920 @ 2.67GHz
[ 1] CORE:0:1:0 6:1a:5:1 [11] Intel(R) Core(TM) i7 CPU 920 @ 2.67GHz
[ 3] CORE:0:3:0 6:1a:5:1 [11] Intel(R) Core(TM) i7 CPU 920 @ 2.67GHz
[ 6] CORE:0:2:1 6:1a:5:1 [11] Intel(R) Core(TM) i7 CPU 920 @ 2.67GHz
[ 2] CORE:0:2:0 6:1a:5:1 [11] Intel(R) Core(TM) i7 CPU 920 @ 2.67GHz
=> hostvesa <=
s0: map self 0 -> b3400000 size 100000 offset 0 s 0 typed 1
=> mem <=
physmem: 0 [0, 100000]
=> pit:0x40,0 <=
=> scp:0x92,0x61 <=
=> pcihostbridge:0,0x100,0xcf8 <=
=> dpci:3,0,0,0,0,0 <=
search_device(3,0,0) bdf 200
s0: map self e0000000 -> a0000000 size 10000000 offset 0 s 0 typed 1
s0: map self d1100000 -> b3000000 size 10000 offset 0 s 0 typed 1
s0: map self 2000000 -> 0 size 100000 offset 0 s 0 typed 1
=> dio:0x3c0+0x20 <=
s0: map self 3c0000 -> 0 size 20000 offset 0 s 0 typed 1
=> dio:0x3b0+0x10 <=
s0: map self 3b0000 -> 0 size 10000 offset 0 s 0 typed 1
=> vcpu <=
=> halifax <=
VBE version 300 tag 41534556 memsize 1000000 oem 'ATI ATOMBIOS' vendor '(C) 1988-2005, ATI Technologies Inc. ' product 'RV710' version '01.00'
framebuffer e0000000+10000000
=> hostkeyb:0,0x60,1,12,1 <=
s0: map self 60000 -> 0 size 1000 offset 0 s 0 typed 1
s0: map self 64000 -> 0 size 1000 offset 0 s 0 typed 1
(1) created sc - prio=2 quantum=10000 cpu=0 sigma0.irq 1 - keyb
(1) created sc - prio=2 quantum=10000 cpu=0 sigma0.irq 12 - aux
=> nubus <=
bus[1] Enabling ARI.
dev[1:00.0] Adapting ARI status on SR-IOV capable device.
dev[1:00.0] Enabled 8 VFs. Wait for them to settle down.
dev[1:00.1] Enabled 8 VFs. Wait for them to settle down.
bus[3] Enabling ARI.
Nubus initialized.
=> host82576:0 <=
82576PF 00: Found Intel 82576-style controller at 100. Attaching IRQ 0.
82576PF 00: BAR 0: d0820000 (size 00020000)
s0: map self d0820000 -> b2c00000 size 20000 offset 0 s 0 typed 1
82576PF 00: Found MMIO window at 0xb2c00000 (phys d0820000).
82576PF 00: BAR 1: d0400000 (size 00400000)
s0: map self d0400000 -> b2800000 size 400000 offset 0 s 0 typed 1
82576PF 00: BAR 2: 00003021 (size 00000020)
82576PF 00: BAR 3: d08c4000 (size 00004000)
s0: map self d08c4000 -> b2400000 size 4000 offset 0 s 0 typed 1
82576PF 00: Perform Global Reset.
82576PF 00: Global Reset successful.
s0: Attaching to CPU 0 (ffffffff 0)
(1) created sc - prio=2 quantum=10000 cpu=0 sigma0.irq 126 - gsi msi
82576PF 00: Attached to IRQ 126 (MSI-X).
82576PF 00: Configuring VFs...
82576PF 00: Configuring link parameters...
82576PF 00: We are 00:1b:21:86:a1:4a
82576PF 00: Notifying VFs that PF is done...
82576PF 00: Initialization complete.
82576PF 00: Enabling interrupts...
82576PF 00: Link status changed to UP.
82576PF 00: UP 100BASE-T FD \| 8 VFs \| 0 RX \| 0 TX
=> host82576vf:0,0,1 <=
s0: map self d0840000 -> b2000000 size 4000 offset 0 s 0 typed 1
s0: map self d0860000 -> b1c00000 size 4000 offset 0 s 0 typed 1
s0: Attaching to CPU 0 (ffffffff 0)
(1) created sc - prio=2 quantum=10000 cpu=0 sigma0.irq 125 - gsi msi
s0: Attaching to CPU 0 (ffffffff 0)
(1) created sc - prio=2 quantum=10000 cpu=0 sigma0.irq 124 - gsi msi
82576VF 80: Found Intel 82576VF-style controller.
82576VF 80: Interrupt throttling DISABLED.
82576VF 80: 00000200 bytes allocated for RX descriptor ring (32 descriptors).
82576VF 80: RDBAL bea4b080 RDBAH 00000000 RXDCTL 02000000
82576VF 80: 00000200 bytes allocated for TX descriptor ring (32 descriptors).
82576PF 00: VF0 sent RESET
82576PF 00: VF0 is now 00:1b:21:86:a1:4a
82576VF 80: We are 00:1b:21:86:a1:4a
82576VF 80: Asking to be promiscuous.
82576PF 00: VF_SET_PROMISC 40006 ENABLE
82576VF 80: Unrecognized message.
=> hostahci <=
s0: Attaching to CPU 0 (ffffffff 0)
(1) created sc - prio=2 quantum=10000 cpu=0 sigma0.irq 123 - gsi msi
MSI 7b enabled for bdf fa MSI fee00018/7b
DISK controller #1 AHCI fa id 3a228086 mmio d1200000
s0: map self d1200000 -> b1800000 size 1000 offset 0 s 0 typed 1
AHCI: cap e720ffc5 cap2 0 global 80000000 ports 3f version 10200 bohc 0
PORT 0 sig 101
_cl (0xbe9b3400,0xbe9b3800) _ct (0xbe967c00, 0xbe970c00)
HDD SAMSUNG HD080HJ LBA48 sectors 950f8b0
PORT 2 sig 101
_cl (0xbe967400,0xbe967800) _ct (0xbe95cc00, 0xbe965c00)
HDD WDC WD5000AAKS-007AA0 LBA48 sectors 3a386030
PORT 4 sig 101
_cl (0xbe95c400,0xbe95c800) _ct (0xbe951c00, 0xbe95ac00)
HDD OCZ-VERTEX3 LBA48 sectors df94bb0
=> service_config <=
=> service_disk <=
disk: Added '0'
disk: Added '1'
disk: Added '2'
Constructing service /disk...
Service /disk registered.
=> script_start:1 <=
=> script_waitchild <=
=> script_start:2 <=
=> name::/s0/events <=
sc: start 0-1 count 1
s0: [ 5] module 'namespace::/tmp sigma0::mem:16 name::/s0/log name::/s0/timer name::/s0/fs/rom name::/s0/admission name::/s0/disk diskadd disk::0 \|\|' \
s0: ... ' rom://(nd)/tftpboot/passive//bin/apps/logdisk.nul'
s0: map self 7e000000 -> b0000000 size 1000000 offset 0 s 0 typed 1
s0: [ 5] using memory: 16 MB (1000000) at 7e000000
s0: [ 5] creating PD on CPU 2
(1) **** created admission client 0xf0013 0xf001c
(1) created sc - prio=1 quantum=10000 cpu=2 .main
s0: [ 5, 4284e] pagefault 48/0 for 800027fd err 4 at 800027fd
sc: wait for child 5
s0: [ 5, 4284e] b00027fd b0000000+1000000 -> order 24: b0000000+1000000
s0: [ 5, 4284e] map 0/1 for 800027fd err 4 at 800027fd
s0: [ 5, 4284e] pagefault 48/0 for bffff006 err 4 at 80001487
s0: [ 5, 4284e] be919006 be919000+1000 -> order 12: be919000+1000
s0: [ 5, 4284e] map 0/1 for bffff006 err 4 at 80001487
disk: Added '0p1' 'uuid:bb8984cd-7972-4f9b-831a-9ee7e5b9d04e' 'type:2be899e8-009f-47d1-a069-bd4bc05c20ea' 'name:PEIG_VM'
kb: receive() failed at 325 -- buggy keyboard?
disk: Added '0p2' 'uuid:3e57f5a9-f02d-4857-8447-cd8456e6fa55' 'type:21686148-6449-6e6f-744e-656564454649' 'name:BIOS boot partition'
disk: Added '0p3' 'uuid:2bb67411-8ddb-45e5-b98a-cdc46a87f3eb' 'type:ebd0a0a2-b9e5-4433-87c0-68b6b72699c7' 'name:'
disk: Added '0p4' 'uuid:26807986-695c-4e92-a02c-3766b923e507' 'type:ebd0a0a2-b9e5-4433-87c0-68b6b72699c7' 'name:disk donor test'
disk: Added '0p5' 'uuid:6ec3cb42-3c6d-45c7-a07b-02c85ecf12f2' 'type:2be899e8-009f-47d1-a069-bd4bc05c20ea' 'name:wvtest_playground'
disk: Added '0p6' 'uuid:d7c88b36-13e8-4379-9f85-40fd6e913e63' 'type:2be899e8-009f-47d1-a069-bd4bc05c20ea' 'name:passive-demo'
disk: Added '0p7' 'uuid:c7f7af37-cbbd-497c-91a1-bca55caf36ec' 'type:2be899e8-009f-47d1-a069-bd4bc05c20ea' 'name:passive-cpuload'
disk: Added '0p8' 'uuid:a516be9b-4bde-4a85-b562-e5d290958834' 'type:2be899e8-009f-47d1-a069-bd4bc05c20ea' 'name:passive-reboot'
disk: Added '0p9' 'uuid:c297613e-14d5-4d74-9390-b47e9ae1f359' 'type:2be899e8-009f-47d1-a069-bd4bc05c20ea' 'name:passive-vm1'
disk: Added '0p10' 'uuid:a586ae52-1fcf-47c5-82df-1577460a5f04' 'type:2be899e8-009f-47d1-a069-bd4bc05c20ea' 'name:passive-vm2'
disk: Added '0p11' 'uuid:531945c3-5605-4a2e-ad42-fe7d2707b069' 'type:2be899e8-009f-47d1-a069-bd4bc05c20ea' 'name:passive-vm3'
disk: Added '0p12' 'uuid:145d8ac4-85ad-4b35-aba1-1bf11d1e6721' 'type:2be899e8-009f-47d1-a069-bd4bc05c20ea' 'name:passive-vm4'
disk: Added '0p13' 'uuid:e37af749-a69a-46ee-81f3-4dcd9b8c46d1' 'type:2be899e8-009f-47d1-a069-bd4bc05c20ea' 'name:passive-vm5'
sc: start 1-1 count 1
s0: [ 6] module 'namespace::/s0 name::/s0/events name::/s0/log name::/s0/timer name::/s0/fs/rom name::/s0/admission name::/s0/config sigma0::mem:64 quota::guid name::/s0/disk disk::type:2be899e8-009f-47d1-a069-bd4bc05c20ea \|\|' \
s0: ... ' rom://(nd)/tftpboot/passive//bin/apps/remote_config.nul linux:rom://(nd)/tftpboot/passive//linux.nulconfig demo:rom://(nd)/tftpboot/passive//passive-demo.nulconfig cpuload:rom://(nd)/tftpboot/passive//cpuload.nulconfig reboot:rom://(nd)/tftpboot/passive//reboot.nulconfig servercert=rom://(nd)/tftpboot/passive//imgs/passive/certSrv.crt serverkey=rom://(nd)/tftpboot/passive//imgs/passive/privkeySrv.der cacert=rom://(nd)/tftpboot/passive//imgs/passive/CAcertSrv.crt template=rom://(nd)/tftpboot/passive//template.config diskuuid=rom://(nd)/tftpboot/passive//diskuuid.config verbose IP_CONFIG'
s0: map self 7a000000 -> 9c000000 size 4000000 offset 0 s 0 typed 2
s0: [ 6] using memory: 64 MB (4000000) at 7a000000
s0: [ 6] creating PD on CPU 3
(1) **** created admission client 0xf001d 0xf001f
(1) created sc - prio=1 quantum=10000 cpu=3 .main
s0: [ 6, 4306e] pagefault 48/0 for 80008285 err 4 at 80008285
sc: done.
s0: => INIT done <=

s0: [ 6, 4306e] 9c008285 9c000000+4000000 -> order 26: 9c000000+4000000
s0: [ 6, 4306e] map 0/1 for 80008285 err 4 at 80008285
s0: [ 6, 4306e] pagefault 48/0 for bffff006 err 4 at 80003a21
s0: [ 6, 4306e] be91e006 be91e000+1000 -> order 12: be91e000+1000
s0: [ 6, 4306e] map 0/1 for bffff006 err 4 at 80003a21
tb: client data 3f002 guid 6 parent 9bc
(6) booting - NOVA daemon ...
(6) done - request timer attach
(1) open - session rebind pseudo=f001d->f2008
(6) - disk 'uuid:6ec3cb42-3c6d-45c7-a07b-02c85ecf12f2'
(6) - disk 'uuid:4867d304-5b38-475f-90ed-00eec3e44907'
(6) - disk 'uuid:88d72d2b-d126-4bd8-80e9-a4ddbb86118f'
(6) - disk 'uuid:2832f211-38dd-44f5-83b7-c6dc86a2a333'
(6) - disk 'uuid:a4817cb4-f2bc-468b-96ec-337a7709c711'
(6) - disk 'uuid:c297613e-14d5-4d74-9390-b47e9ae1f359'
(6) - disk 'uuid:a586ae52-1fcf-47c5-82df-1577460a5f04'
(6) - disk 'uuid:531945c3-5605-4a2e-ad42-fe7d2707b069'
(6) - disk 'uuid:145d8ac4-85ad-4b35-aba1-1bf11d1e6721'
(6) - disk 'uuid:e37af749-a69a-46ee-81f3-4dcd9b8c46d1'
(6) - libvirt protocol version 0xb002
(6) warning - osdepentropyopen not implemented!
(6) warning - tls - entropy not implemented!
(6) done - request network attach
(6) done - mac 00:1b:21:86:a1:4a
(6) - sys_now unimpl.
(6) done - open tcp port 9999, 10000, 10043 - ssl/tls enabled
(6) ....... looking for an IP address via DHCP
(6) update - got ip=141.76.49.60 mask=255.255.255.192 gw=141.76.49.1
(6) ready - NOVA management daemon is up. Waiting for libvirt connection ...
Keeping PID 18857 alive
+ test ''
++ sed -ne '/.update - got ip=$[^ ]$.*/ s//\1/p' passive.log
+ NOVA_IP=141.76.49.60
++ sed -ne 's/^Keeping PID $[0-9]\+$ alive$/\1/p' passive.log
+ pid=18857
+ set +x
>>> test 141.76.49.60
! ./libvirt.wv.inc:39 test 141.76.49.60 ok	ok
>>> virsh -c nova+tls://141.76.49.60:9999 create <(sed -e "s/\/bin\/cat/\\/home\\/sojka\\/nul\/build\/imgs\/bootable-hdd.img/" ./libvirt-test.xml)
(6) [tcp] - connection from 141.76.48.80:34480 -> 9999
(6) [tcp] - connection from 141.76.48.80:34574 -> 10000
(6) - authentication request :Hello (6)
(6) ok - op NOVA_AUTH 5 ms, t=3276532
Checking 0 for uuid:6ec3cb42-3c6d-45c7-a07b-02c85ecf12f2: 0
Checking 0 for uuid:4867d304-5b38-475f-90ed-00eec3e44907: 0
Checking 0 for uuid:88d72d2b-d126-4bd8-80e9-a4ddbb86118f: 0
Checking 0 for uuid:2832f211-38dd-44f5-83b7-c6dc86a2a333: 0
Checking 0 for uuid:a4817cb4-f2bc-468b-96ec-337a7709c711: 0
Checking 0 for uuid:c297613e-14d5-4d74-9390-b47e9ae1f359: 0
Checking 0 for uuid:a586ae52-1fcf-47c5-82df-1577460a5f04: 0
Checking 0 for uuid:531945c3-5605-4a2e-ad42-fe7d2707b069: 0
rule eventid=9893 actionid=0 5
Checking 0 for uuid:145d8ac4-85ad-4b35-aba1-1bf11d1e6721: 0
Checking 0 for uuid:e37af749-a69a-46ee-81f3-4dcd9b8c46d1: 0
Checking 1 for uuid:6ec3cb42-3c6d-45c7-a07b-02c85ecf12f2: 1
(6) ok - op NOVA_VM_START 72 ms, t=3362210
(6) ok - op NOVA_GET_NAME_ID 0 us, t=3370911
rule eventid=-1 actionid=0 5
(6) ok - op NOVA_ENABLE_EVENT 0 us, t=3379808
(6) ok - op NOVA_ATOMIC_RULE 0 us, t=3388399
(6) ok - op NOVA_ENABLE_EVENT 0 us, t=3396875
file size 8248832
[(6) ok - op NOVA_ATOMIC_RULE 1 us, t=3405402
(6) [tcp] - connection from 141.76.48.80:36788 -> 10043
(6) ....... receiving image of size 8248832 from 141.76.48.80:36788 -> 10043
=> 1%[6D=> 2%[6D=> 4%[6D=> 5%[6D=> 7%[6D=> 8%[6D=> 10%[6D=> 11%[6D=> 12%[6D=> 14%[6D=> 15%[6D=> 17%[6D=> 18%[6D=> 20%[6D=> 21%[6D=> 22%[6D=> 24%[6D=> 25%[6D=> 27%[6D=> 28%[6D=> 30%[6D=> 31%[6D=> 32%[6D=> 34%[6D=> 35%[6D=> 37%[6D=> 38%[6D=> 40%[6D=> 41%[6D=> 42%[6D=> 44%[6D=> 45%[6D=> 47%[6D=> 48%[6D=> 50%[6D=> 51%[6D=> 52%[6D=> 54%[6D=> 55%[6D=> 57%[6D=> 58%[6D=> 60%[6D=> 61%[6D=> 62%[6D=> 64%[6D=> 65%[6D=> 67%[6D=> 68%[6D=> 70%[6D=> 71%[6D=> 72%[6D=> 74%[6D=> 75%[6D=> 77%[6D=> 78%[6D=> 80%[6D=> 81%[6D=> 82%[6D=> 84%[6D=> 85%[6D=> 87%[6D=> 88%[6D=> 90%[6D=> 91%[6D=> 92%[6D=> 94%[6D=> 95%[6D=> 97%[6D=> 98%[6D=> 100%[6D(6) [====================================================================]
(6) done - image sha1: d27dc06da84fc651467639b5fcf293a62a838bf2
s0: [ 7] module 'sigma0::mem:256 name::/s0/log name::/s0/timer name::/s0/fs/rom name::/s0/admission name::/s0/disk disk::uuid:6ec3cb42-3c6d-45c7-a07b-02c85ecf12f2 \|\|' \
s0: ... ' rom://(nd)/tftpboot/passive//bin/apps/vancouver.nul PC_PS2 ahci:0xe0800000,14,0x30 82576vf drive:0,0,0 service_events \|\|' \
s0: ... ' '
s0: map self 6a000000 -> 8c000000 size 10000000 offset 0 s 0 typed 8
s0: [ 7] using memory: 256 MB (10000000) at 6a000000
>] - sha1: d27dc06da84fc651467639b5fcf293a62a838bf2
Domain xml created from /dev/fd/63

eventthread - exiting due to error -9 (A TLS packet with unexpected length was received.)
nova - success - closing mgmt connection ...
nova - success - closing event connection ...
! ./libvirt-xml.wv:8 virsh -c nova+tls://141.76.49.60:9999 create <(sed -e "s/\/bin\/cat/\\/home\\/sojka\\/nul\/build\/imgs\/bootable-hdd.img/" ./libvirt-test.xml) ok	ok
>>> virsh -c nova+tls://141.76.49.60:9999 dumpxml 5
s0: [ 7] creating PD on CPU 4
(1) **** created admission client 0xf6004 0xf6005
(1) created sc - prio=1 quantum=10000 cpu=4 .main
s0: [ 7, 4388e] pagefault 48/0 for 80005e7c err 4 at 80005e7c
(6) success - starting VM 5 (err=0)
s0: [ 7, 4388e] 8c005e7c 8c000000+10000000 -> order 26: 8c000000+4000000
(6) [tcp] - incoming connection closed - port 10043
s0: [ 7, 4388e] map 0/4 for 80005e7c err 4 at 80005e7c
(6) [tcp] - incoming connection closed - port 9999
s0: [ 7, 4388e] pagefault 48/0 for bffff006 err 4 at 80005039
(6) [tcp] - incoming connection closed - port 10000
s0: [ 7, 4388e] be91d006 be91d000+1000 -> order 12: be91d000+1000
s0: [ 7, 4388e] map 0/1 for bffff006 err 4 at 80005039
(1) open - session rebind pseudo=f6004->f2009
(6) [tcp] - connection from 141.76.48.80:34483 -> 9999
tb: client data 3f004 guid 7 parent 9bf
(7) Ignored parameter: 'rom://(nd)/tftpboot/passive//bin/apps/vancouver.nul'
(7) => PC_PS2 <=
(7) => mem:0,0xa0000 <=
(7) physmem: 0 [0, a0000]
(7) => mem:0x100000 <=
(7) physmem: 0 [100000, fc00000]
(7) => ioio <=
(7) => nullio:0x80 <=
(7) => pic:0x20,,0x4d0 <=
(7) => pic:0xa0,2,0x4d1 <=
(7) => pit:0x40,0 <=
(7) => scp:0x92,0x61 <=
(7) => kbc:0x60,1,12 <=
(7) => keyb:0,0x10000 <=
(7) => mouse:1,0x10001 <=
(7) => rtc:0x70,8 <=
(7) => serial:0x3f8,0x4,0x4711 <=
(7) => hostsink:0x4712,80 <=
(7) => vga:0x03c0 <=
(7) Allocating from guest 0fbe0000+20000
(7) VGA console fbe0000+20000 0x8ffe0000
(7) => vbios_disk <=
(7) => vbios_keyboard <=
(7) => hostkeyb:0x10,0x60,1,,1 <=
(7) => vbios_mem <=
(7) => vbios_time <=
(7) => vbios_reset <=
(7) => vbios_multiboot <=
(7) => msi <=
(7) => ioapic <=
(7) => pcihostbridge:0,0x10,0xcf8,0xe0000000 <=
(7) => pmtimer:0x8000 <=
(7) => vcpus <=
(7) => vcpu <=
(7) create VCPU
(1) created sc - prio=1 quantum=10000 cpu=4 vancouver.vcpu
(7) startup
(7) => halifax <=
(7) => vbios <=
(7) => lapic <=
(7) LAPIC freq 168941000
(7) => ahci:0xe0800000,14,0x30 <=
(7) => 82576vf <=
(7) Attached 82576VF model at f7ce0000+0x4000, f7cc0000+0x1000
(7) => drive:0,0,0 <=
(7) do_gsi_boot eip 800007f7 esp 80215fec
(1) created sc - prio=2 quantum=10000 cpu=4 vancouver.disk
(7) SATA disk 0 flags 1 sectors 13fffff
(7) not finished 1404034,0 inprogress 0
(7) not finished 1404034,0 inprogress 0
(7) => service_events <=
(7) void DBus<M>::debug_dump() [with M = MessageHwIOIn]: Bus used 0 times.
(7) 0: StaticReceiver<Y>::StaticReceiver() [with Y = IOAccess]
(6) [tcp] - connection from 141.76.48.80:34577 -> 10000
(7)
(7) do_gsi_boot eip 80004c81 esp 80213fec
(1) created sc - prio=2 quantum=10000 cpu=4 vancouver.timer
(7) do_gsi_boot eip 8000599b esp 80212fec
(1) created sc - prio=2 quantum=10000 cpu=4 vancouver.stdin
(7) do_gsi_boot eip 80005c99 esp 80210fec
(1) created sc - prio=2 quantum=10000 cpu=4 vancouver.net
(7) RESET device state
(7) INIT done
(7) reset CPU from 9 mtr_in e0010
(7) > bool VirtualBiosMultiboot::receive(MessageBios&) rip ffff ilen 0 cr0 10 efl 2
(7) boot from disk
(7) VB: driveparam[0] size 1a sectors 13fffff efl 46 eax 0
(7) VB: driveparam[0] size 1a sectors 13fffff efl 46 eax 0
(7) VB: driveparam[0] size 1a sectors 13fffff efl 46 eax 0
(7) handle_int15 eax c0 ebx 0 ecx 2bf03 edx 1 eip ffff efl 46
(7) handle_int15 eax 5300 ebx 0 ecx 2bf03 edx 0 eip ffff efl 46
(7) handle_int15 eax 5304 ebx 0 ecx 2bf03 edx 0 eip ffff efl 46
(7) VB: driveparam[0] size 1a sectors 13fffff efl 46 eax 0
(7) VB: driveparam[0] size 1a sectors 13fffff efl 46 eax 0
<domain type='nova'>
<name>xml</name>
<uuid>49b26316-8b04-d647-89c4-2cde82c081f8</uuid>
<memory>262144</memory>
<currentMemory>262144</currentMemory>
<vcpu>1</vcpu>
<os>
<type arch='i686'>hvm</type>
<boot dev='hd'/>
</os>
<clock offset='utc'/>
<on_poweroff>destroy</on_poweroff>
<on_reboot>restart</on_reboot>
<on_crash>destroy</on_crash>
<devices>
</devices>
</domain>

eventthread - exiting due to error -9 (A TLS packet with unexpected length was received.)
nova - success - closing mgmt connection ...
nova - success - closing event connection ...
! ./libvirt-xml.wv:9 virsh -c nova+tls://141.76.49.60:9999 dumpxml 5 ok	ok
>>> virsh -c nova+tls://141.76.49.60:9999 list --all \| tee log
(6) - authentication request :Hello (6)
(6) ok - op NOVA_AUTH 5 ms, t=5546236
(6) ok - op NOVA_GET_NAME_ID 1 us, t=5555580
(6) ok - op NOVA_GET_VM_INFO 3 us, t=5564130
(6) [tcp] - incoming connection closed - port 9999
(6) [tcp] - incoming connection closed - port 10000
(6) [tcp] - connection from 141.76.48.80:34485 -> 9999
(6) [tcp] - connection from 141.76.48.80:34579 -> 10000
(7) # Press `ESC' to enter the menu... 0 [H[J Booting 'test'
(7) #
(7) # kernel /boot/bzImage root=/dev/sda1 console=ttyS0
(7) VB: driveparam[0] size 1a sectors 13fffff efl 46 eax 0
(7) # [Linux-bzImage, setup=0x3400, size=0x4a8ab0]
(6) - authentication request :Hello (6)
(6) ok - op NOVA_AUTH 7 ms, t=6038283
(6) ok - op NOVA_NUM_OF_ACTIVE_DOMAINS 1 us, t=6047308
(6) ok - op NOVA_LIST_ACTIVE_DOMAINS 1 us, t=6055860
(6) ok - op NOVA_NUM_OF_DEFINED_DOMAINS 1 us, t=6064342
(6) ok - op NOVA_LIST_DEFINED_DOMAINS 0 us, t=6072873
(6) ok - op NOVA_GET_NAME_ID 0 us, t=6081421
(6) ok - op NOVA_GET_VM_INFO 3 us, t=6089941
(6) ok - op NOVA_GET_VM_INFO 2 us, t=6101970
(6) ok - op NOVA_GET_NAME 1 us, t=6110819
(6) ok - op NOVA_GET_VM_INFO 0 us, t=6119252
(6) ok - op NOVA_GET_VM_INFO 0 us, t=6130682
(7) #
(6) ok - op NOVA_GET_NAME 0 us, t=6139370
(7) handle_int15 eax e801 ebx 0 ecx 0 edx 0 eip ffff efl 2
(6) ok - op NOVA_GET_VM_INFO 0 us, t=6149192
(7) handle_int15 eax c000 ebx 0 ecx 0 edx 0 eip ffff efl 2
(6) ok - op NOVA_GET_VM_INFO 0 us, t=6165901
(7) handle_int15 eax e980 ebx 0 ecx 0 edx 47534943 eip ffff efl 2
(6) ok - op NOVA_GET_NAME 0 us, t=6178152
(7) VESA 4f00 tag 0 base 90000+34d0 esi 0
(6) ok - op NOVA_GET_VM_INFO 0 us, t=6193122
(6) ok - op NOVA_GET_VM_INFO 1 us, t=6208169
(6) ok - op NOVA_GET_NAME 1 us, t=6216877
(6) ok - op NOVA_GET_VM_INFO 1 us, t=6225306
Id Name State
----------------------------------
5 xml running
- cpuload no state
- demo no state
- linux no state
- reboot no state

eventthread - exiting due to error -9 (A TLS packet with unexpected length was received.)
nova - success - closing mgmt connection ...
nova - success - closing event connection ...
(6) ok - op NOVA_GET_VM_INFO 0 us, t=6236028
(6) [tcp] - incoming connection closed - port 9999
(6) [tcp] - incoming connection closed - port 10000
! ./libvirt-xml.wv:10 virsh -c nova+tls://141.76.49.60:9999 list --all \| tee log ok	ok
>>> test 1 -eq 1
! ./libvirt-xml.wv:11 test 1 -eq 1 ok	ok
>>> virsh -c nova+tls://141.76.49.60:9999 destroy 5
(6) [tcp] - connection from 141.76.48.80:34487 -> 9999
(7) # [ 0.000000] Initializing cgroup subsys cpuset
(7) # [ 0.000000] Initializing cgroup subsys cpu
(7) # [ 0.000000] Linux version 3.1.4 (sojka@compile) (gcc version 4.3.6 (Buildroo
(7) # \| t 2011.11-dirty) ) #1 SMP Wed Dec 7 00:58:16 CET 2011
(7) # [ 0.000000] CPU: vendor_id 'NOVA microHV' unknown, using generic init.
(7) # [ 0.000000] CPU: Your system may be unstable.
(7) # [ 0.000000] BIOS-provided physical RAM map:
(7) # [ 0.000000] BIOS-e820: 0000000000000000 - 000000000009ac00 (usable)
(7) # [ 0.000000] BIOS-e820: 000000000009ac00 - 00000000000a0000 (reserved)
(7) # [ 0.000000] BIOS-e820: 0000000000100000 - 000000000fbe0000 (usable)
(7) # [ 0.000000] Notice: NX (Execute Disable) protection missing in CPU!
(7) # [ 0.000000] DMI not present or invalid.
(7) # [ 0.000000] last_pfn = 0xfbe0 max_arch_pfn = 0x100000
(7) # [ 0.000000] init_memory_mapping: 0000000000000000-000000000fbe0000
(7) # [ 0.000000] ACPI: RSDP 0009ce00 00014 (v00 NOVA )
(7) # [ 0.000000] ACPI: RSDT 0009e000 00030 (v01 NOVA bk@vmmon 00000001 000
(7) # \| 00000)
(7) # [ 0.000000] ACPI: APIC 0009f000 00064 (v01 NOVA bk@vmmon 00000001 000
(7) # \| 00000)
(7) # [ 0.000000] ACPI: MCFG 0009bc00 0003C (v01 NOVA bk@vmmon 00000001 000
(7) # \| 00000)
(7) # [ 0.000000] ACPI: FACP 0009ac00 000DC (v01 NOVA bk@vmmon 00000001 000
(7) # \| 00000)
(7) # [ 0.000000] ACPI Error: Required field Pm1aEventBlock has zero address and/o
(7) # \| r length: 0x0000000000000000/0x0 (20110623/tbfadt-544)
(7) # [ 0.000000] ACPI Error: Required field Pm1aControlBlock has zero address and
(6) [tcp] - connection from 141.76.48.80:34581 -> 10000
(7) # \| /or length: 0x0000000000000000/0x0 (20110623/tbfadt-544)
(7) # [ 0.000000] ACPI Error: Null physical address for ACPI table [DSDT] (2011062
(7) # \| 3/tbutils-459)
(7) # [ 0.000000] ACPI Error: Null physical address for ACPI table [FACS] (2011062
(7) # \| 3/tbutils-459)
(7) # [ 0.000000] 0MB HIGHMEM available.
(7) # [ 0.000000] 251MB LOWMEM available.
(7) # [ 0.000000] mapped low ram: 0 - 0fbe0000
(7) # [ 0.000000] low ram: 0 - 0fbe0000
(7) # [ 0.000000] Zone PFN ranges:
(7) # [ 0.000000] DMA 0x00000010 -> 0x00001000
(7) # [ 0.000000] Normal 0x00001000 -> 0x0000fbe0
(7) # [ 0.000000] HighMem empty
(7) # [ 0.000000] Movable zone start PFN for each node
(7) # [ 0.000000] early_node_map[2] active PFN ranges
(7) # [ 0.000000] 0: 0x00000010 -> 0x0000009a
(7) # [ 0.000000] 0: 0x00000100 -> 0x0000fbe0
(7) # [ 0.000000] Using APIC driver default
(7) # [ 0.000000] ACPI: PM-Timer IO Port: 0x8000
(7) # [ 0.000000] ACPI: LAPIC (acpi_id[0x00] lapic_id[0x00] enabled)
(7) # [ 0.000000] ACPI: X2APIC_NMI (uid[0xffffffff] dfl dfl lint[0x1])
(7) # [ 0.000000] ACPI: LAPIC_NMI (acpi_id[0xff] dfl dfl lint[0x1])
(7) # [ 0.000000] ACPI: IOAPIC (id[0x00] address[0xfec00000] gsi_base[0])
(7) # [ 0.000000] IOAPIC[0]: apic_id 0, version 32, address 0xfec00000, GSI 0-23
(7) # [ 0.000000] ACPI: INT_SRC_OVR (bus 0 bus_irq 0 global_irq 2 dfl dfl)
(7) # [ 0.000000] ACPI: NMI_SRC (dfl dfl global_irq 23)
(7) # [ 0.000000] Using ACPI (MADT) for SMP configuration information
(7) # [ 0.000000] SMP: Allowing 1 CPUs, 0 hotplug CPUs
(7) # [ 0.000000] PM: Registered nosave memory: 000000000009a000 - 000000000009b00
(7) # \| 0
(7) # [ 0.000000] PM: Registered nosave memory: 000000000009b000 - 00000000000a000
(7) # \| 0
(7) # [ 0.000000] PM: Registered nosave memory: 00000000000a0000 - 000000000010000
(6) - authentication request :Hello (6)
(7) # \| 0
(6) ok - op NOVA_AUTH 12 ms, t=6792619
(7) # [ 0.000000] Allocating PCI resources starting at fbe0000 (gap: fbe0000:f0420
(6) ok - op NOVA_GET_NAME_ID 0 us, t=6804137
(7) # \| 000)
(6) ok - op NOVA_GET_VM_INFO 8 us, t=6821821
(7) # [ 0.000000] setup_percpu: NR_CPUS:8 nr_cpumask_bits:8 nr_cpu_ids:1 nr_node_i
s0: [ 7] - initiate destruction of client ...
(7) # \| ds:1
s0: [ 7] revoke all caps
(7) # [ 0.000000] PERCPU: Embedded 12 pages/cpu @cf400000 s28288 r0 d20864 u419430
s0: [ 7] revoke all memory 0x8c000000 + hip 0xbe91d000
(7) # \| 4
[s 04:] [ K i7]ll e d r EeCv:ok0xec a12l7l 36m0e0mo SryC: 00xx8c1c20200e200000 V+ :0hxiep C0Sxb:0ex911db 0E0I0 P:- 0xd8o0ne00 1d7d CR2:0x 8
0s000:1 [d7 d7 ] ER R b:0efx4o re(P Tl ocnokt found)
[
4s0] :K [il l7e] d E Cde:t0xacc1h2 n73e7tw00o rSkC:0xc122e20 0
s0V::0 [xe 7C] S: 0 xde1bt acEIhP :st0xdi80n000085 CR2 :
0xs80:00 0[ 0078] 5 -E RdeR:s0trx4u ct(IiPoCn dAboonert)
[ 4] Ki l
Domain 5 destroyed

eventthread - exiting due to error -9 (A TLS packet with unexpected length was received.)
nova - success - closing mgmt connection ...
nova - success - closing event connection ...
Clehed cEkCin:g0 xc11 2fo73r8 0uu0 iSd:C:60exc3c1c2b42e22-300c 6dV:-045x1ce7- CaR070:b0-x0280c08550e0cf331 2fCR23:: 10x1915000 C R
4:(06)x0 o(k IP C A bo-r top)
NOVA_VM_DESTROY 82 ms, t=6918159
(6) [tcp] - incoming connection closed - port 9999
(6) warning - tls - entropy not implemented!
! ./libvirt-xml.wv:12 virsh -c nova+tls://141.76.49.60:9999 destroy 5 ok	ok
+ trap - EXIT
+ '[' 18857 ']'
+ kill 18857
! /home/sojka/bin/wvnulrun: $tests_executed > 0 ok	ok