[ovirt-users] VMs with multiple vdisks don't migrate

14 Feb 2018

      ------=_=-_OpenGroupware_org_NGMime-29680-1518600202.220070-147------
Content-Type: text/plain; charset=utf-8
Content-Transfer-Encoding: quoted-printable
Content-Length: 29649

Hi all,
I discovered yesterday a problem when migrating VM with more than one v=
disk.
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 ext=
end the existing vdisks... But I lost time finally...). The VMs with th=
e 2 vdisks works well.
Now I saw some updates waiting on the host. I tried to put it in mainte=
nance... But it stopped on the two VM. They were marked "migrating", bu=
t 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 A=
ND destination host, but after tens of minutes, the migration and the V=
Ms was always freezed. I tried to cancel the migration for the VMs : fa=
iled. 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 mi=
grates then without error ! And no access problem.
I tried to extend the first vdisk of the second VM, the delete the seco=
nd vdisk : it migrates now without problem !=C2=A0=C2=A0=C2=A0

So after another test with a VM with 2 vdisks, I can say that this bloc=
ked the migration process :(

In engine.log, for a VMs with 1 vdisk migrating well, we see :2018-02-1=
2 16:46:29,705+01 INFO =C2=A0[org.ovirt.engine.core.bll.MigrateVmToServ=
erCommand] (default task-28) [2f712024-5982-46a8-82c8-fd8293da5725] Loc=
k Acquired to object 'EngineLock:{exclusiveLocks=3D'[3f57e669-5e4c-4d10=
-85cc-d573004a099d=3DVM]', sharedLocks=3D''}'
2018-02-12 16:46:29,955+01 INFO =C2=A0[org.ovirt.engine.core.bll.Migrat=
eVmToServerCommand] (org.ovirt.thread.pool-6-thread-32) [2f712024-5982-=
46a8-82c8-fd8293da5725] Running command: MigrateVmToServerCommand inter=
nal: false. Entities affected : =C2=A0ID: 3f57e669-5e4c-4d10-85cc-d5730=
04a099d Type: VMAction group MIGRATE=5FVM with role type USER
2018-02-12 16:46:30,261+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
MigrateVDSCommand] (org.ovirt.thread.pool-6-thread-32) [2f712024-5982-4=
6a8-82c8-fd8293da5725] START, MigrateVDSCommand( MigrateVDSCommandParam=
eters:{runAsync=3D'true', hostId=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb=
1', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d', srcHost=3D'192.168.0=
.6', dstVdsId=3D'd569c2dd-8f30-4878-8aea-858db285cf69', dstHost=3D'192.=
168.0.5:54321', migrationMethod=3D'ONLINE', tunnelMigration=3D'false', =
migrationDowntime=3D'0', autoConverge=3D'true', migrateCompressed=3D'fa=
lse', consoleAddress=3D'null', maxBandwidth=3D'500', enableGuestEvents=3D=
'true', maxIncomingMigrations=3D'2', maxOutgoingMigrations=3D'2', conve=
rgenceSchedule=3D'[init=3D[{name=3DsetDowntime, params=3D[100]}], stall=
ing=3D[{limit=3D1, action=3D{name=3DsetDowntime, params=3D[150]}}, {lim=
it=3D2, action=3D{name=3DsetDowntime, params=3D[200]}}, {limit=3D3, act=
ion=3D{name=3DsetDowntime, params=3D[300]}}, {limit=3D4, action=3D{name=
=3DsetDowntime, params=3D[400]}}, {limit=3D6, action=3D{name=3DsetDownt=
ime, params=3D[500]}}, {limit=3D-1, action=3D{name=3Dabort, params=3D[]=
}}]]'}), log id: 14f61ee0
2018-02-12 16:46:30,262+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-thread-32) =
[2f712024-5982-46a8-82c8-fd8293da5725] START, MigrateBrokerVDSCommand(H=
ostName =3D victor.local.systea.fr, MigrateVDSCommandParameters:{runAsy=
nc=3D'true', hostId=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1', vmId=3D'3=
f57e669-5e4c-4d10-85cc-d573004a099d', srcHost=3D'192.168.0.6', dstVdsId=
=3D'd569c2dd-8f30-4878-8aea-858db285cf69', dstHost=3D'192.168.0.5:54321=
', migrationMethod=3D'ONLINE', tunnelMigration=3D'false', migrationDown=
time=3D'0', autoConverge=3D'true', migrateCompressed=3D'false', console=
Address=3D'null', maxBandwidth=3D'500', enableGuestEvents=3D'true', max=
IncomingMigrations=3D'2', maxOutgoingMigrations=3D'2', convergenceSched=
ule=3D'[init=3D[{name=3DsetDowntime, params=3D[100]}], stalling=3D[{lim=
it=3D1, action=3D{name=3DsetDowntime, params=3D[150]}}, {limit=3D2, act=
ion=3D{name=3DsetDowntime, params=3D[200]}}, {limit=3D3, action=3D{name=
=3DsetDowntime, params=3D[300]}}, {limit=3D4, action=3D{name=3DsetDownt=
ime, params=3D[400]}}, {limit=3D6, action=3D{name=3DsetDowntime, params=
=3D[500]}}, {limit=3D-1, action=3D{name=3Dabort, params=3D[]}}]]'}), lo=
g id: 775cd381
2018-02-12 16:46:30,277+01 INFO =C2=A0[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 =C2=A0[org.ovirt.engine.core.vdsbroker.=
MigrateVDSCommand] (org.ovirt.thread.pool-6-thread-32) [2f712024-5982-4=
6a8-82c8-fd8293da5725] FINISH, MigrateVDSCommand, return: MigratingFrom=
, log id: 14f61ee0
2018-02-12 16:46:30,301+01 INFO =C2=A0[org.ovirt.engine.core.dal.dbbrok=
er.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-3=
2) [2f712024-5982-46a8-82c8-fd8293da5725] EVENT=5FID: VM=5FMIGRATION=5F=
START(62), Correlation ID: 2f712024-5982-46a8-82c8-fd8293da5725, Job ID=
: 4bd19aa9-cc99-4d02-884e-5a1e857a7738, Call Stack: null, Custom ID: nu=
ll, Custom Event ID: -1, Message: Migration started (VM: Oracle=5FSECON=
DARY, Source: victor.local.systea.fr, Destination: ginger.local.systea.=
fr, User: admin@internal-authz).
2018-02-12 16:46:31,106+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler9) [54a65b66] STAR=
T, FullListVDSCommand(HostName =3D victor.local.systea.fr, FullListVDSC=
ommandParameters:{runAsync=3D'true', hostId=3D'ce3938b1-b23f-4d22-840a-=
f17d7cd87bb1', vmIds=3D'[3f57e669-5e4c-4d10-85cc-d573004a099d]'}), log =
id: 54b4b435
2018-02-12 16:46:31,147+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler9) [54a65b66] FINI=
SH, FullListVDSCommand, return: [{acpiEnable=3Dtrue, emulatedMachine=3D=
pc-i440fx-rhel7.3.0, tabletEnable=3Dtrue, pid=3D1493, guestDiskMapping=3D=
{0QEMU=5FQEMU=5FHARDDISK=5Fd890fa68-fba4-4f49-9=3D{name=3D/dev/sda}, QE=
MU=5FDVD-ROM=5FQM00003=3D{name=3D/dev/sr0}}, transparentHugePages=3Dtru=
e, timeOffset=3D0, cpuType=3DNehalem, smp=3D2, pauseCode=3DNOERR, guest=
NumaNodes=3D[Ljava.lang.Object;@1d9042cd, smartcardEnable=3Dfalse, cust=
om=3D{device=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F879c93ab-4d=
f1-435c-af02-565039fcc254=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'879=
c93ab-4df1-435c-af02-565039fcc254', vmId=3D'3f57e669-5e4c-4d10-85cc-d57=
3004a099d'}', device=3D'unix', type=3D'CHANNEL', bootOrder=3D'0', specP=
arams=3D'[]', address=3D'{bus=3D0, controller=3D0, type=3Dvirtio-serial=
, port=3D1}', managed=3D'false', plugged=3D'true', readOnly=3D'false', =
deviceAlias=3D'channel0', customProperties=3D'[]', snapshotId=3D'null',=
 logicalName=3D'null', hostDevice=3D'null'}, device=5Ffbddd528-7d93-49c=
6-a286-180e021cb274device=5F879c93ab-4df1-435c-af02-565039fcc254device=5F=
8945f61a-abbe-4156-8485-a4aa6f1908dbdevice=5F017b5e59-01c4-4aac-bf0c-b5=
d9557284d6=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'017b5e59-01c4-4aac=
-bf0c-b5d9557284d6', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', d=
evice=3D'tablet', type=3D'UNKNOWN', bootOrder=3D'0', specParams=3D'[]',=
 address=3D'{bus=3D0, type=3Dusb, port=3D1}', managed=3D'false', plugge=
d=3D'true', readOnly=3D'false', deviceAlias=3D'input0', customPropertie=
s=3D'[]', snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'null=
'}, device=5Ffbddd528-7d93-49c6-a286-180e021cb274=3DVmDevice:{id=3D'VmD=
eviceId:{deviceId=3D'fbddd528-7d93-49c6-a286-180e021cb274', vmId=3D'3f5=
7e669-5e4c-4d10-85cc-d573004a099d'}', device=3D'ide', type=3D'CONTROLLE=
R', bootOrder=3D'0', specParams=3D'[]', address=3D'{slot=3D0x01, bus=3D=
0x00, domain=3D0x0000, type=3Dpci, function=3D0x1}', managed=3D'false',=
 plugged=3D'true', readOnly=3D'false', deviceAlias=3D'ide', customPrope=
rties=3D'[]', snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'=
null'}, device=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F879c93ab-=
4df1-435c-af02-565039fcc254device=5F8945f61a-abbe-4156-8485-a4aa6f1908d=
b=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'8945f61a-abbe-4156-8485-a4a=
a6f1908db', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', device=3D'=
unix', type=3D'CHANNEL', bootOrder=3D'0', specParams=3D'[]', address=3D=
'{bus=3D0, controller=3D0, type=3Dvirtio-serial, port=3D2}', managed=3D=
'false', plugged=3D'true', readOnly=3D'false', deviceAlias=3D'channel1'=
, customProperties=3D'[]', snapshotId=3D'null', logicalName=3D'null', h=
ostDevice=3D'null'}}, vmType=3Dkvm, memSize=3D8192, smpCoresPerSocket=3D=
1, vmName=3DOracle=5FSECONDARY, nice=3D0, status=3DMigration Source, ma=
xMemSize=3D32768, bootMenuEnable=3Dfalse, vmId=3D3f57e669-5e4c-4d10-85c=
c-d573004a099d, numOfIoThreads=3D2, smpThreadsPerCore=3D1, memGuarantee=
dSize=3D8192, kvmEnable=3Dtrue, pitReinjection=3Dfalse, displayNetwork=3D=
ovirtmgmt, devices=3D[Ljava.lang.Object;@28ae66d7, display=3Dvnc, maxVC=
pus=3D16, clientIp=3D, statusTime=3D4299484520, maxMemSlots=3D16}], log=
 id: 54b4b435
2018-02-12 16:46:31,150+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmsStatisticsFetcher] (DefaultQuartzScheduler1) [27fac647] F=
etched 3 VMs from VDS 'd569c2dd-8f30-4878-8aea-858db285cf69'
2018-02-12 16:46:31,151+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler9) [54a65b66] Re=
ceived a vnc Device without an address when processing VM 3f57e669-5e4c=
-4d10-85cc-d573004a099d devices, skipping device: {device=3Dvnc, specPa=
rams=3D{displayNetwork=3Dovirtmgmt, keyMap=3Dfr, displayIp=3D192.168.0.=
6}, type=3Dgraphics, deviceId=3D813957b1-446a-4e88-9e40-9fe76d2c442d, p=
ort=3D5901}
2018-02-12 16:46:31,151+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler9) [54a65b66] Re=
ceived a lease Device without an address when processing VM 3f57e669-5e=
4c-4d10-85cc-d573004a099d devices, skipping device: {lease=5Fid=3D3f57e=
669-5e4c-4d10-85cc-d573004a099d, sd=5Fid=3D1e51cecc-eb2e-47d0-b185-920f=
dc7afa16, deviceId=3D{uuid=3Da09949aa-5642-4b6d-94a4-8b0d04257be5}, off=
set=3D6291456, device=3Dlease, path=3D/rhev/data-center/mnt/glusterSD/1=
92.168.0.6:=5FDATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom=5Fmd/xlea=
ses, type=3Dlease}
2018-02-12 16:46:31,152+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmAnalyzer] (DefaultQuartzScheduler1) [27fac647] VM '3f57e66=
9-5e4c-4d10-85cc-d573004a099d'(Oracle=5FSECONDARY) was unexpectedly det=
ected as 'MigratingTo' on VDS 'd569c2dd-8f30-4878-8aea-858db285cf69'(gi=
nger.local.systea.fr) (expected on 'ce3938b1-b23f-4d22-840a-f17d7cd87bb=
1')
2018-02-12 16:46:31,152+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmAnalyzer] (DefaultQuartzScheduler1) [27fac647] VM '3f57e66=
9-5e4c-4d10-85cc-d573004a099d' is migrating to VDS 'd569c2dd-8f30-4878-=
8aea-858db285cf69'(ginger.local.systea.fr) ignoring it in the refresh u=
ntil migration is done
....
2018-02-12 16:46:41,631+01 INFO =C2=A0[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 =C2=A0[org.ovirt.engine.core.vdsbroker.=
vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-11) [] START, Destr=
oyVDSCommand(HostName =3D victor.local.systea.fr, DestroyVmVDSCommandPa=
rameters:{runAsync=3D'true', hostId=3D'ce3938b1-b23f-4d22-840a-f17d7cd8=
7bb1', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d', force=3D'false', =
secondsToWait=3D'0', gracefully=3D'false', reason=3D'', ignoreNoVm=3D't=
rue'}), log id: 560eca57
2018-02-12 16:46:41,650+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-11) [] FINISH, Dest=
royVDSCommand, log id: 560eca57
2018-02-12 16:46:41,650+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmAnalyzer] (ForkJoinPool-1-worker-11) [] VM '3f57e669-5e4c-=
4d10-85cc-d573004a099d'(Oracle=5FSECONDARY) moved from 'MigratingFrom' =
--> 'Down'
2018-02-12 16:46:41,651+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmAnalyzer] (ForkJoinPool-1-worker-11) [] Handing over VM '3=
f57e669-5e4c-4d10-85cc-d573004a099d'(Oracle=5FSECONDARY) to Host 'd569c=
2dd-8f30-4878-8aea-858db285cf69'. Setting VM to status 'MigratingTo'
2018-02-12 16:46:42,163+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmAnalyzer] (ForkJoinPool-1-worker-4) [] VM '3f57e669-5e4c-4=
d10-85cc-d573004a099d'(Oracle=5FSECONDARY) moved from 'MigratingTo' -->=
 'Up'
2018-02-12 16:46:42,169+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
vdsbroker.MigrateStatusVDSCommand] (ForkJoinPool-1-worker-4) [] START, =
MigrateStatusVDSCommand(HostName =3D ginger.local.systea.fr, MigrateSta=
tusVDSCommandParameters:{runAsync=3D'true', hostId=3D'd569c2dd-8f30-487=
8-8aea-858db285cf69', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}), =
log id: 7a25c281
2018-02-12 16:46:42,174+01 INFO =C2=A0[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 =C2=A0[org.ovirt.engine.core.dal.dbbrok=
er.auditloghandling.AuditLogDirector] (ForkJoinPool-1-worker-4) [] EVEN=
T=5FID: VM=5FMIGRATION=5FDONE(63), Correlation ID: 2f712024-5982-46a8-8=
2c8-fd8293da5725, Job ID: 4bd19aa9-cc99-4d02-884e-5a1e857a7738, Call St=
ack: null, Custom ID: null, Custom Event ID: -1, Message: Migration com=
pleted (VM: Oracle=5FSECONDARY, Source: victor.local.systea.fr, Destina=
tion: ginger.local.systea.fr, Duration: 11 seconds, Total: 11 seconds, =
Actual downtime: (N/A))
2018-02-12 16:46:42,201+01 INFO =C2=A0[org.ovirt.engine.core.bll.Migrat=
eVmToServerCommand] (ForkJoinPool-1-worker-4) [] Lock freed to object '=
EngineLock:{exclusiveLocks=3D'[3f57e669-5e4c-4d10-85cc-d573004a099d=3DV=
M]', sharedLocks=3D''}'
2018-02-12 16:46:42,203+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
vdsbroker.FullListVDSCommand] (ForkJoinPool-1-worker-4) [] START, FullL=
istVDSCommand(HostName =3D ginger.local.systea.fr, FullListVDSCommandPa=
rameters:{runAsync=3D'true', hostId=3D'd569c2dd-8f30-4878-8aea-858db285=
cf69', vmIds=3D'[3f57e669-5e4c-4d10-85cc-d573004a099d]'}), log id: 7cc6=
5298
2018-02-12 16:46:42,254+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
vdsbroker.FullListVDSCommand] (ForkJoinPool-1-worker-4) [] FINISH, Full=
ListVDSCommand, return: [{acpiEnable=3Dtrue, emulatedMachine=3Dpc-i440f=
x-rhel7.3.0, afterMigrationStatus=3D, tabletEnable=3Dtrue, pid=3D18748,=
 guestDiskMapping=3D{}, transparentHugePages=3Dtrue, timeOffset=3D0, cp=
uType=3DNehalem, smp=3D2, guestNumaNodes=3D[Ljava.lang.Object;@760085fd=
, custom=3D{device=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F879c9=
3ab-4df1-435c-af02-565039fcc254=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D=
'879c93ab-4df1-435c-af02-565039fcc254', vmId=3D'3f57e669-5e4c-4d10-85cc=
-d573004a099d'}', device=3D'unix', type=3D'CHANNEL', bootOrder=3D'0', s=
pecParams=3D'[]', address=3D'{bus=3D0, controller=3D0, type=3Dvirtio-se=
rial, port=3D1}', managed=3D'false', plugged=3D'true', readOnly=3D'fals=
e', deviceAlias=3D'channel0', customProperties=3D'[]', snapshotId=3D'nu=
ll', logicalName=3D'null', hostDevice=3D'null'}, device=5Ffbddd528-7d93=
-49c6-a286-180e021cb274device=5F879c93ab-4df1-435c-af02-565039fcc254dev=
ice=5F8945f61a-abbe-4156-8485-a4aa6f1908dbdevice=5F017b5e59-01c4-4aac-b=
f0c-b5d9557284d6=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'017b5e59-01c=
4-4aac-bf0c-b5d9557284d6', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d=
'}', device=3D'tablet', type=3D'UNKNOWN', bootOrder=3D'0', specParams=3D=
'[]', address=3D'{bus=3D0, type=3Dusb, port=3D1}', managed=3D'false', p=
lugged=3D'true', readOnly=3D'false', deviceAlias=3D'input0', customProp=
erties=3D'[]', snapshotId=3D'null', logicalName=3D'null', hostDevice=3D=
'null'}, device=5Ffbddd528-7d93-49c6-a286-180e021cb274=3DVmDevice:{id=3D=
'VmDeviceId:{deviceId=3D'fbddd528-7d93-49c6-a286-180e021cb274', vmId=3D=
'3f57e669-5e4c-4d10-85cc-d573004a099d'}', device=3D'ide', type=3D'CONTR=
OLLER', bootOrder=3D'0', specParams=3D'[]', address=3D'{slot=3D0x01, bu=
s=3D0x00, domain=3D0x0000, type=3Dpci, function=3D0x1}', managed=3D'fal=
se', plugged=3D'true', readOnly=3D'false', deviceAlias=3D'ide', customP=
roperties=3D'[]', snapshotId=3D'null', logicalName=3D'null', hostDevice=
=3D'null'}, device=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F879c9=
3ab-4df1-435c-af02-565039fcc254device=5F8945f61a-abbe-4156-8485-a4aa6f1=
908db=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'8945f61a-abbe-4156-8485=
-a4aa6f1908db', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', device=
=3D'unix', type=3D'CHANNEL', bootOrder=3D'0', specParams=3D'[]', addres=
s=3D'{bus=3D0, controller=3D0, type=3Dvirtio-serial, port=3D2}', manage=
d=3D'false', plugged=3D'true', readOnly=3D'false', deviceAlias=3D'chann=
el1', customProperties=3D'[]', snapshotId=3D'null', logicalName=3D'null=
', hostDevice=3D'null'}}, vmType=3Dkvm, memSize=3D8192, smpCoresPerSock=
et=3D1, vmName=3DOracle=5FSECONDARY, nice=3D0, status=3DUp, maxMemSize=3D=
32768, bootMenuEnable=3Dfalse, vmId=3D3f57e669-5e4c-4d10-85cc-d573004a0=
99d, numOfIoThreads=3D2, smpThreadsPerCore=3D1, smartcardEnable=3Dfalse=
, maxMemSlots=3D16, kvmEnable=3Dtrue, pitReinjection=3Dfalse, displayNe=
twork=3Dovirtmgmt, devices=3D[Ljava.lang.Object;@2e4d3dd3, memGuarantee=
dSize=3D8192, maxVCpus=3D16, clientIp=3D, statusTime=3D4304259600, disp=
lay=3Dvnc}], log id: 7cc65298
2018-02-12 16:46:42,257+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmDevicesMonitoring] (ForkJoinPool-1-worker-4) [] Received a=
 vnc Device without an address when processing VM 3f57e669-5e4c-4d10-85=
cc-d573004a099d devices, skipping device: {device=3Dvnc, specParams=3D{=
displayNetwork=3Dovirtmgmt, keyMap=3Dfr, displayIp=3D192.168.0.5}, type=
=3Dgraphics, deviceId=3D813957b1-446a-4e88-9e40-9fe76d2c442d, port=3D59=
01}
2018-02-12 16:46:42,257+01 INFO =C2=A0[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=5Fid=3D3f57e669-5e4c=
-4d10-85cc-d573004a099d, sd=5Fid=3D1e51cecc-eb2e-47d0-b185-920fdc7afa16=
, deviceId=3D{uuid=3Da09949aa-5642-4b6d-94a4-8b0d04257be5}, offset=3D62=
91456, device=3Dlease, path=3D/rhev/data-center/mnt/glusterSD/192.168.0=
.6:=5FDATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom=5Fmd/xleases, typ=
e=3Dlease}
2018-02-12 16:46:46,260+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler5) [7fcb200a] FINI=
SH, FullListVDSCommand, return: [{acpiEnable=3Dtrue, emulatedMachine=3D=
pc-i440fx-rhel7.3.0, afterMigrationStatus=3D, tabletEnable=3Dtrue, pid=3D=
18748, guestDiskMapping=3D{0QEMU=5FQEMU=5FHARDDISK=5Fd890fa68-fba4-4f49=
-9=3D{name=3D/dev/sda}, QEMU=5FDVD-ROM=5FQM00003=3D{name=3D/dev/sr0}}, =
transparentHugePages=3Dtrue, timeOffset=3D0, cpuType=3DNehalem, smp=3D2=
, guestNumaNodes=3D[Ljava.lang.Object;@77951faf, custom=3D{device=5Ffbd=
dd528-7d93-49c6-a286-180e021cb274device=5F879c93ab-4df1-435c-af02-56503=
9fcc254=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'879c93ab-4df1-435c-af=
02-565039fcc254', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', devi=
ce=3D'unix', type=3D'CHANNEL', bootOrder=3D'0', specParams=3D'[]', addr=
ess=3D'{bus=3D0, controller=3D0, type=3Dvirtio-serial, port=3D1}', mana=
ged=3D'false', plugged=3D'true', readOnly=3D'false', deviceAlias=3D'cha=
nnel0', customProperties=3D'[]', snapshotId=3D'null', logicalName=3D'nu=
ll', hostDevice=3D'null'}, device=5Ffbddd528-7d93-49c6-a286-180e021cb27=
4device=5F879c93ab-4df1-435c-af02-565039fcc254device=5F8945f61a-abbe-41=
56-8485-a4aa6f1908dbdevice=5F017b5e59-01c4-4aac-bf0c-b5d9557284d6=3DVmD=
evice:{id=3D'VmDeviceId:{deviceId=3D'017b5e59-01c4-4aac-bf0c-b5d9557284=
d6', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', device=3D'tablet'=
, type=3D'UNKNOWN', bootOrder=3D'0', specParams=3D'[]', address=3D'{bus=
=3D0, type=3Dusb, port=3D1}', managed=3D'false', plugged=3D'true', read=
Only=3D'false', deviceAlias=3D'input0', customProperties=3D'[]', snapsh=
otId=3D'null', logicalName=3D'null', hostDevice=3D'null'}, device=5Ffbd=
dd528-7d93-49c6-a286-180e021cb274=3DVmDevice:{id=3D'VmDeviceId:{deviceI=
d=3D'fbddd528-7d93-49c6-a286-180e021cb274', vmId=3D'3f57e669-5e4c-4d10-=
85cc-d573004a099d'}', device=3D'ide', type=3D'CONTROLLER', bootOrder=3D=
'0', specParams=3D'[]', address=3D'{slot=3D0x01, bus=3D0x00, domain=3D0=
x0000, type=3Dpci, function=3D0x1}', managed=3D'false', plugged=3D'true=
', readOnly=3D'false', deviceAlias=3D'ide', customProperties=3D'[]', sn=
apshotId=3D'null', logicalName=3D'null', hostDevice=3D'null'}, device=5F=
fbddd528-7d93-49c6-a286-180e021cb274device=5F879c93ab-4df1-435c-af02-56=
5039fcc254device=5F8945f61a-abbe-4156-8485-a4aa6f1908db=3DVmDevice:{id=3D=
'VmDeviceId:{deviceId=3D'8945f61a-abbe-4156-8485-a4aa6f1908db', vmId=3D=
'3f57e669-5e4c-4d10-85cc-d573004a099d'}', device=3D'unix', type=3D'CHAN=
NEL', bootOrder=3D'0', specParams=3D'[]', address=3D'{bus=3D0, controll=
er=3D0, type=3Dvirtio-serial, port=3D2}', managed=3D'false', plugged=3D=
'true', readOnly=3D'false', deviceAlias=3D'channel1', customProperties=3D=
'[]', snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'null'}},=
 vmType=3Dkvm, memSize=3D8192, smpCoresPerSocket=3D1, vmName=3DOracle=5F=
SECONDARY, nice=3D0, status=3DUp, maxMemSize=3D32768, bootMenuEnable=3D=
false, vmId=3D3f57e669-5e4c-4d10-85cc-d573004a099d, numOfIoThreads=3D2,=
 smpThreadsPerCore=3D1, smartcardEnable=3Dfalse, maxMemSlots=3D16, kvmE=
nable=3Dtrue, pitReinjection=3Dfalse, displayNetwork=3Dovirtmgmt, devic=
es=3D[Ljava.lang.Object;@286410fd, memGuaranteedSize=3D8192, maxVCpus=3D=
16, clientIp=3D, statusTime=3D4304263620, display=3Dvnc}], log id: 58cd=
ef4c
2018-02-12 16:46:46,267+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler5) [7fcb200a] Re=
ceived a vnc Device without an address when processing VM 3f57e669-5e4c=
-4d10-85cc-d573004a099d devices, skipping device: {device=3Dvnc, specPa=
rams=3D{displayNetwork=3Dovirtmgmt, keyMap=3Dfr, displayIp=3D192.168.0.=
5}, type=3Dgraphics, deviceId=3D813957b1-446a-4e88-9e40-9fe76d2c442d, p=
ort=3D5901}
2018-02-12 16:46:46,268+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler5) [7fcb200a] Re=
ceived a lease Device without an address when processing VM 3f57e669-5e=
4c-4d10-85cc-d573004a099d devices, skipping device: {lease=5Fid=3D3f57e=
669-5e4c-4d10-85cc-d573004a099d, sd=5Fid=3D1e51cecc-eb2e-47d0-b185-920f=
dc7afa16, deviceId=3D{uuid=3Da09949aa-5642-4b6d-94a4-8b0d04257be5}, off=
set=3D6291456, device=3Dlease, path=3D/rhev/data-center/mnt/glusterSD/1=
92.168.0.6:=5FDATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom=5Fmd/xlea=
ses, type=3Dlease}
=C2=A0
For the VM with 2 vdisks we see :
2018-02-12 16:49:06,112+01 INFO =C2=A0[org.ovirt.engine.core.bll.Migrat=
eVmToServerCommand] (default task-50) [92b5af33-cb87-4142-b8fe-8b838dd7=
458e] Lock Acquired to object 'EngineLock:{exclusiveLocks=3D'[f7d4ec12-=
627a-4b83-b59e-886400d55474=3DVM]', sharedLocks=3D''}'
2018-02-12 16:49:06,407+01 INFO =C2=A0[org.ovirt.engine.core.bll.Migrat=
eVmToServerCommand] (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-=
4142-b8fe-8b838dd7458e] Running command: MigrateVmToServerCommand inter=
nal: false. Entities affected : =C2=A0ID: f7d4ec12-627a-4b83-b59e-88640=
0d55474 Type: VMAction group MIGRATE=5FVM with role type USER
2018-02-12 16:49:06,712+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
MigrateVDSCommand] (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4=
142-b8fe-8b838dd7458e] START, MigrateVDSCommand( MigrateVDSCommandParam=
eters:{runAsync=3D'true', hostId=3D'd569c2dd-8f30-4878-8aea-858db285cf6=
9', vmId=3D'f7d4ec12-627a-4b83-b59e-886400d55474', srcHost=3D'192.168.0=
.5', dstVdsId=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1', dstHost=3D'192.=
168.0.6:54321', migrationMethod=3D'ONLINE', tunnelMigration=3D'false', =
migrationDowntime=3D'0', autoConverge=3D'true', migrateCompressed=3D'fa=
lse', consoleAddress=3D'null', maxBandwidth=3D'500', enableGuestEvents=3D=
'true', maxIncomingMigrations=3D'2', maxOutgoingMigrations=3D'2', conve=
rgenceSchedule=3D'[init=3D[{name=3DsetDowntime, params=3D[100]}], stall=
ing=3D[{limit=3D1, action=3D{name=3DsetDowntime, params=3D[150]}}, {lim=
it=3D2, action=3D{name=3DsetDowntime, params=3D[200]}}, {limit=3D3, act=
ion=3D{name=3DsetDowntime, params=3D[300]}}, {limit=3D4, action=3D{name=
=3DsetDowntime, params=3D[400]}}, {limit=3D6, action=3D{name=3DsetDownt=
ime, params=3D[500]}}, {limit=3D-1, action=3D{name=3Dabort, params=3D[]=
}}]]'}), log id: 3702a9e0
2018-02-12 16:49:06,713+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-thread-49) =
[92b5af33-cb87-4142-b8fe-8b838dd7458e] START, MigrateBrokerVDSCommand(H=
ostName =3D ginger.local.systea.fr, MigrateVDSCommandParameters:{runAsy=
nc=3D'true', hostId=3D'd569c2dd-8f30-4878-8aea-858db285cf69', vmId=3D'f=
7d4ec12-627a-4b83-b59e-886400d55474', srcHost=3D'192.168.0.5', dstVdsId=
=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1', dstHost=3D'192.168.0.6:54321=
', migrationMethod=3D'ONLINE', tunnelMigration=3D'false', migrationDown=
time=3D'0', autoConverge=3D'true', migrateCompressed=3D'false', console=
Address=3D'null', maxBandwidth=3D'500', enableGuestEvents=3D'true', max=
IncomingMigrations=3D'2', maxOutgoingMigrations=3D'2', convergenceSched=
ule=3D'[init=3D[{name=3DsetDowntime, params=3D[100]}], stalling=3D[{lim=
it=3D1, action=3D{name=3DsetDowntime, params=3D[150]}}, {limit=3D2, act=
ion=3D{name=3DsetDowntime, params=3D[200]}}, {limit=3D3, action=3D{name=
=3DsetDowntime, params=3D[300]}}, {limit=3D4, action=3D{name=3DsetDownt=
ime, params=3D[400]}}, {limit=3D6, action=3D{name=3DsetDowntime, params=
=3D[500]}}, {limit=3D-1, action=3D{name=3Dabort, params=3D[]}}]]'}), lo=
g id: 1840069c
2018-02-12 16:49:06,724+01 INFO =C2=A0[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 =C2=A0[org.ovirt.engine.core.vdsbroker.=
MigrateVDSCommand] (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4=
142-b8fe-8b838dd7458e] FINISH, MigrateVDSCommand, return: MigratingFrom=
, log id: 3702a9e0
2018-02-12 16:49:06,753+01 INFO =C2=A0[org.ovirt.engine.core.dal.dbbrok=
er.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thread-4=
9) [92b5af33-cb87-4142-b8fe-8b838dd7458e] EVENT=5FID: VM=5FMIGRATION=5F=
START(62), Correlation ID: 92b5af33-cb87-4142-b8fe-8b838dd7458e, Job ID=
: f4f54054-f7c8-4481-8eda-d5a15c383061, Call Stack: null, Custom ID: nu=
ll, Custom Event ID: -1, Message: Migration started (VM: Oracle=5FPRIMA=
RY, Source: ginger.local.systea.fr, Destination: victor.local.systea.fr=
, User: admin@internal-authz).
...
2018-02-12 16:49:16,453+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmsStatisticsFetcher] (DefaultQuartzScheduler4) [162a5bc3] F=
etched 2 VMs from VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'
2018-02-12 16:49:16,455+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmAnalyzer] (DefaultQuartzScheduler4) [162a5bc3] VM 'f7d4ec1=
2-627a-4b83-b59e-886400d55474'(Oracle=5FPRIMARY) was unexpectedly detec=
ted as 'MigratingTo' on VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(vict=
or.local.systea.fr) (expected on 'd569c2dd-8f30-4878-8aea-858db285cf69'=
)
2018-02-12 16:49:16,455+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmAnalyzer] (DefaultQuartzScheduler4) [162a5bc3] VM 'f7d4ec1=
2-627a-4b83-b59e-886400d55474' is migrating to VDS 'ce3938b1-b23f-4d22-=
840a-f17d7cd87bb1'(victor.local.systea.fr) ignoring it in the refresh u=
ntil migration is done
...
2018-02-12 16:49:31,484+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmAnalyzer] (DefaultQuartzScheduler5) [11a7619a] VM 'f7d4ec1=
2-627a-4b83-b59e-886400d55474'(Oracle=5FPRIMARY) was unexpectedly detec=
ted as 'MigratingTo' on VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(vict=
or.local.systea.fr) (expected on 'd569c2dd-8f30-4878-8aea-858db285cf69'=
)
2018-02-12 16:49:31,484+01 INFO =C2=A0[org.ovirt.engine.core.vdsbroker.=
monitoring.VmAnalyzer] (DefaultQuartzScheduler5) [11a7619a] VM 'f7d4ec1=
2-627a-4b83-b59e-886400d55474' is migrating to VDS 'ce3938b1-b23f-4d22-=
840a-f17d7cd87bb1'(victor.local.systea.fr) ignoring it in the refresh u=
ntil migration is done
=C2=A0
and so on, last lines repeated indefinitly for hours since we poweroff =
the VM...
Is this something known ? Any idea about that ?

Thanks

Ovirt 4.1.6, updated last at feb-13. Gluster 3.12.1.

--

Cordialement,

Frank Soyer 

------=_=-_OpenGroupware_org_NGMime-29680-1518600202.220070-147------
Content-Type: text/html; charset=utf-8
Content-Transfer-Encoding: quoted-printable
Content-Length: 30401

<html><p>Hi all,<br />I discovered yesterday a problem when migrating V=
M with more than one vdisk.<br />On our test servers (oVirt4.1, shared =
storage with Gluster), I created 2 VMs needed for a test, from a templa=
te 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.<br />Now I saw =
some updates waiting on the host. I tried to put it in maintenance... B=
ut it stopped on the two VM. They were marked "migrating", but no more =
accessible. Other (small) VMs with only 1 vdisk was migrated without pr=
oblem at the same time.<br />I saw that a kvm process for the (big) VMs=
 was launched on the source AND destination host, but after tens of min=
utes, the migration and the VMs was always freezed. I tried to cancel t=
he migration for the VMs : failed. The only way to stop it was to power=
off the VMs : the kvm process died on the 2 hosts and the GUI alerted o=
n a failed migration.<br />In doubt, I tried to delete the second vdisk=
 on one of this VMs : it migrates then without error ! And no access pr=
oblem.<br />I tried to extend the first vdisk of the second VM, the del=
ete the second vdisk : it migrates now without problem !  &nb=
sp;<br /><br />So after another test with a VM with 2 vdisks, I can say=
 that this blocked the migration process :(<br /><br />In engine.log, f=
or a VMs with 1 vdisk migrating well, we see :</p><blockquote>2018-02-1=
2 16:46:29,705+01 INFO  [org.ovirt.engine.core.bll.MigrateVmToServ=
erCommand] (default task-28) [2f712024-5982-46a8-82c8-fd8293da5725] Loc=
k Acquired to object 'EngineLock:{exclusiveLocks=3D'[3f57e669-5e4c-4d10=
-85cc-d573004a099d=3DVM]', sharedLocks=3D''}'<br />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-fd8293da57=
25] Running command: MigrateVmToServerCommand internal: false. Entities=
 affected :  ID: 3f57e669-5e4c-4d10-85cc-d573004a099d Type: VMActi=
on group MIGRATE=5FVM with role type USER<br />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] S=
TART, MigrateVDSCommand( MigrateVDSCommandParameters:{runAsync=3D'true'=
, hostId=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1', vmId=3D'3f57e669-5e4=
c-4d10-85cc-d573004a099d', srcHost=3D'192.168.0.6', dstVdsId=3D'd569c2d=
d-8f30-4878-8aea-858db285cf69', dstHost=3D'192.168.0.5:54321', migratio=
nMethod=3D'ONLINE', tunnelMigration=3D'false', migrationDowntime=3D'0',=
 autoConverge=3D'true', migrateCompressed=3D'false', consoleAddress=3D'=
null', maxBandwidth=3D'500', enableGuestEvents=3D'true', maxIncomingMig=
rations=3D'2', maxOutgoingMigrations=3D'2', convergenceSchedule=3D'[ini=
t=3D[{name=3DsetDowntime, params=3D[100]}], stalling=3D[{limit=3D1, act=
ion=3D{name=3DsetDowntime, params=3D[150]}}, {limit=3D2, action=3D{name=
=3DsetDowntime, params=3D[200]}}, {limit=3D3, action=3D{name=3DsetDownt=
ime, params=3D[300]}}, {limit=3D4, action=3D{name=3DsetDowntime, params=
=3D[400]}}, {limit=3D6, action=3D{name=3DsetDowntime, params=3D[500]}},=
 {limit=3D-1, action=3D{name=3Dabort, params=3D[]}}]]'}), log id: 14f61=
ee0<br />2018-02-12 16:46:30,262+01 INFO  [org.ovirt.engine.core.v=
dsbroker.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-th=
read-32) [2f712024-5982-46a8-82c8-fd8293da5725] START, MigrateBrokerVDS=
Command(HostName =3D victor.local.systea.fr, MigrateVDSCommandParameter=
s:{runAsync=3D'true', hostId=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1', =
vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d', srcHost=3D'192.168.0.6',=
 dstVdsId=3D'd569c2dd-8f30-4878-8aea-858db285cf69', dstHost=3D'192.168.=
0.5:54321', migrationMethod=3D'ONLINE', tunnelMigration=3D'false', migr=
ationDowntime=3D'0', autoConverge=3D'true', migrateCompressed=3D'false'=
, consoleAddress=3D'null', maxBandwidth=3D'500', enableGuestEvents=3D't=
rue', maxIncomingMigrations=3D'2', maxOutgoingMigrations=3D'2', converg=
enceSchedule=3D'[init=3D[{name=3DsetDowntime, params=3D[100]}], stallin=
g=3D[{limit=3D1, action=3D{name=3DsetDowntime, params=3D[150]}}, {limit=
=3D2, action=3D{name=3DsetDowntime, params=3D[200]}}, {limit=3D3, actio=
n=3D{name=3DsetDowntime, params=3D[300]}}, {limit=3D4, action=3D{name=3D=
setDowntime, params=3D[400]}}, {limit=3D6, action=3D{name=3DsetDowntime=
, params=3D[500]}}, {limit=3D-1, action=3D{name=3Dabort, params=3D[]}}]=
]'}), log id: 775cd381<br />2018-02-12 16:46:30,277+01 INFO  [org.=
ovirt.engine.core.vdsbroker.vdsbroker.MigrateBrokerVDSCommand] (org.ovi=
rt.thread.pool-6-thread-32) [2f712024-5982-46a8-82c8-fd8293da5725] FINI=
SH, MigrateBrokerVDSCommand, log id: 775cd381<br />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-fd8293da572=
5] FINISH, MigrateVDSCommand, return: MigratingFrom, log id: 14f61ee0<b=
r />2018-02-12 16:46:30,301+01 INFO  [org.ovirt.engine.core.dal.db=
broker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thre=
ad-32) [2f712024-5982-46a8-82c8-fd8293da5725] EVENT=5FID: VM=5FMIGRATIO=
N=5FSTART(62), Correlation ID: 2f712024-5982-46a8-82c8-fd8293da5725, Jo=
b ID: 4bd19aa9-cc99-4d02-884e-5a1e857a7738, Call Stack: null, Custom ID=
: null, Custom Event ID: -1, Message: Migration started (VM: Oracle=5FS=
ECONDARY, Source: victor.local.systea.fr, Destination: ginger.local.sys=
tea.fr, User: admin@internal-authz).<br />2018-02-12 16:46:31,106+01 IN=
FO  [org.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand]=
 (DefaultQuartzScheduler9) [54a65b66] START, FullListVDSCommand(HostNam=
e =3D victor.local.systea.fr, FullListVDSCommandParameters:{runAsync=3D=
'true', hostId=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1', vmIds=3D'[3f57=
e669-5e4c-4d10-85cc-d573004a099d]'}), log id: 54b4b435<br />2018-02-12 =
16:46:31,147+01 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.F=
ullListVDSCommand] (DefaultQuartzScheduler9) [54a65b66] FINISH, FullLis=
tVDSCommand, return: [{acpiEnable=3Dtrue, emulatedMachine=3Dpc-i440fx-r=
hel7.3.0, tabletEnable=3Dtrue, pid=3D1493, guestDiskMapping=3D{0QEMU=5F=
QEMU=5FHARDDISK=5Fd890fa68-fba4-4f49-9=3D{name=3D/dev/sda}, QEMU=5FDVD-=
ROM=5FQM00003=3D{name=3D/dev/sr0}}, transparentHugePages=3Dtrue, timeOf=
fset=3D0, cpuType=3DNehalem, smp=3D2, pauseCode=3DNOERR, guestNumaNodes=
=3D[Ljava.lang.Object;@1d9042cd, smartcardEnable=3Dfalse, custom=3D{dev=
ice=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F879c93ab-4df1-435c-a=
f02-565039fcc254=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'879c93ab-4df=
1-435c-af02-565039fcc254', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d=
'}', device=3D'unix', type=3D'CHANNEL', bootOrder=3D'0', specParams=3D'=
[]', address=3D'{bus=3D0, controller=3D0, type=3Dvirtio-serial, port=3D=
1}', managed=3D'false', plugged=3D'true', readOnly=3D'false', deviceAli=
as=3D'channel0', customProperties=3D'[]', snapshotId=3D'null', logicalN=
ame=3D'null', hostDevice=3D'null'}, device=5Ffbddd528-7d93-49c6-a286-18=
0e021cb274device=5F879c93ab-4df1-435c-af02-565039fcc254device=5F8945f61=
a-abbe-4156-8485-a4aa6f1908dbdevice=5F017b5e59-01c4-4aac-bf0c-b5d955728=
4d6=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'017b5e59-01c4-4aac-bf0c-b=
5d9557284d6', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', device=3D=
'tablet', type=3D'UNKNOWN', bootOrder=3D'0', specParams=3D'[]', address=
=3D'{bus=3D0, type=3Dusb, port=3D1}', managed=3D'false', plugged=3D'tru=
e', readOnly=3D'false', deviceAlias=3D'input0', customProperties=3D'[]'=
, snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'null'}, devi=
ce=5Ffbddd528-7d93-49c6-a286-180e021cb274=3DVmDevice:{id=3D'VmDeviceId:=
{deviceId=3D'fbddd528-7d93-49c6-a286-180e021cb274', vmId=3D'3f57e669-5e=
4c-4d10-85cc-d573004a099d'}', device=3D'ide', type=3D'CONTROLLER', boot=
Order=3D'0', specParams=3D'[]', address=3D'{slot=3D0x01, bus=3D0x00, do=
main=3D0x0000, type=3Dpci, function=3D0x1}', managed=3D'false', plugged=
=3D'true', readOnly=3D'false', deviceAlias=3D'ide', customProperties=3D=
'[]', snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'null'}, =
device=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F879c93ab-4df1-435=
c-af02-565039fcc254device=5F8945f61a-abbe-4156-8485-a4aa6f1908db=3DVmDe=
vice:{id=3D'VmDeviceId:{deviceId=3D'8945f61a-abbe-4156-8485-a4aa6f1908d=
b', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', device=3D'unix', t=
ype=3D'CHANNEL', bootOrder=3D'0', specParams=3D'[]', address=3D'{bus=3D=
0, controller=3D0, type=3Dvirtio-serial, port=3D2}', managed=3D'false',=
 plugged=3D'true', readOnly=3D'false', deviceAlias=3D'channel1', custom=
Properties=3D'[]', snapshotId=3D'null', logicalName=3D'null', hostDevic=
e=3D'null'}}, vmType=3Dkvm, memSize=3D8192, smpCoresPerSocket=3D1, vmNa=
me=3DOracle=5FSECONDARY, nice=3D0, status=3DMigration Source, maxMemSiz=
e=3D32768, bootMenuEnable=3Dfalse, vmId=3D3f57e669-5e4c-4d10-85cc-d5730=
04a099d, numOfIoThreads=3D2, smpThreadsPerCore=3D1, memGuaranteedSize=3D=
8192, kvmEnable=3Dtrue, pitReinjection=3Dfalse, displayNetwork=3Dovirtm=
gmt, devices=3D[Ljava.lang.Object;@28ae66d7, display=3Dvnc, maxVCpus=3D=
16, clientIp=3D, statusTime=3D4299484520, maxMemSlots=3D16}], log id: 5=
4b4b435<br />2018-02-12 16:46:31,150+01 INFO  [org.ovirt.engine.co=
re.vdsbroker.monitoring.VmsStatisticsFetcher] (DefaultQuartzScheduler1)=
 [27fac647] Fetched 3 VMs from VDS 'd569c2dd-8f30-4878-8aea-858db285cf6=
9'<br />2018-02-12 16:46:31,151+01 INFO  [org.ovirt.engine.core.vd=
sbroker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler9) [54a6=
5b66] Received a vnc Device without an address when processing VM 3f57e=
669-5e4c-4d10-85cc-d573004a099d devices, skipping device: {device=3Dvnc=
, specParams=3D{displayNetwork=3Dovirtmgmt, keyMap=3Dfr, displayIp=3D19=
2.168.0.6}, type=3Dgraphics, deviceId=3D813957b1-446a-4e88-9e40-9fe76d2=
c442d, port=3D5901}<br />2018-02-12 16:46:31,151+01 INFO  [org.ovi=
rt.engine.core.vdsbroker.monitoring.VmDevicesMonitoring] (DefaultQuartz=
Scheduler9) [54a65b66] Received a lease Device without an address when =
processing VM 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping de=
vice: {lease=5Fid=3D3f57e669-5e4c-4d10-85cc-d573004a099d, sd=5Fid=3D1e5=
1cecc-eb2e-47d0-b185-920fdc7afa16, deviceId=3D{uuid=3Da09949aa-5642-4b6=
d-94a4-8b0d04257be5}, offset=3D6291456, device=3Dlease, path=3D/rhev/da=
ta-center/mnt/glusterSD/192.168.0.6:=5FDATA01/1e51cecc-eb2e-47d0-b185-9=
20fdc7afa16/dom=5Fmd/xleases, type=3Dlease}<br />2018-02-12 16:46:31,15=
2+01 INFO  [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer]=
 (DefaultQuartzScheduler1) [27fac647] VM '3f57e669-5e4c-4d10-85cc-d5730=
04a099d'(Oracle=5FSECONDARY) was unexpectedly detected as 'MigratingTo'=
 on VDS 'd569c2dd-8f30-4878-8aea-858db285cf69'(ginger.local.systea.fr) =
(expected on 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1')<br />2018-02-12 16=
:46:31,152+01 INFO  [org.ovirt.engine.core.vdsbroker.monitoring.Vm=
Analyzer] (DefaultQuartzScheduler1) [27fac647] VM '3f57e669-5e4c-4d10-8=
5cc-d573004a099d' is migrating to VDS 'd569c2dd-8f30-4878-8aea-858db285=
cf69'(ginger.local.systea.fr) ignoring it in the refresh until migratio=
n is done<br />....<br />2018-02-12 16:46:41,631+01 INFO  [org.ovi=
rt.engine.core.vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-=
11) [] VM '3f57e669-5e4c-4d10-85cc-d573004a099d' was reported as Down o=
n VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(victor.local.systea.fr)<br=
 />2018-02-12 16:46:41,632+01 INFO  [org.ovirt.engine.core.vdsbrok=
er.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-11) [] START, De=
stroyVDSCommand(HostName =3D victor.local.systea.fr, DestroyVmVDSComman=
dParameters:{runAsync=3D'true', hostId=3D'ce3938b1-b23f-4d22-840a-f17d7=
cd87bb1', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d', force=3D'false=
', secondsToWait=3D'0', gracefully=3D'false', reason=3D'', ignoreNoVm=3D=
'true'}), log id: 560eca57<br />2018-02-12 16:46:41,650+01 INFO  [=
org.ovirt.engine.core.vdsbroker.vdsbroker.DestroyVDSCommand] (ForkJoinP=
ool-1-worker-11) [] FINISH, DestroyVDSCommand, log id: 560eca57<br />20=
18-02-12 16:46:41,650+01 INFO  [org.ovirt.engine.core.vdsbroker.mo=
nitoring.VmAnalyzer] (ForkJoinPool-1-worker-11) [] VM '3f57e669-5e4c-4d=
10-85cc-d573004a099d'(Oracle=5FSECONDARY) moved from 'MigratingFrom' --=
> 'Down'<br />2018-02-12 16:46:41,651+01 INFO  [org.ovirt.engin=
e.core.vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-11) [] H=
anding over VM '3f57e669-5e4c-4d10-85cc-d573004a099d'(Oracle=5FSECONDAR=
Y) to Host 'd569c2dd-8f30-4878-8aea-858db285cf69'. Setting VM to status=
 'MigratingTo'<br />2018-02-12 16:46:42,163+01 INFO  [org.ovirt.en=
gine.core.vdsbroker.monitoring.VmAnalyzer] (ForkJoinPool-1-worker-4) []=
 VM '3f57e669-5e4c-4d10-85cc-d573004a099d'(Oracle=5FSECONDARY) moved fr=
om 'MigratingTo' --> 'Up'<br />2018-02-12 16:46:42,169+01 INFO  =
;[org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (F=
orkJoinPool-1-worker-4) [] START, MigrateStatusVDSCommand(HostName =3D =
ginger.local.systea.fr, MigrateStatusVDSCommandParameters:{runAsync=3D'=
true', hostId=3D'd569c2dd-8f30-4878-8aea-858db285cf69', vmId=3D'3f57e66=
9-5e4c-4d10-85cc-d573004a099d'}), log id: 7a25c281<br />2018-02-12 16:4=
6:42,174+01 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.Migra=
teStatusVDSCommand] (ForkJoinPool-1-worker-4) [] FINISH, MigrateStatusV=
DSCommand, log id: 7a25c281<br />2018-02-12 16:46:42,194+01 INFO  =
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] =
(ForkJoinPool-1-worker-4) [] EVENT=5FID: VM=5FMIGRATION=5FDONE(63), Cor=
relation ID: 2f712024-5982-46a8-82c8-fd8293da5725, Job ID: 4bd19aa9-cc9=
9-4d02-884e-5a1e857a7738, Call Stack: null, Custom ID: null, Custom Eve=
nt ID: -1, Message: Migration completed (VM: Oracle=5FSECONDARY, Source=
: victor.local.systea.fr, Destination: ginger.local.systea.fr, Duration=
: 11 seconds, Total: 11 seconds, Actual downtime: (N/A))<br />2018-02-1=
2 16:46:42,201+01 INFO  [org.ovirt.engine.core.bll.MigrateVmToServ=
erCommand] (ForkJoinPool-1-worker-4) [] Lock freed to object 'EngineLoc=
k:{exclusiveLocks=3D'[3f57e669-5e4c-4d10-85cc-d573004a099d=3DVM]', shar=
edLocks=3D''}'<br />2018-02-12 16:46:42,203+01 INFO  [org.ovirt.en=
gine.core.vdsbroker.vdsbroker.FullListVDSCommand] (ForkJoinPool-1-worke=
r-4) [] START, FullListVDSCommand(HostName =3D ginger.local.systea.fr, =
FullListVDSCommandParameters:{runAsync=3D'true', hostId=3D'd569c2dd-8f3=
0-4878-8aea-858db285cf69', vmIds=3D'[3f57e669-5e4c-4d10-85cc-d573004a09=
9d]'}), log id: 7cc65298<br />2018-02-12 16:46:42,254+01 INFO  [or=
g.ovirt.engine.core.vdsbroker.vdsbroker.FullListVDSCommand] (ForkJoinPo=
ol-1-worker-4) [] FINISH, FullListVDSCommand, return: [{acpiEnable=3Dtr=
ue, emulatedMachine=3Dpc-i440fx-rhel7.3.0, afterMigrationStatus=3D, tab=
letEnable=3Dtrue, pid=3D18748, guestDiskMapping=3D{}, transparentHugePa=
ges=3Dtrue, timeOffset=3D0, cpuType=3DNehalem, smp=3D2, guestNumaNodes=3D=
[Ljava.lang.Object;@760085fd, custom=3D{device=5Ffbddd528-7d93-49c6-a28=
6-180e021cb274device=5F879c93ab-4df1-435c-af02-565039fcc254=3DVmDevice:=
{id=3D'VmDeviceId:{deviceId=3D'879c93ab-4df1-435c-af02-565039fcc254', v=
mId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', device=3D'unix', type=3D=
'CHANNEL', bootOrder=3D'0', specParams=3D'[]', address=3D'{bus=3D0, con=
troller=3D0, type=3Dvirtio-serial, port=3D1}', managed=3D'false', plugg=
ed=3D'true', readOnly=3D'false', deviceAlias=3D'channel0', customProper=
ties=3D'[]', snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'n=
ull'}, device=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F879c93ab-4=
df1-435c-af02-565039fcc254device=5F8945f61a-abbe-4156-8485-a4aa6f1908db=
device=5F017b5e59-01c4-4aac-bf0c-b5d9557284d6=3DVmDevice:{id=3D'VmDevic=
eId:{deviceId=3D'017b5e59-01c4-4aac-bf0c-b5d9557284d6', vmId=3D'3f57e66=
9-5e4c-4d10-85cc-d573004a099d'}', device=3D'tablet', type=3D'UNKNOWN', =
bootOrder=3D'0', specParams=3D'[]', address=3D'{bus=3D0, type=3Dusb, po=
rt=3D1}', managed=3D'false', plugged=3D'true', readOnly=3D'false', devi=
ceAlias=3D'input0', customProperties=3D'[]', snapshotId=3D'null', logic=
alName=3D'null', hostDevice=3D'null'}, device=5Ffbddd528-7d93-49c6-a286=
-180e021cb274=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'fbddd528-7d93-4=
9c6-a286-180e021cb274', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}'=
, device=3D'ide', type=3D'CONTROLLER', bootOrder=3D'0', specParams=3D'[=
]', address=3D'{slot=3D0x01, bus=3D0x00, domain=3D0x0000, type=3Dpci, f=
unction=3D0x1}', managed=3D'false', plugged=3D'true', readOnly=3D'false=
', deviceAlias=3D'ide', customProperties=3D'[]', snapshotId=3D'null', l=
ogicalName=3D'null', hostDevice=3D'null'}, device=5Ffbddd528-7d93-49c6-=
a286-180e021cb274device=5F879c93ab-4df1-435c-af02-565039fcc254device=5F=
8945f61a-abbe-4156-8485-a4aa6f1908db=3DVmDevice:{id=3D'VmDeviceId:{devi=
ceId=3D'8945f61a-abbe-4156-8485-a4aa6f1908db', vmId=3D'3f57e669-5e4c-4d=
10-85cc-d573004a099d'}', device=3D'unix', type=3D'CHANNEL', bootOrder=3D=
'0', specParams=3D'[]', address=3D'{bus=3D0, controller=3D0, type=3Dvir=
tio-serial, port=3D2}', managed=3D'false', plugged=3D'true', readOnly=3D=
'false', deviceAlias=3D'channel1', customProperties=3D'[]', snapshotId=3D=
'null', logicalName=3D'null', hostDevice=3D'null'}}, vmType=3Dkvm, memS=
ize=3D8192, smpCoresPerSocket=3D1, vmName=3DOracle=5FSECONDARY, nice=3D=
0, status=3DUp, maxMemSize=3D32768, bootMenuEnable=3Dfalse, vmId=3D3f57=
e669-5e4c-4d10-85cc-d573004a099d, numOfIoThreads=3D2, smpThreadsPerCore=
=3D1, smartcardEnable=3Dfalse, maxMemSlots=3D16, kvmEnable=3Dtrue, pitR=
einjection=3Dfalse, displayNetwork=3Dovirtmgmt, devices=3D[Ljava.lang.O=
bject;@2e4d3dd3, memGuaranteedSize=3D8192, maxVCpus=3D16, clientIp=3D, =
statusTime=3D4304259600, display=3Dvnc}], log id: 7cc65298<br />2018-02=
-12 16:46:42,257+01 INFO  [org.ovirt.engine.core.vdsbroker.monitor=
ing.VmDevicesMonitoring] (ForkJoinPool-1-worker-4) [] Received a vnc De=
vice without an address when processing VM 3f57e669-5e4c-4d10-85cc-d573=
004a099d devices, skipping device: {device=3Dvnc, specParams=3D{display=
Network=3Dovirtmgmt, keyMap=3Dfr, displayIp=3D192.168.0.5}, type=3Dgrap=
hics, deviceId=3D813957b1-446a-4e88-9e40-9fe76d2c442d, port=3D5901}<br =
/>2018-02-12 16:46:42,257+01 INFO  [org.ovirt.engine.core.vdsbroke=
r.monitoring.VmDevicesMonitoring] (ForkJoinPool-1-worker-4) [] Received=
 a lease Device without an address when processing VM 3f57e669-5e4c-4d1=
0-85cc-d573004a099d devices, skipping device: {lease=5Fid=3D3f57e669-5e=
4c-4d10-85cc-d573004a099d, sd=5Fid=3D1e51cecc-eb2e-47d0-b185-920fdc7afa=
16, deviceId=3D{uuid=3Da09949aa-5642-4b6d-94a4-8b0d04257be5}, offset=3D=
6291456, device=3Dlease, path=3D/rhev/data-center/mnt/glusterSD/192.168=
.0.6:=5FDATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom=5Fmd/xleases, t=
ype=3Dlease}<br />2018-02-12 16:46:46,260+01 INFO  [org.ovirt.engi=
ne.core.vdsbroker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler=
5) [7fcb200a] FINISH, FullListVDSCommand, return: [{acpiEnable=3Dtrue, =
emulatedMachine=3Dpc-i440fx-rhel7.3.0, afterMigrationStatus=3D, tabletE=
nable=3Dtrue, pid=3D18748, guestDiskMapping=3D{0QEMU=5FQEMU=5FHARDDISK=5F=
d890fa68-fba4-4f49-9=3D{name=3D/dev/sda}, QEMU=5FDVD-ROM=5FQM00003=3D{n=
ame=3D/dev/sr0}}, transparentHugePages=3Dtrue, timeOffset=3D0, cpuType=3D=
Nehalem, smp=3D2, guestNumaNodes=3D[Ljava.lang.Object;@77951faf, custom=
=3D{device=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F879c93ab-4df1=
-435c-af02-565039fcc254=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'879c9=
3ab-4df1-435c-af02-565039fcc254', vmId=3D'3f57e669-5e4c-4d10-85cc-d5730=
04a099d'}', device=3D'unix', type=3D'CHANNEL', bootOrder=3D'0', specPar=
ams=3D'[]', address=3D'{bus=3D0, controller=3D0, type=3Dvirtio-serial, =
port=3D1}', managed=3D'false', plugged=3D'true', readOnly=3D'false', de=
viceAlias=3D'channel0', customProperties=3D'[]', snapshotId=3D'null', l=
ogicalName=3D'null', hostDevice=3D'null'}, device=5Ffbddd528-7d93-49c6-=
a286-180e021cb274device=5F879c93ab-4df1-435c-af02-565039fcc254device=5F=
8945f61a-abbe-4156-8485-a4aa6f1908dbdevice=5F017b5e59-01c4-4aac-bf0c-b5=
d9557284d6=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'017b5e59-01c4-4aac=
-bf0c-b5d9557284d6', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', d=
evice=3D'tablet', type=3D'UNKNOWN', bootOrder=3D'0', specParams=3D'[]',=
 address=3D'{bus=3D0, type=3Dusb, port=3D1}', managed=3D'false', plugge=
d=3D'true', readOnly=3D'false', deviceAlias=3D'input0', customPropertie=
s=3D'[]', snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'null=
'}, device=5Ffbddd528-7d93-49c6-a286-180e021cb274=3DVmDevice:{id=3D'VmD=
eviceId:{deviceId=3D'fbddd528-7d93-49c6-a286-180e021cb274', vmId=3D'3f5=
7e669-5e4c-4d10-85cc-d573004a099d'}', device=3D'ide', type=3D'CONTROLLE=
R', bootOrder=3D'0', specParams=3D'[]', address=3D'{slot=3D0x01, bus=3D=
0x00, domain=3D0x0000, type=3Dpci, function=3D0x1}', managed=3D'false',=
 plugged=3D'true', readOnly=3D'false', deviceAlias=3D'ide', customPrope=
rties=3D'[]', snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'=
null'}, device=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F879c93ab-=
4df1-435c-af02-565039fcc254device=5F8945f61a-abbe-4156-8485-a4aa6f1908d=
b=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'8945f61a-abbe-4156-8485-a4a=
a6f1908db', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', device=3D'=
unix', type=3D'CHANNEL', bootOrder=3D'0', specParams=3D'[]', address=3D=
'{bus=3D0, controller=3D0, type=3Dvirtio-serial, port=3D2}', managed=3D=
'false', plugged=3D'true', readOnly=3D'false', deviceAlias=3D'channel1'=
, customProperties=3D'[]', snapshotId=3D'null', logicalName=3D'null', h=
ostDevice=3D'null'}}, vmType=3Dkvm, memSize=3D8192, smpCoresPerSocket=3D=
1, vmName=3DOracle=5FSECONDARY, nice=3D0, status=3DUp, maxMemSize=3D327=
68, bootMenuEnable=3Dfalse, vmId=3D3f57e669-5e4c-4d10-85cc-d573004a099d=
, numOfIoThreads=3D2, smpThreadsPerCore=3D1, smartcardEnable=3Dfalse, m=
axMemSlots=3D16, kvmEnable=3Dtrue, pitReinjection=3Dfalse, displayNetwo=
rk=3Dovirtmgmt, devices=3D[Ljava.lang.Object;@286410fd, memGuaranteedSi=
ze=3D8192, maxVCpus=3D16, clientIp=3D, statusTime=3D4304263620, display=
=3Dvnc}], log id: 58cdef4c<br />2018-02-12 16:46:46,267+01 INFO  [=
org.ovirt.engine.core.vdsbroker.monitoring.VmDevicesMonitoring] (Defaul=
tQuartzScheduler5) [7fcb200a] Received a vnc Device without an address =
when processing VM 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skippi=
ng device: {device=3Dvnc, specParams=3D{displayNetwork=3Dovirtmgmt, key=
Map=3Dfr, displayIp=3D192.168.0.5}, type=3Dgraphics, deviceId=3D813957b=
1-446a-4e88-9e40-9fe76d2c442d, port=3D5901}<br />2018-02-12 16:46:46,26=
8+01 INFO  [org.ovirt.engine.core.vdsbroker.monitoring.VmDevicesMo=
nitoring] (DefaultQuartzScheduler5) [7fcb200a] Received a lease Device =
without an address when processing VM 3f57e669-5e4c-4d10-85cc-d573004a0=
99d devices, skipping device: {lease=5Fid=3D3f57e669-5e4c-4d10-85cc-d57=
3004a099d, sd=5Fid=3D1e51cecc-eb2e-47d0-b185-920fdc7afa16, deviceId=3D{=
uuid=3Da09949aa-5642-4b6d-94a4-8b0d04257be5}, offset=3D6291456, device=3D=
lease, path=3D/rhev/data-center/mnt/glusterSD/192.168.0.6:=5FDATA01/1e5=
1cecc-eb2e-47d0-b185-920fdc7afa16/dom=5Fmd/xleases, type=3Dlease}<p>&nb=
sp;</p></blockquote><br />For the VM with 2 vdisks we see :<blockquote>=
<p>2018-02-12 16:49:06,112+01 INFO  [org.ovirt.engine.core.bll.Mig=
rateVmToServerCommand] (default task-50) [92b5af33-cb87-4142-b8fe-8b838=
dd7458e] Lock Acquired to object 'EngineLock:{exclusiveLocks=3D'[f7d4ec=
12-627a-4b83-b59e-886400d55474=3DVM]', sharedLocks=3D''}'<br />2018-02-=
12 16:49:06,407+01 INFO  [org.ovirt.engine.core.bll.MigrateVmToSer=
verCommand] (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4142-b8f=
e-8b838dd7458e] Running command: MigrateVmToServerCommand internal: fal=
se. Entities affected :  ID: f7d4ec12-627a-4b83-b59e-886400d55474 =
Type: VMAction group MIGRATE=5FVM with role type USER<br />2018-02-12 1=
6:49:06,712+01 INFO  [org.ovirt.engine.core.vdsbroker.MigrateVDSCo=
mmand] (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4142-b8fe-8b8=
38dd7458e] START, MigrateVDSCommand( MigrateVDSCommandParameters:{runAs=
ync=3D'true', hostId=3D'd569c2dd-8f30-4878-8aea-858db285cf69', vmId=3D'=
f7d4ec12-627a-4b83-b59e-886400d55474', srcHost=3D'192.168.0.5', dstVdsI=
d=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1', dstHost=3D'192.168.0.6:5432=
1', migrationMethod=3D'ONLINE', tunnelMigration=3D'false', migrationDow=
ntime=3D'0', autoConverge=3D'true', migrateCompressed=3D'false', consol=
eAddress=3D'null', maxBandwidth=3D'500', enableGuestEvents=3D'true', ma=
xIncomingMigrations=3D'2', maxOutgoingMigrations=3D'2', convergenceSche=
dule=3D'[init=3D[{name=3DsetDowntime, params=3D[100]}], stalling=3D[{li=
mit=3D1, action=3D{name=3DsetDowntime, params=3D[150]}}, {limit=3D2, ac=
tion=3D{name=3DsetDowntime, params=3D[200]}}, {limit=3D3, action=3D{nam=
e=3DsetDowntime, params=3D[300]}}, {limit=3D4, action=3D{name=3DsetDown=
time, params=3D[400]}}, {limit=3D6, action=3D{name=3DsetDowntime, param=
s=3D[500]}}, {limit=3D-1, action=3D{name=3Dabort, params=3D[]}}]]'}), l=
og id: 3702a9e0<br />2018-02-12 16:49:06,713+01 INFO  [org.ovirt.e=
ngine.core.vdsbroker.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thre=
ad.pool-6-thread-49) [92b5af33-cb87-4142-b8fe-8b838dd7458e] START, Migr=
ateBrokerVDSCommand(HostName =3D ginger.local.systea.fr, MigrateVDSComm=
andParameters:{runAsync=3D'true', hostId=3D'd569c2dd-8f30-4878-8aea-858=
db285cf69', vmId=3D'f7d4ec12-627a-4b83-b59e-886400d55474', srcHost=3D'1=
92.168.0.5', dstVdsId=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1', dstHost=
=3D'192.168.0.6:54321', migrationMethod=3D'ONLINE', tunnelMigration=3D'=
false', migrationDowntime=3D'0', autoConverge=3D'true', migrateCompress=
ed=3D'false', consoleAddress=3D'null', maxBandwidth=3D'500', enableGues=
tEvents=3D'true', maxIncomingMigrations=3D'2', maxOutgoingMigrations=3D=
'2', convergenceSchedule=3D'[init=3D[{name=3DsetDowntime, params=3D[100=
]}], stalling=3D[{limit=3D1, action=3D{name=3DsetDowntime, params=3D[15=
0]}}, {limit=3D2, action=3D{name=3DsetDowntime, params=3D[200]}}, {limi=
t=3D3, action=3D{name=3DsetDowntime, params=3D[300]}}, {limit=3D4, acti=
on=3D{name=3DsetDowntime, params=3D[400]}}, {limit=3D6, action=3D{name=3D=
setDowntime, params=3D[500]}}, {limit=3D-1, action=3D{name=3Dabort, par=
ams=3D[]}}]]'}), log id: 1840069c<br />2018-02-12 16:49:06,724+01 INFO =
 [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateBrokerVDSComman=
d] (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4142-b8fe-8b838dd=
7458e] FINISH, MigrateBrokerVDSCommand, log id: 1840069c<br />2018-02-1=
2 16:49:06,732+01 INFO  [org.ovirt.engine.core.vdsbroker.MigrateVD=
SCommand] (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4142-b8fe-=
8b838dd7458e] FINISH, MigrateVDSCommand, return: MigratingFrom, log id:=
 3702a9e0<br />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=5FID: VM=
=5FMIGRATION=5FSTART(62), Correlation ID: 92b5af33-cb87-4142-b8fe-8b838=
dd7458e, Job ID: f4f54054-f7c8-4481-8eda-d5a15c383061, Call Stack: null=
, Custom ID: null, Custom Event ID: -1, Message: Migration started (VM:=
 Oracle=5FPRIMARY, Source: ginger.local.systea.fr, Destination: victor.=
local.systea.fr, User: admin@internal-authz).<br />...<br />2018-02-12 =
16:49:16,453+01 INFO  [org.ovirt.engine.core.vdsbroker.monitoring.=
VmsStatisticsFetcher] (DefaultQuartzScheduler4) [162a5bc3] Fetched 2 VM=
s from VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'<br />2018-02-12 16:49=
:16,455+01 INFO  [org.ovirt.engine.core.vdsbroker.monitoring.VmAna=
lyzer] (DefaultQuartzScheduler4) [162a5bc3] VM 'f7d4ec12-627a-4b83-b59e=
-886400d55474'(Oracle=5FPRIMARY) was unexpectedly detected as 'Migratin=
gTo' on VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(victor.local.systea.=
fr) (expected on 'd569c2dd-8f30-4878-8aea-858db285cf69')<br />2018-02-1=
2 16:49:16,455+01 INFO  [org.ovirt.engine.core.vdsbroker.monitorin=
g.VmAnalyzer] (DefaultQuartzScheduler4) [162a5bc3] VM 'f7d4ec12-627a-4b=
83-b59e-886400d55474' is migrating to VDS 'ce3938b1-b23f-4d22-840a-f17d=
7cd87bb1'(victor.local.systea.fr) ignoring it in the refresh until migr=
ation is done<br />...<br />2018-02-12 16:49:31,484+01 INFO  [org.=
ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (DefaultQuartzSchedu=
ler5) [11a7619a] VM 'f7d4ec12-627a-4b83-b59e-886400d55474'(Oracle=5FPRI=
MARY) was unexpectedly detected as 'MigratingTo' on VDS 'ce3938b1-b23f-=
4d22-840a-f17d7cd87bb1'(victor.local.systea.fr) (expected on 'd569c2dd-=
8f30-4878-8aea-858db285cf69')<br />2018-02-12 16:49:31,484+01 INFO &nbs=
p;[org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] (DefaultQuart=
zScheduler5) [11a7619a] VM 'f7d4ec12-627a-4b83-b59e-886400d55474' is mi=
grating to VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(victor.local.syst=
ea.fr) ignoring it in the refresh until migration is done<br /> </=
p></blockquote><br />and so on, last lines repeated indefinitly for hou=
rs since we poweroff the VM...<br />Is this something known ? Any idea =
about that ?<br /><br />Thanks<br /><br />Ovirt 4.1.6, updated last at =
feb-13. Gluster 3.12.1.<br /><br />--<br /><style type=3D"text/css">.Te=
xt1 {
        color: black;
        font-size:9pt;
        font-family:Verdana;
    }
    .Text2 {
        color: black;
        font-size:7pt;
        font-family:Verdana;
    }</style><p class=3D"Text1">Cordialement,<br /><br /><b>Frank Soyer=
 </b></p></html>

------=_=-_OpenGroupware_org_NGMime-29680-1518600202.220070-147--------

[ovirt-users] VMs with multiple vdisks don't migrate

fsoyer