Attachment 844381 Details for Bug 1047763 – DEBUG file

DEBUG file

virt.qemu.repeat1.smp_1.2048m.Host_RHEL.7.0.qcow2.virtio_blk.up.virtio_net.SLES.11.3.x86_64.balloon_check.balloon_evict.guest_s4.DEBUG (text/plain), 29.95 KB, created by CongLi on 2014-01-02 07:53:18 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: CongLi

Created: 2014-01-02 07:53:18 UTC

Size: 29.95 KB

patch

obsolete

>12/31 19:16:45 DEBUG|      test:0310| Profilers present. Profiling run started
>12/31 19:16:45 DEBUG|     utils:0109| Running 'git describe --abbrev=4'
>12/31 19:16:46 DEBUG|     utils:0109| Running 'git rev-parse --abbrev-ref HEAD'
>12/31 19:16:46 DEBUG|     utils:0109| Running 'git show --summary --pretty='%H' | head -1'
>12/31 19:16:46 INFO |      virt:0057| Virt Test '0.15.1-master-5340-g7ff43', Branch 'master', SHA1 '7ff43ea5269b2ae57e38276ccba2689e43a8e1e6'
>12/31 19:16:46 DEBUG|      virt:0059| Test parameters:
>12/31 19:16:46 DEBUG|      virt:0063|     _name_map_file = {'tests-example.cfg': 'repeat1.smp_1.2048m.memory_balloon', 'subtests.cfg': '(subtest=type_specific).(subtest=balloon_check).balloon_evict.guest_s4', 'guest-hw.cfg': 'no_lvm_support.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_blk.up.virtio_net', 'guest-os-internal.cfg': 'Linux.SLES.11.3.x86_64', 'host-kernel-internal.cfg': 'Host_RHEL.7.0', 'guest-hw-internal.cfg': 'vnc.local_stg'}
>12/31 19:16:46 DEBUG|      virt:0063|     _short_name_map_file = {'tests-example.cfg': 'repeat1.smp_1.2048m.memory_balloon', 'subtests.cfg': 'type_specific.balloon_check.balloon_evict.guest_s4', 'guest-hw.cfg': 'no_lvm_support.filesystem.no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_blk.up.virtio_net', 'guest-os-internal.cfg': 'Linux.SLES.11.3.x86_64', 'host-kernel-internal.cfg': 'Host_RHEL.7.0', 'guest-hw-internal.cfg': 'vnc.local_stg'}
>12/31 19:16:46 DEBUG|      virt:0063|     address_range_base_mac_r1 = 00:11:22:33:AB:08
>12/31 19:16:46 DEBUG|      virt:0063|     address_ranges = r1
>12/31 19:16:46 DEBUG|      virt:0063|     always_use_tcpdump = yes
>12/31 19:16:46 DEBUG|      virt:0063|     auto_cpu_model = yes
>12/31 19:16:46 DEBUG|      virt:0063|     backup_dir = images/
>12/31 19:16:46 DEBUG|      virt:0063|     backup_image = no
>12/31 19:16:46 DEBUG|      virt:0063|     backup_image_on_check_error = no
>12/31 19:16:46 DEBUG|      virt:0063|     balloon_type = evict
>12/31 19:16:46 DEBUG|      virt:0063|     boot_menu = off
>12/31 19:16:46 DEBUG|      virt:0063|     boot_once = c
>12/31 19:16:46 DEBUG|      virt:0063|     boot_order = cdn
>12/31 19:16:46 DEBUG|      virt:0063|     cd_format = ide
>12/31 19:16:46 DEBUG|      virt:0063|     cdrom_check_cdrom_pattern = /dev/cdrom-\w+|/dev/cdrom\d*
>12/31 19:16:46 DEBUG|      virt:0063|     cdrom_get_cdrom_cmd = ls /dev/cdrom*
>12/31 19:16:46 DEBUG|      virt:0063|     cdrom_test_cmd = dd if=%s of=/dev/null bs=1 count=1
>12/31 19:16:46 DEBUG|      virt:0063|     cdroms = cd1
>12/31 19:16:46 DEBUG|      virt:0063|     check_image = yes
>12/31 19:16:46 DEBUG|      virt:0063|     check_img = no
>12/31 19:16:46 DEBUG|      virt:0063|     convert_ppm_files_to_png = yes
>12/31 19:16:46 DEBUG|      virt:0063|     convert_ppm_files_to_png_on_error = yes
>12/31 19:16:46 DEBUG|      virt:0063|     cpu_chk_cmd = ls /sys/devices/system/cpu | egrep -c "cpu[0-9]+$"
>12/31 19:16:46 DEBUG|      virt:0063|     cpu_model = qemu64
>12/31 19:16:46 DEBUG|      virt:0063|     cpu_model_flags = 
>12/31 19:16:46 DEBUG|      virt:0063|     dd_timeout = 900
>12/31 19:16:46 DEBUG|      virt:0063|     default_cpu_model = qemu64
>12/31 19:16:46 DEBUG|      virt:0063|     dep = ['repeat1.smp_1.2048m.memory_balloon.Host_RHEL.7.0.vnc.local_stg.no_lvm_support.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_blk.up.virtio_net.Linux.SLES.11.3.x86_64.(subtest=type_specific).install', 'repeat1.smp_1.2048m.memory_balloon.Host_RHEL.7.0.vnc.local_stg.no_lvm_support.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_blk.up.virtio_net.Linux.SLES.11.3.x86_64.(subtest=type_specific).setup', 'repeat1.smp_1.2048m.memory_balloon.Host_RHEL.7.0.vnc.local_stg.no_lvm_support.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_blk.up.virtio_net.Linux.SLES.11.3.x86_64.(subtest=type_specific).image_copy', 'repeat1.smp_1.2048m.memory_balloon.Host_RHEL.7.0.vnc.local_stg.no_lvm_support.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_blk.up.virtio_net.Linux.SLES.11.3.x86_64.(subtest=type_specific).unattended_install.cdrom']
>12/31 19:16:46 DEBUG|      virt:0063|     display = vnc
>12/31 19:16:46 DEBUG|      virt:0063|     drive_cache = unsafe
>12/31 19:16:46 DEBUG|      virt:0063|     drive_format = virtio
>12/31 19:16:46 DEBUG|      virt:0063|     drive_index_cd1 = 1
>12/31 19:16:46 DEBUG|      virt:0063|     drive_index_image1 = 0
>12/31 19:16:46 DEBUG|      virt:0063|     drive_rerror_image1 = 
>12/31 19:16:46 DEBUG|      virt:0063|     drive_werror_image1 = 
>12/31 19:16:46 DEBUG|      virt:0063|     dryrun = yes
>12/31 19:16:46 DEBUG|      virt:0063|     dst_dir = /mnt/linux
>12/31 19:16:46 DEBUG|      virt:0063|     encode_video_files = yes
>12/31 19:16:46 DEBUG|      virt:0063|     extra_params =  -balloon virtio -global PIIX4_PM.disable_s4=0 -no-kvm-pit-reinjection
>12/31 19:16:46 DEBUG|      virt:0063|     file_transfer_client = scp
>12/31 19:16:46 DEBUG|      virt:0063|     file_transfer_port = 22
>12/31 19:16:46 DEBUG|      virt:0063|     free_mem_cmd = cat /proc/meminfo |grep MemFree
>12/31 19:16:46 DEBUG|      virt:0063|     get_time_cmd = date +'TIME: %a %m/%d/%Y %H:%M:%S.%N'
>12/31 19:16:46 DEBUG|      virt:0063|     guest_port_remote_shell = 22
>12/31 19:16:46 DEBUG|      virt:0063|     guest_suspend_type = disk
>12/31 19:16:46 DEBUG|      virt:0063|     host_kernel_ver_str = Host_RHEL.7.0
>12/31 19:16:46 DEBUG|      virt:0063|     host_setup_flag = 0
>12/31 19:16:46 DEBUG|      virt:0063|     hosttype = small
>12/31 19:16:46 DEBUG|      virt:0063|     image_aio = native
>12/31 19:16:46 DEBUG|      virt:0063|     image_backend = filesystem
>12/31 19:16:46 DEBUG|      virt:0063|     image_boot = yes
>12/31 19:16:46 DEBUG|      virt:0063|     image_chain = 
>12/31 19:16:46 DEBUG|      virt:0063|     image_clone_command = cp --reflink=auto %s %s
>12/31 19:16:46 DEBUG|      virt:0063|     image_format = qcow2
>12/31 19:16:46 DEBUG|      virt:0063|     image_name = images/sles11sp3-64-virtio
>12/31 19:16:46 DEBUG|      virt:0063|     image_raw_device = no
>12/31 19:16:46 DEBUG|      virt:0063|     image_remove_command = rm -rf %s
>12/31 19:16:46 DEBUG|      virt:0063|     image_size = 10G
>12/31 19:16:46 DEBUG|      virt:0063|     image_snapshot = no
>12/31 19:16:46 DEBUG|      virt:0063|     image_unbootable_pattern = Hard Disk.*not a bootable disk
>12/31 19:16:46 DEBUG|      virt:0063|     image_verify_bootable = yes
>12/31 19:16:46 DEBUG|      virt:0063|     images = image1
>12/31 19:16:46 DEBUG|      virt:0063|     images_good = 10.66.90.128:/vol/S2/kvmauto/linux_img
>12/31 19:16:46 DEBUG|      virt:0063|     important_key = guest_name,platform,smp,mem,drive_format,nic_model,type,ksm,image_format,kvm_version,kvm_userspace_version,tag,medium,installation
>12/31 19:16:46 DEBUG|      virt:0063|     inactivity_treshold = 1800
>12/31 19:16:46 DEBUG|      virt:0063|     inactivity_watcher = logimage_remove_commnad = 'rm -rf %s'
>12/31 19:16:46 DEBUG|      virt:0063|     index_enable = yes
>12/31 19:16:46 DEBUG|      virt:0063|     indirect_image_blacklist = /dev/hda[\d]* /dev/sda[\d]* /dev/sg0 /dev/md0
>12/31 19:16:46 DEBUG|      virt:0063|     init_pci_addr = 4
>12/31 19:16:46 DEBUG|      virt:0063|     isa_serials = serial0
>12/31 19:16:46 DEBUG|      virt:0063|     iterations = 1
>12/31 19:16:46 DEBUG|      virt:0063|     job_timeout = 0
>12/31 19:16:46 DEBUG|      virt:0063|     keep_ppm_files = no
>12/31 19:16:46 DEBUG|      virt:0063|     keep_ppm_files_on_error = no
>12/31 19:16:46 DEBUG|      virt:0063|     keep_screendumps = yes
>12/31 19:16:46 DEBUG|      virt:0063|     keep_screendumps_on_error = yes
>12/31 19:16:46 DEBUG|      virt:0063|     keep_video_files = yes
>12/31 19:16:46 DEBUG|      virt:0063|     keep_video_files_on_error = yes
>12/31 19:16:46 DEBUG|      virt:0063|     kill_timeout = 60
>12/31 19:16:46 DEBUG|      virt:0063|     kill_unresponsive_vms = yes
>12/31 19:16:46 DEBUG|      virt:0063|     kill_vm = no
>12/31 19:16:46 DEBUG|      virt:0063|     kill_vm_before_test = no
>12/31 19:16:46 DEBUG|      virt:0063|     kill_vm_gracefully = yes
>12/31 19:16:46 DEBUG|      virt:0063|     kill_vm_in_paused = yes
>12/31 19:16:46 DEBUG|      virt:0063|     kill_vm_on_error = yes
>12/31 19:16:46 DEBUG|      virt:0063|     kill_vm_only_when_paused = yes
>12/31 19:16:46 DEBUG|      virt:0063|     ksm = 0
>12/31 19:16:46 DEBUG|      virt:0063|     kvm_default = {'/sys/module/kvm/parameters/ignore_msrs': 'N', '/sys/module/kvm/parameters/min_timer_period_us': '500', '/sys/module/kvm/parameters/tsc_tolerance_ppm': '250', '/sys/module/kvm/parameters/mmu_audit': 'N'}
>12/31 19:16:46 DEBUG|      virt:0063|     kvm_userspace_ver_cmd = grep -q el5 /proc/version && rpm -qa | grep ^kvm-83-.* || rpm -qa | grep qemu-kvm-[0-9].*-.* | head -n 1
>12/31 19:16:46 DEBUG|      virt:0063|     kvm_ver_cmd = grep -q el5 /proc/version && cat /sys/module/kvm/version || uname -r
>12/31 19:16:46 DEBUG|      virt:0063|     login_timeout = 360
>12/31 19:16:46 DEBUG|      virt:0063|     mac_ip_filter = HWaddr (.\w+:\w+:\w+:\w+:\w+:\w+)\s+?inet addr:(.\d+\.\d+\.\d+\.\d+)
>12/31 19:16:46 DEBUG|      virt:0063|     machine_type = pc
>12/31 19:16:46 DEBUG|      virt:0063|     main_monitor = qmpmonitor1
>12/31 19:16:46 DEBUG|      virt:0063|     main_vm = virt-tests-vm1
>12/31 19:16:46 DEBUG|      virt:0063|     malloc_perturb = no
>12/31 19:16:46 DEBUG|      virt:0063|     mem = 2048
>12/31 19:16:46 DEBUG|      virt:0063|     mem_chk_cmd = dmidecode -t 17 |awk -F: '/Size/ {print $2}'
>12/31 19:16:46 DEBUG|      virt:0063|     mem_chk_cur_cmd = grep MemTotal /proc/meminfo
>12/31 19:16:46 DEBUG|      virt:0063|     mem_chk_re_str = ([0-9]+)
>12/31 19:16:46 DEBUG|      virt:0063|     migration_test_command = uname -r
>12/31 19:16:46 DEBUG|      virt:0063|     monitor_type = qmp
>12/31 19:16:46 DEBUG|      virt:0063|     monitor_type_qmpmonitor1 = qmp
>12/31 19:16:46 DEBUG|      virt:0063|     monitors = qmpmonitor1
>12/31 19:16:46 DEBUG|      virt:0063|     name = repeat1.smp_1.2048m.memory_balloon.Host_RHEL.7.0.vnc.local_stg.no_lvm_support.(image_backend=filesystem).no_9p_export.smallpages.no_pci_assignable.qcow2.virtio_blk.up.virtio_net.Linux.SLES.11.3.x86_64.(subtest=type_specific).(subtest=balloon_check).balloon_evict.guest_s4
>12/31 19:16:46 DEBUG|      virt:0063|     netdev_extra_params = 
>12/31 19:16:46 DEBUG|      virt:0063|     netdev_peer_re = \s{2,}(.*?):.*?peer=(.*?)\n
>12/31 19:16:46 DEBUG|      virt:0063|     netdst = switch
>12/31 19:16:46 DEBUG|      virt:0063|     nettype = bridge
>12/31 19:16:46 DEBUG|      virt:0063|     network_query = ifconfig
>12/31 19:16:46 DEBUG|      virt:0063|     nfs_iso = 10.66.90.128:/vol/S2/kvmauto/iso
>12/31 19:16:46 DEBUG|      virt:0063|     nic_mode = tap
>12/31 19:16:46 DEBUG|      virt:0063|     nic_model = virtio
>12/31 19:16:46 DEBUG|      virt:0063|     nics = nic1
>12/31 19:16:46 DEBUG|      virt:0063|     os_type = linux
>12/31 19:16:46 DEBUG|      virt:0063|     package_check_cmd_kernel = uname -r
>12/31 19:16:46 DEBUG|      virt:0063|     package_version_pattern_kernel = [\.\-\_\w\d]+
>12/31 19:16:46 DEBUG|      virt:0063|     password = 123456
>12/31 19:16:46 DEBUG|      virt:0063|     paused_after_start_vm = no
>12/31 19:16:46 DEBUG|      virt:0063|     pci_assignable = no
>12/31 19:16:46 DEBUG|      virt:0063|     platform = 64
>12/31 19:16:46 DEBUG|      virt:0063|     post_command_noncritical = yes
>12/31 19:16:46 DEBUG|      virt:0063|     post_command_timeout = 600
>12/31 19:16:46 DEBUG|      virt:0063|     pre_check_cmd = grep 'Red Hat Enterprise Linux' /etc/redhat-release
>12/31 19:16:46 DEBUG|      virt:0063|     profilers = kvm_stat 
>12/31 19:16:46 DEBUG|      virt:0063|     qemu_binary = qemu
>12/31 19:16:46 DEBUG|      virt:0063|     qemu_img_binary = qemu-img
>12/31 19:16:46 DEBUG|      virt:0063|     qemu_io_binary = qemu-io
>12/31 19:16:46 DEBUG|      virt:0063|     qemu_quit_after_sub_case = yes
>12/31 19:16:46 DEBUG|      virt:0063|     qemu_sandbox = off
>12/31 19:16:46 DEBUG|      virt:0063|     qxl = on
>12/31 19:16:46 DEBUG|      virt:0063|     qxl_dev_memory = 33554432
>12/31 19:16:46 DEBUG|      virt:0063|     qxl_dev_nr = 1
>12/31 19:16:46 DEBUG|      virt:0063|     ratio = 1
>12/31 19:16:46 DEBUG|      virt:0063|     reboot_command = shutdown -r now
>12/31 19:16:46 DEBUG|      virt:0063|     redirs = 
>12/31 19:16:46 DEBUG|      virt:0063|     remove_image = no
>12/31 19:16:46 DEBUG|      virt:0063|     requires_kernel = [">= 3.2.1-0.8"]
>12/31 19:16:46 DEBUG|      virt:0063|     restore_image = no
>12/31 19:16:46 DEBUG|      virt:0063|     restore_image_on_check_error = no
>12/31 19:16:46 DEBUG|      virt:0063|     rtc_drift = slew
>12/31 19:16:46 DEBUG|      virt:0063|     run_sub_test_after_balloon = yes
>12/31 19:16:46 DEBUG|      virt:0063|     run_tcpdump = yes
>12/31 19:16:46 DEBUG|      virt:0063|     s4_bg_program_chk_cmd = pgrep ping
>12/31 19:16:46 DEBUG|      virt:0063|     s4_bg_program_kill_cmd = pkill ping
>12/31 19:16:46 DEBUG|      virt:0063|     s4_bg_program_setup_cmd = cd /tmp/; nohup ping localhost
>12/31 19:16:46 DEBUG|      virt:0063|     s4_log_chk_cmd = dmesg | grep -E "ACPI: Waking up from system sleep state S4"\|"ACPI: PCI interrupt for device .* disabled"
>12/31 19:16:46 DEBUG|      virt:0063|     s4_start_cmd = echo disk > /sys/power/state
>12/31 19:16:46 DEBUG|      virt:0063|     s4_support_chk_cmd = dmesg -c > /dev/null && grep -q disk /sys/power/state
>12/31 19:16:46 DEBUG|      virt:0063|     screendump_delay = 5
>12/31 19:16:46 DEBUG|      virt:0063|     screendump_quality = 30
>12/31 19:16:46 DEBUG|      virt:0063|     screendump_temp_dir = /dev/shm
>12/31 19:16:46 DEBUG|      virt:0063|     screendump_verbose = no
>12/31 19:16:46 DEBUG|      virt:0063|     services_up_timeout = 30
>12/31 19:16:46 DEBUG|      virt:0063|     session_need_update = yes
>12/31 19:16:46 DEBUG|      virt:0063|     shell_client = ssh
>12/31 19:16:46 DEBUG|      virt:0063|     shell_port = 22
>12/31 19:16:46 DEBUG|      virt:0063|     shell_prompt = ^root@.*[\#\$]\s*$|#
>12/31 19:16:46 DEBUG|      virt:0063|     shortname = repeat1.smp_1.2048m.Host_RHEL.7.0.qcow2.virtio_blk.up.virtio_net.SLES.11.3.x86_64.balloon_check.balloon_evict.guest_s4
>12/31 19:16:46 DEBUG|      virt:0063|     shutdown_command = shutdown -h now
>12/31 19:16:46 DEBUG|      virt:0063|     skip_image_processing = no
>12/31 19:16:46 DEBUG|      virt:0063|     smp = 1
>12/31 19:16:46 DEBUG|      virt:0063|     snapshot_name = vm
>12/31 19:16:46 DEBUG|      virt:0063|     soundcards = 
>12/31 19:16:46 DEBUG|      virt:0063|     spice = disable-ticketing
>12/31 19:16:46 DEBUG|      virt:0063|     spice_addr = 0
>12/31 19:16:46 DEBUG|      virt:0063|     spice_agent_mouse = on
>12/31 19:16:46 DEBUG|      virt:0063|     spice_gen_x509 = yes
>12/31 19:16:46 DEBUG|      virt:0063|     spice_image_compression = auto_glz
>12/31 19:16:46 DEBUG|      virt:0063|     spice_ipv4 = yes
>12/31 19:16:46 DEBUG|      virt:0063|     spice_ipv6 = no
>12/31 19:16:46 DEBUG|      virt:0063|     spice_password = 123456
>12/31 19:16:46 DEBUG|      virt:0063|     spice_playback_compression = on
>12/31 19:16:46 DEBUG|      virt:0063|     spice_port = generate
>12/31 19:16:46 DEBUG|      virt:0063|     spice_secure_channels = main, inputs
>12/31 19:16:46 DEBUG|      virt:0063|     spice_ssl = no
>12/31 19:16:46 DEBUG|      virt:0063|     spice_streaming_video = all
>12/31 19:16:46 DEBUG|      virt:0063|     spice_tls_ciphers = DEFAULT
>12/31 19:16:46 DEBUG|      virt:0063|     spice_tls_port = generate
>12/31 19:16:46 DEBUG|      virt:0063|     spice_x509_cacert_file = ca-cert.pem
>12/31 19:16:46 DEBUG|      virt:0063|     spice_x509_cacert_subj = /C=CZ/L=BRNO/O=SPICE/CN=my CA
>12/31 19:16:46 DEBUG|      virt:0063|     spice_x509_cert_file = server-cert.pem
>12/31 19:16:46 DEBUG|      virt:0063|     spice_x509_dir = yes
>12/31 19:16:46 DEBUG|      virt:0063|     spice_x509_key_file = server-key.pem
>12/31 19:16:46 DEBUG|      virt:0063|     spice_x509_key_password = testPassPhrase
>12/31 19:16:46 DEBUG|      virt:0063|     spice_x509_prefix = /tmp/spice_x509d
>12/31 19:16:46 DEBUG|      virt:0063|     spice_x509_secure = no
>12/31 19:16:46 DEBUG|      virt:0063|     spice_x509_server_subj = /C=CZ/L=BRNO/O=SPICE/CN=my Server
>12/31 19:16:46 DEBUG|      virt:0063|     spice_zlib_glz_wan_compression = auto
>12/31 19:16:46 DEBUG|      virt:0063|     srchost = 
>12/31 19:16:46 DEBUG|      virt:0063|     start_vm = yes
>12/31 19:16:46 DEBUG|      virt:0063|     status_test_command = echo $?
>12/31 19:16:46 DEBUG|      virt:0063|     strict_mode = no
>12/31 19:16:46 DEBUG|      virt:0063|     sub_test_after_balloon = guest_suspend
>12/31 19:16:46 DEBUG|      virt:0063|     subtest = balloon_check
>12/31 19:16:46 DEBUG|      virt:0063|     sysfs_dir = /sys
>12/31 19:16:46 DEBUG|      virt:0063|     take_regular_screendumps = yes
>12/31 19:16:46 DEBUG|      virt:0063|     test_tags = evict
>12/31 19:16:46 DEBUG|      virt:0063|     test_timeout = 14400
>12/31 19:16:46 DEBUG|      virt:0063|     try_serial_login = yes
>12/31 19:16:46 DEBUG|      virt:0063|     type = balloon_check
>12/31 19:16:46 DEBUG|      virt:0063|     url_auto_ip = 192.168.122.1
>12/31 19:16:46 DEBUG|      virt:0063|     usb_controller_tablet1 = uhci
>12/31 19:16:46 DEBUG|      virt:0063|     usb_devices = tablet1
>12/31 19:16:46 DEBUG|      virt:0063|     usb_max_port = 2
>12/31 19:16:46 DEBUG|      virt:0063|     usb_type = ich9-usb-uhci1
>12/31 19:16:46 DEBUG|      virt:0063|     usb_type_tablet1 = usb-tablet
>12/31 19:16:46 DEBUG|      virt:0063|     usb_type_usb1 = ich9-usb-uhci1
>12/31 19:16:46 DEBUG|      virt:0063|     usbs = usb1
>12/31 19:16:46 DEBUG|      virt:0063|     use_autostart = no
>12/31 19:16:46 DEBUG|      virt:0063|     use_check_cpu = yes
>12/31 19:16:46 DEBUG|      virt:0063|     use_debug = yes
>12/31 19:16:46 DEBUG|      virt:0063|     use_nic_scritps = no
>12/31 19:16:46 DEBUG|      virt:0063|     use_no_reboot = no
>12/31 19:16:46 DEBUG|      virt:0063|     use_os_type = yes
>12/31 19:16:46 DEBUG|      virt:0063|     use_os_variant = no
>12/31 19:16:46 DEBUG|      virt:0063|     use_storage = local_stg
>12/31 19:16:46 DEBUG|      virt:0063|     use_virt_install_wait = no
>12/31 19:16:46 DEBUG|      virt:0063|     used_cpus = 
>12/31 19:16:46 DEBUG|      virt:0063|     used_mem = 
>12/31 19:16:46 DEBUG|      virt:0063|     username = root
>12/31 19:16:46 DEBUG|      virt:0063|     vcpu_cores = 0
>12/31 19:16:46 DEBUG|      virt:0063|     vcpu_sockets = 2
>12/31 19:16:46 DEBUG|      virt:0063|     vcpu_thread_pattern = u'thread_id':\s+(\d+)
>12/31 19:16:46 DEBUG|      virt:0063|     vcpu_threads = 1
>12/31 19:16:46 DEBUG|      virt:0063|     vfd_size = 1440k
>12/31 19:16:46 DEBUG|      virt:0063|     vga = cirrus
>12/31 19:16:46 DEBUG|      virt:0063|     vhost = vhost=on
>12/31 19:16:46 DEBUG|      virt:0063|     virt_install_wait_time = 300
>12/31 19:16:46 DEBUG|      virt:0063|     virt_test_type = qemu
>12/31 19:16:46 DEBUG|      virt:0063|     virtio-blk-pci_scsi = 
>12/31 19:16:46 DEBUG|      virt:0063|     vm_arch_name = x86_64
>12/31 19:16:46 DEBUG|      virt:0063|     vm_type = qemu
>12/31 19:16:46 DEBUG|      virt:0063|     vms = virt-tests-vm1
>12/31 19:16:46 DEBUG|      virt:0063|     vnc_autoport = yes
>12/31 19:16:46 DEBUG|      virt:0063|     wait_augment_ratio = 1
>12/31 19:16:46 DEBUG|      virt:0063|     workaround_qemu_qmp_crash = always
>12/31 19:16:46 DEBUG|     utils:0109| Running 'grep -q el5 /proc/version && cat /sys/module/kvm/version || uname -r'
>12/31 19:16:46 DEBUG|env_proces:0520| KVM version: 3.10.0-64.el7.x86_64
>12/31 19:16:46 DEBUG|     utils:0109| Running 'grep -q el5 /proc/version && rpm -qa | grep ^kvm-83-.* || rpm -qa | grep qemu-kvm-[0-9].*-.* | head -n 1'
>12/31 19:16:46 DEBUG|env_proces:0541| KVM userspace version: qemu-kvm-1.5.3-30.el7.x86_64
>12/31 19:16:46 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -help'
>12/31 19:16:46 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -device ? 2>&1'
>12/31 19:16:46 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -M ?'
>12/31 19:16:46 DEBUG|     utils:0109| Running 'echo -e 'help
>quit' | /home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -monitor stdio -vnc none'
>12/31 19:16:46 DEBUG|     utils:0109| Running 'echo -e '{ "execute": "qmp_capabilities" }
>{ "execute": "query-commands", "id": "RAND91" }
>{ "execute": "quit" }' | (sleep 1; cat )| /home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -qmp stdio -vnc none | grep return | grep RAND91'
>12/31 19:16:47 DEBUG|   virt_vm:0753| Generating random mac address for nic
>12/31 19:16:47 DEBUG|   qemu_vm:1664| qemu will run in KVM mode
>12/31 19:16:47 DEBUG|   virt_vm:0575| VM params in env don't match requested, restarting.
>12/31 19:16:47 DEBUG|   virt_vm:0753| Generating random mac address for nic
>12/31 19:16:48 DEBUG| utils_net:0636| Host does not support OpenVSwitch: Missing command: ovs-vswitchd
>12/31 19:16:48 DEBUG|   qemu_vm:1708| Adding VM virt-tests-vm1 NIC ifname t0-6s9K0j to bridge switch
>12/31 19:16:48 DEBUG| utils_net:0636| Host does not support OpenVSwitch: Missing command: ovs-vswitchd
>12/31 19:16:48 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -help'
>12/31 19:16:48 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -device ? 2>&1'
>12/31 19:16:48 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -M ?'
>12/31 19:16:48 DEBUG|     utils:0109| Running 'echo -e 'help
>quit' | /home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -monitor stdio -vnc none'
>12/31 19:16:48 DEBUG|     utils:0109| Running 'echo -e '{ "execute": "qmp_capabilities" }
>{ "execute": "query-commands", "id": "RAND91" }
>{ "execute": "quit" }' | (sleep 1; cat )| /home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu -qmp stdio -vnc none | grep return | grep RAND91'
>12/31 19:16:49 DEBUG|   qemu_vm:1664| qemu will run in KVM mode
>12/31 19:16:49 DEBUG|   qemu_vm:1956| Devices of virt-tests-vm1: [t'PREFIX',t'qemu',t'-S',t'vmname',t'qemu_sandbox',t'machine',t'i440FX',t'PIIX4_PM',t'PIIX3',t'piix3-ide',t'fdc',t'nodefaults',t'VGA-cirrus',t'QMP-qmpmonitor1',t'SER-serial0',t'isa-log',usb1,drive_image1,image1,idDIBJUD,t'NET-bridge',t'mem',t'smp',t'cpu',usb-tablet1,t'display',t'rtc',t'bootmenu',t'extra',t'kvm']
>12/31 19:16:49 DEBUG|   qemu_vm:1957| Buses of virt-tests-vm1
>  drive_image1(QDrive): {drive:image1}
>  usb1.0(uhci): {1:usb-tablet1}
>  floppy(floppy): [None,None]
>  ide(ide): [None,None,None,None]
>  _PCI_CHASSIS_NR(None): {}
>  _PCI_CHASSIS(None): {}
>  pci.0(PCI): {00-00:t'i440FX',01-00:t'PIIX3',01-01:t'piix3-ide',01-03:t'PIIX4_PM',02-00:t'VGA-cirrus',03-00:usb1,04-00:image1,05-00:idDIBJUD}
>12/31 19:16:49 INFO |   qemu_vm:2025| Running qemu command (reformatted):
>/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu \
>    -S  \
>    -name 'virt-tests-vm1'  \
>    -sandbox off  \
>    -M pc  \
>    -nodefaults  \
>    -vga cirrus  \
>    -chardev socket,id=qmp_id_qmpmonitor1,path=/tmp/monitor-qmpmonitor1-20131231-191647-wnZt9k9y,server,nowait \
>    -mon chardev=qmp_id_qmpmonitor1,mode=control  \
>    -chardev socket,id=serial_id_serial0,path=/tmp/serial-serial0-20131231-191647-wnZt9k9y,server,nowait \
>    -device isa-serial,chardev=serial_id_serial0  \
>    -chardev socket,id=seabioslog_id_20131231-191647-wnZt9k9y,path=/tmp/seabios-20131231-191647-wnZt9k9y,server,nowait \
>    -device isa-debugcon,chardev=seabioslog_id_20131231-191647-wnZt9k9y,iobase=0x402 \
>    -device ich9-usb-uhci1,id=usb1,bus=pci.0,addr=03 \
>    -drive id=drive_image1,if=none,cache=unsafe,snapshot=off,aio=native,file=/home/staf-kvm-devel/autotest-devel/client/tests/virt/shared/data/images/sles11sp3-64-virtio.qcow2 \
>    -device virtio-blk-pci,id=image1,drive=drive_image1,bootindex=0,bus=pci.0,addr=04 \
>    -device virtio-net-pci,mac=9a:6a:6b:6c:6d:6e,id=idDIBJUD,netdev=id16M5w2,bus=pci.0,addr=05  \
>    -netdev tap,id=id16M5w2,vhost=on,vhostfd=23,fd=22  \
>    -m 2048  \
>    -smp 1,maxcpus=1,cores=1,threads=1,sockets=2  \
>    -cpu 'SandyBridge' \
>    -device usb-tablet,id=usb-tablet1,bus=usb1.0,port=1  \
>    -vnc :0  \
>    -rtc base=utc,clock=host,driftfix=slew  \
>    -boot order=cdn,once=c,menu=off  \
>    -balloon virtio \
>    -global PIIX4_PM.disable_s4=0 \
>    -no-kvm-pit-reinjection \
>    -enable-kvm
>12/31 19:16:49 INFO |   aexpect:0907| [qemu output] Warning: option deprecated, use lost_tick_policy property of kvm-pit instead.
>12/31 19:16:50 INFO |   qemu_vm:2034| Created qemu process with parent PID 25689
>12/31 19:16:50 INFO |qemu_monit:0125| Connecting to monitor 'qmpmonitor1'
>12/31 19:16:50 DEBUG|qemu_monit:0267| (monitor qmpmonitor1) Sending command 'qmp_capabilities' 
>12/31 19:16:50 DEBUG|qemu_monit:1352| Send command: {'execute': 'qmp_capabilities', 'id': '7kCyCgi5'}
>12/31 19:16:50 DEBUG|qemu_monit:0267| (monitor qmpmonitor1) Sending command 'help' (via Human Monitor)
>12/31 19:16:50 DEBUG|   qemu_vm:2133| VM appears to be alive with PID 25691
>12/31 19:16:50 DEBUG|qemu_monit:0267| (monitor qmpmonitor1) Sending command 'query-cpus' 
>12/31 19:16:50 DEBUG|qemu_monit:1352| Send command: {'execute': 'query-cpus', 'id': 'qJKhOzoW'}
>12/31 19:16:50 DEBUG|qemu_monit:1308| (monitor qmpmonitor1) Response to 'query-cpus' (re-formated)
>12/31 19:16:50 DEBUG|qemu_monit:1284| (monitor qmpmonitor1)        current: True
>12/31 19:16:50 DEBUG|qemu_monit:1284| (monitor qmpmonitor1)        pc: 4294967280
>12/31 19:16:50 DEBUG|qemu_monit:1284| (monitor qmpmonitor1)        halted: False
>12/31 19:16:50 DEBUG|qemu_monit:1284| (monitor qmpmonitor1)        CPU: 0
>12/31 19:16:50 DEBUG|qemu_monit:1284| (monitor qmpmonitor1)        thread_id: 25695
>12/31 19:16:50 DEBUG|     utils:0109| Running 'ps aux'
>12/31 19:16:50 DEBUG|qemu_monit:0267| (monitor qmpmonitor1) Sending command 'cont' 
>12/31 19:16:50 DEBUG|qemu_monit:1352| Send command: {'execute': 'cont', 'id': 'vUuMXPA6'}
>12/31 19:16:50 INFO |      virt:0136| Running function: balloon_check.run_balloon_check()
>12/31 19:16:50 DEBUG|   virt_vm:0898| Attempting to log into 'virt-tests-vm1' (timeout 360s)
>12/31 19:16:50 DEBUG|   virt_vm:0908| Could not verify DHCP lease: 9a:6a:6b:6c:6d:6e --> 10.66.84.132
>12/31 19:17:05 DEBUG| utils_env:0064| (address cache) DHCP lease OK: 9a:6a:6b:6c:6d:6e --> 10.66.84.132
>12/31 19:22:51 ERROR|      virt:0155| Test failed: VMAddressVerificationError: Could not verify DHCP lease: 9a:6a:6b:6c:6d:6e --> 10.66.84.132
>12/31 19:22:51 INFO |env_proces:0246| Video creation failed for vm virt-tests-vm1: gstreamer-python library was not found
>12/31 19:22:51 DEBUG|   qemu_vm:2336| Destroying VM virt-tests-vm1 (PID 25691)
>12/31 19:22:51 DEBUG|   qemu_vm:2236| Shutting down VM virt-tests-vm1 (shell)
>12/31 19:22:51 DEBUG|   qemu_vm:2248| Could not verify DHCP lease: 9a:6a:6b:6c:6d:6e --> 10.66.84.132
>12/31 19:22:51 DEBUG|   qemu_vm:2346| VM virt-tests-vm1 failed to go down (shell)
>12/31 19:22:51 DEBUG|   qemu_vm:2350| Ending VM virt-tests-vm1 process (monitor)
>12/31 19:22:51 DEBUG|qemu_monit:0267| (monitor qmpmonitor1) Sending command 'quit' 
>12/31 19:22:51 DEBUG|qemu_monit:1352| Send command: {'execute': 'quit', 'id': '0DbpxJ8J'}
>12/31 19:22:51 INFO |   aexpect:0907| [qemu output] (Process terminated with status 0)
>12/31 19:22:51 DEBUG|   qemu_vm:2358| VM virt-tests-vm1 down (monitor)
>12/31 19:22:52 DEBUG| utils_net:0636| Host does not support OpenVSwitch: Missing command: ovs-vswitchd
>12/31 19:22:52 DEBUG|qemu_stora:0392| Checking image file /home/staf-kvm-devel/autotest-devel/client/tests/virt/shared/data/images/sles11sp3-64-virtio.qcow2
>12/31 19:22:52 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu-img info /home/staf-kvm-devel/autotest-devel/client/tests/virt/shared/data/images/sles11sp3-64-virtio.qcow2'
>12/31 19:22:52 DEBUG|     utils:0109| Running '/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/qemu-img check /home/staf-kvm-devel/autotest-devel/client/tests/virt/shared/data/images/sles11sp3-64-virtio.qcow2'
>12/31 19:22:52 ERROR|      test:0414| Exception escaping from test:
>Traceback (most recent call last):
>  File "/home/staf-kvm-devel/autotest-devel/client/shared/test.py", line 411, in _exec
>    _call_test_function(self.execute, *p_args, **p_dargs)
>  File "/home/staf-kvm-devel/autotest-devel/client/shared/test.py", line 830, in _call_test_function
>    raise error.UnhandledTestFail(e)
>UnhandledTestFail: Unhandled VMAddressVerificationError: Could not verify DHCP lease: 9a:6a:6b:6c:6d:6e --> 10.66.84.132    [context: (run_balloon_check) --> logging into 'virt-tests-vm1']
>Traceback (most recent call last):
>  File "/home/staf-kvm-devel/autotest-devel/client/shared/test.py", line 823, in _call_test_function
>    return func(*args, **dargs)
>  File "/home/staf-kvm-devel/autotest-devel/client/shared/test.py", line 291, in execute
>    postprocess_profiled_run, args, dargs)
>  File "/home/staf-kvm-devel/autotest-devel/client/shared/test.py", line 209, in _call_run_once
>    *args, **dargs)
>  File "/home/staf-kvm-devel/autotest-devel/client/shared/test.py", line 313, in run_once_profiling
>    self.run_once(*args, **dargs)
>  File "/home/staf-kvm-devel/autotest-devel/client/tests/virt/virt.py", line 139, in run_once
>    run_func(self, params, env)
>  File "/home/staf-kvm-devel/autotest-devel/client/shared/error.py", line 141, in new_fn
>    return fn(*args, **kwargs)
>  File "/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/tests/balloon_check.py", line 333, in run_balloon_check
>    balloon_test = BallooningTestLinux(test, params, env)
>  File "/home/staf-kvm-devel/autotest-devel/client/tests/virt/qemu/tests/balloon_check.py", line 24, in __init__
>    self.session = self.vm.wait_for_login(timeout=timeout)
>  File "/home/staf-kvm-devel/autotest-devel/client/tests/virt/virttest/virt_vm.py", line 919, in wait_for_login
>    return self.login(nic_index, internal_timeout, username, password)
>  File "/home/staf-kvm-devel/autotest-devel/client/shared/error.py", line 141, in new_fn
>    return fn(*args, **kwargs)
>  File "/home/staf-kvm-devel/autotest-devel/client/tests/virt/virttest/virt_vm.py", line 862, in login
>    address = self.get_address(nic_index)
>  File "/home/staf-kvm-devel/autotest-devel/client/tests/virt/virttest/virt_vm.py", line 665, in get_address
>    raise VMAddressVerificationError(nic.mac, arp_ip)
>VMAddressVerificationError: Could not verify DHCP lease: 9a:6a:6b:6c:6d:6e --> 10.66.84.132
>

Actions: View

Attachments on bug 1047763: 844380 | 844381 | 844382