[ovirt-devel] [ OST Failure Report ] [ oVirt Master ] [ 14-12-2017 ] [ 004_basic_sanity.disk_operations ]

Michal Skrivanek michal.skrivanek at redhat.com
Thu Dec 14 12:12:25 UTC 2017


> On 14 Dec 2017, at 13:00, Dafna Ron <dron at redhat.com> wrote:
> 
> Hi, 
> We have a failure on basic suite on test: 004_basic_sanity.disk_operations
> I think that we query a snapshot that was already deleted successfully and report the snapshot as gone. and that is because of a different error in update vm query which happens before. 
> 
> Link and headline of suspected patches: 
> https://gerrit.ovirt.org/#/c/85168/ <https://gerrit.ovirt.org/#/c/85168/> - core: Prevent retry lease hotplag in case of failure.
> 
> Link to Job:
> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393 <http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393>
> 
> Link to all logs:
> http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393/artifact/ <http://jenkins.ovirt.org/job/ovirt-master_change-queue-tester/4393/artifact/>
> 
> (Relevant) error snippet from the log: 
> <error>
> 
> Engine: 
> 
> 
> 
> 2017-12-14 02:38:01,470-05 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-5) [] Command 'GetAllVmStatsVDSCommand(HostName = lago-basic-suite-master-host-1, VdsIdVD
> SCommandParametersBase:{hostId='f1c2314f-5617-4c9e-84e0-e822160fbde9'})' execution failed: VDSGenericException: VDSErrorException: Failed to GetAllVmStatsVDS, error = Internal JSON-RPC error: {'reason': "VM '7cab7e5a-cb12-4977-ac4f-652185
> 32df7e' was not defined yet or was undefined"}, code = -32603
> 2017-12-14 02:38:01,470-05 DEBUG [org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-5) [] Exception: org.ovirt.engine.core.vdsbroker.vdsbroker.VDSErrorException: VDSGenericE
> xception: VDSErrorException: Failed to GetAllVmStatsVDS, error = Internal JSON-RPC error: {'reason': "VM '7cab7e5a-cb12-4977-ac4f-65218532df7e' was not defined yet or was undefined"}, code = -32603
>         at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.createDefaultConcreteException(VdsBrokerCommand.java:81) [vdsbroker.jar:]
>         at org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.createException(BrokerCommandBase.java:224) [vdsbroker.jar:]
>         at org.ovirt.engine.core.vdsbroker.vdsbroker.BrokerCommandBase.proceedProxyReturnValue(BrokerCommandBase.java:194) [vdsbroker.jar:]
>         at org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand.executeVdsBrokerCommand(GetAllVmStatsVDSCommand.java:23) [vdsbroker.jar:]
>         at org.ovirt.engine.core.vdsbroker.vdsbroker.VdsBrokerCommand.executeVDSCommand(VdsBrokerCommand.java:112) [vdsbroker.jar:]
>         at org.ovirt.engine.core.vdsbroker.VDSCommandBase.executeCommand(VDSCommandBase.java:73) [vdsbroker.jar:]
>         at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:33) [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:387) [vdsbroker.jar:]
>         at org.ovirt.engine.core.vdsbroker.ResourceManager$Proxy$_$$_WeldSubclass.runVdsCommand$$super(Unknown Source) [vdsbroker.jar:]
>         at sun.reflect.GeneratedMethodAccessor247.invoke(Unknown Source) [:1.8.0_151]
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_151]
>         at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_151]
>         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.GeneratedMethodAccessor69.invoke(Unknown Source) [:1.8.0_151]
>         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.8.0_151]
>         at java.lang.reflect.Method.invoke(Method.java:498) [rt.jar:1.8.0_151]
>         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.vdsbroker.monitoring.VmsStatisticsFetcher.poll(VmsStatisticsFetcher.java:29) [vdsbroker.jar:]
>         at org.ovirt.engine.core.vdsbroker.monitoring.VmsListFetcher.fetch(VmsListFetcher.java:57) [vdsbroker.jar:]
>         at org.ovirt.engine.core.vdsbroker.monitoring.PollVmStatsRefresher.poll(PollVmStatsRefresher.java:42) [vdsbroker.jar:]
>         at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [rt.jar:1.8.0_151]
>         at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308) [rt.jar:1.8.0_151]
>         at org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.access$201(ManagedScheduledThreadPoolExecutor.java:383) [javax.enterprise.concurrent-1.0.jar:]
>         at org.glassfish.enterprise.concurrent.internal.ManagedScheduledThreadPoolExecutor$ManagedScheduledFutureTask.run(ManagedScheduledThreadPoolExecutor.java:534) [javax.enterprise.concurrent-1.0.jar:]
>         at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [rt.jar:1.8.0_151]
>         at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [rt.jar:1.8.0_151]
>         at java.lang.Thread.run(Thread.java:748) [rt.jar:1.8.0_151]
>         at org.glassfish.enterprise.concurrent.ManagedThreadFactoryImpl$ManagedThread.run(ManagedThreadFactoryImpl.java:250) [javax.enterprise.concurrent-1.0.jar:]
>         at org.jboss.as.ee.concurrent.service.ElytronManagedThreadFactory$ElytronManagedThread.run(ElytronManagedThreadFactory.java:78)
> 
> 
> 
> 2017-12-14 02:42:15,525-05 INFO  [org.ovirt.engine.core.bll.snapshots.RemoveSnapshotCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-26) [c5f1846d-d042-4271-86f1-2b1787684554] Ending command 'org.ovirt.engine.core.bll.snapshots.Re
> moveSnapshotCommand' successfully.
> 2017-12-14 02:42:15,528-05 DEBUG [org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter] (default task-16) [] Entered SsoRestApiAuthFilter
> 2017-12-14 02:42:15,528-05 DEBUG [org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter] (default task-16) [] SsoRestApiAuthFilter authenticating with sso
> 2017-12-14 02:42:15,528-05 DEBUG [org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter] (default task-16) [] SsoRestApiAuthFilter authenticating using BEARER header
> 2017-12-14 02:42:15,531-05 DEBUG [org.ovirt.engine.core.aaa.filters.SsoRestApiAuthFilter] (default task-16) [] SsoRestApiAuthFilter successfully authenticated using BEARER header
> 2017-12-14 02:42:15,531-05 DEBUG [org.ovirt.engine.core.aaa.filters.SsoRestApiNegotiationFilter] (default task-16) [] Entered SsoRestApiNegotiationFilter
> 2017-12-14 02:42:15,533-05 DEBUG [org.ovirt.engine.core.aaa.filters.SsoRestApiNegotiationFilter] (default task-16) [] SsoRestApiNegotiationFilter Not performing Negotiate Auth
> 2017-12-14 02:42:15,540-05 DEBUG [org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor] (EE-ManagedThreadFactory-engineScheduled-Thread-26) [c5f1846d-d042-4271-86f1-2b1787684554] method: get, params: [cc9ae472-ef79-456f-9e4
> 7-01fd1617e189], timeElapsed: 3ms
> 2017-12-14 02:42:15,543-05 DEBUG [org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor] (default task-16) [2c5d880a-5c36-41e7-8020-bb2007cf9be2] method: runQuery, params: [GetAllVmSnapshotsByVmId, IdQueryParameters:{refresh
> ='false', filtered='false'}], timeElapsed: 6ms
> 2017-12-14 02:42:15,548-05 WARN  [org.ovirt.engine.core.bll.GetVmConfigurationBySnapshotQuery] (default task-16) [2c5d880a-5c36-41e7-8020-bb2007cf9be2] Snapshot '20b155eb-c15d-42cb-a03f-c45813a045b8' does not exist
> 2017-12-14 02:42:15,548-05 DEBUG [org.ovirt.engine.core.common.di.interceptor.DebugLoggingInterceptor] (default task-16) [2c5d880a-5c36-41e7-8020-bb2007cf9be2] method: runQuery, params: [GetVmConfigurationBySnapshot, IdQueryParameters:{re
> fresh='false', filtered='false'}], timeElapsed: 5ms
> 2017-12-14 02:42:15,548-05 ERROR [org.ovirt.engine.api.restapi.resource.AbstractBackendResource] (default task-16) [] Operation Failed: Entity not found: null
> 2017-12-14 02:42:15,554-05 INFO  [org.ovirt.engine.core.dal.dbbroker.auditloghandling.AuditLogDirector] (EE-ManagedThreadFactory-engineScheduled-Thread-26) [c5f1846d-d042-4271-86f1-2b1787684554] EVENT_ID: USER_REMOVE_SNAPSHOT_FINISHED_SUC
> CESS(356), Snapshot 'dead_snap1' deletion for VM 'vm1' has been completed.
> 2017-12-14 02:42:16,660-05 DEBUG [org.ovirt.engine.core.vdsbroker.vdsbroker.GetAllVmStatsVDSCommand] (EE-ManagedThreadFactory-engineScheduled-Thread-50) [] START, GetAllVmStatsVDSCommand(HostName = lago-basic-suite-master-host-0, VdsIdVDS
> CommandParametersBase:{hostId='3c60017b-0bb3-4a3e-bc24-f1779100fe21'}), log id: f9a1165
> 2017-12-14 02:42:16,660-05 DEBUG [org.ovirt.vdsm.jsonrpc.client.reactors.stomp.impl.Message] (EE-ManagedThreadFactory-engineScheduled-Thread-50) [] SEND
> destination:jms.topic.vdsm_requests
> reply-to:jms.topic.vdsm_responses
> content-length:103
> 
> vdsm: 
> 
> 2017-12-14 02:34:45,222-0500 ERROR (jsonrpc/7) [jsonrpc.JsonRpcServer] Internal server error (__init__:611)
> Traceback (most recent call last):
>   File "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 606, in _handle_request
>     res = method(**params)
>   File "/usr/lib/python2.7/site-packages/vdsm/rpc/Bridge.py", line 201, in _dynamicMethod
>     result = fn(*methodArgs)
>   File "<string>", line 2, in getAllVmStats
>   File "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 48, in method
>     ret = func(*args, **kwargs)
>   File "/usr/lib/python2.7/site-packages/vdsm/API.py", line 1342, in getAllVmStats
>     statsList = self._cif.getAllVmStats()
>   File "/usr/lib/python2.7/site-packages/vdsm/clientIF.py", line 518, in getAllVmStats
>     return [v.getStats() for v in self.vmContainer.values()]
>   File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 1699, in getStats
>     oga_stats = self._getGuestStats()
>   File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 1895, in _getGuestStats
>     self._update_guest_disk_mapping()
>   File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 1909, in _update_guest_disk_mapping
>     self._sync_metadata()
>   File "/usr/lib/python2.7/site-packages/vdsm/virt/vm.py", line 4995, in _sync_metadata
>     self._md_desc.dump(self._dom)
>   File "/usr/lib/python2.7/site-packages/vdsm/virt/metadata.py", line 477, in dump
>     dom.setMetadata(libvirt.VIR_DOMAIN_METADATA_ELEMENT,
>   File "/usr/lib/python2.7/site-packages/vdsm/virt/virdomain.py", line 47, in __getattr__
>     % self.vmid)
> NotConnectedError: VM '7cab7e5a-cb12-4977-ac4f-65218532df7e' was not defined yet or was undefined

it doesn’t seem to be relevant to this failure, but it deserves a fix nevertheless
Francesco?

> 
> 
> 
> </error>
> 
> _______________________________________________
> Devel mailing list
> Devel at ovirt.org
> http://lists.ovirt.org/mailman/listinfo/devel

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.ovirt.org/pipermail/devel/attachments/20171214/43afed0c/attachment-0001.html>


More information about the Devel mailing list