NUL Test Report

Wed, 26 Sep 2012 02:35:22 CEST

11. NOVA boot (PASSIVE configuration) (michal/wvtest/passive-test)

>>> 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'
! /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 okok
>>> cp /home/sojka/nul/michal/imgs/passive/CAcertSrv.pem cacert.pem
! /home/sojka/nul/alexb/apps/libvirt/libvirt.wv.inc:15 cp /home/sojka/nul/michal/imgs/passive/CAcertSrv.pem cacert.pem okok
+ 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
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% 33.82kB/s 0:00:00 381 100% 33.82kB/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% 23.11kB/s 0:00:00 284 100% 23.11kB/s 0:00:00 (xfer#6, to-check=21/27)
template.config
270 100% 21.97kB/s 0:00:00 270 100% 21.97kB/s 0:00:00 (xfer#7, to-check=20/27)
bin/apps/hypervisor
700 1% 52.58kB/s 0:00:01 67346 100% 4.28MB/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.08MB/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% 28.48kB/s 0:00:00 803 100% 32.67kB/s 0:00:00 (xfer#12, to-check=11/27)
bin/apps/sigma0.nul
700 0% 26.29kB/s 0:00:15 417092 100% 9.70MB/s 0:00:00 (xfer#13, to-check=10/27)
bin/apps/vancouver.nul
700 0% 16.28kB/s 0:00:14 237532 100% 4.44MB/s 0:00:00 (xfer#14, to-check=9/27)
bin/boot/munich
700 29% 13.40kB/s 0:00:00 2356 100% 45.11kB/s 0:00:00 (xfer#15, to-check=7/27)
imgs/passive/CAcertSrv.crt
700 92% 13.15kB/s 0:00:00 756 100% 14.20kB/s 0:00:00 (xfer#16, to-check=4/27)
imgs/passive/bzImage
2208 0% 14.57kB/s 0:05:36 4904720 100% 14.90MB/s 0:00:00 (xfer#17, to-check=3/27)
imgs/passive/certSrv.crt
700 96% 2.17kB/s 0:00:00 726 100% 2.25kB/s 0:00:00 (xfer#18, to-check=2/27)
imgs/passive/initramfs
3008 0% 9.27kB/s 0:16:16 9054208 100% 13.86MB/s 0:00:00 (xfer#19, to-check=1/27)
imgs/passive/privkeySrv.der
608 100% 0.95kB/s 0:00:00 608 100% 0.95kB/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
[ 5] CORE:0:1: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
[ 1] CORE:0:1:0 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
[ 6] CORE:0:2:1 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
=> 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 15169 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=15169
+ set +x
>>> test 141.76.49.60
! /home/sojka/nul/alexb/apps/libvirt/libvirt.wv.inc:39 test 141.76.49.60 okok