Note: This bug is displayed in read-only format because the product is no longer active in Red Hat Bugzilla.

Bug 1162078

Summary: [LOG] Query GetVmTemplateQuery failed with NullPointerException when applied to a non-existent template.
Product: Red Hat Enterprise Virtualization Manager Reporter: Raz Tamir <ratamir>
Component: ovirt-engineAssignee: Amit Aviram <aaviram>
Status: CLOSED CURRENTRELEASE QA Contact: Raz Tamir <ratamir>
Severity: medium Docs Contact: Tal Nisan <tnisan>
Priority: unspecified    
Version: 3.4.3CC: aaviram, aberezin, acanan, amureini, ecohen, gklein, iheim, lpeer, lsurette, rbalakri, Rhev-m-bugs, tnisan, yeylon
Target Milestone: ---   
Target Release: 3.5.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard: storage
Fixed In Version: ovirt-engine-3.5.0_vt11 Doc Type: Bug Fix
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2015-02-16 19:10:49 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: Storage RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:
Attachments:
Description Flags
engine log none

Description Raz Tamir 2014-11-10 08:48:25 UTC 
Created attachment 955699 [details]
engine log

Description of problem:
In our automation test [1] attempt to create template fails with "Response code is not valid, expected is: [200, 201], actual is: 404"

[1]http://jenkins.qa.lab.tlv.redhat.com:8080/view/Storage/view/3.4/job/3.4-storage_backup_api_sanity-iscsi/96/consoleFull


Version-Release number of selected component (if applicable):
av13

How reproducible:



Additional info:
ERROR - Errors fetched from VDC(jenkins-vm-14.scl.lab.tlv.redhat.com): 2014-11-09 17:50:32,487 ERROR [org.ovirt.engine.core.vdsbroker.vdsbroker.HSMGetAllTasksStatusesVDSCommand] (DefaultQuartzScheduler_Worker-69) Failed in HSMGetAllTasksStatusesVDS method
2014-11-09 17:50:32,488 INFO  [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-69) SPMAsyncTask::PollTask: Polling task 00cebe69-095b-4e64-bb52-6a0ffbfa9f3f (Parent Command AddVmTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) returned status finished, result 'cleanSuccess'.
2014-11-09 17:50:32,506 ERROR [org.ovirt.engine.core.bll.SPMAsyncTask] (DefaultQuartzScheduler_Worker-69) BaseAsyncTask::LogEndTaskFailure: Task 00cebe69-095b-4e64-bb52-6a0ffbfa9f3f (Parent Command AddVmTemplate, Parameters Type org.ovirt.engine.core.common.asynctasks.AsyncTaskParameters) ended with failure:
-- Result: cleanSuccess
-- Message: VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Error creating a new volume, code = 205,
-- Exception: VDSGenericException: VDSErrorException: Failed to HSMGetAllTasksStatusesVDS, error = Error creating a new volume, code = 205
2014-11-09 17:50:32,507 INFO  [org.ovirt.engine.core.bll.CommandAsyncTask] (DefaultQuartzScheduler_Worker-69) CommandAsyncTask::EndActionIfNecessary: All tasks of command a5e372c7-4f1a-4a0e-a53f-19cb43750c4f has ended -> executing endAction
2014-11-09 17:50:32,560 ERROR [org.ovirt.engine.core.bll.AddVmTemplateCommand] (org.ovirt.thread.pool-4-thread-38) [2b8aa929-871f-4a9b_createTemplate_create] Ending command with failure: org.ovirt.engine.core.bll.AddVmTemplateCommand
2014-11-09 17:50:32,563 ERROR [org.ovirt.engine.core.bll.CreateImageTemplateCommand] (org.ovirt.thread.pool-4-thread-38) [ab550ca] Ending command with failure: org.ovirt.engine.core.bll.CreateImageTemplateCommand
2014-11-09 17:50:32,605 INFO  [org.ovirt.engine.core.bll.RemoveImageCommand] (org.ovirt.thread.pool-4-thread-38) [4601c4cb] Running command: RemoveImageCommand internal: true. Entities affected :  ID: 00000000-0000-0000-0000-000000000000 Type: Storage
2014-11-09 17:50:33,044 ERROR [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-4-thread-38) [4601c4cb] Command DeleteImageGroupVDSCommand( storagePoolId = bef29e22-b5a8-479b-bd42-aa952a22e563, ignoreFailoverLimit = false, storageDomainId = 40492d9a-a031-4590-bc1c-9e16a29651ed, imageGroupId = f4ebce0b-bc00-49f3-9f5c-9da35903874a, postZeros = false, forceDelete = false) execution failed. Exception: IrsOperationFailedNoFailoverException: IRSGenericException: IRSErrorException: Image does not exist in domain: 'image=f4ebce0b-bc00-49f3-9f5c-9da35903874a, domain=40492d9a-a031-4590-bc1c-9e16a29651ed'
2014-11-09 17:50:33,044 INFO  [org.ovirt.engine.core.vdsbroker.irsbroker.DeleteImageGroupVDSCommand] (org.ovirt.thread.pool-4-thread-38) [4601c4cb] FINISH, DeleteImageGroupVDSCommand, log id: 47a9b32
2014-11-09 17:50:43,203 ERROR [org.ovirt.engine.core.bll.GetVmTemplateQuery] (ajp-/127.0.0.1:8702-6) Query GetVmTemplateQuery failed. Exception message is null : java.lang.NullPointerException: java.lang.NullPointerException
	at org.ovirt.engine.core.bll.VmTemplateHandler.updateDisksFromDb(VmTemplateHandler.java:53) [bll.jar:]
	at org.ovirt.engine.core.bll.GetVmTemplateQuery.executeQueryCommand(GetVmTemplateQuery.java:22) [bll.jar:]
	at org.ovirt.engine.core.bll.QueriesCommandBase.executeCommand(QueriesCommandBase.java:66) [bll.jar:]
	at org.ovirt.engine.core.dal.VdcCommandBase.execute(VdcCommandBase.java:31) [dal.jar:]
	at org.ovirt.engine.core.bll.Backend.runQueryImpl(Backend.java:482) [bll.jar:]
	at org.ovirt.engine.core.bll.Backend.runQuery(Backend.java:459) [bll.jar:]
	at sun.reflect.GeneratedMethodAccessor69.invoke(Unknown Source) [:1.7.0_71]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_71]
	at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_71]
	at org.jboss.as.ee.component.ManagedReferenceMethodInterceptorFactory$ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptorFactory.java:72) [jboss-as-ee.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:58) [jboss-as-ee.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:374) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.ovirt.engine.core.bll.interceptors.ThreadLocalSessionCleanerInterceptor.injectWebContextToThreadLocal(ThreadLocalSessionCleanerInterceptor.java:13) [bll.jar:]
	at sun.reflect.GeneratedMethodAccessor24.invoke(Unknown Source) [:1.7.0_71]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_71]
	at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_71]
	at org.jboss.as.ee.component.ManagedReferenceLifecycleMethodInterceptorFactory$ManagedReferenceLifecycleMethodInterceptor.processInvocation(ManagedReferenceLifecycleMethodInterceptorFactory.java:123) [jboss-as-ee.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:53) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:58) [jboss-as-ee.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43) [jboss-as-ejb3.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:21) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:53) [jboss-as-ee.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:52) [jboss-as-ejb3.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInNoTx(CMTTxInterceptor.java:259) [jboss-as-ejb3.jar:7.3.4.Final-redhat-1]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.supports(CMTTxInterceptor.java:398) [jboss-as-ejb3.jar:7.3.4.Final-redhat-1]
	at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:242) [jboss-as-ejb3.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [jboss-as-ejb3.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [jboss-as-ejb3.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:59) [jboss-as-ejb3.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [jboss-as-ee.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.TCCLInterceptor.processInvocation(TCCLInterceptor.java:45) [jboss-as-ee.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:165) [jboss-as-ee.jar:7.3.4.Final-redhat-1]
	at org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:182) [jboss-as-ee.jar:7.3.4.Final-redhat-1]
	at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:288) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:61) [jboss-invocation.jar:1.1.2.Final-redhat-1]
	at org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:72) [jboss-as-ee.jar:7.3.4.Final-redhat-1]
	at org.ovirt.engine.core.common.interfaces.BackendLocal$$$view10.runQuery(Unknown Source) [common.jar:]
	at org.ovirt.engine.api.restapi.resource.BackendResource.runQuery(BackendResource.java:81)
	at org.ovirt.engine.api.restapi.resource.BackendResource.doGetEntity(BackendResource.java:104)
	at org.ovirt.engine.api.restapi.resource.BackendResource.getEntity(BackendResource.java:94)
	at org.ovirt.engine.api.restapi.resource.AbstractBackendSubResource.performGet(AbstractBackendSubResource.java:35)
	at org.ovirt.engine.api.restapi.resource.AbstractBackendSubResource.performGet(AbstractBackendSubResource.java:31)
	at org.ovirt.engine.api.restapi.resource.BackendTemplateResource.get(BackendTemplateResource.java:51)
	at org.ovirt.engine.api.restapi.resource.BackendTemplateResource.get(BackendTemplateResource.java:39)
	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.7.0_71]
	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57) [rt.jar:1.7.0_71]
	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) [rt.jar:1.7.0_71]
	at java.lang.reflect.Method.invoke(Method.java:606) [rt.jar:1.7.0_71]
	at org.jboss.resteasy.core.MethodInjectorImpl.invoke(MethodInjectorImpl.java:167) [resteasy-jaxrs.jar:2.3.7.2.Final-redhat-1]
	at org.jboss.resteasy.core.ResourceMethod.invokeOnTarget(ResourceMethod.java:269) [resteasy-jaxrs.jar:2.3.7.2.Final-redhat-1]
	at org.jboss.resteasy.core.ResourceMethod.invoke(ResourceMethod.java:227) [resteasy-jaxrs.jar:2.3.7.2.Final-redhat-1]
	at org.jboss.resteasy.core.ResourceLocator.invokeOnTargetObject(ResourceLocator.java:159) [resteasy-jaxrs.jar:2.3.7.2.Final-redhat-1]
	at org.jboss.resteasy.core.ResourceLocator.invoke(ResourceLocator.java:92) [resteasy-jaxrs.jar:2.3.7.2.Final-redhat-1]
	at org.jboss.resteasy.core.SynchronousDispatcher.getResponse(SynchronousDispatcher.java:542) [resteasy-jaxrs.jar:2.3.7.2.Final-redhat-1]
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:524) [resteasy-jaxrs.jar:2.3.7.2.Final-redhat-1]
	at org.jboss.resteasy.core.SynchronousDispatcher.invoke(SynchronousDispatcher.java:126) [resteasy-jaxrs.jar:2.3.7.2.Final-redhat-1]
	at org.jboss.resteasy.plugins.server.servlet.ServletContainerDispatcher.service(ServletContainerDispatcher.java:208) [resteasy-jaxrs.jar:2.3.7.2.Final-redhat-1]
	at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:55) [resteasy-jaxrs.jar:2.3.7.2.Final-redhat-1]
	at org.jboss.resteasy.plugins.server.servlet.HttpServletDispatcher.service(HttpServletDispatcher.java:50) [resteasy-jaxrs.jar:2.3.7.2.Final-redhat-1]
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:847) [jboss-servlet-api_3.0_spec.jar:1.0.2.Final-redhat-1]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:295)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
	at org.ovirt.engine.core.authentication.AuthenticationFilter.doFilter(AuthenticationFilter.java:80) [common.jar:]
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:246)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:214)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:230)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:149)
	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:499)
	at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:169)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:145)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:97)
	at org.jboss.web.rewrite.RewriteValve.invoke(RewriteValve.java:466)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:102)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:336)
	at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:490)
	at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:420)
	at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:926)
	at java.lang.Thread.run(Thread.java:745) [rt.jar:1.7.0_71]
Comment 2 Amit Aviram 2014-11-13 16:04:51 UTC 
Please notice that the automation tried to get a vm template, and expected it to succeed without checking if the result is null: 

"
2014-11-09 17:51:57,021 - MainThread - templates - DEBUG - Waiting for status 'OK' currently status is 'locked' 

2014-11-09 17:52:07,029 - MainThread - templates - DEBUG - GET request content is --  url:/api/templates/ad27be17-26b1-40c3-9989-771bd1bcda4e 

2014-11-09 17:52:07,311 - MainThread - templates - ERROR - Response code is not valid, expected is: [200, 201], actual is: 404 

2014-11-09 17:52:07,313 - MainThread - templates - ERROR - Element template doesn't have attribute status
"
Comment 3 Tal Nisan 2014-11-16 10:54:10 UTC 
Reducing severity as the real blocking error is the fact that the template is not created, the fact that the query throws an NPE since it can't find the uncreated template is merely a log error
Comment 4 Allon Mureinik 2014-11-18 10:16:01 UTC 
There are two issues here:
1. The automation test fails to create a template. This is being handled as part of a different BZ - Amit, please provide the number.
2. An NPE once we failed to create the template - handled in this BZ.
Comment 5 Amit Aviram 2014-11-18 15:26:16 UTC 
the bug which handles the template creation failure:
https://bugzilla.redhat.com/show_bug.cgi?id=1160620
Comment 6 Allon Mureinik 2014-11-23 19:39:05 UTC 
(In reply to Amit Aviram from comment #5)
> the bug which handles the template creation failure:
> https://bugzilla.redhat.com/show_bug.cgi?id=1160620

Removing the blocker flag - this is just a logging issue. The real underlying bug may indeed be a blocker though.
Comment 7 Raz Tamir 2014-12-01 10:58:33 UTC 
verified - vt12
Comment 8 Allon Mureinik 2015-02-16 19:10:49 UTC 
RHEV-M 3.5.0 has been released, closing this bug.