Attachment 878921 Details for Bug 991288 – iofuzz-autotest-debug file

iofuzz-autotest-debug file

virt.qemu.repeat1.smp_4.4096m.Host_RHEL.7.0.raw_dd.virtio_scsi.up.virtio_net.RHEL.7.0.x86_64.iofuzz.DEBUG (text/plain), 63.35 KB, created by CongLi on 2014-03-26 09:48:04 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: CongLi

Created: 2014-03-26 09:48:04 UTC

Size: 63.35 KB

patch

obsolete

>03/25 12:57:18 DEBUG|      test:0310| Profilers present. Profiling run started
>03/25 12:57:18 DEBUG|     utils:0109| Running 'git describe --abbrev=4'
>03/25 12:57:18 DEBUG|     utils:0109| Running 'git rev-parse --abbrev-ref HEAD'
>03/25 12:57:18 DEBUG|     utils:0109| Running 'git show --summary --pretty='%H' | head -1'
>03/25 12:57:18 INFO |      virt:0057| Virt Test '0.15.1-master-5436-g1cbd0', Branch 'master', SHA1 '1cbd0ba56ec9bdb53d538640654fcb427b1e68be'
>03/25 12:57:18 DEBUG|      virt:0059| Test parameters:
>03/25 12:57:18 DEBUG|      virt:0063|     _name_map_file = {'tests-example.cfg': 'repeat1.smp_4.4096m.functional', 'subtests.cfg': '(subtest=iofuzz)', 'guest-hw.cfg': 'no_lvm_support.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.raw_dd.virtio_scsi.up.virtio_net', 'guest-os-internal.cfg': 'Linux.RHEL.7.0.x86_64', 'host-kernel-internal.cfg': 'Host_RHEL.7.0', 'guest-hw-internal.cfg': 'vnc.local_stg'}
>03/25 12:57:18 DEBUG|      virt:0063|     _short_name_map_file = {'tests-example.cfg': 'repeat1.smp_4.4096m.functional', 'subtests.cfg': 'iofuzz', 'guest-hw.cfg': 'no_lvm_support.filesystem.no_9p_export.smallpages.no_pci_assignable.raw_dd.virtio_scsi.up.virtio_net', 'guest-os-internal.cfg': 'Linux.RHEL.7.0.x86_64', 'host-kernel-internal.cfg': 'Host_RHEL.7.0', 'guest-hw-internal.cfg': 'vnc.local_stg'}
>03/25 12:57:18 DEBUG|      virt:0063|     address_range_base_mac_r1 = 00:11:22:33:AB:08
>03/25 12:57:18 DEBUG|      virt:0063|     address_ranges = r1
>03/25 12:57:18 DEBUG|      virt:0063|     always_use_tcpdump = yes
>03/25 12:57:18 DEBUG|      virt:0063|     auto_cpu_model = yes
>03/25 12:57:18 DEBUG|      virt:0063|     backup_dir = images/
>03/25 12:57:18 DEBUG|      virt:0063|     backup_image = no
>03/25 12:57:18 DEBUG|      virt:0063|     backup_image_on_check_error = no
>03/25 12:57:19 DEBUG|      virt:0063|     boot_menu = off
>03/25 12:57:19 DEBUG|      virt:0063|     boot_once = c
>03/25 12:57:19 DEBUG|      virt:0063|     boot_order = cdn
>03/25 12:57:19 DEBUG|      virt:0063|     brew_tag = rhel-7.0-candidate
>03/25 12:57:19 DEBUG|      virt:0063|     cd_format = scsi-cd
>03/25 12:57:19 DEBUG|      virt:0063|     cdrom_check_cdrom_pattern = /dev/cdrom-\w+|/dev/cdrom\d*
>03/25 12:57:19 DEBUG|      virt:0063|     cdrom_get_cdrom_cmd = ls /dev/cdrom*
>03/25 12:57:19 DEBUG|      virt:0063|     cdrom_test_cmd = dd if=%s of=/dev/null bs=1 count=1
>03/25 12:57:19 DEBUG|      virt:0063|     cdroms = cd1
>03/25 12:57:19 DEBUG|      virt:0063|     check_img = no
>03/25 12:57:19 DEBUG|      virt:0063|     convert_ppm_files_to_png = yes
>03/25 12:57:19 DEBUG|      virt:0063|     convert_ppm_files_to_png_on_error = yes
>03/25 12:57:19 DEBUG|      virt:0063|     cpu_chk_cmd = ls /sys/devices/system/cpu | egrep -c "cpu[0-9]+$"
>03/25 12:57:19 DEBUG|      virt:0063|     cpu_model = qemu64
>03/25 12:57:19 DEBUG|      virt:0063|     cpu_model_flags = ,+kvm_pv_unhalt
>03/25 12:57:19 DEBUG|      virt:0063|     create_with_dd = yes
>03/25 12:57:19 DEBUG|      virt:0063|     dd_create_cmd = dd if=/dev/zero of=%s bs=1M count=%s
>03/25 12:57:19 DEBUG|      virt:0063|     dd_timeout = 900
>03/25 12:57:19 DEBUG|      virt:0063|     default_cpu_model = qemu64
>03/25 12:57:19 DEBUG|      virt:0063|     dep = ['repeat1.smp_4.4096m.functional.Host_RHEL.7.0.vnc.local_stg.no_lvm_support.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.raw_dd.virtio_scsi.up.virtio_net.Linux.RHEL.7.0.x86_64.install', 'repeat1.smp_4.4096m.functional.Host_RHEL.7.0.vnc.local_stg.no_lvm_support.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.raw_dd.virtio_scsi.up.virtio_net.Linux.RHEL.7.0.x86_64.setup', 'repeat1.smp_4.4096m.functional.Host_RHEL.7.0.vnc.local_stg.no_lvm_support.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.raw_dd.virtio_scsi.up.virtio_net.Linux.RHEL.7.0.x86_64.image_copy', 'repeat1.smp_4.4096m.functional.Host_RHEL.7.0.vnc.local_stg.no_lvm_support.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.raw_dd.virtio_scsi.up.virtio_net.Linux.RHEL.7.0.x86_64.unattended_install.cdrom']
>03/25 12:57:19 DEBUG|      virt:0063|     display = vnc
>03/25 12:57:19 DEBUG|      virt:0063|     drive_cache = none
>03/25 12:57:19 DEBUG|      virt:0063|     drive_format = scsi-hd
>03/25 12:57:19 DEBUG|      virt:0063|     drive_index_cd1 = 1
>03/25 12:57:19 DEBUG|      virt:0063|     drive_index_image1 = 0
>03/25 12:57:19 DEBUG|      virt:0063|     drive_rerror_image1 = 
>03/25 12:57:19 DEBUG|      virt:0063|     drive_werror_image1 = 
>03/25 12:57:19 DEBUG|      virt:0063|     dryrun = yes
>03/25 12:57:19 DEBUG|      virt:0063|     dst_dir = /mnt/linux
>03/25 12:57:19 DEBUG|      virt:0063|     encode_video_files = yes
>03/25 12:57:19 DEBUG|      virt:0063|     extra_params =  -no-kvm-pit-reinjection
>03/25 12:57:19 DEBUG|      virt:0063|     file_transfer_client = scp
>03/25 12:57:19 DEBUG|      virt:0063|     file_transfer_port = 22
>03/25 12:57:19 DEBUG|      virt:0063|     get_time_cmd = date +'TIME: %a %m/%d/%Y %H:%M:%S.%N'
>03/25 12:57:19 DEBUG|      virt:0063|     guest_name = RHEL-Server-7.0-64
>03/25 12:57:19 DEBUG|      virt:0063|     guest_port_remote_shell = 22
>03/25 12:57:19 DEBUG|      virt:0063|     host_kernel_ver_str = Host_RHEL.7.0
>03/25 12:57:19 DEBUG|      virt:0063|     host_setup_flag = 0
>03/25 12:57:19 DEBUG|      virt:0063|     hosttype = small
>03/25 12:57:19 DEBUG|      virt:0063|     image_aio = native
>03/25 12:57:19 DEBUG|      virt:0063|     image_backend = filesystem
>03/25 12:57:19 DEBUG|      virt:0063|     image_boot = no
>03/25 12:57:19 DEBUG|      virt:0063|     image_chain = 
>03/25 12:57:19 DEBUG|      virt:0063|     image_clone_command = cp --reflink=auto %s %s
>03/25 12:57:19 DEBUG|      virt:0063|     image_format = raw
>03/25 12:57:19 DEBUG|      virt:0063|     image_name = images/RHEL-Server-7.0-64-virtio
>03/25 12:57:19 DEBUG|      virt:0063|     image_raw_device = no
>03/25 12:57:19 DEBUG|      virt:0063|     image_remove_command = rm -rf %s
>03/25 12:57:19 DEBUG|      virt:0063|     image_size = 20G
>03/25 12:57:19 DEBUG|      virt:0063|     image_snapshot = no
>03/25 12:57:19 DEBUG|      virt:0063|     image_unbootable_pattern = Hard Disk.*not a bootable disk
>03/25 12:57:19 DEBUG|      virt:0063|     image_verify_bootable = yes
>03/25 12:57:19 DEBUG|      virt:0063|     images = image1
>03/25 12:57:19 DEBUG|      virt:0063|     images_good = 10.66.90.128:/vol/S2/kvmauto/linux_img
>03/25 12:57:19 DEBUG|      virt:0063|     important_key = guest_name,platform,smp,mem,drive_format,nic_model,type,ksm,image_format,kvm_version,kvm_userspace_version,tag,medium,installation
>03/25 12:57:19 DEBUG|      virt:0063|     inactivity_treshold = 3600
>03/25 12:57:19 DEBUG|      virt:0063|     inactivity_watcher = logimage_remove_commnad = 'rm -rf %s'
>03/25 12:57:19 DEBUG|      virt:0063|     index_enable = yes
>03/25 12:57:19 DEBUG|      virt:0063|     indirect_image_blacklist = /dev/hda[\d]* /dev/sda[\d]* /dev/sg0 /dev/md0
>03/25 12:57:19 DEBUG|      virt:0063|     init_pci_addr = 4
>03/25 12:57:19 DEBUG|      virt:0063|     isa_serials = serial0
>03/25 12:57:19 DEBUG|      virt:0063|     iterations = 1
>03/25 12:57:19 DEBUG|      virt:0063|     job_timeout = 0
>03/25 12:57:19 DEBUG|      virt:0063|     keep_ppm_files = no
>03/25 12:57:19 DEBUG|      virt:0063|     keep_ppm_files_on_error = no
>03/25 12:57:19 DEBUG|      virt:0063|     keep_screendumps = yes
>03/25 12:57:19 DEBUG|      virt:0063|     keep_screendumps_on_error = yes
>03/25 12:57:19 DEBUG|      virt:0063|     keep_video_files = yes
>03/25 12:57:19 DEBUG|      virt:0063|     keep_video_files_on_error = yes
>03/25 12:57:19 DEBUG|      virt:0063|     kill_timeout = 60
>03/25 12:57:19 DEBUG|      virt:0063|     kill_unresponsive_vms = yes
>03/25 12:57:19 DEBUG|      virt:0063|     kill_vm = no
>03/25 12:57:19 DEBUG|      virt:0063|     kill_vm_before_test = no
>03/25 12:57:19 DEBUG|      virt:0063|     kill_vm_gracefully = yes
>03/25 12:57:19 DEBUG|      virt:0063|     kill_vm_in_paused = yes
>03/25 12:57:19 DEBUG|      virt:0063|     kill_vm_on_error = yes
>03/25 12:57:19 DEBUG|      virt:0063|     kill_vm_only_when_paused = yes
>03/25 12:57:19 DEBUG|      virt:0063|     ksm = 0
>03/25 12:57:19 DEBUG|      virt:0063|     kvm_default = {'/sys/module/kvm/parameters/ignore_msrs': 'N', '/sys/module/kvm/parameters/min_timer_period_us': '500', '/sys/module/kvm/parameters/tsc_tolerance_ppm': '250', '/sys/module/kvm/parameters/mmu_audit': 'N'}
>03/25 12:57:19 DEBUG|      virt:0063|     kvm_userspace_ver_cmd = grep -q el5 /proc/version && rpm -qa | grep ^kvm-83-.* || rpm -qa | grep qemu-kvm-[0-9].*-.* | head -n 1
>03/25 12:57:19 DEBUG|      virt:0063|     kvm_ver_cmd = grep -q el5 /proc/version && cat /sys/module/kvm/version || uname -r
>03/25 12:57:19 DEBUG|      virt:0063|     login_timeout = 360
>03/25 12:57:19 DEBUG|      virt:0063|     mac_ip_filter = HWaddr (.\w+:\w+:\w+:\w+:\w+:\w+)\s+?inet addr:(.\d+\.\d+\.\d+\.\d+)
>03/25 12:57:19 DEBUG|      virt:0063|     machine_type = pc
>03/25 12:57:19 DEBUG|      virt:0063|     main_monitor = qmpmonitor1
>03/25 12:57:19 DEBUG|      virt:0063|     main_vm = virt-tests-vm1
>03/25 12:57:19 DEBUG|      virt:0063|     malloc_perturb = no
>03/25 12:57:19 DEBUG|      virt:0063|     mem = 4096
>03/25 12:57:19 DEBUG|      virt:0063|     mem_chk_cmd = dmidecode -t 17 |awk -F: '/Size/ {print $2}'
>03/25 12:57:19 DEBUG|      virt:0063|     mem_chk_cur_cmd = grep MemTotal /proc/meminfo
>03/25 12:57:19 DEBUG|      virt:0063|     mem_chk_re_str = ([0-9]+)
>03/25 12:57:19 DEBUG|      virt:0063|     migration_test_command = uname -r
>03/25 12:57:19 DEBUG|      virt:0063|     monitor_type = qmp
>03/25 12:57:19 DEBUG|      virt:0063|     monitor_type_qmpmonitor1 = qmp
>03/25 12:57:19 DEBUG|      virt:0063|     monitors = qmpmonitor1
>03/25 12:57:19 DEBUG|      virt:0063|     name = repeat1.smp_4.4096m.functional.Host_RHEL.7.0.vnc.local_stg.no_lvm_support.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.raw_dd.virtio_scsi.up.virtio_net.Linux.RHEL.7.0.x86_64.(subtest=iofuzz)
>03/25 12:57:19 DEBUG|      virt:0063|     netdev_extra_params = 
>03/25 12:57:19 DEBUG|      virt:0063|     netdev_peer_re = \s{2,}(.*?):.*?peer=(.*?)\n
>03/25 12:57:19 DEBUG|      virt:0063|     netdst = switch
>03/25 12:57:19 DEBUG|      virt:0063|     nettype = bridge
>03/25 12:57:19 DEBUG|      virt:0063|     network_query = ifconfig
>03/25 12:57:19 DEBUG|      virt:0063|     nfs_iso = 10.66.90.128:/vol/S2/kvmauto/iso
>03/25 12:57:19 DEBUG|      virt:0063|     nic_mode = tap
>03/25 12:57:19 DEBUG|      virt:0063|     nic_model = virtio
>03/25 12:57:19 DEBUG|      virt:0063|     nics = nic1
>03/25 12:57:19 DEBUG|      virt:0063|     os_type = linux
>03/25 12:57:19 DEBUG|      virt:0063|     package_check_cmd_kernel = uname -r
>03/25 12:57:19 DEBUG|      virt:0063|     package_version_pattern_kernel = [\.\-\_\w\d]+
>03/25 12:57:19 DEBUG|      virt:0063|     password = redhat
>03/25 12:57:19 DEBUG|      virt:0063|     paused_after_start_vm = no
>03/25 12:57:19 DEBUG|      virt:0063|     pci_assignable = no
>03/25 12:57:19 DEBUG|      virt:0063|     platform = 64
>03/25 12:57:19 DEBUG|      virt:0063|     post_command_noncritical = yes
>03/25 12:57:19 DEBUG|      virt:0063|     pre_check_cmd = grep 'Red Hat Enterprise Linux' /etc/redhat-release
>03/25 12:57:19 DEBUG|      virt:0063|     profilers = kvm_stat 
>03/25 12:57:19 DEBUG|      virt:0063|     qemu_binary = qemu
>03/25 12:57:19 DEBUG|      virt:0063|     qemu_img_binary = qemu-img
>03/25 12:57:19 DEBUG|      virt:0063|     qemu_io_binary = qemu-io
>03/25 12:57:19 DEBUG|      virt:0063|     qemu_sandbox = off
>03/25 12:57:19 DEBUG|      virt:0063|     qxl = on
>03/25 12:57:19 DEBUG|      virt:0063|     qxl_dev_memory = 33554432
>03/25 12:57:19 DEBUG|      virt:0063|     qxl_dev_nr = 1
>03/25 12:57:19 DEBUG|      virt:0063|     reboot_command = shutdown -r now
>03/25 12:57:19 DEBUG|      virt:0063|     redirs = 
>03/25 12:57:19 DEBUG|      virt:0063|     requires_kernel = [">= 3.2.1-0.8"]
>03/25 12:57:19 DEBUG|      virt:0063|     restore_image = no
>03/25 12:57:19 DEBUG|      virt:0063|     restore_image_on_check_error = no
>03/25 12:57:19 DEBUG|      virt:0063|     rtc_drift = slew
>03/25 12:57:19 DEBUG|      virt:0063|     run_tcpdump = yes
>03/25 12:57:19 DEBUG|      virt:0063|     screendump_delay = 5
>03/25 12:57:19 DEBUG|      virt:0063|     screendump_quality = 30
>03/25 12:57:19 DEBUG|      virt:0063|     screendump_temp_dir = /dev/shm
>03/25 12:57:19 DEBUG|      virt:0063|     screendump_verbose = no
>03/25 12:57:19 DEBUG|      virt:0063|     scsi_hba = virtio-scsi-pci
>03/25 12:57:19 DEBUG|      virt:0063|     shell_client = ssh
>03/25 12:57:19 DEBUG|      virt:0063|     shell_port = 22
>03/25 12:57:19 DEBUG|      virt:0063|     shell_prompt = ^\[.*\][\#\$]\s*$
>03/25 12:57:19 DEBUG|      virt:0063|     shortname = repeat1.smp_4.4096m.Host_RHEL.7.0.raw_dd.virtio_scsi.up.virtio_net.RHEL.7.0.x86_64.iofuzz
>03/25 12:57:19 DEBUG|      virt:0063|     shutdown_command = shutdown -h now
>03/25 12:57:19 DEBUG|      virt:0063|     skip_image_processing = no
>03/25 12:57:19 DEBUG|      virt:0063|     smp = 4
>03/25 12:57:19 DEBUG|      virt:0063|     snapshot_name = vm
>03/25 12:57:19 DEBUG|      virt:0063|     soundcards = 
>03/25 12:57:19 DEBUG|      virt:0063|     spice = disable-ticketing
>03/25 12:57:19 DEBUG|      virt:0063|     spice_addr = 0
>03/25 12:57:19 DEBUG|      virt:0063|     spice_agent_mouse = on
>03/25 12:57:19 DEBUG|      virt:0063|     spice_gen_x509 = yes
>03/25 12:57:19 DEBUG|      virt:0063|     spice_image_compression = auto_glz
>03/25 12:57:19 DEBUG|      virt:0063|     spice_ipv4 = yes
>03/25 12:57:19 DEBUG|      virt:0063|     spice_ipv6 = no
>03/25 12:57:19 DEBUG|      virt:0063|     spice_password = 123456
>03/25 12:57:19 DEBUG|      virt:0063|     spice_playback_compression = on
>03/25 12:57:19 DEBUG|      virt:0063|     spice_port = generate
>03/25 12:57:19 DEBUG|      virt:0063|     spice_secure_channels = main, inputs
>03/25 12:57:19 DEBUG|      virt:0063|     spice_ssl = no
>03/25 12:57:19 DEBUG|      virt:0063|     spice_streaming_video = all
>03/25 12:57:19 DEBUG|      virt:0063|     spice_tls_ciphers = DEFAULT
>03/25 12:57:19 DEBUG|      virt:0063|     spice_tls_port = generate
>03/25 12:57:19 DEBUG|      virt:0063|     spice_x509_cacert_file = ca-cert.pem
>03/25 12:57:19 DEBUG|      virt:0063|     spice_x509_cacert_subj = /C=CZ/L=BRNO/O=SPICE/CN=my CA
>03/25 12:57:19 DEBUG|      virt:0063|     spice_x509_cert_file = server-cert.pem
>03/25 12:57:19 DEBUG|      virt:0063|     spice_x509_dir = yes
>03/25 12:57:19 DEBUG|      virt:0063|     spice_x509_key_file = server-key.pem
>03/25 12:57:19 DEBUG|      virt:0063|     spice_x509_key_password = testPassPhrase
>03/25 12:57:19 DEBUG|      virt:0063|     spice_x509_prefix = /tmp/spice_x509d
>03/25 12:57:19 DEBUG|      virt:0063|     spice_x509_secure = no
>03/25 12:57:19 DEBUG|      virt:0063|     spice_x509_server_subj = /C=CZ/L=BRNO/O=SPICE/CN=my Server
>03/25 12:57:19 DEBUG|      virt:0063|     spice_zlib_glz_wan_compression = auto
>03/25 12:57:19 DEBUG|      virt:0063|     srchost = 
>03/25 12:57:19 DEBUG|      virt:0063|     start_vm = yes
>03/25 12:57:19 DEBUG|      virt:0063|     status_test_command = echo $?
>03/25 12:57:19 DEBUG|      virt:0063|     strict_mode = no
>03/25 12:57:19 DEBUG|      virt:0063|     subtest = iofuzz
>03/25 12:57:19 DEBUG|      virt:0063|     sysfs_dir = /sys
>03/25 12:57:19 DEBUG|      virt:0063|     take_regular_screendumps = yes
>03/25 12:57:19 DEBUG|      virt:0063|     test_timeout = 14400
>03/25 12:57:19 DEBUG|      virt:0063|     try_serial_login = yes
>03/25 12:57:19 DEBUG|      virt:0063|     type = iofuzz
>03/25 12:57:19 DEBUG|      virt:0063|     url_auto_ip = 192.168.122.1
>03/25 12:57:19 DEBUG|      virt:0063|     usb_controller_tablet1 = uhci
>03/25 12:57:19 DEBUG|      virt:0063|     usb_devices = tablet1
>03/25 12:57:19 DEBUG|      virt:0063|     usb_max_port = 2
>03/25 12:57:19 DEBUG|      virt:0063|     usb_type = ich9-usb-uhci1
>03/25 12:57:19 DEBUG|      virt:0063|     usb_type_tablet1 = usb-tablet
>03/25 12:57:19 DEBUG|      virt:0063|     usb_type_usb1 = ich9-usb-uhci1
>03/25 12:57:19 DEBUG|      virt:0063|     usbs = usb1
>03/25 12:57:19 DEBUG|      virt:0063|     use_autostart = no
>03/25 12:57:19 DEBUG|      virt:0063|     use_check_cpu = yes
>03/25 12:57:19 DEBUG|      virt:0063|     use_debug = yes
>03/25 12:57:19 DEBUG|      virt:0063|     use_nic_scritps = no
>03/25 12:57:19 DEBUG|      virt:0063|     use_no_reboot = no
>03/25 12:57:19 DEBUG|      virt:0063|     use_os_type = yes
>03/25 12:57:19 DEBUG|      virt:0063|     use_os_variant = no
>03/25 12:57:19 DEBUG|      virt:0063|     use_storage = local_stg
>03/25 12:57:19 DEBUG|      virt:0063|     use_virt_install_wait = no
>03/25 12:57:19 DEBUG|      virt:0063|     used_cpus = 
>03/25 12:57:19 DEBUG|      virt:0063|     used_mem = 
>03/25 12:57:19 DEBUG|      virt:0063|     username = root
>03/25 12:57:19 DEBUG|      virt:0063|     vcpu_cores = 0
>03/25 12:57:19 DEBUG|      virt:0063|     vcpu_sockets = 2
>03/25 12:57:19 DEBUG|      virt:0063|     vcpu_thread_pattern = u'thread_id':\s+(\d+)
>03/25 12:57:19 DEBUG|      virt:0063|     vcpu_threads = 1
>03/25 12:57:19 DEBUG|      virt:0063|     vfd_size = 1440k
>03/25 12:57:19 DEBUG|      virt:0063|     vga = cirrus
>03/25 12:57:19 DEBUG|      virt:0063|     vhost = vhost=on
>03/25 12:57:19 DEBUG|      virt:0063|     virt_install_wait_time = 300
>03/25 12:57:19 DEBUG|      virt:0063|     virt_test_type = qemu libvirt
>03/25 12:57:19 DEBUG|      virt:0063|     virtio-blk-pci_scsi = 
>03/25 12:57:19 DEBUG|      virt:0063|     vm_type = qemu
>03/25 12:57:19 DEBUG|      virt:0063|     vms = virt-tests-vm1
>03/25 12:57:19 DEBUG|      virt:0063|     vnc_autoport = yes
>03/25 12:57:19 DEBUG|      virt:0063|     wait_augment_ratio = 1
>03/25 12:57:19 DEBUG|      virt:0063|     workaround_qemu_qmp_crash = always
>03/25 12:57:19 DEBUG|qemu_monit:0267| (monitor qmpmonitor1) Sending command 'qmp_capabilities' 
>03/25 12:57:19 DEBUG|qemu_monit:1372| Send command: {'execute': 'qmp_capabilities', 'id': 'mPdDtd4K'}
>03/25 12:57:19 DEBUG|qemu_monit:0267| (monitor qmpmonitor1) Sending command 'help' (via Human Monitor)
>03/25 12:57:19 DEBUG|     utils:0109| Running 'grep -q el5 /proc/version && cat /sys/module/kvm/version || uname -r'
>03/25 12:57:19 DEBUG|env_proces:0521| KVM version: 3.10.0-114.el7.x86_64
>03/25 12:57:19 DEBUG|     utils:0109| Running 'grep -q el5 /proc/version && rpm -qa | grep ^kvm-83-.* || rpm -qa | grep qemu-kvm-[0-9].*-.* | head -n 1'
>03/25 12:57:20 DEBUG|env_proces:0542| KVM userspace version: 
>03/25 12:57:20 DEBUG|qemu_monit:0267| (monitor qmpmonitor1) Sending command 'stop' 
>03/25 12:57:20 DEBUG|qemu_monit:1372| Send command: {'execute': 'stop', 'id': 'J3qU5T9N'}
>03/25 12:57:20 DEBUG|qemu_monit:0267| (monitor qmpmonitor1) Sending command 'cont' 
>03/25 12:57:20 DEBUG|qemu_monit:1372| Send command: {'execute': 'cont', 'id': 'vJJR8RVx'}
>03/25 12:57:20 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -help'
>03/25 12:57:20 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -device ? 2>&1'
>03/25 12:57:20 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -M ?'
>03/25 12:57:20 DEBUG|     utils:0109| Running 'echo -e 'help
>quit' | /home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -monitor stdio -vnc none'
>03/25 12:57:20 DEBUG|     utils:0109| Running 'echo -e '{ "execute": "qmp_capabilities" }
>{ "execute": "query-commands", "id": "RAND91" }
>{ "execute": "quit" }' | (sleep 1; cat )| /home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -qmp stdio -vnc none | grep return | grep RAND91'
>03/25 12:57:21 DEBUG|   qemu_vm:1668| qemu will run in KVM mode
>03/25 12:57:21 DEBUG|   virt_vm:0577| VM params in env don't match requested, restarting.
>03/25 12:57:21 DEBUG|   qemu_vm:2347| Destroying VM virt-tests-vm1 (PID 10040)
>03/25 12:57:21 DEBUG|   qemu_vm:2247| Shutting down VM virt-tests-vm1 (shell)
>03/25 12:57:22 DEBUG|   virt_vm:0683| Found/Verified IP 10.66.110.87 for VM virt-tests-vm1 NIC 0
>03/25 12:57:22 DEBUG|   virt_vm:0683| Found/Verified IP 10.66.110.87 for VM virt-tests-vm1 NIC 0
>03/25 12:57:22 DEBUG|    remote:0219| Login command: 'ssh -o UserKnownHostsFile=/dev/null -o PreferredAuthentications=password -p 22 root@10.66.110.87'
>03/25 12:57:29 INFO |   aexpect:0907| [qemu output] (Process terminated with status 0)
>03/25 12:57:30 DEBUG|   qemu_vm:2354| VM virt-tests-vm1 down (shell)
>03/25 12:57:30 DEBUG| utils_net:0727| Host does not support OpenVSwitch: Missing command: ovs-vswitchd
>03/25 12:57:30 DEBUG|   virt_vm:0792| Generating random mac address for nic
>03/25 12:57:30 DEBUG| utils_net:0727| Host does not support OpenVSwitch: Missing command: ovs-vswitchd
>03/25 12:57:30 DEBUG|   qemu_vm:1713| Adding VM virt-tests-vm1 NIC ifname t0-I87tSh to bridge switch
>03/25 12:57:30 DEBUG| utils_net:0727| Host does not support OpenVSwitch: Missing command: ovs-vswitchd
>03/25 12:57:30 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -help'
>03/25 12:57:30 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -device ? 2>&1'
>03/25 12:57:30 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -M ?'
>03/25 12:57:30 DEBUG|     utils:0109| Running 'echo -e 'help
>quit' | /home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -monitor stdio -vnc none'
>03/25 12:57:31 DEBUG|     utils:0109| Running 'echo -e '{ "execute": "qmp_capabilities" }
>{ "execute": "query-commands", "id": "RAND91" }
>{ "execute": "quit" }' | (sleep 1; cat )| /home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -qmp stdio -vnc none | grep return | grep RAND91'
>03/25 12:57:32 DEBUG|   qemu_vm:1668| qemu will run in KVM mode
>03/25 12:57:32 DEBUG|   qemu_vm:1962| Devices of virt-tests-vm1: [t'PREFIX',t'qemu',t'-S',t'vmname',t'qemu_sandbox',t'machine',t'i440FX',t'PIIX4_PM',t'PIIX3',t'piix3-ide',t'fdc',t'nodefaults',t'VGA-cirrus',t'QMP-qmpmonitor1',t'SER-serial0',t'isa-log',usb1,virtio_scsi_pci0,drive_image1,image1,idT5VEdz,t'NET-bridge',t'mem',t'smp',t'cpu',usb-tablet1,t'display',t'rtc',t'bootmenu',t'extra',t'kvm']
>03/25 12:57:32 DEBUG|   qemu_vm:1963| Buses of virt-tests-vm1
>  drive_image1(QDrive): {drive:image1}
>  virtio_scsi_pci0.0(virtio-scsi-pci): {0-0:image1}
>  usb1.0(uhci): {1:usb-tablet1}
>  floppy(floppy): [None,None]
>  ide(ide): [None,None,None,None]
>  _PCI_CHASSIS_NR(None): {}
>  _PCI_CHASSIS(None): {}
>  pci.0(PCI): {00-00:t'i440FX',01-00:t'PIIX3',01-01:t'piix3-ide',01-03:t'PIIX4_PM',02-00:t'VGA-cirrus',03-00:usb1,04-00:virtio_scsi_pci0,05-00:idT5VEdz}
>03/25 12:57:32 INFO |   qemu_vm:2031| Running qemu command (reformatted):
>/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu \
>    -S  \
>    -name 'virt-tests-vm1'  \
>    -sandbox off  \
>    -M pc  \
>    -nodefaults  \
>    -vga cirrus  \
>    -chardev socket,id=qmp_id_qmpmonitor1,path=/tmp/monitor-qmpmonitor1-20140325-125730-6svGNq1r,server,nowait \
>    -mon chardev=qmp_id_qmpmonitor1,mode=control  \
>    -chardev socket,id=serial_id_serial0,path=/tmp/serial-serial0-20140325-125730-6svGNq1r,server,nowait \
>    -device isa-serial,chardev=serial_id_serial0  \
>    -chardev socket,id=seabioslog_id_20140325-125730-6svGNq1r,path=/tmp/seabios-20140325-125730-6svGNq1r,server,nowait \
>    -device isa-debugcon,chardev=seabioslog_id_20140325-125730-6svGNq1r,iobase=0x402 \
>    -device ich9-usb-uhci1,id=usb1,bus=pci.0,addr=03 \
>    -device virtio-scsi-pci,id=virtio_scsi_pci0,bus=pci.0,addr=04 \
>    -drive id=drive_image1,if=none,cache=none,snapshot=off,aio=native,file=/home/staf-kvm-devel/autotest-devel/client/tests/virt/shared/data/images/RHEL-Server-7.0-64-virtio.raw \
>    -device scsi-hd,id=image1,drive=drive_image1 \
>    -device virtio-net-pci,mac=9a:27:28:29:2a:2b,id=idT5VEdz,netdev=idQUbjjt,bus=pci.0,addr=05  \
>    -netdev tap,id=idQUbjjt,vhost=on,vhostfd=22,fd=20  \
>    -m 4096  \
>    -smp 4,maxcpus=4,cores=2,threads=1,sockets=2  \
>    -cpu 'Opteron_G4',+kvm_pv_unhalt \
>    -device usb-tablet,id=usb-tablet1,bus=usb1.0,port=1  \
>    -vnc :0  \
>    -rtc base=utc,clock=host,driftfix=slew  \
>    -boot order=cdn,once=c,menu=off  \
>    -no-kvm-pit-reinjection \
>    -enable-kvm
>03/25 12:57:32 INFO |   aexpect:0907| [qemu output] Warning: option deprecated, use lost_tick_policy property of kvm-pit instead.
>03/25 12:57:33 INFO |   qemu_vm:2040| Created qemu process with parent PID 10318
>03/25 12:57:33 INFO |qemu_monit:0125| Connecting to monitor 'qmpmonitor1'
>03/25 12:57:33 DEBUG|qemu_monit:0267| (monitor qmpmonitor1) Sending command 'qmp_capabilities' 
>03/25 12:57:33 DEBUG|qemu_monit:1372| Send command: {'execute': 'qmp_capabilities', 'id': 'fczxHnwJ'}
>03/25 12:57:33 DEBUG|qemu_monit:0267| (monitor qmpmonitor1) Sending command 'help' (via Human Monitor)
>03/25 12:57:33 DEBUG|   qemu_vm:2139| VM appears to be alive with PID 10320
>03/25 12:57:33 DEBUG|qemu_monit:0267| (monitor qmpmonitor1) Sending command 'query-cpus' 
>03/25 12:57:33 DEBUG|qemu_monit:1372| Send command: {'execute': 'query-cpus', 'id': 'f8WBfjJZ'}
>03/25 12:57:33 DEBUG|qemu_monit:1328| (monitor qmpmonitor1) Response to 'query-cpus' (re-formated)
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        current: True
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        pc: 4294967280
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        halted: False
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        CPU: 0
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        thread_id: 10324
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        current: False
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        pc: 4294967280
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        halted: False
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        CPU: 1
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        thread_id: 10325
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        current: False
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        pc: 4294967280
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        halted: False
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        CPU: 2
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        thread_id: 10326
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        current: False
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        pc: 4294967280
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        halted: False
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        CPU: 3
>03/25 12:57:33 DEBUG|qemu_monit:1304| (monitor qmpmonitor1)        thread_id: 10327
>03/25 12:57:33 DEBUG|     utils:0109| Running 'ps aux'
>03/25 12:57:34 DEBUG|qemu_monit:0267| (monitor qmpmonitor1) Sending command 'cont' 
>03/25 12:57:34 DEBUG|qemu_monit:1372| Send command: {'execute': 'cont', 'id': 'JdWpiMhT'}
>03/25 12:57:34 INFO |      virt:0136| Running function: iofuzz.run_iofuzz()
>03/25 12:57:34 DEBUG|   virt_vm:0959| Attempting to log into 'virt-tests-vm1' (timeout 360s)
>03/25 12:57:59 DEBUG| utils_env:0081| (address cache) DHCP lease OK: 9a:27:28:29:2a:2b --> 10.66.110.87
>03/25 12:57:59 DEBUG| utils_env:0064| (address cache) DHCP lease OK: 9a:27:28:29:2a:2b --> 10.66.109.68
>03/25 12:58:00 DEBUG|   virt_vm:0683| Found/Verified IP 10.66.109.68 for VM virt-tests-vm1 NIC 0
>03/25 12:58:00 DEBUG|   virt_vm:0683| Found/Verified IP 10.66.109.68 for VM virt-tests-vm1 NIC 0
>03/25 12:58:00 DEBUG|    remote:0219| Login command: 'ssh -o UserKnownHostsFile=/dev/null -o PreferredAuthentications=password -p 22 root@10.66.109.68'
>03/25 12:58:03 INFO |    iofuzz:0099| Enumerate guest devices through /proc/ioports
>03/25 12:58:03 DEBUG|   aexpect:1407| Sending command: cat /proc/ioports
>03/25 12:58:03 DEBUG|    iofuzz:0101| 0000-0cf7 : PCI Bus 0000:00
>  0000-001f : dma1
>  0020-0021 : pic1
>  0040-0043 : timer0
>  0050-0053 : timer1
>  0060-0060 : keyboard
>  0064-0064 : keyboard
>  0070-0071 : rtc0
>  0080-008f : dma page reg
>  00a0-00a1 : pic2
>  00c0-00df : dma2
>  00f0-00ff : fpu
>  0170-0177 : 0000:00:01.1
>    0170-0177 : ata_piix
>  01f0-01f7 : 0000:00:01.1
>    01f0-01f7 : ata_piix
>  0376-0376 : 0000:00:01.1
>    0376-0376 : ata_piix
>  03c0-03df : vga+
>  03f2-03f2 : floppy
>  03f4-03f5 : floppy
>  03f6-03f6 : 0000:00:01.1
>    03f6-03f6 : ata_piix
>  03f7-03f7 : floppy
>  03f8-03ff : serial
>0cf8-0cff : PCI conf1
>0d00-ffff : PCI Bus 0000:00
>  afe0-afe3 : ACPI GPE0_BLK
>  b000-b03f : 0000:00:01.3
>    b000-b003 : ACPI PM1a_EVT_BLK
>    b004-b005 : ACPI PM1a_CNT_BLK
>    b008-b00b : ACPI PM_TMR
>  b100-b10f : 0000:00:01.3
>    b100-b107 : piix4_smbus
>  c000-c03f : 0000:00:04.0
>    c000-c03f : virtio-pci
>  c040-c05f : 0000:00:03.0
>    c040-c05f : uhci_hcd
>  c060-c07f : 0000:00:05.0
>    c060-c07f : virtio-pci
>  c080-c08f : 0000:00:01.1
>    c080-c08f : ata_piix
>
>03/25 12:58:03 INFO |    iofuzz:0116| Fuzzing keyboard, port range 0x60-0x60
>03/25 12:58:03 DEBUG|    iofuzz:0050| inb(0x60)
>03/25 12:58:03 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=96 of=/dev/null bs=1 count=1
>03/25 12:58:03 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:04 DEBUG|    iofuzz:0035| outb(0x60, 0x0)
>03/25 12:58:04 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=96 bs=1 count=1
>03/25 12:58:04 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:05 DEBUG|    iofuzz:0035| outb(0x60, 0xca)
>03/25 12:58:05 DEBUG|   aexpect:1407| Sending command: echo -e '\0312' | dd of=/dev/port seek=96 bs=1 count=1
>03/25 12:58:05 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:05 DEBUG|    iofuzz:0035| outb(0x60, 0x7b)
>03/25 12:58:05 DEBUG|   aexpect:1407| Sending command: echo -e '\0173' | dd of=/dev/port seek=96 bs=1 count=1
>03/25 12:58:05 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:06 DEBUG|    iofuzz:0035| outb(0x60, 0x3e)
>03/25 12:58:06 DEBUG|   aexpect:1407| Sending command: echo -e '\076' | dd of=/dev/port seek=96 bs=1 count=1
>03/25 12:58:06 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:07 DEBUG|    iofuzz:0035| outb(0x60, 0x65)
>03/25 12:58:07 DEBUG|   aexpect:1407| Sending command: echo -e '\0145' | dd of=/dev/port seek=96 bs=1 count=1
>03/25 12:58:07 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:08 DEBUG|    iofuzz:0035| outb(0x60, 0xad)
>03/25 12:58:08 DEBUG|   aexpect:1407| Sending command: echo -e '\0255' | dd of=/dev/port seek=96 bs=1 count=1
>03/25 12:58:08 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:08 DEBUG|    iofuzz:0035| outb(0x60, 0xb2)
>03/25 12:58:08 DEBUG|   aexpect:1407| Sending command: echo -e '\0262' | dd of=/dev/port seek=96 bs=1 count=1
>03/25 12:58:08 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:09 DEBUG|    iofuzz:0035| outb(0x60, 0xac)
>03/25 12:58:09 DEBUG|   aexpect:1407| Sending command: echo -e '\0254' | dd of=/dev/port seek=96 bs=1 count=1
>03/25 12:58:09 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:10 DEBUG|    iofuzz:0035| outb(0x60, 0x5c)
>03/25 12:58:10 DEBUG|   aexpect:1407| Sending command: echo -e '\0134' | dd of=/dev/port seek=96 bs=1 count=1
>03/25 12:58:10 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:10 DEBUG|    iofuzz:0035| outb(0x60, 0x3)
>03/25 12:58:10 DEBUG|   aexpect:1407| Sending command: echo -e '\03' | dd of=/dev/port seek=96 bs=1 count=1
>03/25 12:58:11 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:11 DEBUG|    iofuzz:0035| outb(0x60, 0xe8)
>03/25 12:58:11 DEBUG|   aexpect:1407| Sending command: echo -e '\0350' | dd of=/dev/port seek=96 bs=1 count=1
>03/25 12:58:11 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:12 INFO |    iofuzz:0116| Fuzzing virtio-pci, port range 0xc000-0xc03f
>03/25 12:58:12 DEBUG|    iofuzz:0050| inb(0xc000)
>03/25 12:58:12 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49152 of=/dev/null bs=1 count=1
>03/25 12:58:12 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:13 DEBUG|    iofuzz:0050| inb(0xc001)
>03/25 12:58:13 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49153 of=/dev/null bs=1 count=1
>03/25 12:58:13 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:13 DEBUG|    iofuzz:0050| inb(0xc002)
>03/25 12:58:13 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49154 of=/dev/null bs=1 count=1
>03/25 12:58:14 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:14 DEBUG|    iofuzz:0050| inb(0xc003)
>03/25 12:58:14 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49155 of=/dev/null bs=1 count=1
>03/25 12:58:14 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:15 DEBUG|    iofuzz:0050| inb(0xc004)
>03/25 12:58:15 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49156 of=/dev/null bs=1 count=1
>03/25 12:58:15 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:16 DEBUG|    iofuzz:0050| inb(0xc005)
>03/25 12:58:16 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49157 of=/dev/null bs=1 count=1
>03/25 12:58:16 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:16 DEBUG|    iofuzz:0050| inb(0xc006)
>03/25 12:58:16 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49158 of=/dev/null bs=1 count=1
>03/25 12:58:16 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:17 DEBUG|    iofuzz:0050| inb(0xc007)
>03/25 12:58:17 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49159 of=/dev/null bs=1 count=1
>03/25 12:58:17 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:18 DEBUG|    iofuzz:0050| inb(0xc008)
>03/25 12:58:18 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49160 of=/dev/null bs=1 count=1
>03/25 12:58:18 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:18 DEBUG|    iofuzz:0050| inb(0xc009)
>03/25 12:58:18 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49161 of=/dev/null bs=1 count=1
>03/25 12:58:19 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:19 DEBUG|    iofuzz:0050| inb(0xc00a)
>03/25 12:58:19 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49162 of=/dev/null bs=1 count=1
>03/25 12:58:19 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:20 DEBUG|    iofuzz:0050| inb(0xc00b)
>03/25 12:58:20 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49163 of=/dev/null bs=1 count=1
>03/25 12:58:20 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:21 DEBUG|    iofuzz:0050| inb(0xc00c)
>03/25 12:58:21 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49164 of=/dev/null bs=1 count=1
>03/25 12:58:21 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:21 DEBUG|    iofuzz:0050| inb(0xc00d)
>03/25 12:58:21 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49165 of=/dev/null bs=1 count=1
>03/25 12:58:22 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:22 DEBUG|    iofuzz:0050| inb(0xc00e)
>03/25 12:58:22 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49166 of=/dev/null bs=1 count=1
>03/25 12:58:22 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:23 DEBUG|    iofuzz:0050| inb(0xc00f)
>03/25 12:58:23 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49167 of=/dev/null bs=1 count=1
>03/25 12:58:23 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:24 DEBUG|    iofuzz:0050| inb(0xc010)
>03/25 12:58:24 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49168 of=/dev/null bs=1 count=1
>03/25 12:58:24 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:24 DEBUG|    iofuzz:0050| inb(0xc011)
>03/25 12:58:24 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49169 of=/dev/null bs=1 count=1
>03/25 12:58:24 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:25 DEBUG|    iofuzz:0050| inb(0xc012)
>03/25 12:58:25 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49170 of=/dev/null bs=1 count=1
>03/25 12:58:25 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:26 DEBUG|    iofuzz:0050| inb(0xc013)
>03/25 12:58:26 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49171 of=/dev/null bs=1 count=1
>03/25 12:58:26 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:26 DEBUG|    iofuzz:0050| inb(0xc014)
>03/25 12:58:26 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49172 of=/dev/null bs=1 count=1
>03/25 12:58:27 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:27 DEBUG|    iofuzz:0050| inb(0xc015)
>03/25 12:58:27 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49173 of=/dev/null bs=1 count=1
>03/25 12:58:27 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:28 DEBUG|    iofuzz:0050| inb(0xc016)
>03/25 12:58:28 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49174 of=/dev/null bs=1 count=1
>03/25 12:58:28 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:29 DEBUG|    iofuzz:0050| inb(0xc017)
>03/25 12:58:29 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49175 of=/dev/null bs=1 count=1
>03/25 12:58:29 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:29 DEBUG|    iofuzz:0050| inb(0xc018)
>03/25 12:58:29 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49176 of=/dev/null bs=1 count=1
>03/25 12:58:30 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:30 DEBUG|    iofuzz:0050| inb(0xc019)
>03/25 12:58:30 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49177 of=/dev/null bs=1 count=1
>03/25 12:58:30 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:31 DEBUG|    iofuzz:0050| inb(0xc01a)
>03/25 12:58:31 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49178 of=/dev/null bs=1 count=1
>03/25 12:58:31 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:32 DEBUG|    iofuzz:0050| inb(0xc01b)
>03/25 12:58:32 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49179 of=/dev/null bs=1 count=1
>03/25 12:58:32 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:32 DEBUG|    iofuzz:0050| inb(0xc01c)
>03/25 12:58:32 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49180 of=/dev/null bs=1 count=1
>03/25 12:58:32 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:33 DEBUG|    iofuzz:0050| inb(0xc01d)
>03/25 12:58:33 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49181 of=/dev/null bs=1 count=1
>03/25 12:58:33 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:34 DEBUG|    iofuzz:0050| inb(0xc01e)
>03/25 12:58:34 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49182 of=/dev/null bs=1 count=1
>03/25 12:58:34 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:34 DEBUG|    iofuzz:0050| inb(0xc01f)
>03/25 12:58:34 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49183 of=/dev/null bs=1 count=1
>03/25 12:58:35 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:35 DEBUG|    iofuzz:0050| inb(0xc020)
>03/25 12:58:35 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49184 of=/dev/null bs=1 count=1
>03/25 12:58:35 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:36 DEBUG|    iofuzz:0050| inb(0xc021)
>03/25 12:58:36 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49185 of=/dev/null bs=1 count=1
>03/25 12:58:36 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:37 DEBUG|    iofuzz:0050| inb(0xc022)
>03/25 12:58:37 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49186 of=/dev/null bs=1 count=1
>03/25 12:58:37 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:37 DEBUG|    iofuzz:0050| inb(0xc023)
>03/25 12:58:37 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49187 of=/dev/null bs=1 count=1
>03/25 12:58:38 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:38 DEBUG|    iofuzz:0050| inb(0xc024)
>03/25 12:58:38 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49188 of=/dev/null bs=1 count=1
>03/25 12:58:38 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:39 DEBUG|    iofuzz:0050| inb(0xc025)
>03/25 12:58:39 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49189 of=/dev/null bs=1 count=1
>03/25 12:58:39 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:40 DEBUG|    iofuzz:0050| inb(0xc026)
>03/25 12:58:40 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49190 of=/dev/null bs=1 count=1
>03/25 12:58:40 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:40 DEBUG|    iofuzz:0050| inb(0xc027)
>03/25 12:58:40 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49191 of=/dev/null bs=1 count=1
>03/25 12:58:40 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:41 DEBUG|    iofuzz:0050| inb(0xc028)
>03/25 12:58:41 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49192 of=/dev/null bs=1 count=1
>03/25 12:58:41 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:42 DEBUG|    iofuzz:0050| inb(0xc029)
>03/25 12:58:42 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49193 of=/dev/null bs=1 count=1
>03/25 12:58:42 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:43 DEBUG|    iofuzz:0050| inb(0xc02a)
>03/25 12:58:43 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49194 of=/dev/null bs=1 count=1
>03/25 12:58:43 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:43 DEBUG|    iofuzz:0050| inb(0xc02b)
>03/25 12:58:43 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49195 of=/dev/null bs=1 count=1
>03/25 12:58:43 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:44 DEBUG|    iofuzz:0050| inb(0xc02c)
>03/25 12:58:44 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49196 of=/dev/null bs=1 count=1
>03/25 12:58:44 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:45 DEBUG|    iofuzz:0050| inb(0xc02d)
>03/25 12:58:45 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49197 of=/dev/null bs=1 count=1
>03/25 12:58:45 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:45 DEBUG|    iofuzz:0050| inb(0xc02e)
>03/25 12:58:45 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49198 of=/dev/null bs=1 count=1
>03/25 12:58:46 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:46 DEBUG|    iofuzz:0050| inb(0xc02f)
>03/25 12:58:46 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49199 of=/dev/null bs=1 count=1
>03/25 12:58:46 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:47 DEBUG|    iofuzz:0050| inb(0xc030)
>03/25 12:58:47 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49200 of=/dev/null bs=1 count=1
>03/25 12:58:47 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:48 DEBUG|    iofuzz:0050| inb(0xc031)
>03/25 12:58:48 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49201 of=/dev/null bs=1 count=1
>03/25 12:58:48 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:48 DEBUG|    iofuzz:0050| inb(0xc032)
>03/25 12:58:48 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49202 of=/dev/null bs=1 count=1
>03/25 12:58:48 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:49 DEBUG|    iofuzz:0050| inb(0xc033)
>03/25 12:58:49 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49203 of=/dev/null bs=1 count=1
>03/25 12:58:49 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:50 DEBUG|    iofuzz:0050| inb(0xc034)
>03/25 12:58:50 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49204 of=/dev/null bs=1 count=1
>03/25 12:58:50 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:51 DEBUG|    iofuzz:0050| inb(0xc035)
>03/25 12:58:51 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49205 of=/dev/null bs=1 count=1
>03/25 12:58:51 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:51 DEBUG|    iofuzz:0050| inb(0xc036)
>03/25 12:58:51 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49206 of=/dev/null bs=1 count=1
>03/25 12:58:51 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:52 DEBUG|    iofuzz:0050| inb(0xc037)
>03/25 12:58:52 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49207 of=/dev/null bs=1 count=1
>03/25 12:58:52 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:53 DEBUG|    iofuzz:0050| inb(0xc038)
>03/25 12:58:53 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49208 of=/dev/null bs=1 count=1
>03/25 12:58:53 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:53 DEBUG|    iofuzz:0050| inb(0xc039)
>03/25 12:58:53 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49209 of=/dev/null bs=1 count=1
>03/25 12:58:54 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:54 DEBUG|    iofuzz:0050| inb(0xc03a)
>03/25 12:58:54 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49210 of=/dev/null bs=1 count=1
>03/25 12:58:54 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:55 DEBUG|    iofuzz:0050| inb(0xc03b)
>03/25 12:58:55 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49211 of=/dev/null bs=1 count=1
>03/25 12:58:55 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:56 DEBUG|    iofuzz:0050| inb(0xc03c)
>03/25 12:58:56 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49212 of=/dev/null bs=1 count=1
>03/25 12:58:56 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:56 DEBUG|    iofuzz:0050| inb(0xc03d)
>03/25 12:58:56 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49213 of=/dev/null bs=1 count=1
>03/25 12:58:56 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:57 DEBUG|    iofuzz:0050| inb(0xc03e)
>03/25 12:58:57 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49214 of=/dev/null bs=1 count=1
>03/25 12:58:57 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:58 DEBUG|    iofuzz:0050| inb(0xc03f)
>03/25 12:58:58 DEBUG|   aexpect:1407| Sending command: dd if=/dev/port seek=49215 of=/dev/null bs=1 count=1
>03/25 12:58:58 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:58 DEBUG|    iofuzz:0035| outb(0xc000, 0x0)
>03/25 12:58:58 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49152 bs=1 count=1
>03/25 12:58:59 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0x0 value 0x0
>03/25 12:58:59 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:58:59 DEBUG|    iofuzz:0035| outb(0xc001, 0x0)
>03/25 12:58:59 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49153 bs=1 count=1
>03/25 12:58:59 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0x1 value 0x0
>03/25 12:58:59 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:00 DEBUG|    iofuzz:0035| outb(0xc002, 0x0)
>03/25 12:59:00 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49154 bs=1 count=1
>03/25 12:59:00 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0x2 value 0x0
>03/25 12:59:00 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:01 DEBUG|    iofuzz:0035| outb(0xc003, 0x0)
>03/25 12:59:01 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49155 bs=1 count=1
>03/25 12:59:01 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0x3 value 0x0
>03/25 12:59:01 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:01 DEBUG|    iofuzz:0035| outb(0xc004, 0x0)
>03/25 12:59:01 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49156 bs=1 count=1
>03/25 12:59:02 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:02 DEBUG|    iofuzz:0035| outb(0xc005, 0x0)
>03/25 12:59:02 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49157 bs=1 count=1
>03/25 12:59:02 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0x5 value 0x0
>03/25 12:59:02 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:03 DEBUG|    iofuzz:0035| outb(0xc006, 0x0)
>03/25 12:59:03 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49158 bs=1 count=1
>03/25 12:59:03 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0x6 value 0x0
>03/25 12:59:03 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:04 DEBUG|    iofuzz:0035| outb(0xc007, 0x0)
>03/25 12:59:04 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49159 bs=1 count=1
>03/25 12:59:04 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0x7 value 0x0
>03/25 12:59:04 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:04 DEBUG|    iofuzz:0035| outb(0xc008, 0x0)
>03/25 12:59:04 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49160 bs=1 count=1
>03/25 12:59:04 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:05 DEBUG|    iofuzz:0035| outb(0xc009, 0x0)
>03/25 12:59:05 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49161 bs=1 count=1
>03/25 12:59:05 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0x9 value 0x0
>03/25 12:59:05 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:06 DEBUG|    iofuzz:0035| outb(0xc00a, 0x0)
>03/25 12:59:06 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49162 bs=1 count=1
>03/25 12:59:06 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0xa value 0x0
>03/25 12:59:06 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:07 DEBUG|    iofuzz:0035| outb(0xc00b, 0x0)
>03/25 12:59:07 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49163 bs=1 count=1
>03/25 12:59:07 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0xb value 0x0
>03/25 12:59:07 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:07 DEBUG|    iofuzz:0035| outb(0xc00c, 0x0)
>03/25 12:59:07 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49164 bs=1 count=1
>03/25 12:59:07 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0xc value 0x0
>03/25 12:59:07 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:08 DEBUG|    iofuzz:0035| outb(0xc00d, 0x0)
>03/25 12:59:08 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49165 bs=1 count=1
>03/25 12:59:08 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0xd value 0x0
>03/25 12:59:08 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:09 DEBUG|    iofuzz:0035| outb(0xc00e, 0x0)
>03/25 12:59:09 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49166 bs=1 count=1
>03/25 12:59:09 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:09 DEBUG|    iofuzz:0035| outb(0xc00f, 0x0)
>03/25 12:59:09 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49167 bs=1 count=1
>03/25 12:59:09 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0xf value 0x0
>03/25 12:59:10 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:10 DEBUG|    iofuzz:0035| outb(0xc010, 0x0)
>03/25 12:59:10 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49168 bs=1 count=1
>03/25 12:59:10 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:11 DEBUG|    iofuzz:0035| outb(0xc011, 0x0)
>03/25 12:59:11 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49169 bs=1 count=1
>03/25 12:59:11 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0x11 value 0x0
>03/25 12:59:11 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:12 DEBUG|    iofuzz:0035| outb(0xc012, 0x0)
>03/25 12:59:12 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49170 bs=1 count=1
>03/25 12:59:12 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:12 DEBUG|    iofuzz:0035| outb(0xc013, 0x0)
>03/25 12:59:12 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49171 bs=1 count=1
>03/25 12:59:12 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0x13 value 0x0
>03/25 12:59:13 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:13 DEBUG|    iofuzz:0035| outb(0xc014, 0x0)
>03/25 12:59:13 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49172 bs=1 count=1
>03/25 12:59:13 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:14 DEBUG|    iofuzz:0035| outb(0xc015, 0x0)
>03/25 12:59:14 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49173 bs=1 count=1
>03/25 12:59:14 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0x15 value 0x0
>03/25 12:59:14 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:15 DEBUG|    iofuzz:0035| outb(0xc016, 0x0)
>03/25 12:59:15 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49174 bs=1 count=1
>03/25 12:59:15 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:15 DEBUG|    iofuzz:0035| outb(0xc017, 0x0)
>03/25 12:59:15 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49175 bs=1 count=1
>03/25 12:59:15 INFO |   aexpect:0907| [qemu output] qemu: virtio_ioport_write: unexpected address 0x17 value 0x0
>03/25 12:59:15 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:16 DEBUG|    iofuzz:0035| outb(0xc018, 0x0)
>03/25 12:59:16 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49176 bs=1 count=1
>03/25 12:59:16 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:17 DEBUG|    iofuzz:0035| outb(0xc019, 0x0)
>03/25 12:59:17 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49177 bs=1 count=1
>03/25 12:59:17 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:18 DEBUG|    iofuzz:0035| outb(0xc01a, 0x0)
>03/25 12:59:18 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49178 bs=1 count=1
>03/25 12:59:18 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:18 DEBUG|    iofuzz:0035| outb(0xc01b, 0x0)
>03/25 12:59:18 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49179 bs=1 count=1
>03/25 12:59:18 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:19 DEBUG|    iofuzz:0035| outb(0xc01c, 0x0)
>03/25 12:59:19 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49180 bs=1 count=1
>03/25 12:59:19 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:20 DEBUG|    iofuzz:0035| outb(0xc01d, 0x0)
>03/25 12:59:20 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49181 bs=1 count=1
>03/25 12:59:20 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:20 DEBUG|    iofuzz:0035| outb(0xc01e, 0x0)
>03/25 12:59:20 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49182 bs=1 count=1
>03/25 12:59:21 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:21 DEBUG|    iofuzz:0035| outb(0xc01f, 0x0)
>03/25 12:59:21 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49183 bs=1 count=1
>03/25 12:59:21 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:22 DEBUG|    iofuzz:0035| outb(0xc020, 0x0)
>03/25 12:59:22 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49184 bs=1 count=1
>03/25 12:59:22 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:23 DEBUG|    iofuzz:0035| outb(0xc021, 0x0)
>03/25 12:59:23 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49185 bs=1 count=1
>03/25 12:59:23 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:23 DEBUG|    iofuzz:0035| outb(0xc022, 0x0)
>03/25 12:59:23 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49186 bs=1 count=1
>03/25 12:59:24 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:24 DEBUG|    iofuzz:0035| outb(0xc023, 0x0)
>03/25 12:59:24 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49187 bs=1 count=1
>03/25 12:59:24 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:25 DEBUG|    iofuzz:0035| outb(0xc024, 0x0)
>03/25 12:59:25 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49188 bs=1 count=1
>03/25 12:59:25 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:26 DEBUG|    iofuzz:0035| outb(0xc025, 0x0)
>03/25 12:59:26 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49189 bs=1 count=1
>03/25 12:59:26 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:26 DEBUG|    iofuzz:0035| outb(0xc026, 0x0)
>03/25 12:59:26 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49190 bs=1 count=1
>03/25 12:59:26 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:27 DEBUG|    iofuzz:0035| outb(0xc027, 0x0)
>03/25 12:59:27 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49191 bs=1 count=1
>03/25 12:59:27 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:28 DEBUG|    iofuzz:0035| outb(0xc028, 0x0)
>03/25 12:59:28 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49192 bs=1 count=1
>03/25 12:59:28 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:28 DEBUG|    iofuzz:0035| outb(0xc029, 0x0)
>03/25 12:59:28 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49193 bs=1 count=1
>03/25 12:59:29 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:29 DEBUG|    iofuzz:0035| outb(0xc02a, 0x0)
>03/25 12:59:29 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49194 bs=1 count=1
>03/25 12:59:29 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:30 DEBUG|    iofuzz:0035| outb(0xc02b, 0x0)
>03/25 12:59:30 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49195 bs=1 count=1
>03/25 12:59:30 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:31 DEBUG|    iofuzz:0035| outb(0xc02c, 0x0)
>03/25 12:59:31 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49196 bs=1 count=1
>03/25 12:59:31 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:31 DEBUG|    iofuzz:0035| outb(0xc02d, 0x0)
>03/25 12:59:31 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49197 bs=1 count=1
>03/25 12:59:32 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:32 DEBUG|    iofuzz:0035| outb(0xc02e, 0x0)
>03/25 12:59:32 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49198 bs=1 count=1
>03/25 12:59:32 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:33 DEBUG|    iofuzz:0035| outb(0xc02f, 0x0)
>03/25 12:59:33 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49199 bs=1 count=1
>03/25 12:59:33 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:34 DEBUG|    iofuzz:0035| outb(0xc030, 0x0)
>03/25 12:59:34 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49200 bs=1 count=1
>03/25 12:59:34 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:34 DEBUG|    iofuzz:0035| outb(0xc031, 0x0)
>03/25 12:59:34 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49201 bs=1 count=1
>03/25 12:59:34 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:35 DEBUG|    iofuzz:0035| outb(0xc032, 0x0)
>03/25 12:59:35 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49202 bs=1 count=1
>03/25 12:59:35 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:36 DEBUG|    iofuzz:0035| outb(0xc033, 0x0)
>03/25 12:59:36 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49203 bs=1 count=1
>03/25 12:59:36 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:37 DEBUG|    iofuzz:0035| outb(0xc034, 0x0)
>03/25 12:59:37 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49204 bs=1 count=1
>03/25 12:59:37 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:37 DEBUG|    iofuzz:0035| outb(0xc035, 0x0)
>03/25 12:59:37 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49205 bs=1 count=1
>03/25 12:59:37 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:38 DEBUG|    iofuzz:0035| outb(0xc036, 0x0)
>03/25 12:59:38 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49206 bs=1 count=1
>03/25 12:59:38 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:39 DEBUG|    iofuzz:0035| outb(0xc037, 0x0)
>03/25 12:59:39 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49207 bs=1 count=1
>03/25 12:59:39 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:39 DEBUG|    iofuzz:0035| outb(0xc038, 0x0)
>03/25 12:59:39 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49208 bs=1 count=1
>03/25 12:59:40 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:40 DEBUG|    iofuzz:0035| outb(0xc039, 0x0)
>03/25 12:59:40 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49209 bs=1 count=1
>03/25 12:59:40 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:41 DEBUG|    iofuzz:0035| outb(0xc03a, 0x0)
>03/25 12:59:41 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49210 bs=1 count=1
>03/25 12:59:41 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:42 DEBUG|    iofuzz:0035| outb(0xc03b, 0x0)
>03/25 12:59:42 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49211 bs=1 count=1
>03/25 12:59:42 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:42 DEBUG|    iofuzz:0035| outb(0xc03c, 0x0)
>03/25 12:59:42 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49212 bs=1 count=1
>03/25 12:59:42 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:43 DEBUG|    iofuzz:0035| outb(0xc03d, 0x0)
>03/25 12:59:43 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49213 bs=1 count=1
>03/25 12:59:43 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:44 DEBUG|    iofuzz:0035| outb(0xc03e, 0x0)
>03/25 12:59:44 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49214 bs=1 count=1
>03/25 12:59:44 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:45 DEBUG|    iofuzz:0035| outb(0xc03f, 0x0)
>03/25 12:59:45 DEBUG|   aexpect:1407| Sending command: echo -e '\0' | dd of=/dev/port seek=49215 bs=1 count=1
>03/25 12:59:45 DEBUG|   aexpect:1407| Sending command: echo $?
>03/25 12:59:45 DEBUG|    iofuzz:0035| outb(0xc032, 0xfa)
>03/25 12:59:45 DEBUG|   aexpect:1407| Sending command: echo -e '\0372' | dd of=/dev/port seek=49202 bs=1 count=1
>03/25 12:59:45 INFO |   aexpect:0907| [qemu output] qemu: bad data written to virtio-scsi configuration space
>03/25 12:59:45 INFO |   aexpect:0907| [qemu output] (Process terminated with status 1)
>03/25 13:00:45 DEBUG|    iofuzz:0041| Timeout expired while waiting for shell command to complete: "echo -e '\\0372' | dd of=/dev/port seek=49202 bs=1 count=1"    (output: '')
>03/25 13:00:50 DEBUG|    iofuzz:0078| Session is not responsive
>03/25 13:00:50 ERROR|      virt:0155| Test failed: TestFail: VM has quit abnormally during write: [49202, 250]
>03/25 13:00:50 INFO |env_proces:0247| Video creation failed for vm virt-tests-vm1: gstreamer-python library was not found
>03/25 13:00:51 DEBUG| utils_net:0727| Host does not support OpenVSwitch: Missing command: ovs-vswitchd
>03/25 13:00:51 ERROR|      test:0414| Exception escaping from test:
>Traceback (most recent call last):
>  File "/home/staf-kvm-devel/autotest-devel/client/shared/test.py", line 411, in _exec
>    _call_test_function(self.execute, *p_args, **p_dargs)
>  File "/home/staf-kvm-devel/autotest-devel/client/shared/test.py", line 823, in _call_test_function
>    return func(*args, **dargs)
>  File "/home/staf-kvm-devel/autotest-devel/client/shared/test.py", line 291, in execute
>    postprocess_profiled_run, args, dargs)
>  File "/home/staf-kvm-devel/autotest-devel/client/shared/test.py", line 209, in _call_run_once
>    *args, **dargs)
>  File "/home/staf-kvm-devel/autotest-devel/client/shared/test.py", line 313, in run_once_profiling
>    self.run_once(*args, **dargs)
>  File "/home/staf-kvm-devel/autotest-devel/client/tests/virt/virt.py", line 139, in run_once
>    run_func(self, params, env)
>  File "/home/staf-kvm-devel/autotest-devel/client/tests/virt/tests/iofuzz.py", line 132, in run_iofuzz
>    fuzz(session, inst)
>  File "/home/staf-kvm-devel/autotest-devel/client/tests/virt/tests/iofuzz.py", line 88, in fuzz
>    "%s: %s" % (op, operand))
>TestFail: VM has quit abnormally during write: [49202, 250]

Actions: View

Attachments on bug 991288: 878921