Description of problem: When a resource that has a reoccurring scheduled operation has its parent platform removed from inventory, also resulting in the resource itself being removed from inventory, the scheduler continues trying to execute the operation. It results in the following exception in the server log: 2010-04-07 11:53:03,078 ERROR [org.rhq.enterprise.server.operation.OperationJob] Failed to update schedule entity for job: JobDetail 'rhq-resource-10215.rhq-resource-10215--1319569547-1270654773064': jobClass: 'org.rhq.enterprise.server.operation.ResourceOperationJob isStateful: false isVolatile: false isDurable: false requestsRecovers: false javax.ejb.EJBException: java.lang.NullPointerException at org.jboss.ejb3.tx.Ejb3TxPolicy.handleExceptionInOurTx(Ejb3TxPolicy.java:63) at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:83) at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:191) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:77) at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:110) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:240) at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:210) at org.jboss.ejb3.stateless.StatelessLocalProxy.invoke(StatelessLocalProxy.java:84) at $Proxy333.updateOperationScheduleEntity(Unknown Source) at org.rhq.enterprise.server.operation.OperationJob.updateOperationScheduleEntity(OperationJob.java:70) at org.rhq.enterprise.server.operation.ResourceOperationJob.execute(ResourceOperationJob.java:68) at org.quartz.core.JobRunShell.run(JobRunShell.java:202) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:525) Caused by: java.lang.NullPointerException at org.rhq.enterprise.server.operation.OperationManagerBean.updateOperationScheduleEntity(OperationManagerBean.java:367) at sun.reflect.GeneratedMethodAccessor747.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112) at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166) at org.rhq.enterprise.server.common.TransactionInterruptInterceptor.addCheckedActionToTransactionManager(TransactionInterruptInterceptor.java:77) at sun.reflect.GeneratedMethodAccessor113.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:118) at org.rhq.enterprise.server.authz.RequiredPermissionsInterceptor.checkRequiredPermissions(RequiredPermissionsInterceptor.java:156) at sun.reflect.GeneratedMethodAccessor112.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:118) at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:79) ... 21 more 2010-04-07 11:53:03,096 ERROR [org.rhq.enterprise.server.operation.ResourceOperationJob] Failed to execute scheduled operation [null] javax.ejb.EJBTransactionRolledbackException: A resource with id 10215 does not exist in inventory. at org.jboss.ejb3.tx.Ejb3TxPolicy.handleInCallerTx(Ejb3TxPolicy.java:87) at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:130) at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:195) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:77) at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:110) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:240) at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:210) at org.jboss.ejb3.stateless.StatelessLocalProxy.invoke(StatelessLocalProxy.java:84) at $Proxy298.getResourceById(Unknown Source) at org.rhq.enterprise.server.operation.OperationManagerBean.getResourceIfAuthorized(OperationManagerBean.java:1593) at org.rhq.enterprise.server.operation.OperationManagerBean.getResourceOperationSchedule(OperationManagerBean.java:434) at sun.reflect.GeneratedMethodAccessor736.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112) at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166) at org.rhq.enterprise.server.common.TransactionInterruptInterceptor.addCheckedActionToTransactionManager(TransactionInterruptInterceptor.java:77) at sun.reflect.GeneratedMethodAccessor113.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:118) at org.rhq.enterprise.server.authz.RequiredPermissionsInterceptor.checkRequiredPermissions(RequiredPermissionsInterceptor.java:156) at sun.reflect.GeneratedMethodAccessor112.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:118) at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:79) at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:191) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.stateless.StatelessInstanceInterceptor.invoke(StatelessInstanceInterceptor.java:62) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.aspects.security.AuthenticationInterceptor.invoke(AuthenticationInterceptor.java:77) at org.jboss.ejb3.security.Ejb3AuthenticationInterceptor.invoke(Ejb3AuthenticationInterceptor.java:110) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:240) at org.jboss.ejb3.stateless.StatelessContainer.localInvoke(StatelessContainer.java:210) at org.jboss.ejb3.stateless.StatelessLocalProxy.invoke(StatelessLocalProxy.java:84) at $Proxy333.getResourceOperationSchedule(Unknown Source) at org.rhq.enterprise.server.operation.ResourceOperationJob.execute(ResourceOperationJob.java:71) at org.quartz.core.JobRunShell.run(JobRunShell.java:202) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:525) Caused by: org.rhq.enterprise.server.resource.ResourceNotFoundException: A resource with id 10215 does not exist in inventory. at org.rhq.enterprise.server.resource.ResourceManagerBean.getResourceById(ResourceManagerBean.java:527) at sun.reflect.GeneratedMethodAccessor495.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:112) at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:166) at org.rhq.enterprise.server.common.TransactionInterruptInterceptor.addCheckedActionToTransactionManager(TransactionInterruptInterceptor.java:77) at sun.reflect.GeneratedMethodAccessor113.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:118) at org.rhq.enterprise.server.authz.RequiredPermissionsInterceptor.checkRequiredPermissions(RequiredPermissionsInterceptor.java:156) at sun.reflect.GeneratedMethodAccessor112.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) at java.lang.reflect.Method.invoke(Method.java:597) at org.jboss.ejb3.interceptor.InvocationContextImpl.proceed(InvocationContextImpl.java:118) at org.jboss.ejb3.interceptor.EJB3InterceptorsInterceptor.invoke(EJB3InterceptorsInterceptor.java:63) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.entity.TransactionScopedEntityManagerInterceptor.invoke(TransactionScopedEntityManagerInterceptor.java:54) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.ejb3.AllowedOperationsInterceptor.invoke(AllowedOperationsInterceptor.java:47) at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101) at org.jboss.aspects.tx.TxPolicy.invokeInCallerTx(TxPolicy.java:126) ... 61 more Version-Release number of selected component (if applicable): How reproducible: Steps to Reproduce: 1. Create a reoccurring scheduled operation for some server in inventory. 1.1. Set the repeat interval to something short like 30 sec so that you can more quickly reproduce the issue. 1.2. To keep things simple I creates a one-line bash script that just echos a message and then manually created a script server for that script. I can provide specific details on how to do this if necessary. 2. Remove the parent platform of the resource from inventory 3. Wait until you see in the server log that the resource has been removed from the database. 3.1. You should see a log message like, [org.rhq.enterprise.server.scheduler.jobs.AsyncResourceDeleteJob] Async resource deletion - 1 successful, 0 failed, took [448]ms 4. After the resources have been removed from the database you will begin seeing the exception show above in your server log. Actual results: See steps to reproduce Expected results: The scheduled jobs should be removed along side with the resources that are being removed from inventory. Additional info: Initially when I tried to reproduce this, I tried removing only the resource with the scheduled operation from inventory, and I did not see the exception. I need to test this again though because it could have been due to the resource deletion job not running yet. I will test this scenario again and update the bug with my findings.
After discussion and review with the dev code, it appears that the defect is in ResourceManagerBean.deleteResource(Subject subject, int resourceId) which is called to remove a resource and its children from inventory. The resource to be remove has its associated scheduled jobs removed, but scheduled jobs for the child resources are not deleted.
Pushed commits to the bugfixes branch that make two changes. First, in the classes ResourceOperationJob and GroupOperationJob logic has been added to see if the resource is null (i.e., already deleted in db) or does not have a committed inventory status. If either of these conditions holds, a CancelJobException is throw and future executions of the job are canceled. Secondly, the code in ResourceManagerBean that deletes a resource's scheduled jobs when the resource is being marked for removal has been moved to AsyncResourceDeleteJob so that it is done asynchronously. And now the jobs for child resources are deleted as well.
These commits have been merged into master. Moving to ON_QA.
blocked by https://bugzilla.redhat.com/show_bug.cgi?id=583669
Created attachment 407595 [details] A simple function for scheduling a reoccurring resource operation
Rajan, I have just attached a script to this bug that you can use to schedule a resource operation job from the CLI. Once you are logged into the CLI, load the script as follows, rhqadmin@localhost:7080$ exec -f schedule_job.js In the above example it assumes that the script is in the current working directory. If the script is in another directory, be sure to specify the path to it, e.g., exec -f /path/to/schedule_job.js. This binds the function schedule_resource_operation into the script context. The function expects two arguments - the resource id and the operation name. You might invoke the function in the following way, rhqadmin@localhost:7080$ resourceId = 1234 rhqadmin@localhost:7080$ operationName = "execute" rhqadmin@localhost:7080$ schedule_resource_operation(resourceId, operationName) The function schedules the operation to execute every 30 seconds indefinitely. I have provided comments and variables in the function to make it easy for you to tweak the values. This should do the trick.
Verified on JON build #108 - Revision: 10611 The scheduled jobs has been removed along side with the resources that are being removed from inventory. Stpes: 1. Create a reoccurring scheduled operation for 'RHQ Agent' and set the repeat interval to 30 sec. 2. Remove the parent platform of the resource from inventory. 3. Wait until you see in the server log that the resource has been removed from the database. 3.1. Log message like, 2010-04-22 18:02:24,797 INFO [org.rhq.enterprise.server.resource.ResourceManagerBean] User [org.rhq.core.domain.auth.Subject[id=2,name=rhqadmin]] is marking resource [Resource[id=14311, type=Linux, key=rajanlaptop.usersys.redhat.com, name=rajanlaptop.usersys.redhat.com, parent=<null>, version=Linux 2.6.18-164.11.1.el5PAE]] for asynchronous deletion 2010-04-22 18:02:25,443 WARN [org.rhq.enterprise.server.core.comm.ServerCommunicationsService] {Failed to truncate/delete spool for deleted agent [Agent[id=10011,name=rajanlaptop.usersys.redhat.com,address=rajanlaptop.usersys.redhat.com,port=16163,remote-endpoint=socket://rajanlaptop.usersys.redhat.com:16163/?rhq.communications.connector.rhqtype=agent&numAcceptThreads=1&maxPoolSize=303&clientMaxPoolSize=304&socketTimeout=60000&enableTcpNoDelay=true&backlog=200,last-availability-report=1271939520757]] please manually remove the file: null}!!! missing resource message key=[Failed to truncate/delete spool for deleted agent [Agent[id=10011,name=rajanlaptop.usersys.redhat.com,address=rajanlaptop.usersys.redhat.com,port=16163,remote-endpoint=socket://rajanlaptop.usersys.redhat.com:16163/?rhq.communications.connector.rhqtype=agent&numAcceptThreads=1&maxPoolSize=303&clientMaxPoolSize=304&socketTimeout=60000&enableTcpNoDelay=true&backlog=200,last-availability-report=1271939520757]] please manually remove the file: null] args=[java.lang.NullPointerException] 2010-04-22 18:02:25,443 INFO [org.rhq.enterprise.server.core.AgentManagerBean] Removed agent: Agent[id=10011,name=rajanlaptop.usersys.redhat.com,address=rajanlaptop.usersys.redhat.com,port=16163,remote-endpoint=socket://rajanlaptop.usersys.redhat.com:16163/?rhq.communications.connector.rhqtype=agent&numAcceptThreads=1&maxPoolSize=303&clientMaxPoolSize=304&socketTimeout=60000&enableTcpNoDelay=true&backlog=200,last-availability-report=1271939520757] 2010-04-22 18:02:25,691 WARN [org.jboss.seam.ui.renderkit.DefaultActionRendererBase] Must set an id for the default action source 2010-04-22 18:02:25,708 ERROR [org.rhq.enterprise.server.discovery.DiscoveryServerServiceImpl] Received invalid inventory report from agent [Agent[id=0,name=rajanlaptop.usersys.redhat.com,address=null,port=0,remote-endpoint=null,last-availability-report=null]]: Unknown Agent named [rajanlaptop.usersys.redhat.com] sent an inventory report - that report will be ignored 2010-04-22 18:02:27,705 INFO [org.rhq.enterprise.server.core.CoreServerServiceImpl] Got agent registration request for new agent: rajanlaptop.usersys.redhat.com[rajanlaptop.usersys.redhat.com:16163][3.0.0-SNAPSHOT(ac4460c)] 2010-04-22 18:02:30,106 WARN [org.rhq.enterprise.server.operation.ResourceOperationJob] The resource with id 14312 is not committed in inventory. It may have been deleted from inventory. Canceling job. 2010-04-22 18:02:30,331 INFO [org.quartz.core.JobRunShell] Job rhq-resource-14312.rhq-resource-14312-1097506319-1271939434370 threw a JobExecutionException: org.rhq.enterprise.server.operation.CancelJobException: The resource with id 14312 is not committed in inventory. It may have been deleted from inventory. Canceling job. at org.rhq.enterprise.server.operation.ResourceOperationJob.invokeOperationOnResource(ResourceOperationJob.java:177) at org.rhq.enterprise.server.operation.ResourceOperationJob.execute(ResourceOperationJob.java:95) at org.quartz.core.JobRunShell.run(JobRunShell.java:202) at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:525)
Mass-closure of verified bugs against JON.