Hi,

CQ reported a failure for test 004_basic_sanity.verify_vm_import on basic suite.

It seems to me that its related to the reported change. can you please have a look?

Link and headline of suspected patches:

https://gerrit.ovirt.org/#/c/89852/ - examples: upload ova as a virtual machine template

Link to Job:


http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/7166/

Link to all logs:

http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/7166/artifact/exported-artifacts/basic-suit-master-el7/test_logs/basic-suite-master/post-004_basic_sanity.py/



(Relevant) error snippet from the log:

<error>


vdsm:


2018-04-27 10:26:03,131-0400 INFO (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call Host.dumpxmls succeeded in 0.00 seconds (__init__:311)
2018-04-27 10:26:04,825-0400 DEBUG (tasks/8) [root] FAILED: <err> = "virt-sparsify: error: libguestfs error: guestfs_launch failed.\nThis usually means the libguestfs appliance failed to start or crashed.\nDo:\n export LIBGUESTFS_DEBUG=1
LIBGUESTFS_TRACE=1\nand run the command again. For further information, read:\n http://libguestfs.org/guestfs-faq.1.html#debugging-libguestfs\nYou can also run 'libguestfs-test-tool' and post the *complete* output\ninto a bug report or
message to the libguestfs mailing list.\n\nIf reporting bugs, run virt-sparsify with debugging enabled and include the \ncomplete output:\n\n virt-sparsify -v -x [...]\n"; <rc> = 1 (commands:87)
2018-04-27 10:26:04,829-0400 INFO (tasks/8) [storage.SANLock] Releasing Lease(name='ee91b001-53e4-42b0-9dc1-3a24e5e2b273', path=u'/rhev/data-center/mnt/192.168.200.4:_exports_nfs_share1/c4befad8-ac1e-4cf7-929e-8c26e3a12935/images/46fd673
b-4e94-4bc5-aab3-f7af16f11e19/ee91b001-53e4-42b0-9dc1-3a24e5e2b273.lease', offset=0) (clusterlock:435)
2018-04-27 10:26:04,835-0400 INFO (tasks/8) [storage.SANLock] Successfully released Lease(name='ee91b001-53e4-42b0-9dc1-3a24e5e2b273', path=u'/rhev/data-center/mnt/192.168.200.4:_exports_nfs_share1/c4befad8-ac1e-4cf7-929e-8c26e3a12935/im
ages/46fd673b-4e94-4bc5-aab3-f7af16f11e19/ee91b001-53e4-42b0-9dc1-3a24e5e2b273.lease', offset=0) (clusterlock:444)
2018-04-27 10:26:04,835-0400 ERROR (tasks/8) [root] Job u'f7cc21f1-26fa-430a-93d0-671b402613d1' failed (jobs:221)
Traceback (most recent call last):
File "/usr/lib/python2.7/site-packages/vdsm/jobs.py", line 157, in run
self._run()
File "/usr/lib/python2.7/site-packages/vdsm/storage/sdm/api/sparsify_volume.py", line 56, in _run
virtsparsify.sparsify_inplace(self._vol_info.path)
File "/usr/lib/python2.7/site-packages/vdsm/virtsparsify.py", line 71, in sparsify_inplace
raise cmdutils.Error(cmd, rc, out, err)
Error: Command ['/usr/bin/virt-sparsify', '--machine-readable', '--in-place', u'/rhev/data-center/mnt/192.168.200


engine:


2018-04-27 10:16:40,016-04 ERROR [org.ovirt.engine.core.bll.storage.domain.AttachStorageDomainToPoolCommand] (default task-9) [] An error occurred while fetching unregistered disks from Storage Domain id 'f25de789-f7ce-4b7a-9e92-156bae627b9c'

{"jsonrpc": "2.0", "id": "38e21a74-88e9-4f1b-a4bf-8ba61f6a0438", "error": {"message": "Image does not exist in domain: u'image=79a81745-1140-4ba8-aa6b-16ab7820df5e, domain=9729b818-49e6-4ac6-b7a6-5d634bb06a83'", "code": 268}}^@
2018-04-27 10:28:00,286-04 DEBUG [org.ovirt.vdsm.jsonrpc.client.internal.ResponseWorker] (ResponseWorker) [] Message received: {"jsonrpc": "2.0", "id": "38e21a74-88e9-4f1b-a4bf-8ba61f6a0438", "error": {"message": "Image does not exist in
domain: u'image=79a81745-1140-4ba8-aa6b-16ab7820df5e, domain=9729b818-49e6-4ac6-b7a6-5d634bb06a83'", "code": 268}}
2018-04-27 10:28:00,296-04 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-12) [1d9c39cd] EVENT_ID: IRS_BROKER_COMMAND_FAILURE(10,803), VDSM command DeleteImageG
roupVDS failed: Image does not exist in domain: u'image=79a81745-1140-4ba8-aa6b-16ab7820df5e, domain=9729b818-49e6-4ac6-b7a6-5d634bb06a83'
2018-04-27 10:28:00,296-04 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-12) [1d9c39cd] Command 'DeleteImageGroupVDSCommand( DeleteImageGroupVDSCommandParamete
rs:{storagePoolId='42724c3b-3d09-4c1d-a716-56758c9ba2e3', ignoreFailoverLimit='false', storageDomainId='9729b818-49e6-4ac6-b7a6-5d634bb06a83', imageGroupId='79a81745-1140-4ba8-aa6b-16ab7820df5e', postZeros='false', discard='true', forceDe
lete='false'})' execution failed: IRSGenericException: IRSErrorException: Image does not exist in domain: u'image=79a81745-1140-4ba8-aa6b-16ab7820df5e, domain=9729b818-49e6-4ac6-b7a6-5d634bb06a83'
2018-04-27 10:28:00,296-04 DEBUG [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-12) [1d9c39cd] Exception: org.ovirt.engine.core.vdsbroker.irsbroker.IrsOperationFailed
NoFailoverException: IRSGenericException: IRSErrorException: Image does not exist in domain: u'image=79a81745-1140-4ba8-aa6b-16ab7820df5e, domain=9729b818-49e6-4ac6-b7a6-5d634bb06a83'
        at org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyReturnValue(BrokerCommandBase.java:180) [vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand.executeIrsBrokerCommand(DeleteImageGroupVDSCommand.java:30) [vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand.lambda$executeVDSCommand$0(IrsBrokerCommand.java:98) [vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.irsbroker.IrsProxy.runInControlledConcurrency(IrsProxy.java:274) [vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.irsbroker.IrsBrokerCommand.executeVDSCommand(IrsBrokerCommand.java:95) [vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:65) [vdsbroker.jar:]
        at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:31) [dal.jar:]
        at org.ovirt.engine.core.vdsbroker.vdsbroker.DefaultVdsCommandExecutor.execute(DefaultVdsCommandExecutor.java:14) [vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.ResourceManager.runVdsCommand(ResourceManager.java:398) [vdsbroker.jar:]
        at org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.runVdsCommand$$super(Unknown Source) [vdsbroker.jar:]
        at sun.reflect.GeneratedMethodAccessor271.invoke(Unknown Source) [:1.8.0_161]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_161]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_161]
        at org.jboss.weld.interceptor.proxy.TerminalAroundInvokeInvocationContext.proceedInternal(TerminalAroundInvokeInvocationContext.java:49) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at org.jboss.weld.interceptor.proxy.AroundInvokeInvocationContext.proceed(AroundInvokeInvocationContext.java:77) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at org.ovirt.engine.core.common.di.interceptor.LoggingInterceptor.apply(LoggingInterceptor.java:12) [common.jar:]
        at sun.reflect.GeneratedMethodAccessor70.invoke(Unknown Source) [:1.8.0_161]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_161]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_161]
        at org.jboss.weld.interceptor.reader.SimpleInterceptorInvocation$SimpleMethodInvocation.invoke(SimpleInterceptorInvocation.java:73) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeAroundInvoke(InterceptorMethodHandler.java:84) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.executeInterception(InterceptorMethodHandler.java:72) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at org.jboss.weld.interceptor.proxy.InterceptorMethodHandler.invoke(InterceptorMethodHandler.java:56) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:79) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at org.jboss.weld.bean.proxy.CombinedInterceptorAndDecoratorStackMethodHandler.invoke(CombinedInterceptorAndDecoratorStackMethodHandler.java:68) [weld-core-impl-2.4.3.Final.jar:2.4.3.Final]
        at org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.runVdsCommand(Unknown Source) [vdsbroker.jar:]
        at org.ovirt.engine.core.bll.VDSBrokerFrontendImpl.runVdsCommand(VDSBrokerFrontendImpl.java:33) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.runVdsCommand(CommandBase.java:2046) [bll.jar:]
        at org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand.performDeleteImageVdsmOperation(RemoveImageCommand.java:310) [bll.jar:]
        at org.ovirt.engine.core.bll.storage.disk.image.RemoveImageCommand.executeCommand(RemoveImageCommand.java:112) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeWithoutTransaction(CommandBase.java:1133) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeActionInTransactionScope(CommandBase.java:1286) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.runInTransaction(CommandBase.java:1935) [bll.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInSuppressed(TransactionSupport.java:164) [utils.jar:]
        at org.ovirt.engine.core.utils.transaction.TransactionSupport.executeInScope(TransactionSupport.java:103) [utils.jar:]
        at org.ovirt.engine.core.bll.CommandBase.execute(CommandBase.java:1346) [bll.jar:]
        at org.ovirt.engine.core.bll.CommandBase.executeAction(CommandBase.java:400) [bll.jar:]
        at org.ovirt.engine.core.bll.executor.DefaultBackendActionExecutor.execute(DefaultBackendActionExecutor.java:13) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runAction(Backend.java:450) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runActionImpl(Backend.java:432) [bll.jar:]
        at org.ovirt.engine.core.bll.Backend.runInternalAction(Backend.java:638) [bll.jar:]
        at sun.reflect.GeneratedMethodAccessor551.invoke(Unknown Source) [:1.8.0_161]
        at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_161]
        at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_161]
        at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
        at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
        at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
:
2018-04-27 10:28:00,358-04 INFO  [org.ovirt.engine.core.bll.exportimport.ImportVmCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-12) [] Lock freed to object 'EngineLock:{exclusiveLocks='[2cf61dee-c89c-469a-8ab8-54aebd0ab875=VM, i
mported_vm=VM_NAME]', sharedLocks='[5e0b3417-5e0d-4f98-a3cb-1a78445de946=REMOTE_VM]'}'
2018-04-27 10:28:00,372-04 ERROR [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-12) [] EVENT_ID: IMPORTEXPORT_IMPORT_VM_FAILED(1,153), Failed to import Vm imported_vm
 to Data Center test-dc, Cluster test-cluster


</error>