2017-11-07 11:25:09,706+01 INFO  [org.ovirt.engine.core.bll.MigrateVmToServerCommand] (default task-7) [68971ee3-707e-4bf7-91ce-9826fc254d64] Lock Acquired to object 'EngineLock:{exclusiveLocks='[d4ddd4d1-2de4-4ace-900d-76552cadefb0=VM]', sharedLocks=''}'
2017-11-07 11:25:09,878+01 INFO  [org.ovirt.engine.core.bll.MigrateVmToServerCommand] (org.ovirt.thread.pool-6-thread-6) [68971ee3-707e-4bf7-91ce-9826fc254d64] Running command: MigrateVmToServerCommand internal: false. Entities affected :  ID: d4ddd4d1-2de4-4ace-900d-76552cadefb0 Type: VMAction group MIGRATE_VM with role type USER
2017-11-07 11:25:10,225+01 INFO  [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand] (org.ovirt.thread.pool-6-thread-6) [68971ee3-707e-4bf7-91ce-9826fc254d64] START, MigrateVDSCommand( MigrateVDSCommandParameters:{runAsync='true', hostId='f162d746-3541-4b30-8e00-dfc91799e054', vmId='d4ddd4d1-2de4-4ace-900d-76552cadefb0', srcHost='ov-test-04-02.ovn.some.domain', dstVdsId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', dstHost='ov-test-04-01.ovn.some.domain:54321', migrationMethod='ONLINE', tunnelMigration='false', migrationDowntime='0', autoConverge='false', migrateCompressed='false', consoleAddress='null', maxBandwidth='null', enableGuestEvents='false', maxIncomingMigrations='2', maxOutgoingMigrations='2', convergenceSchedule='null'}), log id: 71a17aae
2017-11-07 11:25:10,225+01 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-thread-6) [68971ee3-707e-4bf7-91ce-9826fc254d64] START, MigrateBrokerVDSCommand(HostName = ov-test-04-02, MigrateVDSCommandParameters:{runAsync='true', hostId='f162d746-3541-4b30-8e00-dfc91799e054', vmId='d4ddd4d1-2de4-4ace-900d-76552cadefb0', srcHost='ov-test-04-02.ovn.some.domain', dstVdsId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', dstHost='ov-test-04-01.ovn.some.domain:54321', migrationMethod='ONLINE', tunnelMigration='false', migrationDowntime='0', autoConverge='false', migrateCompressed='false', consoleAddress='null', maxBandwidth='null', enableGuestEvents='false', maxIncomingMigrations='2', maxOutgoingMigrations='2', convergenceSchedule='null'}), log id: 13e47e7b
2017-11-07 11:25:11,409+01 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-thread-6) [68971ee3-707e-4bf7-91ce-9826fc254d64] FINISH, MigrateBrokerVDSCommand, log id: 13e47e7b
2017-11-07 11:25:11,423+01 INFO  [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand] (org.ovirt.thread.pool-6-thread-6) [68971ee3-707e-4bf7-91ce-9826fc254d64] FINISH, MigrateVDSCommand, return: MigratingFrom, log id: 71a17aae
2017-11-07 11:25:11,441+01 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-6) [68971ee3-707e-4bf7-91ce-9826fc254d64] EVENT_ID: VM_MIGRATION_START(62), Correlation ID: 68971ee3-707e-4bf7-91ce-9826fc254d64, Job ID: c586546c-6bf0-418e-ba75-3ebe37eea0dd, Call Stack: null, Custom ID: null, Custom Event ID: -1, Message: Migration started (VM: ovirt-test03_win2012, Source: ov-test-04-02, Destination: ov-test-04-01, User: admin@internal-authz). 
2017-11-07 11:25:11,494+01 INFO  [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-2) [] VM 'd4ddd4d1-2de4-4ace-900d-76552cadefb0' was reported as Down on VDS 'd8794e95-3f89-4b1a-9bec-12ccf6db0cb1'(ov-test-04-01)
2017-11-07 11:25:11,495+01 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-2) [] START, DestroyVDSCommand(HostName = ov-test-04-01, DestroyVmVDSCommandParameters:{runAsync='true', hostId='d8794e95-3f89-4b1a-9bec-12ccf6db0cb1', vmId='d4ddd4d1-2de4-4ace-900d-76552cadefb0', force='false', secondsToWait='0', gracefully='false', reason='', ignoreNoVm='true'}), log id: 7f5e7600
2017-11-07 11:25:12,521+01 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-2) [] Failed to destroy VM 'd4ddd4d1-2de4-4ace-900d-76552cadefb0' because VM does not exist, ignoring
2017-11-07 11:25:12,521+01 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-2) [] FINISH, DestroyVDSCommand, log id: 7f5e7600
2017-11-07 11:25:12,521+01 INFO  [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-2) [] VM 'd4ddd4d1-2de4-4ace-900d-76552cadefb0'(ovirt-test03_win2012) was unexpectedly detected as 'Down' on VDS 'd8794e95-3f89-4b1a-9bec-12ccf6db0cb1'(ov-test-04-01) (expected on 'f162d746-3541-4b30-8e00-dfc91799e054')
2017-11-07 11:25:23,459+01 INFO  [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (DefaultQuartzScheduler6) [16ccff7b] VM 'd4ddd4d1-2de4-4ace-900d-76552cadefb0'(ovirt-test03_win2012) moved from 'MigratingFrom' --> 'Up'
2017-11-07 11:25:23,459+01 INFO  [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (DefaultQuartzScheduler6) [16ccff7b] Adding VM 'd4ddd4d1-2de4-4ace-900d-76552cadefb0'(ovirt-test03_win2012) to re-run list
2017-11-07 11:25:23,467+01 ERROR [org.ovirt.engine.core.vdsbroker.monitoring.VmsMonitoring] (DefaultQuartzScheduler6) [16ccff7b] Rerun VM 'd4ddd4d1-2de4-4ace-900d-76552cadefb0'. Called from VDS 'ov-test-04-02'
2017-11-07 11:25:23,468+01 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler6) [16ccff7b] START, FullListVDSCommand(HostName = ov-test-04-02, FullListVDSCommandParameters:{runAsync='true', hostId='f162d746-3541-4b30-8e00-dfc91799e054', vmIds='[d4ddd4d1-2de4-4ace-900d-76552cadefb0]'}), log id: 7a4f9890
2017-11-07 11:25:23,528+01 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (org.ovirt.thread.pool-6-thread-9) [16ccff7b] START, MigrateStatusVDSCommand(HostName = ov-test-04-02, MigrateStatusVDSCommandParameters:{runAsync='true', hostId='f162d746-3541-4b30-8e00-dfc91799e054', vmId='d4ddd4d1-2de4-4ace-900d-76552cadefb0'}), log id: 5b3d11e1
2017-11-07 11:25:23,549+01 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler6) [16ccff7b] FINISH, FullListVDSCommand, return: [{acpiEnable=true, emulatedMachine=pc-i440fx-rhel7.3.0, vmId=d4ddd4d1-2de4-4ace-900d-76552cadefb0, guestDiskMapping={df0458f4-e19e-4356-8={name=\\.\PHYSICALDRIVE0}}, transparentHugePages=true, timeOffset=7200, cpuType=Haswell-noTSX, smp=2, pauseCode=NOERR, guestNumaNodes=[Ljava.lang.Object;@7bd80adf, smartcardEnable=false, hypervEnable=true, custom={device_e951f4b9-f82e-4fc0-a099-9ec2c74c5192device_874cf45d-3abb-456a-819c-d97a3e34bccedevice_02fcf3aa-c614-4deb-b946-1574d287aaa8=VmDevice:{id='VmDeviceId:{deviceId='02fcf3aa-c614-4deb-b946-1574d287aaa8', vmId='d4ddd4d1-2de4-4ace-900d-76552cadefb0'}', device='unix', type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, controller=0, type=virtio-serial, port=2}', managed='false', plugged='true', readOnly='false', deviceAlias='channel1', customProperties='[]', snapshotId='null', logicalName='null', hostDevice='null'}, device_e951f4b9-f82e-4fc0-a099-9ec2c74c5192device_874cf45d-3abb-456a-819c-d97a3e34bccedevice_02fcf3aa-c614-4deb-b946-1574d287aaa8device_a4608018-c5cc-4ff0-aa67-eebe79406961=VmDevice:{id='VmDeviceId:{deviceId='a4608018-c5cc-4ff0-aa67-eebe79406961', vmId='d4ddd4d1-2de4-4ace-900d-76552cadefb0'}', device='spicevmc', type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, controller=0, type=virtio-serial, port=3}', managed='false', plugged='true', readOnly='false', deviceAlias='channel2', customProperties='[]', snapshotId='null', logicalName='null', hostDevice='null'}, device_e951f4b9-f82e-4fc0-a099-9ec2c74c5192device_874cf45d-3abb-456a-819c-d97a3e34bcce=VmDevice:{id='VmDeviceId:{deviceId='874cf45d-3abb-456a-819c-d97a3e34bcce', vmId='d4ddd4d1-2de4-4ace-900d-76552cadefb0'}', device='unix', type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, controller=0, type=virtio-serial, port=1}', managed='false', plugged='true', readOnly='false', deviceAlias='channel0', customProperties='[]', snapshotId='null', logicalName='null', hostDevice='null'}, device_e951f4b9-f82e-4fc0-a099-9ec2c74c5192=VmDevice:{id='VmDeviceId:{deviceId='e951f4b9-f82e-4fc0-a099-9ec2c74c5192', vmId='d4ddd4d1-2de4-4ace-900d-76552cadefb0'}', device='ide', type='CONTROLLER', bootOrder='0', specParams='[]', address='{slot=0x01, bus=0x00, domain=0x0000, type=pci, function=0x1}', managed='false', plugged='true', readOnly='false', deviceAlias='ide', customProperties='[]', snapshotId='null', logicalName='null', hostDevice='null'}}, vmType=kvm, memSize=4096, smpCoresPerSocket=1, vmName=ovirt-test03_win2012, nice=0, status=Up, maxMemSize=16384, bootMenuEnable=false, pid=12423, smpThreadsPerCore=1, memGuaranteedSize=4096, kvmEnable=true, displayNetwork=ovirtmgmt, devices=[Ljava.lang.Object;@2c55ad15, display=qxl, maxVCpus=16, clientIp=xxx.yyy.52.63, statusTime=4878767990, maxMemSlots=16}], log id: 7a4f9890
2017-11-07 11:25:23,552+01 INFO  [org.ovirt.engine.core.vdsbroker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler6) [16ccff7b] Received a memballoon Device without an address when processing VM d4ddd4d1-2de4-4ace-900d-76552cadefb0 devices, skipping device: {device=memballoon, specParams={model=none}, type=balloon, alias=balloon0}
2017-11-07 11:25:23,552+01 INFO  [org.ovirt.engine.core.vdsbroker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler6) [16ccff7b] Received a spice Device without an address when processing VM d4ddd4d1-2de4-4ace-900d-76552cadefb0 devices, skipping device: {device=spice, specParams={fileTransferEnable=true, displayNetwork=ovirtmgmt, copyPasteEnable=true, displayIp=xxx.yyy.215.7, spiceSecureChannels=smain,sinputs,scursor,splayback,srecord,sdisplay,ssmartcard,susbredir}, type=graphics, deviceId=ff42e193-08bc-46fd-90ba-31b0b3c0129c, tlsPort=5900}
2017-11-07 11:25:24,555+01 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (org.ovirt.thread.pool-6-thread-9) [16ccff7b] FINISH, MigrateStatusVDSCommand, log id: 5b3d11e1
2017-11-07 11:25:24,563+01 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-9) [16ccff7b] EVENT_ID: VM_MIGRATION_TO_SERVER_FAILED(120), Correlation ID: 68971ee3-707e-4bf7-91ce-9826fc254d64, Job ID: c586546c-6bf0-418e-ba75-3ebe37eea0dd, Call Stack: null, Custom ID: null, Custom Event ID: -1, Message: Migration failed  (VM: ovirt-test03_win2012, Source: ov-test-04-02, Destination: ov-test-04-01).
2017-11-07 11:25:24,566+01 INFO  [org.ovirt.engine.core.bll.MigrateVmToServerCommand] (org.ovirt.thread.pool-6-thread-9) [16ccff7b] Lock freed to object 'EngineLock:{exclusiveLocks='[d4ddd4d1-2de4-4ace-900d-76552cadefb0=VM]', sharedLocks=''}'