I encountered a bug (see [1]) which contains the same error mentioned in your VDSM logs (see [2]), but I doubt it is related. Milan, maybe you have any advice to troubleshoot the issue? Will the libvirt/qemu logs can help? 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_bug.cgi?id=1486543 - Migration leads to VM running on 2 Hosts [2] 2018-02-16 09:43:35,236+0100 ERROR (jsonrpc/7) [jsonrpc.JsonRpcServer] Internal server error (__init__:577) Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 572, in _handle_request res = method(**params) File "/usr/lib/python2.7/site-packages/vdsm/rpc/Bridge.py", line 198, in _dynamicMethod result = fn(*methodArgs) File "/usr/share/vdsm/API.py", line 1454, in getAllVmIoTunePolicies io_tune_policies_dict = self._cif.getAllVmIoTunePolicies() File "/usr/share/vdsm/clientIF.py", line 454, in getAllVmIoTunePolicies 'current_values': v.getIoTune()} File "/usr/share/vdsm/virt/vm.py", line 2859, in getIoTune result = self.getIoTuneResponse() File "/usr/share/vdsm/virt/vm.py", line 2878, in getIoTuneResponse res = self._dom.blockIoTune( File "/usr/lib/python2.7/site-packages/vdsm/virt/virdomain.py", line 47, in __getattr__ % self.vmid) NotConnectedError: VM u'755cf168-de65-42ed-b22f-efe9136f7594' was not started yet or was shut down On Thu, Feb 22, 2018 at 4:22 PM, fsoyer <fso...@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 standing > on victor, migrated (or failed to migrate...) to ginger. Symptoms were > exactly the same, in both directions, and VMs works like a charm before, > 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évrier 22, 2018 00:45 CET, Maor Lipchuk <mlipc...@redhat.com> > a écrit: > > > 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 disk you > were mentionning. > Does this VM run with both disks on the target host without migration? > > Regards, > Maor > > > On Fri, Feb 16, 2018 at 11:03 AM, fsoyer <fso...@systea.fr> wrote: >> >> Hi Maor, >> sorry for the double post, I've change the email adress of my account 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 minutes. >> Then simply deleting the second disk makes migrate it in exactly 9s without >> problem ! >> https://gist.github.com/fgth/4707446331d201eef574ac31b6e89561 >> https://gist.github.com/fgth/f8de9c22664aee53722af676bff8719d >> >> -- >> >> Cordialement, >> >> *Frank Soyer * >> Le Mercredi, Février 14, 2018 11:04 CET, Maor Lipchuk < >> mlipc...@redhat.com> a écrit: >> >> >> Hi Frank, >> >> I already replied on your last email. >> Can you provide the VDSM logs from the time of the migration failure for >> both hosts: >> ginger.local.systea.f <http://ginger.local.systea.fr/>r and v >> ictor.local.systea.fr >> >> Thanks, >> Maor >> >> On Wed, Feb 14, 2018 at 11:23 AM, fsoyer <fso...@systea.fr> wrote: >>> >>> Hi all, >>> I discovered yesterday a problem when migrating VM with more than one >>> vdisk. >>> On our test servers (oVirt4.1, shared storage with Gluster), I created 2 >>> VMs needed for a test, from a template with a 20G vdisk. On this VMs I >>> added a 100G vdisk (for this tests I didn't want to waste time to extend >>> the existing vdisks... But I lost time finally...). The VMs with the 2 >>> vdisks works well. >>> Now I saw some updates waiting on the host. I tried to put it in >>> maintenance... But it stopped on the two VM. They were marked "migrating", >>> but no more accessible. Other (small) VMs with only 1 vdisk was migrated >>> without problem at the same time. >>> I saw that a kvm process for the (big) VMs was launched on the source >>> AND destination host, but after tens of minutes, the migration and the VMs >>> was always freezed. I tried to cancel the migration for the VMs : failed. >>> The only way to stop it was to poweroff the VMs : the kvm process died on >>> the 2 hosts and the GUI alerted on a failed migration. >>> In doubt, I tried to delete the second vdisk on one of this VMs : it >>> migrates then without error ! And no access problem. >>> I tried to extend the first vdisk of the second VM, the delete the >>> second vdisk : it migrates now without problem ! >>> >>> So after another test with a VM with 2 vdisks, I can say that this >>> blocked the migration process :( >>> >>> In engine.log, for a VMs with 1 vdisk migrating well, we see : >>> >>> 2018-02-12 16:46:29,705+01 INFO >>> [org.ovirt.engine.core.bll.MigrateVmToServerCommand] >>> (default task-28) [2f712024-5982-46a8-82c8-fd8293da5725] Lock Acquired >>> to object >>> 'EngineLock:{exclusiveLocks='[3f57e669-5e4c-4d10-85cc-d573004a099d=VM]', >>> sharedLocks=''}' >>> 2018-02-12 16:46:29,955+01 INFO >>> [org.ovirt.engine.core.bll.MigrateVmToServerCommand] >>> (org.ovirt.thread.pool-6-thread-32) [2f712024-5982-46a8-82c8-fd8293da5725] >>> Running command: MigrateVmToServerCommand internal: false. Entities >>> affected : ID: 3f57e669-5e4c-4d10-85cc-d573004a099d Type: VMAction >>> group MIGRATE_VM with role type USER >>> 2018-02-12 16:46:30,261+01 INFO >>> [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand] >>> (org.ovirt.thread.pool-6-thread-32) [2f712024-5982-46a8-82c8-fd8293da5725] >>> START, MigrateVDSCommand( MigrateVDSCommandParameters:{runAsync='true', >>> hostId='ce3938b1-b23f-4d22-840a-f17d7cd87bb1', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d', srcHost='192.168.0.6', >>> dstVdsId='d569c2dd-8f30-4878-8aea-858db285cf69', dstHost=' >>> 192.168.0.5:54321', migrationMethod='ONLINE', tunnelMigration='false', >>> migrationDowntime='0', autoConverge='true', migrateCompressed='false', >>> consoleAddress='null', maxBandwidth='500', enableGuestEvents='true', >>> maxIncomingMigrations='2', maxOutgoingMigrations='2', >>> convergenceSchedule='[init=[{name=setDowntime, params=[100]}], >>> stalling=[{limit=1, action={name=setDowntime, params=[150]}}, {limit=2, >>> action={name=setDowntime, params=[200]}}, {limit=3, >>> action={name=setDowntime, params=[300]}}, {limit=4, >>> action={name=setDowntime, params=[400]}}, {limit=6, >>> action={name=setDowntime, params=[500]}}, {limit=-1, action={name=abort, >>> params=[]}}]]'}), log id: 14f61ee0 >>> 2018-02-12 16:46:30,262+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-thread-32) >>> [2f712024-5982-46a8-82c8-fd8293da5725] START, >>> MigrateBrokerVDSCommand(HostName = victor.local.systea.fr, >>> MigrateVDSCommandParameters:{runAsync='true', >>> hostId='ce3938b1-b23f-4d22-840a-f17d7cd87bb1', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d', srcHost='192.168.0.6', >>> dstVdsId='d569c2dd-8f30-4878-8aea-858db285cf69', dstHost=' >>> 192.168.0.5:54321', migrationMethod='ONLINE', tunnelMigration='false', >>> migrationDowntime='0', autoConverge='true', migrateCompressed='false', >>> consoleAddress='null', maxBandwidth='500', enableGuestEvents='true', >>> maxIncomingMigrations='2', maxOutgoingMigrations='2', >>> convergenceSchedule='[init=[{name=setDowntime, params=[100]}], >>> stalling=[{limit=1, action={name=setDowntime, params=[150]}}, {limit=2, >>> action={name=setDowntime, params=[200]}}, {limit=3, >>> action={name=setDowntime, params=[300]}}, {limit=4, >>> action={name=setDowntime, params=[400]}}, {limit=6, >>> action={name=setDowntime, params=[500]}}, {limit=-1, action={name=abort, >>> params=[]}}]]'}), log id: 775cd381 >>> 2018-02-12 16:46:30,277+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-thread-32) >>> [2f712024-5982-46a8-82c8-fd8293da5725] FINISH, MigrateBrokerVDSCommand, >>> log id: 775cd381 >>> 2018-02-12 16:46:30,285+01 INFO >>> [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand] >>> (org.ovirt.thread.pool-6-thread-32) [2f712024-5982-46a8-82c8-fd8293da5725] >>> FINISH, MigrateVDSCommand, return: MigratingFrom, log id: 14f61ee0 >>> 2018-02-12 16:46:30,301+01 INFO [org.ovirt.engine.core.dal.db >>> broker.auditloghandling.AuditLogDirector] >>> (org.ovirt.thread.pool-6-thread-32) >>> [2f712024-5982-46a8-82c8-fd8293da5725] EVENT_ID: >>> VM_MIGRATION_START(62), Correlation ID: >>> 2f712024-5982-46a8-82c8-fd8293da5725, >>> Job ID: 4bd19aa9-cc99-4d02-884e-5a1e857a7738, Call Stack: null, Custom >>> ID: null, Custom Event ID: -1, Message: Migration started (VM: >>> Oracle_SECONDARY, Source: victor.local.systea.fr, Destination: >>> ginger.local.systea.fr, User: admin@internal-authz). >>> 2018-02-12 16:46:31,106+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler9) [54a65b66] >>> START, FullListVDSCommand(HostName = victor.local.systea.fr, >>> FullListVDSCommandParameters:{runAsync='true', >>> hostId='ce3938b1-b23f-4d22-840a-f17d7cd87bb1', >>> vmIds='[3f57e669-5e4c-4d10-85cc-d573004a099d]'}), log id: 54b4b435 >>> 2018-02-12 16:46:31,147+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler9) [54a65b66] >>> FINISH, FullListVDSCommand, return: [{acpiEnable=true, >>> emulatedMachine=pc-i440fx-rhel7.3.0, tabletEnable=true, pid=1493, >>> guestDiskMapping={0QEMU_QEMU_HARDDISK_d890fa68-fba4-4f49-9={name=/dev/sda}, >>> QEMU_DVD-ROM_QM00003={name=/dev/sr0}}, transparentHugePages=true, >>> timeOffset=0, cpuType=Nehalem, smp=2, pauseCode=NOERR, >>> guestNumaNodes=[Ljava.lang.Object;@1d9042cd, smartcardEnable=false, >>> custom={device_fbddd528-7d93-49c6-a286-180e021cb274device_87 >>> 9c93ab-4df1-435c-af02-565039fcc254=VmDevice:{id='VmDeviceId: >>> {deviceId='879c93ab-4df1-435c-af02-565039fcc254', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', device='unix', >>> type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, >>> controller=0, type=virtio-serial, port=1}', managed='false', >>> plugged='true', readOnly='false', deviceAlias='channel0', >>> customProperties='[]', snapshotId='null', logicalName='null', >>> hostDevice='null'}, device_fbddd528-7d93-49c6-a286 >>> -180e021cb274device_879c93ab-4df1-435c-af02-565039fcc254devi >>> ce_8945f61a-abbe-4156-8485-a4aa6f1908dbdevice_017b5e59-01c4- >>> 4aac-bf0c-b5d9557284d6=VmDevice:{id='VmDeviceId:{deviceId='0 >>> 17b5e59-01c4-4aac-bf0c-b5d9557284d6', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', >>> device='tablet', type='UNKNOWN', bootOrder='0', specParams='[]', >>> address='{bus=0, type=usb, port=1}', managed='false', plugged='true', >>> readOnly='false', deviceAlias='input0', customProperties='[]', >>> snapshotId='null', logicalName='null', hostDevice='null'}, >>> device_fbddd528-7d93-49c6-a286-180e021cb274=VmDevice:{id='Vm >>> DeviceId:{deviceId='fbddd528-7d93-49c6-a286-180e021cb274', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', device='ide', >>> type='CONTROLLER', bootOrder='0', specParams='[]', address='{slot=0x01, >>> bus=0x00, domain=0x0000, type=pci, function=0x1}', managed='false', >>> plugged='true', readOnly='false', deviceAlias='ide', customProperties='[]', >>> snapshotId='null', logicalName='null', hostDevice='null'}, >>> device_fbddd528-7d93-49c6-a286-180e021cb274device_879c93ab-4 >>> df1-435c-af02-565039fcc254device_8945f61a-abbe-4156-8485-a4a >>> a6f1908db=VmDevice:{id='VmDeviceId:{deviceId='8945f61a-abbe-4156-8485-a4aa6f1908db', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', device='unix', >>> type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, >>> controller=0, type=virtio-serial, port=2}', managed='false', >>> plugged='true', readOnly='false', deviceAlias='channel1', >>> customProperties='[]', snapshotId='null', logicalName='null', >>> hostDevice='null'}}, vmType=kvm, memSize=8192, smpCoresPerSocket=1, >>> vmName=Oracle_SECONDARY, nice=0, status=Migration Source, maxMemSize=32768, >>> bootMenuEnable=false, vmId=3f57e669-5e4c-4d10-85cc-d573004a099d, >>> numOfIoThreads=2, smpThreadsPerCore=1, memGuaranteedSize=8192, >>> kvmEnable=true, pitReinjection=false, displayNetwork=ovirtmgmt, >>> devices=[Ljava.lang.Object;@28ae66d7, display=vnc, maxVCpus=16, >>> clientIp=, statusTime=4299484520, maxMemSlots=16}], log id: 54b4b435 >>> 2018-02-12 16:46:31,150+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.monitoring.VmsStatisticsFetcher] (DefaultQuartzScheduler1) >>> [27fac647] Fetched 3 VMs from VDS 'd569c2dd-8f30-4878-8aea-858db285cf69' >>> 2018-02-12 16:46:31,151+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler9) >>> [54a65b66] Received a vnc Device without an address when processing VM >>> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping device: >>> {device=vnc, specParams={displayNetwork=ovirtmgmt, keyMap=fr, >>> displayIp=192.168.0.6}, type=graphics, >>> deviceId=813957b1-446a-4e88-9e40-9fe76d2c442d, >>> port=5901} >>> 2018-02-12 16:46:31,151+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler9) >>> [54a65b66] Received a lease Device without an address when processing VM >>> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping device: >>> {lease_id=3f57e669-5e4c-4d10-85cc-d573004a099d, >>> sd_id=1e51cecc-eb2e-47d0-b185-920fdc7afa16, >>> deviceId={uuid=a09949aa-5642-4b6d-94a4-8b0d04257be5}, offset=6291456, >>> device=lease, path=/rhev/data-center/mnt/glusterSD/192.168.0.6: >>> _DATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom_md/xleases, type=lease} >>> 2018-02-12 16:46:31,152+01 INFO >>> [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] >>> (DefaultQuartzScheduler1) [27fac647] VM >>> '3f57e669-5e4c-4d10-85cc-d573004a099d'(Oracle_SECONDARY) >>> was unexpectedly detected as 'MigratingTo' on VDS >>> 'd569c2dd-8f30-4878-8aea-858db285cf69'(ginger.local.systea.fr) >>> (expected on 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1') >>> 2018-02-12 16:46:31,152+01 INFO >>> [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] >>> (DefaultQuartzScheduler1) [27fac647] VM >>> '3f57e669-5e4c-4d10-85cc-d573004a099d' >>> is migrating to VDS 'd569c2dd-8f30-4878-8aea-858db285cf69'( >>> ginger.local.systea.fr) ignoring it in the refresh until migration is >>> done >>> .... >>> 2018-02-12 16:46:41,631+01 INFO >>> [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] >>> (ForkJoinPool-1-worker-11) [] VM '3f57e669-5e4c-4d10-85cc-d573004a099d' >>> was reported as Down on VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'( >>> victor.local.systea.fr) >>> 2018-02-12 16:46:41,632+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-11) [] START, >>> DestroyVDSCommand(HostName = victor.local.systea.fr, >>> DestroyVmVDSCommandParameters:{runAsync='true', >>> hostId='ce3938b1-b23f-4d22-840a-f17d7cd87bb1', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d', force='false', >>> secondsToWait='0', gracefully='false', reason='', ignoreNoVm='true'}), log >>> id: 560eca57 >>> 2018-02-12 16:46:41,650+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.vdsbroker.DestroyVDSCommand] (ForkJoinPool-1-worker-11) [] FINISH, >>> DestroyVDSCommand, log id: 560eca57 >>> 2018-02-12 16:46:41,650+01 INFO >>> [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] >>> (ForkJoinPool-1-worker-11) [] VM >>> '3f57e669-5e4c-4d10-85cc-d573004a099d'(Oracle_SECONDARY) >>> moved from 'MigratingFrom' --> 'Down' >>> 2018-02-12 16:46:41,651+01 INFO >>> [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] >>> (ForkJoinPool-1-worker-11) [] Handing over VM >>> '3f57e669-5e4c-4d10-85cc-d573004a099d'(Oracle_SECONDARY) >>> to Host 'd569c2dd-8f30-4878-8aea-858db285cf69'. Setting VM to status >>> 'MigratingTo' >>> 2018-02-12 16:46:42,163+01 INFO >>> [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] >>> (ForkJoinPool-1-worker-4) [] VM >>> '3f57e669-5e4c-4d10-85cc-d573004a099d'(Oracle_SECONDARY) >>> moved from 'MigratingTo' --> 'Up' >>> 2018-02-12 16:46:42,169+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.vdsbroker.MigrateStatusVDSCommand] (ForkJoinPool-1-worker-4) [] >>> START, MigrateStatusVDSCommand(HostName = ginger.local.systea.fr, >>> MigrateStatusVDSCommandParameters:{runAsync='true', >>> hostId='d569c2dd-8f30-4878-8aea-858db285cf69', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}), log id: 7a25c281 >>> 2018-02-12 16:46:42,174+01 INFO [org.ovirt.engine.core.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_ID: VM_MIGRATION_DONE(63), Correlation ID: >>> 2f712024-5982-46a8-82c8-fd8293da5725, Job ID: >>> 4bd19aa9-cc99-4d02-884e-5a1e857a7738, Call Stack: null, Custom ID: >>> null, Custom Event ID: -1, Message: Migration completed (VM: >>> Oracle_SECONDARY, Source: victor.local.systea.fr, Destination: >>> ginger.local.systea.fr, Duration: 11 seconds, Total: 11 seconds, Actual >>> downtime: (N/A)) >>> 2018-02-12 16:46:42,201+01 INFO >>> [org.ovirt.engine.core.bll.MigrateVmToServerCommand] >>> (ForkJoinPool-1-worker-4) [] Lock freed to object >>> 'EngineLock:{exclusiveLocks='[3f57e669-5e4c-4d10-85cc-d573004a099d=VM]', >>> sharedLocks=''}' >>> 2018-02-12 16:46:42,203+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.vdsbroker.FullListVDSCommand] (ForkJoinPool-1-worker-4) [] START, >>> FullListVDSCommand(HostName = ginger.local.systea.fr, >>> FullListVDSCommandParameters:{runAsync='true', >>> hostId='d569c2dd-8f30-4878-8aea-858db285cf69', >>> vmIds='[3f57e669-5e4c-4d10-85cc-d573004a099d]'}), log id: 7cc65298 >>> 2018-02-12 16:46:42,254+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.vdsbroker.FullListVDSCommand] (ForkJoinPool-1-worker-4) [] FINISH, >>> FullListVDSCommand, return: [{acpiEnable=true, >>> emulatedMachine=pc-i440fx-rhel7.3.0, afterMigrationStatus=, >>> tabletEnable=true, pid=18748, guestDiskMapping={}, >>> transparentHugePages=true, timeOffset=0, cpuType=Nehalem, smp=2, >>> guestNumaNodes=[Ljava.lang.Object;@760085fd, >>> custom={device_fbddd528-7d93-49c6-a286-180e021cb274device_87 >>> 9c93ab-4df1-435c-af02-565039fcc254=VmDevice:{id='VmDeviceId: >>> {deviceId='879c93ab-4df1-435c-af02-565039fcc254', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', device='unix', >>> type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, >>> controller=0, type=virtio-serial, port=1}', managed='false', >>> plugged='true', readOnly='false', deviceAlias='channel0', >>> customProperties='[]', snapshotId='null', logicalName='null', >>> hostDevice='null'}, device_fbddd528-7d93-49c6-a286 >>> -180e021cb274device_879c93ab-4df1-435c-af02-565039fcc254devi >>> ce_8945f61a-abbe-4156-8485-a4aa6f1908dbdevice_017b5e59-01c4- >>> 4aac-bf0c-b5d9557284d6=VmDevice:{id='VmDeviceId:{deviceId='0 >>> 17b5e59-01c4-4aac-bf0c-b5d9557284d6', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', >>> device='tablet', type='UNKNOWN', bootOrder='0', specParams='[]', >>> address='{bus=0, type=usb, port=1}', managed='false', plugged='true', >>> readOnly='false', deviceAlias='input0', customProperties='[]', >>> snapshotId='null', logicalName='null', hostDevice='null'}, >>> device_fbddd528-7d93-49c6-a286-180e021cb274=VmDevice:{id='Vm >>> DeviceId:{deviceId='fbddd528-7d93-49c6-a286-180e021cb274', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', device='ide', >>> type='CONTROLLER', bootOrder='0', specParams='[]', address='{slot=0x01, >>> bus=0x00, domain=0x0000, type=pci, function=0x1}', managed='false', >>> plugged='true', readOnly='false', deviceAlias='ide', customProperties='[]', >>> snapshotId='null', logicalName='null', hostDevice='null'}, >>> device_fbddd528-7d93-49c6-a286-180e021cb274device_879c93ab-4 >>> df1-435c-af02-565039fcc254device_8945f61a-abbe-4156-8485-a4a >>> a6f1908db=VmDevice:{id='VmDeviceId:{deviceId='8945f61a-abbe-4156-8485-a4aa6f1908db', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', device='unix', >>> type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, >>> controller=0, type=virtio-serial, port=2}', managed='false', >>> plugged='true', readOnly='false', deviceAlias='channel1', >>> customProperties='[]', snapshotId='null', logicalName='null', >>> hostDevice='null'}}, vmType=kvm, memSize=8192, smpCoresPerSocket=1, >>> vmName=Oracle_SECONDARY, nice=0, status=Up, maxMemSize=32768, >>> bootMenuEnable=false, vmId=3f57e669-5e4c-4d10-85cc-d573004a099d, >>> numOfIoThreads=2, smpThreadsPerCore=1, smartcardEnable=false, >>> maxMemSlots=16, kvmEnable=true, pitReinjection=false, >>> displayNetwork=ovirtmgmt, devices=[Ljava.lang.Object;@2e4d3dd3, >>> memGuaranteedSize=8192, maxVCpus=16, clientIp=, statusTime=4304259600 >>> <(430)%20425-9600>, display=vnc}], log id: 7cc65298 >>> 2018-02-12 16:46:42,257+01 INFO [org.ovirt.engine.core.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=vnc, specParams={displayNetwork=ovirtmgmt, keyMap=fr, >>> displayIp=192.168.0.5}, type=graphics, >>> deviceId=813957b1-446a-4e88-9e40-9fe76d2c442d, >>> port=5901} >>> 2018-02-12 16:46:42,257+01 INFO [org.ovirt.engine.core.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_id=3f57e669-5e4c-4d10-85cc-d573004a099d, >>> sd_id=1e51cecc-eb2e-47d0-b185-920fdc7afa16, >>> deviceId={uuid=a09949aa-5642-4b6d-94a4-8b0d04257be5}, offset=6291456, >>> device=lease, path=/rhev/data-center/mnt/glusterSD/192.168.0.6: >>> _DATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom_md/xleases, type=lease} >>> 2018-02-12 16:46:46,260+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.vdsbroker.FullListVDSCommand] (DefaultQuartzScheduler5) [7fcb200a] >>> FINISH, FullListVDSCommand, return: [{acpiEnable=true, >>> emulatedMachine=pc-i440fx-rhel7.3.0, afterMigrationStatus=, >>> tabletEnable=true, pid=18748, guestDiskMapping={0QEMU_QEMU_H >>> ARDDISK_d890fa68-fba4-4f49-9={name=/dev/sda}, >>> QEMU_DVD-ROM_QM00003={name=/dev/sr0}}, transparentHugePages=true, >>> timeOffset=0, cpuType=Nehalem, smp=2, guestNumaNodes=[Ljava.lang.Obj >>> ect;@77951faf, custom={device_fbddd528-7d93-4 >>> 9c6-a286-180e021cb274device_879c93ab-4df1-435c-af02-565039fc >>> c254=VmDevice:{id='VmDeviceId:{deviceId='879c93ab-4df1-435c-af02-565039fcc254', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', device='unix', >>> type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, >>> controller=0, type=virtio-serial, port=1}', managed='false', >>> plugged='true', readOnly='false', deviceAlias='channel0', >>> customProperties='[]', snapshotId='null', logicalName='null', >>> hostDevice='null'}, device_fbddd528-7d93-49c6-a286 >>> -180e021cb274device_879c93ab-4df1-435c-af02-565039fcc254devi >>> ce_8945f61a-abbe-4156-8485-a4aa6f1908dbdevice_017b5e59-01c4- >>> 4aac-bf0c-b5d9557284d6=VmDevice:{id='VmDeviceId:{deviceId='0 >>> 17b5e59-01c4-4aac-bf0c-b5d9557284d6', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', >>> device='tablet', type='UNKNOWN', bootOrder='0', specParams='[]', >>> address='{bus=0, type=usb, port=1}', managed='false', plugged='true', >>> readOnly='false', deviceAlias='input0', customProperties='[]', >>> snapshotId='null', logicalName='null', hostDevice='null'}, >>> device_fbddd528-7d93-49c6-a286-180e021cb274=VmDevice:{id='Vm >>> DeviceId:{deviceId='fbddd528-7d93-49c6-a286-180e021cb274', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', device='ide', >>> type='CONTROLLER', bootOrder='0', specParams='[]', address='{slot=0x01, >>> bus=0x00, domain=0x0000, type=pci, function=0x1}', managed='false', >>> plugged='true', readOnly='false', deviceAlias='ide', customProperties='[]', >>> snapshotId='null', logicalName='null', hostDevice='null'}, >>> device_fbddd528-7d93-49c6-a286-180e021cb274device_879c93ab-4 >>> df1-435c-af02-565039fcc254device_8945f61a-abbe-4156-8485-a4a >>> a6f1908db=VmDevice:{id='VmDeviceId:{deviceId='8945f61a-abbe-4156-8485-a4aa6f1908db', >>> vmId='3f57e669-5e4c-4d10-85cc-d573004a099d'}', device='unix', >>> type='CHANNEL', bootOrder='0', specParams='[]', address='{bus=0, >>> controller=0, type=virtio-serial, port=2}', managed='false', >>> plugged='true', readOnly='false', deviceAlias='channel1', >>> customProperties='[]', snapshotId='null', logicalName='null', >>> hostDevice='null'}}, vmType=kvm, memSize=8192, smpCoresPerSocket=1, >>> vmName=Oracle_SECONDARY, nice=0, status=Up, maxMemSize=32768, >>> bootMenuEnable=false, vmId=3f57e669-5e4c-4d10-85cc-d573004a099d, >>> numOfIoThreads=2, smpThreadsPerCore=1, smartcardEnable=false, >>> maxMemSlots=16, kvmEnable=true, pitReinjection=false, >>> displayNetwork=ovirtmgmt, devices=[Ljava.lang.Object;@286410fd, >>> memGuaranteedSize=8192, maxVCpus=16, clientIp=, statusTime=4304263620 >>> <(430)%20426-3620>, display=vnc}], log id: 58cdef4c >>> 2018-02-12 16:46:46,267+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler5) >>> [7fcb200a] Received a vnc Device without an address when processing VM >>> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping device: >>> {device=vnc, specParams={displayNetwork=ovirtmgmt, keyMap=fr, >>> displayIp=192.168.0.5}, type=graphics, >>> deviceId=813957b1-446a-4e88-9e40-9fe76d2c442d, >>> port=5901} >>> 2018-02-12 16:46:46,268+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.monitoring.VmDevicesMonitoring] (DefaultQuartzScheduler5) >>> [7fcb200a] Received a lease Device without an address when processing VM >>> 3f57e669-5e4c-4d10-85cc-d573004a099d devices, skipping device: >>> {lease_id=3f57e669-5e4c-4d10-85cc-d573004a099d, >>> sd_id=1e51cecc-eb2e-47d0-b185-920fdc7afa16, >>> deviceId={uuid=a09949aa-5642-4b6d-94a4-8b0d04257be5}, offset=6291456, >>> device=lease, path=/rhev/data-center/mnt/glusterSD/192.168.0.6: >>> _DATA01/1e51cecc-eb2e-47d0-b185-920fdc7afa16/dom_md/xleases, type=lease} >>> >>> >>> >>> >>> For the VM with 2 vdisks we see : >>> >>> 2018-02-12 16:49:06,112+01 INFO >>> [org.ovirt.engine.core.bll.MigrateVmToServerCommand] >>> (default task-50) [92b5af33-cb87-4142-b8fe-8b838dd7458e] Lock Acquired >>> to object >>> 'EngineLock:{exclusiveLocks='[f7d4ec12-627a-4b83-b59e-886400d55474=VM]', >>> sharedLocks=''}' >>> 2018-02-12 16:49:06,407+01 INFO >>> [org.ovirt.engine.core.bll.MigrateVmToServerCommand] >>> (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4142-b8fe-8b838dd7458e] >>> Running command: MigrateVmToServerCommand internal: false. Entities >>> affected : ID: f7d4ec12-627a-4b83-b59e-886400d55474 Type: VMAction >>> group MIGRATE_VM with role type USER >>> 2018-02-12 16:49:06,712+01 INFO >>> [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand] >>> (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4142-b8fe-8b838dd7458e] >>> START, MigrateVDSCommand( MigrateVDSCommandParameters:{runAsync='true', >>> hostId='d569c2dd-8f30-4878-8aea-858db285cf69', >>> vmId='f7d4ec12-627a-4b83-b59e-886400d55474', srcHost='192.168.0.5', >>> dstVdsId='ce3938b1-b23f-4d22-840a-f17d7cd87bb1', dstHost=' >>> 192.168.0.6:54321', migrationMethod='ONLINE', tunnelMigration='false', >>> migrationDowntime='0', autoConverge='true', migrateCompressed='false', >>> consoleAddress='null', maxBandwidth='500', enableGuestEvents='true', >>> maxIncomingMigrations='2', maxOutgoingMigrations='2', >>> convergenceSchedule='[init=[{name=setDowntime, params=[100]}], >>> stalling=[{limit=1, action={name=setDowntime, params=[150]}}, {limit=2, >>> action={name=setDowntime, params=[200]}}, {limit=3, >>> action={name=setDowntime, params=[300]}}, {limit=4, >>> action={name=setDowntime, params=[400]}}, {limit=6, >>> action={name=setDowntime, params=[500]}}, {limit=-1, action={name=abort, >>> params=[]}}]]'}), log id: 3702a9e0 >>> 2018-02-12 16:49:06,713+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-thread-49) >>> [92b5af33-cb87-4142-b8fe-8b838dd7458e] START, >>> MigrateBrokerVDSCommand(HostName = ginger.local.systea.fr, >>> MigrateVDSCommandParameters:{runAsync='true', >>> hostId='d569c2dd-8f30-4878-8aea-858db285cf69', >>> vmId='f7d4ec12-627a-4b83-b59e-886400d55474', srcHost='192.168.0.5', >>> dstVdsId='ce3938b1-b23f-4d22-840a-f17d7cd87bb1', dstHost=' >>> 192.168.0.6:54321', migrationMethod='ONLINE', tunnelMigration='false', >>> migrationDowntime='0', autoConverge='true', migrateCompressed='false', >>> consoleAddress='null', maxBandwidth='500', enableGuestEvents='true', >>> maxIncomingMigrations='2', maxOutgoingMigrations='2', >>> convergenceSchedule='[init=[{name=setDowntime, params=[100]}], >>> stalling=[{limit=1, action={name=setDowntime, params=[150]}}, {limit=2, >>> action={name=setDowntime, params=[200]}}, {limit=3, >>> action={name=setDowntime, params=[300]}}, {limit=4, >>> action={name=setDowntime, params=[400]}}, {limit=6, >>> action={name=setDowntime, params=[500]}}, {limit=-1, action={name=abort, >>> params=[]}}]]'}), log id: 1840069c >>> 2018-02-12 16:49:06,724+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.vdsbroker.MigrateBrokerVDSCommand] (org.ovirt.thread.pool-6-thread-49) >>> [92b5af33-cb87-4142-b8fe-8b838dd7458e] FINISH, MigrateBrokerVDSCommand, >>> log id: 1840069c >>> 2018-02-12 16:49:06,732+01 INFO >>> [org.ovirt.engine.core.vdsbroker.MigrateVDSCommand] >>> (org.ovirt.thread.pool-6-thread-49) [92b5af33-cb87-4142-b8fe-8b838dd7458e] >>> FINISH, MigrateVDSCommand, return: MigratingFrom, log id: 3702a9e0 >>> 2018-02-12 16:49:06,753+01 INFO [org.ovirt.engine.core.dal.db >>> broker.auditloghandling.AuditLogDirector] >>> (org.ovirt.thread.pool-6-thread-49) >>> [92b5af33-cb87-4142-b8fe-8b838dd7458e] EVENT_ID: >>> VM_MIGRATION_START(62), Correlation ID: >>> 92b5af33-cb87-4142-b8fe-8b838dd7458e, >>> Job ID: f4f54054-f7c8-4481-8eda-d5a15c383061, Call Stack: null, Custom >>> ID: null, Custom Event ID: -1, Message: Migration started (VM: >>> Oracle_PRIMARY, Source: ginger.local.systea.fr, Destination: >>> victor.local.systea.fr, User: admin@internal-authz). >>> ... >>> 2018-02-12 16:49:16,453+01 INFO [org.ovirt.engine.core.vdsbro >>> ker.monitoring.VmsStatisticsFetcher] (DefaultQuartzScheduler4) >>> [162a5bc3] Fetched 2 VMs from VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1' >>> 2018-02-12 16:49:16,455+01 INFO >>> [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] >>> (DefaultQuartzScheduler4) [162a5bc3] VM >>> 'f7d4ec12-627a-4b83-b59e-886400d55474'(Oracle_PRIMARY) >>> was unexpectedly detected as 'MigratingTo' on VDS >>> 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(victor.local.systea.fr) >>> (expected on 'd569c2dd-8f30-4878-8aea-858db285cf69') >>> 2018-02-12 16:49:16,455+01 INFO >>> [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] >>> (DefaultQuartzScheduler4) [162a5bc3] VM >>> 'f7d4ec12-627a-4b83-b59e-886400d55474' >>> is migrating to VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'( >>> victor.local.systea.fr) ignoring it in the refresh until migration is >>> done >>> ... >>> 2018-02-12 16:49:31,484+01 INFO >>> [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] >>> (DefaultQuartzScheduler5) [11a7619a] VM >>> 'f7d4ec12-627a-4b83-b59e-886400d55474'(Oracle_PRIMARY) >>> was unexpectedly detected as 'MigratingTo' on VDS >>> 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'(victor.local.systea.fr) >>> (expected on 'd569c2dd-8f30-4878-8aea-858db285cf69') >>> 2018-02-12 16:49:31,484+01 INFO >>> [org.ovirt.engine.core.vdsbroker.monitoring.VmAnalyzer] >>> (DefaultQuartzScheduler5) [11a7619a] VM >>> 'f7d4ec12-627a-4b83-b59e-886400d55474' >>> is migrating to VDS 'ce3938b1-b23f-4d22-840a-f17d7cd87bb1'( >>> victor.local.systea.fr) ignoring it in the refresh until migration is >>> done >>> >>> >>> >>> and so on, last lines repeated indefinitly for hours since we poweroff >>> the VM... >>> Is this something known ? Any idea about that ? >>> >>> Thanks >>> >>> Ovirt 4.1.6, updated last at feb-13. Gluster 3.12.1. >>> >>> -- >>> >>> Cordialement, >>> >>> *Frank Soyer * >>> >>> _______________________________________________ >>> Users mailing list >>> Users@ovirt.org >>> http://lists.ovirt.org/mailman/listinfo/users >>> >> >> >> >> > > >
_______________________________________________ Users mailing list Users@ovirt.org http://lists.ovirt.org/mailman/listinfo/users