Login
Log in using an SSO provider:
Fedora Account System
Red Hat Associate
Red Hat Customer
Login using a Red Hat Bugzilla account
Forgot Password
Create an Account
Red Hat Bugzilla – Attachment 1627242 Details for
Bug 1762906
Intermittent error 'Hotplug nic can not get IP address' when executing test case nic_hotplug.vhost_nic.nic_virtio
Home
New
Search
Simple Search
Advanced Search
My Links
Browse
Requests
Reports
Current State
Search
Tabular reports
Graphical reports
Duplicates
Other Reports
User Changes
Plotly Reports
Bug Status
Bug Severity
Non-Defaults
Product Dashboard
Help
Page Help!
Bug Writing Guidelines
What's new
Browser Support Policy
5.0.4.rh90 Release notes
FAQ
Guides index
User guide
Web Services
Contact
Legal
[?]
This site requires JavaScript to be enabled to function correctly, please enable it.
Log file showing nic_virtio test case error with Avocado 71.0
nic_virtio_fail_av71_fail.log (text/plain), 105.66 KB, created by
Karen Mezick
on 2019-10-18 17:54:16 UTC
(
hide
)
Description:
Log file showing nic_virtio test case error with Avocado 71.0
Filename:
MIME Type:
Creator:
Karen Mezick
Created:
2019-10-18 17:54:16 UTC
Size:
105.66 KB
patch
obsolete
>2019-10-18 13:12:16,660 sysinfo L0405 DEBUG| File /etc/avocado/sysinfo/commands does not exist. >2019-10-18 13:12:16,660 sysinfo L0416 DEBUG| File /etc/avocado/sysinfo/files does not exist. >2019-10-18 13:12:16,660 sysinfo L0444 DEBUG| File /etc/avocado/sysinfo/profilers does not exist. >2019-10-18 13:12:16,669 job L0381 INFO | Command line: /root/venv/bin/avocado run --vt-type qemu --vt-guest-os Linux.RHEL.7.devel.ppc64le --vt-machine-type pseries type_specific.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio --vt-extra-params nettype=bridge skip_cluster_leak_warn=yes >2019-10-18 13:12:16,669 job L0382 INFO | >2019-10-18 13:12:16,669 job L0416 INFO | Avocado version: 71.0 >2019-10-18 13:12:16,670 job L0417 INFO | >2019-10-18 13:12:16,670 job L0421 INFO | Config files read (in order): >2019-10-18 13:12:16,670 job L0423 INFO | /root/venv/lib/python3.6/site-packages/avocado_vt/conf.d/vt_joblock.conf >2019-10-18 13:12:16,670 job L0423 INFO | /root/venv/lib/python3.6/site-packages/avocado_vt/conf.d/vt.conf >2019-10-18 13:12:16,670 job L0423 INFO | /root/venv/lib/python3.6/site-packages/avocado/etc/avocado/avocado.conf >2019-10-18 13:12:16,670 job L0423 INFO | /root/venv/lib/python3.6/site-packages/avocado/etc/avocado/conf.d/resultsdb.conf >2019-10-18 13:12:16,670 job L0423 INFO | /root/venv/lib/python3.6/site-packages/avocado/etc/avocado/conf.d/gdb.conf >2019-10-18 13:12:16,670 job L0423 INFO | /root/venv/lib/python3.6/site-packages/avocado/etc/avocado/conf.d/glib.conf >2019-10-18 13:12:16,670 job L0423 INFO | /root/venv/lib/python3.6/site-packages/avocado/etc/avocado/conf.d/result_upload.conf >2019-10-18 13:12:16,670 job L0423 INFO | /root/venv/lib/python3.6/site-packages/avocado/etc/avocado/conf.d/jobscripts.conf >2019-10-18 13:12:16,670 job L0423 INFO | /root/venv/.config/avocado/avocado.conf >2019-10-18 13:12:16,670 job L0424 INFO | >2019-10-18 13:12:16,671 job L0426 INFO | Avocado config: >2019-10-18 13:12:16,672 job L0435 INFO | Section.Key Value >2019-10-18 13:12:16,672 job L0435 INFO | plugins.vtjoblock.dir /tmp >2019-10-18 13:12:16,672 job L0435 INFO | vt.setup.backup_image_before_test True >2019-10-18 13:12:16,672 job L0435 INFO | vt.setup.restore_image_after_test True >2019-10-18 13:12:16,672 job L0435 INFO | vt.setup.keep_guest_running False >2019-10-18 13:12:16,672 job L0435 INFO | vt.common.data_dir >2019-10-18 13:12:16,673 job L0435 INFO | vt.common.type_specific_only False >2019-10-18 13:12:16,673 job L0435 INFO | vt.common.mem >2019-10-18 13:12:16,673 job L0435 INFO | vt.common.arch >2019-10-18 13:12:16,673 job L0435 INFO | vt.common.machine_type >2019-10-18 13:12:16,673 job L0435 INFO | vt.common.nettype >2019-10-18 13:12:16,673 job L0435 INFO | vt.common.netdst virbr0 >2019-10-18 13:12:16,673 job L0435 INFO | vt.qemu.qemu_bin >2019-10-18 13:12:16,673 job L0435 INFO | vt.qemu.qemu_dst_bin >2019-10-18 13:12:16,673 job L0435 INFO | vt.qemu.accel kvm >2019-10-18 13:12:16,673 job L0435 INFO | vt.qemu.vhost off >2019-10-18 13:12:16,673 job L0435 INFO | vt.qemu.monitor >2019-10-18 13:12:16,674 job L0435 INFO | vt.qemu.smp 2 >2019-10-18 13:12:16,674 job L0435 INFO | vt.qemu.image_type qcow2 >2019-10-18 13:12:16,674 job L0435 INFO | vt.qemu.nic_model virtio_net >2019-10-18 13:12:16,674 job L0435 INFO | vt.qemu.disk_bus virtio_scsi >2019-10-18 13:12:16,674 job L0435 INFO | vt.qemu.sandbox on >2019-10-18 13:12:16,674 job L0435 INFO | vt.qemu.defconfig yes >2019-10-18 13:12:16,674 job L0435 INFO | vt.qemu.malloc_perturb yes >2019-10-18 13:12:16,674 job L0435 INFO | vt.libvirt.connect_uri qemu:///session >2019-10-18 13:12:16,674 job L0435 INFO | vt.debug.no_cleanup False >2019-10-18 13:12:16,674 job L0435 INFO | datadir.paths.base_dir /var/lib/avocado >2019-10-18 13:12:16,674 job L0435 INFO | datadir.paths.test_dir /usr/share/doc/avocado/tests >2019-10-18 13:12:16,674 job L0435 INFO | datadir.paths.data_dir /var/lib/avocado/data >2019-10-18 13:12:16,675 job L0435 INFO | datadir.paths.logs_dir ~/avocado/job-results >2019-10-18 13:12:16,675 job L0435 INFO | sysinfo.collect.enabled True >2019-10-18 13:12:16,675 job L0435 INFO | sysinfo.collect.commands_timeout -1 >2019-10-18 13:12:16,675 job L0435 INFO | sysinfo.collect.installed_packages False >2019-10-18 13:12:16,675 job L0435 INFO | sysinfo.collect.profiler False >2019-10-18 13:12:16,675 job L0435 INFO | sysinfo.collect.locale C >2019-10-18 13:12:16,675 job L0435 INFO | sysinfo.collect.per_test False >2019-10-18 13:12:16,675 job L0435 INFO | sysinfo.collectibles.commands /etc/avocado/sysinfo/commands >2019-10-18 13:12:16,675 job L0435 INFO | sysinfo.collectibles.files /etc/avocado/sysinfo/files >2019-10-18 13:12:16,675 job L0435 INFO | sysinfo.collectibles.profilers /etc/avocado/sysinfo/profilers >2019-10-18 13:12:16,675 job L0435 INFO | runner.output.colored True >2019-10-18 13:12:16,675 job L0435 INFO | runner.output.utf8 >2019-10-18 13:12:16,676 job L0435 INFO | runner.timeout.after_interrupted 60 >2019-10-18 13:12:16,676 job L0435 INFO | runner.timeout.process_died 10 >2019-10-18 13:12:16,676 job L0435 INFO | runner.timeout.process_alive 60 >2019-10-18 13:12:16,676 job L0435 INFO | remoter.behavior.reject_unknown_hosts False >2019-10-18 13:12:16,676 job L0435 INFO | remoter.behavior.disable_known_hosts False >2019-10-18 13:12:16,676 job L0435 INFO | job.output.loglevel debug >2019-10-18 13:12:16,676 job L0435 INFO | restclient.connection.hostname localhost >2019-10-18 13:12:16,676 job L0435 INFO | restclient.connection.port 9405 >2019-10-18 13:12:16,676 job L0435 INFO | restclient.connection.username >2019-10-18 13:12:16,676 job L0435 INFO | restclient.connection.password >2019-10-18 13:12:16,676 job L0435 INFO | plugins.disable [] >2019-10-18 13:12:16,677 job L0435 INFO | plugins.skip_broken_plugin_notification [] >2019-10-18 13:12:16,677 job L0435 INFO | plugins.loaders ['file', '@DEFAULT'] >2019-10-18 13:12:16,677 job L0435 INFO | gdb.paths.gdb /usr/bin/gdb >2019-10-18 13:12:16,677 job L0435 INFO | gdb.paths.gdbserver /usr/bin/gdbserver >2019-10-18 13:12:16,677 job L0435 INFO | plugins.glib.unsafe False >2019-10-18 13:12:16,677 job L0435 INFO | plugins.jobscripts.pre /etc/avocado/scripts/job/pre.d/ >2019-10-18 13:12:16,677 job L0435 INFO | plugins.jobscripts.post /etc/avocado/scripts/job/post.d/ >2019-10-18 13:12:16,677 job L0435 INFO | plugins.jobscripts.warn_non_existing_dir False >2019-10-18 13:12:16,677 job L0435 INFO | plugins.jobscripts.warn_non_zero_status True >2019-10-18 13:12:16,677 job L0436 INFO | >2019-10-18 13:12:16,677 job L0439 INFO | Avocado Data Directories: >2019-10-18 13:12:16,677 job L0440 INFO | >2019-10-18 13:12:16,678 job L0441 INFO | base /var/lib/avocado >2019-10-18 13:12:16,678 job L0442 INFO | tests /root/venv/tests >2019-10-18 13:12:16,678 job L0443 INFO | data /var/lib/avocado/data >2019-10-18 13:12:16,678 job L0444 INFO | logs /root/avocado/job-results/job-2019-10-18T13.12-0f4bdbc >2019-10-18 13:12:16,678 job L0445 INFO | >2019-10-18 13:12:16,679 job L0451 INFO | No variants available, using defaults only >2019-10-18 13:12:16,679 job L0451 INFO | >2019-10-18 13:12:16,679 job L0451 INFO | Variant : / >2019-10-18 13:12:16,679 job L0454 INFO | Temporary dir: /var/tmp/avocado_zngdvo2i/avocado_job__7hhhl7q >2019-10-18 13:12:16,679 job L0455 INFO | >2019-10-18 13:12:16,679 job L0373 INFO | Job ID: 0f4bdbc1651f3c74020dc8da6bbda4ab734b8c8f >2019-10-18 13:12:16,679 job L0376 INFO | >2019-10-18 13:12:16,792 sysinfo L0405 DEBUG| File /etc/avocado/sysinfo/commands does not exist. >2019-10-18 13:12:16,793 sysinfo L0416 DEBUG| File /etc/avocado/sysinfo/files does not exist. >2019-10-18 13:12:16,793 sysinfo L0444 DEBUG| File /etc/avocado/sysinfo/profilers does not exist. >2019-10-18 13:12:16,800 test L0383 INFO | INIT 1-type_specific.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio >2019-10-18 13:12:16,801 parameters L0143 DEBUG| PARAMS (key=timeout, path=*, default=14400) => '14400' >2019-10-18 13:12:16,802 test L0415 DEBUG| Test metadata: >2019-10-18 13:12:16,802 test L0423 DEBUG| teststmpdir: /var/tmp/avocado_qnlzkdys >2019-10-18 13:12:16,802 test L0424 DEBUG| workdir: /var/tmp/avocado_zngdvo2i/avocado_job__7hhhl7q/1-type_specific.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio >2019-10-18 13:12:16,924 test L0609 INFO | START 1-type_specific.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio >2019-10-18 13:12:16,924 test L0297 DEBUG| DATA (filename=output.expected) => NOT FOUND (data sources: variant, test, file) >2019-10-18 13:12:16,950 test L0323 INFO | Avocado-VT 'unknown' >2019-10-18 13:12:16,950 test L0325 DEBUG| Test parameters: >2019-10-18 13:12:16,950 test L0329 DEBUG| _name_map_file = {'machines.cfg': 'pseries', 'subtests.cfg': '(subtest=type_specific).(subtest=io-github-autotest-qemu).(subtest=nic_hotplug).vhost_nic.nic_virtio', 'host-os.cfg': 'Host.RHEL.m8.u1.Host_arch_ppc64le', 'guest-os.cfg': 'Guest.Linux.RHEL.7.devel.ppc64le', 'guest-hw.cfg': 'bridge.default_bios.no_virtio_rng.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_scsi.smp2.virtio_net', 'tests.cfg': 'qemu_kvm_jeos_quick'} >2019-10-18 13:12:16,950 test L0329 DEBUG| _short_name_map_file = {'machines.cfg': 'pseries', 'subtests.cfg': 'type_specific.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio', 'host-os.cfg': 'Host.RHEL.m8.u1.Host_arch_ppc64le', 'guest-os.cfg': 'Guest.Linux.RHEL.7.devel.ppc64le', 'guest-hw.cfg': 'bridge.default_bios.no_virtio_rng.filesystem.no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_scsi.smp2.virtio_net', 'tests.cfg': 'qemu_kvm_jeos_quick'} >2019-10-18 13:12:16,950 test L0329 DEBUG| auto_cpu_model = yes >2019-10-18 13:12:16,951 test L0329 DEBUG| backup_dir = images/ >2019-10-18 13:12:16,951 test L0329 DEBUG| backup_image = no >2019-10-18 13:12:16,951 test L0329 DEBUG| backup_image_before_testing = yes >2019-10-18 13:12:16,951 test L0329 DEBUG| backup_image_on_check_error = no >2019-10-18 13:12:16,951 test L0329 DEBUG| boot_menu = off >2019-10-18 13:12:16,951 test L0329 DEBUG| boot_once = c >2019-10-18 13:12:16,951 test L0329 DEBUG| boot_order = cdn >2019-10-18 13:12:16,951 test L0329 DEBUG| catch_monitor = catch_monitor >2019-10-18 13:12:16,952 test L0329 DEBUG| cd_format = scsi-cd >2019-10-18 13:12:16,952 test L0329 DEBUG| cdrom_check_cdrom_pattern = /dev/cdrom-\w+|/dev/cdrom\d* >2019-10-18 13:12:16,952 test L0329 DEBUG| cdrom_get_cdrom_cmd = ls /dev/cdrom* >2019-10-18 13:12:16,952 test L0329 DEBUG| cdrom_info_cmd = cat /proc/sys/dev/cdrom/info >2019-10-18 13:12:16,952 test L0329 DEBUG| cdrom_test_cmd = dd if=%s of=/dev/null bs=1 count=1 >2019-10-18 13:12:16,952 test L0329 DEBUG| cdroms = cd1 >2019-10-18 13:12:16,952 test L0329 DEBUG| check_image = yes >2019-10-18 13:12:16,952 test L0329 DEBUG| cmds_installed_host = >2019-10-18 13:12:16,953 test L0329 DEBUG| connect_uri = default >2019-10-18 13:12:16,953 test L0329 DEBUG| convert_ppm_files_to_png = no >2019-10-18 13:12:16,953 test L0329 DEBUG| cpu_chk_all_cmd = lscpu | grep "^CPU(s)" | grep -o "[0-9]*" >2019-10-18 13:12:16,953 test L0329 DEBUG| cpu_chk_cmd = grep -c "^processor\b" /proc/cpuinfo >2019-10-18 13:12:16,953 test L0329 DEBUG| cpu_model_flags = >2019-10-18 13:12:16,953 test L0329 DEBUG| create_vm_libvirt = no >2019-10-18 13:12:16,953 test L0329 DEBUG| dep = ['qemu_kvm_jeos_quick.bridge.default_bios.no_virtio_rng.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_scsi.smp2.virtio_net.Guest.Linux.RHEL.7.devel.ppc64le.Host.RHEL.m8.u1.Host_arch_ppc64le.(subtest=type_specific).install', 'qemu_kvm_jeos_quick.bridge.default_bios.no_virtio_rng.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_scsi.smp2.virtio_net.Guest.Linux.RHEL.7.devel.ppc64le.Host.RHEL.m8.u1.Host_arch_ppc64le.(subtest=type_specific).setup', 'qemu_kvm_jeos_quick.bridge.default_bios.no_virtio_rng.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_scsi.smp2.virtio_net.Guest.Linux.RHEL.7.devel.ppc64le.Host.RHEL.m8.u1.Host_arch_ppc64le.(subtest=type_specific).image_copy', 'qemu_kvm_jeos_quick.bridge.default_bios.no_virtio_rng.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_scsi.smp2.virtio_net.Guest.Linux.RHEL.7.devel.ppc64le.Host.RHEL.m8.u1.Host_arch_ppc64le.(subtest=type_specific).unattended_install.cdrom'] >2019-10-18 13:12:16,953 test L0329 DEBUG| display = vnc >2019-10-18 13:12:16,954 test L0329 DEBUG| download_url_stress = http://people.seas.harvard.edu/~apw/stress/stress-1.0.4.tar.gz >2019-10-18 13:12:16,954 test L0329 DEBUG| drive_format = scsi-hd >2019-10-18 13:12:16,954 test L0329 DEBUG| drive_index_cd1 = 1 >2019-10-18 13:12:16,954 test L0329 DEBUG| drive_index_image1 = 0 >2019-10-18 13:12:16,954 test L0329 DEBUG| drive_rerror_image1 = >2019-10-18 13:12:16,954 test L0329 DEBUG| drive_werror_image1 = >2019-10-18 13:12:16,954 test L0329 DEBUG| enable_guest_sosreport = no >2019-10-18 13:12:16,954 test L0329 DEBUG| enable_host_sosreport = no >2019-10-18 13:12:16,954 test L0329 DEBUG| enable_libvirtd_debug_log = yes >2019-10-18 13:12:16,955 test L0329 DEBUG| enable_msix_vectors = yes >2019-10-18 13:12:16,955 test L0329 DEBUG| enable_remote_host_sosreport = no >2019-10-18 13:12:16,955 test L0329 DEBUG| encode_video_files = yes >2019-10-18 13:12:16,955 test L0329 DEBUG| env_cleanup = no >2019-10-18 13:12:16,955 test L0329 DEBUG| extra_params = -net none >2019-10-18 13:12:16,955 test L0329 DEBUG| file_transfer_client = scp >2019-10-18 13:12:16,955 test L0329 DEBUG| file_transfer_port = 22 >2019-10-18 13:12:16,955 test L0329 DEBUG| find_pci_cmd = lspci | grep Ethernet >2019-10-18 13:12:16,956 test L0329 DEBUG| flexible_nic_index = no >2019-10-18 13:12:16,956 test L0329 DEBUG| guest_dmesg_dump_console = no >2019-10-18 13:12:16,956 test L0329 DEBUG| guest_dmesg_ignore = False >2019-10-18 13:12:16,956 test L0329 DEBUG| guest_dmesg_level = 3 >2019-10-18 13:12:16,956 test L0329 DEBUG| guest_port_remote_shell = 22 >2019-10-18 13:12:16,956 test L0329 DEBUG| id = type_specific.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio >2019-10-18 13:12:16,956 test L0329 DEBUG| image_backend = filesystem >2019-10-18 13:12:16,956 test L0329 DEBUG| image_chain = >2019-10-18 13:12:16,956 test L0329 DEBUG| image_clone_command = cp --reflink=auto %s %s >2019-10-18 13:12:16,957 test L0329 DEBUG| image_format = qcow2 >2019-10-18 13:12:16,957 test L0329 DEBUG| image_name = images/rhel7devel-ppc64le >2019-10-18 13:12:16,957 test L0329 DEBUG| image_raw_device = no >2019-10-18 13:12:16,957 test L0329 DEBUG| image_remove_command = rm -rf %s >2019-10-18 13:12:16,957 test L0329 DEBUG| image_size = 10G >2019-10-18 13:12:16,957 test L0329 DEBUG| image_unbootable_pattern = Hard Disk.*not a bootable disk >2019-10-18 13:12:16,957 test L0329 DEBUG| image_verify_bootable = yes >2019-10-18 13:12:16,957 test L0329 DEBUG| images = image1 >2019-10-18 13:12:16,958 test L0329 DEBUG| inactivity_treshold = 1800 >2019-10-18 13:12:16,958 test L0329 DEBUG| inactivity_watcher = log >2019-10-18 13:12:16,958 test L0329 DEBUG| indirect_image_blacklist = /dev/hda[\d]* /dev/sda[\d]* /dev/sg0 /dev/md0 >2019-10-18 13:12:16,958 test L0329 DEBUG| inputs = >2019-10-18 13:12:16,958 test L0329 DEBUG| install_virtio = no >2019-10-18 13:12:16,958 test L0329 DEBUG| keep_ppm_files = no >2019-10-18 13:12:16,958 test L0329 DEBUG| keep_ppm_files_on_error = no >2019-10-18 13:12:16,958 test L0329 DEBUG| keep_screendumps = yes >2019-10-18 13:12:16,959 test L0329 DEBUG| keep_screendumps_on_error = yes >2019-10-18 13:12:16,959 test L0329 DEBUG| keep_video_files = yes >2019-10-18 13:12:16,959 test L0329 DEBUG| keep_video_files_on_error = yes >2019-10-18 13:12:16,959 test L0329 DEBUG| kickstart_reboot_bug = no >2019-10-18 13:12:16,959 test L0329 DEBUG| kill_timeout = 60 >2019-10-18 13:12:16,959 test L0329 DEBUG| kill_unresponsive_vms = yes >2019-10-18 13:12:16,959 test L0329 DEBUG| kill_vm = yes >2019-10-18 13:12:16,959 test L0329 DEBUG| kill_vm_before_test = no >2019-10-18 13:12:16,959 test L0329 DEBUG| kill_vm_gracefully = yes >2019-10-18 13:12:16,960 test L0329 DEBUG| kill_vm_libvirt = no >2019-10-18 13:12:16,960 test L0329 DEBUG| libvirt_controller = virtio-scsi >2019-10-18 13:12:16,960 test L0329 DEBUG| libvirtd_debug_file = >2019-10-18 13:12:16,960 test L0329 DEBUG| libvirtd_debug_level = 2 >2019-10-18 13:12:16,960 test L0329 DEBUG| libvirtd_log_cleanup = yes >2019-10-18 13:12:16,960 test L0329 DEBUG| local_ip = ENTER.YOUR.LOCAL.EXAMPLE.COM >2019-10-18 13:12:16,960 test L0329 DEBUG| local_pwd = >2019-10-18 13:12:16,960 test L0329 DEBUG| login_timeout = 360 >2019-10-18 13:12:16,961 test L0329 DEBUG| machine_type = pseries >2019-10-18 13:12:16,961 test L0329 DEBUG| main_vm = avocado-vt-vm1 >2019-10-18 13:12:16,961 test L0329 DEBUG| malloc_perturb = yes >2019-10-18 13:12:16,961 test L0329 DEBUG| mem = 1024 >2019-10-18 13:12:16,961 test L0329 DEBUG| mem_chk_cmd = numactl --hardware | awk -F: '/size/ {print $2}' >2019-10-18 13:12:16,961 test L0329 DEBUG| mem_chk_cur_cmd = grep MemTotal /proc/meminfo >2019-10-18 13:12:16,961 test L0329 DEBUG| mem_chk_re_str = [^\$]([0-9]+) >2019-10-18 13:12:16,961 test L0329 DEBUG| memballoon_model = virtio >2019-10-18 13:12:16,961 test L0329 DEBUG| migrate_dest_host = ENTER.YOUR.DEST.EXAMPLE.COM >2019-10-18 13:12:16,962 test L0329 DEBUG| migrate_dest_pwd = PASSWORD.DEST.EXAMPLE >2019-10-18 13:12:16,962 test L0329 DEBUG| migrate_load_vms = >2019-10-18 13:12:16,962 test L0329 DEBUG| migrate_main_vm = avocado-vt-vm1 >2019-10-18 13:12:16,962 test L0329 DEBUG| migrate_port = 49152 >2019-10-18 13:12:16,962 test L0329 DEBUG| migrate_proto = tcp >2019-10-18 13:12:16,962 test L0329 DEBUG| migrate_shared_storage = SHARED_IMAGE.EXAMPLE >2019-10-18 13:12:16,962 test L0329 DEBUG| migrate_source_host = ENTER.YOUR.SOURCE.EXAMPLE.COM >2019-10-18 13:12:16,962 test L0329 DEBUG| migrate_source_pwd = PASSWORD.SOURCE.EXAMPLE >2019-10-18 13:12:16,963 test L0329 DEBUG| migrate_vms = >2019-10-18 13:12:16,963 test L0329 DEBUG| migration_setup = no >2019-10-18 13:12:16,963 test L0329 DEBUG| modprobe_module = >2019-10-18 13:12:16,963 test L0329 DEBUG| monitor_type = qmp >2019-10-18 13:12:16,963 test L0329 DEBUG| monitors = qmpmonitor1 >2019-10-18 13:12:16,963 test L0329 DEBUG| name = qemu_kvm_jeos_quick.bridge.default_bios.no_virtio_rng.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_scsi.smp2.virtio_net.Guest.Linux.RHEL.7.devel.ppc64le.Host.RHEL.m8.u1.Host_arch_ppc64le.(subtest=type_specific).(subtest=io-github-autotest-qemu).(subtest=nic_hotplug).vhost_nic.nic_virtio.pseries >2019-10-18 13:12:16,963 test L0329 DEBUG| netdev_extra_params_hotplug_nic1 = ,vhost=on >2019-10-18 13:12:16,963 test L0329 DEBUG| netdev_peer_re = (.*?): .*?\\\s(.*?): >2019-10-18 13:12:16,964 test L0329 DEBUG| netdst = virbr0 >2019-10-18 13:12:16,964 test L0329 DEBUG| nettype = bridge >2019-10-18 13:12:16,964 test L0329 DEBUG| nic_hotplug_count = 1 >2019-10-18 13:12:16,964 test L0329 DEBUG| nic_model = virtio >2019-10-18 13:12:16,964 test L0329 DEBUG| nics = >2019-10-18 13:12:16,964 test L0329 DEBUG| os_type = linux >2019-10-18 13:12:16,964 test L0329 DEBUG| os_variant = rhel7 >2019-10-18 13:12:16,964 test L0329 DEBUG| other_tests_dirs = >2019-10-18 13:12:16,964 test L0329 DEBUG| password = 123456 >2019-10-18 13:12:16,965 test L0329 DEBUG| paused_after_start_vm = no >2019-10-18 13:12:16,965 test L0329 DEBUG| pci_assignable = no >2019-10-18 13:12:16,965 test L0329 DEBUG| pci_model = virtio-net-pci >2019-10-18 13:12:16,965 test L0329 DEBUG| pci_test_cmd = echo %s; nslookup www.redhat.com >2019-10-18 13:12:16,965 test L0329 DEBUG| pci_type = nic >2019-10-18 13:12:16,965 test L0329 DEBUG| power9_compat = no >2019-10-18 13:12:16,965 test L0329 DEBUG| power9_compat_remote = no >2019-10-18 13:12:16,965 test L0329 DEBUG| profilers = kvm_stat >2019-10-18 13:12:16,966 test L0329 DEBUG| provider = io-github-autotest-qemu >2019-10-18 13:12:16,966 test L0329 DEBUG| qemu_binary = /usr/libexec/qemu-kvm >2019-10-18 13:12:16,966 test L0329 DEBUG| qemu_dst_binary = /usr/libexec/qemu-kvm >2019-10-18 13:12:16,966 test L0329 DEBUG| qemu_img_binary = /usr/bin/qemu-img >2019-10-18 13:12:16,966 test L0329 DEBUG| qemu_io_binary = /usr/bin/qemu-io >2019-10-18 13:12:16,966 test L0329 DEBUG| qemu_stop = on >2019-10-18 13:12:16,966 test L0329 DEBUG| reboot_command = shutdown -r now >2019-10-18 13:12:16,966 test L0329 DEBUG| redirs = remote_shell >2019-10-18 13:12:16,967 test L0329 DEBUG| reference_cmd = lspci >2019-10-18 13:12:16,967 test L0329 DEBUG| remote_ip = ENTER.YOUR.REMOTE.EXAMPLE.COM >2019-10-18 13:12:16,967 test L0329 DEBUG| remote_pwd = >2019-10-18 13:12:16,967 test L0329 DEBUG| remote_user = root >2019-10-18 13:12:16,967 test L0329 DEBUG| remove_image_image1 = no >2019-10-18 13:12:16,967 test L0329 DEBUG| restore_image = no >2019-10-18 13:12:16,967 test L0329 DEBUG| restore_image_after_testing = yes >2019-10-18 13:12:16,967 test L0329 DEBUG| restore_image_on_check_error = no >2019-10-18 13:12:16,967 test L0329 DEBUG| restore_smt = no >2019-10-18 13:12:16,968 test L0329 DEBUG| rpmbuild_path = /root/rpmbuild/ >2019-10-18 13:12:16,968 test L0329 DEBUG| run_dhclient = no >2019-10-18 13:12:16,968 test L0329 DEBUG| run_tcpdump = yes >2019-10-18 13:12:16,968 test L0329 DEBUG| screendump_delay = 5 >2019-10-18 13:12:16,968 test L0329 DEBUG| screendump_quality = 30 >2019-10-18 13:12:16,968 test L0329 DEBUG| screendump_temp_dir = /dev/shm >2019-10-18 13:12:16,968 test L0329 DEBUG| screendump_verbose = no >2019-10-18 13:12:16,968 test L0329 DEBUG| scsi_hba = virtio-scsi-pci >2019-10-18 13:12:16,969 test L0329 DEBUG| serial_type = spapr-vty >2019-10-18 13:12:16,969 test L0329 DEBUG| serials = serial0 >2019-10-18 13:12:16,969 test L0329 DEBUG| shell_client = ssh >2019-10-18 13:12:16,969 test L0329 DEBUG| shell_linesep = \n >2019-10-18 13:12:16,969 test L0329 DEBUG| shell_port = 22 >2019-10-18 13:12:16,969 test L0329 DEBUG| shell_prompt = ^\[.*\][\#\$]\s*$ >2019-10-18 13:12:16,969 test L0329 DEBUG| shortname = qcow2.virtio_scsi.smp2.virtio_net.Guest.RHEL.7.devel.ppc64le.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio >2019-10-18 13:12:16,969 test L0329 DEBUG| shutdown_command = shutdown -h now >2019-10-18 13:12:16,970 test L0329 DEBUG| skip_cluster_leak_warn = yes >2019-10-18 13:12:16,970 test L0329 DEBUG| skip_image_check_during_running = no >2019-10-18 13:12:16,970 test L0329 DEBUG| skip_image_processing = no >2019-10-18 13:12:16,970 test L0329 DEBUG| smp = 2 >2019-10-18 13:12:16,970 test L0329 DEBUG| start_vm = yes >2019-10-18 13:12:16,970 test L0329 DEBUG| status_test_command = echo $? >2019-10-18 13:12:16,970 test L0329 DEBUG| store_vm_register = yes >2019-10-18 13:12:16,970 test L0329 DEBUG| stress_args = --cpu 4 --io 4 --vm 2 --vm-bytes 256M >2019-10-18 13:12:16,970 test L0329 DEBUG| stress_install_from_repo = no >2019-10-18 13:12:16,971 test L0329 DEBUG| strict_mode = no >2019-10-18 13:12:16,971 test L0329 DEBUG| subtest = io-github-autotest-qemu.nic_hotplug >2019-10-18 13:12:16,971 test L0329 DEBUG| sysprep_options = --operations machine-id >2019-10-18 13:12:16,971 test L0329 DEBUG| sysprep_required = no >2019-10-18 13:12:16,971 test L0329 DEBUG| take_regular_screendumps = yes >2019-10-18 13:12:16,971 test L0329 DEBUG| test_timeout = 14400 >2019-10-18 13:12:16,971 test L0329 DEBUG| type = nic_hotplug >2019-10-18 13:12:16,971 test L0329 DEBUG| url_auto_ip = >2019-10-18 13:12:16,972 test L0329 DEBUG| usb_bus = usb1.0 >2019-10-18 13:12:16,972 test L0329 DEBUG| usb_controller = xhci >2019-10-18 13:12:16,972 test L0329 DEBUG| usb_devices = tablet1 >2019-10-18 13:12:16,972 test L0329 DEBUG| usb_max_port = 6 >2019-10-18 13:12:16,972 test L0329 DEBUG| usb_type = nec-usb-xhci >2019-10-18 13:12:16,972 test L0329 DEBUG| usb_type_tablet1 = usb-tablet >2019-10-18 13:12:16,972 test L0329 DEBUG| usb_type_usb1 = nec-usb-xhci >2019-10-18 13:12:16,972 test L0329 DEBUG| usbs = usb1 >2019-10-18 13:12:16,972 test L0329 DEBUG| use_autostart = no >2019-10-18 13:12:16,973 test L0329 DEBUG| use_check_cpu = yes >2019-10-18 13:12:16,973 test L0329 DEBUG| use_debug = yes >2019-10-18 13:12:16,973 test L0329 DEBUG| use_no_reboot = no >2019-10-18 13:12:16,973 test L0329 DEBUG| use_os_type = yes >2019-10-18 13:12:16,973 test L0329 DEBUG| use_os_variant = no >2019-10-18 13:12:16,973 test L0329 DEBUG| use_virt_install_wait = no >2019-10-18 13:12:16,973 test L0329 DEBUG| used_cpus = 2 >2019-10-18 13:12:16,973 test L0329 DEBUG| used_mem = 512 >2019-10-18 13:12:16,974 test L0329 DEBUG| username = root >2019-10-18 13:12:16,974 test L0329 DEBUG| verify_guest_dmesg = yes >2019-10-18 13:12:16,974 test L0329 DEBUG| verify_host_dmesg = yes >2019-10-18 13:12:16,974 test L0329 DEBUG| vfd_size = 1440k >2019-10-18 13:12:16,974 test L0329 DEBUG| vga = std >2019-10-18 13:12:16,974 test L0329 DEBUG| vga_use_legacy_expression = no >2019-10-18 13:12:16,974 test L0329 DEBUG| virt_install_wait_time = 300 >2019-10-18 13:12:16,974 test L0329 DEBUG| virt_test_type = qemu >2019-10-18 13:12:16,974 test L0329 DEBUG| virtinstall_extra_args = >2019-10-18 13:12:16,975 test L0329 DEBUG| vm_arch_name = ppc64le >2019-10-18 13:12:16,975 test L0329 DEBUG| vm_monitor_exit_status = no >2019-10-18 13:12:16,975 test L0329 DEBUG| vm_register_delay = 5 >2019-10-18 13:12:16,975 test L0329 DEBUG| vm_type = qemu >2019-10-18 13:12:16,975 test L0329 DEBUG| vms = avocado-vt-vm1 >2019-10-18 13:12:16,975 test L0329 DEBUG| vnc_autoport = yes >2019-10-18 13:12:16,975 test L0329 DEBUG| wait_secs_for_hook_up = 3 >2019-10-18 13:12:16,984 test L0382 DEBUG| Searching for test modules that match 'type = nic_hotplug' and 'provider = io-github-autotest-qemu' on this cartesian dict >2019-10-18 13:12:16,985 test L0396 DEBUG| Found subtest module /var/lib/avocado/data/avocado-vt/test-providers.d/downloads/io-github-autotest-qemu/qemu/tests/nic_hotplug.py >2019-10-18 13:12:16,991 utils_env L0082 WARNI| Creating new, empty env file >2019-10-18 13:12:16,997 process L0605 INFO | Running 'grep revision /proc/cpuinfo | awk '{print $3}' | head -n 1' >2019-10-18 13:12:17,001 process L0437 DEBUG| [stdout] 2.1 >2019-10-18 13:12:17,001 process L0687 INFO | Command 'grep revision /proc/cpuinfo | awk '{print $3}' | head -n 1' finished with 0 after 0.002657651901245117s >2019-10-18 13:12:17,019 process L0605 INFO | Running 'ppc64_cpu --smt' >2019-10-18 13:12:17,051 process L0437 DEBUG| [stdout] SMT is off >2019-10-18 13:12:17,051 process L0687 INFO | Command 'ppc64_cpu --smt' finished with 0 after 0.030210494995117188s >2019-10-18 13:12:18,163 env_process L0974 DEBUG| KVM version: 4.18.0-141.el8.ppc64le >2019-10-18 13:12:18,179 env_process L1009 DEBUG| KVM userspace version(qemu): 2.12.0 (qemu-kvm-2.12.0-88.module+el8.1.0+4233+bc44be3f) >2019-10-18 13:12:18,180 process L0605 INFO | Running 'true' >2019-10-18 13:12:18,182 process L0687 INFO | Command 'true' finished with 0 after 0.0006029605865478516s >2019-10-18 13:12:18,182 process L0605 INFO | Running 'ps -o comm 1' >2019-10-18 13:12:18,239 process L0437 DEBUG| [stdout] COMMAND >2019-10-18 13:12:18,239 process L0687 INFO | Command 'ps -o comm 1' finished with 0 after 0.05402779579162598s >2019-10-18 13:12:18,239 process L0437 DEBUG| [stdout] systemd >2019-10-18 13:12:18,266 storage L0431 INFO | Checking disk size on /var/lib/avocado/data/avocado-vt/images. >2019-10-18 13:12:18,266 storage L0439 DEBUG| Image backup /var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2.backup already exists, skipping... >2019-10-18 13:12:18,312 process L0605 INFO | Running '/usr/libexec/qemu-kvm -version' >2019-10-18 13:12:18,326 process L0437 DEBUG| [stdout] QEMU emulator version 2.12.0 (qemu-kvm-2.12.0-88.module+el8.1.0+4233+bc44be3f) >2019-10-18 13:12:18,326 process L0437 DEBUG| [stdout] Copyright (c) 2003-2017 Fabrice Bellard and the QEMU Project developers >2019-10-18 13:12:18,327 process L0687 INFO | Command '/usr/libexec/qemu-kvm -version' finished with 0 after 0.013339042663574219s >2019-10-18 13:12:18,605 utils_misc L2059 DEBUG| Detected CPU vendor as 'unknown' >2019-10-18 13:12:18,622 qemu_vm L2209 DEBUG| qemu will run in KVM mode >2019-10-18 13:12:18,626 qemu_vm L2758 DEBUG| Devices of avocado-vt-vm1: [t'PREFIX',t'qemu',t'-S',t'vmname',t'machine',t'i440FX',t'PIIX4_PM',t'PIIX3',t'piix3-ide',t'fdc',t'nodefaults',a'VGA',t'QMP-qmpmonitor1',t'QMP-catch_monitor',chardev_serial0,serial0,t'isa-log',usb1,virtio_scsi_pci0,file_image1,drive_image1,image1,t'mem',t'smp',usb-tablet1,t'tcp-redir',t'display',t'rtc',t'bootmenu',t'extra',t'kvm'] >2019-10-18 13:12:18,626 qemu_vm L2759 DEBUG| Buses of avocado-vt-vm1 > drive_image1(QDrive): {drive:image1} > virtio_scsi_pci0.0(virtio-scsi-pci): {0-0:image1} > usb1.0(xhci): {1:usb-tablet1} > floppy(floppy): [None,None] > ide(ide): [None,None,None,None] > _PCI_CHASSIS_NR(None): {} > _PCI_CHASSIS(None): {} > pci.0(PCI): {0x0-0x0:t'i440FX',0x1-0x0:t'PIIX3',0x1-0x1:t'piix3-ide',0x1-0x3:t'PIIX4_PM',0x2-0x0:a'VGA',0x3-0x0:usb1,0x4-0x0:virtio_scsi_pci0} >2019-10-18 13:12:18,626 qemu_vm L2823 INFO | Running qemu command (reformatted): >MALLOC_PERTURB_=1 /usr/libexec/qemu-kvm \ > -S \ > -name 'avocado-vt-vm1' \ > -machine pseries \ > -nodefaults \ > -device VGA,bus=pci.0,addr=0x2 \ > -chardev socket,id=qmp_id_qmpmonitor1,path=/var/tmp/avocado_zngdvo2i/monitor-qmpmonitor1-20191018-131218-feCcHlGN,server,nowait \ > -mon chardev=qmp_id_qmpmonitor1,mode=control \ > -chardev socket,id=qmp_id_catch_monitor,path=/var/tmp/avocado_zngdvo2i/monitor-catch_monitor-20191018-131218-feCcHlGN,server,nowait \ > -mon chardev=qmp_id_catch_monitor,mode=control \ > -chardev socket,nowait,server,id=chardev_serial0,path=/var/tmp/avocado_zngdvo2i/serial-serial0-20191018-131218-feCcHlGN \ > -device spapr-vty,id=serial0,reg=0x30000000,chardev=chardev_serial0 \ > -device nec-usb-xhci,id=usb1,bus=pci.0,addr=0x3 \ > -device virtio-scsi-pci,id=virtio_scsi_pci0,bus=pci.0,addr=0x4 \ > -blockdev node-name=file_image1,driver=file,filename=/var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2 \ > -blockdev node-name=drive_image1,driver=qcow2,file=file_image1 \ > -device scsi-hd,id=image1,drive=drive_image1 \ > -m 1024 \ > -smp 2,maxcpus=2,cores=1,threads=1,sockets=2 \ > -device usb-tablet,id=usb-tablet1,bus=usb1.0,port=1 \ > -vnc :0 \ > -rtc base=utc,clock=host \ > -boot order=cdn,once=c,menu=off,strict=off \ > -net none \ > -enable-kvm >2019-10-18 13:12:19,705 qemu_vm L2835 INFO | Created qemu process with parent PID 52472 >2019-10-18 13:12:20,177 qemu_monitor L0153 INFO | Connecting to monitor '<<class 'virttest.qemu_monitor.QMPMonitor'>> qmpmonitor1' >2019-10-18 13:12:20,327 qemu_monitor L0410 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'qmp_capabilities' >2019-10-18 13:12:20,328 qemu_monitor L1920 DEBUG| Send command: {'execute': 'qmp_capabilities', 'id': 'JctKKhPz'} >2019-10-18 13:12:20,353 qemu_monitor L0153 INFO | Connecting to monitor '<<class 'virttest.qemu_monitor.QMPMonitor'>> catch_monitor' >2019-10-18 13:12:20,504 qemu_monitor L0410 DEBUG| (monitor avocado-vt-vm1.catch_monitor) Sending command 'qmp_capabilities' >2019-10-18 13:12:20,504 qemu_monitor L1920 DEBUG| Send command: {'execute': 'qmp_capabilities', 'id': '3okLJlEg'} >2019-10-18 13:12:20,561 qemu_vm L2917 DEBUG| VM appears to be alive with PID 52474 >2019-10-18 13:12:20,561 qemu_monitor L0410 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'query-cpus-fast' >2019-10-18 13:12:20,562 qemu_monitor L1920 DEBUG| Send command: {'execute': 'query-cpus-fast', 'id': 'gepEruZz'} >2019-10-18 13:12:20,563 qemu_monitor L1876 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Response to 'query-cpus-fast' (re-formated) >2019-10-18 13:12:20,563 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) arch: x86 >2019-10-18 13:12:20,563 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) thread-id: 52481 >2019-10-18 13:12:20,563 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) props: >2019-10-18 13:12:20,563 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) core-id: 0 >2019-10-18 13:12:20,563 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) qom-path: /machine/unattached/device[0]/thread[0] >2019-10-18 13:12:20,563 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) cpu-index: 0 >2019-10-18 13:12:20,563 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) arch: x86 >2019-10-18 13:12:20,564 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) thread-id: 52482 >2019-10-18 13:12:20,564 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) props: >2019-10-18 13:12:20,564 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) core-id: 1 >2019-10-18 13:12:20,564 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) qom-path: /machine/unattached/device[1]/thread[0] >2019-10-18 13:12:20,564 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) cpu-index: 1 >2019-10-18 13:12:21,832 qemu_monitor L0410 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'cont' >2019-10-18 13:12:21,832 qemu_monitor L1920 DEBUG| Send command: {'execute': 'cont', 'id': 'Xukm4icf'} >2019-10-18 13:12:21,846 utils_net L3406 WARNI| No IP address of host was provided, using IP address on virbr0 interface >2019-10-18 13:12:21,847 virt_vm L1352 DEBUG| Attempting to log into 'avocado-vt-vm1' via serial console (timeout 360s) >2019-10-18 13:13:12,377 nic_hotplug L0168 INFO | Disable other link(s) of guest >2019-10-18 13:13:12,377 nic_hotplug L0179 DEBUG| Hotplug 1th 'virtio-net-pci' nic named 'hotplug_nic1' >2019-10-18 13:13:12,378 virt_vm L0920 DEBUG| Generating random mac address for nic >2019-10-18 13:13:12,435 error_context L0079 DEBUG| Context: (hotplug_nic) --> Opening tap device node for t0-gPrF8P >2019-10-18 13:13:12,496 error_context L0079 INFO | Context: (hotplug_nic) --> Assigning tap idYJueDT to qemu by fd >2019-10-18 13:13:12,497 qemu_monitor L0410 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'getfd' >2019-10-18 13:13:12,498 qemu_monitor L1920 DEBUG| Send command: {'execute': 'getfd', 'arguments': {'fdname': 'idYJueDT'}, 'id': '6LpmzHcR'} >2019-10-18 13:13:12,652 error_context L0079 DEBUG| Context: (hotplug_nic) --> Raising interface for nic {'netdev_extra_params': ',vhost=on', 'nic_name': 'hotplug_nic1', 'nic_model': 'virtio-net-pci', 'nettype': 'bridge', 'netdst': 'virbr0', 'mac': '9a:2e:0b:20:95:0c', 'vlan': '0', 'device_id': 'id1hXOy1', 'queues': '1', 'netdev_id': 'idF7dzRm', 'ifname': 't0-gPrF8P', 'tapfd_ids': ['idYJueDT'], 'vectors': 4} on vm avocado-vt-vm1 with attach_cmd netdev_add type=tap,id=id1hXOy1,fd=33 >2019-10-18 13:13:12,660 error_context L0079 DEBUG| Context: (hotplug_nic) --> Raising bridge for nic {'netdev_extra_params': ',vhost=on', 'nic_name': 'hotplug_nic1', 'nic_model': 'virtio-net-pci', 'nettype': 'bridge', 'netdst': 'virbr0', 'mac': '9a:2e:0b:20:95:0c', 'vlan': '0', 'device_id': 'id1hXOy1', 'queues': '1', 'netdev_id': 'idF7dzRm', 'ifname': 't0-gPrF8P', 'tapfd_ids': ['idYJueDT'], 'vectors': 4} on vm avocado-vt-vm1 with attach_cmd netdev_add type=tap,id=id1hXOy1,fd=33 >2019-10-18 13:13:12,660 utils_net L1184 DEBUG| Host does not support OpenVSwitch: Command 'ovs-vswitchd' could not be found in any of the PATH dirs: ['/usr/local/bin', '/usr/bin', '/usr/sbin', '/root/bin', '/root/venv/bin', '/usr/local/sbin', '/bin', '/sbin', '/usr/libexec'] >2019-10-18 13:13:12,663 error_context L0079 DEBUG| Context: (hotplug_nic) --> Hotplugging nic {'netdev_extra_params': ',vhost=on', 'nic_name': 'hotplug_nic1', 'nic_model': 'virtio-net-pci', 'nettype': 'bridge', 'netdst': 'virbr0', 'mac': '9a:2e:0b:20:95:0c', 'vlan': '0', 'device_id': 'id1hXOy1', 'queues': '1', 'netdev_id': 'idF7dzRm', 'ifname': 't0-gPrF8P', 'tapfd_ids': ['idYJueDT'], 'vectors': 4} on vm avocado-vt-vm1 with attach_cmd netdev_add type=tap,id=id1hXOy1,fd=33,vhost=on >2019-10-18 13:13:12,664 qemu_monitor L0410 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'netdev_add' >2019-10-18 13:13:12,665 qemu_monitor L1920 DEBUG| Send command: {'execute': 'netdev_add', 'arguments': {'type': 'tap', 'id': 'id1hXOy1', 'fd': 33, 'vhost': 'on'}, 'id': '4y7q61Gf'} >2019-10-18 13:13:12,689 qemu_monitor L0410 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'info network' (via Human Monitor) >2019-10-18 13:13:12,691 qemu_monitor L1876 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Response to 'info network' (re-formated) >2019-10-18 13:13:12,692 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) id1hXOy1: index=0,type=tap,fd=33 >2019-10-18 13:13:12,692 qemu_monitor L0410 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'device_add' >2019-10-18 13:13:12,692 qemu_monitor L1920 DEBUG| Send command: {'execute': 'device_add', 'arguments': {'driver': 'virtio-net-pci', 'netdev': 'id1hXOy1', 'mac': '9a:2e:0b:20:95:0c', 'id': 'hotplug_nic1', 'vectors': 4}, 'id': 'kxorZOVp'} >2019-10-18 13:13:12,702 qemu_monitor L0410 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'info qtree' (via Human Monitor) >2019-10-18 13:13:12,705 qemu_monitor L1876 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Response to 'info qtree' (re-formated) >2019-10-18 13:13:12,705 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: main-system-bus >2019-10-18 13:13:12,706 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type System >2019-10-18 13:13:12,706 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: spapr-pci-host-bridge, id "" >2019-10-18 13:13:12,706 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) index = 0 (0x0) >2019-10-18 13:13:12,706 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mem_win_size = 2147483648 (0x80000000) >2019-10-18 13:13:12,706 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mem64_win_size = 1099511627776 (0x10000000000) >2019-10-18 13:13:12,706 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) io_win_size = 65536 (0x10000) >2019-10-18 13:13:12,706 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dynamic-reconfiguration = true >2019-10-18 13:13:12,706 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dma_win_addr = 0 (0x0) >2019-10-18 13:13:12,707 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dma_win_size = 1073741824 (0x40000000) >2019-10-18 13:13:12,707 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dma64_win_addr = 576460752303423488 (0x800000000000000) >2019-10-18 13:13:12,707 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ddw = true >2019-10-18 13:13:12,707 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) pgsz = 69632 (0x11000) >2019-10-18 13:13:12,707 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) numa_node = 4294967295 (0xffffffff) >2019-10-18 13:13:12,707 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) pre-2.8-migration = false >2019-10-18 13:13:12,707 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) pcie-extended-configuration-space = true >2019-10-18 13:13:12,707 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) gpa = 70368744177664 (0x400000000000) >2019-10-18 13:13:12,708 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) atsd = 140737488355328 (0x800000000000) >2019-10-18 13:13:12,708 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: pci.0 >2019-10-18 13:13:12,708 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type PCI >2019-10-18 13:13:12,708 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: virtio-net-pci, id "hotplug_nic1" >2019-10-18 13:13:12,708 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ioeventfd = true >2019-10-18 13:13:12,708 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) vectors = 4 (0x4) >2019-10-18 13:13:12,708 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) virtio-pci-bus-master-bug-migration = false >2019-10-18 13:13:12,708 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) disable-legacy = "off" >2019-10-18 13:13:12,708 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) disable-modern = false >2019-10-18 13:13:12,709 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) migrate-extra = true >2019-10-18 13:13:12,709 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) modern-pio-notify = false >2019-10-18 13:13:12,709 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-disable-pcie = false >2019-10-18 13:13:12,709 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) page-per-vq = false >2019-10-18 13:13:12,709 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-ignore-backend-features = false >2019-10-18 13:13:12,709 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ats = false >2019-10-18 13:13:12,709 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-deverr-init = true >2019-10-18 13:13:12,709 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnkctl-init = true >2019-10-18 13:13:12,710 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-pm-init = true >2019-10-18 13:13:12,710 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr = 00.0 >2019-10-18 13:13:12,710 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) romfile = "efi-virtio.rom" >2019-10-18 13:13:12,710 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rombar = 1 (0x1) >2019-10-18 13:13:12,710 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) multifunction = false >2019-10-18 13:13:12,710 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) command_serr_enable = true >2019-10-18 13:13:12,710 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnksta-dllla = true >2019-10-18 13:13:12,710 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-extcap-init = true >2019-10-18 13:13:12,710 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) class Ethernet controller, addr 00:00.0, pci id 1af4:1000 (sub 1af4:0001) >2019-10-18 13:13:12,711 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 0: i/o at 0xffffffffffffffff [0x1e] >2019-10-18 13:13:12,711 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 1: mem at 0xffffffffffffffff [0xffe] >2019-10-18 13:13:12,711 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 4: mem at 0xffffffffffffffff [0x3ffe] >2019-10-18 13:13:12,711 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 6: mem at 0xffffffffffffffff [0x3fffe] >2019-10-18 13:13:12,711 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: virtio-bus >2019-10-18 13:13:12,711 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type virtio-pci-bus >2019-10-18 13:13:12,711 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: virtio-net-device, id "" >2019-10-18 13:13:12,711 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) csum = true >2019-10-18 13:13:12,712 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) guest_csum = true >2019-10-18 13:13:12,712 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) gso = true >2019-10-18 13:13:12,712 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) guest_tso4 = true >2019-10-18 13:13:12,712 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) guest_tso6 = true >2019-10-18 13:13:12,712 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) guest_ecn = true >2019-10-18 13:13:12,712 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) guest_ufo = true >2019-10-18 13:13:12,712 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) guest_announce = true >2019-10-18 13:13:12,712 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) host_tso4 = true >2019-10-18 13:13:12,713 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) host_tso6 = true >2019-10-18 13:13:12,713 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) host_ecn = true >2019-10-18 13:13:12,713 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) host_ufo = true >2019-10-18 13:13:12,713 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mrg_rxbuf = true >2019-10-18 13:13:12,713 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) status = true >2019-10-18 13:13:12,713 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ctrl_vq = true >2019-10-18 13:13:12,713 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ctrl_rx = true >2019-10-18 13:13:12,713 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ctrl_vlan = true >2019-10-18 13:13:12,713 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ctrl_rx_extra = true >2019-10-18 13:13:12,714 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ctrl_mac_addr = true >2019-10-18 13:13:12,714 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ctrl_guest_offloads = true >2019-10-18 13:13:12,714 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mq = false >2019-10-18 13:13:12,714 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mac = "9a:2e:0b:20:95:0c" >2019-10-18 13:13:12,714 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) vlan = <null> >2019-10-18 13:13:12,714 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) netdev = "id1hXOy1" >2019-10-18 13:13:12,714 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-txtimer = 150000 (0x249f0) >2019-10-18 13:13:12,714 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-txburst = 256 (0x100) >2019-10-18 13:13:12,715 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) tx = "" >2019-10-18 13:13:12,715 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rx_queue_size = 256 (0x100) >2019-10-18 13:13:12,715 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) tx_queue_size = 256 (0x100) >2019-10-18 13:13:12,715 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) host_mtu = 0 (0x0) >2019-10-18 13:13:12,715 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-mtu-bypass-backend = true >2019-10-18 13:13:12,715 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) speed = -1 (0xffffffffffffffff) >2019-10-18 13:13:12,715 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) duplex = "" >2019-10-18 13:13:12,715 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) indirect_desc = true >2019-10-18 13:13:12,716 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) event_idx = true >2019-10-18 13:13:12,716 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) notify_on_empty = true >2019-10-18 13:13:12,716 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) any_layout = true >2019-10-18 13:13:12,716 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) iommu_platform = false >2019-10-18 13:13:12,716 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: virtio-scsi-pci, id "virtio_scsi_pci0" >2019-10-18 13:13:12,716 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ioeventfd = true >2019-10-18 13:13:12,716 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) vectors = 4 (0x4) >2019-10-18 13:13:12,716 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) virtio-pci-bus-master-bug-migration = false >2019-10-18 13:13:12,716 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) disable-legacy = "off" >2019-10-18 13:13:12,717 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) disable-modern = false >2019-10-18 13:13:12,717 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) migrate-extra = true >2019-10-18 13:13:12,717 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) modern-pio-notify = false >2019-10-18 13:13:12,717 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-disable-pcie = false >2019-10-18 13:13:12,717 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) page-per-vq = false >2019-10-18 13:13:12,717 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-ignore-backend-features = false >2019-10-18 13:13:12,717 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ats = false >2019-10-18 13:13:12,717 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-deverr-init = true >2019-10-18 13:13:12,718 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnkctl-init = true >2019-10-18 13:13:12,718 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-pm-init = true >2019-10-18 13:13:12,718 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr = 04.0 >2019-10-18 13:13:12,718 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) romfile = "" >2019-10-18 13:13:12,718 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rombar = 1 (0x1) >2019-10-18 13:13:12,718 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) multifunction = false >2019-10-18 13:13:12,718 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) command_serr_enable = true >2019-10-18 13:13:12,718 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnksta-dllla = true >2019-10-18 13:13:12,718 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-extcap-init = true >2019-10-18 13:13:12,719 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) class SCSI controller, addr 00:04.0, pci id 1af4:1004 (sub 1af4:0008) >2019-10-18 13:13:12,719 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 0: i/o at 0x40 [0x7f] >2019-10-18 13:13:12,719 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 1: mem at 0x81030000 [0x81030fff] >2019-10-18 13:13:12,719 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 4: mem at 0x210000000000 [0x210000003fff] >2019-10-18 13:13:12,719 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: virtio-bus >2019-10-18 13:13:12,719 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type virtio-pci-bus >2019-10-18 13:13:12,719 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: virtio-scsi-device, id "" >2019-10-18 13:13:12,719 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) num_queues = 1 (0x1) >2019-10-18 13:13:12,720 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) virtqueue_size = 128 (0x80) >2019-10-18 13:13:12,720 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) max_sectors = 65535 (0xffff) >2019-10-18 13:13:12,720 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) cmd_per_lun = 128 (0x80) >2019-10-18 13:13:12,720 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) hotplug = true >2019-10-18 13:13:12,720 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) param_change = true >2019-10-18 13:13:12,720 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) iothread = "" >2019-10-18 13:13:12,720 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) indirect_desc = true >2019-10-18 13:13:12,720 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) event_idx = true >2019-10-18 13:13:12,721 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) notify_on_empty = true >2019-10-18 13:13:12,721 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) any_layout = true >2019-10-18 13:13:12,721 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) iommu_platform = false >2019-10-18 13:13:12,721 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: virtio_scsi_pci0.0 >2019-10-18 13:13:12,721 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type SCSI >2019-10-18 13:13:12,721 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: scsi-hd, id "image1" >2019-10-18 13:13:12,721 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) drive = "drive_image1" >2019-10-18 13:13:12,721 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) logical_block_size = 512 (0x200) >2019-10-18 13:13:12,721 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) physical_block_size = 512 (0x200) >2019-10-18 13:13:12,722 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) min_io_size = 0 (0x0) >2019-10-18 13:13:12,722 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) opt_io_size = 0 (0x0) >2019-10-18 13:13:12,722 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) discard_granularity = 4096 (0x1000) >2019-10-18 13:13:12,722 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) write-cache = "auto" >2019-10-18 13:13:12,722 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) share-rw = false >2019-10-18 13:13:12,722 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rerror = "auto" >2019-10-18 13:13:12,722 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) werror = "auto" >2019-10-18 13:13:12,722 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ver = "2.5+" >2019-10-18 13:13:12,723 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) serial = "" >2019-10-18 13:13:12,723 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) vendor = "QEMU" >2019-10-18 13:13:12,723 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) product = "QEMU HARDDISK" >2019-10-18 13:13:12,723 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) removable = false >2019-10-18 13:13:12,723 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dpofua = false >2019-10-18 13:13:12,723 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) wwn = 0 (0x0) >2019-10-18 13:13:12,723 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) port_wwn = 0 (0x0) >2019-10-18 13:13:12,723 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) port_index = 0 (0x0) >2019-10-18 13:13:12,724 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) max_unmap_size = 1073741824 (0x40000000) >2019-10-18 13:13:12,724 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) max_io_size = 2147483647 (0x7fffffff) >2019-10-18 13:13:12,724 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rotation_rate = 0 (0x0) >2019-10-18 13:13:12,724 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) scsi_version = 5 (0x5) >2019-10-18 13:13:12,724 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) cyls = 16383 (0x3fff) >2019-10-18 13:13:12,724 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) heads = 16 (0x10) >2019-10-18 13:13:12,724 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) secs = 63 (0x3f) >2019-10-18 13:13:12,724 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) channel = 0 (0x0) >2019-10-18 13:13:12,724 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) scsi-id = 0 (0x0) >2019-10-18 13:13:12,725 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) lun = 0 (0x0) >2019-10-18 13:13:12,725 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: nec-usb-xhci, id "usb1" >2019-10-18 13:13:12,725 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) msi = "auto" >2019-10-18 13:13:12,725 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) msix = "auto" >2019-10-18 13:13:12,725 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) superspeed-ports-first = true >2019-10-18 13:13:12,725 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) force-pcie-endcap = false >2019-10-18 13:13:12,725 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) intrs = 16 (0x10) >2019-10-18 13:13:12,725 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) slots = 64 (0x40) >2019-10-18 13:13:12,726 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) streams = true >2019-10-18 13:13:12,726 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) p2 = 4 (0x4) >2019-10-18 13:13:12,726 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) p3 = 4 (0x4) >2019-10-18 13:13:12,726 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr = 03.0 >2019-10-18 13:13:12,726 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) romfile = "" >2019-10-18 13:13:12,726 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rombar = 1 (0x1) >2019-10-18 13:13:12,726 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) multifunction = false >2019-10-18 13:13:12,726 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) command_serr_enable = true >2019-10-18 13:13:12,727 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnksta-dllla = true >2019-10-18 13:13:12,727 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-extcap-init = true >2019-10-18 13:13:12,727 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) class USB controller, addr 00:03.0, pci id 1033:0194 (sub 1af4:1100) >2019-10-18 13:13:12,727 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 0: mem at 0x81020000 [0x81023fff] >2019-10-18 13:13:12,727 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: usb1.0 >2019-10-18 13:13:12,727 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type usb-bus >2019-10-18 13:13:12,727 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: usb-tablet, id "usb-tablet1" >2019-10-18 13:13:12,727 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) usb_version = 2 (0x2) >2019-10-18 13:13:12,728 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) display = "" >2019-10-18 13:13:12,728 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) head = 0 (0x0) >2019-10-18 13:13:12,728 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) port = "1" >2019-10-18 13:13:12,728 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) serial = "" >2019-10-18 13:13:12,728 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) full-path = true >2019-10-18 13:13:12,728 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) msos-desc = true >2019-10-18 13:13:12,728 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr 0.1, port 1, speed 480, name QEMU USB Tablet, attached >2019-10-18 13:13:12,728 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: VGA, id "" >2019-10-18 13:13:12,729 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) vgamem_mb = 16 (0x10) >2019-10-18 13:13:12,729 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mmio = true >2019-10-18 13:13:12,729 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) qemu-extended-regs = true >2019-10-18 13:13:12,729 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr = 02.0 >2019-10-18 13:13:12,729 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) romfile = "vgabios-stdvga.bin" >2019-10-18 13:13:12,729 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rombar = 1 (0x1) >2019-10-18 13:13:12,729 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) multifunction = false >2019-10-18 13:13:12,729 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) command_serr_enable = true >2019-10-18 13:13:12,729 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnksta-dllla = true >2019-10-18 13:13:12,730 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-extcap-init = true >2019-10-18 13:13:12,730 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) class VGA controller, addr 00:02.0, pci id 1234:1111 (sub 1af4:1100) >2019-10-18 13:13:12,730 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 0: mem at 0x80000000 [0x80ffffff] >2019-10-18 13:13:12,730 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 2: mem at 0x81000000 [0x81000fff] >2019-10-18 13:13:12,730 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 6: mem at 0xffffffffffffffff [0xfffe] >2019-10-18 13:13:12,730 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: spapr-vio-bridge, id "" >2019-10-18 13:13:12,730 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: spapr-vio >2019-10-18 13:13:12,730 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type spapr-vio-bus >2019-10-18 13:13:12,731 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: spapr-vty, id "serial0" >2019-10-18 13:13:12,731 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) reg = 805306368 (0x30000000) >2019-10-18 13:13:12,731 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) chardev = "chardev_serial0" >2019-10-18 13:13:12,731 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) irq = 4103 (0x1007) >2019-10-18 13:13:12,731 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: spapr-nvram, id "nvram@71000000" >2019-10-18 13:13:12,731 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) reg = 1895825408 (0x71000000) >2019-10-18 13:13:12,731 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) drive = "" >2019-10-18 13:13:12,731 qemu_monitor L1852 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) irq = 4098 (0x1002) >2019-10-18 13:13:12,732 nic_hotplug L0181 INFO | Check if new interface gets ip address >2019-10-18 13:13:20,581 ip_sniffing L0053 DEBUG| Updated HWADDR (9a:2e:0b:20:95:0c)<->(192.168.122.76) IP pair into address cache >2019-10-18 13:13:20,743 utils_misc L0588 DEBUG| Retry verifying IP address (0.000007 secs) >2019-10-18 13:13:20,746 virt_vm L0898 DEBUG| Found/Verified IP 192.168.122.76 for VM avocado-vt-vm1 NIC 0 >2019-10-18 13:13:20,747 nic_hotplug L0189 INFO | Got the ip address of new nic: 192.168.122.76 >2019-10-18 13:13:20,747 nic_hotplug L0191 INFO | Ping guest's new ip from host >2019-10-18 13:13:20,747 utils_net L0830 INFO | The command of Ping is: ping 192.168.122.1 -c 10 >2019-10-18 13:13:20,891 client L0605 DEBUG| PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data. >2019-10-18 13:13:20,892 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=1 ttl=64 time=0.056 ms >2019-10-18 13:13:21,915 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=2 ttl=64 time=0.015 ms >2019-10-18 13:13:22,965 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=3 ttl=64 time=0.070 ms >2019-10-18 13:13:23,995 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=4 ttl=64 time=0.014 ms >2019-10-18 13:13:25,035 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=5 ttl=64 time=0.009 ms >2019-10-18 13:13:26,075 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=6 ttl=64 time=0.008 ms >2019-10-18 13:13:27,125 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=7 ttl=64 time=0.009 ms >2019-10-18 13:13:28,155 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=8 ttl=64 time=0.008 ms >2019-10-18 13:13:29,205 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=9 ttl=64 time=0.009 ms >2019-10-18 13:13:30,235 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=10 ttl=64 time=0.008 ms >2019-10-18 13:13:30,235 client L0605 DEBUG| >2019-10-18 13:13:30,235 client L0605 DEBUG| --- 192.168.122.1 ping statistics --- >2019-10-18 13:13:30,235 client L0605 DEBUG| 10 packets transmitted, 10 received, 0% packet loss, time 353ms >2019-10-18 13:13:30,235 client L0605 DEBUG| rtt min/avg/max/mdev = 0.008/0.020/0.070/0.022 ms >2019-10-18 13:13:30,237 client L0605 DEBUG| (Process terminated with status 0) >2019-10-18 13:13:30,238 nic_hotplug L0198 INFO | Reboot vm after hotplug nic >2019-10-18 13:13:30,238 error_context L0097 INFO | Context: rebooting 'avocado-vt-vm1' >2019-10-18 13:13:30,238 qemu_vm L4205 DEBUG| Send command: shutdown -r now >2019-10-18 13:13:30,239 client L1126 DEBUG| Sending command: shutdown -r now >2019-10-18 13:14:30,242 error_context L0079 INFO | Context: rebooting 'avocado-vt-vm1' --> waiting for guest to go down >2019-10-18 13:14:30,243 error_context L0079 INFO | Context: rebooting 'avocado-vt-vm1' --> logging in after reboot >2019-10-18 13:14:30,243 virt_vm L1352 DEBUG| Attempting to log into 'avocado-vt-vm1' via serial console (timeout 180s) >2019-10-18 13:14:43,115 utils_misc L0588 DEBUG| Retry verifying IP address (0.000006 secs) >2019-10-18 13:15:45,686 ip_sniffing L0068 DEBUG| Dropped the address cache of HWADDR (9a:2e:0b:20:95:0c) >2019-10-18 13:16:13,222 virt_vm L1352 DEBUG| Attempting to log into 'avocado-vt-vm1' via serial console (timeout 90s) >2019-10-18 13:16:24,228 client L1126 DEBUG| Sending command: echo %OS% >2019-10-18 13:16:24,329 client L1162 DEBUG| Sending command (safe): ifconfig -a >2019-10-18 13:16:24,438 client L1162 DEBUG| Sending command (safe): ip link | grep -B1 '' -i >2019-10-18 13:16:24,544 client L1126 DEBUG| Sending command: test -d /sys/class/net/enp0s0 >2019-10-18 13:16:24,645 client L1126 DEBUG| Sending command: echo $? >2019-10-18 13:16:24,752 client L1126 DEBUG| Sending command: cat /sys/class/net/enp0s0/address >2019-10-18 13:16:24,857 client L1162 DEBUG| Sending command (safe): ifconfig enp0s0 || ip address show enp0s0 >2019-10-18 13:16:24,961 utils_net L3621 WARNI| No VM's NIC got IP address >2019-10-18 13:16:24,962 client L1162 DEBUG| Sending command (safe): ifconfig -a >2019-10-18 13:16:25,067 client L1162 DEBUG| Sending command (safe): ip link | grep -B1 '9a:2e:0b:20:95:0c' -i >2019-10-18 13:16:25,171 client L1162 DEBUG| Sending command (safe): test -f /etc/sysconfig/network-scripts/ifcfg-enp0s0 || echo 'DEVICE=enp0s0 >BOOTPROTO=dhcp >ONBOOT=yes' > /etc/sysconfig/network-scripts/ifcfg-enp0s0 >2019-10-18 13:16:25,273 client L1162 DEBUG| Sending command (safe): ifconfig enp0s0 up >2019-10-18 13:16:25,376 client L1162 DEBUG| Sending command (safe): dhclient -r >2019-10-18 13:16:25,734 client L1162 DEBUG| Sending command (safe): dhclient enp0s0 >2019-10-18 13:17:26,807 client L1162 DEBUG| Sending command (safe): arp -n|awk '/^[1-9]/{print "arp -d " $1}'|sh >2019-10-18 13:18:58,021 virt_vm L1352 DEBUG| Attempting to log into 'avocado-vt-vm1' via serial console (timeout 90s) >2019-10-18 13:19:09,027 client L1126 DEBUG| Sending command: echo %OS% >2019-10-18 13:19:09,131 client L1162 DEBUG| Sending command (safe): ifconfig -a >2019-10-18 13:19:09,239 client L1162 DEBUG| Sending command (safe): ip link | grep -B1 '' -i >2019-10-18 13:19:09,345 client L1126 DEBUG| Sending command: test -d /sys/class/net/enp0s0 >2019-10-18 13:19:09,446 client L1126 DEBUG| Sending command: echo $? >2019-10-18 13:19:09,547 client L1126 DEBUG| Sending command: cat /sys/class/net/enp0s0/address >2019-10-18 13:19:09,650 client L1162 DEBUG| Sending command (safe): ifconfig enp0s0 || ip address show enp0s0 >2019-10-18 13:19:09,755 utils_net L3621 WARNI| No VM's NIC got IP address >2019-10-18 13:19:09,755 client L1162 DEBUG| Sending command (safe): ifconfig -a >2019-10-18 13:19:09,861 client L1162 DEBUG| Sending command (safe): ip link | grep -B1 '9a:2e:0b:20:95:0c' -i >2019-10-18 13:19:09,970 client L1162 DEBUG| Sending command (safe): test -f /etc/sysconfig/network-scripts/ifcfg-enp0s0 || echo 'DEVICE=enp0s0 >BOOTPROTO=dhcp >ONBOOT=yes' > /etc/sysconfig/network-scripts/ifcfg-enp0s0 >2019-10-18 13:19:10,072 client L1162 DEBUG| Sending command (safe): ifconfig enp0s0 up >2019-10-18 13:19:10,175 client L1162 DEBUG| Sending command (safe): dhclient -r >2019-10-18 13:19:11,378 client L1162 DEBUG| Sending command (safe): dhclient enp0s0 >2019-10-18 13:20:12,185 client L1162 DEBUG| Sending command (safe): arp -n|awk '/^[1-9]/{print "arp -d " $1}'|sh >2019-10-18 13:21:43,402 virt_vm L1352 DEBUG| Attempting to log into 'avocado-vt-vm1' via serial console (timeout 90s) >2019-10-18 13:21:54,407 client L1126 DEBUG| Sending command: echo %OS% >2019-10-18 13:21:54,508 client L1162 DEBUG| Sending command (safe): ifconfig -a >2019-10-18 13:21:54,612 client L1162 DEBUG| Sending command (safe): ip link | grep -B1 '' -i >2019-10-18 13:21:54,716 client L1126 DEBUG| Sending command: test -d /sys/class/net/enp0s0 >2019-10-18 13:21:54,816 client L1126 DEBUG| Sending command: echo $? >2019-10-18 13:21:54,917 client L1126 DEBUG| Sending command: cat /sys/class/net/enp0s0/address >2019-10-18 13:21:55,019 client L1162 DEBUG| Sending command (safe): ifconfig enp0s0 || ip address show enp0s0 >2019-10-18 13:21:55,122 utils_net L3621 WARNI| No VM's NIC got IP address >2019-10-18 13:21:55,122 client L1162 DEBUG| Sending command (safe): ifconfig -a >2019-10-18 13:21:55,226 client L1162 DEBUG| Sending command (safe): ip link | grep -B1 '9a:2e:0b:20:95:0c' -i >2019-10-18 13:21:55,329 client L1162 DEBUG| Sending command (safe): test -f /etc/sysconfig/network-scripts/ifcfg-enp0s0 || echo 'DEVICE=enp0s0 >BOOTPROTO=dhcp >ONBOOT=yes' > /etc/sysconfig/network-scripts/ifcfg-enp0s0 >2019-10-18 13:21:55,431 client L1162 DEBUG| Sending command (safe): ifconfig enp0s0 up >2019-10-18 13:21:55,533 client L1162 DEBUG| Sending command (safe): dhclient -r >2019-10-18 13:21:56,721 client L1162 DEBUG| Sending command (safe): dhclient enp0s0 >2019-10-18 13:22:57,805 client L1162 DEBUG| Sending command (safe): arp -n|awk '/^[1-9]/{print "arp -d " $1}'|sh >2019-10-18 13:22:58,913 process L0605 INFO | Running 'arp -aen' >2019-10-18 13:22:58,916 process L0437 DEBUG| [stdout] Address HWtype HWaddress Flags Mask Iface >2019-10-18 13:22:58,917 process L0687 INFO | Command 'arp -aen' finished with 0 after 0.001577138900756836s >2019-10-18 13:22:58,924 process L0437 DEBUG| [stdout] 10.0.1.254 ether e8:b6:c2:10:dc:81 C enP68p1s0f2 >2019-10-18 13:22:58,924 process L0437 DEBUG| [stdout] 192.168.122.186 ether 9a:16:f1:d7:a6:ea C virbr0 >2019-10-18 13:22:58,924 process L0437 DEBUG| [stdout] 192.168.122.76 (incomplete) virbr0 >2019-10-18 13:22:58,944 nic_hotplug L0079 DEBUG| Can't get IP address: >2019-10-18 13:22:58,944 nic_hotplug L0080 DEBUG| Cached IP: None >2019-10-18 13:22:58,944 nic_hotplug L0081 DEBUG| ARP table: Address HWtype HWaddress Flags Mask Iface >10.0.1.254 ether e8:b6:c2:10:dc:81 C enP68p1s0f2 >192.168.122.186 ether 9a:16:f1:d7:a6:ea C virbr0 >192.168.122.76 (incomplete) virbr0 >2019-10-18 13:22:58,944 nic_hotplug L0244 INFO | Re-enabling the primary link(s) >2019-10-18 13:22:58,945 nic_hotplug L0247 INFO | Reboot vm to verify it alive after hotunplug nic(s) >2019-10-18 13:22:58,945 error_context L0097 INFO | Context: rebooting 'avocado-vt-vm1' >2019-10-18 13:22:58,945 virt_vm L1167 DEBUG| Attempting to log into 'avocado-vt-vm1' (timeout 240s) >2019-10-18 13:26:59,235 virt_vm L1352 DEBUG| Attempting to log into 'avocado-vt-vm1' via serial console (timeout 240s) >2019-10-18 13:27:10,247 client L1126 DEBUG| Sending command: echo %OS% >2019-10-18 13:27:10,348 client L1162 DEBUG| Sending command (safe): ifconfig -a >2019-10-18 13:27:10,455 client L1162 DEBUG| Sending command (safe): ip link | grep -B1 '' -i >2019-10-18 13:27:10,560 client L1126 DEBUG| Sending command: test -d /sys/class/net/enp0s0 >2019-10-18 13:27:10,661 client L1126 DEBUG| Sending command: echo $? >2019-10-18 13:27:10,762 client L1126 DEBUG| Sending command: cat /sys/class/net/enp0s0/address >2019-10-18 13:27:10,865 client L1162 DEBUG| Sending command (safe): ifconfig enp0s0 || ip address show enp0s0 >2019-10-18 13:27:10,968 utils_net L3621 WARNI| No VM's NIC got IP address >2019-10-18 13:27:22,047 client L1126 DEBUG| Sending command: ipconfig || ifconfig >2019-10-18 13:27:22,490 client L1126 DEBUG| Sending command: ip route || route print >2019-10-18 13:27:22,594 virt_vm L1157 ERROR| Guest network status: > bash: ipconfig: command not found... >enp0s0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST> mtu 1500 > ether 9a:2e:0b:20:95:0c txqueuelen 1000 (Ethernet) > RX packets 1176 bytes 53652 (52.3 KiB) > RX errors 0 dropped 85 overruns 0 frame 0 > TX packets 0 bytes 0 (0.0 B) > TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 > >lo: flags=73<UP,LOOPBACK,RUNNING> mtu 65536 > inet 127.0.0.1 netmask 255.0.0.0 > inet6 ::1 prefixlen 128 scopeid 0x10<host> > loop txqueuelen 1000 (Local Loopback) > RX packets 8 bytes 480 (480.0 B) > RX errors 0 dropped 0 overruns 0 frame 0 > TX packets 8 bytes 480 (480.0 B) > TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 > > >Guest route table: > >2019-10-18 13:27:22,597 stacktrace L0039 ERROR| >2019-10-18 13:27:22,597 stacktrace L0042 ERROR| Reproduced traceback from: /root/venv/lib/python3.6/site-packages/avocado_vt/test.py:449 >2019-10-18 13:27:22,600 stacktrace L0045 ERROR| Traceback (most recent call last): >2019-10-18 13:27:22,601 stacktrace L0045 ERROR| File "/var/lib/avocado/data/avocado-vt/test-providers.d/downloads/io-github-autotest-qemu/qemu/tests/nic_hotplug.py", line 210, in run >2019-10-18 13:27:22,601 stacktrace L0045 ERROR| "Hotplug nic can't get ip after reboot vm") >2019-10-18 13:27:22,601 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/avocado/core/test.py", line 1043, in fail >2019-10-18 13:27:22,601 stacktrace L0045 ERROR| raise exceptions.TestFail(message) >2019-10-18 13:27:22,601 stacktrace L0045 ERROR| avocado.core.exceptions.TestFail: Hotplug nic can't get ip after reboot vm >2019-10-18 13:27:22,601 stacktrace L0045 ERROR| >2019-10-18 13:27:22,601 stacktrace L0045 ERROR| During handling of the above exception, another exception occurred: >2019-10-18 13:27:22,601 stacktrace L0045 ERROR| >2019-10-18 13:27:22,601 stacktrace L0045 ERROR| Traceback (most recent call last): >2019-10-18 13:27:22,602 stacktrace L0045 ERROR| File "/var/lib/avocado/data/avocado-vt/test-providers.d/downloads/io-github-autotest-qemu/qemu/tests/nic_hotplug.py", line 249, in run >2019-10-18 13:27:22,602 stacktrace L0045 ERROR| session = vm.reboot(serial=serial) >2019-10-18 13:27:22,602 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/error_context.py", line 135, in new_fn >2019-10-18 13:27:22,602 stacktrace L0045 ERROR| return fn(*args, **kwargs) >2019-10-18 13:27:22,602 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/qemu_vm.py", line 4229, in reboot >2019-10-18 13:27:22,602 stacktrace L0045 ERROR| _reboot() >2019-10-18 13:27:22,602 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/qemu_vm.py", line 4201, in _shell_reboot >2019-10-18 13:27:22,602 stacktrace L0045 ERROR| timeout=timeout) >2019-10-18 13:27:22,602 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 1172, in wait_for_login >2019-10-18 13:27:22,603 stacktrace L0045 ERROR| ip_version=self.ip_version) >2019-10-18 13:27:22,603 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/error_context.py", line 135, in new_fn >2019-10-18 13:27:22,603 stacktrace L0045 ERROR| return fn(*args, **kwargs) >2019-10-18 13:27:22,603 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 894, in wait_for_get_address >2019-10-18 13:27:22,603 stacktrace L0045 ERROR| ipaddr = self.get_address(nic_index, ip_version) >2019-10-18 13:27:22,603 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 758, in get_address >2019-10-18 13:27:22,603 stacktrace L0045 ERROR| timeout=timeout) >2019-10-18 13:27:22,603 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 801, in _get_address >2019-10-18 13:27:22,603 stacktrace L0045 ERROR| raise VMIPAddressMissingError(mac, ip_version) >2019-10-18 13:27:22,604 stacktrace L0045 ERROR| virttest.virt_vm.VMIPAddressMissingError: No ipv4 DHCP lease for MAC 9a:2e:0b:20:95:0c >2019-10-18 13:27:22,604 stacktrace L0046 ERROR| >2019-10-18 13:27:22,610 virt_vm L1167 DEBUG| Attempting to log into 'avocado-vt-vm1' (timeout 240s) >2019-10-18 13:31:22,901 virt_vm L1352 DEBUG| Attempting to log into 'avocado-vt-vm1' via serial console (timeout 240s) >2019-10-18 13:31:33,913 client L1126 DEBUG| Sending command: echo %OS% >2019-10-18 13:31:34,014 client L1162 DEBUG| Sending command (safe): ifconfig -a >2019-10-18 13:31:34,120 client L1162 DEBUG| Sending command (safe): ip link | grep -B1 '' -i >2019-10-18 13:31:34,225 client L1126 DEBUG| Sending command: test -d /sys/class/net/enp0s0 >2019-10-18 13:31:34,326 client L1126 DEBUG| Sending command: echo $? >2019-10-18 13:31:34,426 client L1126 DEBUG| Sending command: cat /sys/class/net/enp0s0/address >2019-10-18 13:31:34,529 client L1162 DEBUG| Sending command (safe): ifconfig enp0s0 || ip address show enp0s0 >2019-10-18 13:31:34,632 utils_net L3621 WARNI| No VM's NIC got IP address >2019-10-18 13:31:45,717 client L1126 DEBUG| Sending command: ipconfig || ifconfig >2019-10-18 13:31:46,040 client L1126 DEBUG| Sending command: ip route || route print >2019-10-18 13:31:46,144 virt_vm L1157 ERROR| Guest network status: > bash: ipconfig: command not found... >enp0s0: flags=4163<UP,BROADCAST,RUNNING,MULTICAST> mtu 1500 > inet6 fe80::efcf:bccb:6f21:510b prefixlen 64 scopeid 0x20<link> > ether 9a:2e:0b:20:95:0c txqueuelen 1000 (Ethernet) > RX packets 1375 bytes 63358 (61.8 KiB) > RX errors 0 dropped 85 overruns 0 frame 0 > TX packets 0 bytes 0 (0.0 B) > TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 > >lo: flags=73<UP,LOOPBACK,RUNNING> mtu 65536 > inet 127.0.0.1 netmask 255.0.0.0 > inet6 ::1 prefixlen 128 scopeid 0x10<host> > loop txqueuelen 1000 (Local Loopback) > RX packets 8 bytes 480 (480.0 B) > RX errors 0 dropped 0 overruns 0 frame 0 > TX packets 8 bytes 480 (480.0 B) > TX errors 0 dropped 0 overruns 0 carrier 0 collisions 0 > > >Guest route table: > >2019-10-18 13:31:46,195 qemu_vm L3136 DEBUG| Destroying VM avocado-vt-vm1 (PID 52474) >2019-10-18 13:31:46,196 qemu_vm L3029 DEBUG| Shutting down VM avocado-vt-vm1 (shell) >2019-10-18 13:31:46,196 virt_vm L1352 DEBUG| Attempting to log into 'avocado-vt-vm1' via serial console (timeout 10s) >2019-10-18 13:31:57,207 client L1126 DEBUG| Sending command: echo %OS% >2019-10-18 13:31:57,308 client L1162 DEBUG| Sending command (safe): ifconfig -a >2019-10-18 13:31:57,412 client L1162 DEBUG| Sending command (safe): ip link | grep -B1 '' -i >2019-10-18 13:31:57,516 client L1126 DEBUG| Sending command: test -d /sys/class/net/enp0s0 >2019-10-18 13:31:57,617 client L1126 DEBUG| Sending command: echo $? >2019-10-18 13:31:57,718 client L1126 DEBUG| Sending command: cat /sys/class/net/enp0s0/address >2019-10-18 13:31:57,820 client L1162 DEBUG| Sending command (safe): ifconfig enp0s0 || ip address show enp0s0 >2019-10-18 13:31:57,923 utils_net L3621 WARNI| No VM's NIC got IP address >2019-10-18 13:31:57,924 qemu_vm L3044 DEBUG| No ipv4 DHCP lease for MAC 9a:2e:0b:20:95:0c >2019-10-18 13:31:57,924 qemu_vm L3146 DEBUG| VM avocado-vt-vm1 failed to go down (shell) >2019-10-18 13:31:57,924 qemu_vm L3150 DEBUG| Ending VM avocado-vt-vm1 process (monitor) >2019-10-18 13:31:57,924 qemu_monitor L0410 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'quit' >2019-10-18 13:31:57,924 qemu_monitor L1920 DEBUG| Send command: {'execute': 'quit', 'id': 'FYeZXLMx'} >2019-10-18 13:31:58,098 client L0605 INFO | [qemu output] (Process terminated with status 0) >2019-10-18 13:31:58,426 qemu_vm L3162 DEBUG| VM avocado-vt-vm1 down (monitor) >2019-10-18 13:32:00,587 env_process L1683 WARNI| avocado-vt-vm1 is not alive. Can't query the register status >2019-10-18 13:32:04,202 qemu_vm L3114 WARNI| Deleting t0-gPrF8P failed during tap cleanup >2019-10-18 13:32:04,213 qemu_storage L0508 DEBUG| Checking image file /var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2 >2019-10-18 13:32:04,213 qemu_storage L0404 DEBUG| Run qemu-img info command on /var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2 >2019-10-18 13:32:04,214 process L0605 INFO | Running '/usr/bin/qemu-img info -U /var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2 --output=human' >2019-10-18 13:32:04,221 process L0437 DEBUG| [stdout] image: /var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2 >2019-10-18 13:32:04,221 process L0437 DEBUG| [stdout] file format: qcow2 >2019-10-18 13:32:04,221 process L0687 INFO | Command '/usr/bin/qemu-img info -U /var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2 --output=human' finished with 0 after 0.005513191223144531s >2019-10-18 13:32:04,222 process L0437 DEBUG| [stdout] virtual size: 10G (10737418240 bytes) >2019-10-18 13:32:04,222 process L0437 DEBUG| [stdout] disk size: 6.4G >2019-10-18 13:32:04,222 process L0437 DEBUG| [stdout] cluster_size: 65536 >2019-10-18 13:32:04,222 process L0437 DEBUG| [stdout] Format specific information: >2019-10-18 13:32:04,222 process L0437 DEBUG| [stdout] compat: 1.1 >2019-10-18 13:32:04,223 process L0437 DEBUG| [stdout] lazy refcounts: false >2019-10-18 13:32:04,223 process L0437 DEBUG| [stdout] refcount bits: 16 >2019-10-18 13:32:04,223 process L0437 DEBUG| [stdout] corrupt: false >2019-10-18 13:32:04,268 storage L0500 DEBUG| Copying /var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2.backup -> /var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2 >2019-10-18 13:32:55,270 env_process L1669 DEBUG| Thread quit. Used to failed to get register info from guest 20191018-131218-feCcHlGN for 12 times. >2019-10-18 13:32:55,478 process L0605 INFO | Running 'true' >2019-10-18 13:32:55,480 process L0687 INFO | Command 'true' finished with 0 after 0.0008170604705810547s >2019-10-18 13:32:55,481 process L0605 INFO | Running 'ps -o comm 1' >2019-10-18 13:32:55,530 process L0437 DEBUG| [stdout] COMMAND >2019-10-18 13:32:55,530 process L0687 INFO | Command 'ps -o comm 1' finished with 0 after 0.047297000885009766s >2019-10-18 13:32:55,530 process L0437 DEBUG| [stdout] systemd >2019-10-18 13:32:55,548 process L0605 INFO | Running 'grep revision /proc/cpuinfo | awk '{print $3}' | head -n 1' >2019-10-18 13:32:55,552 process L0437 DEBUG| [stdout] 2.1 >2019-10-18 13:32:55,553 process L0687 INFO | Command 'grep revision /proc/cpuinfo | awk '{print $3}' | head -n 1' finished with 0 after 0.0025577545166015625s >2019-10-18 13:32:55,572 stacktrace L0039 ERROR| >2019-10-18 13:32:55,572 stacktrace L0042 ERROR| Reproduced traceback from: /root/venv/lib/python3.6/site-packages/avocado_vt/test.py:469 >2019-10-18 13:32:55,574 stacktrace L0045 ERROR| Traceback (most recent call last): >2019-10-18 13:32:55,574 stacktrace L0045 ERROR| File "/var/lib/avocado/data/avocado-vt/test-providers.d/downloads/io-github-autotest-qemu/qemu/tests/nic_hotplug.py", line 210, in run >2019-10-18 13:32:55,574 stacktrace L0045 ERROR| "Hotplug nic can't get ip after reboot vm") >2019-10-18 13:32:55,574 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/avocado/core/test.py", line 1043, in fail >2019-10-18 13:32:55,574 stacktrace L0045 ERROR| raise exceptions.TestFail(message) >2019-10-18 13:32:55,575 stacktrace L0045 ERROR| avocado.core.exceptions.TestFail: Hotplug nic can't get ip after reboot vm >2019-10-18 13:32:55,575 stacktrace L0045 ERROR| >2019-10-18 13:32:55,575 stacktrace L0045 ERROR| During handling of the above exception, another exception occurred: >2019-10-18 13:32:55,575 stacktrace L0045 ERROR| >2019-10-18 13:32:55,575 stacktrace L0045 ERROR| Traceback (most recent call last): >2019-10-18 13:32:55,575 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/avocado_vt/test.py", line 438, in _runTest >2019-10-18 13:32:55,575 stacktrace L0045 ERROR| run_func(self, params, env) >2019-10-18 13:32:55,576 stacktrace L0045 ERROR| File "/var/lib/avocado/data/avocado-vt/test-providers.d/downloads/io-github-autotest-qemu/qemu/tests/nic_hotplug.py", line 249, in run >2019-10-18 13:32:55,576 stacktrace L0045 ERROR| session = vm.reboot(serial=serial) >2019-10-18 13:32:55,576 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/error_context.py", line 135, in new_fn >2019-10-18 13:32:55,576 stacktrace L0045 ERROR| return fn(*args, **kwargs) >2019-10-18 13:32:55,576 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/qemu_vm.py", line 4229, in reboot >2019-10-18 13:32:55,576 stacktrace L0045 ERROR| _reboot() >2019-10-18 13:32:55,576 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/qemu_vm.py", line 4201, in _shell_reboot >2019-10-18 13:32:55,576 stacktrace L0045 ERROR| timeout=timeout) >2019-10-18 13:32:55,576 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 1172, in wait_for_login >2019-10-18 13:32:55,577 stacktrace L0045 ERROR| ip_version=self.ip_version) >2019-10-18 13:32:55,577 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/error_context.py", line 135, in new_fn >2019-10-18 13:32:55,577 stacktrace L0045 ERROR| return fn(*args, **kwargs) >2019-10-18 13:32:55,577 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 894, in wait_for_get_address >2019-10-18 13:32:55,577 stacktrace L0045 ERROR| ipaddr = self.get_address(nic_index, ip_version) >2019-10-18 13:32:55,577 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 758, in get_address >2019-10-18 13:32:55,577 stacktrace L0045 ERROR| timeout=timeout) >2019-10-18 13:32:55,577 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 801, in _get_address >2019-10-18 13:32:55,577 stacktrace L0045 ERROR| raise VMIPAddressMissingError(mac, ip_version) >2019-10-18 13:32:55,578 stacktrace L0045 ERROR| virttest.virt_vm.VMIPAddressMissingError: No ipv4 DHCP lease for MAC 9a:2e:0b:20:95:0c >2019-10-18 13:32:55,578 stacktrace L0045 ERROR| >2019-10-18 13:32:55,578 stacktrace L0045 ERROR| During handling of the above exception, another exception occurred: >2019-10-18 13:32:55,578 stacktrace L0045 ERROR| >2019-10-18 13:32:55,578 stacktrace L0045 ERROR| Traceback (most recent call last): >2019-10-18 13:32:55,578 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/error_context.py", line 135, in new_fn >2019-10-18 13:32:55,578 stacktrace L0045 ERROR| return fn(*args, **kwargs) >2019-10-18 13:32:55,578 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/env_process.py", line 1502, in postprocess >2019-10-18 13:32:55,578 stacktrace L0045 ERROR| raise RuntimeError("Failures occurred while postprocess:\n%s" % err) >2019-10-18 13:32:55,579 stacktrace L0045 ERROR| RuntimeError: Failures occurred while postprocess: >2019-10-18 13:32:55,579 stacktrace L0045 ERROR| >2019-10-18 13:32:55,579 stacktrace L0045 ERROR| : Guest avocado-vt-vm1 dmesg verification failed: No ipv4 DHCP lease for MAC 9a:2e:0b:20:95:0c >2019-10-18 13:32:55,579 stacktrace L0046 ERROR| >2019-10-18 13:32:55,579 test L0474 ERROR| Exception raised during postprocessing: Failures occurred while postprocess: > >: Guest avocado-vt-vm1 dmesg verification failed: No ipv4 DHCP lease for MAC 9a:2e:0b:20:95:0c >2019-10-18 13:32:55,583 stacktrace L0039 ERROR| >2019-10-18 13:32:55,583 stacktrace L0042 ERROR| Reproduced traceback from: /root/venv/lib/python3.6/site-packages/avocado/core/test.py:853 >2019-10-18 13:32:55,583 stacktrace L0045 ERROR| Traceback (most recent call last): >2019-10-18 13:32:55,583 stacktrace L0045 ERROR| File "/var/lib/avocado/data/avocado-vt/test-providers.d/downloads/io-github-autotest-qemu/qemu/tests/nic_hotplug.py", line 210, in run >2019-10-18 13:32:55,584 stacktrace L0045 ERROR| "Hotplug nic can't get ip after reboot vm") >2019-10-18 13:32:55,584 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/avocado/core/test.py", line 1043, in fail >2019-10-18 13:32:55,584 stacktrace L0045 ERROR| raise exceptions.TestFail(message) >2019-10-18 13:32:55,584 stacktrace L0045 ERROR| avocado.core.exceptions.TestFail: Hotplug nic can't get ip after reboot vm >2019-10-18 13:32:55,584 stacktrace L0045 ERROR| >2019-10-18 13:32:55,584 stacktrace L0045 ERROR| During handling of the above exception, another exception occurred: >2019-10-18 13:32:55,584 stacktrace L0045 ERROR| >2019-10-18 13:32:55,584 stacktrace L0045 ERROR| Traceback (most recent call last): >2019-10-18 13:32:55,584 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/avocado_vt/test.py", line 312, in runTest >2019-10-18 13:32:55,585 stacktrace L0045 ERROR| raise self.__status # pylint: disable=E0702 >2019-10-18 13:32:55,585 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/avocado_vt/test.py", line 263, in setUp >2019-10-18 13:32:55,585 stacktrace L0045 ERROR| self._runTest() >2019-10-18 13:32:55,585 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/avocado_vt/test.py", line 438, in _runTest >2019-10-18 13:32:55,585 stacktrace L0045 ERROR| run_func(self, params, env) >2019-10-18 13:32:55,585 stacktrace L0045 ERROR| File "/var/lib/avocado/data/avocado-vt/test-providers.d/downloads/io-github-autotest-qemu/qemu/tests/nic_hotplug.py", line 249, in run >2019-10-18 13:32:55,585 stacktrace L0045 ERROR| session = vm.reboot(serial=serial) >2019-10-18 13:32:55,585 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/error_context.py", line 135, in new_fn >2019-10-18 13:32:55,585 stacktrace L0045 ERROR| return fn(*args, **kwargs) >2019-10-18 13:32:55,586 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/qemu_vm.py", line 4229, in reboot >2019-10-18 13:32:55,586 stacktrace L0045 ERROR| _reboot() >2019-10-18 13:32:55,586 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/qemu_vm.py", line 4201, in _shell_reboot >2019-10-18 13:32:55,586 stacktrace L0045 ERROR| timeout=timeout) >2019-10-18 13:32:55,586 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 1172, in wait_for_login >2019-10-18 13:32:55,586 stacktrace L0045 ERROR| ip_version=self.ip_version) >2019-10-18 13:32:55,586 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/error_context.py", line 135, in new_fn >2019-10-18 13:32:55,586 stacktrace L0045 ERROR| return fn(*args, **kwargs) >2019-10-18 13:32:55,586 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 894, in wait_for_get_address >2019-10-18 13:32:55,587 stacktrace L0045 ERROR| ipaddr = self.get_address(nic_index, ip_version) >2019-10-18 13:32:55,587 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 758, in get_address >2019-10-18 13:32:55,587 stacktrace L0045 ERROR| timeout=timeout) >2019-10-18 13:32:55,587 stacktrace L0045 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 801, in _get_address >2019-10-18 13:32:55,587 stacktrace L0045 ERROR| raise VMIPAddressMissingError(mac, ip_version) >2019-10-18 13:32:55,587 stacktrace L0045 ERROR| virttest.virt_vm.VMIPAddressMissingError: No ipv4 DHCP lease for MAC 9a:2e:0b:20:95:0c >2019-10-18 13:32:55,587 stacktrace L0046 ERROR| >2019-10-18 13:32:55,587 test L0858 DEBUG| Local variables: >2019-10-18 13:32:55,671 test L0861 DEBUG| -> self <class 'avocado_vt.test.VirtTest'>: 1-type_specific.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio >2019-10-18 13:32:55,672 test L0297 DEBUG| DATA (filename=output.expected) => NOT FOUND (data sources: variant, test, file) >2019-10-18 13:32:55,672 test L0297 DEBUG| DATA (filename=stdout.expected) => NOT FOUND (data sources: variant, test, file) >2019-10-18 13:32:55,672 test L0297 DEBUG| DATA (filename=stderr.expected) => NOT FOUND (data sources: variant, test, file) >2019-10-18 13:32:55,683 test L1007 ERROR| Traceback (most recent call last): > >2019-10-18 13:32:55,684 test L1007 ERROR| File "/var/lib/avocado/data/avocado-vt/test-providers.d/downloads/io-github-autotest-qemu/qemu/tests/nic_hotplug.py", line 210, in run > "Hotplug nic can't get ip after reboot vm") > >2019-10-18 13:32:55,684 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/avocado/core/test.py", line 1043, in fail > raise exceptions.TestFail(message) > >2019-10-18 13:32:55,684 test L1007 ERROR| avocado.core.exceptions.TestFail: Hotplug nic can't get ip after reboot vm > >2019-10-18 13:32:55,684 test L1007 ERROR| >During handling of the above exception, another exception occurred: > > >2019-10-18 13:32:55,684 test L1007 ERROR| Traceback (most recent call last): > >2019-10-18 13:32:55,684 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/avocado/core/test.py", line 948, in _run_avocado > raise test_exception > >2019-10-18 13:32:55,684 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/avocado/core/test.py", line 848, in _run_avocado > testMethod() > >2019-10-18 13:32:55,684 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/avocado_vt/test.py", line 312, in runTest > raise self.__status # pylint: disable=E0702 > >2019-10-18 13:32:55,684 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/avocado_vt/test.py", line 263, in setUp > self._runTest() > >2019-10-18 13:32:55,685 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/avocado_vt/test.py", line 438, in _runTest > run_func(self, params, env) > >2019-10-18 13:32:55,685 test L1007 ERROR| File "/var/lib/avocado/data/avocado-vt/test-providers.d/downloads/io-github-autotest-qemu/qemu/tests/nic_hotplug.py", line 249, in run > session = vm.reboot(serial=serial) > >2019-10-18 13:32:55,685 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/error_context.py", line 135, in new_fn > return fn(*args, **kwargs) > >2019-10-18 13:32:55,685 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/qemu_vm.py", line 4229, in reboot > _reboot() > >2019-10-18 13:32:55,685 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/qemu_vm.py", line 4201, in _shell_reboot > timeout=timeout) > >2019-10-18 13:32:55,685 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 1172, in wait_for_login > ip_version=self.ip_version) > >2019-10-18 13:32:55,685 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/error_context.py", line 135, in new_fn > return fn(*args, **kwargs) > >2019-10-18 13:32:55,685 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 894, in wait_for_get_address > ipaddr = self.get_address(nic_index, ip_version) > >2019-10-18 13:32:55,686 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 758, in get_address > timeout=timeout) > >2019-10-18 13:32:55,686 test L1007 ERROR| File "/root/venv/lib/python3.6/site-packages/virttest/virt_vm.py", line 801, in _get_address > raise VMIPAddressMissingError(mac, ip_version) > >2019-10-18 13:32:55,686 test L1007 ERROR| virttest.virt_vm.VMIPAddressMissingError: No ipv4 DHCP lease for MAC 9a:2e:0b:20:95:0c > >2019-10-18 13:32:55,686 test L1023 ERROR| ERROR 1-type_specific.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio -> VMIPAddressMissingError: No ipv4 DHCP lease for MAC 9a:2e:0b:20:95:0c >2019-10-18 13:32:55,686 test L1012 INFO | >2019-10-18 13:32:56,502 utils_net L1184 DEBUG| Host does not support OpenVSwitch: Command 'ovs-vswitchd' could not be found in any of the PATH dirs: ['/usr/local/bin', '/usr/bin', '/usr/sbin', '/root/bin', '/root/venv/bin', '/usr/local/sbin', '/bin', '/sbin', '/usr/libexec'] >2019-10-18 13:32:56,505 job L0533 INFO | Test results available in /root/avocado/job-results/job-2019-10-18T13.12-0f4bdbc
<b>You cannot view the attachment while viewing its details because your browser does not support IFRAMEs. <a href="attachment.cgi?id=1627242">View the attachment on a separate page</a>.</b>
View Attachment As Raw
Actions:
View
Attachments on
bug 1762906
:
1626925
|
1626926
| 1627242