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 1626926 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_hotplug test case passing (attached for comparison purposes)
nic_virtio_pass_job.log (text/plain), 101.26 KB, created by
Karen Mezick
on 2019-10-17 18:58:05 UTC
(
hide
)
Description:
Log file showing nic_hotplug test case passing (attached for comparison purposes)
Filename:
MIME Type:
Creator:
Karen Mezick
Created:
2019-10-17 18:58:05 UTC
Size:
101.26 KB
patch
obsolete
>2019-10-14 14:51:31,301 extension L0189 DEBUG| found extension EntryPoint.parse('human = avocado.plugins.human:HumanJob') >2019-10-14 14:51:31,301 extension L0189 DEBUG| found extension EntryPoint.parse('jobscripts = avocado.plugins.jobscripts:JobScripts') >2019-10-14 14:51:31,302 extension L0189 DEBUG| found extension EntryPoint.parse('teststmpdir = avocado.plugins.teststmpdir:TestsTmpDir') >2019-10-14 14:51:34,688 sysinfo L0405 DEBUG| File /etc/avocado/sysinfo/commands does not exist. >2019-10-14 14:51:34,688 sysinfo L0416 DEBUG| File /etc/avocado/sysinfo/files does not exist. >2019-10-14 14:51:34,688 sysinfo L0444 DEBUG| File /etc/avocado/sysinfo/profilers does not exist. >2019-10-14 14:51:34,697 job L0343 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-14 14:51:34,697 job L0344 INFO | >2019-10-14 14:51:34,697 job L0378 INFO | Avocado version: 69.0 >2019-10-14 14:51:34,697 job L0379 INFO | >2019-10-14 14:51:34,697 job L0383 INFO | Config files read (in order): >2019-10-14 14:51:34,697 job L0385 INFO | /root/venv/lib/python3.6/site-packages/avocado/etc/avocado/avocado.conf >2019-10-14 14:51:34,697 job L0385 INFO | /root/venv/lib/python3.6/site-packages/avocado/etc/avocado/conf.d/gdb.conf >2019-10-14 14:51:34,697 job L0385 INFO | /root/venv/lib/python3.6/site-packages/avocado/etc/avocado/conf.d/jobscripts.conf >2019-10-14 14:51:34,698 job L0385 INFO | /root/venv/lib/python3.6/site-packages/avocado/etc/avocado/conf.d/resultsdb.conf >2019-10-14 14:51:34,698 job L0385 INFO | /root/venv/lib/python3.6/site-packages/avocado/etc/avocado/conf.d/result_upload.conf >2019-10-14 14:51:34,698 job L0385 INFO | /root/venv/etc/avocado/conf.d/vt.conf >2019-10-14 14:51:34,698 job L0385 INFO | /root/venv/.config/avocado/avocado.conf >2019-10-14 14:51:34,698 job L0386 INFO | >2019-10-14 14:51:34,698 job L0388 INFO | Avocado config: >2019-10-14 14:51:34,700 job L0397 INFO | Section.Key Value >2019-10-14 14:51:34,700 job L0397 INFO | datadir.paths.base_dir /var/lib/avocado >2019-10-14 14:51:34,700 job L0397 INFO | datadir.paths.test_dir /usr/share/doc/avocado/tests >2019-10-14 14:51:34,700 job L0397 INFO | datadir.paths.data_dir /var/lib/avocado/data >2019-10-14 14:51:34,700 job L0397 INFO | datadir.paths.logs_dir ~/avocado/job-results >2019-10-14 14:51:34,700 job L0397 INFO | sysinfo.collect.enabled True >2019-10-14 14:51:34,700 job L0397 INFO | sysinfo.collect.commands_timeout -1 >2019-10-14 14:51:34,700 job L0397 INFO | sysinfo.collect.installed_packages False >2019-10-14 14:51:34,700 job L0397 INFO | sysinfo.collect.profiler False >2019-10-14 14:51:34,701 job L0397 INFO | sysinfo.collect.locale C >2019-10-14 14:51:34,701 job L0397 INFO | sysinfo.collect.per_test False >2019-10-14 14:51:34,701 job L0397 INFO | sysinfo.collectibles.commands /etc/avocado/sysinfo/commands >2019-10-14 14:51:34,701 job L0397 INFO | sysinfo.collectibles.files /etc/avocado/sysinfo/files >2019-10-14 14:51:34,701 job L0397 INFO | sysinfo.collectibles.profilers /etc/avocado/sysinfo/profilers >2019-10-14 14:51:34,701 job L0397 INFO | runner.output.colored True >2019-10-14 14:51:34,701 job L0397 INFO | runner.output.utf8 >2019-10-14 14:51:34,701 job L0397 INFO | remoter.behavior.reject_unknown_hosts False >2019-10-14 14:51:34,701 job L0397 INFO | remoter.behavior.disable_known_hosts False >2019-10-14 14:51:34,702 job L0397 INFO | job.output.loglevel debug >2019-10-14 14:51:34,702 job L0397 INFO | restclient.connection.hostname localhost >2019-10-14 14:51:34,702 job L0397 INFO | restclient.connection.port 9405 >2019-10-14 14:51:34,702 job L0397 INFO | restclient.connection.username >2019-10-14 14:51:34,702 job L0397 INFO | restclient.connection.password >2019-10-14 14:51:34,702 job L0397 INFO | plugins.disable [] >2019-10-14 14:51:34,702 job L0397 INFO | plugins.skip_broken_plugin_notification [] >2019-10-14 14:51:34,702 job L0397 INFO | plugins.loaders ['file', '@DEFAULT'] >2019-10-14 14:51:34,702 job L0397 INFO | gdb.paths.gdb /usr/bin/gdb >2019-10-14 14:51:34,702 job L0397 INFO | gdb.paths.gdbserver /usr/bin/gdbserver >2019-10-14 14:51:34,703 job L0397 INFO | plugins.jobscripts.pre /etc/avocado/scripts/job/pre.d/ >2019-10-14 14:51:34,703 job L0397 INFO | plugins.jobscripts.post /etc/avocado/scripts/job/post.d/ >2019-10-14 14:51:34,703 job L0397 INFO | plugins.jobscripts.warn_non_existing_dir False >2019-10-14 14:51:34,703 job L0397 INFO | plugins.jobscripts.warn_non_zero_status True >2019-10-14 14:51:34,703 job L0397 INFO | vt.setup.backup_image_before_test True >2019-10-14 14:51:34,703 job L0397 INFO | vt.setup.restore_image_after_test True >2019-10-14 14:51:34,703 job L0397 INFO | vt.setup.keep_guest_running False >2019-10-14 14:51:34,703 job L0397 INFO | vt.common.data_dir >2019-10-14 14:51:34,703 job L0397 INFO | vt.common.type_specific_only False >2019-10-14 14:51:34,703 job L0397 INFO | vt.common.mem >2019-10-14 14:51:34,704 job L0397 INFO | vt.common.arch >2019-10-14 14:51:34,704 job L0397 INFO | vt.common.machine_type >2019-10-14 14:51:34,704 job L0397 INFO | vt.common.nettype >2019-10-14 14:51:34,704 job L0397 INFO | vt.common.netdst virbr0 >2019-10-14 14:51:34,704 job L0397 INFO | vt.qemu.qemu_bin >2019-10-14 14:51:34,704 job L0397 INFO | vt.qemu.qemu_dst_bin >2019-10-14 14:51:34,704 job L0397 INFO | vt.qemu.accel kvm >2019-10-14 14:51:34,704 job L0397 INFO | vt.qemu.vhost off >2019-10-14 14:51:34,704 job L0397 INFO | vt.qemu.monitor >2019-10-14 14:51:34,704 job L0397 INFO | vt.qemu.smp 2 >2019-10-14 14:51:34,705 job L0397 INFO | vt.qemu.image_type qcow2 >2019-10-14 14:51:34,705 job L0397 INFO | vt.qemu.nic_model virtio_net >2019-10-14 14:51:34,705 job L0397 INFO | vt.qemu.disk_bus virtio_scsi >2019-10-14 14:51:34,705 job L0397 INFO | vt.qemu.sandbox on >2019-10-14 14:51:34,705 job L0397 INFO | vt.qemu.defconfig yes >2019-10-14 14:51:34,705 job L0397 INFO | vt.qemu.malloc_perturb yes >2019-10-14 14:51:34,705 job L0397 INFO | vt.libvirt.connect_uri qemu:///session >2019-10-14 14:51:34,705 job L0397 INFO | vt.debug.no_cleanup False >2019-10-14 14:51:34,705 job L0398 INFO | >2019-10-14 14:51:34,706 job L0401 INFO | Avocado Data Directories: >2019-10-14 14:51:34,706 job L0402 INFO | >2019-10-14 14:51:34,706 job L0403 INFO | base /var/lib/avocado >2019-10-14 14:51:34,706 job L0404 INFO | tests /root/venv/tests >2019-10-14 14:51:34,707 job L0405 INFO | data /var/lib/avocado/data >2019-10-14 14:51:34,707 job L0406 INFO | logs /root/avocado/job-results/job-2019-10-14T14.51-c751b0b >2019-10-14 14:51:34,707 job L0407 INFO | >2019-10-14 14:51:34,707 job L0413 INFO | No variants available, using defaults only >2019-10-14 14:51:34,707 job L0413 INFO | >2019-10-14 14:51:34,707 job L0413 INFO | Variant : / >2019-10-14 14:51:34,707 job L0416 INFO | Temporary dir: /var/tmp/avocado_w3_1ez5j/avocado_job_xf4zqnmk >2019-10-14 14:51:34,707 job L0417 INFO | >2019-10-14 14:51:34,707 job L0335 INFO | Job ID: c751b0b74c957ef94a9a8945b78d54833d1166b3 >2019-10-14 14:51:34,707 job L0338 INFO | >2019-10-14 14:51:34,825 sysinfo L0405 DEBUG| File /etc/avocado/sysinfo/commands does not exist. >2019-10-14 14:51:34,825 sysinfo L0416 DEBUG| File /etc/avocado/sysinfo/files does not exist. >2019-10-14 14:51:34,825 sysinfo L0444 DEBUG| File /etc/avocado/sysinfo/profilers does not exist. >2019-10-14 14:51:34,833 test L0385 INFO | INIT 1-type_specific.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio >2019-10-14 14:51:34,834 parameters L0146 DEBUG| PARAMS (key=timeout, path=*, default=14400) => '14400' >2019-10-14 14:51:34,835 test L0417 DEBUG| Test metadata: >2019-10-14 14:51:34,835 test L0425 DEBUG| teststmpdir: /var/tmp/avocado_ikh8x5mt >2019-10-14 14:51:34,835 test L0426 DEBUG| workdir: /var/tmp/avocado_w3_1ez5j/avocado_job_xf4zqnmk/1-type_specific.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio >2019-10-14 14:51:35,032 test L0602 INFO | START 1-type_specific.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio >2019-10-14 14:51:35,032 test L0298 DEBUG| DATA (filename=output.expected) => NOT FOUND (data sources: variant, test, file) >2019-10-14 14:51:35,064 test L0312 INFO | Avocado-VT 'unknown' >2019-10-14 14:51:35,064 test L0314 DEBUG| Test parameters: >2019-10-14 14:51:35,064 test L0318 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.m0.u0.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-14 14:51:35,065 test L0318 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.m0.u0.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-14 14:51:35,065 test L0318 DEBUG| auto_cpu_model = yes >2019-10-14 14:51:35,065 test L0318 DEBUG| backup_dir = images/ >2019-10-14 14:51:35,065 test L0318 DEBUG| backup_image = no >2019-10-14 14:51:35,065 test L0318 DEBUG| backup_image_before_testing = yes >2019-10-14 14:51:35,065 test L0318 DEBUG| backup_image_on_check_error = no >2019-10-14 14:51:35,066 test L0318 DEBUG| boot_menu = off >2019-10-14 14:51:35,066 test L0318 DEBUG| boot_once = c >2019-10-14 14:51:35,066 test L0318 DEBUG| boot_order = cdn >2019-10-14 14:51:35,066 test L0318 DEBUG| catch_monitor = catch_monitor >2019-10-14 14:51:35,066 test L0318 DEBUG| cd_format = scsi-cd >2019-10-14 14:51:35,066 test L0318 DEBUG| cdrom_check_cdrom_pattern = /dev/cdrom-\w+|/dev/cdrom\d* >2019-10-14 14:51:35,066 test L0318 DEBUG| cdrom_get_cdrom_cmd = ls /dev/cdrom* >2019-10-14 14:51:35,067 test L0318 DEBUG| cdrom_info_cmd = cat /proc/sys/dev/cdrom/info >2019-10-14 14:51:35,067 test L0318 DEBUG| cdrom_test_cmd = dd if=%s of=/dev/null bs=1 count=1 >2019-10-14 14:51:35,067 test L0318 DEBUG| cdroms = cd1 >2019-10-14 14:51:35,067 test L0318 DEBUG| check_image = yes >2019-10-14 14:51:35,067 test L0318 DEBUG| cmds_installed_host = >2019-10-14 14:51:35,067 test L0318 DEBUG| connect_uri = default >2019-10-14 14:51:35,067 test L0318 DEBUG| convert_ppm_files_to_png = no >2019-10-14 14:51:35,068 test L0318 DEBUG| cpu_chk_cmd = grep -c "^processor\b" /proc/cpuinfo >2019-10-14 14:51:35,068 test L0318 DEBUG| cpu_model_flags = >2019-10-14 14:51:35,068 test L0318 DEBUG| create_vm_libvirt = no >2019-10-14 14:51:35,068 test L0318 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.m0.u0.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.m0.u0.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.m0.u0.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.m0.u0.Host_arch_ppc64le.(subtest=type_specific).unattended_install.cdrom'] >2019-10-14 14:51:35,068 test L0318 DEBUG| display = vnc >2019-10-14 14:51:35,068 test L0318 DEBUG| download_url_stress = http://people.seas.harvard.edu/~apw/stress/stress-1.0.4.tar.gz >2019-10-14 14:51:35,068 test L0318 DEBUG| drive_format = scsi-hd >2019-10-14 14:51:35,069 test L0318 DEBUG| drive_index_cd1 = 1 >2019-10-14 14:51:35,069 test L0318 DEBUG| drive_index_image1 = 0 >2019-10-14 14:51:35,069 test L0318 DEBUG| drive_rerror_image1 = >2019-10-14 14:51:35,069 test L0318 DEBUG| drive_werror_image1 = >2019-10-14 14:51:35,069 test L0318 DEBUG| enable_guest_sosreport = no >2019-10-14 14:51:35,069 test L0318 DEBUG| enable_host_sosreport = no >2019-10-14 14:51:35,069 test L0318 DEBUG| enable_libvirtd_debug_log = yes >2019-10-14 14:51:35,070 test L0318 DEBUG| enable_msix_vectors = yes >2019-10-14 14:51:35,070 test L0318 DEBUG| enable_remote_host_sosreport = no >2019-10-14 14:51:35,070 test L0318 DEBUG| encode_video_files = yes >2019-10-14 14:51:35,070 test L0318 DEBUG| env_cleanup = no >2019-10-14 14:51:35,070 test L0318 DEBUG| extra_params = -net none >2019-10-14 14:51:35,070 test L0318 DEBUG| file_transfer_client = scp >2019-10-14 14:51:35,070 test L0318 DEBUG| file_transfer_port = 22 >2019-10-14 14:51:35,071 test L0318 DEBUG| find_pci_cmd = lspci | grep Ethernet >2019-10-14 14:51:35,071 test L0318 DEBUG| flexible_nic_index = no >2019-10-14 14:51:35,071 test L0318 DEBUG| guest_dmesg_dump_console = no >2019-10-14 14:51:35,071 test L0318 DEBUG| guest_dmesg_ignore = False >2019-10-14 14:51:35,071 test L0318 DEBUG| guest_dmesg_level = 3 >2019-10-14 14:51:35,071 test L0318 DEBUG| guest_port_remote_shell = 22 >2019-10-14 14:51:35,071 test L0318 DEBUG| id = type_specific.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio >2019-10-14 14:51:35,072 test L0318 DEBUG| image_backend = filesystem >2019-10-14 14:51:35,072 test L0318 DEBUG| image_chain = >2019-10-14 14:51:35,072 test L0318 DEBUG| image_clone_command = cp --reflink=auto %s %s >2019-10-14 14:51:35,072 test L0318 DEBUG| image_format = qcow2 >2019-10-14 14:51:35,072 test L0318 DEBUG| image_name = images/rhel7devel-ppc64le >2019-10-14 14:51:35,072 test L0318 DEBUG| image_raw_device = no >2019-10-14 14:51:35,072 test L0318 DEBUG| image_remove_command = rm -rf %s >2019-10-14 14:51:35,073 test L0318 DEBUG| image_size = 10G >2019-10-14 14:51:35,073 test L0318 DEBUG| image_unbootable_pattern = Hard Disk.*not a bootable disk >2019-10-14 14:51:35,073 test L0318 DEBUG| image_verify_bootable = yes >2019-10-14 14:51:35,073 test L0318 DEBUG| images = image1 >2019-10-14 14:51:35,073 test L0318 DEBUG| inactivity_treshold = 1800 >2019-10-14 14:51:35,073 test L0318 DEBUG| inactivity_watcher = log >2019-10-14 14:51:35,073 test L0318 DEBUG| indirect_image_blacklist = /dev/hda[\d]* /dev/sda[\d]* /dev/sg0 /dev/md0 >2019-10-14 14:51:35,074 test L0318 DEBUG| inputs = >2019-10-14 14:51:35,074 test L0318 DEBUG| install_virtio = no >2019-10-14 14:51:35,074 test L0318 DEBUG| keep_ppm_files = no >2019-10-14 14:51:35,074 test L0318 DEBUG| keep_ppm_files_on_error = no >2019-10-14 14:51:35,074 test L0318 DEBUG| keep_screendumps = yes >2019-10-14 14:51:35,074 test L0318 DEBUG| keep_screendumps_on_error = yes >2019-10-14 14:51:35,074 test L0318 DEBUG| keep_video_files = yes >2019-10-14 14:51:35,075 test L0318 DEBUG| keep_video_files_on_error = yes >2019-10-14 14:51:35,075 test L0318 DEBUG| kill_timeout = 60 >2019-10-14 14:51:35,075 test L0318 DEBUG| kill_unresponsive_vms = yes >2019-10-14 14:51:35,075 test L0318 DEBUG| kill_vm = yes >2019-10-14 14:51:35,075 test L0318 DEBUG| kill_vm_before_test = no >2019-10-14 14:51:35,075 test L0318 DEBUG| kill_vm_gracefully = yes >2019-10-14 14:51:35,075 test L0318 DEBUG| kill_vm_libvirt = no >2019-10-14 14:51:35,076 test L0318 DEBUG| libvirt_controller = virtio-scsi >2019-10-14 14:51:35,076 test L0318 DEBUG| libvirtd_debug_file = >2019-10-14 14:51:35,076 test L0318 DEBUG| libvirtd_debug_level = 2 >2019-10-14 14:51:35,076 test L0318 DEBUG| libvirtd_log_cleanup = yes >2019-10-14 14:51:35,076 test L0318 DEBUG| local_ip = ENTER.YOUR.LOCAL.EXAMPLE.COM >2019-10-14 14:51:35,076 test L0318 DEBUG| local_pwd = >2019-10-14 14:51:35,076 test L0318 DEBUG| login_timeout = 360 >2019-10-14 14:51:35,077 test L0318 DEBUG| machine_type = pseries >2019-10-14 14:51:35,077 test L0318 DEBUG| main_vm = avocado-vt-vm1 >2019-10-14 14:51:35,077 test L0318 DEBUG| malloc_perturb = yes >2019-10-14 14:51:35,077 test L0318 DEBUG| mem = 1024 >2019-10-14 14:51:35,077 test L0318 DEBUG| mem_chk_cmd = numactl --hardware | awk -F: '/size/ {print $2}' >2019-10-14 14:51:35,077 test L0318 DEBUG| mem_chk_cur_cmd = grep MemTotal /proc/meminfo >2019-10-14 14:51:35,077 test L0318 DEBUG| mem_chk_re_str = [^\$]([0-9]+) >2019-10-14 14:51:35,078 test L0318 DEBUG| memballoon_model = virtio >2019-10-14 14:51:35,078 test L0318 DEBUG| migrate_dest_host = ENTER.YOUR.DEST.EXAMPLE.COM >2019-10-14 14:51:35,078 test L0318 DEBUG| migrate_dest_pwd = PASSWORD.DEST.EXAMPLE >2019-10-14 14:51:35,078 test L0318 DEBUG| migrate_load_vms = >2019-10-14 14:51:35,078 test L0318 DEBUG| migrate_main_vm = avocado-vt-vm1 >2019-10-14 14:51:35,078 test L0318 DEBUG| migrate_port = 49152 >2019-10-14 14:51:35,078 test L0318 DEBUG| migrate_proto = tcp >2019-10-14 14:51:35,079 test L0318 DEBUG| migrate_shared_storage = SHARED_IMAGE.EXAMPLE >2019-10-14 14:51:35,079 test L0318 DEBUG| migrate_source_host = ENTER.YOUR.SOURCE.EXAMPLE.COM >2019-10-14 14:51:35,079 test L0318 DEBUG| migrate_source_pwd = PASSWORD.SOURCE.EXAMPLE >2019-10-14 14:51:35,079 test L0318 DEBUG| migrate_vms = >2019-10-14 14:51:35,079 test L0318 DEBUG| migration_setup = no >2019-10-14 14:51:35,079 test L0318 DEBUG| modprobe_module = >2019-10-14 14:51:35,079 test L0318 DEBUG| monitor_type = qmp >2019-10-14 14:51:35,080 test L0318 DEBUG| monitors = qmpmonitor1 >2019-10-14 14:51:35,080 test L0318 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.m0.u0.Host_arch_ppc64le.(subtest=type_specific).(subtest=io-github-autotest-qemu).(subtest=nic_hotplug).vhost_nic.nic_virtio.pseries >2019-10-14 14:51:35,080 test L0318 DEBUG| netdev_extra_params_hotplug_nic1 = ,vhost=on >2019-10-14 14:51:35,080 test L0318 DEBUG| netdev_peer_re = (.*?): .*?\\\s(.*?): >2019-10-14 14:51:35,080 test L0318 DEBUG| netdst = virbr0 >2019-10-14 14:51:35,080 test L0318 DEBUG| nettype = bridge >2019-10-14 14:51:35,080 test L0318 DEBUG| nic_hotplug_count = 1 >2019-10-14 14:51:35,081 test L0318 DEBUG| nic_model = virtio >2019-10-14 14:51:35,081 test L0318 DEBUG| nics = >2019-10-14 14:51:35,081 test L0318 DEBUG| os_type = linux >2019-10-14 14:51:35,081 test L0318 DEBUG| os_variant = rhel7 >2019-10-14 14:51:35,081 test L0318 DEBUG| other_tests_dirs = >2019-10-14 14:51:35,081 test L0318 DEBUG| password = 123456 >2019-10-14 14:51:35,081 test L0318 DEBUG| paused_after_start_vm = no >2019-10-14 14:51:35,082 test L0318 DEBUG| pci_assignable = no >2019-10-14 14:51:35,082 test L0318 DEBUG| pci_model = virtio-net-pci >2019-10-14 14:51:35,082 test L0318 DEBUG| pci_test_cmd = echo %s; nslookup www.redhat.com >2019-10-14 14:51:35,082 test L0318 DEBUG| pci_type = nic >2019-10-14 14:51:35,082 test L0318 DEBUG| power9_compat = no >2019-10-14 14:51:35,082 test L0318 DEBUG| power9_compat_remote = no >2019-10-14 14:51:35,082 test L0318 DEBUG| profilers = kvm_stat >2019-10-14 14:51:35,083 test L0318 DEBUG| provider = io-github-autotest-qemu >2019-10-14 14:51:35,083 test L0318 DEBUG| qemu_binary = /usr/libexec/qemu-kvm >2019-10-14 14:51:35,083 test L0318 DEBUG| qemu_dst_binary = /usr/libexec/qemu-kvm >2019-10-14 14:51:35,083 test L0318 DEBUG| qemu_img_binary = /usr/bin/qemu-img >2019-10-14 14:51:35,083 test L0318 DEBUG| qemu_io_binary = /usr/bin/qemu-io >2019-10-14 14:51:35,083 test L0318 DEBUG| reboot_command = shutdown -r now >2019-10-14 14:51:35,083 test L0318 DEBUG| redirs = remote_shell >2019-10-14 14:51:35,084 test L0318 DEBUG| reference_cmd = lspci >2019-10-14 14:51:35,084 test L0318 DEBUG| remote_ip = ENTER.YOUR.REMOTE.EXAMPLE.COM >2019-10-14 14:51:35,084 test L0318 DEBUG| remote_pwd = >2019-10-14 14:51:35,084 test L0318 DEBUG| remote_user = root >2019-10-14 14:51:35,084 test L0318 DEBUG| remove_image_image1 = no >2019-10-14 14:51:35,084 test L0318 DEBUG| restore_image = no >2019-10-14 14:51:35,084 test L0318 DEBUG| restore_image_after_testing = yes >2019-10-14 14:51:35,085 test L0318 DEBUG| restore_image_on_check_error = no >2019-10-14 14:51:35,085 test L0318 DEBUG| restore_smt = no >2019-10-14 14:51:35,085 test L0318 DEBUG| rpmbuild_path = /root/rpmbuild/ >2019-10-14 14:51:35,085 test L0318 DEBUG| run_dhclient = no >2019-10-14 14:51:35,085 test L0318 DEBUG| run_tcpdump = yes >2019-10-14 14:51:35,085 test L0318 DEBUG| screendump_delay = 5 >2019-10-14 14:51:35,085 test L0318 DEBUG| screendump_quality = 30 >2019-10-14 14:51:35,086 test L0318 DEBUG| screendump_temp_dir = /dev/shm >2019-10-14 14:51:35,086 test L0318 DEBUG| screendump_verbose = no >2019-10-14 14:51:35,086 test L0318 DEBUG| scsi_hba = virtio-scsi-pci >2019-10-14 14:51:35,086 test L0318 DEBUG| serials = serial0 >2019-10-14 14:51:35,086 test L0318 DEBUG| shell_client = ssh >2019-10-14 14:51:35,086 test L0318 DEBUG| shell_linesep = \n >2019-10-14 14:51:35,086 test L0318 DEBUG| shell_port = 22 >2019-10-14 14:51:35,087 test L0318 DEBUG| shell_prompt = ^\[.*\][\#\$]\s*$ >2019-10-14 14:51:35,087 test L0318 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-14 14:51:35,087 test L0318 DEBUG| shutdown_command = shutdown -h now >2019-10-14 14:51:35,087 test L0318 DEBUG| skip_cluster_leak_warn = yes >2019-10-14 14:51:35,087 test L0318 DEBUG| skip_image_check_during_running = no >2019-10-14 14:51:35,087 test L0318 DEBUG| skip_image_processing = no >2019-10-14 14:51:35,087 test L0318 DEBUG| smp = 2 >2019-10-14 14:51:35,088 test L0318 DEBUG| start_vm = yes >2019-10-14 14:51:35,088 test L0318 DEBUG| status_test_command = echo $? >2019-10-14 14:51:35,088 test L0318 DEBUG| store_vm_register = yes >2019-10-14 14:51:35,088 test L0318 DEBUG| stress_args = --cpu 4 --io 4 --vm 2 --vm-bytes 256M >2019-10-14 14:51:35,088 test L0318 DEBUG| stress_install_from_repo = no >2019-10-14 14:51:35,088 test L0318 DEBUG| strict_mode = no >2019-10-14 14:51:35,088 test L0318 DEBUG| subtest = io-github-autotest-qemu.nic_hotplug >2019-10-14 14:51:35,089 test L0318 DEBUG| take_regular_screendumps = yes >2019-10-14 14:51:35,089 test L0318 DEBUG| test_timeout = 14400 >2019-10-14 14:51:35,089 test L0318 DEBUG| type = nic_hotplug >2019-10-14 14:51:35,089 test L0318 DEBUG| url_auto_ip = >2019-10-14 14:51:35,089 test L0318 DEBUG| usb_bus = usb1.0 >2019-10-14 14:51:35,089 test L0318 DEBUG| usb_controller = xhci >2019-10-14 14:51:35,089 test L0318 DEBUG| usb_devices = tablet1 >2019-10-14 14:51:35,090 test L0318 DEBUG| usb_max_port = 6 >2019-10-14 14:51:35,090 test L0318 DEBUG| usb_type = nec-usb-xhci >2019-10-14 14:51:35,090 test L0318 DEBUG| usb_type_tablet1 = usb-tablet >2019-10-14 14:51:35,090 test L0318 DEBUG| usb_type_usb1 = nec-usb-xhci >2019-10-14 14:51:35,090 test L0318 DEBUG| usbs = usb1 >2019-10-14 14:51:35,090 test L0318 DEBUG| use_autostart = no >2019-10-14 14:51:35,090 test L0318 DEBUG| use_check_cpu = yes >2019-10-14 14:51:35,091 test L0318 DEBUG| use_debug = yes >2019-10-14 14:51:35,091 test L0318 DEBUG| use_no_reboot = no >2019-10-14 14:51:35,091 test L0318 DEBUG| use_os_type = yes >2019-10-14 14:51:35,091 test L0318 DEBUG| use_os_variant = no >2019-10-14 14:51:35,091 test L0318 DEBUG| use_virt_install_wait = no >2019-10-14 14:51:35,091 test L0318 DEBUG| used_cpus = 2 >2019-10-14 14:51:35,091 test L0318 DEBUG| used_mem = 512 >2019-10-14 14:51:35,092 test L0318 DEBUG| username = root >2019-10-14 14:51:35,092 test L0318 DEBUG| vcpu_thread_pattern = thread_id.?[:|=]\s*(\d+) >2019-10-14 14:51:35,092 test L0318 DEBUG| verify_guest_dmesg = yes >2019-10-14 14:51:35,092 test L0318 DEBUG| verify_host_dmesg = yes >2019-10-14 14:51:35,092 test L0318 DEBUG| vfd_size = 1440k >2019-10-14 14:51:35,092 test L0318 DEBUG| vga = std >2019-10-14 14:51:35,092 test L0318 DEBUG| vga_use_legacy_expression = no >2019-10-14 14:51:35,093 test L0318 DEBUG| virt_install_wait_time = 300 >2019-10-14 14:51:35,093 test L0318 DEBUG| virt_test_type = qemu >2019-10-14 14:51:35,093 test L0318 DEBUG| virtinstall_extra_args = >2019-10-14 14:51:35,093 test L0318 DEBUG| vm_arch_name = ppc64le >2019-10-14 14:51:35,093 test L0318 DEBUG| vm_register_delay = 5 >2019-10-14 14:51:35,093 test L0318 DEBUG| vm_type = qemu >2019-10-14 14:51:35,093 test L0318 DEBUG| vms = avocado-vt-vm1 >2019-10-14 14:51:35,093 test L0318 DEBUG| vnc_autoport = yes >2019-10-14 14:51:35,094 test L0318 DEBUG| wait_secs_for_hook_up = 3 >2019-10-14 14:51:35,103 test L0371 DEBUG| Searching for test modules that match 'type = nic_hotplug' and 'provider = io-github-autotest-qemu' on this cartesian dict >2019-10-14 14:51:35,105 test L0385 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-14 14:51:35,107 utils_env L0088 WARNI| Creating new, empty env file >2019-10-14 14:51:35,113 process L0626 INFO | Running 'grep revision /proc/cpuinfo | awk '{print $3}' | head -n 1' >2019-10-14 14:51:35,116 process L0458 DEBUG| [stdout] 2.1 >2019-10-14 14:51:35,117 process L0714 INFO | Command 'grep revision /proc/cpuinfo | awk '{print $3}' | head -n 1' finished with 0 after 0.0024008750915527344s >2019-10-14 14:51:35,138 process L0626 INFO | Running 'ppc64_cpu --smt' >2019-10-14 14:51:35,150 process L0458 DEBUG| [stdout] SMT is off >2019-10-14 14:51:35,150 process L0714 INFO | Command 'ppc64_cpu --smt' finished with 0 after 0.010900497436523438s >2019-10-14 14:51:36,283 env_process L0901 DEBUG| KVM version: 4.18.0-141.el8.ppc64le >2019-10-14 14:51:36,300 env_process L0936 DEBUG| KVM userspace version(qemu): 2.12.0 (qemu-kvm-2.12.0-88.module+el8.1.0+4233+bc44be3f) >2019-10-14 14:51:36,300 process L0626 INFO | Running 'true' >2019-10-14 14:51:36,302 process L0714 INFO | Command 'true' finished with 0 after 0.0006487369537353516s >2019-10-14 14:51:36,303 process L0626 INFO | Running 'ps -o comm 1' >2019-10-14 14:51:36,338 process L0458 DEBUG| [stdout] COMMAND >2019-10-14 14:51:36,339 process L0458 DEBUG| [stdout] systemd >2019-10-14 14:51:36,338 process L0714 INFO | Command 'ps -o comm 1' finished with 0 after 0.03444528579711914s >2019-10-14 14:51:36,371 storage L0471 DEBUG| Image backup /var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2.backup already exists, skipping... >2019-10-14 14:51:36,696 utils_misc L2010 DEBUG| Detected CPU vendor as 'unknown' >2019-10-14 14:51:36,717 qemu_vm L2296 DEBUG| qemu will run in KVM mode >2019-10-14 14:51:36,721 qemu_vm L2853 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',t'SER-serial0',t'isa-log',usb1,virtio_scsi_pci0,drive_image1,image1,t'mem',t'smp',usb-tablet1,t'tcp-redir',t'display',t'rtc',t'bootmenu',t'extra',t'kvm'] >2019-10-14 14:51:36,721 qemu_vm L2854 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-14 14:51:36,722 qemu_vm L2918 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_w3_1ez5j/monitor-qmpmonitor1-20191014-145136-VeSFZVlQ,server,nowait \ > -mon chardev=qmp_id_qmpmonitor1,mode=control \ > -chardev socket,id=qmp_id_catch_monitor,path=/var/tmp/avocado_w3_1ez5j/monitor-catch_monitor-20191014-145136-VeSFZVlQ,server,nowait \ > -mon chardev=qmp_id_catch_monitor,mode=control \ > -chardev socket,id=serial_id_serial0,path=/var/tmp/avocado_w3_1ez5j/serial-serial0-20191014-145136-VeSFZVlQ,server,nowait \ > -device spapr-vty,reg=0x30000000,chardev=serial_id_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 \ > -drive id=drive_image1,if=none,format=qcow2,file=/var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2 \ > -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-14 14:51:37,812 qemu_vm L2928 INFO | Created qemu process with parent PID 82169 >2019-10-14 14:51:38,119 qemu_monitor L0148 INFO | Connecting to monitor '<<class 'virttest.qemu_monitor.QMPMonitor'>> qmpmonitor1' >2019-10-14 14:51:38,220 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'qmp_capabilities' >2019-10-14 14:51:38,220 qemu_monitor L1700 DEBUG| Send command: {'execute': 'qmp_capabilities', 'id': 'mIDxZ9mB'} >2019-10-14 14:51:38,249 qemu_monitor L0148 INFO | Connecting to monitor '<<class 'virttest.qemu_monitor.QMPMonitor'>> catch_monitor' >2019-10-14 14:51:38,350 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.catch_monitor) Sending command 'qmp_capabilities' >2019-10-14 14:51:38,350 qemu_monitor L1700 DEBUG| Send command: {'execute': 'qmp_capabilities', 'id': 'yNaajQyJ'} >2019-10-14 14:51:38,390 qemu_vm L3036 DEBUG| VM appears to be alive with PID 82171 >2019-10-14 14:51:38,390 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'query-cpus' >2019-10-14 14:51:38,391 qemu_monitor L1700 DEBUG| Send command: {'execute': 'query-cpus', 'id': 'jGMtpl6G'} >2019-10-14 14:51:38,392 qemu_monitor L1656 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Response to 'query-cpus' (re-formated) >2019-10-14 14:51:38,392 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) arch: ppc >2019-10-14 14:51:38,392 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) current: True >2019-10-14 14:51:38,392 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) props: >2019-10-14 14:51:38,393 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) core-id: 0 >2019-10-14 14:51:38,393 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) CPU: 0 >2019-10-14 14:51:38,393 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) nip: 256 >2019-10-14 14:51:38,393 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) qom_path: /machine/unattached/device[0]/thread[0] >2019-10-14 14:51:38,393 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) halted: False >2019-10-14 14:51:38,393 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) thread_id: 82178 >2019-10-14 14:51:38,393 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) arch: ppc >2019-10-14 14:51:38,394 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) current: False >2019-10-14 14:51:38,394 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) props: >2019-10-14 14:51:38,394 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) core-id: 1 >2019-10-14 14:51:38,394 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) CPU: 1 >2019-10-14 14:51:38,394 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) nip: 256 >2019-10-14 14:51:38,394 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) qom_path: /machine/unattached/device[1]/thread[0] >2019-10-14 14:51:38,394 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) halted: True >2019-10-14 14:51:38,395 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) thread_id: 82179 >2019-10-14 14:51:39,608 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'cont' >2019-10-14 14:51:39,609 qemu_monitor L1700 DEBUG| Send command: {'execute': 'cont', 'id': 'rPQlV25O'} >2019-10-14 14:51:39,616 virt_vm L0935 WARNI| Unable to read serial console >2019-10-14 14:51:39,616 virt_vm L0995 WARNI| Unable to read serial console >2019-10-14 14:51:39,621 utils_net L3233 WARNI| No IP address of host was provided, using IP address on virbr0 interface >2019-10-14 14:51:39,622 virt_vm L1338 DEBUG| Attempting to log into 'avocado-vt-vm1' via serial console (timeout 360s) >2019-10-14 14:52:34,067 nic_hotplug L0168 INFO | Disable other link(s) of guest >2019-10-14 14:52:34,067 nic_hotplug L0179 DEBUG| Hotplug 1th 'virtio-net-pci' nic named 'hotplug_nic1' >2019-10-14 14:52:34,068 virt_vm L0884 DEBUG| Generating random mac address for nic >2019-10-14 14:52:34,092 error_context L0079 DEBUG| Context: (hotplug_nic) --> Opening tap device node for t0-acKwrc >2019-10-14 14:52:34,127 error_context L0079 INFO | Context: (hotplug_nic) --> Assigning tap idb1hqh4 to qemu by fd >2019-10-14 14:52:34,127 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'getfd' >2019-10-14 14:52:34,128 qemu_monitor L1700 DEBUG| Send command: {'execute': 'getfd', 'arguments': {'fdname': 'idb1hqh4'}, 'id': 'e9NqT5b9'} >2019-10-14 14:52:34,130 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:46:47:48:49:4a', 'vlan': '0', 'device_id': 'idHHrRMa', 'queues': '1', 'netdev_id': 'idfGC4xq', 'ifname': 't0-acKwrc', 'tapfd_ids': ['idb1hqh4'], 'vectors': 4} on vm avocado-vt-vm1 with attach_cmd netdev_add type=tap,id=idHHrRMa,fd=33 >2019-10-14 14:52:34,134 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:46:47:48:49:4a', 'vlan': '0', 'device_id': 'idHHrRMa', 'queues': '1', 'netdev_id': 'idfGC4xq', 'ifname': 't0-acKwrc', 'tapfd_ids': ['idb1hqh4'], 'vectors': 4} on vm avocado-vt-vm1 with attach_cmd netdev_add type=tap,id=idHHrRMa,fd=33 >2019-10-14 14:52:34,135 utils_net L1131 DEBUG| Host does not support OpenVSwitch: Command 'ovs-vswitchd' could not be found in any of the PATH dirs: ['/usr/bin', '/usr/local/sbin', '/root/bin', '/root/venv/bin', '/sbin', '/usr/libexec', '/bin', '/usr/local/bin', '/usr/sbin'] >2019-10-14 14:52:34,137 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:46:47:48:49:4a', 'vlan': '0', 'device_id': 'idHHrRMa', 'queues': '1', 'netdev_id': 'idfGC4xq', 'ifname': 't0-acKwrc', 'tapfd_ids': ['idb1hqh4'], 'vectors': 4} on vm avocado-vt-vm1 with attach_cmd netdev_add type=tap,id=idHHrRMa,fd=33,vhost=on >2019-10-14 14:52:34,139 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'netdev_add' >2019-10-14 14:52:34,139 qemu_monitor L1700 DEBUG| Send command: {'execute': 'netdev_add', 'arguments': {'type': 'tap', 'id': 'idHHrRMa', 'fd': 33, 'vhost': 'on'}, 'id': 'ud2dTrbD'} >2019-10-14 14:52:34,141 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'info network' (via Human Monitor) >2019-10-14 14:52:34,143 qemu_monitor L1656 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Response to 'info network' (re-formated) >2019-10-14 14:52:34,143 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) idHHrRMa: index=0,type=tap,fd=33 >2019-10-14 14:52:34,144 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'device_add' >2019-10-14 14:52:34,144 qemu_monitor L1700 DEBUG| Send command: {'execute': 'device_add', 'arguments': {'driver': 'virtio-net-pci', 'netdev': 'idHHrRMa', 'mac': '9a:46:47:48:49:4a', 'id': 'hotplug_nic1', 'vectors': 4}, 'id': 'uZxDH0ZV'} >2019-10-14 14:52:34,149 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'info qtree' (via Human Monitor) >2019-10-14 14:52:34,152 qemu_monitor L1656 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Response to 'info qtree' (re-formated) >2019-10-14 14:52:34,152 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: main-system-bus >2019-10-14 14:52:34,153 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type System >2019-10-14 14:52:34,153 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: spapr-pci-host-bridge, id "" >2019-10-14 14:52:34,153 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) index = 0 (0x0) >2019-10-14 14:52:34,153 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mem_win_size = 2147483648 (0x80000000) >2019-10-14 14:52:34,153 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mem64_win_size = 1099511627776 (0x10000000000) >2019-10-14 14:52:34,153 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) io_win_size = 65536 (0x10000) >2019-10-14 14:52:34,153 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dynamic-reconfiguration = true >2019-10-14 14:52:34,153 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dma_win_addr = 0 (0x0) >2019-10-14 14:52:34,154 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dma_win_size = 1073741824 (0x40000000) >2019-10-14 14:52:34,154 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dma64_win_addr = 576460752303423488 (0x800000000000000) >2019-10-14 14:52:34,154 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ddw = true >2019-10-14 14:52:34,154 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) pgsz = 69632 (0x11000) >2019-10-14 14:52:34,154 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) numa_node = 4294967295 (0xffffffff) >2019-10-14 14:52:34,154 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) pre-2.8-migration = false >2019-10-14 14:52:34,154 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) pcie-extended-configuration-space = true >2019-10-14 14:52:34,155 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) gpa = 70368744177664 (0x400000000000) >2019-10-14 14:52:34,155 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) atsd = 140737488355328 (0x800000000000) >2019-10-14 14:52:34,155 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: pci.0 >2019-10-14 14:52:34,155 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type PCI >2019-10-14 14:52:34,155 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: virtio-net-pci, id "hotplug_nic1" >2019-10-14 14:52:34,155 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ioeventfd = true >2019-10-14 14:52:34,155 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) vectors = 4 (0x4) >2019-10-14 14:52:34,156 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) virtio-pci-bus-master-bug-migration = false >2019-10-14 14:52:34,156 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) disable-legacy = "off" >2019-10-14 14:52:34,156 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) disable-modern = false >2019-10-14 14:52:34,156 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) migrate-extra = true >2019-10-14 14:52:34,156 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) modern-pio-notify = false >2019-10-14 14:52:34,156 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-disable-pcie = false >2019-10-14 14:52:34,156 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) page-per-vq = false >2019-10-14 14:52:34,157 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-ignore-backend-features = false >2019-10-14 14:52:34,157 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ats = false >2019-10-14 14:52:34,157 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-deverr-init = true >2019-10-14 14:52:34,157 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnkctl-init = true >2019-10-14 14:52:34,157 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-pm-init = true >2019-10-14 14:52:34,157 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr = 00.0 >2019-10-14 14:52:34,157 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) romfile = "efi-virtio.rom" >2019-10-14 14:52:34,158 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rombar = 1 (0x1) >2019-10-14 14:52:34,158 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) multifunction = false >2019-10-14 14:52:34,158 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) command_serr_enable = true >2019-10-14 14:52:34,158 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnksta-dllla = true >2019-10-14 14:52:34,158 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-extcap-init = true >2019-10-14 14:52:34,158 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) class Ethernet controller, addr 00:00.0, pci id 1af4:1000 (sub 1af4:0001) >2019-10-14 14:52:34,158 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 0: i/o at 0xffffffffffffffff [0x1e] >2019-10-14 14:52:34,159 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 1: mem at 0xffffffffffffffff [0xffe] >2019-10-14 14:52:34,159 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 4: mem at 0xffffffffffffffff [0x3ffe] >2019-10-14 14:52:34,159 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 6: mem at 0xffffffffffffffff [0x3fffe] >2019-10-14 14:52:34,159 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: virtio-bus >2019-10-14 14:52:34,159 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type virtio-pci-bus >2019-10-14 14:52:34,159 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: virtio-net-device, id "" >2019-10-14 14:52:34,159 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) csum = true >2019-10-14 14:52:34,160 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) guest_csum = true >2019-10-14 14:52:34,160 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) gso = true >2019-10-14 14:52:34,160 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) guest_tso4 = true >2019-10-14 14:52:34,160 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) guest_tso6 = true >2019-10-14 14:52:34,160 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) guest_ecn = true >2019-10-14 14:52:34,160 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) guest_ufo = true >2019-10-14 14:52:34,160 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) guest_announce = true >2019-10-14 14:52:34,161 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) host_tso4 = true >2019-10-14 14:52:34,161 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) host_tso6 = true >2019-10-14 14:52:34,161 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) host_ecn = true >2019-10-14 14:52:34,161 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) host_ufo = true >2019-10-14 14:52:34,161 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mrg_rxbuf = true >2019-10-14 14:52:34,161 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) status = true >2019-10-14 14:52:34,161 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ctrl_vq = true >2019-10-14 14:52:34,162 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ctrl_rx = true >2019-10-14 14:52:34,162 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ctrl_vlan = true >2019-10-14 14:52:34,162 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ctrl_rx_extra = true >2019-10-14 14:52:34,162 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ctrl_mac_addr = true >2019-10-14 14:52:34,162 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ctrl_guest_offloads = true >2019-10-14 14:52:34,162 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mq = false >2019-10-14 14:52:34,162 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mac = "9a:46:47:48:49:4a" >2019-10-14 14:52:34,163 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) vlan = <null> >2019-10-14 14:52:34,163 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) netdev = "idHHrRMa" >2019-10-14 14:52:34,163 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-txtimer = 150000 (0x249f0) >2019-10-14 14:52:34,163 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-txburst = 256 (0x100) >2019-10-14 14:52:34,163 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) tx = "" >2019-10-14 14:52:34,163 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rx_queue_size = 256 (0x100) >2019-10-14 14:52:34,163 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) tx_queue_size = 256 (0x100) >2019-10-14 14:52:34,164 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) host_mtu = 0 (0x0) >2019-10-14 14:52:34,164 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-mtu-bypass-backend = true >2019-10-14 14:52:34,164 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) speed = -1 (0xffffffffffffffff) >2019-10-14 14:52:34,164 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) duplex = "" >2019-10-14 14:52:34,164 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) indirect_desc = true >2019-10-14 14:52:34,164 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) event_idx = true >2019-10-14 14:52:34,164 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) notify_on_empty = true >2019-10-14 14:52:34,165 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) any_layout = true >2019-10-14 14:52:34,165 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) iommu_platform = false >2019-10-14 14:52:34,165 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: virtio-scsi-pci, id "virtio_scsi_pci0" >2019-10-14 14:52:34,165 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ioeventfd = true >2019-10-14 14:52:34,165 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) vectors = 4 (0x4) >2019-10-14 14:52:34,165 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) virtio-pci-bus-master-bug-migration = false >2019-10-14 14:52:34,165 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) disable-legacy = "off" >2019-10-14 14:52:34,166 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) disable-modern = false >2019-10-14 14:52:34,166 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) migrate-extra = true >2019-10-14 14:52:34,166 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) modern-pio-notify = false >2019-10-14 14:52:34,166 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-disable-pcie = false >2019-10-14 14:52:34,166 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) page-per-vq = false >2019-10-14 14:52:34,166 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-ignore-backend-features = false >2019-10-14 14:52:34,166 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ats = false >2019-10-14 14:52:34,167 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-deverr-init = true >2019-10-14 14:52:34,167 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnkctl-init = true >2019-10-14 14:52:34,167 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-pm-init = true >2019-10-14 14:52:34,167 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr = 04.0 >2019-10-14 14:52:34,167 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) romfile = "" >2019-10-14 14:52:34,167 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rombar = 1 (0x1) >2019-10-14 14:52:34,167 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) multifunction = false >2019-10-14 14:52:34,168 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) command_serr_enable = true >2019-10-14 14:52:34,168 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnksta-dllla = true >2019-10-14 14:52:34,168 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-extcap-init = true >2019-10-14 14:52:34,168 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) class SCSI controller, addr 00:04.0, pci id 1af4:1004 (sub 1af4:0008) >2019-10-14 14:52:34,168 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 0: i/o at 0x40 [0x7f] >2019-10-14 14:52:34,168 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 1: mem at 0x81030000 [0x81030fff] >2019-10-14 14:52:34,168 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 4: mem at 0x210000000000 [0x210000003fff] >2019-10-14 14:52:34,169 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: virtio-bus >2019-10-14 14:52:34,169 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type virtio-pci-bus >2019-10-14 14:52:34,169 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: virtio-scsi-device, id "" >2019-10-14 14:52:34,169 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) num_queues = 1 (0x1) >2019-10-14 14:52:34,169 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) virtqueue_size = 128 (0x80) >2019-10-14 14:52:34,169 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) max_sectors = 65535 (0xffff) >2019-10-14 14:52:34,169 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) cmd_per_lun = 128 (0x80) >2019-10-14 14:52:34,170 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) hotplug = true >2019-10-14 14:52:34,170 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) param_change = true >2019-10-14 14:52:34,170 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) iothread = "" >2019-10-14 14:52:34,170 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) indirect_desc = true >2019-10-14 14:52:34,170 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) event_idx = true >2019-10-14 14:52:34,170 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) notify_on_empty = true >2019-10-14 14:52:34,170 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) any_layout = true >2019-10-14 14:52:34,171 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) iommu_platform = false >2019-10-14 14:52:34,171 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: virtio_scsi_pci0.0 >2019-10-14 14:52:34,171 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type SCSI >2019-10-14 14:52:34,171 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: scsi-hd, id "image1" >2019-10-14 14:52:34,171 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) drive = "drive_image1" >2019-10-14 14:52:34,171 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) logical_block_size = 512 (0x200) >2019-10-14 14:52:34,171 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) physical_block_size = 512 (0x200) >2019-10-14 14:52:34,172 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) min_io_size = 0 (0x0) >2019-10-14 14:52:34,172 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) opt_io_size = 0 (0x0) >2019-10-14 14:52:34,172 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) discard_granularity = 4096 (0x1000) >2019-10-14 14:52:34,172 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) write-cache = "auto" >2019-10-14 14:52:34,172 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) share-rw = false >2019-10-14 14:52:34,172 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rerror = "auto" >2019-10-14 14:52:34,172 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) werror = "auto" >2019-10-14 14:52:34,173 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ver = "2.5+" >2019-10-14 14:52:34,173 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) serial = "" >2019-10-14 14:52:34,173 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) vendor = "QEMU" >2019-10-14 14:52:34,173 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) product = "QEMU HARDDISK" >2019-10-14 14:52:34,173 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) removable = false >2019-10-14 14:52:34,173 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dpofua = false >2019-10-14 14:52:34,173 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) wwn = 0 (0x0) >2019-10-14 14:52:34,174 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) port_wwn = 0 (0x0) >2019-10-14 14:52:34,174 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) port_index = 0 (0x0) >2019-10-14 14:52:34,174 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) max_unmap_size = 1073741824 (0x40000000) >2019-10-14 14:52:34,174 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) max_io_size = 2147483647 (0x7fffffff) >2019-10-14 14:52:34,174 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rotation_rate = 0 (0x0) >2019-10-14 14:52:34,174 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) scsi_version = 5 (0x5) >2019-10-14 14:52:34,174 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) cyls = 16383 (0x3fff) >2019-10-14 14:52:34,175 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) heads = 16 (0x10) >2019-10-14 14:52:34,175 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) secs = 63 (0x3f) >2019-10-14 14:52:34,175 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) channel = 0 (0x0) >2019-10-14 14:52:34,175 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) scsi-id = 0 (0x0) >2019-10-14 14:52:34,175 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) lun = 0 (0x0) >2019-10-14 14:52:34,175 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: nec-usb-xhci, id "usb1" >2019-10-14 14:52:34,175 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) msi = "auto" >2019-10-14 14:52:34,176 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) msix = "auto" >2019-10-14 14:52:34,176 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) superspeed-ports-first = true >2019-10-14 14:52:34,176 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) force-pcie-endcap = false >2019-10-14 14:52:34,176 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) intrs = 16 (0x10) >2019-10-14 14:52:34,176 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) slots = 64 (0x40) >2019-10-14 14:52:34,176 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) streams = true >2019-10-14 14:52:34,176 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) p2 = 4 (0x4) >2019-10-14 14:52:34,177 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) p3 = 4 (0x4) >2019-10-14 14:52:34,177 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr = 03.0 >2019-10-14 14:52:34,177 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) romfile = "" >2019-10-14 14:52:34,177 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rombar = 1 (0x1) >2019-10-14 14:52:34,177 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) multifunction = false >2019-10-14 14:52:34,177 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) command_serr_enable = true >2019-10-14 14:52:34,177 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnksta-dllla = true >2019-10-14 14:52:34,178 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-extcap-init = true >2019-10-14 14:52:34,178 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) class USB controller, addr 00:03.0, pci id 1033:0194 (sub 1af4:1100) >2019-10-14 14:52:34,178 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 0: mem at 0x81020000 [0x81023fff] >2019-10-14 14:52:34,178 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: usb1.0 >2019-10-14 14:52:34,178 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type usb-bus >2019-10-14 14:52:34,178 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: usb-tablet, id "usb-tablet1" >2019-10-14 14:52:34,178 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) usb_version = 2 (0x2) >2019-10-14 14:52:34,179 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) display = "" >2019-10-14 14:52:34,179 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) head = 0 (0x0) >2019-10-14 14:52:34,179 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) port = "1" >2019-10-14 14:52:34,179 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) serial = "" >2019-10-14 14:52:34,179 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) full-path = true >2019-10-14 14:52:34,179 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) msos-desc = true >2019-10-14 14:52:34,179 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr 0.1, port 1, speed 480, name QEMU USB Tablet, attached >2019-10-14 14:52:34,180 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: VGA, id "" >2019-10-14 14:52:34,180 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) vgamem_mb = 16 (0x10) >2019-10-14 14:52:34,180 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mmio = true >2019-10-14 14:52:34,180 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) qemu-extended-regs = true >2019-10-14 14:52:34,180 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr = 02.0 >2019-10-14 14:52:34,180 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) romfile = "vgabios-stdvga.bin" >2019-10-14 14:52:34,180 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rombar = 1 (0x1) >2019-10-14 14:52:34,181 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) multifunction = false >2019-10-14 14:52:34,181 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) command_serr_enable = true >2019-10-14 14:52:34,181 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnksta-dllla = true >2019-10-14 14:52:34,181 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-extcap-init = true >2019-10-14 14:52:34,181 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) class VGA controller, addr 00:02.0, pci id 1234:1111 (sub 1af4:1100) >2019-10-14 14:52:34,181 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 0: mem at 0x80000000 [0x80ffffff] >2019-10-14 14:52:34,181 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 2: mem at 0x81000000 [0x81000fff] >2019-10-14 14:52:34,182 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 6: mem at 0xffffffffffffffff [0xfffe] >2019-10-14 14:52:34,182 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: spapr-vio-bridge, id "" >2019-10-14 14:52:34,182 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: spapr-vio >2019-10-14 14:52:34,182 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type spapr-vio-bus >2019-10-14 14:52:34,182 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: spapr-vty, id "vty@30000000" >2019-10-14 14:52:34,182 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) reg = 805306368 (0x30000000) >2019-10-14 14:52:34,182 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) chardev = "serial_id_serial0" >2019-10-14 14:52:34,183 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) irq = 4103 (0x1007) >2019-10-14 14:52:34,183 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: spapr-nvram, id "nvram@71000000" >2019-10-14 14:52:34,183 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) reg = 1895825408 (0x71000000) >2019-10-14 14:52:34,183 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) drive = "" >2019-10-14 14:52:34,183 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) irq = 4098 (0x1002) >2019-10-14 14:52:34,197 nic_hotplug L0181 INFO | Check if new interface gets ip address >2019-10-14 14:52:42,022 ip_sniffing L0053 DEBUG| Updated HWADDR (9a:46:47:48:49:4a)<->(192.168.122.83) IP pair into address cache >2019-10-14 14:52:42,209 virt_vm L0862 DEBUG| Found/Verified IP 192.168.122.83 for VM avocado-vt-vm1 NIC 0 >2019-10-14 14:52:42,209 nic_hotplug L0189 INFO | Got the ip address of new nic: 192.168.122.83 >2019-10-14 14:52:42,209 nic_hotplug L0191 INFO | Ping guest's new ip from host >2019-10-14 14:52:42,210 utils_net L0788 INFO | The command of Ping is: ping 192.168.122.1 -c 10 >2019-10-14 14:52:42,302 client L0605 DEBUG| PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data. >2019-10-14 14:52:42,302 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=1 ttl=64 time=0.047 ms >2019-10-14 14:52:43,312 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=2 ttl=64 time=0.016 ms >2019-10-14 14:52:44,362 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=3 ttl=64 time=0.014 ms >2019-10-14 14:52:45,392 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=4 ttl=64 time=0.016 ms >2019-10-14 14:52:46,432 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=5 ttl=64 time=0.013 ms >2019-10-14 14:52:47,482 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=6 ttl=64 time=0.012 ms >2019-10-14 14:52:48,522 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=7 ttl=64 time=0.012 ms >2019-10-14 14:52:49,562 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=8 ttl=64 time=0.013 ms >2019-10-14 14:52:50,592 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=9 ttl=64 time=0.013 ms >2019-10-14 14:52:51,632 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=10 ttl=64 time=0.026 ms >2019-10-14 14:52:51,632 client L0605 DEBUG| >2019-10-14 14:52:51,632 client L0605 DEBUG| --- 192.168.122.1 ping statistics --- >2019-10-14 14:52:51,632 client L0605 DEBUG| 10 packets transmitted, 10 received, 0% packet loss, time 339ms >2019-10-14 14:52:51,632 client L0605 DEBUG| rtt min/avg/max/mdev = 0.012/0.018/0.047/0.010 ms >2019-10-14 14:52:51,633 client L0605 DEBUG| (Process terminated with status 0) >2019-10-14 14:52:51,712 nic_hotplug L0198 INFO | Reboot vm after hotplug nic >2019-10-14 14:52:51,712 error_context L0097 INFO | Context: rebooting 'avocado-vt-vm1' >2019-10-14 14:52:51,713 qemu_vm L4236 DEBUG| Send command: shutdown -r now >2019-10-14 14:52:51,713 client L1126 DEBUG| Sending command: shutdown -r now >2019-10-14 14:53:51,718 error_context L0079 INFO | Context: rebooting 'avocado-vt-vm1' --> waiting for guest to go down >2019-10-14 14:53:51,719 error_context L0079 INFO | Context: rebooting 'avocado-vt-vm1' --> logging in after reboot >2019-10-14 14:53:51,719 virt_vm L1338 DEBUG| Attempting to log into 'avocado-vt-vm1' via serial console (timeout 180s) >2019-10-14 14:54:04,791 virt_vm L0862 DEBUG| Found/Verified IP 192.168.122.83 for VM avocado-vt-vm1 NIC 0 >2019-10-14 14:54:04,791 nic_hotplug L0212 INFO | Ping guest's new ip from host >2019-10-14 14:54:04,792 utils_net L0788 INFO | The command of Ping is: ping 192.168.122.1 -c 10 >2019-10-14 14:54:04,884 client L0605 DEBUG| PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data. >2019-10-14 14:54:04,885 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=1 ttl=64 time=0.061 ms >2019-10-14 14:54:05,952 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=2 ttl=64 time=0.061 ms >2019-10-14 14:54:06,992 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=3 ttl=64 time=0.047 ms >2019-10-14 14:54:08,032 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=4 ttl=64 time=0.013 ms >2019-10-14 14:54:09,072 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=5 ttl=64 time=0.011 ms >2019-10-14 14:54:10,112 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=6 ttl=64 time=0.027 ms >2019-10-14 14:54:11,152 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=7 ttl=64 time=0.011 ms >2019-10-14 14:54:12,192 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=8 ttl=64 time=0.010 ms >2019-10-14 14:54:13,232 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=9 ttl=64 time=0.012 ms >2019-10-14 14:54:14,272 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=10 ttl=64 time=0.012 ms >2019-10-14 14:54:14,272 client L0605 DEBUG| >2019-10-14 14:54:14,272 client L0605 DEBUG| --- 192.168.122.1 ping statistics --- >2019-10-14 14:54:14,272 client L0605 DEBUG| 10 packets transmitted, 10 received, 0% packet loss, time 397ms >2019-10-14 14:54:14,273 client L0605 DEBUG| rtt min/avg/max/mdev = 0.010/0.026/0.061/0.021 ms >2019-10-14 14:54:14,281 client L0605 DEBUG| (Process terminated with status 0) >2019-10-14 14:54:14,297 nic_hotplug L0219 INFO | Pause vm >2019-10-14 14:54:14,297 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'stop' >2019-10-14 14:54:14,297 qemu_monitor L1700 DEBUG| Send command: {'execute': 'stop', 'id': '6x38obas'} >2019-10-14 14:54:14,459 nic_hotplug L0221 INFO | Resume vm >2019-10-14 14:54:14,459 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'cont' >2019-10-14 14:54:14,460 qemu_monitor L1700 DEBUG| Send command: {'execute': 'cont', 'id': 'tm3BHcbI'} >2019-10-14 14:54:14,462 nic_hotplug L0223 INFO | Ping guest's new ip after resume >2019-10-14 14:54:14,462 utils_net L0788 INFO | The command of Ping is: ping 192.168.122.1 -c 10 >2019-10-14 14:54:14,552 client L0605 DEBUG| PING 192.168.122.1 (192.168.122.1) 56(84) bytes of data. >2019-10-14 14:54:14,552 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=1 ttl=64 time=0.045 ms >2019-10-14 14:54:15,642 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=2 ttl=64 time=0.011 ms >2019-10-14 14:54:16,672 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=3 ttl=64 time=0.012 ms >2019-10-14 14:54:17,712 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=4 ttl=64 time=0.011 ms >2019-10-14 14:54:18,762 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=5 ttl=64 time=0.010 ms >2019-10-14 14:54:19,802 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=6 ttl=64 time=0.034 ms >2019-10-14 14:54:20,832 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=7 ttl=64 time=0.012 ms >2019-10-14 14:54:21,872 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=8 ttl=64 time=0.012 ms >2019-10-14 14:54:22,912 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=9 ttl=64 time=0.011 ms >2019-10-14 14:54:23,952 client L0605 DEBUG| 64 bytes from 192.168.122.1: icmp_seq=10 ttl=64 time=0.012 ms >2019-10-14 14:54:23,962 client L0605 DEBUG| >2019-10-14 14:54:23,962 client L0605 DEBUG| --- 192.168.122.1 ping statistics --- >2019-10-14 14:54:23,962 client L0605 DEBUG| 10 packets transmitted, 10 received, 0% packet loss, time 409ms >2019-10-14 14:54:23,962 client L0605 DEBUG| rtt min/avg/max/mdev = 0.010/0.017/0.045/0.011 ms >2019-10-14 14:54:23,963 client L0605 DEBUG| (Process terminated with status 0) >2019-10-14 14:54:23,964 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'device_del' >2019-10-14 14:54:23,964 qemu_monitor L1700 DEBUG| Send command: {'execute': 'device_del', 'arguments': {'id': 'hotplug_nic1'}, 'id': 'TrRZnunJ'} >2019-10-14 14:54:23,966 qemu_vm L3776 INFO | waiting for the guest to finish the unplug >2019-10-14 14:54:28,971 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'info qtree' (via Human Monitor) >2019-10-14 14:54:28,975 qemu_monitor L1656 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Response to 'info qtree' (re-formated) >2019-10-14 14:54:28,975 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: main-system-bus >2019-10-14 14:54:28,975 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type System >2019-10-14 14:54:28,975 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: spapr-pci-host-bridge, id "" >2019-10-14 14:54:28,976 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) index = 0 (0x0) >2019-10-14 14:54:28,976 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mem_win_size = 2147483648 (0x80000000) >2019-10-14 14:54:28,976 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mem64_win_size = 1099511627776 (0x10000000000) >2019-10-14 14:54:28,976 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) io_win_size = 65536 (0x10000) >2019-10-14 14:54:28,976 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dynamic-reconfiguration = true >2019-10-14 14:54:28,976 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dma_win_addr = 0 (0x0) >2019-10-14 14:54:28,976 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dma_win_size = 1073741824 (0x40000000) >2019-10-14 14:54:28,977 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dma64_win_addr = 576460752303423488 (0x800000000000000) >2019-10-14 14:54:28,977 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ddw = true >2019-10-14 14:54:28,977 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) pgsz = 69632 (0x11000) >2019-10-14 14:54:28,977 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) numa_node = 4294967295 (0xffffffff) >2019-10-14 14:54:28,977 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) pre-2.8-migration = false >2019-10-14 14:54:28,977 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) pcie-extended-configuration-space = true >2019-10-14 14:54:28,977 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) gpa = 70368744177664 (0x400000000000) >2019-10-14 14:54:28,978 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) atsd = 140737488355328 (0x800000000000) >2019-10-14 14:54:28,978 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: pci.0 >2019-10-14 14:54:28,978 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type PCI >2019-10-14 14:54:28,978 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: virtio-scsi-pci, id "virtio_scsi_pci0" >2019-10-14 14:54:28,978 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ioeventfd = true >2019-10-14 14:54:28,978 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) vectors = 4 (0x4) >2019-10-14 14:54:28,978 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) virtio-pci-bus-master-bug-migration = false >2019-10-14 14:54:28,979 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) disable-legacy = "off" >2019-10-14 14:54:28,979 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) disable-modern = false >2019-10-14 14:54:28,979 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) migrate-extra = true >2019-10-14 14:54:28,979 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) modern-pio-notify = false >2019-10-14 14:54:28,979 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-disable-pcie = false >2019-10-14 14:54:28,979 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) page-per-vq = false >2019-10-14 14:54:28,979 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-ignore-backend-features = false >2019-10-14 14:54:28,980 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ats = false >2019-10-14 14:54:28,980 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-deverr-init = true >2019-10-14 14:54:28,980 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnkctl-init = true >2019-10-14 14:54:28,980 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-pm-init = true >2019-10-14 14:54:28,980 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr = 04.0 >2019-10-14 14:54:28,980 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) romfile = "" >2019-10-14 14:54:28,980 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rombar = 1 (0x1) >2019-10-14 14:54:28,981 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) multifunction = false >2019-10-14 14:54:28,981 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) command_serr_enable = true >2019-10-14 14:54:28,981 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnksta-dllla = true >2019-10-14 14:54:28,981 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-extcap-init = true >2019-10-14 14:54:28,981 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) class SCSI controller, addr 00:04.0, pci id 1af4:1004 (sub 1af4:0008) >2019-10-14 14:54:28,981 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 0: i/o at 0x40 [0x7f] >2019-10-14 14:54:28,981 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 1: mem at 0x82030000 [0x82030fff] >2019-10-14 14:54:28,982 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 4: mem at 0x210000010000 [0x210000013fff] >2019-10-14 14:54:28,982 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: virtio-bus >2019-10-14 14:54:28,982 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type virtio-pci-bus >2019-10-14 14:54:28,982 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: virtio-scsi-device, id "" >2019-10-14 14:54:28,982 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) num_queues = 1 (0x1) >2019-10-14 14:54:28,982 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) virtqueue_size = 128 (0x80) >2019-10-14 14:54:28,982 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) max_sectors = 65535 (0xffff) >2019-10-14 14:54:28,983 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) cmd_per_lun = 128 (0x80) >2019-10-14 14:54:28,983 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) hotplug = true >2019-10-14 14:54:28,983 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) param_change = true >2019-10-14 14:54:28,983 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) iothread = "" >2019-10-14 14:54:28,983 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) indirect_desc = true >2019-10-14 14:54:28,983 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) event_idx = true >2019-10-14 14:54:28,983 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) notify_on_empty = true >2019-10-14 14:54:28,984 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) any_layout = true >2019-10-14 14:54:28,984 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) iommu_platform = false >2019-10-14 14:54:28,984 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: virtio_scsi_pci0.0 >2019-10-14 14:54:28,984 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type SCSI >2019-10-14 14:54:28,984 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: scsi-hd, id "image1" >2019-10-14 14:54:28,984 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) drive = "drive_image1" >2019-10-14 14:54:28,984 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) logical_block_size = 512 (0x200) >2019-10-14 14:54:28,985 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) physical_block_size = 512 (0x200) >2019-10-14 14:54:28,985 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) min_io_size = 0 (0x0) >2019-10-14 14:54:28,985 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) opt_io_size = 0 (0x0) >2019-10-14 14:54:28,985 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) discard_granularity = 4096 (0x1000) >2019-10-14 14:54:28,985 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) write-cache = "auto" >2019-10-14 14:54:28,985 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) share-rw = false >2019-10-14 14:54:28,985 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rerror = "auto" >2019-10-14 14:54:28,986 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) werror = "auto" >2019-10-14 14:54:28,986 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) ver = "2.5+" >2019-10-14 14:54:28,986 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) serial = "" >2019-10-14 14:54:28,986 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) vendor = "QEMU" >2019-10-14 14:54:28,986 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) product = "QEMU HARDDISK" >2019-10-14 14:54:28,986 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) removable = false >2019-10-14 14:54:28,986 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dpofua = false >2019-10-14 14:54:28,987 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) wwn = 0 (0x0) >2019-10-14 14:54:28,987 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) port_wwn = 0 (0x0) >2019-10-14 14:54:28,987 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) port_index = 0 (0x0) >2019-10-14 14:54:28,987 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) max_unmap_size = 1073741824 (0x40000000) >2019-10-14 14:54:28,987 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) max_io_size = 2147483647 (0x7fffffff) >2019-10-14 14:54:28,987 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rotation_rate = 0 (0x0) >2019-10-14 14:54:28,987 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) scsi_version = 5 (0x5) >2019-10-14 14:54:28,987 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) cyls = 16383 (0x3fff) >2019-10-14 14:54:28,988 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) heads = 16 (0x10) >2019-10-14 14:54:28,988 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) secs = 63 (0x3f) >2019-10-14 14:54:28,988 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) channel = 0 (0x0) >2019-10-14 14:54:28,988 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) scsi-id = 0 (0x0) >2019-10-14 14:54:28,988 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) lun = 0 (0x0) >2019-10-14 14:54:28,988 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: nec-usb-xhci, id "usb1" >2019-10-14 14:54:28,988 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) msi = "auto" >2019-10-14 14:54:28,989 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) msix = "auto" >2019-10-14 14:54:28,989 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) superspeed-ports-first = true >2019-10-14 14:54:28,989 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) force-pcie-endcap = false >2019-10-14 14:54:28,989 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) intrs = 16 (0x10) >2019-10-14 14:54:28,989 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) slots = 64 (0x40) >2019-10-14 14:54:28,989 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) streams = true >2019-10-14 14:54:28,989 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) p2 = 4 (0x4) >2019-10-14 14:54:28,990 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) p3 = 4 (0x4) >2019-10-14 14:54:28,990 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr = 03.0 >2019-10-14 14:54:28,990 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) romfile = "" >2019-10-14 14:54:28,990 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rombar = 1 (0x1) >2019-10-14 14:54:28,990 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) multifunction = false >2019-10-14 14:54:28,990 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) command_serr_enable = true >2019-10-14 14:54:28,990 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnksta-dllla = true >2019-10-14 14:54:28,991 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-extcap-init = true >2019-10-14 14:54:28,991 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) class USB controller, addr 00:03.0, pci id 1033:0194 (sub 1af4:1100) >2019-10-14 14:54:28,991 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 0: mem at 0x82020000 [0x82023fff] >2019-10-14 14:54:28,991 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: usb1.0 >2019-10-14 14:54:28,991 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type usb-bus >2019-10-14 14:54:28,991 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: usb-tablet, id "usb-tablet1" >2019-10-14 14:54:28,991 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) usb_version = 2 (0x2) >2019-10-14 14:54:28,992 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) display = "" >2019-10-14 14:54:28,992 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) head = 0 (0x0) >2019-10-14 14:54:28,992 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) port = "1" >2019-10-14 14:54:28,992 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) serial = "" >2019-10-14 14:54:28,992 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) full-path = true >2019-10-14 14:54:28,992 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) msos-desc = true >2019-10-14 14:54:28,992 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr 0.1, port 1, speed 480, name QEMU USB Tablet, attached >2019-10-14 14:54:28,993 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: VGA, id "" >2019-10-14 14:54:28,993 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) vgamem_mb = 16 (0x10) >2019-10-14 14:54:28,993 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) mmio = true >2019-10-14 14:54:28,993 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) qemu-extended-regs = true >2019-10-14 14:54:28,993 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) addr = 02.0 >2019-10-14 14:54:28,993 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) romfile = "vgabios-stdvga.bin" >2019-10-14 14:54:28,993 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) rombar = 1 (0x1) >2019-10-14 14:54:28,994 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) multifunction = false >2019-10-14 14:54:28,994 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) command_serr_enable = true >2019-10-14 14:54:28,994 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-lnksta-dllla = true >2019-10-14 14:54:28,994 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) x-pcie-extcap-init = true >2019-10-14 14:54:28,994 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) class VGA controller, addr 00:02.0, pci id 1234:1111 (sub 1af4:1100) >2019-10-14 14:54:28,994 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 0: mem at 0x81000000 [0x81ffffff] >2019-10-14 14:54:28,994 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 2: mem at 0x82000000 [0x82000fff] >2019-10-14 14:54:28,995 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bar 6: mem at 0xffffffffffffffff [0xfffe] >2019-10-14 14:54:28,995 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: spapr-vio-bridge, id "" >2019-10-14 14:54:28,995 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) bus: spapr-vio >2019-10-14 14:54:28,995 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) type spapr-vio-bus >2019-10-14 14:54:28,995 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: spapr-vty, id "vty@30000000" >2019-10-14 14:54:28,995 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) reg = 805306368 (0x30000000) >2019-10-14 14:54:28,995 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) chardev = "serial_id_serial0" >2019-10-14 14:54:28,996 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) irq = 4103 (0x1007) >2019-10-14 14:54:28,996 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) dev: spapr-nvram, id "nvram@71000000" >2019-10-14 14:54:28,996 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) reg = 1895825408 (0x71000000) >2019-10-14 14:54:28,996 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) drive = "" >2019-10-14 14:54:28,996 qemu_monitor L1632 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) irq = 4098 (0x1002) >2019-10-14 14:54:28,997 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'netdev_del' >2019-10-14 14:54:28,997 qemu_monitor L1700 DEBUG| Send command: {'execute': 'netdev_del', 'arguments': {'id': 'idHHrRMa'}, 'id': 'JS41bXjF'} >2019-10-14 14:54:29,032 qemu_monitor L0344 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'info network' (via Human Monitor) >2019-10-14 14:54:29,043 ip_sniffing L0068 DEBUG| Dropped the address cache of HWADDR (9a:46:47:48:49:4a) >2019-10-14 14:54:29,043 nic_hotplug L0244 INFO | Re-enabling the primary link(s) >2019-10-14 14:54:29,043 nic_hotplug L0247 INFO | Reboot vm to verify it alive after hotunplug nic(s) >2019-10-14 14:54:29,043 error_context L0097 INFO | Context: rebooting 'avocado-vt-vm1' >2019-10-14 14:54:29,044 virt_vm L1338 DEBUG| Attempting to log into 'avocado-vt-vm1' via serial console (timeout 240s) >2019-10-14 14:54:40,054 qemu_vm L4236 DEBUG| Send command: shutdown -r now >2019-10-14 14:54:40,054 client L1126 DEBUG| Sending command: shutdown -r now >2019-10-14 14:55:40,061 error_context L0079 INFO | Context: rebooting 'avocado-vt-vm1' --> waiting for guest to go down >2019-10-14 14:55:40,061 error_context L0079 INFO | Context: rebooting 'avocado-vt-vm1' --> logging in after reboot >2019-10-14 14:55:40,062 virt_vm L1338 DEBUG| Attempting to log into 'avocado-vt-vm1' via serial console (timeout 169s) >2019-10-14 14:55:52,915 virt_vm L1338 DEBUG| Attempting to log into 'avocado-vt-vm1' via serial console (timeout 240s) >2019-10-14 14:56:03,924 client L1126 DEBUG| Sending command: dmesg -T -l 0,1,2|grep . >2019-10-14 14:56:04,032 client L1126 DEBUG| Sending command: echo $? >2019-10-14 14:56:04,165 qemu_vm L3248 DEBUG| Destroying VM avocado-vt-vm1 (PID 82171) >2019-10-14 14:56:04,165 qemu_vm L3150 DEBUG| Shutting down VM avocado-vt-vm1 (shell) >2019-10-14 14:56:21,152 client L0605 INFO | [qemu output] (Process terminated with status 0) >2019-10-14 14:56:21,180 qemu_vm L3255 DEBUG| VM avocado-vt-vm1 down (shell) >2019-10-14 14:56:21,266 qemu_storage L0508 DEBUG| Checking image file /var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2 >2019-10-14 14:56:21,266 qemu_storage L0404 DEBUG| Run qemu-img info command on /var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2 >2019-10-14 14:56:21,267 process L0626 INFO | Running '/usr/bin/qemu-img info -U /var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2 --output=human' >2019-10-14 14:56:21,274 process L0458 DEBUG| [stdout] image: /var/lib/avocado/data/avocado-vt/images/rhel7devel-ppc64le.qcow2 >2019-10-14 14:56:21,275 process L0714 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.0055310726165771484s >2019-10-14 14:56:21,275 process L0458 DEBUG| [stdout] file format: qcow2 >2019-10-14 14:56:21,275 process L0458 DEBUG| [stdout] virtual size: 10G (10737418240 bytes) >2019-10-14 14:56:21,276 process L0458 DEBUG| [stdout] disk size: 6.4G >2019-10-14 14:56:21,276 process L0458 DEBUG| [stdout] cluster_size: 65536 >2019-10-14 14:56:21,276 process L0458 DEBUG| [stdout] Format specific information: >2019-10-14 14:56:21,276 process L0458 DEBUG| [stdout] compat: 1.1 >2019-10-14 14:56:21,276 process L0458 DEBUG| [stdout] lazy refcounts: false >2019-10-14 14:56:21,277 process L0458 DEBUG| [stdout] refcount bits: 16 >2019-10-14 14:56:21,277 process L0458 DEBUG| [stdout] corrupt: false >2019-10-14 14:56:21,335 storage L0385 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-14 14:56:22,342 env_process L1627 WARNI| avocado-vt-vm1 is not alive. Can't query the register status >2019-10-14 14:57:06,534 env_process L1613 DEBUG| Thread quit. Used to failed to get register info from guest 20191014-145136-VeSFZVlQ for 10 times. >2019-10-14 14:57:06,702 process L0626 INFO | Running 'true' >2019-10-14 14:57:06,705 process L0714 INFO | Command 'true' finished with 0 after 0.0007767677307128906s >2019-10-14 14:57:06,705 process L0626 INFO | Running 'ps -o comm 1' >2019-10-14 14:57:06,736 process L0458 DEBUG| [stdout] COMMAND >2019-10-14 14:57:06,736 process L0714 INFO | Command 'ps -o comm 1' finished with 0 after 0.028914928436279297s >2019-10-14 14:57:06,736 process L0458 DEBUG| [stdout] systemd >2019-10-14 14:57:06,762 process L0626 INFO | Running 'grep revision /proc/cpuinfo | awk '{print $3}' | head -n 1' >2019-10-14 14:57:06,766 process L0458 DEBUG| [stdout] 2.1 >2019-10-14 14:57:06,766 process L0714 INFO | Command 'grep revision /proc/cpuinfo | awk '{print $3}' | head -n 1' finished with 0 after 0.002681732177734375s >2019-10-14 14:57:06,794 test L0298 DEBUG| DATA (filename=output.expected) => NOT FOUND (data sources: variant, test, file) >2019-10-14 14:57:06,794 test L0298 DEBUG| DATA (filename=stdout.expected) => NOT FOUND (data sources: variant, test, file) >2019-10-14 14:57:06,794 test L0298 DEBUG| DATA (filename=stderr.expected) => NOT FOUND (data sources: variant, test, file) >2019-10-14 14:57:06,805 test L1018 INFO | PASS 1-type_specific.io-github-autotest-qemu.nic_hotplug.vhost_nic.nic_virtio >2019-10-14 14:57:06,805 test L1001 INFO | >2019-10-14 14:57:07,018 job L0495 INFO | Test results available in /root/avocado/job-results/job-2019-10-14T14.51-c751b0b >2019-10-14 14:57:07,020 extension L0189 DEBUG| found extension EntryPoint.parse('json = avocado.plugins.jsonresult:JSONResult') >2019-10-14 14:57:07,020 extension L0189 DEBUG| found extension EntryPoint.parse('xunit = avocado.plugins.xunit:XUnitResult') >2019-10-14 14:57:07,020 extension L0189 DEBUG| found extension EntryPoint.parse('zip_archive = avocado.plugins.archive:Archive')
<b>You cannot view the attachment while viewing its details because your browser does not support IFRAMEs. <a href="attachment.cgi?id=1626926">View the attachment on a separate page</a>.</b>
View Attachment As Raw
Actions:
View
Attachments on
bug 1762906
:
1626925
| 1626926 |
1627242