Note: This bug is displayed in read-only format because
the product is no longer active in Red Hat Bugzilla.
RHEL Engineering is moving the tracking of its product development work on RHEL 6 through RHEL 9 to Red Hat Jira (issues.redhat.com). If you're a Red Hat customer, please continue to file support cases via the Red Hat customer portal. If you're not, please head to the "RHEL project" in Red Hat Jira and file new tickets here. Individual Bugzilla bugs in the statuses "NEW", "ASSIGNED", and "POST" are being migrated throughout September 2023. Bugs of Red Hat partners with an assigned Engineering Partner Manager (EPM) are migrated in late September as per pre-agreed dates. Bugs against components "kernel", "kernel-rt", and "kpatch" are only migrated if still in "NEW" or "ASSIGNED". If you cannot log in to RH Jira, please consult article #7032570. That failing, please send an e-mail to the RH Jira admins at rh-issues@redhat.com to troubleshoot your issue as a user management inquiry. The email creates a ServiceNow ticket with Red Hat. Individual Bugzilla bugs that are migrated will be moved to status "CLOSED", resolution "MIGRATED", and set with "MigratedToJIRA" in "Keywords". The link to the successor Jira issue will be found under "Links", have a little "two-footprint" icon next to it, and direct you to the "RHEL project" in Red Hat Jira (issue links are of type "https://issues.redhat.com/browse/RHEL-XXXX", where "X" is a digit). This same link will be available in a blue banner at the top of the page informing you that that bug has been migrated.
Description of problem:
Hit this problem with automation test.
case name: migrate.with_reboot.tcp
Low priority, need time to verify if it is a regression or not.
Version-Release number of selected component (if applicable):
kernel: kernel-3.10.0-862.el7.x86_64
qemu: qemu-kvm-rhev-2.10.0-21.el7_5.2.x86_64
How reproducible:
Low
Steps to Reproduce:
1. migrate VM (reel7.5) during reboot.
Actual results:
Expected results:
Additional info:
call Trace:
21:31:01 WARNI| No IP address of host was provided, using IP address on switch interface
21:31:01 DEBUG| Informing migration to spice client
21:31:01 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'client_migrate_info'
21:31:01 DEBUG| Send command: {'execute': u'client_migrate_info', 'arguments': {u'cert-subject': u'"C=CZ,L=BRNO,O=SPICE,CN=my Server10.73.224.145"', u'hostname': u'10.73.224.145', u'protocol': u'spice', u'port': 3001, u'tls-port': 3201}, 'id': 'NDmeCFXw'}
21:31:02 INFO | [qemu output] Thread 12 (Thread 0x7ff405267700 (LWP 22892)):
21:31:02 INFO | [qemu output] #0 0x00007ff40c460e59 in syscall () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] #1 0x000056092453a0c0 in qemu_event_wait (val=<optimized out>, f=<optimized out>) at /usr/src/debug/qemu-2.10.0/include/qemu/futex.h:26
21:31:02 INFO | [qemu output] #2 0x000056092453a0c0 in qemu_event_wait (ev=ev@entry=0x560924f45328 <rcu_call_ready_event>) at util/qemu-thread-posix.c:442
21:31:02 INFO | [qemu output] #3 0x0000560924549fbe in call_rcu_thread (opaque=<optimized out>) at util/rcu.c:249
21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] Thread 11 (Thread 0x7ff40306a700 (LWP 22896)):
21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926e80000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170
21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926e80000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007
21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926e80000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138
21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] Thread 10 (Thread 0x7ff402869700 (LWP 22897)):
21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926eda000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170
21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926eda000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007
21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926eda000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138
21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] Thread 9 (Thread 0x7ff402068700 (LWP 22898)):
21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926ef8000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170
21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926ef8000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007
21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926ef8000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138
21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] Thread 8 (Thread 0x7ff401867700 (LWP 22899)):
21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926f14000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170
21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926f14000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007
21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926f14000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138
21:31:02 INFO | Migrating to tcp:localhost:5200
21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0
21:31:02 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'migrate'
21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6
21:31:02 DEBUG| Send command: {'execute': 'migrate', 'arguments': {'uri': 'tcp:localhost:5200', 'blk': False, 'inc': False}, 'id': 'wLvNP0mW'}
21:31:02 INFO | [qemu output] Thread 7 (Thread 0x7ff401066700 (LWP 22900)):
21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926f34000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170
21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926f34000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007
21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926f34000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138
21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] Thread 6 (Thread 0x7ff400865700 (LWP 22901)):
21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926f56000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170
21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926f56000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007
21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926f56000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138
21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] Thread 5 (Thread 0x7ff400064700 (LWP 22902)):
21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926f74000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170
21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926f74000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007
21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926f74000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138
21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] Thread 4 (Thread 0x7ff3ff863700 (LWP 22903)):
21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926f92000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170
21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926f92000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007
21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926f92000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138
21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] Thread 3 (Thread 0x7ff1f65ff700 (LWP 22904)):
21:31:02 INFO | [qemu output] #0 0x00007ff40c7467ad in read () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #1 0x00007ff40e547ae1 in spice_backtrace_gstack () at /lib64/libspice-server.so.1
21:31:02 INFO | [qemu output] #2 0x00007ff40e54f457 in spice_log () at /lib64/libspice-server.so.1
21:31:02 INFO | [qemu output] #3 0x00007ff40e504308 in display_channel_update () at /lib64/libspice-server.so.1
21:31:02 INFO | [qemu output] #4 0x00007ff40e532b8b in handle_dev_update_async () at /lib64/libspice-server.so.1
21:31:02 INFO | [qemu output] qemu-kvm: Not a migration stream
21:31:02 INFO | [qemu output] #5 0x00007ff40e4fe29d in dispatcher_handle_recv_read () at /lib64/libspice-server.so.1
21:31:02 INFO | [qemu output] qemu-kvm: load of migration failed: Invalid argument
21:31:02 INFO | [qemu output] #6 0x00007ff40e504aab in watch_func () at /lib64/libspice-server.so.1
21:31:02 INFO | [qemu output] #7 0x00007ff40e0028f9 in g_main_context_dispatch () at /lib64/libglib-2.0.so.0
21:31:02 INFO | [qemu output] #8 0x00007ff40e002c58 in g_main_context_iterate.isra.22 () at /lib64/libglib-2.0.so.0
21:31:02 INFO | [qemu output] (Process terminated with status 1)
21:31:02 INFO | [qemu output] #9 0x00007ff40e002f2a in g_main_loop_run () at /lib64/libglib-2.0.so.0
21:31:02 INFO | [qemu output] #10 0x00007ff40e532f2a in red_worker_main () at /lib64/libspice-server.so.1
21:31:02 INFO | [qemu output] #11 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #12 0x00007ff40c466b3d in clone () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] Thread 2 (Thread 0x7ff403c6f700 (LWP 22979)):
21:31:02 INFO | [qemu output] #0 0x00007ff40c745cc1 in do_futex_wait () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #1 0x00007ff40c745d87 in __new_sem_wait_slow () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #2 0x00007ff40c745e25 in sem_timedwait () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #3 0x0000560924539e57 in qemu_sem_timedwait (sem=sem@entry=0x560926a7d2d8, ms=ms@entry=10000) at util/qemu-thread-posix.c:289
21:31:02 INFO | [qemu output] #4 0x000056092453584c in worker_thread (opaque=0x560926a7d260) at util/thread-pool.c:92
21:31:02 INFO | [qemu output] #5 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0
21:31:02 INFO | [qemu output] #6 0x00007ff40c466b3d in clone () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] Thread 1 (Thread 0x7ff416b7dd00 (LWP 22891)):
21:31:02 INFO | [qemu output] #0 0x00007ff40c45bf5f in ppoll () at /lib64/libc.so.6
21:31:02 INFO | [qemu output] #1 0x00005609245361b9 in qemu_poll_ns (__ss=0x0, __timeout=0x7ffdf8f4dbf0, __nfds=<optimized out>, __fds=<optimized out>) at /usr/include/bits/poll2.h:77
21:31:02 INFO | [qemu output] #2 0x00005609245361b9 in qemu_poll_ns (fds=<optimized out>, nfds=<optimized out>, timeout=timeout@entry=2999680380) at util/qemu-timer.c:334
21:31:02 INFO | [qemu output] #3 0x0000560924536fb8 in main_loop_wait (timeout=2999680380) at util/main-loop.c:255
21:31:02 INFO | [qemu output] #4 0x0000560924536fb8 in main_loop_wait (nonblocking=nonblocking@entry=0) at util/main-loop.c:515
21:31:02 INFO | [qemu output] #5 0x000056092421699a in main () at vl.c:1937
21:31:02 INFO | [qemu output] #6 0x000056092421699a in main (argc=<optimized out>, argv=<optimized out>, envp=<optimized out>) at vl.c:4828
21:31:02 INFO | [qemu output] /tmp/aexpect_D40uGPeo/aexpect-HNDiWE.sh: line 1: 22891 Aborted MALLOC_PERTURB_=1 /usr/libexec/qemu-kvm -S -name 'avocado-vt-vm1' -sandbox off -machine pc -nodefaults -vga qxl -device pci-bridge,id=pci_bridge,bus=pci.0,addr=0x3,chassis_nr=1 -device intel-hda,bus=pci.0,addr=0x4 -device hda-duplex -chardev socket,id=qmp_id_qmpmonitor1,path=/var/tmp/avocado_08ZN5j/monitor-qmpmonitor1-20180413-213008-5syNFntP,server,nowait -mon chardev=qmp_id_qmpmonitor1,mode=control -chardev socket,id=qmp_id_catch_monitor,path=/var/tmp/avocado_08ZN5j/monitor-catch_monitor-20180413-213008-5syNFntP,server,nowait -mon chardev=qmp_id_catch_monitor,mode=control -device pvpanic,ioport=0x505,id=idGRAE02 -chardev socket,id=serial_id_serial0,path=/var/tmp/avocado_08ZN5j/serial-serial0-20180413-213008-5syNFntP,server,nowait -device isa-serial,chardev=serial_id_serial0 -device virtio-serial-pci,id=virtio_serial_pci0,bus=pci.0,addr=0x5 -chardev socket,path=/var/tmp/avocado_08ZN5j/virtio_port-vs-20180413-213008-5syNFntP,nowait,id=idQWhOxa,server -device virtserialport,id=id6bOn7S,name=vs,bus=virtio_serial_pci0.0,chardev=idQWhOxa -object rng-random,filename=/dev/random,id=passthrough-lGLRcVsy -device virtio-rng-pci,id=virtio-rng-pci-0LqIY2JJ,rng=passthrough-lGLRcVsy,bus=pci.0,addr=0x6 -chardev socket,id=seabioslog_id_20180413-213008-5syNFntP,path=/var/tmp/avocado_08ZN5j/seabios-20180413-213008-5syNFntP,server,nowait -device isa-debugcon,chardev=seabioslog_id_20180413-213008-5syNFntP,iobase=0x402 -device ich9-usb-ehci1,id=usb1,addr=0x1d.7,multifunction=on,bus=pci.0 -device ich9-usb-uhci1,id=usb1.0,multifunction=on,masterbus=usb1.0,addr=0x1d.0,firstport=0,bus=pci.0 -device ich9-usb-uhci2,id=usb1.1,multifunction=on,masterbus=usb1.0,addr=0x1d.2,firstport=2,bus=pci.0 -device ich9-usb-uhci3,id=usb1.2,multifunction=on,masterbus=usb1.0,addr=0x1d.4,firstport=4,bus=pci.0 -device nec-usb-xhci,id=usb2,bus=pci.0,addr=0x7 -device virtio-scsi-pci,id=virtio_scsi_pci0,bus=pci.0,addr=0x8 -drive id=drive_image1,if=none,snapshot=off,aio=native,cache=none,format=qcow2,file=/home/kvm_autotest_root/images/rhel75-64-virtio-scsi.qcow2 -device scsi-hd,id=image1,drive=drive_image1 -device virtio-net-pci,mac=9a:e3:e4:e5:e6:e7,id=id8UtUIz,vectors=4,netdev=idq2Gn0A,bus=pci.0,addr=0x9 -netdev tap,id=idq2Gn0A,vhost=on,vhostfd=21,fd=20 -m 8192 -smp 8,maxcpus=8,cores=4,threads=1,sockets=2 -cpu 'Opteron_G4',+kvm_pv_unhalt -device usb-tablet,id=usb-tablet1,bus=usb2.0,port=1 -spice port=3000,password=123456,addr=0,tls-port=3200,x509-dir=/tmp/spice_x509d,tls-channel=main,tls-channel=inputs,image-compression=auto_glz,zlib-glz-wan-compression=auto,streaming-video=all,agent-mouse=on,playback-compression=on,ipv4 -rtc base=utc,clock=host,driftfix=slew -boot order=cdn,once=c,menu=off,strict=off -no-hpet -enable-kvm -watchdog i6300esb -watchdog-action reset -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0xa
21:31:02 INFO | [qemu output] (Process terminated with status 134)
21:31:03 WARNI| avocado-vt-vm1 is not alive. Can't query the register status
21:31:04 DEBUG| Waiting for migration to complete (2.002236 secs)
Comment 2Dr. David Alan Gilbert
2018-04-18 15:23:30 UTC
Hi,
You say the reproducability is low - how low? Can you reproduce it if you just
sit that avocado test in a loop?
Can you attach the full avocado log section for the test?
(In reply to Dr. David Alan Gilbert from comment #2)
> Hi,
> You say the reproducability is low - how low? Can you reproduce it if you
> just
> sit that avocado test in a loop?
In my testing, about 1/10.
Yes, i can reproduce it with avocado test in a loop.
Now, i basically sure this is not a regression issue.
It should be a same issue with bz 1520729> Can you attach the full avocado log section for the test?
Full avocado log was added in the attachment, and also trace log that mentioned in 1520729 comment 18:
# stap -e 'probe qemu.kvm.simpletrace.qxl* {} probe qemu.kvm.simpletrace.qemu_spice* {} probe qemu.kvm.simpletrace.display* {}' -x $pidof_qemu-kvm >/tmp/trace_$pidof_qemu_kvm
# /usr/share/qemu-kvm/simpletrace.py --no-header /usr/share/qemu-kvm/trace-events-all /tmp/trace_$pidof_qemu_kvm
(In reply to Dr. David Alan Gilbert from comment #6)
> Yeh I agree it looks like 1520729;
> Gerd: Dupe?
Likely. And we have a trace log (comment 5) now, cool.
Repeat the testing, and checked in with three version.
qemu-kvm-rhev-2.12.0-6.el7, qemu-kvm-rhev-2.12.0-7.el7, qemu-kvm-rhev-2.12.0-8.el7, can not hit this issue again.
Move to VERIFIED.
Since the problem described in this bug report should be
resolved in a recent advisory, it has been closed with a
resolution of ERRATA.
For information on the advisory, and where to find the updated
files, follow the link below.
If the solution does not work for you, open a new bug report.
https://access.redhat.com/errata/RHBA-2018:3443
Description of problem: Hit this problem with automation test. case name: migrate.with_reboot.tcp Low priority, need time to verify if it is a regression or not. Version-Release number of selected component (if applicable): kernel: kernel-3.10.0-862.el7.x86_64 qemu: qemu-kvm-rhev-2.10.0-21.el7_5.2.x86_64 How reproducible: Low Steps to Reproduce: 1. migrate VM (reel7.5) during reboot. Actual results: Expected results: Additional info: call Trace: 21:31:01 WARNI| No IP address of host was provided, using IP address on switch interface 21:31:01 DEBUG| Informing migration to spice client 21:31:01 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'client_migrate_info' 21:31:01 DEBUG| Send command: {'execute': u'client_migrate_info', 'arguments': {u'cert-subject': u'"C=CZ,L=BRNO,O=SPICE,CN=my Server10.73.224.145"', u'hostname': u'10.73.224.145', u'protocol': u'spice', u'port': 3001, u'tls-port': 3201}, 'id': 'NDmeCFXw'} 21:31:02 INFO | [qemu output] Thread 12 (Thread 0x7ff405267700 (LWP 22892)): 21:31:02 INFO | [qemu output] #0 0x00007ff40c460e59 in syscall () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] #1 0x000056092453a0c0 in qemu_event_wait (val=<optimized out>, f=<optimized out>) at /usr/src/debug/qemu-2.10.0/include/qemu/futex.h:26 21:31:02 INFO | [qemu output] #2 0x000056092453a0c0 in qemu_event_wait (ev=ev@entry=0x560924f45328 <rcu_call_ready_event>) at util/qemu-thread-posix.c:442 21:31:02 INFO | [qemu output] #3 0x0000560924549fbe in call_rcu_thread (opaque=<optimized out>) at util/rcu.c:249 21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] Thread 11 (Thread 0x7ff40306a700 (LWP 22896)): 21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926e80000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170 21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926e80000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007 21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926e80000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138 21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] Thread 10 (Thread 0x7ff402869700 (LWP 22897)): 21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926eda000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170 21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926eda000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007 21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926eda000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138 21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] Thread 9 (Thread 0x7ff402068700 (LWP 22898)): 21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926ef8000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170 21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926ef8000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007 21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926ef8000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138 21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] Thread 8 (Thread 0x7ff401867700 (LWP 22899)): 21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926f14000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170 21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926f14000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007 21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926f14000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138 21:31:02 INFO | Migrating to tcp:localhost:5200 21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0 21:31:02 DEBUG| (monitor avocado-vt-vm1.qmpmonitor1) Sending command 'migrate' 21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6 21:31:02 DEBUG| Send command: {'execute': 'migrate', 'arguments': {'uri': 'tcp:localhost:5200', 'blk': False, 'inc': False}, 'id': 'wLvNP0mW'} 21:31:02 INFO | [qemu output] Thread 7 (Thread 0x7ff401066700 (LWP 22900)): 21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926f34000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170 21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926f34000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007 21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926f34000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138 21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] Thread 6 (Thread 0x7ff400865700 (LWP 22901)): 21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926f56000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170 21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926f56000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007 21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926f56000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138 21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] Thread 5 (Thread 0x7ff400064700 (LWP 22902)): 21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926f74000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170 21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926f74000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007 21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926f74000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138 21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] Thread 4 (Thread 0x7ff3ff863700 (LWP 22903)): 21:31:02 INFO | [qemu output] #0 0x00007ff40c45d567 in ioctl () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] #1 0x0000560924271855 in kvm_vcpu_ioctl (cpu=cpu@entry=0x560926f92000, type=type@entry=44672) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2170 21:31:02 INFO | [qemu output] #2 0x0000560924271923 in kvm_cpu_exec (cpu=cpu@entry=0x560926f92000) at /usr/src/debug/qemu-2.10.0/accel/kvm/kvm-all.c:2007 21:31:02 INFO | [qemu output] #3 0x0000560924250b42 in qemu_kvm_cpu_thread_fn (arg=0x560926f92000) at /usr/src/debug/qemu-2.10.0/cpus.c:1138 21:31:02 INFO | [qemu output] #4 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #5 0x00007ff40c466b3d in clone () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] Thread 3 (Thread 0x7ff1f65ff700 (LWP 22904)): 21:31:02 INFO | [qemu output] #0 0x00007ff40c7467ad in read () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #1 0x00007ff40e547ae1 in spice_backtrace_gstack () at /lib64/libspice-server.so.1 21:31:02 INFO | [qemu output] #2 0x00007ff40e54f457 in spice_log () at /lib64/libspice-server.so.1 21:31:02 INFO | [qemu output] #3 0x00007ff40e504308 in display_channel_update () at /lib64/libspice-server.so.1 21:31:02 INFO | [qemu output] #4 0x00007ff40e532b8b in handle_dev_update_async () at /lib64/libspice-server.so.1 21:31:02 INFO | [qemu output] qemu-kvm: Not a migration stream 21:31:02 INFO | [qemu output] #5 0x00007ff40e4fe29d in dispatcher_handle_recv_read () at /lib64/libspice-server.so.1 21:31:02 INFO | [qemu output] qemu-kvm: load of migration failed: Invalid argument 21:31:02 INFO | [qemu output] #6 0x00007ff40e504aab in watch_func () at /lib64/libspice-server.so.1 21:31:02 INFO | [qemu output] #7 0x00007ff40e0028f9 in g_main_context_dispatch () at /lib64/libglib-2.0.so.0 21:31:02 INFO | [qemu output] #8 0x00007ff40e002c58 in g_main_context_iterate.isra.22 () at /lib64/libglib-2.0.so.0 21:31:02 INFO | [qemu output] (Process terminated with status 1) 21:31:02 INFO | [qemu output] #9 0x00007ff40e002f2a in g_main_loop_run () at /lib64/libglib-2.0.so.0 21:31:02 INFO | [qemu output] #10 0x00007ff40e532f2a in red_worker_main () at /lib64/libspice-server.so.1 21:31:02 INFO | [qemu output] #11 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #12 0x00007ff40c466b3d in clone () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] Thread 2 (Thread 0x7ff403c6f700 (LWP 22979)): 21:31:02 INFO | [qemu output] #0 0x00007ff40c745cc1 in do_futex_wait () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #1 0x00007ff40c745d87 in __new_sem_wait_slow () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #2 0x00007ff40c745e25 in sem_timedwait () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #3 0x0000560924539e57 in qemu_sem_timedwait (sem=sem@entry=0x560926a7d2d8, ms=ms@entry=10000) at util/qemu-thread-posix.c:289 21:31:02 INFO | [qemu output] #4 0x000056092453584c in worker_thread (opaque=0x560926a7d260) at util/thread-pool.c:92 21:31:02 INFO | [qemu output] #5 0x00007ff40c73fdd5 in start_thread () at /lib64/libpthread.so.0 21:31:02 INFO | [qemu output] #6 0x00007ff40c466b3d in clone () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] Thread 1 (Thread 0x7ff416b7dd00 (LWP 22891)): 21:31:02 INFO | [qemu output] #0 0x00007ff40c45bf5f in ppoll () at /lib64/libc.so.6 21:31:02 INFO | [qemu output] #1 0x00005609245361b9 in qemu_poll_ns (__ss=0x0, __timeout=0x7ffdf8f4dbf0, __nfds=<optimized out>, __fds=<optimized out>) at /usr/include/bits/poll2.h:77 21:31:02 INFO | [qemu output] #2 0x00005609245361b9 in qemu_poll_ns (fds=<optimized out>, nfds=<optimized out>, timeout=timeout@entry=2999680380) at util/qemu-timer.c:334 21:31:02 INFO | [qemu output] #3 0x0000560924536fb8 in main_loop_wait (timeout=2999680380) at util/main-loop.c:255 21:31:02 INFO | [qemu output] #4 0x0000560924536fb8 in main_loop_wait (nonblocking=nonblocking@entry=0) at util/main-loop.c:515 21:31:02 INFO | [qemu output] #5 0x000056092421699a in main () at vl.c:1937 21:31:02 INFO | [qemu output] #6 0x000056092421699a in main (argc=<optimized out>, argv=<optimized out>, envp=<optimized out>) at vl.c:4828 21:31:02 INFO | [qemu output] /tmp/aexpect_D40uGPeo/aexpect-HNDiWE.sh: line 1: 22891 Aborted MALLOC_PERTURB_=1 /usr/libexec/qemu-kvm -S -name 'avocado-vt-vm1' -sandbox off -machine pc -nodefaults -vga qxl -device pci-bridge,id=pci_bridge,bus=pci.0,addr=0x3,chassis_nr=1 -device intel-hda,bus=pci.0,addr=0x4 -device hda-duplex -chardev socket,id=qmp_id_qmpmonitor1,path=/var/tmp/avocado_08ZN5j/monitor-qmpmonitor1-20180413-213008-5syNFntP,server,nowait -mon chardev=qmp_id_qmpmonitor1,mode=control -chardev socket,id=qmp_id_catch_monitor,path=/var/tmp/avocado_08ZN5j/monitor-catch_monitor-20180413-213008-5syNFntP,server,nowait -mon chardev=qmp_id_catch_monitor,mode=control -device pvpanic,ioport=0x505,id=idGRAE02 -chardev socket,id=serial_id_serial0,path=/var/tmp/avocado_08ZN5j/serial-serial0-20180413-213008-5syNFntP,server,nowait -device isa-serial,chardev=serial_id_serial0 -device virtio-serial-pci,id=virtio_serial_pci0,bus=pci.0,addr=0x5 -chardev socket,path=/var/tmp/avocado_08ZN5j/virtio_port-vs-20180413-213008-5syNFntP,nowait,id=idQWhOxa,server -device virtserialport,id=id6bOn7S,name=vs,bus=virtio_serial_pci0.0,chardev=idQWhOxa -object rng-random,filename=/dev/random,id=passthrough-lGLRcVsy -device virtio-rng-pci,id=virtio-rng-pci-0LqIY2JJ,rng=passthrough-lGLRcVsy,bus=pci.0,addr=0x6 -chardev socket,id=seabioslog_id_20180413-213008-5syNFntP,path=/var/tmp/avocado_08ZN5j/seabios-20180413-213008-5syNFntP,server,nowait -device isa-debugcon,chardev=seabioslog_id_20180413-213008-5syNFntP,iobase=0x402 -device ich9-usb-ehci1,id=usb1,addr=0x1d.7,multifunction=on,bus=pci.0 -device ich9-usb-uhci1,id=usb1.0,multifunction=on,masterbus=usb1.0,addr=0x1d.0,firstport=0,bus=pci.0 -device ich9-usb-uhci2,id=usb1.1,multifunction=on,masterbus=usb1.0,addr=0x1d.2,firstport=2,bus=pci.0 -device ich9-usb-uhci3,id=usb1.2,multifunction=on,masterbus=usb1.0,addr=0x1d.4,firstport=4,bus=pci.0 -device nec-usb-xhci,id=usb2,bus=pci.0,addr=0x7 -device virtio-scsi-pci,id=virtio_scsi_pci0,bus=pci.0,addr=0x8 -drive id=drive_image1,if=none,snapshot=off,aio=native,cache=none,format=qcow2,file=/home/kvm_autotest_root/images/rhel75-64-virtio-scsi.qcow2 -device scsi-hd,id=image1,drive=drive_image1 -device virtio-net-pci,mac=9a:e3:e4:e5:e6:e7,id=id8UtUIz,vectors=4,netdev=idq2Gn0A,bus=pci.0,addr=0x9 -netdev tap,id=idq2Gn0A,vhost=on,vhostfd=21,fd=20 -m 8192 -smp 8,maxcpus=8,cores=4,threads=1,sockets=2 -cpu 'Opteron_G4',+kvm_pv_unhalt -device usb-tablet,id=usb-tablet1,bus=usb2.0,port=1 -spice port=3000,password=123456,addr=0,tls-port=3200,x509-dir=/tmp/spice_x509d,tls-channel=main,tls-channel=inputs,image-compression=auto_glz,zlib-glz-wan-compression=auto,streaming-video=all,agent-mouse=on,playback-compression=on,ipv4 -rtc base=utc,clock=host,driftfix=slew -boot order=cdn,once=c,menu=off,strict=off -no-hpet -enable-kvm -watchdog i6300esb -watchdog-action reset -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0xa 21:31:02 INFO | [qemu output] (Process terminated with status 134) 21:31:03 WARNI| avocado-vt-vm1 is not alive. Can't query the register status 21:31:04 DEBUG| Waiting for migration to complete (2.002236 secs)