9:30 a.m.
Hello all,
since we updated our Commvault to the version "service pack 26 hotfix 16",
random VM backups are failing to attach disk snapshots to the backup proxy VM.
We are running oVirt Version 4.4.10.6-1.el8 and the hypervisor is oVirt Node 4.4.9.
These are the logs from the managerVM:
##############
2022-03-24 11:13:59,390+01 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugDiskVDSCommand] (default task-1578)
[0aeb5794-5c2e-44c6-8fc5-34ec0e81d16b] Disk hot-plug: <?xml version="1.0"
encoding="UTF-8"?><hotplug>
<devices>
<disk snapshot="no" type="file" device="disk">
<target dev="sda" bus="scsi"/>
<source
file="/rhev/data-center/mnt/blockSD/6da85fb1-ff4b-4665-ade3-0f32f83250bc/images/e3c292e0-dfd2-4cd5-a27f-f87308a18e64/8b524896-902c-445f-a33a-65335cb75eff">
<seclabel model="dac" type="none"
relabel="no"/>
</source>
<driver name="qemu" io="threads" type="qcow2"
error_policy="stop" cache="writethrough"/>
<alias name="ua-e3c292e0-dfd2-4cd5-a27f-f87308a18e64"/>
<address bus="0" controller="0" unit="0"
type="drive" target="0"/>
<serial>e3c292e0-dfd2-4cd5-a27f-f87308a18e64</serial>
</disk>
</devices>
<metadata xmlns:ovirt-vm="http://ovirt.org/vm/1.0">
<ovirt-vm:vm>
<ovirt-vm:device devtype="disk" name="sda">
<ovirt-vm:poolID>98d981da-d010-11ea-9e4d-00163e1be424</ovirt-vm:poolID>
<ovirt-vm:volumeID>8b524896-902c-445f-a33a-65335cb75eff</ovirt-vm:volumeID>
<ovirt-vm:shared>transient</ovirt-vm:shared>
<ovirt-vm:imageID>e3c292e0-dfd2-4cd5-a27f-f87308a18e64</ovirt-vm:imageID>
<ovirt-vm:domainID>6da85fb1-ff4b-4665-ade3-0f32f83250bc</ovirt-vm:domainID>
</ovirt-vm:device>
</ovirt-vm:vm>
</metadata>
</hotplug>
2022-03-24 11:13:59,898+01 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugDiskVDSCommand] (default task-1578)
[0aeb5794-5c2e-44c6-8fc5-34ec0e81d16b] Failed in 'HotPlugDiskVDS' method
2022-03-24 11:13:59,898+01 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugDiskVDSCommand] (default task-1578)
[0aeb5794-5c2e-44c6-8fc5-34ec0e81d16b] Command
'org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugDiskVDSCommand' return value
'StatusOnlyReturn [status=Status [code=45, message=Requested operation is not valid:
Domain already contains a disk with that address]]'
2022-03-24 11:13:59,898+01 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugDiskVDSCommand] (default task-1578)
[0aeb5794-5c2e-44c6-8fc5-34ec0e81d16b] HostName = hypervisor1.domain
2022-03-24 11:13:59,898+01 ERROR
[org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugDiskVDSCommand] (default task-1578)
[0aeb5794-5c2e-44c6-8fc5-34ec0e81d16b] Command 'HotPlugDiskVDSCommand(HostName =
hypervisor1.domain,
HotPlugDiskVDSParameters:{hostId='c2fd81cd-8fc8-410e-8333-a0a36b87ab2b',
vmId='890c105d-333b-435e-8d8b-0b889f4f9c14',
diskId='e3c292e0-dfd2-4cd5-a27f-f87308a18e64'})' execution failed:
VDSGenericException: VDSErrorException: Failed to HotPlugDiskVDS, error = Requested
operation is not valid: Domain already contains a disk with that address, code = 45
2022-03-24 11:13:59,898+01 INFO
[org.ovirt.engine.core.vdsbroker.vdsbroker.HotPlugDiskVDSCommand] (default task-1578)
[0aeb5794-5c2e-44c6-8fc5-34ec0e81d16b] FINISH, HotPlugDiskVDSCommand, return: , log id:
536a4414
2022-03-24 11:13:59,898+01 ERROR
[org.ovirt.engine.core.bll.storage.disk.AttachDiskToVmCommand] (default task-1578)
[0aeb5794-5c2e-44c6-8fc5-34ec0e81d16b] Command
'org.ovirt.engine.core.bll.storage.disk.AttachDiskToVmCommand' failed:
EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException:
VDSGenericException: VDSErrorException: Failed to HotPlugDiskVDS, error = Requested
operation is not valid: Domain already contains a disk with that address, code = 45
(Failed with error FailedToPlugDisk and code 45)
2022-03-24 11:13:59,899+01 INFO [org.ovirt.engine.core.bll.CommandCompensator] (default
task-1578) [0aeb5794-5c2e-44c6-8fc5-34ec0e81d16b] Command
[id=87712152-4660-40ca-b292-397796c735d5]: Compensating NEW_ENTITY_ID of
org.ovirt.engine.core.common.businessentities.storage.DiskVmElement; snapshot:
VmDeviceId:{deviceId='e3c292e0-dfd2-4cd5-a27f-f87308a18e64',
vmId='890c105d-333b-435e-8d8b-0b889f4f9c14'}.
2022-03-24 11:13:59,900+01 INFO [org.ovirt.engine.core.bll.CommandCompensator] (default
task-1578) [0aeb5794-5c2e-44c6-8fc5-34ec0e81d16b] Command
[id=87712152-4660-40ca-b292-397796c735d5]: Compensating NEW_ENTITY_ID of
org.ovirt.engine.core.common.businessentities.VmDevice; snapshot:
VmDeviceId:{deviceId='e3c292e0-dfd2-4cd5-a27f-f87308a18e64',
vmId='890c105d-333b-435e-8d8b-0b889f4f9c14'}.
2022-03-24 11:13:59,910+01 ERROR
[org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (default task-1578)
[0aeb5794-5c2e-44c6-8fc5-34ec0e81d16b] EVENT_ID: USER_FAILED_ATTACH_DISK_TO_VM(2,017),
Failed to attach Disk VM1_Disk1 to VM backupproxyVM (User: backupagent@internal-authz).
2022-03-24 11:13:59,910+01 INFO
[org.ovirt.engine.core.bll.storage.disk.AttachDiskToVmCommand] (default task-1578)
[0aeb5794-5c2e-44c6-8fc5-34ec0e81d16b] Lock freed to object
'EngineLock:{exclusiveLocks='[e3c292e0-dfd2-4cd5-a27f-f87308a18e64=DISK]',
sharedLocks=''}'
2022-03-24 11:13:59,910+01 ERROR
[org.ovirt.engine.api.restapi.resource.AbstractBackendResource] (default task-1578) []
Operation Failed: [Failed to hot-plug disk]
###################
Here are the logs from the hypervisor:
##################
2022-03-24 11:13:59,712+0100 INFO (jsonrpc/4) [virt.vm]
(vmId='890c105d-333b-435e-8d8b-0b889f4f9c14') Hotplug disk xml: <?xml
version='1.0' encoding='utf-8'?>
<disk device="disk" snapshot="no" type="file">
<address bus="0" controller="0" target="0"
type="drive" unit="0" />
<source
file="/var/lib/vdsm/transient/6da85fb1-ff4b-4665-ade3-0f32f83250bc-8b524896-902c-445f-a33a-65335cb75eff.pxhtm0_4">
<seclabel model="dac" relabel="no" type="none"
/>
</source>
<target bus="scsi" dev="sdbzk" />
<serial>e3c292e0-dfd2-4cd5-a27f-f87308a18e64</serial>
<driver cache="writethrough" error_policy="stop"
io="threads" name="qemu" type="qcow2" />
<alias name="ua-e3c292e0-dfd2-4cd5-a27f-f87308a18e64" />
</disk>
(vm:3851)
2022-03-24 11:13:59,721+0100 ERROR (jsonrpc/4) [virt.vm]
(vmId='890c105d-333b-435e-8d8b-0b889f4f9c14') Hotplug failed (vm:3859)
Traceback (most recent call last):
File "/usr/lib/python3.6/site-packages/vdsm/virt/vm.py", line 3857, in
hotplugDisk
self._dom.attachDevice(driveXml)
File "/usr/lib/python3.6/site-packages/vdsm/virt/virdomain.py", line 101, in
f
ret = attr(*args, **kwargs)
File "/usr/lib/python3.6/site-packages/vdsm/common/libvirtconnection.py", line
131, in wrapper
ret = f(*args, **kwargs)
File "/usr/lib/python3.6/site-packages/vdsm/common/function.py", line 94, in
wrapper
return func(inst, *args, **kwargs)
File "/usr/lib64/python3.6/site-packages/libvirt.py", line 682, in
attachDevice
raise libvirtError('virDomainAttachDevice() failed')
libvirt.libvirtError: Requested operation is not valid: Domain already contains a disk
with that address
#####################
Any idea what could cause these errors?
Best regards,
Martin