NUL Test Report

Sun, 26 Apr 2015 01:00:05 +0000 testbox/ivybridge-1-g5bc2785 (Michal Sojka: Move files related to nightly testing to another repo)

18. /home/nul/nul/michal/boot/diskbench-vm.wv

novaboot: Connecting to IP relay... done
<iprelayd: connected>
novaboot: Entering directory `/home/nul/nul/build'
novaboot: Created vancuver.nulconfig
novaboot: Created diskbench.img
novaboot: Created /home/nul/nul/build/config-novaboot
novaboot: Running: rsync -RLp --chmod=Dg+s,ug+w,o-w,+rX --rsync-path="umask 002 && rsync" bin/apps/hypervisor bin/apps/sigma0.nul bin/apps/vancouver.nul bin/boot/munich imgs/bzImage-3.0 imgs/initrd-wvtest-vm-disk.lzma vancuver.nulconfig diskbench.img config-novaboot rtime.felk.cvut.cz:/srv/tftp/novaboot
novaboot: Reseting the test box... done
novaboot: Serial line interaction (press Ctrl-C to interrupt)...
handle id(3) is not a tty. Not changing mode at /usr/share/perl5/Expect.pm line 393, <> line 21.
handle id(3) is not a tty. Not changing mode at /usr/share/perl5/Expect.pm line 393, <> line 21.
handle id(3) is not a tty. Not changing mode at /usr/share/perl5/Expect.pm line 393, <> line 21.
handle id(3) is not a tty. Not changing mode at /usr/share/perl5/Expect.pm line 393, <> line 21.
***** WHICH IDE Returns: Pri/Sec:0, Mas/Slave: 0
SetSataPortString, Port# 0
***** Found a match!!! Drive= 0
GetDriveInfo()
GDI - Found HDD.
NOVA Microhypervisor v6-7ebd956 (x86_32): Apr 26 2015 01:00:34 [gcc 4.7.2]
[ 0] CORE:0:0:0 6:3a:9:1 [12] Intel(R) Core(TM) i5-3550 CPU @ 3.30GHz
[ 1] CORE:0:1:0 6:3a:9:1 [12] Intel(R) Core(TM) i5-3550 CPU @ 3.30GHz
[ 3] CORE:0:3:0 6:3a:9:1 [12] Intel(R) Core(TM) i5-3550 CPU @ 3.30GHz
[ 2] CORE:0:2:0 6:3a:9:1 [12] Intel(R) Core(TM) i5-3550 CPU @ 3.30GHz
=> hostkeyb:0,0x60,1,12 <=
=> script_start:1,1 <=
=> service_config <=
=> vdisk:rom://diskbench.img <=
vdisk: Opened 'diskbench.img' 0x201 bytes.
vdisk: Attached as vdisk 0.
=> vdisk_empty:104857600 <=
vdisk_empty: Attached as vdisk 1.
=> service_disk <=
disk: Added '0'
disk: Added '1'
Constructing service /disk...
Service /disk registered.
sc: start 0-1 count 1
sc: done.
tb: client data 3f000 guid 5 parent 925
(5) Ignored parameter: 'rom://bin/apps/vancouver.nul'
(5) => PC_PS2 <=
(5) => mem:0,0xa0000 <=
(5) physmem: 0 [0, a0000]
(5) => mem:0x100000 <=
(5) physmem: 0 [100000, 3c00000]
(5) => ioio <=
(5) => nullio:0x80 <=
(5) => pic:0x20,,0x4d0 <=
(5) => pic:0xa0,2,0x4d1 <=
(5) => pit:0x40,0 <=
(5) => scp:0x92,0x61 <=
(5) => kbc:0x60,1,12 <=
(5) => keyb:0,0x10000 <=
(5) => mouse:1,0x10001 <=
(5) => rtc:0x70,8 <=
(5) => serial:0x3f8,0x4,0x4711 <=
(5) => hostsink:0x4712,80 <=
(5) => vga:0x03c0 <=
s0: => INIT done <=
(5) Allocating from guest 03be0000+20000
(5) VGA console 3be0000+20000 0x83fe0000
(5) => vbios_disk <=
(5) => vbios_keyboard <=
(5) => hostkeyb:0x10,0x60,1,,1 <=
(5) => vbios_mem <=
(5) => vbios_time <=
(5) => vbios_reset <=
(5) => vbios_multiboot <=
(5) => msi <=
(5) => ioapic <=
(5) => pcihostbridge:0,0x10,0xcf8,0xe0000000 <=
(5) => pmtimer:0x8000 <=
(5) => vcpus <=
(5) => vcpu <=
(5) create VCPU
(5) => halifax <=
(5) => vbios <=
(5) startup
(5) => lapic <=
(5) LAPIC freq 102903312
(5) => ahci:0xe0800000,14,0x30 <=
(5) => drive:0,0,0 <=
(5) do_gsi_boot eip 800007b2 esp 80238fec
(5) SATA disk 0 flags 1 sectors 1
(5) not finished 1404034,0 inprogress 0
(5) not finished 1404034,0 inprogress 0
(5) => drive:1,0,1 <=
(5) SATA disk 1 flags 1 sectors 32000
(5) not finished 1404034,0 inprogress 0
(5) not finished 1404034,0 inprogress 0
(5) void DBus<M>::debug_dump() [with M = MessageHwIOIn]: Bus used 0 times.
(5) 0: StaticReceiver<Y>::StaticReceiver() [with Y = IOAccess]
(5)
(5) do_gsi_boot eip 80004bd8 esp 80236fec
(5) do_gsi_boot eip 800059b8 esp 80235fec
(5) RESET device state
(5) INIT done
(5) reset CPU from 9 mtr_in e0010
(5) > bool VirtualBiosMultiboot::receive(MessageBios&) rip ffff ilen 3 cr0 10 efl 10002
(5) module 0 start 0x81c00000+918 cmdline rom://bin/boot/munich
(5) module 1 start 0x81c02000+14b630 cmdline rom://imgs/bzImage-3.0 clocksource=tsc c
(5) module 2 start 0x81d4f000+1335 cmdline rom://imgs/initrd-wvtest-vm-disk.lzma
(5) # MUNICH: v.0.4.6 starts Linux
(5) # MUNICH: 3.0.8+ (wsh@steelpick) #45 Thu Nov 3 14:55:26 CET 2011
(5) # MUNICH: clocksource=tsc console=ttyS0
(5) # MUNICH: initrd 194F000
(5) # MUNICH: copy image
(5) # MUNICH: start kernel
(5) handle_int15 eax e801 ebx 0 ecx 0 edx 0 eip ffff efl 10002
(5) handle_int15 eax c000 ebx 0 ecx 0 edx 0 eip ffff efl 10002
(5) handle_int15 eax e980 ebx 0 ecx 0 edx 47534943 eip ffff efl 10002
(5) VESA 4f00 tag 0 base 40000+3ac0 esi 0
(5) # Linux version 3.0.8+ (wsh@steelpick) (gcc version 4.6.1 (Debian 4.6.1-7) ) #45
(5) # | Thu Nov 3 14:55:26 CET 2011
(5) # CPU: vendor_id 'NOVA microHV' unknown, using generic init.
(5) # CPU: Your system may be unstable.
(5) # BIOS-provided physical RAM map:
(5) # BIOS-e820: 0000000000000000 - 000000000009ac00 (usable)
(5) # BIOS-e820: 000000000009ac00 - 00000000000a0000 (reserved)
(5) # BIOS-e820: 0000000000100000 - 0000000003be0000 (usable)
(5) # Notice: NX (Execute Disable) protection missing in CPU!
(5) # DMI not present or invalid.
(5) # last_pfn = 0x3be0 max_arch_pfn = 0x100000
(5) # init_memory_mapping: 0000000000000000-0000000003be0000
(5) # RAMDISK: 0194f000 - 01951000
(5) # ACPI: RSDP 0009ce00 00014 (v00 NOVA )
(5) # ACPI: RSDT 0009e000 00030 (v01 NOVA bk@vmmon 00000001 00000000)
(5) # ACPI: APIC 0009f000 00064 (v01 NOVA bk@vmmon 00000001 00000000)
(5) # ACPI: MCFG 0009bc00 0003C (v01 NOVA bk@vmmon 00000001 00000000)
(5) # ACPI: FACP 0009ac00 000DC (v01 NOVA bk@vmmon 00000001 00000000)
(5) # ACPI Error: Required field Pm1aEventBlock has zero address and/or length: 0x000
(5) # | 0000000000000/0x0 (20110413/tbfadt-544)
(5) # ACPI Error: Required field Pm1aControlBlock has zero address and/or length: 0x0
(5) # | 000000000000000/0x0 (20110413/tbfadt-544)
(5) # ACPI Error: Null physical address for ACPI table [DSDT] (20110413/tbutils-459)
(5) # ACPI Error: Null physical address for ACPI table [FACS] (20110413/tbutils-459)
(5) # 0MB HIGHMEM available.
(5) # 59MB LOWMEM available.
(5) # mapped low ram: 0 - 03be0000
(5) # low ram: 0 - 03be0000
(5) # Zone PFN ranges:
(5) # DMA 0x00000010 -> 0x00001000
(5) # Normal 0x00001000 -> 0x00003be0
(5) # HighMem empty
(5) # Movable zone start PFN for each node
(5) # early_node_map[2] active PFN ranges
(5) # 0: 0x00000010 -> 0x0000009a
(5) # 0: 0x00000100 -> 0x00003be0
(5) # ACPI: PM-Timer IO Port: 0x8000
(5) # Allocating PCI resources starting at 3be0000 (gap: 3be0000:fc420000)
(5) # Built 1 zonelists in Zone order, mobility grouping on. Total pages: 15090
(5) # Kernel command line: clocksource=tsc console=ttyS0
(5) # PID hash table entries: 256 (order: -2, 1024 bytes)
(5) # Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
(5) # Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
(5) # Initializing CPU#0
(5) # Initializing HighMem for node 0 (00000000:00000000)
(5) # Memory: 57100k/61312k available (1701k kernel code, 3740k reserved, 755k data,
(5) # | 300k init, 0k highmem)
(5) # virtual kernel memory layout:
(5) # fixmap : 0xfffe4000 - 0xfffff000 ( 108 kB)
(5) # pkmap : 0xff800000 - 0xffc00000 (4096 kB)
(5) # vmalloc : 0xc43e0000 - 0xff7fe000 ( 948 MB)
(5) # lowmem : 0xc0000000 - 0xc3be0000 ( 59 MB)
(5) # .init : 0xc1267000 - 0xc12b2000 ( 300 kB)
(5) # .data : 0xc11a9602 - 0xc1266540 ( 755 kB)
(5) # .text : 0xc1000000 - 0xc11a9602 (1701 kB)
(5) # Checking if this processor honours the WP bit even in supervisor mode...Ok.
(5) # SLUB: Genslabs=15, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
(5) # NR_IRQS:16
(5) # Console: colour VGA+ 80x25
(5) # console [ttyS0] enabled
(5) # Fast TSC calibration using PIT
(5) # Detected 3292.877 MHz processor.
(5) # Calibrating delay loop (skipped), value calculated using timer frequency.. 6585
(5) # | .75 BogoMIPS (lpj=13171508)
(5) # pid_max: default: 32768 minimum: 301
(5) # Mount-cache hash table entries: 512
(5) # CPU: NOVA microHV Vancouver VMM proudly presents this VirtualCPU. stepping 03
(5) # ACPI: Core revision 20110413
(5) # ACPI Exception: AE_NO_ACPI_TABLES, While loading namespace from ACPI tables (20
(5) # | 110413/tbxface-640)
(5) # ACPI: Unable to load the System Description Tables
(5) # ftrace: allocating 8100 entries in 16 pages
(5) # Performance Events:
(5) # devtmpfs: initialized
(5) # PCI: Using configuration type 1 for base access
(5) # bio: create slab <bio-0> at 0
(5) # ACPI: Interpreter disabled.
(5) # vgaarb: loaded
(5) # SCSI subsystem initialized
(5) # PCI: Probing PCI hardware
(5) # Switching to clocksource pit
(5) # pnp: PnP ACPI: disabled
(5) # Switching to clocksource acpi_pm
(5) # Unpacking initramfs...
(5) # Freeing initrd memory: 8k freed
(5) # platform rtc_cmos: registered platform RTC device (no PNP device found)
(5) # io scheduler noop registered (default)
(5) # Serial: 8250/16550 driver, 4 ports, IRQ sharing disabled
(5) # serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16450
(5) bool AhciController::receive(MessageMem&)(1c) read failed
(5) bool AhciController::receive(MessageMem&)(20) read failed
(5) not finished 1404034,0 inprogress 0
(5) not finished 1404034,0 inprogress 0
(5) not finished 1404034,0 inprogress 0
(5) not finished 1404034,0 inprogress 0
(5) bool AhciController::receive(MessageMem&)(0) write failed
(5) bool AhciController::receive(MessageMem&)(c) write failed
(5) # ahci 0000:00:06.0: AHCI 0001.0200 32 slots 2 ports 1.5 Gbps 0x3 impl SATA mode
(5) # ahci 0000:00:06.0: flags: ncq only pio
(5) # scsi0 : ahci
(5) # scsi1 : ahci
(5) # ata1: SATA max UDMA/133 abar m8192@0xe0800000 port 0xe0800100 irq 14
(5) # ata2: SATA max UDMA/133 abar m8192@0xe0800000 port 0xe0800180 irq 14
(5) # i8042: PNP: No PS/2 controller found. Probing ports directly.
(5) # serio: i8042 KBD port at 0x60,0x64 irq 1
(5) # serio: i8042 AUX port at 0x60,0x64 irq 12
(5) # mousedev: PS/2 mouse device common for all mice
(5) # cpuidle: using governor ladder
(5) # input: AT Translated Set 2 keyboard as /devices/platform/i8042/serio0/input/inp
(5) # | ut0
(5) not finished 1404034,0 inprogress 0
(5) not finished 1404034,0 inprogress 0
(5) not finished 1404034,0 inprogress 0
(5) not finished 1404034,0 inprogress 0
(5) # ata1: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
(5) IDENTIFY
(5) PIO setup fis
(5) push data 200 prdbase 2895a80 _dsf 2895a80 0 1
(5) IDENTIFY transfered
(5) # ata1.00: ATA-6: virtualdisk, , max UDMA/100
(5) # ata1.00: 1 sectors, multi 0: LBA48
(5) SET FEATURES 3 sc 45
(5) IDENTIFY
(5) PIO setup fis
(5) push data 200 prdbase 2895a80 _dsf 2895a80 0 1
(5) IDENTIFY transfered
(5) # ata1.00: configured for UDMA/100
(5) # ata2: SATA link up 1.5 Gbps (SStatus 113 SControl 300)
(5) IDENTIFY
(5) PIO setup fis
(5) push data 200 prdbase 34d5a80 _dsf 34d5a80 0 1
(5) IDENTIFY transfered
(5) # ata2.00: ATA-6: virtualdisk, , max UDMA/100
(5) # ata2.00: 204800 sectors, multi 0: LBA48
(5) SET FEATURES 3 sc 45
(5) IDENTIFY
(5) PIO setup fis
(5) push data 200 prdbase 34d5a80 _dsf 34d5a80 0 1
(5) IDENTIFY transfered
(5) # ata2.00: configured for UDMA/100
(5) # scsi 0:0:0:0: Direct-Access ATA virtualdisk n/a PQ: 0 ANSI: 5
(5) # scsi 1:0:0:0: Direct-Access ATA virtualdisk n/a PQ: 0 ANSI: 5
(5) # sd 0:0:0:0: [sda] 1 512-byte logical blocks: (512 B/512 B)
(5) # sd 1:0:0:0: [sdb] 204800 512-byte logical blocks: (104 MB/100 MiB)
(5) # sd 0:0:0:0: [sda] Write Protect is off
(5) # sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support D
(5) # | PO or FUA
(5) # sd 1:0:0:0: [sdb] Write Protect is off
(5) # sd 1:0:0:0: [sdb] Write cache: disabled, read cache: enabled, doesn't support D
(5) # | PO or FUA
(5) # sda: unknown partition table
(5) # sd 0:0:0:0: [sda] Attached SCSI disk
(5) # sdb: unknown partition table
(5) # sd 1:0:0:0: [sdb] Attached SCSI disk
(5) # Freeing unused kernel memory: 300k freed
(5) # ! init.cc:45 mount("none", "/dev", "devtmpfs", 0, NULL) == 0 okok
(5) # ! init.cc:46 (fd = open("/dev/sda", O_RDONLY)) >= 0 okok
(5) # ! init.cc:47 read(fd, buffer, 512) > 0 okok
(5) # ! init.cc:48 strncmp("Lorem ipsum", buffer, 11) == 0 okok
(5) # ! init.cc:52 (fd = open("/dev/sdb", O_RDONLY)) >= 0 okok
(5) # 104857600 b / 123 ms = 852500 kB/s
(5) # ! init.cc:64 PERF: throughput 852500 kB/s okok
(5) # wvtest: done
(5) #
! /home/nul/nul/michal/wvtest/wvnulrun: $assertions_executed > 0 okok