OLVM: Unable to Migrate VMs to KVM Host (Doc ID 2906791.1)

Last updated on MAY 31, 2024

Applies to:

Symptoms

A KVM Host does not accept any migration of VMs to it. The migration fails and reports the errors as mentioned in the following logs

Engine Log :

2022-10-26 10:43:51,616+11 ERROR [org.ovirt.engine.core.vdsbroker.monitoring.VmsMonitoring] (ForkJoinPool-1-worker-6) [] Rerun VM 'd427d99e-3c5d-49d5-a0bf-5afbbdb44f29'. Called from VDS 'test01.test.local'
2022-10-26 10:43:51,660+11 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (EE-ManagedThreadFactory-engine-Thread-148346) [] START, MigrateStatusVDSCommand(HostName = test01.test.local, MigrateStatusVDSCommandParameters:{hostId='a4603c63-5f33-48bb-8a3a-69b18dcfee92', vmId='d427d99e-3c5d-49d5-a0bf-5afbbdb44f29'}), log id: 287d0924
2022-10-26 10:43:51,662+11 INFO [org.ovirt.engine.core.vdsbroker.vdsbroker.MigrateStatusVDSCommand] (EE-ManagedThreadFactory-engine-Thread-148346) [] FINISH, MigrateStatusVDSCommand, return: , log id: 287d0924
2022-10-26 10:43:51,668+11 WARN [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engine-Thread-148346) [] EVENT_ID: VM_MIGRATION_TRYING_RERUN(128), Failed to migrate VM testvm to Host test07.test.local . Trying to migrate to another Host.

Source KVM Host vdsm log :

2022-10-26 10:43:48,883+1100 INFO (jsonrpc/2) [api.virt] FINISH migrate return={'status': {'message': 'Migration in progress', 'code': 0}, 'progress': 0} from=::ffff:10.144.6.50,42596, flow_id=57c29c1a-8cbe-4f78-bd2e-3e1a66e7da1a, vmId=d427d99e-3c5d-49d5-a0bf-xxxxxxxxxxxx (api:54)
2022-10-26 10:43:48,883+1100 INFO (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call VM.migrate succeeded in 0.00 seconds (__init__:312)
2022-10-26 10:43:48,908+1100 INFO (migsrc/d427d99e) [virt.vm] (vmId='d427d99e-3c5d-49d5-a0bf-xxxxxxxxxxxx') Migration semaphore: acquiring (migration:407)
2022-10-26 10:43:48,908+1100 INFO (migsrc/d427d99e) [virt.vm] (vmId='d427d99e-3c5d-49d5-a0bf-xxxxxxxxxxxx') Migration semaphore: acquired (migration:409)
2022-10-26 10:43:49,698+1100 INFO (migsrc/d427d99e) [virt.vm] (vmId='d427d99e-3c5d-49d5-a0bf-xxxxxxxxxxxx') Creation of destination VM took: 0 seconds (migration:469)
2022-10-26 10:43:49,698+1100 INFO (migsrc/d427d99e) [virt.vm] (vmId='d427d99e-3c5d-49d5-a0bf-xxxxxxxxxxxx') starting migration to qemu+tls://test07.test.local/system with miguri tcp://10.144.6.57 (migration:498)
2022-10-26 10:43:50,544+1100 INFO (jsonrpc/7) [api.virt] START getStats() from=::1,54764, vmId=84dd5ae7-3a8e-4df2-aa2d-xxxxxxxxxxxx (api:48)
2022-10-26 10:43:50,544+1100 INFO (jsonrpc/7) [api] FINISH getStats error=Virtual machine does not exist: {'vmId': u'84dd5ae7-3a8e-4df2-aa2d-xxxxxxxxxxxx'} (api:129)
2022-10-26 10:43:50,544+1100 INFO (jsonrpc/7) [api.virt] FINISH getStats return={'status': {'message': "Virtual machine does not exist: {'vmId': u'84dd5ae7-3a8e-4df2-aa2d-xxxxxxxxxxxx'}", 'code': 1}} from=::1,54764, vmId=84dd5ae7-3a8e-4df2-aa2d-xxxxxxxxxxxx (api:54)
2022-10-26 10:43:50,544+1100 INFO (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call VM.getStats failed (error 1) in 0.00 seconds (__init__:312)
2022-10-26 10:43:51,003+1100 ERROR (migsrc/d427d99e) [virt.vm] (vmId='d427d99e-3c5d-49d5-a0bf-xxxxxxxxxxxx') internal error: qemu unexpectedly closed the monitor (migration:282)
2022-10-26 10:43:51,613+1100 ERROR (migsrc/d427d99e) [virt.vm] (vmId='d427d99e-3c5d-49d5-a0bf-xxxxxxxxxxxx') Failed to migrate (migration:450)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/virt/migration.py", line 431, in _regular_run
time.time(), migrationParams, machineParams
File "/usr/lib/python2.7/site-packages/vdsm/virt/migration.py", line 505, in _startUnderlyingMigration
self._perform_with_conv_schedule(duri, muri)
File "/usr/lib/python2.7/site-packages/vdsm/virt/migration.py", line 591, in _perform_with_conv_schedule
self._perform_migration(duri, muri)
File "/usr/lib/python2.7/site-packages/vdsm/virt/migration.py", line 525, in _perform_migration
self._migration_flags)
File "/usr/lib/python2.7/site-packages/vdsm/virt/virdomain.py", line 100, in f
ret = attr(*args, **kwargs)
File "/usr/lib/python2.7/site-packages/vdsm/common/libvirtconnection.py", line 131, in wrapper
ret = f(*args, **kwargs)
File "/usr/lib/python2.7/site-packages/vdsm/common/function.py", line 94, in wrapper
return func(inst, *args, **kwargs)
File "/usr/lib64/python2.7/site-packages/libvirt.py", line 1858, in migrateToURI3
if ret == -1: raise libvirtError ('virDomainMigrateToURI3() failed', dom=self)
libvirtError: internal error: qemu unexpectedly closed the monitor

Destination KVM Host :

2022-10-26 10:43:48,933+1100 INFO (vm/d427d99e) [virt.vm] (vmId='d427d99e-3c5d-49d5-a0bf-xxxxxxxxxxxx') VM wrapper has started (vm:2786)
2022-10-26 10:43:48,934+1100 INFO (vm/d427d99e) [vdsm.api] START getVolumeSize(sdUUID='4695103e-fd7f-48ad-8a99-620f98b2b14d', spUUID='398d792e-9077-11ec-9911-00163e7a89b5', imgUUID='abf972d5-cf76-4248-9dec-xxxxxxxxxxxx', volUUID='daa02328-8c5e-4b6b-8c7d-xxxxxxxxxxxx', options=None) from=internal, task_id=60c4beb5-d487-41e4-a601-34868fbe0cc2 (api:48)
2022-10-26 10:43:48,935+1100 INFO (vm/d427d99e) [vdsm.api] FINISH getVolumeSize return={'truesize': '53687091200', 'apparentsize': '53687091200'} from=internal, task_id=60c4beb5-d487-41e4-a601-34868fbe0cc2 (api:54)
2022-10-26 10:43:48,935+1100 INFO (vm/d427d99e) [vds] prepared volume path: (clientIF:510)
2022-10-26 10:43:48,935+1100 INFO (vm/d427d99e) [vdsm.api] START prepareImage(sdUUID='4695103e-fd7f-48ad-8a99-620f98b2b14d', spUUID='398d792e-9077-11ec-9911-00163e7a89b5', imgUUID='abf972d5-cf76-4248-9dec-xxxxxxxxxxxx', leafUUID='daa02328-8c5e-4b6b-8c7d-xxxxxxxxxxxx', allowIllegal=False) from=internal, task_id=54edee55-3110-4b4d-adfd-4108b099b8bc (api:48)
2022-10-26 10:43:49,111+1100 INFO (vm/d427d99e) [storage.LVM] Activating lvs: vg=4695103e-fd7f-48ad-8a99-620f98b2b14d lvs=['daa02328-8c5e-4b6b-8c7d-xxxxxxxxxxxx'] (lvm:1608)
2022-10-26 10:43:49,254+1100 INFO (vm/d427d99e) [storage.StorageDomain] Creating image run directory '/var/run/vdsm/storage/4695103e-fd7f-48ad-8a99-620f98b2b14d/abf972d5-cf76-4248-9dec-xxxxxxxxxxxx' (blockSD:1461)
2022-10-26 10:43:49,254+1100 INFO (vm/d427d99e) [storage.fileUtils] Creating directory: /var/run/vdsm/storage/4695103e-fd7f-48ad-8a99-620f98b2b14d/abf972d5-cf76-4248-9dec-xxxxxxxxxxxx mode: None (fileUtils:199)
2022-10-26 10:43:49,254+1100 INFO (vm/d427d99e) [storage.StorageDomain] Creating symlink from /dev/4695103e-fd7f-48ad-8a99-620f98b2b14d/daa02328-8c5e-4b6b-8c7d-xxxxxxxxxxxx to /var/run/vdsm/storage/4695103e-fd7f-48ad-8a99-620f98b2b14d/abf972d5-cf76-4248-9dec-xxxxxxxxxxxx/daa02328-8c5e-4b6b-8c7d-xxxxxxxxxxxx (blockSD:1466)
2022-10-26 10:43:49,425+1100 INFO (vm/d427d99e) [storage.StorageDomain] Creating symlink from /var/run/vdsm/storage/4695103e-fd7f-48ad-8a99-620f98b2b14d/abf972d5-cf76-4248-9dec-xxxxxxxxxxxx to /rhev/data-center/mnt/blockSD/4695103e-fd7f-48ad-8a99-620f98b2b14d/images/abf972d5-cf76-4248-9dec-xxxxxxxxxxxx (blockSD:1431)
2022-10-26 10:43:49,426+1100 INFO (vm/d427d99e) [vdsm.api] FINISH prepareImage return={'info': {'path': '/rhev/data-center/mnt/blockSD/4695103e-fd7f-48ad-8a99-620f98b2b14d/images/abf972d5-cf76-4248-9dec-xxxxxxxxxxxx/daa02328-8c5e-4b6b-8c7d-xxxxxxxxxxxx', 'type': 'block'}, 'path': '/rhev/data-center/mnt/blockSD/4695103e-fd7f-48ad-8a99-620f98b2b14d/images/abf972d5-cf76-4248-9dec-xxxxxxxxxxxx/daa02328-8c5e-4b6b-8c7d-xxxxxxxxxxxx', 'imgVolumesInfo': [{'domainID': '4695103e-fd7f-48ad-8a99-620f98b2b14d', 'leaseOffset': 186646528, 'path': '/rhev/data-center/mnt/blockSD/4695103e-fd7f-48ad-8a99-620f98b2b14d/images/abf972d5-cf76-4248-9dec-xxxxxxxxxxxx/daa02328-8c5e-4b6b-8c7d-xxxxxxxxxxxx', 'volumeID': 'daa02328-8c5e-4b6b-8c7d-xxxxxxxxxxxx', 'leasePath': '/dev/4695103e-fd7f-48ad-8a99-620f98b2b14d/leases', 'imageID': 'abf972d5-cf76-4248-9dec-xxxxxxxxxxxx'}]} from=internal, task_id=54edee55-3110-4b4d-adfd-4108b099b8bc (api:54)
2022-10-26 10:43:49,426+1100 INFO (vm/d427d99e) [vds] prepared volume path: /rhev/data-center/mnt/blockSD/4695103e-fd7f-48ad-8a99-620f98b2b14d/images/abf972d5-cf76-4248-9dec-xxxxxxxxxxxx/daa02328-8c5e-4b6b-8c7d-xxxxxxxxxxxx (clientIF:510)
2022-10-26 10:43:49,427+1100 INFO (vm/d427d99e) [virt.vm] (vmId='d427d99e-3c5d-49d5-a0bf-xxxxxxxxxxxx') Enabling drive monitoring (drivemonitor:56)
2022-10-26 10:43:49,468+1100 ERROR (jsonrpc/3) [virt.vm] (vmId='d427d99e-3c5d-49d5-a0bf-xxxxxxxxxxxx') Alias not found for device type balloon during migration at destination host (vm:5628)

Changes

No recent changes

Cause

My Oracle Support provides customers with access to over a million knowledge articles and a vibrant support community of peers and Oracle experts.