Details about why a live migration failed
Helo I have a VM on a host that seems it cannot be live-migrated away. I'm trying to migrate it to another (superior) cluster but please consider: - VM isn't receiving too much tarffic and is not doing much at all - I've already successfully live migrated other VMs from this host to the same other cluster looking through engine.log I cannot see anything interesting a aprt from the generic ( I grepped for the job ID) 2017-03-24 10:30:52,186 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-42) [20518310] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Migration started (VM: druid-co01., Source: vmhost04, Destination: vmhost06, User: admin@internal-authz). 2017-03-24 10:34:28,072 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-2) [6d6a3a53] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Failed to migrate VM druid-co01. to Host vmhost06 . Trying to migrate to another Host. 2017-03-24 10:34:28,676 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-2) [6d6a3a53] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Migration started (VM: druid-co01., Source: vmhost04, Destination: vmhost11, User: admin@internal-authz). 2017-03-24 10:37:59,097 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-40) [779e9773] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Failed to migrate VM druid-co01. to Host vmhost11 . Trying to migrate to another Host. 2017-03-24 10:38:00,626 INFO [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-40) [779e9773] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Migration started (VM: druid-co01, Source: vmhost04, Destination: vmhost08, User: admin@internal-authz). 2017-03-24 10:41:29,441 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-42) [6f032492] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Failed to migrate VM druid-co01 to Host vmhost08 . Trying to migrate to another Host. 2017-03-24 10:41:29,488 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-42) [6f032492] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Migration failed (VM: druid-co01, Source: vmhost04). -- Davide Ferrari Senior Systems Engineer
And this is the vdsm log from vmhost04: Thread-6320715::DEBUG::2017-03-24 11:38:02,224::migration::188::virt.vm::(_setupVdsConnection) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Initiating connection with destination Thread-6320715::DEBUG::2017-03-24 11:38:02,239::migration::200::virt.vm::(_setupVdsConnection) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Destination server is: vm08.ovirt.internal:54321 Thread-6320715::DEBUG::2017-03-24 11:38:02,241::migration::246::virt.vm::(_prepareGuest) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration started Thread-6320715::DEBUG::2017-03-24 11:38:02,253::guestagent::502::virt.vm::(send_lifecycle_event) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::send_lifecycle_event before_migration called Thread-6320715::DEBUG::2017-03-24 11:38:02,319::migration::353::virt.vm::(run) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::migration semaphore acquired after 2 seconds Thread-6320715::INFO::2017-03-24 11:38:02,950::migration::407::virt.vm::(_startUnderlyingMigration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Creation of destination VM took: 0 seconds Thread-6320715::INFO::2017-03-24 11:38:02,951::migration::429::virt.vm::(_startUnderlyingMigration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::starting migration to qemu+tls://vm08.ovirt.internal/system with miguri tcp://192.168.10.107 Thread-6320715::DEBUG::2017-03-24 11:38:02,951::migration::494::virt.vm::(_perform_with_conv_schedule) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::performing migration with conv schedule Thread-6320717::DEBUG::2017-03-24 11:38:02,952::migration::620::virt.vm::(run) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::starting migration monitor thread Thread-6320717::DEBUG::2017-03-24 11:38:02,952::migration::739::virt.vm::(_execute_action_with_params) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Setting downtime to 100 Thread-6320717::INFO::2017-03-24 11:38:12,959::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 10 seconds elapsed, 8% of data processed, total data: 16456MB, processed data: 483MB, remaining data: 15157MB, transfer speed 52MBps, zero pages: 209524MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:38:22,963::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 20 seconds elapsed, 13% of data processed, total data: 16456MB, processed data: 1003MB, remaining data: 14469MB, transfer speed 51MBps, zero pages: 252844MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:38:32,966::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 30 seconds elapsed, 16% of data processed, total data: 16456MB, processed data: 1524MB, remaining data: 13839MB, transfer speed 52MBps, zero pages: 281344MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:38:42,969::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 40 seconds elapsed, 42% of data processed, total data: 16456MB, processed data: 2040MB, remaining data: 9685MB, transfer speed 52MBps, zero pages: 1214867MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:38:52,973::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 50 seconds elapsed, 46% of data processed, total data: 16456MB, processed data: 2560MB, remaining data: 8944MB, transfer speed 52MBps, zero pages: 1271798MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:39:02,976::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 60 seconds elapsed, 51% of data processed, total data: 16456MB, processed data: 3080MB, remaining data: 8148MB, transfer speed 52MBps, zero pages: 1342711MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:39:12,979::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 70 seconds elapsed, 56% of data processed, total data: 16456MB, processed data: 3600MB, remaining data: 7353MB, transfer speed 52MBps, zero pages: 1413447MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:39:22,984::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 80 seconds elapsed, 59% of data processed, total data: 16456MB, processed data: 4120MB, remaining data: 6755MB, transfer speed 52MBps, zero pages: 1433707MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:39:32,987::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 90 seconds elapsed, 64% of data processed, total data: 16456MB, processed data: 4641MB, remaining data: 6032MB, transfer speed 52MBps, zero pages: 1486003MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:39:42,990::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 100 seconds elapsed, 67% of data processed, total data: 16456MB, processed data: 5161MB, remaining data: 5457MB, transfer speed 52MBps, zero pages: 1500433MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:39:52,993::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 110 seconds elapsed, 71% of data processed, total data: 16456MB, processed data: 5681MB, remaining data: 4836MB, transfer speed 52MBps, zero pages: 1526530MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:40:02,996::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 120 seconds elapsed, 75% of data processed, total data: 16456MB, processed data: 6201MB, remaining data: 4220MB, transfer speed 52MBps, zero pages: 1551477MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:40:12,999::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 130 seconds elapsed, 79% of data processed, total data: 16456MB, processed data: 6721MB, remaining data: 3574MB, transfer speed 52MBps, zero pages: 1583895MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:40:23,002::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 140 seconds elapsed, 82% of data processed, total data: 16456MB, processed data: 7242MB, remaining data: 2979MB, transfer speed 52MBps, zero pages: 1603409MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:40:33,005::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 150 seconds elapsed, 86% of data processed, total data: 16456MB, processed data: 7762MB, remaining data: 2382MB, transfer speed 52MBps, zero pages: 1623448MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:40:43,008::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 160 seconds elapsed, 90% of data processed, total data: 16456MB, processed data: 8282MB, remaining data: 1736MB, transfer speed 52MBps, zero pages: 1655832MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:40:53,011::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 170 seconds elapsed, 93% of data processed, total data: 16456MB, processed data: 8802MB, remaining data: 1166MB, transfer speed 52MBps, zero pages: 1668937MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:41:03,014::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 180 seconds elapsed, 97% of data processed, total data: 16456MB, processed data: 9322MB, remaining data: 581MB, transfer speed 52MBps, zero pages: 1685861MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 Thread-6320717::INFO::2017-03-24 11:41:13,019::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 190 seconds elapsed, 98% of data processed, total data: 16456MB, processed data: 9842MB, remaining data: 386MB, transfer speed 52MBps, zero pages: 1718676MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 libvirtEventLoop::DEBUG::2017-03-24 11:41:21,007::vm::4291::virt.vm::(onLibvirtLifecycleEvent) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::event Suspended detail 0 opaque None libvirtEventLoop::INFO::2017-03-24 11:41:21,025::vm::4815::virt.vm::(_logGuestCpuStatus) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::CPU stopped: onSuspend libvirtEventLoop::DEBUG::2017-03-24 11:41:21,069::vm::4291::virt.vm::(onLibvirtLifecycleEvent) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::event Resumed detail 0 opaque None libvirtEventLoop::INFO::2017-03-24 11:41:21,069::vm::4815::virt.vm::(_logGuestCpuStatus) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::CPU running: onResume Thread-6320715::DEBUG::2017-03-24 11:41:21,224::migration::715::virt.vm::(stop) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::stopping migration monitor thread Thread-6320715::ERROR::2017-03-24 11:41:21,225::migration::252::virt.vm::(_recover) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::operation failed: migration job: unexpectedly failed Thread-6320717::DEBUG::2017-03-24 11:41:21,226::migration::629::virt.vm::(run) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::stopped migration monitor thread Thread-6320715::DEBUG::2017-03-24 11:41:21,257::guestagent::502::virt.vm::(send_lifecycle_event) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::send_lifecycle_event after_migration called Thread-6320715::DEBUG::2017-03-24 11:41:21,284::__init__::209::jsonrpc.Notification::(emit) Sending event {"params": {"notify_time": 19498739270, "4f627cc1-9b52-4eef-bf3a-c02e8a6303b8": {"status": "Migration Source"}}, "jsonrpc": "2.0", "method": "|virt|VM_status|4f627cc1-9b52-4eef-bf3a-c02e8a6303b8"} Thread-6320715::ERROR::2017-03-24 11:41:21,285::migration::381::virt.vm::(run) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Failed to migrate jsonrpc.Executor/6::DEBUG::2017-03-24 11:41:29,161::__init__::530::jsonrpc.JsonRpcServer::(_handle_request) Calling 'VM.getMigrationStatus' in bridge with {u'vmID': u'4f627cc1-9b52-4eef-bf3a-c02e8a6303b8'} 2017-03-24 11:54 GMT+01:00 Davide Ferrari <davide@billymob.com>:
Helo
I have a VM on a host that seems it cannot be live-migrated away. I'm trying to migrate it to another (superior) cluster but please consider: - VM isn't receiving too much tarffic and is not doing much at all - I've already successfully live migrated other VMs from this host to the same other cluster
looking through engine.log I cannot see anything interesting a aprt from the generic ( I grepped for the job ID)
2017-03-24 10:30:52,186 INFO [org.ovirt.engine.core.dal. dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-42) [20518310] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Migration started (VM: druid-co01., Source: vmhost04, Destination: vmhost06, User: admin@internal-authz). 2017-03-24 10:34:28,072 WARN [org.ovirt.engine.core.dal. dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-2) [6d6a3a53] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Failed to migrate VM druid-co01. to Host vmhost06 . Trying to migrate to another Host. 2017-03-24 10:34:28,676 INFO [org.ovirt.engine.core.dal. dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-2) [6d6a3a53] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Migration started (VM: druid-co01., Source: vmhost04, Destination: vmhost11, User: admin@internal-authz). 2017-03-24 10:37:59,097 WARN [org.ovirt.engine.core.dal. dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-40) [779e9773] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Failed to migrate VM druid-co01. to Host vmhost11 . Trying to migrate to another Host. 2017-03-24 10:38:00,626 INFO [org.ovirt.engine.core.dal. dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-40) [779e9773] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Migration started (VM: druid-co01, Source: vmhost04, Destination: vmhost08, User: admin@internal-authz). 2017-03-24 10:41:29,441 WARN [org.ovirt.engine.core.dal. dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-42) [6f032492] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Failed to migrate VM druid-co01 to Host vmhost08 . Trying to migrate to another Host. 2017-03-24 10:41:29,488 ERROR [org.ovirt.engine.core.dal. dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-42) [6f032492] Correlation ID: 20518310, Job ID: 039f0694-3e05-4f93-993d-9e7383047873, Call Stack: null, Custom Event ID: -1, Message: Migration failed (VM: druid-co01, Source: vmhost04).
-- Davide Ferrari Senior Systems Engineer
-- Davide Ferrari Senior Systems Engineer
On 03/24/2017 11:58 AM, Davide Ferrari wrote:
And this is the vdsm log from vmhost04:
Thread-6320717::INFO::2017-03-24 11:41:13,019::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 190 seconds elapsed, 98% of data processed, total data: 16456MB, processed data: 9842MB, remaining data: 386MB, transfer speed 52MBps, zero pages: 1718676MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 libvirtEventLoop::DEBUG::2017-03-24 11:41:21,007::vm::4291::virt.vm::(onLibvirtLifecycleEvent) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::event Suspended detail 0 opaque None libvirtEventLoop::INFO::2017-03-24 11:41:21,025::vm::4815::virt.vm::(_logGuestCpuStatus) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::CPU stopped: onSuspend libvirtEventLoop::DEBUG::2017-03-24 11:41:21,069::vm::4291::virt.vm::(onLibvirtLifecycleEvent) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::event Resumed detail 0 opaque None libvirtEventLoop::INFO::2017-03-24 11:41:21,069::vm::4815::virt.vm::(_logGuestCpuStatus) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::CPU running: onResume Thread-6320715::DEBUG::2017-03-24 11:41:21,224::migration::715::virt.vm::(stop) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::stopping migration monitor thread Thread-6320715::ERROR::2017-03-24 11:41:21,225::migration::252::virt.vm::(_recover) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::operation failed: migration job: unexpectedly failed
This is surprising (no pun intended) With a pretty high chance this comes from libvirt, I'm afraid you need to dig in the libvirt logs/journal entries to learn more. Vdsm could unfortunately do better than what it is already doing :\ -- Francesco Romani Senior SW Eng., Virtualization R&D Red Hat IRC: fromani github: @fromanirh
Mmmh this is all I got from libvirt log on receiver host: LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin QEMU_AUDIO_DRV=spice /usr/libexec/qemu-kvm -name guest=druid-co01,debug-threads=on -S -object secret,id=masterKey0,format=raw,file=/var/lib/libvirt/qemu/domain-5-druid-co01/master-key.aes -machine pc-i440fx-rhel7.2.0,accel=kvm,usb=off -cpu Haswell-noTSX -m size=16777216k,slots=16,maxmem=4294967296k -realtime mlock=off -smp 4,maxcpus=64,sockets=16,cores=4,threads=1 -numa node,nodeid=0,cpus=0-3,mem=16384 -uuid 4f627cc1-9b52-4eef-bf3a-c02e8a6303b8 -smbios 'type=1,manufacturer=oVirt,product=oVirt Node,version=7-2.1511.el7.centos.2.10,serial=4C4C4544-0037-4C10-8031-B7C04F564232,uuid=4f627cc1-9b52-4eef-bf3a-c02e8a6303b8' -no-user-config -nodefaults -chardev socket,id=charmonitor,path=/var/lib/libvirt/qemu/domain-5-druid-co01.billydoma/monitor.sock,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=2017-03-24T10:38:03,driftfix=slew -global kvm-pit.lost_tick_policy=discard -no-hpet -no-shutdown -boot strict=on -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x7 -device virtio-serial-pci,id=virtio-serial0,max_ports=16,bus=pci.0,addr=0x4 -drive if=none,id=drive-ide0-1-0,readonly=on -device ide-cd,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0 -drive file=/rhev/data-center/00000001-0001-0001-0001-0000000003e3/ba2bd397-9222-424d-aecc-eb652c0169d9/images/08b19faa-4b1f-4da8-87a2-2af0700a7906/bdb18a7d-1558-41f9-aa3a-e63407c7881e,format=qcow2,if=none,id=drive-virtio-disk0,serial=08b19faa-4b1f-4da8-87a2-2af0700a7906,cache=none,werror=stop,rerror=stop,aio=threads -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x5,drive=drive-virtio-disk0,id=virtio-disk0,bootindex=1 -drive file=/rhev/data-center/00000001-0001-0001-0001-0000000003e3/ba2bd397-9222-424d-aecc-eb652c0169d9/images/987d84da-188b-45c0-99d0-3dde29ddcb6e/51a1b9ee-b0ae-4208-9806-a319d34db06e,format=qcow2,if=none,id=drive-virtio-disk1,serial=987d84da-188b-45c0-99d0-3dde29ddcb6e,cache=none,werror=stop,rerror=stop,aio=threads -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x8,drive=drive-virtio-disk1,id=virtio-disk1 -netdev tap,fd=34,id=hostnet0,vhost=on,vhostfd=35 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=00:1a:4a:16:01:93,bus=pci.0,addr=0x3 -chardev socket,id=charchannel0,path=/var/lib/libvirt/qemu/channels/4f627cc1-9b52-4eef-bf3a-c02e8a6303b8.com.redhat.rhevm.vdsm,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=1,chardev=charchannel0,id=channel0,name=com.redhat.rhevm.vdsm -chardev socket,id=charchannel1,path=/var/lib/libvirt/qemu/channels/4f627cc1-9b52-4eef-bf3a-c02e8a6303b8.org.qemu.guest_agent.0,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=2,chardev=charchannel1,id=channel1,name=org.qemu.guest_agent.0 -chardev spicevmc,id=charchannel2,name=vdagent -device virtserialport,bus=virtio-serial0.0,nr=3,chardev=charchannel2,id=channel2,name=com.redhat.spice.0 -spice tls-port=5904,addr=192.168.10.107,x509-dir=/etc/pki/vdsm/libvirt-spice,tls-channel=default,tls-channel=main,tls-channel=display,tls-channel=inputs,tls-channel=cursor,tls-channel=playback,tls-channel=record,tls-channel=smartcard,tls-channel=usbredir,seamless-migration=on -device qxl-vga,id=video0,ram_size=67108864,vram_size=8388608,vram64_size_mb=0,vgamem_mb=16,bus=pci.0,addr=0x2 -incoming defer -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x6 -msg timestamp=on Domain id=5 is tainted: hook-script 2017-03-24T10:38:03.414396Z qemu-kvm: warning: CPU(s) not present in any NUMA nodes: 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 2017-03-24T10:38:03.414497Z qemu-kvm: warning: All CPU(s) up to maxcpus should be described in NUMA config 2017-03-24 10:41:20.982+0000: shutting down 2017-03-24T10:41:20.986633Z qemu-kvm: load of migration failed: Input/output error Donating host doesn't say a thing about this VM. There's an "input/output error" but I can't see to what is related... 2017-03-24 13:38 GMT+01:00 Francesco Romani <fromani@redhat.com>:
On 03/24/2017 11:58 AM, Davide Ferrari wrote:
And this is the vdsm log from vmhost04:
Thread-6320717::INFO::2017-03-24 11:41:13,019::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 190 seconds elapsed, 98% of data processed, total data: 16456MB, processed data: 9842MB, remaining data: 386MB, transfer speed 52MBps, zero pages: 1718676MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 libvirtEventLoop::DEBUG::2017-03-24 11:41:21,007::vm::4291::virt.vm::(onLibvirtLifecycleEvent) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::event Suspended detail 0 opaque None libvirtEventLoop::INFO::2017-03-24 11:41:21,025::vm::4815::virt.vm::(_logGuestCpuStatus) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::CPU stopped: onSuspend libvirtEventLoop::DEBUG::2017-03-24 11:41:21,069::vm::4291::virt.vm::(onLibvirtLifecycleEvent) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::event Resumed detail 0 opaque None libvirtEventLoop::INFO::2017-03-24 11:41:21,069::vm::4815::virt.vm::(_logGuestCpuStatus) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::CPU running: onResume Thread-6320715::DEBUG::2017-03-24 11:41:21,224::migration::715::virt.vm::(stop) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::stopping migration monitor thread Thread-6320715::ERROR::2017-03-24 11:41:21,225::migration::252::virt.vm::(_recover) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::operation failed: migration job: unexpectedly failed
This is surprising (no pun intended) With a pretty high chance this comes from libvirt, I'm afraid you need to dig in the libvirt logs/journal entries to learn more. Vdsm could unfortunately do better than what it is already doing :\
-- Francesco Romani Senior SW Eng., Virtualization R&D Red Hat IRC: fromani github: @fromanirh
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users
-- Davide Ferrari Senior Systems Engineer
On 24 Mar 2017, at 15:15, Davide Ferrari <davide@billymob.com> wrote: =20 Mmmh this is all I got from libvirt log on receiver host: =20 LC_ALL=3DC PATH=3D/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin = QEMU_AUDIO_DRV=3Dspice /usr/libexec/qemu-kvm -name = guest=3Ddruid-co01,debug-threads=3Don -S -object = secret,id=3DmasterKey0,format=3Draw,file=3D/var/lib/libvirt/qemu/domain-5-= druid-co01/master-key.aes -machine pc-i440fx-rhel7.2.0,accel=3Dkvm,usb=3Do= ff -cpu Haswell-noTSX -m size=3D16777216k,slots=3D16,maxmem=3D4294967296k = -realtime mlock=3Doff -smp 4,maxcpus=3D64,sockets=3D16,cores=3D4,threads=3D= 1 -numa node,nodeid=3D0,cpus=3D0-3,mem=3D16384 -uuid = 4f627cc1-9b52-4eef-bf3a-c02e8a6303b8 -smbios = 'type=3D1,manufacturer=3DoVirt,product=3DoVirt = Node,version=3D7-2.1511.el7.centos.2.10,serial=3D4C4C4544-0037-4C10-8031-B= 7C04F564232,uuid=3D4f627cc1-9b52-4eef-bf3a-c02e8a6303b8' -no-user-config = -nodefaults -chardev = socket,id=3Dcharmonitor,path=3D/var/lib/libvirt/qemu/domain-5-druid-co01.b= illydoma/monitor.sock,server,nowait -mon = chardev=3Dcharmonitor,id=3Dmonitor,mode=3Dcontrol -rtc =
--Apple-Mail=_5B8C2080-30BE-4282-9FAC-08BCCFCC89C1 Content-Transfer-Encoding: quoted-printable Content-Type: text/plain; charset=utf-8 base=3D2017-03-24T10:38:03,driftfix=3Dslew -global = kvm-pit.lost_tick_policy=3Ddiscard -no-hpet -no-shutdown -boot strict=3Don= -device piix3-usb-uhci,id=3Dusb,bus=3Dpci.0,addr=3D0x1.0x2 -device = virtio-scsi-pci,id=3Dscsi0,bus=3Dpci.0,addr=3D0x7 -device = virtio-serial-pci,id=3Dvirtio-serial0,max_ports=3D16,bus=3Dpci.0,addr=3D0x= 4 -drive if=3Dnone,id=3Ddrive-ide0-1-0,readonly=3Don -device = ide-cd,bus=3Dide.1,unit=3D0,drive=3Ddrive-ide0-1-0,id=3Dide0-1-0 -drive = file=3D/rhev/data-center/00000001-0001-0001-0001-0000000003e3/ba2bd397-922= 2-424d-aecc-eb652c0169d9/images/08b19faa-4b1f-4da8-87a2-2af0700a7906/bdb18= a7d-1558-41f9-aa3a-e63407c7881e,format=3Dqcow2,if=3Dnone,id=3Ddrive-virtio= -disk0,serial=3D08b19faa-4b1f-4da8-87a2-2af0700a7906,cache=3Dnone,werror=3D= stop,rerror=3Dstop,aio=3Dthreads -device = virtio-blk-pci,scsi=3Doff,bus=3Dpci.0,addr=3D0x5,drive=3Ddrive-virtio-disk= 0,id=3Dvirtio-disk0,bootindex=3D1 -drive = file=3D/rhev/data-center/00000001-0001-0001-0001-0000000003e3/ba2bd397-922= 2-424d-aecc-eb652c0169d9/images/987d84da-188b-45c0-99d0-3dde29ddcb6e/51a1b= 9ee-b0ae-4208-9806-a319d34db06e,format=3Dqcow2,if=3Dnone,id=3Ddrive-virtio= -disk1,serial=3D987d84da-188b-45c0-99d0-3dde29ddcb6e,cache=3Dnone,werror=3D= stop,rerror=3Dstop,aio=3Dthreads -device = virtio-blk-pci,scsi=3Doff,bus=3Dpci.0,addr=3D0x8,drive=3Ddrive-virtio-disk= 1,id=3Dvirtio-disk1 -netdev tap,fd=3D34,id=3Dhostnet0,vhost=3Don,vhostfd=3D= 35 -device = virtio-net-pci,netdev=3Dhostnet0,id=3Dnet0,mac=3D00:1a:4a:16:01:93,bus=3Dp= ci.0,addr=3D0x3 -chardev = socket,id=3Dcharchannel0,path=3D/var/lib/libvirt/qemu/channels/4f627cc1-9b= 52-4eef-bf3a-c02e8a6303b8.com.redhat.rhevm.vdsm,server,nowait -device = virtserialport,bus=3Dvirtio-serial0.0,nr=3D1,chardev=3Dcharchannel0,id=3Dc= hannel0,name=3Dcom.redhat.rhevm.vdsm -chardev = socket,id=3Dcharchannel1,path=3D/var/lib/libvirt/qemu/channels/4f627cc1-9b= 52-4eef-bf3a-c02e8a6303b8.org.qemu.guest_agent.0,server,nowait -device = virtserialport,bus=3Dvirtio-serial0.0,nr=3D2,chardev=3Dcharchannel1,id=3Dc= hannel1,name=3Dorg.qemu.guest_agent.0 -chardev = spicevmc,id=3Dcharchannel2,name=3Dvdagent -device = virtserialport,bus=3Dvirtio-serial0.0,nr=3D3,chardev=3Dcharchannel2,id=3Dc= hannel2,name=3Dcom.redhat.spice.0 -spice = tls-port=3D5904,addr=3D192.168.10.107,x509-dir=3D/etc/pki/vdsm/libvirt-spi= ce,tls-channel=3Ddefault,tls-channel=3Dmain,tls-channel=3Ddisplay,tls-chan= nel=3Dinputs,tls-channel=3Dcursor,tls-channel=3Dplayback,tls-channel=3Drec= ord,tls-channel=3Dsmartcard,tls-channel=3Dusbredir,seamless-migration=3Don= -device = qxl-vga,id=3Dvideo0,ram_size=3D67108864,vram_size=3D8388608,vram64_size_mb= =3D0,vgamem_mb=3D16,bus=3Dpci.0,addr=3D0x2 -incoming defer -device = virtio-balloon-pci,id=3Dballoon0,bus=3Dpci.0,addr=3D0x6 -msg = timestamp=3Don
Domain id=3D5 is tainted: hook-script 2017-03-24T10:38:03.414396Z qemu-kvm: warning: CPU(s) not present in = any NUMA nodes: 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 = 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 = 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 2017-03-24T10:38:03.414497Z qemu-kvm: warning: All CPU(s) up to = maxcpus should be described in NUMA config 2017-03-24 10:41:20.982+0000: shutting down 2017-03-24T10:41:20.986633Z qemu-kvm: load of migration failed: = Input/output error =20 Donating host doesn't say a thing about this VM. There's an "input/output error" but I can't see to what is related=E2=80= =A6
=20 =20 =20 =20 =20 2017-03-24 13:38 GMT+01:00 Francesco Romani <fromani@redhat.com = <mailto:fromani@redhat.com>>: =20 On 03/24/2017 11:58 AM, Davide Ferrari wrote:
And this is the vdsm log from vmhost04:
Thread-6320717::INFO::2017-03-24 11:41:13,019::migration::712::virt.vm::(monitor_migration) vmId=3D`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: = 190 seconds elapsed, 98% of data processed, total data: 16456MB, =
most likely to the migration stream, either the TCP connection was cut = short or internal bug What are the version of qemu on both ends? host OS? Thanks, michal processed
data: 9842MB, remaining data: 386MB, transfer speed 52MBps, zero pages: 1718676MB, compressed: 0MB, dirty rate: -1, memory iteration: = -1 libvirtEventLoop::DEBUG::2017-03-24 11:41:21,007::vm::4291::virt.vm::(onLibvirtLifecycleEvent) vmId=3D`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::event Suspended = detail 0 opaque None libvirtEventLoop::INFO::2017-03-24 11:41:21,025::vm::4815::virt.vm::(_logGuestCpuStatus) vmId=3D`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::CPU stopped: = onSuspend libvirtEventLoop::DEBUG::2017-03-24 11:41:21,069::vm::4291::virt.vm::(onLibvirtLifecycleEvent) vmId=3D`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::event Resumed detail = 0 opaque None libvirtEventLoop::INFO::2017-03-24 11:41:21,069::vm::4815::virt.vm::(_logGuestCpuStatus) vmId=3D`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::CPU running: onResume Thread-6320715::DEBUG::2017-03-24 11:41:21,224::migration::715::virt.vm::(stop) vmId=3D`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::stopping migration monitor thread Thread-6320715::ERROR::2017-03-24 11:41:21,225::migration::252::virt.vm::(_recover) vmId=3D`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::operation failed: migration job: unexpectedly failed =20 This is surprising (no pun intended) With a pretty high chance this comes from libvirt, I'm afraid you need to dig in the libvirt logs/journal entries to learn more. Vdsm could unfortunately do better than what it is already doing :\ =20 -- Francesco Romani Senior SW Eng., Virtualization R&D Red Hat IRC: fromani github: @fromanirh =20
Users mailing list Users@ovirt.org <mailto:Users@ovirt.org> http://lists.ovirt.org/mailman/listinfo/users = <http://lists.ovirt.org/mailman/listinfo/users> =20 =20 =20 --=20 Davide Ferrari Senior Systems Engineer _______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users
--Apple-Mail=_5B8C2080-30BE-4282-9FAC-08BCCFCC89C1 Content-Transfer-Encoding: quoted-printable Content-Type: text/html; charset=utf-8 <html><head><meta http-equiv=3D"Content-Type" content=3D"text/html = charset=3Dutf-8"></head><body style=3D"word-wrap: break-word; = -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" = class=3D""><br class=3D""><div><blockquote type=3D"cite" class=3D""><div = class=3D"">On 24 Mar 2017, at 15:15, Davide Ferrari <<a = href=3D"mailto:davide@billymob.com" class=3D"">davide@billymob.com</a>>= wrote:</div><br class=3D"Apple-interchange-newline"><div class=3D""><div = dir=3D"ltr" class=3D""><div class=3D""><div class=3D"">Mmmh this is all = I got from libvirt log on receiver host:<br class=3D""><br = class=3D"">LC_ALL=3DC = PATH=3D/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin = QEMU_AUDIO_DRV=3Dspice /usr/libexec/qemu-kvm -name = guest=3Ddruid-co01,debug-threads=3Don -S -object = secret,id=3DmasterKey0,format=3Draw,file=3D/var/lib/libvirt/qemu/domain-5-= druid-co01/master-key.aes -machine pc-i440fx-rhel7.2.0,accel=3Dkvm,usb=3Do= ff -cpu Haswell-noTSX -m size=3D16777216k,slots=3D16,maxmem=3D4294967296k = -realtime mlock=3Doff -smp 4,maxcpus=3D64,sockets=3D16,cores=3D4,threads=3D= 1 -numa node,nodeid=3D0,cpus=3D0-3,mem=3D16384 -uuid = 4f627cc1-9b52-4eef-bf3a-c02e8a6303b8 -smbios = 'type=3D1,manufacturer=3DoVirt,product=3DoVirt = Node,version=3D7-2.1511.el7.centos.2.10,serial=3D4C4C4544-0037-4C10-8031-B= 7C04F564232,uuid=3D4f627cc1-9b52-4eef-bf3a-c02e8a6303b8' -no-user-config = -nodefaults -chardev = socket,id=3Dcharmonitor,path=3D/var/lib/libvirt/qemu/domain-5-druid-co01.b= illydoma/monitor.sock,server,nowait -mon = chardev=3Dcharmonitor,id=3Dmonitor,mode=3Dcontrol -rtc = base=3D2017-03-24T10:38:03,driftfix=3Dslew -global = kvm-pit.lost_tick_policy=3Ddiscard -no-hpet -no-shutdown -boot strict=3Don= -device piix3-usb-uhci,id=3Dusb,bus=3Dpci.0,addr=3D0x1.0x2 -device = virtio-scsi-pci,id=3Dscsi0,bus=3Dpci.0,addr=3D0x7 -device = virtio-serial-pci,id=3Dvirtio-serial0,max_ports=3D16,bus=3Dpci.0,addr=3D0x= 4 -drive if=3Dnone,id=3Ddrive-ide0-1-0,readonly=3Don -device = ide-cd,bus=3Dide.1,unit=3D0,drive=3Ddrive-ide0-1-0,id=3Dide0-1-0 -drive = file=3D/rhev/data-center/00000001-0001-0001-0001-0000000003e3/ba2bd397-922= 2-424d-aecc-eb652c0169d9/images/08b19faa-4b1f-4da8-87a2-2af0700a7906/bdb18= a7d-1558-41f9-aa3a-e63407c7881e,format=3Dqcow2,if=3Dnone,id=3Ddrive-virtio= -disk0,serial=3D08b19faa-4b1f-4da8-87a2-2af0700a7906,cache=3Dnone,werror=3D= stop,rerror=3Dstop,aio=3Dthreads -device = virtio-blk-pci,scsi=3Doff,bus=3Dpci.0,addr=3D0x5,drive=3Ddrive-virtio-disk= 0,id=3Dvirtio-disk0,bootindex=3D1 -drive = file=3D/rhev/data-center/00000001-0001-0001-0001-0000000003e3/ba2bd397-922= 2-424d-aecc-eb652c0169d9/images/987d84da-188b-45c0-99d0-3dde29ddcb6e/51a1b= 9ee-b0ae-4208-9806-a319d34db06e,format=3Dqcow2,if=3Dnone,id=3Ddrive-virtio= -disk1,serial=3D987d84da-188b-45c0-99d0-3dde29ddcb6e,cache=3Dnone,werror=3D= stop,rerror=3Dstop,aio=3Dthreads -device = virtio-blk-pci,scsi=3Doff,bus=3Dpci.0,addr=3D0x8,drive=3Ddrive-virtio-disk= 1,id=3Dvirtio-disk1 -netdev tap,fd=3D34,id=3Dhostnet0,vhost=3Don,vhostfd=3D= 35 -device = virtio-net-pci,netdev=3Dhostnet0,id=3Dnet0,mac=3D00:1a:4a:16:01:93,bus=3Dp= ci.0,addr=3D0x3 -chardev = socket,id=3Dcharchannel0,path=3D/var/lib/libvirt/qemu/channels/4f627cc1-9b= 52-4eef-bf3a-c02e8a6303b8.com.redhat.rhevm.vdsm,server,nowait -device = virtserialport,bus=3Dvirtio-serial0.0,nr=3D1,chardev=3Dcharchannel0,id=3Dc= hannel0,name=3Dcom.redhat.rhevm.vdsm -chardev = socket,id=3Dcharchannel1,path=3D/var/lib/libvirt/qemu/channels/4f627cc1-9b= 52-4eef-bf3a-c02e8a6303b8.org.qemu.guest_agent.0,server,nowait -device = virtserialport,bus=3Dvirtio-serial0.0,nr=3D2,chardev=3Dcharchannel1,id=3Dc= hannel1,name=3Dorg.qemu.guest_agent.0 -chardev = spicevmc,id=3Dcharchannel2,name=3Dvdagent -device = virtserialport,bus=3Dvirtio-serial0.0,nr=3D3,chardev=3Dcharchannel2,id=3Dc= hannel2,name=3Dcom.redhat.spice.0 -spice = tls-port=3D5904,addr=3D192.168.10.107,x509-dir=3D/etc/pki/vdsm/libvirt-spi= ce,tls-channel=3Ddefault,tls-channel=3Dmain,tls-channel=3Ddisplay,tls-chan= nel=3Dinputs,tls-channel=3Dcursor,tls-channel=3Dplayback,tls-channel=3Drec= ord,tls-channel=3Dsmartcard,tls-channel=3Dusbredir,seamless-migration=3Don= -device = qxl-vga,id=3Dvideo0,ram_size=3D67108864,vram_size=3D8388608,vram64_size_mb= =3D0,vgamem_mb=3D16,bus=3Dpci.0,addr=3D0x2 -incoming defer -device = virtio-balloon-pci,id=3Dballoon0,bus=3Dpci.0,addr=3D0x6 -msg = timestamp=3Don<br class=3D"">Domain id=3D5 is tainted: hook-script<br = class=3D"">2017-03-24T10:38:03.414396Z qemu-kvm: warning: CPU(s) not = present in any NUMA nodes: 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 = 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 = 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63<br = class=3D"">2017-03-24T10:38:03.414497Z qemu-kvm: warning: All CPU(s) up = to maxcpus should be described in NUMA config<br class=3D"">2017-03-24 = 10:41:20.982+0000: shutting down<br class=3D"">2017-03-24T10:41:20.986633Z= qemu-kvm: load of migration failed: Input/output error<br class=3D""><br = class=3D""></div>Donating host doesn't say a thing about this VM.<br = class=3D""></div>There's an "input/output error" but I can't see to what = is related=E2=80=A6</div></div></blockquote><div><br class=3D""></div>most= likely to the migration stream, either the TCP connection was cut short = or internal bug</div><div>What are the version of qemu on both ends? = host OS?</div><div><br = class=3D""></div><div>Thanks,</div><div>michal</div><div><br = class=3D""><blockquote type=3D"cite" class=3D""><div class=3D""><div = dir=3D"ltr" class=3D""><br class=3D""><br class=3D""><div class=3D""><div = class=3D""><br class=3D""><br class=3D""></div></div></div><div = class=3D"gmail_extra"><br class=3D""><div class=3D"gmail_quote">2017-03-24= 13:38 GMT+01:00 Francesco Romani <span dir=3D"ltr" class=3D""><<a = href=3D"mailto:fromani@redhat.com" target=3D"_blank" = class=3D"">fromani@redhat.com</a>></span>:<br class=3D""><blockquote = class=3D"gmail_quote" style=3D"margin:0 0 0 .8ex;border-left:1px #ccc = solid;padding-left:1ex"><span class=3D""><br class=3D""> On 03/24/2017 11:58 AM, Davide Ferrari wrote:<br class=3D""> > And this is the vdsm log from vmhost04:<br class=3D""> ><br class=3D""> </span><div class=3D""><div class=3D"h5">> = Thread-6320717::INFO::2017-03-<wbr class=3D"">24<br class=3D""> > 11:41:13,019::migration::712::<wbr = class=3D"">virt.vm::(monitor_migration)<br class=3D""> > vmId=3D`4f627cc1-9b52-4eef-bf3a-<wbr = class=3D"">c02e8a6303b8`::Migration Progress: 190<br class=3D""> > seconds elapsed, 98% of data processed, total data: 16456MB, = processed<br class=3D""> > data: 9842MB, remaining data: 386MB, transfer speed 52MBps, zero<br = class=3D""> > pages: 1718676MB, compressed: 0MB, dirty rate: -1, memory = iteration: -1<br class=3D""> > libvirtEventLoop::DEBUG::2017-<wbr class=3D"">03-24<br class=3D""> > 11:41:21,007::vm::4291::virt.<wbr = class=3D"">vm::(onLibvirtLifecycleEvent)<br class=3D""> > vmId=3D`4f627cc1-9b52-4eef-bf3a-<wbr class=3D"">c02e8a6303b8`::event = Suspended detail 0<br class=3D""> > opaque None<br class=3D""> > libvirtEventLoop::INFO::2017-<wbr class=3D"">03-24<br class=3D""> > 11:41:21,025::vm::4815::virt.<wbr = class=3D"">vm::(_logGuestCpuStatus)<br class=3D""> > vmId=3D`4f627cc1-9b52-4eef-bf3a-<wbr class=3D"">c02e8a6303b8`::CPU = stopped: onSuspend<br class=3D""> > libvirtEventLoop::DEBUG::2017-<wbr class=3D"">03-24<br class=3D""> > 11:41:21,069::vm::4291::virt.<wbr = class=3D"">vm::(onLibvirtLifecycleEvent)<br class=3D""> > vmId=3D`4f627cc1-9b52-4eef-bf3a-<wbr class=3D"">c02e8a6303b8`::event = Resumed detail 0<br class=3D""> > opaque None<br class=3D""> > libvirtEventLoop::INFO::2017-<wbr class=3D"">03-24<br class=3D""> > 11:41:21,069::vm::4815::virt.<wbr = class=3D"">vm::(_logGuestCpuStatus)<br class=3D""> > vmId=3D`4f627cc1-9b52-4eef-bf3a-<wbr class=3D"">c02e8a6303b8`::CPU = running: onResume<br class=3D""> > Thread-6320715::DEBUG::2017-<wbr class=3D"">03-24<br class=3D""> > 11:41:21,224::migration::715::<wbr class=3D"">virt.vm::(stop)<br = class=3D""> > vmId=3D`4f627cc1-9b52-4eef-bf3a-<wbr = class=3D"">c02e8a6303b8`::stopping migration<br class=3D""> > monitor thread<br class=3D""> > Thread-6320715::ERROR::2017-<wbr class=3D"">03-24<br class=3D""> > 11:41:21,225::migration::252::<wbr class=3D"">virt.vm::(_recover)<br = class=3D""> > vmId=3D`4f627cc1-9b52-4eef-bf3a-<wbr = class=3D"">c02e8a6303b8`::operation failed:<br class=3D""> > migration job: unexpectedly failed<br class=3D""> <br class=3D""> </div></div>This is surprising (no pun intended)<br class=3D""> With a pretty high chance this comes from libvirt, I'm afraid you = need<br class=3D""> to dig in the libvirt logs/journal entries to learn more.<br class=3D""> Vdsm could unfortunately do better than what it is already doing :\<br = class=3D""> <span class=3D"HOEnZb"><font color=3D"#888888" class=3D""><br class=3D""> --<br class=3D""> Francesco Romani<br class=3D""> Senior SW Eng., Virtualization R&D<br class=3D""> Red Hat<br class=3D""> IRC: fromani github: @fromanirh<br class=3D""> <br class=3D""> ______________________________<wbr class=3D"">_________________<br = class=3D""> Users mailing list<br class=3D""> <a href=3D"mailto:Users@ovirt.org" class=3D"">Users@ovirt.org</a><br = class=3D""> <a href=3D"http://lists.ovirt.org/mailman/listinfo/users" = rel=3D"noreferrer" target=3D"_blank" = class=3D"">http://lists.ovirt.org/<wbr = class=3D"">mailman/listinfo/users</a><br class=3D""> </font></span></blockquote></div><br class=3D""><br clear=3D"all" = class=3D""><br class=3D"">-- <br class=3D""><div class=3D"gmail_signature"= data-smartmail=3D"gmail_signature"><div dir=3D"ltr" class=3D""><div = class=3D"">Davide Ferrari<br class=3D""></div>Senior Systems Engineer<br = class=3D""></div></div> </div> _______________________________________________<br class=3D"">Users = mailing list<br class=3D""><a href=3D"mailto:Users@ovirt.org" = class=3D"">Users@ovirt.org</a><br = class=3D"">http://lists.ovirt.org/mailman/listinfo/users<br = class=3D""></div></blockquote></div><br class=3D""></body></html>= --Apple-Mail=_5B8C2080-30BE-4282-9FAC-08BCCFCC89C1--
Source: CentOS 7.2 - qemu-kvm-ev-2.3.0-31.el7.16.1 Dest: CentOS 7.3 - qemu-kvm-ev-2.6.0-28.el7_3.3.1 To be fair I'm trying to migrate away that VM so I can install updates on the source host. 2017-03-24 15:18 GMT+01:00 Michal Skrivanek <michal.skrivanek@redhat.com>:
On 24 Mar 2017, at 15:15, Davide Ferrari <davide@billymob.com> wrote:
Mmmh this is all I got from libvirt log on receiver host:
LC_ALL=C PATH=/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin QEMU_AUDIO_DRV=spice /usr/libexec/qemu-kvm -name guest=druid-co01,debug-threads=on -S -object secret,id=masterKey0,format=raw,file=/var/lib/libvirt/ qemu/domain-5-druid-co01/master-key.aes -machine pc-i440fx-rhel7.2.0,accel=kvm,usb=off -cpu Haswell-noTSX -m size=16777216k,slots=16,maxmem=4294967296k -realtime mlock=off -smp 4,maxcpus=64,sockets=16,cores=4,threads=1 -numa node,nodeid=0,cpus=0-3,mem=16384 -uuid 4f627cc1-9b52-4eef-bf3a-c02e8a6303b8 -smbios 'type=1,manufacturer=oVirt,product=oVirt Node,version=7-2.1511.el7.centos.2.10,serial=4C4C4544- 0037-4C10-8031-B7C04F564232,uuid=4f627cc1-9b52-4eef-bf3a-c02e8a6303b8' -no-user-config -nodefaults -chardev socket,id=charmonitor,path=/ var/lib/libvirt/qemu/domain-5-druid-co01.billydoma/monitor.sock,server,nowait -mon chardev=charmonitor,id=monitor,mode=control -rtc base=2017-03-24T10:38:03,driftfix=slew -global kvm-pit.lost_tick_policy=discard -no-hpet -no-shutdown -boot strict=on -device piix3-usb-uhci,id=usb,bus=pci.0,addr=0x1.0x2 -device virtio-scsi-pci,id=scsi0,bus=pci.0,addr=0x7 -device virtio-serial-pci,id=virtio-serial0,max_ports=16,bus=pci.0,addr=0x4 -drive if=none,id=drive-ide0-1-0,readonly=on -device ide-cd,bus=ide.1,unit=0,drive=drive-ide0-1-0,id=ide0-1-0 -drive file=/rhev/data-center/00000001-0001-0001-0001-0000000003e3/ba2bd397-9222- 424d-aecc-eb652c0169d9/images/08b19faa-4b1f-4da8-87a2- 2af0700a7906/bdb18a7d-1558-41f9-aa3a-e63407c7881e,format= qcow2,if=none,id=drive-virtio-disk0,serial=08b19faa-4b1f- 4da8-87a2-2af0700a7906,cache=none,werror=stop,rerror=stop,aio=threads -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x5,drive=drive- virtio-disk0,id=virtio-disk0,bootindex=1 -drive file=/rhev/data-center/ 00000001-0001-0001-0001-0000000003e3/ba2bd397-9222- 424d-aecc-eb652c0169d9/images/987d84da-188b-45c0-99d0- 3dde29ddcb6e/51a1b9ee-b0ae-4208-9806-a319d34db06e,format= qcow2,if=none,id=drive-virtio-disk1,serial=987d84da-188b- 45c0-99d0-3dde29ddcb6e,cache=none,werror=stop,rerror=stop,aio=threads -device virtio-blk-pci,scsi=off,bus=pci.0,addr=0x8,drive=drive-virtio-disk1,id=virtio-disk1 -netdev tap,fd=34,id=hostnet0,vhost=on,vhostfd=35 -device virtio-net-pci,netdev=hostnet0,id=net0,mac=00:1a:4a:16:01:93,bus=pci.0,addr=0x3 -chardev socket,id=charchannel0,path=/var/lib/libvirt/qemu/channels/ 4f627cc1-9b52-4eef-bf3a-c02e8a6303b8.com.redhat.rhevm.vdsm,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=1,chardev= charchannel0,id=channel0,name=com.redhat.rhevm.vdsm -chardev socket,id=charchannel1,path=/var/lib/libvirt/qemu/channels/ 4f627cc1-9b52-4eef-bf3a-c02e8a6303b8.org.qemu.guest_agent.0,server,nowait -device virtserialport,bus=virtio-serial0.0,nr=2,chardev= charchannel1,id=channel1,name=org.qemu.guest_agent.0 -chardev spicevmc,id=charchannel2,name=vdagent -device virtserialport,bus=virtio- serial0.0,nr=3,chardev=charchannel2,id=channel2,name=com.redhat.spice.0 -spice tls-port=5904,addr=192.168.10.107,x509-dir=/etc/pki/vdsm/ libvirt-spice,tls-channel=default,tls-channel=main,tls- channel=display,tls-channel=inputs,tls-channel=cursor,tls- channel=playback,tls-channel=record,tls-channel=smartcard, tls-channel=usbredir,seamless-migration=on -device qxl-vga,id=video0,ram_size=67108864,vram_size=8388608, vram64_size_mb=0,vgamem_mb=16,bus=pci.0,addr=0x2 -incoming defer -device virtio-balloon-pci,id=balloon0,bus=pci.0,addr=0x6 -msg timestamp=on Domain id=5 is tainted: hook-script 2017-03-24T10:38:03.414396Z qemu-kvm: warning: CPU(s) not present in any NUMA nodes: 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 26 27 28 29 30 31 32 33 34 35 36 37 38 39 40 41 42 43 44 45 46 47 48 49 50 51 52 53 54 55 56 57 58 59 60 61 62 63 2017-03-24T10:38:03.414497Z qemu-kvm: warning: All CPU(s) up to maxcpus should be described in NUMA config 2017-03-24 10:41:20.982+0000: shutting down 2017-03-24T10:41:20.986633Z qemu-kvm: load of migration failed: Input/output error
Donating host doesn't say a thing about this VM. There's an "input/output error" but I can't see to what is related…
most likely to the migration stream, either the TCP connection was cut short or internal bug What are the version of qemu on both ends? host OS?
Thanks, michal
2017-03-24 13:38 GMT+01:00 Francesco Romani <fromani@redhat.com>:
On 03/24/2017 11:58 AM, Davide Ferrari wrote:
And this is the vdsm log from vmhost04:
Thread-6320717::INFO::2017-03-24 11:41:13,019::migration::712::virt.vm::(monitor_migration) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::Migration Progress: 190 seconds elapsed, 98% of data processed, total data: 16456MB, processed data: 9842MB, remaining data: 386MB, transfer speed 52MBps, zero pages: 1718676MB, compressed: 0MB, dirty rate: -1, memory iteration: -1 libvirtEventLoop::DEBUG::2017-03-24 11:41:21,007::vm::4291::virt.vm::(onLibvirtLifecycleEvent) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::event Suspended detail 0 opaque None libvirtEventLoop::INFO::2017-03-24 11:41:21,025::vm::4815::virt.vm::(_logGuestCpuStatus) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::CPU stopped: onSuspend libvirtEventLoop::DEBUG::2017-03-24 11:41:21,069::vm::4291::virt.vm::(onLibvirtLifecycleEvent) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::event Resumed detail 0 opaque None libvirtEventLoop::INFO::2017-03-24 11:41:21,069::vm::4815::virt.vm::(_logGuestCpuStatus) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::CPU running: onResume Thread-6320715::DEBUG::2017-03-24 11:41:21,224::migration::715::virt.vm::(stop) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::stopping migration monitor thread Thread-6320715::ERROR::2017-03-24 11:41:21,225::migration::252::virt.vm::(_recover) vmId=`4f627cc1-9b52-4eef-bf3a-c02e8a6303b8`::operation failed: migration job: unexpectedly failed
This is surprising (no pun intended) With a pretty high chance this comes from libvirt, I'm afraid you need to dig in the libvirt logs/journal entries to learn more. Vdsm could unfortunately do better than what it is already doing :\
-- Francesco Romani Senior SW Eng., Virtualization R&D Red Hat IRC: fromani github: @fromanirh
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users
-- Davide Ferrari Senior Systems Engineer _______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users
-- Davide Ferrari Senior Systems Engineer
On 03/24/2017 04:01 PM, Davide Ferrari wrote:
Source: CentOS 7.2 - qemu-kvm-ev-2.3.0-31.el7.16.1 Dest: CentOS 7.3 - qemu-kvm-ev-2.6.0-28.el7_3.3.1
To be fair I'm trying to migrate away that VM so I can install updates on the source host.
Another, hopefully less likely, case is a QEMu bug. If QEMU cannot correctly restore the VM state from the migration data stream, you'll get the same error. Anyway, this definitely looks like libvirt/qemu issue; better be prepared to file a libvirt bug. does it happen migrating to *any* CentOS7.3 box? Bests, -- Francesco Romani Senior SW Eng., Virtualization R&D Red Hat IRC: fromani github: @fromanirh
Hello again Yep, it fails to migrate to any 7.3 host. I still have to try to migrate to one of the old 7.2 hosts, I'll let you know 2017-03-27 13:51 GMT+02:00 Francesco Romani <fromani@redhat.com>:
On 03/24/2017 04:01 PM, Davide Ferrari wrote:
Source: CentOS 7.2 - qemu-kvm-ev-2.3.0-31.el7.16.1 Dest: CentOS 7.3 - qemu-kvm-ev-2.6.0-28.el7_3.3.1
To be fair I'm trying to migrate away that VM so I can install updates on the source host.
Another, hopefully less likely, case is a QEMu bug. If QEMU cannot correctly restore the VM state from the migration data stream, you'll get the same error. Anyway, this definitely looks like libvirt/qemu issue; better be prepared to file a libvirt bug. does it happen migrating to *any* CentOS7.3 box?
Bests,
-- Francesco Romani Senior SW Eng., Virtualization R&D Red Hat IRC: fromani github: @fromanirh
-- Davide Ferrari Senior Systems Engineer
It fails even when trying to migrate to a CentOS 7.2 host :/ I guess I'll have to shut it down then :( 2017-03-30 9:55 GMT+02:00 Davide Ferrari <davide@billymob.com>:
Hello again
Yep, it fails to migrate to any 7.3 host. I still have to try to migrate to one of the old 7.2 hosts, I'll let you know
2017-03-27 13:51 GMT+02:00 Francesco Romani <fromani@redhat.com>:
On 03/24/2017 04:01 PM, Davide Ferrari wrote:
Source: CentOS 7.2 - qemu-kvm-ev-2.3.0-31.el7.16.1 Dest: CentOS 7.3 - qemu-kvm-ev-2.6.0-28.el7_3.3.1
To be fair I'm trying to migrate away that VM so I can install updates on the source host.
Another, hopefully less likely, case is a QEMu bug. If QEMU cannot correctly restore the VM state from the migration data stream, you'll get the same error. Anyway, this definitely looks like libvirt/qemu issue; better be prepared to file a libvirt bug. does it happen migrating to *any* CentOS7.3 box?
Bests,
-- Francesco Romani Senior SW Eng., Virtualization R&D Red Hat IRC: fromani github: @fromanirh
-- Davide Ferrari Senior Systems Engineer
-- Davide Ferrari Senior Systems Engineer
participants (3)
-
Davide Ferrari -
Francesco Romani -
Michal Skrivanek