Hi Frank,

Can you please attach the VDSM logs from the time of the migration failure
for both hosts:
  ginger.local.systea.f <http://ginger.local.systea.fr/>r and v
ictor.local.systea.fr

Thanks,
Maor

On Tue, Feb 13, 2018 at 12:07 PM, fsoyer <fso...@systea.fr> wrote:

> Hi all,
> I discovered yesterday a problem when migrating VM with more than one
> vdisk.
> On our test servers (oVirt4.1, shared storage with Gluster), I created 2
> VMs needed for a test, from a template with a 20G vdisk. On this VMs I
> added a 100G vdisk (for this tests I didn't want to waste time to extend
> the existing vdisks... But I lost time finally...). The VMs with the 2
> vdisks works well.
> Now I saw some updates waiting on the host. I tried to put it in
> maintenance... But it stopped on the two VM. They were marked "migrating",
> but no more accessible. Other (small) VMs with only 1 vdisk was migrated
> without problem at the same time.
> I saw that a kvm process for the (big) VMs was launched on the source AND
> destination host, but after tens of minutes, the migration and the VMs was
> always freezed. I tried to cancel the migration for the VMs : failed. The
> only way to stop it was to poweroff the VMs : the kvm process died on the 2
> hosts and the GUI alerted on a failed migration.
> In doubt, I tried to delete the second vdisk on one of this VMs : it
> migrates then without error ! And no access problem.
> I tried to extend the first vdisk of the second VM, the delete the second
> vdisk : it migrates now without problem !
>
> So after another test with a VM with 2 vdisks, I can say that this blocked
> the migration process :(
>
> In engine.log, for a VMs with 1 vdisk migrating well, we see :
>
> 2018-02-12 16:46:29,705+01 INFO  
> [org.ovirt.engine.core.bll.MigrateVmToServerCommand]
> (default task-28) [2f712024-5982-46a8-82c8-fd8293da5725] Lock Acquired to
> object 
> 'EngineLock:{exclusiveLocks='[3f57e669-5e4c-4d10-85cc-d573004a099d=VM]',
> sharedLocks=''}'
> 2018-02-12 16:46:29,955+01 INFO  
> [org.ovirt.engine.core.bll.MigrateVmToServerCommand]
> (org.ovirt.thread.pool-6-thread-32) [2f712024-5982-46a8-82c8-fd8293da5725]
> Running command: MigrateVmToServerCommand internal: false. Entities
> affected :  ID: 3f57e669-5e4c-4d10-85cc-d573004a099d Type: VMAction group
> MIGRATE_VM with role type USER
> 2018-02-12 16:46:30,261+01 INFO  
> [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand]
> (org.ovirt.thread.pool-6-thread-32) [2f712024-5982-46a8-82c8-fd8293da5725]
> START, MigrateVDSCommand( MigrateVDSCommandParameters:{runAsync='true',
> hostId='ce3938b1-b23f-4d22-840a-f17d7cd87bb1',
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d', srcHost='192.168.0.6',
> dstVdsId='d569c2dd-8f30-4878-8aea-858db285cf69', dstHost='
> 192.168.0.5:54321', migrationMethod='ONLINE', tunnelMigration='false',
> migrationDowntime='0', autoConverge='true', migrateCompressed='false',
> consoleAddress='null', maxBandwidth='500', enableGuestEvents='true',
> maxIncomingMigrations='2', maxOutgoingMigrations='2',
> convergenceSchedule='[init=[{name=setDowntime, params=[100]}],
> stalling=[{limit=1, action={name=setDowntime, params=[150]}}, {limit=2,
> action={name=setDowntime, params=[200]}}, {limit=3,
> action={name=setDowntime, params=[300]}}, {limit=4,
> action={name=setDowntime, params=[400]}}, {limit=6,
> action={name=setDowntime, params=[500]}}, {limit=-1, action={name=abort,
> params=[]}}]]'}), log id: 14f61ee0
> 2018-02-12 16:46:30,262+01 INFO  [org.ovirt.engine.core.
> vdsbroker.vdsbroker.MigrateBrokerVDSCommand] 
> (org.ovirt.thread.pool-6-thread-32)
> [2f712024-5982-46a8-82c8-fd8293da5725] START, MigrateBrokerVDSCommand(HostName
> = victor.local.systea.fr, MigrateVDSCommandParameters:{runAsync='true',
> hostId='ce3938b1-b23f-4d22-840a-f17d7cd87bb1',
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d', srcHost='192.168.0.6',
> dstVdsId='d569c2dd-8f30-4878-8aea-858db285cf69', dstHost='
> 192.168.0.5:54321', migrationMethod='ONLINE', tunnelMigration='false',
> migrationDowntime='0', autoConverge='true', migrateCompressed='false',
> consoleAddress='null', maxBandwidth='500', enableGuestEvents='true',
> maxIncomingMigrations='2', maxOutgoingMigrations='2',
> convergenceSchedule='[init=[{name=setDowntime, params=[100]}],
> stalling=[{limit=1, action={name=setDowntime, params=[150]}}, {limit=2,
> action={name=setDowntime, params=[200]}}, {limit=3,
> action={name=setDowntime, params=[300]}}, {limit=4,
> action={name=setDowntime, params=[400]}}, {limit=6,
> action={name=setDowntime, params=[500]}}, {limit=-1, action={name=abort,
> params=[]}}]]'}), log id: 775cd381
> 2018-02-12 16:46:30,277+01 INFO  [org.ovirt.engine.core.
> vdsbroker.vdsbroker.MigrateBrokerVDSCommand] 
> (org.ovirt.thread.pool-6-thread-32)
> [2f712024-5982-46a8-82c8-fd8293da5725] FINISH, MigrateBrokerVDSCommand,
> log id: 775cd381
> 2018-02-12 16:46:30,285+01 INFO  
> [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand]
> (org.ovirt.thread.pool-6-thread-32) [2f712024-5982-46a8-82c8-fd8293da5725]
> FINISH, MigrateVDSCommand, return: MigratingFrom, log id: 14f61ee0
> 2018-02-12 16:46:30,301+01 INFO  [org.ovirt.engine.core.dal.
> dbbroker.auditloghandling.AuditLogDirector] 
> (org.ovirt.thread.pool-6-thread-32)
> [2f712024-5982-46a8-82c8-fd8293da5725] EVENT_ID: VM_MIGRATION_START(62),
> Correlation ID: 2f712024-5982-46a8-82c8-fd8293da5725, Job ID:
> 4bd19aa9-cc99-4d02-884e-5a1e857a7738, Call Stack: null, Custom ID: null,
> Custom Event ID: -1, Message: Migration started (VM: Oracle_SECONDARY,
> Source: victor.local.systea.fr, Destination: ginger.local.systea.fr,
> User: admin@internal-authz).
> 2018-02-12 16:46:31,106+01 INFO  [org.ovirt.engine.core.
> vdsbroker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler9)
> [54a65b66] START, FullListVDSCommand(HostName = victor.local.systea.fr,
> FullListVDSCommandParameters:{runAsync='true', 
> hostId='ce3938b1-b23f-4d22-840a-f17d7cd87bb1',
> vmIds='[3f57e669-5e4c-4d10-85cc-d573004a099d]'}), log id: 54b4b435
> 2018-02-12 16:46:31,147+01 INFO  [org.ovirt.engine.core.
> vdsbroker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler9)
> [54a65b66] FINISH, FullListVDSCommand, return: [{acpiEnable=true,
> emulatedMachine=pc-i440fx-rhel7.3.0, tabletEnable=true, pid=1493,
> guestDiskMapping={0QEMU_QEMU_HARDDISK_d890fa68-fba4-4f49-9={name=/dev/sda},
> QEMU_DVD-ROM_QM00003={name=/dev/sr0}}, transparentHugePages=true,
> timeOffset=0, cpuType=Nehalem, smp=2, pauseCode=NOERR,
> guestNumaNodes=[Ljava.lang.Object;@1d9042cd, smartcardEnable=false,
> custom={device_fbddd528-7d93-49c6-a286-180e021cb274device_
> 879c93ab-4df1-435c-af02-565039fcc254=VmDevice:{id='VmDeviceId:{deviceId='
> 879c93ab-4df1-435c-af02-565039fcc254', 
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}',
> 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_fbddd528-7d93-49c6-a286-180e021cb274device_
> 879c93ab-4df1-435c-af02-565039fcc254device_8945f61a-abbe-4156-8485-
> a4aa6f1908dbdevice_017b5e59-01c4-4aac-bf0c-b5d9557284d6=
> VmDevice:{id='VmDeviceId:{deviceId='017b5e59-01c4-4aac-bf0c-b5d9557284d6',
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', device='tablet',
> type='UNKNOWN', bootOrder='0', specParams='[]', address='{bus=0, type=usb,
> port=1}', managed='false', plugged='true', readOnly='false',
> deviceAlias='input0', customProperties='[]', snapshotId='null',
> logicalName='null', hostDevice='null'}, device_fbddd528-7d93-49c6-
> a286-180e021cb274=VmDevice:{id='VmDeviceId:{deviceId='
> fbddd528-7d93-49c6-a286-180e021cb274', 
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}',
> 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'}, device_fbddd528-7d93-49c6-a286-180e021cb274device_
> 879c93ab-4df1-435c-af02-565039fcc254device_8945f61a-
> abbe-4156-8485-a4aa6f1908db=VmDevice:{id='VmDeviceId:{
> deviceId='8945f61a-abbe-4156-8485-a4aa6f1908db',
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', 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'}}, vmType=kvm, memSize=8192, smpCoresPerSocket=1,
> vmName=Oracle_SECONDARY, nice=0, status=Migration Source, maxMemSize=32768,
> bootMenuEnable=false, vmId=3f57e669-5e4c-4d10-85cc-d573004a099d,
> numOfIoThreads=2, smpThreadsPerCore=1, memGuaranteedSize=8192,
> kvmEnable=true, pitReinjection=false, displayNetwork=ovirtmgmt,
> devices=[Ljava.lang.Object;@28ae66d7, display=vnc, maxVCpus=16,
> clientIp=, statusTime=4299484520, maxMemSlots=16}], log id: 54b4b435
> 2018-02-12 16:46:31,150+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmsStatisticsFetcher] (DefaultQuartzScheduler1)
> [27fac647] Fetched 3 VMs from VDS 'd569c2dd-8f30-4878-8aea-858db285cf69'
> 2018-02-12 16:46:31,151+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler9)
> [54a65b66] Received a vnc Device without an address when processing VM
> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping device:
> {device=vnc, specParams={displayNetwork=ovirtmgmt, keyMap=fr,
> displayIp=192.168.0.6}, type=graphics, 
> deviceId=813957b1-446a-4e88-9e40-9fe76d2c442d,
> port=5901}
> 2018-02-12 16:46:31,151+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler9)
> [54a65b66] Received a lease Device without an address when processing VM
> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping device:
> {lease_id=3f57e669-5e4c-4d10-85cc-d573004a099d,
> sd_id=1e51cecc-eb2e-47d0-b185-920fdc7afa16, 
> deviceId={uuid=a09949aa-5642-4b6d-94a4-8b0d04257be5},
> offset=6291456, device=lease, path=/rhev/data-center/mnt/
> glusterSD/192.168.0.6:_DATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom_md/xleases,
> type=lease}
> 2018-02-12 16:46:31,152+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmAnalyzer] (DefaultQuartzScheduler1) [27fac647] VM
> '3f57e669-5e4c-4d10-85cc-d573004a099d'(Oracle_SECONDARY) was unexpectedly
> detected as 'MigratingTo' on VDS 'd569c2dd-8f30-4878-8aea-858db285cf69'(
> ginger.local.systea.fr) (expected on 'ce3938b1-b23f-4d22-840a-
> f17d7cd87bb1')
> 2018-02-12 16:46:31,152+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmAnalyzer] (DefaultQuartzScheduler1) [27fac647] VM
> '3f57e669-5e4c-4d10-85cc-d573004a099d' is migrating to VDS
> 'd569c2dd-8f30-4878-8aea-858db285cf69'(ginger.local.systea.fr) ignoring
> it in the refresh until migration is done
> ....
> 2018-02-12 16:46:41,631+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-11) [] VM
> '3f57e669-5e4c-4d10-85cc-d573004a099d' was reported as Down on VDS
> 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(victor.local.systea.fr)
> 2018-02-12 16:46:41,632+01 INFO  [org.ovirt.engine.core.
> vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-11) []
> START, DestroyVDSCommand(HostName = victor.local.systea.fr,
> DestroyVmVDSCommandParameters:{runAsync='true',
> hostId='ce3938b1-b23f-4d22-840a-f17d7cd87bb1',
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d', force='false',
> secondsToWait='0', gracefully='false', reason='', ignoreNoVm='true'}), log
> id: 560eca57
> 2018-02-12 16:46:41,650+01 INFO  [org.ovirt.engine.core.
> vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-11) []
> FINISH, DestroyVDSCommand, log id: 560eca57
> 2018-02-12 16:46:41,650+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-11) [] VM
> '3f57e669-5e4c-4d10-85cc-d573004a099d'(Oracle_SECONDARY) moved from
> 'MigratingFrom' --> 'Down'
> 2018-02-12 16:46:41,651+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-11) [] Handing
> over VM '3f57e669-5e4c-4d10-85cc-d573004a099d'(Oracle_SECONDARY) to Host
> 'd569c2dd-8f30-4878-8aea-858db285cf69'. Setting VM to status 'MigratingTo'
> 2018-02-12 16:46:42,163+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-4) [] VM
> '3f57e669-5e4c-4d10-85cc-d573004a099d'(Oracle_SECONDARY) moved from
> 'MigratingTo' --> 'Up'
> 2018-02-12 16:46:42,169+01 INFO  [org.ovirt.engine.core.
> vdsbroker.vdsbroker.MigrateStatusVDSCommand] (ForkJoinPool-1-worker-4) []
> START, MigrateStatusVDSCommand(HostName = ginger.local.systea.fr,
> MigrateStatusVDSCommandParameters:{runAsync='true',
> hostId='d569c2dd-8f30-4878-8aea-858db285cf69',
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}), log id: 7a25c281
> 2018-02-12 16:46:42,174+01 INFO  [org.ovirt.engine.core.
> vdsbroker.vdsbroker.MigrateStatusVDSCommand] (ForkJoinPool-1-worker-4) []
> FINISH, MigrateStatusVDSCommand, log id: 7a25c281
> 2018-02-12 16:46:42,194+01 INFO  [org.ovirt.engine.core.dal.
> dbbroker.auditloghandling.AuditLogDirector] (ForkJoinPool-1-worker-4) []
> EVENT_ID: VM_MIGRATION_DONE(63), Correlation ID: 
> 2f712024-5982-46a8-82c8-fd8293da5725,
> Job ID: 4bd19aa9-cc99-4d02-884e-5a1e857a7738, Call Stack: null, Custom
> ID: null, Custom Event ID: -1, Message: Migration completed (VM:
> Oracle_SECONDARY, Source: victor.local.systea.fr, Destination:
> ginger.local.systea.fr, Duration: 11 seconds, Total: 11 seconds, Actual
> downtime: (N/A))
> 2018-02-12 16:46:42,201+01 INFO  
> [org.ovirt.engine.core.bll.MigrateVmToServerCommand]
> (ForkJoinPool-1-worker-4) [] Lock freed to object
> 'EngineLock:{exclusiveLocks='[3f57e669-5e4c-4d10-85cc-d573004a099d=VM]',
> sharedLocks=''}'
> 2018-02-12 16:46:42,203+01 INFO  [org.ovirt.engine.core.
> vdsbroker.vdsbroker.FullListVDSCommand] (ForkJoinPool-1-worker-4) []
> START, FullListVDSCommand(HostName = ginger.local.systea.fr,
> FullListVDSCommandParameters:{runAsync='true', 
> hostId='d569c2dd-8f30-4878-8aea-858db285cf69',
> vmIds='[3f57e669-5e4c-4d10-85cc-d573004a099d]'}), log id: 7cc65298
> 2018-02-12 16:46:42,254+01 INFO  [org.ovirt.engine.core.
> vdsbroker.vdsbroker.FullListVDSCommand] (ForkJoinPool-1-worker-4) []
> FINISH, FullListVDSCommand, return: [{acpiEnable=true,
> emulatedMachine=pc-i440fx-rhel7.3.0, afterMigrationStatus=,
> tabletEnable=true, pid=18748, guestDiskMapping={},
> transparentHugePages=true, timeOffset=0, cpuType=Nehalem, smp=2,
> guestNumaNodes=[Ljava.lang.Object;@760085fd, custom={device_fbddd528-7d93-
> 49c6-a286-180e021cb274device_879c93ab-4df1-435c-af02-
> 565039fcc254=VmDevice:{id='VmDeviceId:{deviceId='879c93ab-4df1-435c-af02-565039fcc254',
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', 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_fbddd528-7d93-49c6-a286-180e021cb274device_
> 879c93ab-4df1-435c-af02-565039fcc254device_8945f61a-abbe-4156-8485-
> a4aa6f1908dbdevice_017b5e59-01c4-4aac-bf0c-b5d9557284d6=
> VmDevice:{id='VmDeviceId:{deviceId='017b5e59-01c4-4aac-bf0c-b5d9557284d6',
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', device='tablet',
> type='UNKNOWN', bootOrder='0', specParams='[]', address='{bus=0, type=usb,
> port=1}', managed='false', plugged='true', readOnly='false',
> deviceAlias='input0', customProperties='[]', snapshotId='null',
> logicalName='null', hostDevice='null'}, device_fbddd528-7d93-49c6-
> a286-180e021cb274=VmDevice:{id='VmDeviceId:{deviceId='
> fbddd528-7d93-49c6-a286-180e021cb274', 
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}',
> 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'}, device_fbddd528-7d93-49c6-a286-180e021cb274device_
> 879c93ab-4df1-435c-af02-565039fcc254device_8945f61a-
> abbe-4156-8485-a4aa6f1908db=VmDevice:{id='VmDeviceId:{
> deviceId='8945f61a-abbe-4156-8485-a4aa6f1908db',
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', 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'}}, vmType=kvm, memSize=8192, smpCoresPerSocket=1,
> vmName=Oracle_SECONDARY, nice=0, status=Up, maxMemSize=32768,
> bootMenuEnable=false, vmId=3f57e669-5e4c-4d10-85cc-d573004a099d,
> numOfIoThreads=2, smpThreadsPerCore=1, smartcardEnable=false,
> maxMemSlots=16, kvmEnable=true, pitReinjection=false,
> displayNetwork=ovirtmgmt, devices=[Ljava.lang.Object;@2e4d3dd3,
> memGuaranteedSize=8192, maxVCpus=16, clientIp=, statusTime=4304259600
> <(430)%20425-9600>, display=vnc}], log id: 7cc65298
> 2018-02-12 16:46:42,257+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmDevicesMonitoring] (ForkJoinPool-1-worker-4) []
> Received a vnc Device without an address when processing VM
> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping device:
> {device=vnc, specParams={displayNetwork=ovirtmgmt, keyMap=fr,
> displayIp=192.168.0.5}, type=graphics, 
> deviceId=813957b1-446a-4e88-9e40-9fe76d2c442d,
> port=5901}
> 2018-02-12 16:46:42,257+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmDevicesMonitoring] (ForkJoinPool-1-worker-4) []
> Received a lease Device without an address when processing VM
> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping device:
> {lease_id=3f57e669-5e4c-4d10-85cc-d573004a099d,
> sd_id=1e51cecc-eb2e-47d0-b185-920fdc7afa16, 
> deviceId={uuid=a09949aa-5642-4b6d-94a4-8b0d04257be5},
> offset=6291456, device=lease, path=/rhev/data-center/mnt/
> glusterSD/192.168.0.6:_DATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom_md/xleases,
> type=lease}
> 2018-02-12 16:46:46,260+01 INFO  [org.ovirt.engine.core.
> vdsbroker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler5)
> [7fcb200a] FINISH, FullListVDSCommand, return: [{acpiEnable=true,
> emulatedMachine=pc-i440fx-rhel7.3.0, afterMigrationStatus=,
> tabletEnable=true, pid=18748, guestDiskMapping={0QEMU_QEMU_
> HARDDISK_d890fa68-fba4-4f49-9={name=/dev/sda},
> QEMU_DVD-ROM_QM00003={name=/dev/sr0}}, transparentHugePages=true,
> timeOffset=0, cpuType=Nehalem, smp=2, guestNumaNodes=[Ljava.lang.
> Object;@77951faf, custom={device_fbddd528-7d93-
> 49c6-a286-180e021cb274device_879c93ab-4df1-435c-af02-
> 565039fcc254=VmDevice:{id='VmDeviceId:{deviceId='879c93ab-4df1-435c-af02-565039fcc254',
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', 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_fbddd528-7d93-49c6-a286-180e021cb274device_
> 879c93ab-4df1-435c-af02-565039fcc254device_8945f61a-abbe-4156-8485-
> a4aa6f1908dbdevice_017b5e59-01c4-4aac-bf0c-b5d9557284d6=
> VmDevice:{id='VmDeviceId:{deviceId='017b5e59-01c4-4aac-bf0c-b5d9557284d6',
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', device='tablet',
> type='UNKNOWN', bootOrder='0', specParams='[]', address='{bus=0, type=usb,
> port=1}', managed='false', plugged='true', readOnly='false',
> deviceAlias='input0', customProperties='[]', snapshotId='null',
> logicalName='null', hostDevice='null'}, device_fbddd528-7d93-49c6-
> a286-180e021cb274=VmDevice:{id='VmDeviceId:{deviceId='
> fbddd528-7d93-49c6-a286-180e021cb274', 
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}',
> 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'}, device_fbddd528-7d93-49c6-a286-180e021cb274device_
> 879c93ab-4df1-435c-af02-565039fcc254device_8945f61a-
> abbe-4156-8485-a4aa6f1908db=VmDevice:{id='VmDeviceId:{
> deviceId='8945f61a-abbe-4156-8485-a4aa6f1908db',
> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', 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'}}, vmType=kvm, memSize=8192, smpCoresPerSocket=1,
> vmName=Oracle_SECONDARY, nice=0, status=Up, maxMemSize=32768,
> bootMenuEnable=false, vmId=3f57e669-5e4c-4d10-85cc-d573004a099d,
> numOfIoThreads=2, smpThreadsPerCore=1, smartcardEnable=false,
> maxMemSlots=16, kvmEnable=true, pitReinjection=false,
> displayNetwork=ovirtmgmt, devices=[Ljava.lang.Object;@286410fd,
> memGuaranteedSize=8192, maxVCpus=16, clientIp=, statusTime=4304263620
> <(430)%20426-3620>, display=vnc}], log id: 58cdef4c
> 2018-02-12 16:46:46,267+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler5)
> [7fcb200a] Received a vnc Device without an address when processing VM
> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping device:
> {device=vnc, specParams={displayNetwork=ovirtmgmt, keyMap=fr,
> displayIp=192.168.0.5}, type=graphics, 
> deviceId=813957b1-446a-4e88-9e40-9fe76d2c442d,
> port=5901}
> 2018-02-12 16:46:46,268+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler5)
> [7fcb200a] Received a lease Device without an address when processing VM
> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping device:
> {lease_id=3f57e669-5e4c-4d10-85cc-d573004a099d,
> sd_id=1e51cecc-eb2e-47d0-b185-920fdc7afa16, 
> deviceId={uuid=a09949aa-5642-4b6d-94a4-8b0d04257be5},
> offset=6291456, device=lease, path=/rhev/data-center/mnt/
> glusterSD/192.168.0.6:_DATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom_md/xleases,
> type=lease}
>
>
>
>
> For the VM with 2 vdisks we see :
>
> 2018-02-12 16:49:06,112+01 INFO  
> [org.ovirt.engine.core.bll.MigrateVmToServerCommand]
> (default task-50) [92b5af33-cb87-4142-b8fe-8b838dd7458e] Lock Acquired to
> object 
> 'EngineLock:{exclusiveLocks='[f7d4ec12-627a-4b83-b59e-886400d55474=VM]',
> sharedLocks=''}'
> 2018-02-12 16:49:06,407+01 INFO  
> [org.ovirt.engine.core.bll.MigrateVmToServerCommand]
> (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4142-b8fe-8b838dd7458e]
> Running command: MigrateVmToServerCommand internal: false. Entities
> affected :  ID: f7d4ec12-627a-4b83-b59e-886400d55474 Type: VMAction group
> MIGRATE_VM with role type USER
> 2018-02-12 16:49:06,712+01 INFO  
> [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand]
> (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4142-b8fe-8b838dd7458e]
> START, MigrateVDSCommand( MigrateVDSCommandParameters:{runAsync='true',
> hostId='d569c2dd-8f30-4878-8aea-858db285cf69',
> vmId='f7d4ec12-627a-4b83-b59e-886400d55474', srcHost='192.168.0.5',
> dstVdsId='ce3938b1-b23f-4d22-840a-f17d7cd87bb1', dstHost='
> 192.168.0.6:54321', migrationMethod='ONLINE', tunnelMigration='false',
> migrationDowntime='0', autoConverge='true', migrateCompressed='false',
> consoleAddress='null', maxBandwidth='500', enableGuestEvents='true',
> maxIncomingMigrations='2', maxOutgoingMigrations='2',
> convergenceSchedule='[init=[{name=setDowntime, params=[100]}],
> stalling=[{limit=1, action={name=setDowntime, params=[150]}}, {limit=2,
> action={name=setDowntime, params=[200]}}, {limit=3,
> action={name=setDowntime, params=[300]}}, {limit=4,
> action={name=setDowntime, params=[400]}}, {limit=6,
> action={name=setDowntime, params=[500]}}, {limit=-1, action={name=abort,
> params=[]}}]]'}), log id: 3702a9e0
> 2018-02-12 16:49:06,713+01 INFO  [org.ovirt.engine.core.
> vdsbroker.vdsbroker.MigrateBrokerVDSCommand] 
> (org.ovirt.thread.pool-6-thread-49)
> [92b5af33-cb87-4142-b8fe-8b838dd7458e] START, MigrateBrokerVDSCommand(HostName
> = ginger.local.systea.fr, MigrateVDSCommandParameters:{runAsync='true',
> hostId='d569c2dd-8f30-4878-8aea-858db285cf69',
> vmId='f7d4ec12-627a-4b83-b59e-886400d55474', srcHost='192.168.0.5',
> dstVdsId='ce3938b1-b23f-4d22-840a-f17d7cd87bb1', dstHost='
> 192.168.0.6:54321', migrationMethod='ONLINE', tunnelMigration='false',
> migrationDowntime='0', autoConverge='true', migrateCompressed='false',
> consoleAddress='null', maxBandwidth='500', enableGuestEvents='true',
> maxIncomingMigrations='2', maxOutgoingMigrations='2',
> convergenceSchedule='[init=[{name=setDowntime, params=[100]}],
> stalling=[{limit=1, action={name=setDowntime, params=[150]}}, {limit=2,
> action={name=setDowntime, params=[200]}}, {limit=3,
> action={name=setDowntime, params=[300]}}, {limit=4,
> action={name=setDowntime, params=[400]}}, {limit=6,
> action={name=setDowntime, params=[500]}}, {limit=-1, action={name=abort,
> params=[]}}]]'}), log id: 1840069c
> 2018-02-12 16:49:06,724+01 INFO  [org.ovirt.engine.core.
> vdsbroker.vdsbroker.MigrateBrokerVDSCommand] 
> (org.ovirt.thread.pool-6-thread-49)
> [92b5af33-cb87-4142-b8fe-8b838dd7458e] FINISH, MigrateBrokerVDSCommand,
> log id: 1840069c
> 2018-02-12 16:49:06,732+01 INFO  
> [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand]
> (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4142-b8fe-8b838dd7458e]
> FINISH, MigrateVDSCommand, return: MigratingFrom, log id: 3702a9e0
> 2018-02-12 16:49:06,753+01 INFO  [org.ovirt.engine.core.dal.
> dbbroker.auditloghandling.AuditLogDirector] 
> (org.ovirt.thread.pool-6-thread-49)
> [92b5af33-cb87-4142-b8fe-8b838dd7458e] EVENT_ID: VM_MIGRATION_START(62),
> Correlation ID: 92b5af33-cb87-4142-b8fe-8b838dd7458e, Job ID:
> f4f54054-f7c8-4481-8eda-d5a15c383061, Call Stack: null, Custom ID: null,
> Custom Event ID: -1, Message: Migration started (VM: Oracle_PRIMARY,
> Source: ginger.local.systea.fr, Destination: victor.local.systea.fr,
> User: admin@internal-authz).
> ...
> 2018-02-12 16:49:16,453+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmsStatisticsFetcher] (DefaultQuartzScheduler4)
> [162a5bc3] Fetched 2 VMs from VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'
> 2018-02-12 16:49:16,455+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmAnalyzer] (DefaultQuartzScheduler4) [162a5bc3] VM
> 'f7d4ec12-627a-4b83-b59e-886400d55474'(Oracle_PRIMARY) was unexpectedly
> detected as 'MigratingTo' on VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(
> victor.local.systea.fr) (expected on 'd569c2dd-8f30-4878-8aea-
> 858db285cf69')
> 2018-02-12 16:49:16,455+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmAnalyzer] (DefaultQuartzScheduler4) [162a5bc3] VM
> 'f7d4ec12-627a-4b83-b59e-886400d55474' is migrating to VDS
> 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(victor.local.systea.fr) ignoring
> it in the refresh until migration is done
> ...
> 2018-02-12 16:49:31,484+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmAnalyzer] (DefaultQuartzScheduler5) [11a7619a] VM
> 'f7d4ec12-627a-4b83-b59e-886400d55474'(Oracle_PRIMARY) was unexpectedly
> detected as 'MigratingTo' on VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(
> victor.local.systea.fr) (expected on 'd569c2dd-8f30-4878-8aea-
> 858db285cf69')
> 2018-02-12 16:49:31,484+01 INFO  [org.ovirt.engine.core.
> vdsbroker.monitoring.VmAnalyzer] (DefaultQuartzScheduler5) [11a7619a] VM
> 'f7d4ec12-627a-4b83-b59e-886400d55474' is migrating to VDS
> 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(victor.local.systea.fr) ignoring
> it in the refresh until migration is done
>
>
>
> and so on, last lines repeated indefinitly for hours since we poweroff the
> VM...
> Is this something known ? Any idea about that ?
>
> Thanks
> --
>
> Cordialement,
>
> *Frank Soyer *
>
>
> _______________________________________________
> Users mailing list
> Users@ovirt.org
> http://lists.ovirt.org/mailman/listinfo/users
>
>
_______________________________________________
Users mailing list
Users@ovirt.org
http://lists.ovirt.org/mailman/listinfo/users

Reply via email to