Issue

• VM fails to live migrate with the following messages in the logs:

  The migration took 390 seconds which is exceeding the configured maximum time for migrations of 384 seconds.The migration will be aborted.
  Migration failed due to Error:Migration not in progress
  

  # less /var/log/ovirt-engine/engine.log

  2014-08-06 12:33:10,403 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (org.ovirt.thread.pool-4-thread-14) Command MigrateStatusVDSCommand(HostName = xxxxx, HostId = f3e83168-85a2-11e2-a7eb-0050569b005f, vmId=0aec5524-a1ac-4114-8b33-877d90862bbd) execution failed.Exception:VDSErrorException:VDSGenericException:VDSErrorException:Failed to MigrateStatusVDS, error = Migration canceled, code = 47  <<<< 
  ..
  ..
  2014-08-06 12:33:10,465 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-4-thread-14) Correlation ID:48699621, Job ID:7ccbd79a-d6dc-48b0-95c4-2f8dc8cb671b, Call Stack: null, Custom Event ID:-1, Message:Migration failed due to Error:Migration not in progress (VM: abcd02, Source: xxxx03, Destination: xxxx04).<<<<
  

  # less /var/log/vdsm/vdsm.log

  Thread-18752::WARNING::2014-08-06 12:32:45,047::vm::853::vm.Vm::(run) vmId=`0aec5524-a1ac-4114-8b33-877d90862bbd`::Migration stalling: remaining (1334MiB) > lowmark (1100MiB).Refer to RHBZ#919201.
  Thread-18752::INFO::2014-08-06 12:32:45,048::vm::865::vm.Vm::(run) vmId=`0aec5524-a1ac-4114-8b33-877d90862bbd`::Migration Progress:370 seconds elapsed, 90% of data processed, 90% of mem processed
  ..
  ..
  Thread-18752::INFO::2014-08-06 12:32:55,053::vm::865::vm.Vm::(run) vmId=`0aec5524-a1ac-4114-8b33-877d90862bbd`::Migration Progress:380 seconds elapsed, 92% of data processed, 92% of mem processed
  ..
  ..
  Thread-18752::WARNING::2014-08-06 12:33:05,059::vm::830::vm.Vm::(run) vmId=`0aec5524-a1ac-4114-8b33-877d90862bbd`::The migration took 390 seconds which is exceeding the configured maximum time for migrations of 384 seconds.The migration will be aborted.<<<<
  ..
  ..
  Thread-18752::DEBUG::2014-08-06 12:33:05,122::vm::868::vm.Vm::(stop) vmId=`0aec5524-a1ac-4114-8b33-877d90862bbd`::stopping migration monitor thread
  libvirtEventLoop::DEBUG::2014-08-06 12:33:06,363::vm::5176::vm.Vm::(_onLibvirtLifecycleEvent) vmId=`0aec5524-a1ac-4114-8b33-877d90862bbd`::event Resumed detail 1 opaque None
  Thread-18750::DEBUG::2014/08/06 12:33:06,371::libvirtconnection::124::root::(wrapper) Unknown libvirterror: ecode:78 edom:10 level:2 message: operation aborted: migration job: canceled by client
  Thread-18750::DEBUG::2014-08-06 12:33:06,372::vm::780::vm.Vm::(cancel) vmId=`0aec5524-a1ac-4114-8b33-877d90862bbd`::canceling migration downtime thread
  Thread-18750::DEBUG::2014-08-06 12:33:06,373::vm::868::vm.Vm::(stop) vmId=`0aec5524-a1ac-4114-8b33-877d90862bbd`::stopping migration monitor thread
  Thread-18751::DEBUG::2014-08-06 12:33:06,374::vm::777::vm.Vm::(run) vmId=`0aec5524-a1ac-4114-8b33-877d90862bbd`::migration downtime thread exiting
  Thread-18750::ERROR::2014-08-06 12:33:06,378::vm::229::vm.Vm::(_recover) vmId=`0aec5524-a1ac-4114-8b33-877d90862bbd`::operation aborted: migration job: canceled by client
  Thread-18750::ERROR::2014-08-06 12:33:06,642::vm::328::vm.Vm::(run) vmId=`0aec5524-a1ac-4114-8b33-877d90862bbd`::Failed to migrate
  Traceback (most recent call last):
  File "/usr/share/vdsm/vm.py", line 314, in run
    self._startUnderlyingMigration(time.time())
  File "/usr/share/vdsm/vm.py", line 396, in _startUnderlyingMigration
  None, maxBandwidth)
  File "/usr/share/vdsm/vm.py", line 891, in f
    ret = attr(*args, **kwargs)
  File "/usr/lib64/python2.6/site-packages/vdsm/libvirtconnection.py", line 92, in wrapper
    ret = f(*args, **kwargs)
  File "/usr/lib64/python2.6/site-packages/libvirt.py", line 1178, in migrateToURI2
    if ret == -1: raise libvirtError ('virDomainMigrateToURI2() failed', dom=self)
  libvirtError: operation aborted: migration job: canceled by client