Bug 1810143

This bug blockes QE from building the ENV's before we start the regressions tests.
As we heavily use FCP I'm marking this as an automation blocker and raising the severity.

Manual Steps for bug currently does via jenkins/ansible scripts:

1) Create DC+ cluster + create 3xstorage domains per storage flavor(FCP,ISCSI,NFS,glusterFS)
2) import imageRHEL8 infra latest ) as a template from glance.
3) copy template disk to all existing SD's -> Here we see the issue when coping the template disk to one of the FCP SD(fcp_2).

Some questions: 

1. Is fcp_2 the FCP flavor or the iSCSI flavor?
2. What exactly is the error message? According to the above log the copy process failed, but how?

2020-03-03 16:47:25,394+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-93) [] EVENT_ID: USER_COPIED_DISK_FINISHED_FAILURE(2,007), User admin@internal-authz finished with error copying disk latest-rhel-guest-image-8.1-infra to domain fcp_2.

So what does that error really mean. What process/action does fail?

(In reply to Martin Tessun from comment #3)
> Some questions: 
> 
> 1. Is fcp_2 the FCP flavor or the iSCSI flavor?
FCP, fcp_2 is the FC storage domain
> 2. What exactly is the error message? According to the above log the copy
> process failed, but how?
> 
> 2020-03-03 16:47:25,394+02 ERROR
> [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-93) []
> EVENT_ID: USER_COPIED_DISK_FINISHED_FAILURE(2,007), User
> admin@internal-authz finished with error copying disk
> latest-rhel-guest-image-8.1-infra to domain fcp_2.
> 
> So what does that error really mean. What process/action does fail?
Copying template disk to fcp_2 fails

(In reply to Evelina Shames from comment #4)
> (In reply to Martin Tessun from comment #3)
> > Some questions: 
> > 
> > 1. Is fcp_2 the FCP flavor or the iSCSI flavor?
> FCP, fcp_2 is the FC storage domain
> > 2. What exactly is the error message? According to the above log the copy
> > process failed, but how?
> > 
> > 2020-03-03 16:47:25,394+02 ERROR
> > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> > (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-93) []
> > EVENT_ID: USER_COPIED_DISK_FINISHED_FAILURE(2,007), User
> > admin@internal-authz finished with error copying disk
> > latest-rhel-guest-image-8.1-infra to domain fcp_2.
> > 
> > So what does that error really mean. What process/action does fail?
> Copying template disk to fcp_2 fails

Exactly. It fails with which error message? There are lots of reasons why copying something can fail. So the exact error message why the copy fails is relevant.

(In reply to Martin Tessun from comment #5)
> (In reply to Evelina Shames from comment #4)
> > (In reply to Martin Tessun from comment #3)
> > > Some questions: 
> > > 
> > > 1. Is fcp_2 the FCP flavor or the iSCSI flavor?
> > FCP, fcp_2 is the FC storage domain
> > > 2. What exactly is the error message? According to the above log the copy
> > > process failed, but how?
> > > 
> > > 2020-03-03 16:47:25,394+02 ERROR
> > > [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector]
> > > (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-93) []
> > > EVENT_ID: USER_COPIED_DISK_FINISHED_FAILURE(2,007), User
> > > admin@internal-authz finished with error copying disk
> > > latest-rhel-guest-image-8.1-infra to domain fcp_2.
> > > 
> > > So what does that error really mean. What process/action does fail?
> > Copying template disk to fcp_2 fails
> 
> Exactly. It fails with which error message? There are lots of reasons why
> copying something can fail. So the exact error message why the copy fails is
> relevant.


I tried again on the same environment, these are the errors from the engine:

2020-03-12 12:03:45,921+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-12) [] Failed in 'HSMGetAllTasksStatusesVDS' method
2020-03-12 12:03:45,925+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-12) [] EVENT_ID: VDS_BROKER_COMMAND_FAILURE(10,802), VDSM host_mixed_3 command HSMGetAllTasksStatusesVDS failed: value=Namespace '01_img_89998522-986f-4493-ab05-06ad7944847a' is not registered with this manager abortedcode=100
2020-03-12 12:03:45,925+02 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-12) [] Failed in 'HSMGetAllTasksStatusesVDS' method
2020-03-12 12:03:45,925+02 INFO  [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-12) [] SPMAsyncTask::PollTask: Polling task 'df69a182-e577-403c-9340-0b4c8280be3b' (Parent Command 'CreateVolumeContainer', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') returned status 'finished', result 'cleanSuccess'.
2020-03-12 12:03:45,928+02 ERROR [org.ovirt.engine.core.bll.tasks.SPMAsyncTask] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-12) [] BaseAsyncTask::logEndTaskFailure: Task 'df69a182-e577-403c-9340-0b4c8280be3b' (Parent Command 'CreateVolumeContainer', Parameters Type 'org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters') ended with failure:
-- Result: 'cleanSuccess'
-- Message: 'VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = value=Cannot create Logical Volume: 'vgname=debcf34f-cc39-4c85-bc84-93e74fa27797 lvname=89998522-986f-4493-ab05-06ad7944847a err=[\'  Logical Volume "89998522-986f-4493-ab05-06ad7944847a" already exists in volume group "debcf34f-cc39-4c85-bc84-93e74fa27797"\']' abortedcode=550, code = 550',
-- Exception: 'VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = value=Cannot create Logical Volume: 'vgname=debcf34f-cc39-4c85-bc84-93e74fa27797 lvname=89998522-986f-4493-ab05-06ad7944847a err=[\'  Logical Volume "89998522-986f-4493-ab05-06ad7944847a" already exists in volume group "debcf34f-cc39-4c85-bc84-93e74fa27797"\']' abortedcode=550, code = 550'
2020-03-12 12:03:45,934+02 ERROR [org.ovirt.engine.core.bll.storage.disk.image.CreateVolumeContainerCommand] (EE-ManagedThreadFactory-engine-Thread-281561) [9ab36fb4-585f-4bf4-8acd-ca2c97d1ed93] Ending command 'org.ovirt.engine.core.bll.storage.disk.image.CreateVolumeContainerCommand' with failure.
2020-03-12 12:03:50,231+02 ERROR [org.ovirt.engine.core.bll.storage.disk.image.CloneImageGroupVolumesStructureCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-48) [9ab36fb4-585f-4bf4-8acd-ca2c97d1ed93] Ending command 'org.ovirt.engine.core.bll.storage.disk.image.CloneImageGroupVolumesStructureCommand' with failure.
2020-03-12 12:03:50,240+02 INFO  [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-48) [9ab36fb4-585f-4bf4-8acd-ca2c97d1ed93] Command 'CopyImageGroupWithData' id: 'bb80858d-70e2-483e-8932-013b09aa03cf' child commands '[de57b9c4-a8f4-4853-9a21-3cab5f220da8]' executions were completed, status 'FAILED'
2020-03-12 12:03:51,243+02 ERROR [org.ovirt.engine.core.bll.storage.disk.image.CopyImageGroupWithDataCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-80) [9ab36fb4-585f-4bf4-8acd-ca2c97d1ed93] Ending command 'org.ovirt.engine.core.bll.storage.disk.image.CopyImageGroupWithDataCommand' with failure.
2020-03-12 12:03:52,251+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84) [9ab36fb4-585f-4bf4-8acd-ca2c97d1ed93] Command 'CopyImageGroup' id: '8ef08bd3-c7e1-43da-bfec-e6dcd47811f2' child commands '[bb80858d-70e2-483e-8932-013b09aa03cf]' executions were completed, status 'FAILED'
2020-03-12 12:03:52,251+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-84) [9ab36fb4-585f-4bf4-8acd-ca2c97d1ed93] Command 'CopyImageGroup' id: '8ef08bd3-c7e1-43da-bfec-e6dcd47811f2' Updating status to 'FAILED', The command end method logic will be executed by one of its parent commands.
2020-03-12 12:03:54,272+02 INFO  [org.ovirt.engine.core.bll.ConcurrentChildCommandsExecutionCallback] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-71) [9ab36fb4-585f-4bf4-8acd-ca2c97d1ed93] Command 'MoveOrCopyDisk' id: '3e6ffc60-ae77-4210-9a34-774a526f0572' child commands '[8ef08bd3-c7e1-43da-bfec-e6dcd47811f2]' executions were completed, status 'FAILED'
2020-03-12 12:03:55,284+02 ERROR [org.ovirt.engine.core.bll.storage.disk.MoveOrCopyDiskCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-2) [9ab36fb4-585f-4bf4-8acd-ca2c97d1ed93] Ending command 'org.ovirt.engine.core.bll.storage.disk.MoveOrCopyDiskCommand' with failure.
2020-03-12 12:03:55,296+02 ERROR [org.ovirt.engine.core.bll.storage.disk.image.CopyImageGroupCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-2) [9ab36fb4-585f-4bf4-8acd-ca2c97d1ed93] Ending command 'org.ovirt.engine.core.bll.storage.disk.image.CopyImageGroupCommand' with failure.
2020-03-12 12:03:55,302+02 INFO  [org.ovirt.engine.core.bll.storage.disk.MoveOrCopyDiskCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-2) [] Lock freed to object 'EngineLock:{exclusiveLocks='[b087a6fd-3d31-45df-a26b-a3dcb8f3c70b=DISK]', sharedLocks='[ff7370d8-792d-4a91-b130-4b51b0556958=TEMPLATE]'}'
2020-03-12 12:03:55,314+02 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-2) [] EVENT_ID: USER_COPIED_DISK_FINISHED_FAILURE(2,007), User admin@internal-authz finished with error copying disk latest-rhel-guest-image-8.1-infra to domain fcp_2.

vdsm:
2020-03-12 12:03:44,223+0200 ERROR (tasks/2) [storage.TaskManager.Task] (Task='df69a182-e577-403c-9340-0b4c8280be3b') Unexpected error (task:874)
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/vdsm/storage/task.py", line 881, in _run
    return fn(*args, **kargs)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/task.py", line 344, in run
    return self.cmd(*self.argslist, **self.argsdict)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/securable.py", line 79, in wrapper
    return method(self, *args, **kwargs)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/sp.py", line 1874, in createVolume
    initial_size=initialSize)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/sd.py", line 968, in createVolume
    initial_size=initial_size)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/volume.py", line 1163, in create
    initial_size=initial_size)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/blockVolume.py", line 503, in _create
    initialTags=(sc.TAG_VOL_UNINIT,))
  File "/usr/lib/python3.6/site-packages/vdsm/storage/lvm.py", line 1340, in createLV
    raise se.CannotCreateLogicalVolume(vgName, lvName, err)
vdsm.storage.exception.CannotCreateLogicalVolume: Cannot create Logical Volume: 'vgname=debcf34f-cc39-4c85-bc84-93e74fa27797 lvname=89998522-986f-4493-ab05-06ad7944847a err=[\'  Logical Volume "89998522-986f-4493-ab05-06ad7944847a" alread
y exists in volume group "debcf34f-cc39-4c85-bc84-93e74fa27797"\']'

Created attachment 1669598 [details]
Logs

Questions answered by Evelina, removing NEEDINFO

Created attachment 1672567 [details]
engine and vdsm logs rhv-4.4.0-26

Moving back to ON_QA as this issue was not seen in copy template disk to FCP SD in rhv-4.4.0-26 BUT as we see a new issue that falls on the same functionality, see bug 1816004 we depend on it to be fixed before we verify this bug.

Please disregard comments 10 and 9 they belong to another similar bug(copy template disk to nfs SD bug 1811590)

This bug report has Keywords: Regression or TestBlocker.
Since no regressions or test blockers are allowed between releases, it is also being identified as a blocker for this release. Please resolve ASAP.

Copy disk to FCP failed again on rhv-4.4.0-30/engine 4.4.0-0.32.master.el8ev/vdsm-4.40.13-1.el8ev.x86_64 .

Seen on 2 FCP storage domains(hosted_engine SD and 'fcp_1' SD) in the same stage as the original bug was opened on(Clean environment reprovision) but this time with a different error that might be related to bug 1820182('MeasureVolumeVDS' method with Could not open image No such file or directory ).



This means that this bug can not be verified until 1820182 is fixed.

Marking this bug as depends on 1820182.

Engine log:
2020-04-14 12:56:33,035+03 INFO  [org.ovirt.engine.core.vdsbroker.vdsbroker.MeasureVolumeVDSCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-95) [8226a8ed-4c9c-475d-9ab9-58e4350abb5d] FINISH, MeasureVolumeVDSCommand, return: , log id: 6c9e9694
2020-04-14 12:56:33,035+03 ERROR [org.ovirt.engine.core.bll.storage.disk.image.MeasureVolumeCommand] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-95) [8226a8ed-4c9c-475d-9ab9-58e4350abb5d] Command 'org.ovirt.engine.core.bll.storage.disk.image.MeasureVolumeCommand' failed: EngineException: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericException: VDSErrorException: Failed to MeasureVolumeVDS, error = Command ['/usr/bin/qemu-img', 'measure', '--output', 'json', '-f', 'qcow2', '-O', 'qcow2', '/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3'] failed with rc=1 out=b'' err=b"qemu-img: Could not open '/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3': Could not open '/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3': No such file or directory\n", code = 100 (Failed with error GeneralException and code 100)
2020-04-14 12:56:33,042+03 ERROR [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-95) [8226a8ed-4c9c-475d-9ab9-58e4350abb5d] Command 'CloneImageGroupVolumesStructure' id: 'a6d0dc4e-0990-4439-8e14-e513d3f293aa' with children [] failed when attempting to perform the next operation, marking as 'ACTIVE'
2020-04-14 12:56:33,042+03 ERROR [org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback] (EE-ManagedScheduledExecutorService-engineScheduledThreadPool-Thread-95) [8226a8ed-4c9c-475d-9ab9-58e4350abb5d] Could not measure volume: java.lang.RuntimeException: Could not measure volume
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.storage.disk.image.CloneImageGroupVolumesStructureCommand.determineImageInitialSize(CloneImageGroupVolumesStructureCommand.java:214)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.storage.disk.image.CloneImageGroupVolumesStructureCommand.createImage(CloneImageGroupVolumesStructureCommand.java:163)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.storage.disk.image.CloneImageGroupVolumesStructureCommand.performNextOperation(CloneImageGroupVolumesStructureCommand.java:133)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.SerialChildCommandsExecutionCallback.childCommandsExecutionEnded(SerialChildCommandsExecutionCallback.java:32)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.ChildCommandsCallbackBase.doPolling(ChildCommandsCallbackBase.java:80)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethodsImpl(CommandCallbacksPoller.java:175)
        at deployment.engine.ear.bll.jar//org.ovirt.engine.core.bll.tasks.CommandCallbacksPoller.invokeCallbackMethods(CommandCallbacksPoller.java:109)
        at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
        at java.base/java.util.concurrent.FutureTask.runAndReset(FutureTask.java:305)
        at org.glassfish.javax.enterprise.concurrent.0.redhat-1//org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.access$201(ManagedScheduledThreadPoolExecutor.java:383)
        at org.glassfish.javax.enterprise.concurrent.0.redhat-1//org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.run(ManagedScheduledThreadPoolExecutor.java:534)
        at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
        at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
        at java.base/java.lang.Thread.run(Thread.java:834)
        at org.glassfish.javax.enterprise.concurrent.0.redhat-1//org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250)


VDSM log:
2020-04-14 12:56:33,021+0300 ERROR (jsonrpc/4) [storage.TaskManager.Task] (Task='e0d4b20d-3e22-4b49-876e-f0204514b0e0') Unexpected error (task:880)
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/vdsm/storage/task.py", line 887, in _run
    return fn(*args, **kargs)
  File "<decorator-gen-161>", line 2, in measure
  File "/usr/lib/python3.6/site-packages/vdsm/common/api.py", line 50, in method
    ret = func(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/hsm.py", line 3155, in measure
    output_format=sc.fmt2str(dest_format)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/qemuimg.py", line 160, in measure
    out = _run_cmd(cmd)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/qemuimg.py", line 481, in _run_cmd
    raise cmdutils.Error(cmd, rc, out, err)
vdsm.common.cmdutils.Error: Command ['/usr/bin/qemu-img', 'measure', '--output', 'json', '-f', 'qcow2', '-O', 'qcow2', '/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3'] failed with rc=1 out=b'' err=b"qemu-img: Could not open '/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3': Could not open '/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3': No such file or directory\n"
2020-04-14 12:56:33,021+0300 INFO  (jsonrpc/4) [storage.TaskManager.Task] (Task='e0d4b20d-3e22-4b49-876e-f0204514b0e0') aborting: Task is aborted: 'value=Command [\'/usr/bin/qemu-img\', \'measure\', \'--output\', \'json\', \'-f\', \'qcow2\', \'-O\', \'qcow2\', \'/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3\'] failed with rc=1 out=b\'\' err=b"qemu-img: Could not open \'/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3\': Could not open \'/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3\': No such file or directory\\n" abortedcode=100' (task:1190)
2020-04-14 12:56:33,022+0300 ERROR (jsonrpc/4) [storage.Dispatcher] FINISH measure error=Command ['/usr/bin/qemu-img', 'measure', '--output', 'json', '-f', 'qcow2', '-O', 'qcow2', '/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3'] failed with rc=1 out=b'' err=b"qemu-img: Could not open '/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3': Could not open '/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3': No such file or directory\n" (dispatcher:87)
Traceback (most recent call last):
  File "/usr/lib/python3.6/site-packages/vdsm/storage/dispatcher.py", line 74, in wrapper
    result = ctask.prepare(func, *args, **kwargs)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/task.py", line 110, in wrapper
    return m(self, *a, **kw)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/task.py", line 1198, in prepare
    raise self.error
  File "/usr/lib/python3.6/site-packages/vdsm/storage/task.py", line 887, in _run
    return fn(*args, **kargs)
  File "<decorator-gen-161>", line 2, in measure
  File "/usr/lib/python3.6/site-packages/vdsm/common/api.py", line 50, in method
    ret = func(*args, **kwargs)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/hsm.py", line 3155, in measure
    output_format=sc.fmt2str(dest_format)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/qemuimg.py", line 160, in measure
    out = _run_cmd(cmd)
  File "/usr/lib/python3.6/site-packages/vdsm/storage/qemuimg.py", line 481, in _run_cmd
    raise cmdutils.Error(cmd, rc, out, err)
vdsm.common.cmdutils.Error: Command ['/usr/bin/qemu-img', 'measure', '--output', 'json', '-f', 'qcow2', '-O', 'qcow2', '/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3'] failed with rc=1 out=b'' err=b"qemu-img: Could not open '/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3': Could not open '/rhev/data-center/mnt/blockSD/a47d1d0a-fab5-41e9-acda-3f54bb632677/images/7a8c4308-c2a6-4650-b5a9-2eda810949dc/49e3a489-eda6-44d5-8ca4-067600cf50b3': No such file or directory\n"
2020-04-14 12:56:33,022+0300 INFO  (jsonrpc/4) [jsonrpc.JsonRpcServer] RPC call Volume.measure failed (error 100) in 0.06 seconds (__init__:312)

Created attachment 1679375 [details]
engine and vdsm logs of on ovirt-engine 4.4.0.32

Verified on 4.4.0-0.32.master.el8ev

Template disk is being copied successfully between FC domains.

This bugzilla is included in oVirt 4.4.0 release, published on May 20th 2020.

Since the problem described in this bug report should be
resolved in oVirt 4.4.0 release, it has been closed with a resolution of CURRENT RELEASE.

If the solution does not work for you, please open a new bug report.