
1 Mar
2018
1 Mar
'18
3:27 p.m.
------=_=-_OpenGroupware_org_NGMime-18019-1519921630.582362-42------ Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: quoted-printable Content-Length: 38502 I Milan, I tried to activate the debug mode, but the restart of libvirt crashed = something on the host : it was no more possible to start any vm on it, = and migration to it just never started. So I decided to restart it, and= to be sure, I've restarted all the hosts. And... now the migration of all VMs, simple or multi-disks, works ?!? S= o, there was probably something hidden that was resetted or repaired by= the global restart !.... In french, we call that "tomber en marche" ;)= So : solved. Thank you for the wasted time ! -- Cordialement, Frank Soyer Mob. 06 72 28 38 53 - Fix. 05 49 50 52 34 Le Lundi, F=C3=A9vrier 26, 2018 12:59 CET, Milan Zamazal <mzamazal@redh= at.com> a =C3=A9crit: =C2=A0"fsoyer" <fsoyer@systea.fr> writes: > I don't beleive that this is relatd to a host, tests have been done f= rom victor > source to ginger dest and ginger to victor. I don't see problems on s= torage > (gluster 3.12 native managed by ovirt), when VMs with a uniq disk fro= m 20 to > 250G migrate without error in some seconds and with no downtime. The host itself may be fine, but libvirt/QEMU running there may expose problems, perhaps just for some VMs. According to your logs something is not behaving as expected on the source host during the faulty migration. > How ca I enable this libvirt debug mode ? Set the following options in /etc/libvirt/libvirtd.conf (look for examples in comments there) - log=5Flevel=3D1 - log=5Foutputs=3D"1:file:/var/log/libvirt/libvirtd.log" and restart libvirt. Then /var/log/libvirt/libvirtd.log should contain the log. It will be huge, so I suggest to enable it only for the time of reproducing the problem. > -- > > Cordialement, > > Frank Soyer > > =C2=A0 > > Le Vendredi, F=C3=A9vrier 23, 2018 09:56 CET, Milan Zamazal <mzamazal= @redhat.com> a =C3=A9crit: > =C2=A0Maor Lipchuk <mlipchuk@redhat.com> writes: > >> I encountered a bug (see [1]) which contains the same error mentione= d in >> your VDSM logs (see [2]), but I doubt it is related. > > Indeed, it's not related. > > The error in vdsm=5Fvictor.log just means that the info gathering cal= l > tries to access libvirt domain before the incoming migration is > completed. It's ugly but harmless. > >> Milan, maybe you have any advice to troubleshoot the issue? Will the= >> libvirt/qemu logs can help? > > It seems there is something wrong on (at least) the source host. Ther= e > are no migration progress messages in the vdsm=5Fginger.log and there= are > warnings about stale stat samples. That looks like problems with > calling libvirt =E2=80=93 slow and/or stuck calls, maybe due to stora= ge > problems. The possibly faulty second disk could cause that. > > libvirt debug logs could tell us whether that is indeed the problem a= nd > whether it is caused by storage or something else. > >> I would suggest to open a bug on that issue so we can track it more >> properly. >> >> Regards, >> Maor >> >> >> [1] >> https://bugzilla.redhat.com/show=5Fbug.cgi?id=3D1486543 - Migration = leads to >> VM running on 2 Hosts >> >> [2] >> 2018-02-16 09:43:35,236+0100 ERROR (jsonrpc/7) [jsonrpc.JsonRpcServe= r] >> Internal server error (=5F=5Finit=5F=5F:577) >> Traceback (most recent call last): >> File "/usr/lib/python2.7/site-packages/yajsonrpc/=5F=5Finit=5F=5F.py= ", line 572, >> in =5Fhandle=5Frequest >> res =3D method(**params) >> File "/usr/lib/python2.7/site-packages/vdsm/rpc/Bridge.py", line 198= , in >> =5FdynamicMethod >> result =3D fn(*methodArgs) >> File "/usr/share/vdsm/API.py", line 1454, in getAllVmIoTunePolicies >> io=5Ftune=5Fpolicies=5Fdict =3D self.=5Fcif.getAllVmIoTunePolicies()= >> File "/usr/share/vdsm/clientIF.py", line 454, in getAllVmIoTunePolic= ies >> 'current=5Fvalues': v.getIoTune()} >> File "/usr/share/vdsm/virt/vm.py", line 2859, in getIoTune >> result =3D self.getIoTuneResponse() >> File "/usr/share/vdsm/virt/vm.py", line 2878, in getIoTuneResponse >> res =3D self.=5Fdom.blockIoTune( >> File "/usr/lib/python2.7/site-packages/vdsm/virt/virdomain.py", line= 47, >> in =5F=5Fgetattr=5F=5F >> % self.vmid) >> NotConnectedError: VM u'755cf168-de65-42ed-b22f-efe9136f7594' was no= t >> started yet or was shut down >> >> On Thu, Feb 22, 2018 at 4:22 PM, fsoyer <fsoyer@systea.fr> wrote: >> >>> Hi, >>> Yes, on 2018-02-16 (vdsm logs) I tried with a VM standing on ginger= >>> (192.168.0.6) migrated (or failed to migrate...) to victor (192.168= .0.5), >>> while the engine.log in the first mail on 2018-02-12 was for VMs st= anding >>> on victor, migrated (or failed to migrate...) to ginger. Symptoms w= ere >>> exactly the same, in both directions, and VMs works like a charm be= fore, >>> and even after (migration "killed" by a poweroff of VMs). >>> Am I the only one experimenting this problem ? >>> >>> >>> Thanks >>> -- >>> >>> Cordialement, >>> >>> *Frank Soyer * >>> >>> >>> >>> Le Jeudi, F=C3=A9vrier 22, 2018 00:45 CET, Maor Lipchuk <mlipchuk@r= edhat.com> >>> a =C3=A9crit: >>> >>> >>> Hi Frank, >>> >>> Sorry about the delay repond. >>> I've been going through the logs you attached, although I could not= find >>> any specific indication why the migration failed because of the dis= k you >>> were mentionning. >>> Does this VM run with both disks on the target host without migrati= on? >>> >>> Regards, >>> Maor >>> >>> >>> On Fri, Feb 16, 2018 at 11:03 AM, fsoyer <fsoyer@systea.fr> wrote: >>>> >>>> Hi Maor, >>>> sorry for the double post, I've change the email adress of my acco= unt and >>>> supposed that I'd need to re-post it. >>>> And thank you for your time. Here are the logs. I added a vdisk to= an >>>> existing VM : it no more migrates, needing to poweroff it after mi= nutes. >>>> Then simply deleting the second disk makes migrate it in exactly 9= s without >>>> problem ! >>>> https://gist.github.com/fgth/4707446331d201eef574ac31b6e89561 >>>> https://gist.github.com/fgth/f8de9c22664aee53722af676bff8719d >>>> >>>> -- >>>> >>>> Cordialement, >>>> >>>> *Frank Soyer * >>>> Le Mercredi, F=C3=A9vrier 14, 2018 11:04 CET, Maor Lipchuk < >>>> mlipchuk@redhat.com> a =C3=A9crit: >>>> >>>> >>>> Hi Frank, >>>> >>>> I already replied on your last email. >>>> Can you provide the VDSM logs from the time of the migration failu= re for >>>> both hosts: >>>> ginger.local.systea.f <http://ginger.local.systea.fr/>r and v >>>> ictor.local.systea.fr >>>> >>>> Thanks, >>>> Maor >>>> >>>> On Wed, Feb 14, 2018 at 11:23 AM, fsoyer <fsoyer@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 cr= eated 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 "mi= grating", >>>>> but no more accessible. Other (small) VMs with only 1 vdisk was m= igrated >>>>> without problem at the same time. >>>>> I saw that a kvm process for the (big) VMs was launched on the so= urce >>>>> AND destination host, but after tens of minutes, the migration an= d 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 th= e >>>>> second vdisk : it migrates now without problem ! >>>>> >>>>> So after another test with a VM with 2 vdisks, I can say that thi= s >>>>> 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.Migrat= eVmToServerCommand] >>>>> (default task-28) [2f712024-5982-46a8-82c8-fd8293da5725] Lock Acq= uired >>>>> to object 'EngineLock:{exclusiveLocks=3D'[3f57e669-5e4c-4d10-85cc= -d573004a099d=3DVM]', >>>>> sharedLocks=3D''}' >>>>> 2018-02-12 16:46:29,955+01 INFO [org.ovirt.engine.core.bll.Migrat= eVmToServerCommand] >>>>> (org.ovirt.thread.pool-6-thread-32) [2f712024-5982-46a8-82c8-fd82= 93da5725] >>>>> Running command: MigrateVmToServerCommand internal: false. Entiti= es >>>>> affected : ID: 3f57e669-5e4c-4d10-85cc-d573004a099d Type: VMActio= n >>>>> group MIGRATE=5FVM 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-fd82= 93da5725] >>>>> START, MigrateVDSCommand( MigrateVDSCommandParameters:{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', >>>>> migrationDowntime=3D'0', autoConverge=3D'true', migrateCompressed= =3D'false', >>>>> consoleAddress=3D'null', maxBandwidth=3D'500', enableGuestEvents=3D= 'true', >>>>> maxIncomingMigrations=3D'2', maxOutgoingMigrations=3D'2', >>>>> convergenceSchedule=3D'[init=3D[{name=3DsetDowntime, params=3D[10= 0]}], >>>>> stalling=3D[{limit=3D1, action=3D{name=3DsetDowntime, params=3D[1= 50]}}, {limit=3D2, >>>>> action=3D{name=3DsetDowntime, params=3D[200]}}, {limit=3D3, >>>>> action=3D{name=3DsetDowntime, params=3D[300]}}, {limit=3D4, >>>>> action=3D{name=3DsetDowntime, params=3D[400]}}, {limit=3D6, >>>>> action=3D{name=3DsetDowntime, params=3D[500]}}, {limit=3D-1, acti= on=3D{name=3Dabort, >>>>> params=3D[]}}]]'}), log id: 14f61ee0 >>>>> 2018-02-12 16:46:30,262+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-t= hread-32) >>>>> [2f712024-5982-46a8-82c8-fd8293da5725] START, >>>>> MigrateBrokerVDSCommand(HostName =3D victor.local.systea.fr, >>>>> MigrateVDSCommandParameters:{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', >>>>> migrationDowntime=3D'0', autoConverge=3D'true', migrateCompressed= =3D'false', >>>>> consoleAddress=3D'null', maxBandwidth=3D'500', enableGuestEvents=3D= 'true', >>>>> maxIncomingMigrations=3D'2', maxOutgoingMigrations=3D'2', >>>>> convergenceSchedule=3D'[init=3D[{name=3DsetDowntime, params=3D[10= 0]}], >>>>> stalling=3D[{limit=3D1, action=3D{name=3DsetDowntime, params=3D[1= 50]}}, {limit=3D2, >>>>> action=3D{name=3DsetDowntime, params=3D[200]}}, {limit=3D3, >>>>> action=3D{name=3DsetDowntime, params=3D[300]}}, {limit=3D4, >>>>> action=3D{name=3DsetDowntime, params=3D[400]}}, {limit=3D6, >>>>> action=3D{name=3DsetDowntime, params=3D[500]}}, {limit=3D-1, acti= on=3D{name=3Dabort, >>>>> params=3D[]}}]]'}), log id: 775cd381 >>>>> 2018-02-12 16:46:30,277+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-t= hread-32) >>>>> [2f712024-5982-46a8-82c8-fd8293da5725] FINISH, MigrateBrokerVDSCo= mmand, >>>>> 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-fd82= 93da5725] >>>>> FINISH, MigrateVDSCommand, return: MigratingFrom, log id: 14f61ee= 0 >>>>> 2018-02-12 16:46:30,301+01 INFO [org.ovirt.engine.core.dal.db >>>>> broker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-= 6-thread-32) >>>>> [2f712024-5982-46a8-82c8-fd8293da5725] EVENT=5FID: >>>>> VM=5FMIGRATION=5FSTART(62), Correlation ID: 2f712024-5982-46a8-82= c8-fd8293da5725, >>>>> Job ID: 4bd19aa9-cc99-4d02-884e-5a1e857a7738, Call Stack: null, C= ustom >>>>> ID: null, Custom Event ID: -1, Message: Migration started (VM: >>>>> Oracle=5FSECONDARY, 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.vdsbro >>>>> ker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler9) [54a6= 5b66] >>>>> START, FullListVDSCommand(HostName =3D victor.local.systea.fr, >>>>> FullListVDSCommandParameters:{runAsync=3D'true', >>>>> hostId=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1', >>>>> vmIds=3D'[3f57e669-5e4c-4d10-85cc-d573004a099d]'}), log id: 54b4b= 435 >>>>> 2018-02-12 16:46:31,147+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler9) [54a6= 5b66] >>>>> FINISH, FullListVDSCommand, return: [{acpiEnable=3Dtrue, >>>>> emulatedMachine=3Dpc-i440fx-rhel7.3.0, tabletEnable=3Dtrue, pid=3D= 1493, >>>>> guestDiskMapping=3D{0QEMU=5FQEMU=5FHARDDISK=5Fd890fa68-fba4-4f49-= 9=3D{name=3D/dev/sda}, >>>>> QEMU=5FDVD-ROM=5FQM00003=3D{name=3D/dev/sr0}}, transparentHugePag= es=3Dtrue, >>>>> timeOffset=3D0, cpuType=3DNehalem, smp=3D2, pauseCode=3DNOERR, >>>>> guestNumaNodes=3D[Ljava.lang.Object;@1d9042cd, smartcardEnable=3D= false, >>>>> custom=3D{device=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F8= 7 >>>>> 9c93ab-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', specParams=3D'[]', address=3D'= {bus=3D0, >>>>> controller=3D0, type=3Dvirtio-serial, port=3D1}', managed=3D'fals= e', >>>>> plugged=3D'true', readOnly=3D'false', deviceAlias=3D'channel0', >>>>> customProperties=3D'[]', snapshotId=3D'null', logicalName=3D'null= ', >>>>> hostDevice=3D'null'}, device=5Ffbddd528-7d93-49c6-a286 >>>>> -180e021cb274device=5F879c93ab-4df1-435c-af02-565039fcc254devi >>>>> ce=5F8945f61a-abbe-4156-8485-a4aa6f1908dbdevice=5F017b5e59-01c4- >>>>> 4aac-bf0c-b5d9557284d6=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'= 0 >>>>> 17b5e59-01c4-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', customProperties=3D'[= ]', >>>>> snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'null'}, >>>>> device=5Ffbddd528-7d93-49c6-a286-180e021cb274=3DVmDevice:{id=3D'V= m >>>>> DeviceId:{deviceId=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=3D0x0000, type=3Dpci, function=3D0x1}', manage= d=3D'false', >>>>> plugged=3D'true', readOnly=3D'false', deviceAlias=3D'ide', custom= Properties=3D'[]', >>>>> snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'null'}, >>>>> device=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F879c93ab-4 >>>>> df1-435c-af02-565039fcc254device=5F8945f61a-abbe-4156-8485-a4a >>>>> a6f1908db=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'[]', address=3D'= {bus=3D0, >>>>> controller=3D0, type=3Dvirtio-serial, port=3D2}', managed=3D'fals= e', >>>>> plugged=3D'true', readOnly=3D'false', deviceAlias=3D'channel1', >>>>> customProperties=3D'[]', snapshotId=3D'null', logicalName=3D'null= ', >>>>> hostDevice=3D'null'}}, vmType=3Dkvm, memSize=3D8192, smpCoresPerS= ocket=3D1, >>>>> vmName=3DOracle=5FSECONDARY, nice=3D0, status=3DMigration Source,= maxMemSize=3D32768, >>>>> bootMenuEnable=3Dfalse, vmId=3D3f57e669-5e4c-4d10-85cc-d573004a09= 9d, >>>>> numOfIoThreads=3D2, smpThreadsPerCore=3D1, memGuaranteedSize=3D81= 92, >>>>> 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:= 54b4b435 >>>>> 2018-02-12 16:46:31,150+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.monitoring.VmsStatisticsFetcher] (DefaultQuartzScheduler1) >>>>> [27fac647] Fetched 3 VMs from VDS 'd569c2dd-8f30-4878-8aea-858db2= 85cf69' >>>>> 2018-02-12 16:46:31,151+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler9) >>>>> [54a65b66] Received a vnc Device without an address when processi= ng VM >>>>> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping device: >>>>> {device=3Dvnc, specParams=3D{displayNetwork=3Dovirtmgmt, keyMap=3D= fr, >>>>> displayIp=3D192.168.0.6}, type=3Dgraphics, deviceId=3D813957b1-44= 6a-4e88-9e40-9fe76d2c442d, >>>>> port=3D5901} >>>>> 2018-02-12 16:46:31,151+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler9) >>>>> [54a65b66] Received a lease Device without an address when proces= sing 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=3D= 6291456, >>>>> device=3Dlease, path=3D/rhev/data-center/mnt/glusterSD/192.168.0.= 6: >>>>> =5FDATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom=5Fmd/xleases, = type=3Dlease} >>>>> 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=5FSECONDARY) >>>>> 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 migratio= n 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-d573004= a099d' >>>>> 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.vdsbro >>>>> ker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-11) [] ST= ART, >>>>> DestroyVDSCommand(HostName =3D victor.local.systea.fr, >>>>> DestroyVmVDSCommandParameters:{runAsync=3D'true', >>>>> hostId=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1', >>>>> vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d', force=3D'false', >>>>> secondsToWait=3D'0', gracefully=3D'false', reason=3D'', ignoreNoV= m=3D'true'}), log >>>>> id: 560eca57 >>>>> 2018-02-12 16:46:41,650+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-11) [] FI= NISH, >>>>> 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-d573004= a099d'(Oracle=5FSECONDARY) >>>>> 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=5FSECONDARY) >>>>> to Host 'd569c2dd-8f30-4878-8aea-858db285cf69'. Setting VM to sta= tus >>>>> '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-d573004a= 099d'(Oracle=5FSECONDARY) >>>>> moved from 'MigratingTo' --> 'Up' >>>>> 2018-02-12 16:46:42,169+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.vdsbroker.MigrateStatusVDSCommand] (ForkJoinPool-1-worker-4) = [] >>>>> START, MigrateStatusVDSCommand(HostName =3D ginger.local.systea.f= r, >>>>> MigrateStatusVDSCommandParameters:{runAsync=3D'true', >>>>> hostId=3D'd569c2dd-8f30-4878-8aea-858db285cf69', >>>>> vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}), log id: 7a25c281= >>>>> 2018-02-12 16:46:42,174+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.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.db >>>>> broker.auditloghandling.AuditLogDirector] (ForkJoinPool-1-worker-= 4) [] >>>>> EVENT=5FID: VM=5FMIGRATION=5FDONE(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=5FSECONDARY, 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.Migrat= eVmToServerCommand] >>>>> (ForkJoinPool-1-worker-4) [] Lock freed to object >>>>> 'EngineLock:{exclusiveLocks=3D'[3f57e669-5e4c-4d10-85cc-d573004a0= 99d=3DVM]', >>>>> sharedLocks=3D''}' >>>>> 2018-02-12 16:46:42,203+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.vdsbroker.FullListVDSCommand] (ForkJoinPool-1-worker-4) [] ST= ART, >>>>> FullListVDSCommand(HostName =3D ginger.local.systea.fr, >>>>> FullListVDSCommandParameters:{runAsync=3D'true', >>>>> hostId=3D'd569c2dd-8f30-4878-8aea-858db285cf69', >>>>> vmIds=3D'[3f57e669-5e4c-4d10-85cc-d573004a099d]'}), log id: 7cc65= 298 >>>>> 2018-02-12 16:46:42,254+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.vdsbroker.FullListVDSCommand] (ForkJoinPool-1-worker-4) [] FI= NISH, >>>>> FullListVDSCommand, return: [{acpiEnable=3Dtrue, >>>>> emulatedMachine=3Dpc-i440fx-rhel7.3.0, afterMigrationStatus=3D, >>>>> tabletEnable=3Dtrue, pid=3D18748, guestDiskMapping=3D{}, >>>>> transparentHugePages=3Dtrue, timeOffset=3D0, cpuType=3DNehalem, s= mp=3D2, >>>>> guestNumaNodes=3D[Ljava.lang.Object;@760085fd, >>>>> custom=3D{device=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F8= 7 >>>>> 9c93ab-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', specParams=3D'[]', address=3D'= {bus=3D0, >>>>> controller=3D0, type=3Dvirtio-serial, port=3D1}', managed=3D'fals= e', >>>>> plugged=3D'true', readOnly=3D'false', deviceAlias=3D'channel0', >>>>> customProperties=3D'[]', snapshotId=3D'null', logicalName=3D'null= ', >>>>> hostDevice=3D'null'}, device=5Ffbddd528-7d93-49c6-a286 >>>>> -180e021cb274device=5F879c93ab-4df1-435c-af02-565039fcc254devi >>>>> ce=5F8945f61a-abbe-4156-8485-a4aa6f1908dbdevice=5F017b5e59-01c4- >>>>> 4aac-bf0c-b5d9557284d6=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'= 0 >>>>> 17b5e59-01c4-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', customProperties=3D'[= ]', >>>>> snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'null'}, >>>>> device=5Ffbddd528-7d93-49c6-a286-180e021cb274=3DVmDevice:{id=3D'V= m >>>>> DeviceId:{deviceId=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=3D0x0000, type=3Dpci, function=3D0x1}', manage= d=3D'false', >>>>> plugged=3D'true', readOnly=3D'false', deviceAlias=3D'ide', custom= Properties=3D'[]', >>>>> snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'null'}, >>>>> device=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F879c93ab-4 >>>>> df1-435c-af02-565039fcc254device=5F8945f61a-abbe-4156-8485-a4a >>>>> a6f1908db=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'[]', address=3D'= {bus=3D0, >>>>> controller=3D0, type=3Dvirtio-serial, port=3D2}', managed=3D'fals= e', >>>>> plugged=3D'true', readOnly=3D'false', deviceAlias=3D'channel1', >>>>> customProperties=3D'[]', snapshotId=3D'null', logicalName=3D'null= ', >>>>> hostDevice=3D'null'}}, vmType=3Dkvm, memSize=3D8192, smpCoresPerS= ocket=3D1, >>>>> vmName=3DOracle=5FSECONDARY, nice=3D0, status=3DUp, maxMemSize=3D= 32768, >>>>> bootMenuEnable=3Dfalse, vmId=3D3f57e669-5e4c-4d10-85cc-d573004a09= 9d, >>>>> numOfIoThreads=3D2, smpThreadsPerCore=3D1, smartcardEnable=3Dfals= e, >>>>> maxMemSlots=3D16, kvmEnable=3Dtrue, pitReinjection=3Dfalse, >>>>> displayNetwork=3Dovirtmgmt, devices=3D[Ljava.lang.Object;@2e4d3dd= 3, >>>>> memGuaranteedSize=3D8192, maxVCpus=3D16, clientIp=3D, statusTime=3D= 4304259600 >>>>> <(430)%20425-9600>, display=3Dvnc}], log id: 7cc65298 >>>>> 2018-02-12 16:46:42,257+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.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=3Dvnc, specParams=3D{displayNetwork=3Dovirtmgmt, keyMap=3D= fr, >>>>> displayIp=3D192.168.0.5}, type=3Dgraphics, deviceId=3D813957b1-44= 6a-4e88-9e40-9fe76d2c442d, >>>>> port=3D5901} >>>>> 2018-02-12 16:46:42,257+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.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=3D= 6291456, >>>>> device=3Dlease, path=3D/rhev/data-center/mnt/glusterSD/192.168.0.= 6: >>>>> =5FDATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom=5Fmd/xleases, = type=3Dlease} >>>>> 2018-02-12 16:46:46,260+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler5) [7fcb= 200a] >>>>> FINISH, FullListVDSCommand, return: [{acpiEnable=3Dtrue, >>>>> emulatedMachine=3Dpc-i440fx-rhel7.3.0, afterMigrationStatus=3D, >>>>> tabletEnable=3Dtrue, pid=3D18748, guestDiskMapping=3D{0QEMU=5FQEM= U=5FH >>>>> ARDDISK=5Fd890fa68-fba4-4f49-9=3D{name=3D/dev/sda}, >>>>> QEMU=5FDVD-ROM=5FQM00003=3D{name=3D/dev/sr0}}, transparentHugePag= es=3Dtrue, >>>>> timeOffset=3D0, cpuType=3DNehalem, smp=3D2, guestNumaNodes=3D[Lja= va.lang.Obj >>>>> ect;@77951faf, custom=3D{device=5Ffbddd528-7d93-4 >>>>> 9c6-a286-180e021cb274device=5F879c93ab-4df1-435c-af02-565039fc >>>>> c254=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', specParams=3D'[]', address=3D'= {bus=3D0, >>>>> controller=3D0, type=3Dvirtio-serial, port=3D1}', managed=3D'fals= e', >>>>> plugged=3D'true', readOnly=3D'false', deviceAlias=3D'channel0', >>>>> customProperties=3D'[]', snapshotId=3D'null', logicalName=3D'null= ', >>>>> hostDevice=3D'null'}, device=5Ffbddd528-7d93-49c6-a286 >>>>> -180e021cb274device=5F879c93ab-4df1-435c-af02-565039fcc254devi >>>>> ce=5F8945f61a-abbe-4156-8485-a4aa6f1908dbdevice=5F017b5e59-01c4- >>>>> 4aac-bf0c-b5d9557284d6=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'= 0 >>>>> 17b5e59-01c4-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', customProperties=3D'[= ]', >>>>> snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'null'}, >>>>> device=5Ffbddd528-7d93-49c6-a286-180e021cb274=3DVmDevice:{id=3D'V= m >>>>> DeviceId:{deviceId=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=3D0x0000, type=3Dpci, function=3D0x1}', manage= d=3D'false', >>>>> plugged=3D'true', readOnly=3D'false', deviceAlias=3D'ide', custom= Properties=3D'[]', >>>>> snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'null'}, >>>>> device=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F879c93ab-4 >>>>> df1-435c-af02-565039fcc254device=5F8945f61a-abbe-4156-8485-a4a >>>>> a6f1908db=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'[]', address=3D'= {bus=3D0, >>>>> controller=3D0, type=3Dvirtio-serial, port=3D2}', managed=3D'fals= e', >>>>> plugged=3D'true', readOnly=3D'false', deviceAlias=3D'channel1', >>>>> customProperties=3D'[]', snapshotId=3D'null', logicalName=3D'null= ', >>>>> hostDevice=3D'null'}}, vmType=3Dkvm, memSize=3D8192, smpCoresPerS= ocket=3D1, >>>>> vmName=3DOracle=5FSECONDARY, nice=3D0, status=3DUp, maxMemSize=3D= 32768, >>>>> bootMenuEnable=3Dfalse, vmId=3D3f57e669-5e4c-4d10-85cc-d573004a09= 9d, >>>>> numOfIoThreads=3D2, smpThreadsPerCore=3D1, smartcardEnable=3Dfals= e, >>>>> maxMemSlots=3D16, kvmEnable=3Dtrue, pitReinjection=3Dfalse, >>>>> displayNetwork=3Dovirtmgmt, devices=3D[Ljava.lang.Object;@286410f= d, >>>>> memGuaranteedSize=3D8192, maxVCpus=3D16, clientIp=3D, statusTime=3D= 4304263620 >>>>> <(430)%20426-3620>, display=3Dvnc}], log id: 58cdef4c >>>>> 2018-02-12 16:46:46,267+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler5) >>>>> [7fcb200a] Received a vnc Device without an address when processi= ng VM >>>>> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping device: >>>>> {device=3Dvnc, specParams=3D{displayNetwork=3Dovirtmgmt, keyMap=3D= fr, >>>>> displayIp=3D192.168.0.5}, type=3Dgraphics, deviceId=3D813957b1-44= 6a-4e88-9e40-9fe76d2c442d, >>>>> port=3D5901} >>>>> 2018-02-12 16:46:46,268+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler5) >>>>> [7fcb200a] Received a lease Device without an address when proces= sing 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=3D= 6291456, >>>>> device=3Dlease, path=3D/rhev/data-center/mnt/glusterSD/192.168.0.= 6: >>>>> =5FDATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom=5Fmd/xleases, = type=3Dlease} >>>>> >>>>> >>>>> >>>>> >>>>> For the VM with 2 vdisks we see : >>>>> >>>>> 2018-02-12 16:49:06,112+01 INFO [org.ovirt.engine.core.bll.Migrat= eVmToServerCommand] >>>>> (default task-50) [92b5af33-cb87-4142-b8fe-8b838dd7458e] Lock Acq= uired >>>>> to object 'EngineLock:{exclusiveLocks=3D'[f7d4ec12-627a-4b83-b59e= -886400d55474=3DVM]', >>>>> sharedLocks=3D''}' >>>>> 2018-02-12 16:49:06,407+01 INFO [org.ovirt.engine.core.bll.Migrat= eVmToServerCommand] >>>>> (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4142-b8fe-8b83= 8dd7458e] >>>>> Running command: MigrateVmToServerCommand internal: false. Entiti= es >>>>> affected : ID: f7d4ec12-627a-4b83-b59e-886400d55474 Type: VMActio= n >>>>> group MIGRATE=5FVM 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-8b83= 8dd7458e] >>>>> START, MigrateVDSCommand( MigrateVDSCommandParameters:{runAsync=3D= 'true', >>>>> hostId=3D'd569c2dd-8f30-4878-8aea-858db285cf69', >>>>> 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'false', >>>>> consoleAddress=3D'null', maxBandwidth=3D'500', enableGuestEvents=3D= 'true', >>>>> maxIncomingMigrations=3D'2', maxOutgoingMigrations=3D'2', >>>>> convergenceSchedule=3D'[init=3D[{name=3DsetDowntime, params=3D[10= 0]}], >>>>> stalling=3D[{limit=3D1, action=3D{name=3DsetDowntime, params=3D[1= 50]}}, {limit=3D2, >>>>> action=3D{name=3DsetDowntime, params=3D[200]}}, {limit=3D3, >>>>> action=3D{name=3DsetDowntime, params=3D[300]}}, {limit=3D4, >>>>> action=3D{name=3DsetDowntime, params=3D[400]}}, {limit=3D6, >>>>> action=3D{name=3DsetDowntime, params=3D[500]}}, {limit=3D-1, acti= on=3D{name=3Dabort, >>>>> params=3D[]}}]]'}), log id: 3702a9e0 >>>>> 2018-02-12 16:49:06,713+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-t= hread-49) >>>>> [92b5af33-cb87-4142-b8fe-8b838dd7458e] START, >>>>> MigrateBrokerVDSCommand(HostName =3D ginger.local.systea.fr, >>>>> MigrateVDSCommandParameters:{runAsync=3D'true', >>>>> hostId=3D'd569c2dd-8f30-4878-8aea-858db285cf69', >>>>> 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'false', >>>>> consoleAddress=3D'null', maxBandwidth=3D'500', enableGuestEvents=3D= 'true', >>>>> maxIncomingMigrations=3D'2', maxOutgoingMigrations=3D'2', >>>>> convergenceSchedule=3D'[init=3D[{name=3DsetDowntime, params=3D[10= 0]}], >>>>> stalling=3D[{limit=3D1, action=3D{name=3DsetDowntime, params=3D[1= 50]}}, {limit=3D2, >>>>> action=3D{name=3DsetDowntime, params=3D[200]}}, {limit=3D3, >>>>> action=3D{name=3DsetDowntime, params=3D[300]}}, {limit=3D4, >>>>> action=3D{name=3DsetDowntime, params=3D[400]}}, {limit=3D6, >>>>> action=3D{name=3DsetDowntime, params=3D[500]}}, {limit=3D-1, acti= on=3D{name=3Dabort, >>>>> params=3D[]}}]]'}), log id: 1840069c >>>>> 2018-02-12 16:49:06,724+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-t= hread-49) >>>>> [92b5af33-cb87-4142-b8fe-8b838dd7458e] FINISH, MigrateBrokerVDSCo= mmand, >>>>> 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-8b83= 8dd7458e] >>>>> FINISH, MigrateVDSCommand, return: MigratingFrom, log id: 3702a9e= 0 >>>>> 2018-02-12 16:49:06,753+01 INFO [org.ovirt.engine.core.dal.db >>>>> broker.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-b8= fe-8b838dd7458e, >>>>> Job ID: f4f54054-f7c8-4481-8eda-d5a15c383061, Call Stack: null, C= ustom >>>>> 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). >>>>> ... >>>>> 2018-02-12 16:49:16,453+01 INFO [org.ovirt.engine.core.vdsbro >>>>> ker.monitoring.VmsStatisticsFetcher] (DefaultQuartzScheduler4) >>>>> [162a5bc3] Fetched 2 VMs from VDS 'ce3938b1-b23f-4d22-840a-f17d7c= d87bb1' >>>>> 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=5FPRIMARY) >>>>> 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 migratio= n 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=5FPRIMARY) >>>>> 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 migratio= n is >>>>> done >>>>> >>>>> >>>>> >>>>> and so on, last lines repeated indefinitly for hours since we pow= eroff >>>>> 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 * >>>>> >>>>> =5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F= =5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F= =5F >>>>> Users mailing list >>>>> Users@ovirt.org >>>>> http://lists.ovirt.org/mailman/listinfo/users =C2=A0 =C2=A0 ------=_=-_OpenGroupware_org_NGMime-18019-1519921630.582362-42------ Content-Type: text/html; charset=utf-8 Content-Transfer-Encoding: quoted-printable Content-Length: 51348 <html>I Milan,<br />I tried to activate the debug mode, but the restart= of libvirt crashed something on the host : it was no more possible to = start any vm on it, and migration to it just never started. So I decide= d to restart it, and to be sure, I've restarted all the hosts.<br />And= ... now the migration of all VMs, simple or multi-disks, works ?!? So, = there was probably something hidden that was resetted or repaired by th= e global restart !.... In french, we call that "tomber en marche" ;)<br= /><br />So : solved. Thank you for the wasted time !<br /><br />--<br = /><style type=3D"text/css">.Text1 { 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><br />Mob. 06 72 28 38 53 - Fix. 05 49 50 52 34</p><br /><br />Le = Lundi, F=C3=A9vrier 26, 2018 12:59 CET, Milan Zamazal <mzamazal@redh= at.com> a =C3=A9crit:<br /> <blockquote type=3D"cite" cite=3D"8= 78tbg9d1y.fsf@redhat.com">"fsoyer" <fsoyer@systea.fr> writes:<br = /><br />> I don't beleive that this is relatd to a host, tests have = been done from victor<br />> source to ginger dest and ginger to vic= tor. I don't see problems on storage<br />> (gluster 3.12 native man= aged by ovirt), when VMs with a uniq disk from 20 to<br />> 250G mig= rate without error in some seconds and with no downtime.<br /><br />The= host itself may be fine, but libvirt/QEMU running there may expose<br = />problems, perhaps just for some VMs. According to your logs something= <br />is not behaving as expected on the source host during the faulty<= br />migration.<br /><br />> How ca I enable this libvirt debug mode= ?<br /><br />Set the following options in /etc/libvirt/libvirtd.conf (= look for<br />examples in comments there)<br /><br />- log=5Flevel=3D1<= br />- log=5Foutputs=3D"1:file:/var/log/libvirt/libvirtd.log"<br /><br = />and restart libvirt. Then /var/log/libvirt/libvirtd.log should contai= n<br />the log. It will be huge, so I suggest to enable it only for the= time<br />of reproducing the problem.<br /><br />> --<br />><br = />> Cordialement,<br />><br />> Frank Soyer<br />><br />>= ; <br />><br />> Le Vendredi, F=C3=A9vrier 23, 2018 09:56 C= ET, Milan Zamazal <mzamazal@redhat.com> a =C3=A9crit:<br />> &= nbsp;Maor Lipchuk <mlipchuk@redhat.com> writes:<br />><br />&g= t;> I encountered a bug (see [1]) which contains the same error ment= ioned in<br />>> your VDSM logs (see [2]), but I doubt it is rela= ted.<br />><br />> Indeed, it's not related.<br />><br />> = The error in vdsm=5Fvictor.log just means that the info gathering call<= br />> tries to access libvirt domain before the incoming migration = is<br />> completed. It's ugly but harmless.<br />><br />>>= Milan, maybe you have any advice to troubleshoot the issue? Will the<b= r />>> libvirt/qemu logs can help?<br />><br />> It seems t= here is something wrong on (at least) the source host. There<br />> = are no migration progress messages in the vdsm=5Fginger.log and there a= re<br />> warnings about stale stat samples. That looks like problem= s with<br />> calling libvirt =E2=80=93 slow and/or stuck calls, may= be due to storage<br />> problems. The possibly faulty second disk c= ould cause that.<br />><br />> libvirt debug logs could tell us w= hether that is indeed the problem and<br />> whether it is caused by= storage or something else.<br />><br />>> I would suggest to = open a bug on that issue so we can track it more<br />>> properly= .<br />>><br />>> Regards,<br />>> Maor<br />>>= <br />>><br />>> [1]<br />>> https://bugzilla.redhat.= com/show=5Fbug.cgi?id=3D1486543 - Migration leads to<br />>> VM r= unning on 2 Hosts<br />>><br />>> [2]<br />>> 2018-02= -16 09:43:35,236+0100 ERROR (jsonrpc/7) [jsonrpc.JsonRpcServer]<br />&g= t;> Internal server error (=5F=5Finit=5F=5F:577)<br />>> Trace= back (most recent call last):<br />>> File "/usr/lib/python2.7/si= te-packages/yajsonrpc/=5F=5Finit=5F=5F.py", line 572,<br />>> in = =5Fhandle=5Frequest<br />>> res =3D method(**params)<br />>>= ; File "/usr/lib/python2.7/site-packages/vdsm/rpc/Bridge.py", line 198,= in<br />>> =5FdynamicMethod<br />>> result =3D fn(*methodA= rgs)<br />>> File "/usr/share/vdsm/API.py", line 1454, in getAllV= mIoTunePolicies<br />>> io=5Ftune=5Fpolicies=5Fdict =3D self.=5Fc= if.getAllVmIoTunePolicies()<br />>> File "/usr/share/vdsm/clientI= F.py", line 454, in getAllVmIoTunePolicies<br />>> 'current=5Fval= ues': v.getIoTune()}<br />>> File "/usr/share/vdsm/virt/vm.py", l= ine 2859, in getIoTune<br />>> result =3D self.getIoTuneResponse(= )<br />>> File "/usr/share/vdsm/virt/vm.py", line 2878, in getIoT= uneResponse<br />>> res =3D self.=5Fdom.blockIoTune(<br />>>= ; File "/usr/lib/python2.7/site-packages/vdsm/virt/virdomain.py", line = 47,<br />>> in =5F=5Fgetattr=5F=5F<br />>> % self.vmid)<br = />>> NotConnectedError: VM u'755cf168-de65-42ed-b22f-efe9136f7594= ' was not<br />>> started yet or was shut down<br />>><br /= >>> On Thu, Feb 22, 2018 at 4:22 PM, fsoyer <fsoyer@systea.fr&= gt; wrote:<br />>><br />>>> Hi,<br />>>> Yes, o= n 2018-02-16 (vdsm logs) I tried with a VM standing on ginger<br />>= >> (192.168.0.6) migrated (or failed to migrate...) to victor (19= 2.168.0.5),<br />>>> while the engine.log in the first mail on= 2018-02-12 was for VMs standing<br />>>> on victor, migrated = (or failed to migrate...) to ginger. Symptoms were<br />>>> ex= actly the same, in both directions, and VMs works like a charm before,<= br />>>> and even after (migration "killed" by a poweroff of V= Ms).<br />>>> Am I the only one experimenting this problem ?<b= r />>>><br />>>><br />>>> Thanks<br />>&g= t;> --<br />>>><br />>>> Cordialement,<br />>&g= t;><br />>>> *Frank Soyer *<br />>>><br />>>= ><br />>>><br />>>> Le Jeudi, F=C3=A9vrier 22, 201= 8 00:45 CET, Maor Lipchuk <mlipchuk@redhat.com><br />>>>= a =C3=A9crit:<br />>>><br />>>><br />>>> Hi= Frank,<br />>>><br />>>> Sorry about the delay repon= d.<br />>>> I've been going through the logs you attached, alt= hough I could not find<br />>>> any specific indication why th= e migration failed because of the disk you<br />>>> were menti= onning.<br />>>> Does this VM run with both disks on the targe= t host without migration?<br />>>><br />>>> Regards,<= br />>>> Maor<br />>>><br />>>><br />>>= ;> On Fri, Feb 16, 2018 at 11:03 AM, fsoyer <fsoyer@systea.fr>= wrote:<br />>>>><br />>>>> Hi Maor,<br />>&= gt;>> sorry for the double post, I've change the email adress of = my account and<br />>>>> supposed that I'd need to re-post = it.<br />>>>> And thank you for your time. Here are the log= s. I added a vdisk to an<br />>>>> existing VM : it no more= migrates, needing to poweroff it after minutes.<br />>>>> = Then simply deleting the second disk makes migrate it in exactly 9s wit= hout<br />>>>> problem !<br />>>>> https://gist= .github.com/fgth/4707446331d201eef574ac31b6e89561<br />>>>>= https://gist.github.com/fgth/f8de9c22664aee53722af676bff8719d<br />>= ;>>><br />>>>> --<br />>>>><br />>&= gt;>> Cordialement,<br />>>>><br />>>>> *= Frank Soyer *<br />>>>> Le Mercredi, F=C3=A9vrier 14, 2018 = 11:04 CET, Maor Lipchuk <<br />>>>> mlipchuk@redhat.com&= gt; a =C3=A9crit:<br />>>>><br />>>>><br />>= >>> Hi Frank,<br />>>>><br />>>>> I al= ready replied on your last email.<br />>>>> Can you provide= the VDSM logs from the time of the migration failure for<br />>>= >> both hosts:<br />>>>> ginger.local.systea.f <ht= tp://ginger.local.systea.fr/>r and v<br />>>>> ictor.loc= al.systea.fr<br />>>>><br />>>>> Thanks,<br />&= gt;>>> Maor<br />>>>><br />>>>> On Wed= , Feb 14, 2018 at 11:23 AM, fsoyer <fsoyer@systea.fr> wrote:<br /= >>>>>><br />>>>>> Hi all,<br />>>&g= t;>> I discovered yesterday a problem when migrating VM with more= than one<br />>>>>> vdisk.<br />>>>>> On= our test servers (oVirt4.1, shared storage with Gluster), I created 2<= br />>>>>> VMs needed for a test, from a template with a= 20G vdisk. On this VMs I<br />>>>>> added a 100G vdisk = (for this tests I didn't want to waste time to extend<br />>>>= >> the existing vdisks... But I lost time finally...). The VMs wi= th the 2<br />>>>>> vdisks works well.<br />>>>= >> Now I saw some updates waiting on the host. I tried to put it = in<br />>>>>> maintenance... But it stopped on the two V= M. They were marked "migrating",<br />>>>>> but no more = accessible. Other (small) VMs with only 1 vdisk was migrated<br />>&= gt;>>> without problem at the same time.<br />>>>>= > I saw that a kvm process for the (big) VMs was launched on the sou= rce<br />>>>>> AND destination host, but after tens of m= inutes, the migration and the VMs<br />>>>>> was always = freezed. I tried to cancel the migration for the VMs : failed.<br />>= ;>>>> The only way to stop it was to poweroff the VMs : the= kvm process died on<br />>>>>> the 2 hosts and the GUI = alerted on a failed migration.<br />>>>>> In doubt, I tr= ied to delete the second vdisk on one of this VMs : it<br />>>>= ;>> migrates then without error ! And no access problem.<br />>= ;>>>> I tried to extend the first vdisk of the second VM, t= he delete the<br />>>>>> second vdisk : it migrates now = without problem !<br />>>>>><br />>>>>> S= o after another test with a VM with 2 vdisks, I can say that this<br />= >>>>> blocked the migration process :(<br />>>>= >><br />>>>>> In engine.log, for a VMs with 1 vdis= k migrating well, we see :<br />>>>>><br />>>>&= gt;> 2018-02-12 16:46:29,705+01 INFO [org.ovirt.engine.core.bll.Migr= ateVmToServerCommand]<br />>>>>> (default task-28) [2f71= 2024-5982-46a8-82c8-fd8293da5725] Lock Acquired<br />>>>>&g= t; to object 'EngineLock:{exclusiveLocks=3D'[3f57e669-5e4c-4d10-85cc-d5= 73004a099d=3DVM]',<br />>>>>> sharedLocks=3D''}'<br />&g= t;>>>> 2018-02-12 16:46:29,955+01 INFO [org.ovirt.engine.co= re.bll.MigrateVmToServerCommand]<br />>>>>> (org.ovirt.t= hread.pool-6-thread-32) [2f712024-5982-46a8-82c8-fd8293da5725]<br />>= ;>>>> Running command: MigrateVmToServerCommand internal: f= alse. Entities<br />>>>>> affected : ID: 3f57e669-5e4c-4= d10-85cc-d573004a099d Type: VMAction<br />>>>>> group MI= GRATE=5FVM with role type USER<br />>>>>> 2018-02-12 16:= 46:30,261+01 INFO [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand]<b= r />>>>>> (org.ovirt.thread.pool-6-thread-32) [2f712024-= 5982-46a8-82c8-fd8293da5725]<br />>>>>> START, MigrateVD= SCommand( MigrateVDSCommandParameters:{runAsync=3D'true',<br />>>= >>> hostId=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1',<br />>= >>>> vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d', srcHost= =3D'192.168.0.6',<br />>>>>> dstVdsId=3D'd569c2dd-8f30-4= 878-8aea-858db285cf69', dstHost=3D'<br />>>>>> 192.168.0= .5:54321', migrationMethod=3D'ONLINE', tunnelMigration=3D'false',<br />= >>>>> migrationDowntime=3D'0', autoConverge=3D'true', mi= grateCompressed=3D'false',<br />>>>>> consoleAddress=3D'= null', maxBandwidth=3D'500', enableGuestEvents=3D'true',<br />>>&= gt;>> maxIncomingMigrations=3D'2', maxOutgoingMigrations=3D'2',<b= r />>>>>> convergenceSchedule=3D'[init=3D[{name=3DsetDow= ntime, params=3D[100]}],<br />>>>>> stalling=3D[{limit=3D= 1, action=3D{name=3DsetDowntime, params=3D[150]}}, {limit=3D2,<br />>= ;>>>> action=3D{name=3DsetDowntime, params=3D[200]}}, {limi= t=3D3,<br />>>>>> action=3D{name=3DsetDowntime, params=3D= [300]}}, {limit=3D4,<br />>>>>> action=3D{name=3DsetDown= time, params=3D[400]}}, {limit=3D6,<br />>>>>> action=3D= {name=3DsetDowntime, params=3D[500]}}, {limit=3D-1, action=3D{name=3Dab= ort,<br />>>>>> params=3D[]}}]]'}), log id: 14f61ee0<br = />>>>>> 2018-02-12 16:46:30,262+01 INFO [org.ovirt.engin= e.core.vdsbro<br />>>>>> ker.vdsbroker.MigrateBrokerVDSC= ommand] (org.ovirt.thread.pool-6-thread-32)<br />>>>>> [= 2f712024-5982-46a8-82c8-fd8293da5725] START,<br />>>>>> = MigrateBrokerVDSCommand(HostName =3D victor.local.systea.fr,<br />>&= gt;>>> MigrateVDSCommandParameters:{runAsync=3D'true',<br />&g= t;>>>> hostId=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1',<br = />>>>>> vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d', s= rcHost=3D'192.168.0.6',<br />>>>>> dstVdsId=3D'd569c2dd-= 8f30-4878-8aea-858db285cf69', dstHost=3D'<br />>>>>> 192= .168.0.5:54321', migrationMethod=3D'ONLINE', tunnelMigration=3D'false',= <br />>>>>> migrationDowntime=3D'0', autoConverge=3D'tru= e', migrateCompressed=3D'false',<br />>>>>> consoleAddre= ss=3D'null', maxBandwidth=3D'500', enableGuestEvents=3D'true',<br />>= ;>>>> maxIncomingMigrations=3D'2', maxOutgoingMigrations=3D= '2',<br />>>>>> convergenceSchedule=3D'[init=3D[{name=3D= setDowntime, params=3D[100]}],<br />>>>>> stalling=3D[{l= imit=3D1, action=3D{name=3DsetDowntime, params=3D[150]}}, {limit=3D2,<b= r />>>>>> action=3D{name=3DsetDowntime, params=3D[200]}}= , {limit=3D3,<br />>>>>> action=3D{name=3DsetDowntime, p= arams=3D[300]}}, {limit=3D4,<br />>>>>> action=3D{name=3D= setDowntime, params=3D[400]}}, {limit=3D6,<br />>>>>> ac= tion=3D{name=3DsetDowntime, params=3D[500]}}, {limit=3D-1, action=3D{na= me=3Dabort,<br />>>>>> params=3D[]}}]]'}), log id: 775cd= 381<br />>>>>> 2018-02-12 16:46:30,277+01 INFO [org.ovir= t.engine.core.vdsbro<br />>>>>> ker.vdsbroker.MigrateBro= kerVDSCommand] (org.ovirt.thread.pool-6-thread-32)<br />>>>>= ;> [2f712024-5982-46a8-82c8-fd8293da5725] FINISH, MigrateBrokerVDSCo= mmand,<br />>>>>> log id: 775cd381<br />>>>>= > 2018-02-12 16:46:30,285+01 INFO [org.ovirt.engine.core.vdsbroker.M= igrateVDSCommand]<br />>>>>> (org.ovirt.thread.pool-6-th= read-32) [2f712024-5982-46a8-82c8-fd8293da5725]<br />>>>>&g= t; FINISH, MigrateVDSCommand, return: MigratingFrom, log id: 14f61ee0<b= r />>>>>> 2018-02-12 16:46:30,301+01 INFO [org.ovirt.eng= ine.core.dal.db<br />>>>>> broker.auditloghandling.Audit= LogDirector] (org.ovirt.thread.pool-6-thread-32)<br />>>>>&= gt; [2f712024-5982-46a8-82c8-fd8293da5725] EVENT=5FID:<br />>>>= ;>> VM=5FMIGRATION=5FSTART(62), Correlation ID: 2f712024-5982-46a= 8-82c8-fd8293da5725,<br />>>>>> Job ID: 4bd19aa9-cc99-4d= 02-884e-5a1e857a7738, Call Stack: null, Custom<br />>>>>>= ; ID: null, Custom Event ID: -1, Message: Migration started (VM:<br />&= gt;>>>> Oracle=5FSECONDARY, Source: victor.local.systea.fr,= Destination:<br />>>>>> ginger.local.systea.fr, User: a= dmin@internal-authz).<br />>>>>> 2018-02-12 16:46:31,106= +01 INFO [org.ovirt.engine.core.vdsbro<br />>>>>> ker.vd= sbroker.FullListVDSCommand] (DefaultQuartzScheduler9) [54a65b66]<br />&= gt;>>>> START, FullListVDSCommand(HostName =3D victor.local= .systea.fr,<br />>>>>> FullListVDSCommandParameters:{run= Async=3D'true',<br />>>>>> hostId=3D'ce3938b1-b23f-4d22-= 840a-f17d7cd87bb1',<br />>>>>> vmIds=3D'[3f57e669-5e4c-4= d10-85cc-d573004a099d]'}), log id: 54b4b435<br />>>>>> 2= 018-02-12 16:46:31,147+01 INFO [org.ovirt.engine.core.vdsbro<br />>&= gt;>>> ker.vdsbroker.FullListVDSCommand] (DefaultQuartzSchedul= er9) [54a65b66]<br />>>>>> FINISH, FullListVDSCommand, r= eturn: [{acpiEnable=3Dtrue,<br />>>>>> emulatedMachine=3D= pc-i440fx-rhel7.3.0, tabletEnable=3Dtrue, pid=3D1493,<br />>>>= >> guestDiskMapping=3D{0QEMU=5FQEMU=5FHARDDISK=5Fd890fa68-fba4-4f= 49-9=3D{name=3D/dev/sda},<br />>>>>> QEMU=5FDVD-ROM=5FQM= 00003=3D{name=3D/dev/sr0}}, transparentHugePages=3Dtrue,<br />>>&= gt;>> timeOffset=3D0, cpuType=3DNehalem, smp=3D2, pauseCode=3DNOE= RR,<br />>>>>> guestNumaNodes=3D[Ljava.lang.Object;@1d90= 42cd, smartcardEnable=3Dfalse,<br />>>>>> custom=3D{devi= ce=5Ffbddd528-7d93-49c6-a286-180e021cb274device=5F87<br />>>>&= gt;> 9c93ab-4df1-435c-af02-565039fcc254=3DVmDevice:{id=3D'VmDeviceId= :<br />>>>>> {deviceId=3D'879c93ab-4df1-435c-af02-565039= fcc254',<br />>>>>> vmId=3D'3f57e669-5e4c-4d10-85cc-d573= 004a099d'}', device=3D'unix',<br />>>>>> type=3D'CHANNEL= ', bootOrder=3D'0', specParams=3D'[]', address=3D'{bus=3D0,<br />>&g= t;>>> controller=3D0, type=3Dvirtio-serial, port=3D1}', manage= d=3D'false',<br />>>>>> plugged=3D'true', readOnly=3D'fa= lse', deviceAlias=3D'channel0',<br />>>>>> customPropert= ies=3D'[]', snapshotId=3D'null', logicalName=3D'null',<br />>>>= ;>> hostDevice=3D'null'}, device=5Ffbddd528-7d93-49c6-a286<br />&= gt;>>>> -180e021cb274device=5F879c93ab-4df1-435c-af02-56503= 9fcc254devi<br />>>>>> ce=5F8945f61a-abbe-4156-8485-a4aa= 6f1908dbdevice=5F017b5e59-01c4-<br />>>>>> 4aac-bf0c-b5d= 9557284d6=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D'0<br />>>>= >> 17b5e59-01c4-4aac-bf0c-b5d9557284d6', vmId=3D'3f57e669-5e4c-4d= 10-85cc-d573004a099d'}',<br />>>>>> device=3D'tablet', t= ype=3D'UNKNOWN', bootOrder=3D'0', specParams=3D'[]',<br />>>>&= gt;> address=3D'{bus=3D0, type=3Dusb, port=3D1}', managed=3D'false',= plugged=3D'true',<br />>>>>> readOnly=3D'false', device= Alias=3D'input0', customProperties=3D'[]',<br />>>>>> sn= apshotId=3D'null', logicalName=3D'null', hostDevice=3D'null'},<br />>= ;>>>> device=5Ffbddd528-7d93-49c6-a286-180e021cb274=3DVmDev= ice:{id=3D'Vm<br />>>>>> DeviceId:{deviceId=3D'fbddd528-= 7d93-49c6-a286-180e021cb274',<br />>>>>> vmId=3D'3f57e66= 9-5e4c-4d10-85cc-d573004a099d'}', device=3D'ide',<br />>>>>= > type=3D'CONTROLLER', bootOrder=3D'0', specParams=3D'[]', address=3D= '{slot=3D0x01,<br />>>>>> bus=3D0x00, domain=3D0x0000, t= ype=3Dpci, function=3D0x1}', managed=3D'false',<br />>>>>&g= t; plugged=3D'true', readOnly=3D'false', deviceAlias=3D'ide', customPro= perties=3D'[]',<br />>>>>> snapshotId=3D'null', logicalN= ame=3D'null', hostDevice=3D'null'},<br />>>>>> device=5F= fbddd528-7d93-49c6-a286-180e021cb274device=5F879c93ab-4<br />>>&g= t;>> df1-435c-af02-565039fcc254device=5F8945f61a-abbe-4156-8485-a= 4a<br />>>>>> a6f1908db=3DVmDevice:{id=3D'VmDeviceId:{de= viceId=3D'8945f61a-abbe-4156-8485-a4aa6f1908db',<br />>>>>&= gt; vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', device=3D'unix',<b= r />>>>>> type=3D'CHANNEL', bootOrder=3D'0', specParams=3D= '[]', address=3D'{bus=3D0,<br />>>>>> controller=3D0, ty= pe=3Dvirtio-serial, port=3D2}', managed=3D'false',<br />>>>>= ;> plugged=3D'true', readOnly=3D'false', deviceAlias=3D'channel1',<b= r />>>>>> customProperties=3D'[]', snapshotId=3D'null', = logicalName=3D'null',<br />>>>>> hostDevice=3D'null'}}, = vmType=3Dkvm, memSize=3D8192, smpCoresPerSocket=3D1,<br />>>>&= gt;> vmName=3DOracle=5FSECONDARY, nice=3D0, status=3DMigration Sourc= e, maxMemSize=3D32768,<br />>>>>> bootMenuEnable=3Dfalse= , vmId=3D3f57e669-5e4c-4d10-85cc-d573004a099d,<br />>>>>>= ; numOfIoThreads=3D2, smpThreadsPerCore=3D1, memGuaranteedSize=3D8192,<= br />>>>>> kvmEnable=3Dtrue, pitReinjection=3Dfalse, dis= playNetwork=3Dovirtmgmt,<br />>>>>> devices=3D[Ljava.lan= g.Object;@28ae66d7, display=3Dvnc, maxVCpus=3D16,<br />>>>>= > clientIp=3D, statusTime=3D4299484520, maxMemSlots=3D16}], log id: = 54b4b435<br />>>>>> 2018-02-12 16:46:31,150+01 INFO [org= .ovirt.engine.core.vdsbro<br />>>>>> ker.monitoring.VmsS= tatisticsFetcher] (DefaultQuartzScheduler1)<br />>>>>> [= 27fac647] Fetched 3 VMs from VDS 'd569c2dd-8f30-4878-8aea-858db285cf69'= <br />>>>>> 2018-02-12 16:46:31,151+01 INFO [org.ovirt.e= ngine.core.vdsbro<br />>>>>> ker.monitoring.VmDevicesMon= itoring] (DefaultQuartzScheduler9)<br />>>>>> [54a65b66]= Received a vnc Device without an address when processing VM<br />>&= gt;>>> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping = device:<br />>>>>> {device=3Dvnc, specParams=3D{displayN= etwork=3Dovirtmgmt, keyMap=3Dfr,<br />>>>>> displayIp=3D= 192.168.0.6}, type=3Dgraphics, deviceId=3D813957b1-446a-4e88-9e40-9fe76= d2c442d,<br />>>>>> port=3D5901}<br />>>>>&g= t; 2018-02-12 16:46:31,151+01 INFO [org.ovirt.engine.core.vdsbro<br />&= gt;>>>> ker.monitoring.VmDevicesMonitoring] (DefaultQuartzS= cheduler9)<br />>>>>> [54a65b66] Received a lease Device= without an address when processing VM<br />>>>>> 3f57e6= 69-5e4c-4d10-85cc-d573004a099d devices, skipping device:<br />>>&= gt;>> {lease=5Fid=3D3f57e669-5e4c-4d10-85cc-d573004a099d,<br />&g= t;>>>> sd=5Fid=3D1e51cecc-eb2e-47d0-b185-920fdc7afa16,<br /= >>>>>> deviceId=3D{uuid=3Da09949aa-5642-4b6d-94a4-8b0d04= 257be5}, offset=3D6291456,<br />>>>>> device=3Dlease, pa= th=3D/rhev/data-center/mnt/glusterSD/192.168.0.6:<br />>>>>= > =5FDATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom=5Fmd/xleases, t= ype=3Dlease}<br />>>>>> 2018-02-12 16:46:31,152+01 INFO = [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer]<br />>>&g= t;>> (DefaultQuartzScheduler1) [27fac647] VM '3f57e669-5e4c-4d10-= 85cc-d573004a099d'(Oracle=5FSECONDARY)<br />>>>>> was un= expectedly detected as 'MigratingTo' on VDS<br />>>>>> '= d569c2dd-8f30-4878-8aea-858db285cf69'(ginger.local.systea.fr)<br />>= >>>> (expected on 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1')<b= r />>>>>> 2018-02-12 16:46:31,152+01 INFO [org.ovirt.eng= ine.core.vdsbroker.monitoring.VmAnalyzer]<br />>>>>> (De= faultQuartzScheduler1) [27fac647] VM '3f57e669-5e4c-4d10-85cc-d573004a0= 99d'<br />>>>>> is migrating to VDS 'd569c2dd-8f30-4878-= 8aea-858db285cf69'(<br />>>>>> ginger.local.systea.fr) i= gnoring it in the refresh until migration is<br />>>>>> = done<br />>>>>> ....<br />>>>>> 2018-02-1= 2 16:46:41,631+01 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAn= alyzer]<br />>>>>> (ForkJoinPool-1-worker-11) [] VM '3f5= 7e669-5e4c-4d10-85cc-d573004a099d'<br />>>>>> was report= ed as Down on VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(<br />>>= >>> victor.local.systea.fr)<br />>>>>> 2018-02-= 12 16:46:41,632+01 INFO [org.ovirt.engine.core.vdsbro<br />>>>= >> ker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-11) []= START,<br />>>>>> DestroyVDSCommand(HostName =3D victor= .local.systea.fr,<br />>>>>> DestroyVmVDSCommandParamete= rs:{runAsync=3D'true',<br />>>>>> hostId=3D'ce3938b1-b23= f-4d22-840a-f17d7cd87bb1',<br />>>>>> vmId=3D'3f57e669-5= e4c-4d10-85cc-d573004a099d', force=3D'false',<br />>>>>>= secondsToWait=3D'0', gracefully=3D'false', reason=3D'', ignoreNoVm=3D'= true'}), log<br />>>>>> id: 560eca57<br />>>>&g= t;> 2018-02-12 16:46:41,650+01 INFO [org.ovirt.engine.core.vdsbro<br= />>>>>> ker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-= 1-worker-11) [] FINISH,<br />>>>>> DestroyVDSCommand, lo= g id: 560eca57<br />>>>>> 2018-02-12 16:46:41,650+01 INF= O [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer]<br />>>= >>> (ForkJoinPool-1-worker-11) [] VM '3f57e669-5e4c-4d10-85cc-= d573004a099d'(Oracle=5FSECONDARY)<br />>>>>> moved from = 'MigratingFrom' --> 'Down'<br />>>>>> 2018-02-12 16:4= 6:41,651+01 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer= ]<br />>>>>> (ForkJoinPool-1-worker-11) [] Handing over = VM '3f57e669-5e4c-4d10-85cc-d573004a099d'(Oracle=5FSECONDARY)<br />>= >>>> to Host 'd569c2dd-8f30-4878-8aea-858db285cf69'. Settin= g VM to status<br />>>>>> 'MigratingTo'<br />>>>= ;>> 2018-02-12 16:46:42,163+01 INFO [org.ovirt.engine.core.vdsbro= ker.monitoring.VmAnalyzer]<br />>>>>> (ForkJoinPool-1-wo= rker-4) [] VM '3f57e669-5e4c-4d10-85cc-d573004a099d'(Oracle=5FSECONDARY= )<br />>>>>> moved from 'MigratingTo' --> 'Up'<br />&= gt;>>>> 2018-02-12 16:46:42,169+01 INFO [org.ovirt.engine.c= ore.vdsbro<br />>>>>> ker.vdsbroker.MigrateStatusVDSComm= and] (ForkJoinPool-1-worker-4) []<br />>>>>> START, Migr= ateStatusVDSCommand(HostName =3D ginger.local.systea.fr,<br />>>&= gt;>> MigrateStatusVDSCommandParameters:{runAsync=3D'true',<br />= >>>>> hostId=3D'd569c2dd-8f30-4878-8aea-858db285cf69',<b= r />>>>>> vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}= ), log id: 7a25c281<br />>>>>> 2018-02-12 16:46:42,174+0= 1 INFO [org.ovirt.engine.core.vdsbro<br />>>>>> ker.vdsb= roker.MigrateStatusVDSCommand] (ForkJoinPool-1-worker-4) []<br />>&g= t;>>> FINISH, MigrateStatusVDSCommand, log id: 7a25c281<br />&= gt;>>>> 2018-02-12 16:46:42,194+01 INFO [org.ovirt.engine.c= ore.dal.db<br />>>>>> broker.auditloghandling.AuditLogDi= rector] (ForkJoinPool-1-worker-4) []<br />>>>>> EVENT=5F= ID: VM=5FMIGRATION=5FDONE(63), Correlation ID:<br />>>>>>= ; 2f712024-5982-46a8-82c8-fd8293da5725, Job ID:<br />>>>>&g= t; 4bd19aa9-cc99-4d02-884e-5a1e857a7738, Call Stack: null, Custom ID:<b= r />>>>>> null, Custom Event ID: -1, Message: Migration = completed (VM:<br />>>>>> Oracle=5FSECONDARY, Source: vi= ctor.local.systea.fr, Destination:<br />>>>>> ginger.loc= al.systea.fr, Duration: 11 seconds, Total: 11 seconds, Actual<br />>= >>>> downtime: (N/A))<br />>>>>> 2018-02-12 = 16:46:42,201+01 INFO [org.ovirt.engine.core.bll.MigrateVmToServerComman= d]<br />>>>>> (ForkJoinPool-1-worker-4) [] Lock freed to= object<br />>>>>> 'EngineLock:{exclusiveLocks=3D'[3f57e= 669-5e4c-4d10-85cc-d573004a099d=3DVM]',<br />>>>>> share= dLocks=3D''}'<br />>>>>> 2018-02-12 16:46:42,203+01 INFO= [org.ovirt.engine.core.vdsbro<br />>>>>> ker.vdsbroker.= FullListVDSCommand] (ForkJoinPool-1-worker-4) [] START,<br />>>&g= t;>> FullListVDSCommand(HostName =3D ginger.local.systea.fr,<br /= >>>>>> FullListVDSCommandParameters:{runAsync=3D'true',<= br />>>>>> hostId=3D'd569c2dd-8f30-4878-8aea-858db285cf6= 9',<br />>>>>> vmIds=3D'[3f57e669-5e4c-4d10-85cc-d573004= a099d]'}), log id: 7cc65298<br />>>>>> 2018-02-12 16:46:= 42,254+01 INFO [org.ovirt.engine.core.vdsbro<br />>>>>> = ker.vdsbroker.FullListVDSCommand] (ForkJoinPool-1-worker-4) [] FINISH,<= br />>>>>> FullListVDSCommand, return: [{acpiEnable=3Dtr= ue,<br />>>>>> emulatedMachine=3Dpc-i440fx-rhel7.3.0, af= terMigrationStatus=3D,<br />>>>>> tabletEnable=3Dtrue, p= id=3D18748, guestDiskMapping=3D{},<br />>>>>> transparen= tHugePages=3Dtrue, timeOffset=3D0, cpuType=3DNehalem, smp=3D2,<br />>= ;>>>> guestNumaNodes=3D[Ljava.lang.Object;@760085fd,<br />&= gt;>>>> custom=3D{device=5Ffbddd528-7d93-49c6-a286-180e021c= b274device=5F87<br />>>>>> 9c93ab-4df1-435c-af02-565039f= cc254=3DVmDevice:{id=3D'VmDeviceId:<br />>>>>> {deviceId= =3D'879c93ab-4df1-435c-af02-565039fcc254',<br />>>>>> vm= Id=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', device=3D'unix',<br />&g= t;>>>> type=3D'CHANNEL', bootOrder=3D'0', specParams=3D'[]'= , address=3D'{bus=3D0,<br />>>>>> controller=3D0, type=3D= virtio-serial, port=3D1}', managed=3D'false',<br />>>>>>= plugged=3D'true', readOnly=3D'false', deviceAlias=3D'channel0',<br />&= gt;>>>> customProperties=3D'[]', snapshotId=3D'null', logic= alName=3D'null',<br />>>>>> hostDevice=3D'null'}, device= =5Ffbddd528-7d93-49c6-a286<br />>>>>> -180e021cb274devic= e=5F879c93ab-4df1-435c-af02-565039fcc254devi<br />>>>>> = ce=5F8945f61a-abbe-4156-8485-a4aa6f1908dbdevice=5F017b5e59-01c4-<br />&= gt;>>>> 4aac-bf0c-b5d9557284d6=3DVmDevice:{id=3D'VmDeviceId= :{deviceId=3D'0<br />>>>>> 17b5e59-01c4-4aac-bf0c-b5d955= 7284d6', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}',<br />>>= >>> device=3D'tablet', type=3D'UNKNOWN', bootOrder=3D'0', spec= Params=3D'[]',<br />>>>>> address=3D'{bus=3D0, type=3Dus= b, port=3D1}', managed=3D'false', plugged=3D'true',<br />>>>&g= t;> readOnly=3D'false', deviceAlias=3D'input0', customProperties=3D'= []',<br />>>>>> snapshotId=3D'null', logicalName=3D'null= ', hostDevice=3D'null'},<br />>>>>> device=5Ffbddd528-7d= 93-49c6-a286-180e021cb274=3DVmDevice:{id=3D'Vm<br />>>>>>= ; DeviceId:{deviceId=3D'fbddd528-7d93-49c6-a286-180e021cb274',<br />>= ;>>>> vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', devi= ce=3D'ide',<br />>>>>> type=3D'CONTROLLER', bootOrder=3D= '0', specParams=3D'[]', address=3D'{slot=3D0x01,<br />>>>>&= gt; bus=3D0x00, domain=3D0x0000, type=3Dpci, function=3D0x1}', managed=3D= 'false',<br />>>>>> plugged=3D'true', readOnly=3D'false'= , deviceAlias=3D'ide', customProperties=3D'[]',<br />>>>>&g= t; snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'null'},<br = />>>>>> device=5Ffbddd528-7d93-49c6-a286-180e021cb274dev= ice=5F879c93ab-4<br />>>>>> df1-435c-af02-565039fcc254de= vice=5F8945f61a-abbe-4156-8485-a4a<br />>>>>> a6f1908db=3D= VmDevice:{id=3D'VmDeviceId:{deviceId=3D'8945f61a-abbe-4156-8485-a4aa6f1= 908db',<br />>>>>> vmId=3D'3f57e669-5e4c-4d10-85cc-d5730= 04a099d'}', device=3D'unix',<br />>>>>> type=3D'CHANNEL'= , bootOrder=3D'0', specParams=3D'[]', address=3D'{bus=3D0,<br />>>= ;>>> controller=3D0, type=3Dvirtio-serial, port=3D2}', managed= =3D'false',<br />>>>>> plugged=3D'true', readOnly=3D'fal= se', deviceAlias=3D'channel1',<br />>>>>> customProperti= es=3D'[]', snapshotId=3D'null', logicalName=3D'null',<br />>>>= >> hostDevice=3D'null'}}, vmType=3Dkvm, memSize=3D8192, smpCoresP= erSocket=3D1,<br />>>>>> vmName=3DOracle=5FSECONDARY, ni= ce=3D0, status=3DUp, maxMemSize=3D32768,<br />>>>>> boot= MenuEnable=3Dfalse, vmId=3D3f57e669-5e4c-4d10-85cc-d573004a099d,<br />&= gt;>>>> numOfIoThreads=3D2, smpThreadsPerCore=3D1, smartcar= dEnable=3Dfalse,<br />>>>>> maxMemSlots=3D16, kvmEnable=3D= true, pitReinjection=3Dfalse,<br />>>>>> displayNetwork=3D= ovirtmgmt, devices=3D[Ljava.lang.Object;@2e4d3dd3,<br />>>>>= ;> memGuaranteedSize=3D8192, maxVCpus=3D16, clientIp=3D, statusTime=3D= 4304259600<br />>>>>> <(430)%20425-9600>, display=3D= vnc}], log id: 7cc65298<br />>>>>> 2018-02-12 16:46:42,2= 57+01 INFO [org.ovirt.engine.core.vdsbro<br />>>>>> ker.= monitoring.VmDevicesMonitoring] (ForkJoinPool-1-worker-4) []<br />>&= gt;>>> Received a vnc Device without an address when processin= g VM<br />>>>>> 3f57e669-5e4c-4d10-85cc-d573004a099d dev= ices, skipping device:<br />>>>>> {device=3Dvnc, specPar= ams=3D{displayNetwork=3Dovirtmgmt, keyMap=3Dfr,<br />>>>>&g= t; displayIp=3D192.168.0.5}, type=3Dgraphics, deviceId=3D813957b1-446a-= 4e88-9e40-9fe76d2c442d,<br />>>>>> port=3D5901}<br />>= ;>>>> 2018-02-12 16:46:42,257+01 INFO [org.ovirt.engine.cor= e.vdsbro<br />>>>>> ker.monitoring.VmDevicesMonitoring] = (ForkJoinPool-1-worker-4) []<br />>>>>> Received a lease= Device without an address when processing VM<br />>>>>>= 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping device:<br />&g= t;>>>> {lease=5Fid=3D3f57e669-5e4c-4d10-85cc-d573004a099d,<= br />>>>>> sd=5Fid=3D1e51cecc-eb2e-47d0-b185-920fdc7afa1= 6,<br />>>>>> deviceId=3D{uuid=3Da09949aa-5642-4b6d-94a4= -8b0d04257be5}, offset=3D6291456,<br />>>>>> device=3Dle= ase, path=3D/rhev/data-center/mnt/glusterSD/192.168.0.6:<br />>>&= gt;>> =5FDATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom=5Fmd/xle= ases, type=3Dlease}<br />>>>>> 2018-02-12 16:46:46,260+0= 1 INFO [org.ovirt.engine.core.vdsbro<br />>>>>> ker.vdsb= roker.FullListVDSCommand] (DefaultQuartzScheduler5) [7fcb200a]<br />>= ;>>>> FINISH, FullListVDSCommand, return: [{acpiEnable=3Dtr= ue,<br />>>>>> emulatedMachine=3Dpc-i440fx-rhel7.3.0, af= terMigrationStatus=3D,<br />>>>>> tabletEnable=3Dtrue, p= id=3D18748, guestDiskMapping=3D{0QEMU=5FQEMU=5FH<br />>>>>&= gt; ARDDISK=5Fd890fa68-fba4-4f49-9=3D{name=3D/dev/sda},<br />>>&g= t;>> QEMU=5FDVD-ROM=5FQM00003=3D{name=3D/dev/sr0}}, transparentHu= gePages=3Dtrue,<br />>>>>> timeOffset=3D0, cpuType=3DNeh= alem, smp=3D2, guestNumaNodes=3D[Ljava.lang.Obj<br />>>>>&g= t; ect;@77951faf, custom=3D{device=5Ffbddd528-7d93-4<br />>>>&= gt;> 9c6-a286-180e021cb274device=5F879c93ab-4df1-435c-af02-565039fc<= br />>>>>> c254=3DVmDevice:{id=3D'VmDeviceId:{deviceId=3D= '879c93ab-4df1-435c-af02-565039fcc254',<br />>>>>> vmId=3D= '3f57e669-5e4c-4d10-85cc-d573004a099d'}', device=3D'unix',<br />>>= ;>>> type=3D'CHANNEL', bootOrder=3D'0', specParams=3D'[]', add= ress=3D'{bus=3D0,<br />>>>>> controller=3D0, type=3Dvirt= io-serial, port=3D1}', managed=3D'false',<br />>>>>> plu= gged=3D'true', readOnly=3D'false', deviceAlias=3D'channel0',<br />>&= gt;>>> customProperties=3D'[]', snapshotId=3D'null', logicalNa= me=3D'null',<br />>>>>> hostDevice=3D'null'}, device=5Ff= bddd528-7d93-49c6-a286<br />>>>>> -180e021cb274device=5F= 879c93ab-4df1-435c-af02-565039fcc254devi<br />>>>>> ce=5F= 8945f61a-abbe-4156-8485-a4aa6f1908dbdevice=5F017b5e59-01c4-<br />>&g= t;>>> 4aac-bf0c-b5d9557284d6=3DVmDevice:{id=3D'VmDeviceId:{dev= iceId=3D'0<br />>>>>> 17b5e59-01c4-4aac-bf0c-b5d9557284d= 6', vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}',<br />>>>&= gt;> device=3D'tablet', type=3D'UNKNOWN', bootOrder=3D'0', specParam= s=3D'[]',<br />>>>>> address=3D'{bus=3D0, type=3Dusb, po= rt=3D1}', managed=3D'false', plugged=3D'true',<br />>>>>>= ; readOnly=3D'false', deviceAlias=3D'input0', customProperties=3D'[]',<= br />>>>>> snapshotId=3D'null', logicalName=3D'null', ho= stDevice=3D'null'},<br />>>>>> device=5Ffbddd528-7d93-49= c6-a286-180e021cb274=3DVmDevice:{id=3D'Vm<br />>>>>> Dev= iceId:{deviceId=3D'fbddd528-7d93-49c6-a286-180e021cb274',<br />>>= >>> vmId=3D'3f57e669-5e4c-4d10-85cc-d573004a099d'}', device=3D= 'ide',<br />>>>>> type=3D'CONTROLLER', bootOrder=3D'0', = specParams=3D'[]', address=3D'{slot=3D0x01,<br />>>>>> b= us=3D0x00, domain=3D0x0000, type=3Dpci, function=3D0x1}', managed=3D'fa= lse',<br />>>>>> plugged=3D'true', readOnly=3D'false', d= eviceAlias=3D'ide', customProperties=3D'[]',<br />>>>>> = snapshotId=3D'null', logicalName=3D'null', hostDevice=3D'null'},<br />&= gt;>>>> device=5Ffbddd528-7d93-49c6-a286-180e021cb274device= =5F879c93ab-4<br />>>>>> df1-435c-af02-565039fcc254devic= e=5F8945f61a-abbe-4156-8485-a4a<br />>>>>> a6f1908db=3DV= mDevice:{id=3D'VmDeviceId:{deviceId=3D'8945f61a-abbe-4156-8485-a4aa6f19= 08db',<br />>>>>> vmId=3D'3f57e669-5e4c-4d10-85cc-d57300= 4a099d'}', device=3D'unix',<br />>>>>> type=3D'CHANNEL',= bootOrder=3D'0', specParams=3D'[]', address=3D'{bus=3D0,<br />>>= >>> controller=3D0, type=3Dvirtio-serial, port=3D2}', managed=3D= 'false',<br />>>>>> plugged=3D'true', readOnly=3D'false'= , deviceAlias=3D'channel1',<br />>>>>> customProperties=3D= '[]', snapshotId=3D'null', logicalName=3D'null',<br />>>>>&= gt; hostDevice=3D'null'}}, vmType=3Dkvm, memSize=3D8192, smpCoresPerSoc= ket=3D1,<br />>>>>> vmName=3DOracle=5FSECONDARY, nice=3D= 0, status=3DUp, maxMemSize=3D32768,<br />>>>>> bootMenuE= nable=3Dfalse, vmId=3D3f57e669-5e4c-4d10-85cc-d573004a099d,<br />>&g= t;>>> numOfIoThreads=3D2, smpThreadsPerCore=3D1, smartcardEnab= le=3Dfalse,<br />>>>>> maxMemSlots=3D16, kvmEnable=3Dtru= e, pitReinjection=3Dfalse,<br />>>>>> displayNetwork=3Do= virtmgmt, devices=3D[Ljava.lang.Object;@286410fd,<br />>>>>= > memGuaranteedSize=3D8192, maxVCpus=3D16, clientIp=3D, statusTime=3D= 4304263620<br />>>>>> <(430)%20426-3620>, display=3D= vnc}], log id: 58cdef4c<br />>>>>> 2018-02-12 16:46:46,2= 67+01 INFO [org.ovirt.engine.core.vdsbro<br />>>>>> ker.= monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler5)<br />>>= >>> [7fcb200a] Received a vnc Device without an address when p= rocessing VM<br />>>>>> 3f57e669-5e4c-4d10-85cc-d573004a= 099d devices, skipping device:<br />>>>>> {device=3Dvnc,= specParams=3D{displayNetwork=3Dovirtmgmt, keyMap=3Dfr,<br />>>&g= t;>> displayIp=3D192.168.0.5}, type=3Dgraphics, deviceId=3D813957= b1-446a-4e88-9e40-9fe76d2c442d,<br />>>>>> port=3D5901}<= br />>>>>> 2018-02-12 16:46:46,268+01 INFO [org.ovirt.en= gine.core.vdsbro<br />>>>>> ker.monitoring.VmDevicesMoni= toring] (DefaultQuartzScheduler5)<br />>>>>> [7fcb200a] = Received a lease Device without an address when processing VM<br />>= >>>> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping= device:<br />>>>>> {lease=5Fid=3D3f57e669-5e4c-4d10-85c= c-d573004a099d,<br />>>>>> sd=5Fid=3D1e51cecc-eb2e-47d0-= b185-920fdc7afa16,<br />>>>>> deviceId=3D{uuid=3Da09949a= a-5642-4b6d-94a4-8b0d04257be5}, offset=3D6291456,<br />>>>>= > device=3Dlease, path=3D/rhev/data-center/mnt/glusterSD/192.168.0.6= :<br />>>>>> =5FDATA01/1e51cecc-eb2e-47d0-b185-920fdc7af= a16/dom=5Fmd/xleases, type=3Dlease}<br />>>>>><br />>= >>>><br />>>>>><br />>>>>><br= />>>>>> For the VM with 2 vdisks we see :<br />>>= >>><br />>>>>> 2018-02-12 16:49:06,112+01 INFO = [org.ovirt.engine.core.bll.MigrateVmToServerCommand]<br />>>>&= gt;> (default task-50) [92b5af33-cb87-4142-b8fe-8b838dd7458e] Lock A= cquired<br />>>>>> to object 'EngineLock:{exclusiveLocks= =3D'[f7d4ec12-627a-4b83-b59e-886400d55474=3DVM]',<br />>>>>= > sharedLocks=3D''}'<br />>>>>> 2018-02-12 16:49:06,4= 07+01 INFO [org.ovirt.engine.core.bll.MigrateVmToServerCommand]<br />&g= t;>>>> (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4= 142-b8fe-8b838dd7458e]<br />>>>>> Running command: Migra= teVmToServerCommand internal: false. Entities<br />>>>>>= affected : ID: f7d4ec12-627a-4b83-b59e-886400d55474 Type: VMAction<br = />>>>>> group MIGRATE=5FVM with role type USER<br />>= >>>> 2018-02-12 16:49:06,712+01 INFO [org.ovirt.engine.core= .vdsbroker.MigrateVDSCommand]<br />>>>>> (org.ovirt.thre= ad.pool-6-thread-49) [92b5af33-cb87-4142-b8fe-8b838dd7458e]<br />>&g= t;>>> START, MigrateVDSCommand( MigrateVDSCommandParameters:{r= unAsync=3D'true',<br />>>>>> hostId=3D'd569c2dd-8f30-487= 8-8aea-858db285cf69',<br />>>>>> vmId=3D'f7d4ec12-627a-4= b83-b59e-886400d55474', srcHost=3D'192.168.0.5',<br />>>>>&= gt; dstVdsId=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1', dstHost=3D'<br /= >>>>>> 192.168.0.6:54321', migrationMethod=3D'ONLINE', t= unnelMigration=3D'false',<br />>>>>> migrationDowntime=3D= '0', autoConverge=3D'true', migrateCompressed=3D'false',<br />>>&= gt;>> consoleAddress=3D'null', maxBandwidth=3D'500', enableGuestE= vents=3D'true',<br />>>>>> maxIncomingMigrations=3D'2', = maxOutgoingMigrations=3D'2',<br />>>>>> convergenceSched= ule=3D'[init=3D[{name=3DsetDowntime, params=3D[100]}],<br />>>>= ;>> stalling=3D[{limit=3D1, action=3D{name=3DsetDowntime, params=3D= [150]}}, {limit=3D2,<br />>>>>> action=3D{name=3DsetDown= time, params=3D[200]}}, {limit=3D3,<br />>>>>> action=3D= {name=3DsetDowntime, params=3D[300]}}, {limit=3D4,<br />>>>>= ;> action=3D{name=3DsetDowntime, params=3D[400]}}, {limit=3D6,<br />= >>>>> action=3D{name=3DsetDowntime, params=3D[500]}}, {l= imit=3D-1, action=3D{name=3Dabort,<br />>>>>> params=3D[= ]}}]]'}), log id: 3702a9e0<br />>>>>> 2018-02-12 16:49:0= 6,713+01 INFO [org.ovirt.engine.core.vdsbro<br />>>>>> k= er.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-thread-4= 9)<br />>>>>> [92b5af33-cb87-4142-b8fe-8b838dd7458e] STA= RT,<br />>>>>> MigrateBrokerVDSCommand(HostName =3D ging= er.local.systea.fr,<br />>>>>> MigrateVDSCommandParamete= rs:{runAsync=3D'true',<br />>>>>> hostId=3D'd569c2dd-8f3= 0-4878-8aea-858db285cf69',<br />>>>>> vmId=3D'f7d4ec12-6= 27a-4b83-b59e-886400d55474', srcHost=3D'192.168.0.5',<br />>>>= >> dstVdsId=3D'ce3938b1-b23f-4d22-840a-f17d7cd87bb1', dstHost=3D'= <br />>>>>> 192.168.0.6:54321', migrationMethod=3D'ONLIN= E', tunnelMigration=3D'false',<br />>>>>> migrationDownt= ime=3D'0', autoConverge=3D'true', migrateCompressed=3D'false',<br />>= ;>>>> consoleAddress=3D'null', maxBandwidth=3D'500', enable= GuestEvents=3D'true',<br />>>>>> maxIncomingMigrations=3D= '2', maxOutgoingMigrations=3D'2',<br />>>>>> convergence= Schedule=3D'[init=3D[{name=3DsetDowntime, params=3D[100]}],<br />>&g= t;>>> stalling=3D[{limit=3D1, action=3D{name=3DsetDowntime, pa= rams=3D[150]}}, {limit=3D2,<br />>>>>> action=3D{name=3D= setDowntime, params=3D[200]}}, {limit=3D3,<br />>>>>> ac= tion=3D{name=3DsetDowntime, params=3D[300]}}, {limit=3D4,<br />>>= >>> action=3D{name=3DsetDowntime, params=3D[400]}}, {limit=3D6= ,<br />>>>>> action=3D{name=3DsetDowntime, params=3D[500= ]}}, {limit=3D-1, action=3D{name=3Dabort,<br />>>>>> par= ams=3D[]}}]]'}), log id: 1840069c<br />>>>>> 2018-02-12 = 16:49:06,724+01 INFO [org.ovirt.engine.core.vdsbro<br />>>>>= ;> ker.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-t= hread-49)<br />>>>>> [92b5af33-cb87-4142-b8fe-8b838dd745= 8e] FINISH, MigrateBrokerVDSCommand,<br />>>>>> log id: = 1840069c<br />>>>>> 2018-02-12 16:49:06,732+01 INFO [org= .ovirt.engine.core.vdsbroker.MigrateVDSCommand]<br />>>>>&g= t; (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4142-b8fe-8b838dd= 7458e]<br />>>>>> FINISH, MigrateVDSCommand, return: Mig= ratingFrom, log id: 3702a9e0<br />>>>>> 2018-02-12 16:49= :06,753+01 INFO [org.ovirt.engine.core.dal.db<br />>>>>>= broker.auditloghandling.AuditLogDirector] (org.ovirt.thread.pool-6-thr= ead-49)<br />>>>>> [92b5af33-cb87-4142-b8fe-8b838dd7458e= ] EVENT=5FID:<br />>>>>> VM=5FMIGRATION=5FSTART(62), Cor= relation ID: 92b5af33-cb87-4142-b8fe-8b838dd7458e,<br />>>>>= ;> Job ID: f4f54054-f7c8-4481-8eda-d5a15c383061, Call Stack: null, C= ustom<br />>>>>> ID: null, Custom Event ID: -1, Message:= Migration started (VM:<br />>>>>> Oracle=5FPRIMARY, Sou= rce: ginger.local.systea.fr, Destination:<br />>>>>> vic= tor.local.systea.fr, User: admin@internal-authz).<br />>>>>= > ...<br />>>>>> 2018-02-12 16:49:16,453+01 INFO [org= .ovirt.engine.core.vdsbro<br />>>>>> ker.monitoring.VmsS= tatisticsFetcher] (DefaultQuartzScheduler4)<br />>>>>> [= 162a5bc3] Fetched 2 VMs from VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'= <br />>>>>> 2018-02-12 16:49:16,455+01 INFO [org.ovirt.e= ngine.core.vdsbroker.monitoring.VmAnalyzer]<br />>>>>> (= DefaultQuartzScheduler4) [162a5bc3] VM 'f7d4ec12-627a-4b83-b59e-886400d= 55474'(Oracle=5FPRIMARY)<br />>>>>> was unexpectedly det= ected as 'MigratingTo' on VDS<br />>>>>> 'ce3938b1-b23f-= 4d22-840a-f17d7cd87bb1'(victor.local.systea.fr)<br />>>>>&g= t; (expected on 'd569c2dd-8f30-4878-8aea-858db285cf69')<br />>>&g= t;>> 2018-02-12 16:49:16,455+01 INFO [org.ovirt.engine.core.vdsbr= oker.monitoring.VmAnalyzer]<br />>>>>> (DefaultQuartzSch= eduler4) [162a5bc3] VM 'f7d4ec12-627a-4b83-b59e-886400d55474'<br />>= >>>> is migrating to VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87= bb1'(<br />>>>>> victor.local.systea.fr) ignoring it in = the refresh until migration is<br />>>>>> done<br />>= >>>> ...<br />>>>>> 2018-02-12 16:49:31,484+= 01 INFO [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer]<br />&g= t;>>>> (DefaultQuartzScheduler5) [11a7619a] VM 'f7d4ec12-62= 7a-4b83-b59e-886400d55474'(Oracle=5FPRIMARY)<br />>>>>> = was unexpectedly detected as 'MigratingTo' on VDS<br />>>>>= > 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(victor.local.systea.fr)<br = />>>>>> (expected on 'd569c2dd-8f30-4878-8aea-858db285cf= 69')<br />>>>>> 2018-02-12 16:49:31,484+01 INFO [org.ovi= rt.engine.core.vdsbroker.monitoring.VmAnalyzer]<br />>>>>&g= t; (DefaultQuartzScheduler5) [11a7619a] VM 'f7d4ec12-627a-4b83-b59e-886= 400d55474'<br />>>>>> is migrating to VDS 'ce3938b1-b23f= -4d22-840a-f17d7cd87bb1'(<br />>>>>> victor.local.systea= .fr) ignoring it in the refresh until migration is<br />>>>>= ;> done<br />>>>>><br />>>>>><br />>= ;>>>><br />>>>>> and so on, last lines repea= ted indefinitly for hours since we poweroff<br />>>>>> t= he VM...<br />>>>>> Is this something known ? Any idea a= bout that ?<br />>>>>><br />>>>>> Thanks<= br />>>>>><br />>>>>> Ovirt 4.1.6, update= d last at feb-13. Gluster 3.12.1.<br />>>>>><br />>&g= t;>>> --<br />>>>>><br />>>>>> C= ordialement,<br />>>>>><br />>>>>> *Frank= Soyer *<br />>>>>><br />>>>>> =5F=5F=5F=5F= =5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F= =5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F=5F<br />>>= >>> Users mailing list<br />>>>>> Users@ovirt.o= rg<br />>>>>> http://lists.ovirt.org/mailman/listinfo/us= ers<br /> </blockquote><br /> </html> ------=_=-_OpenGroupware_org_NGMime-18019-1519921630.582362-42--------