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