Uploaded image for project: 'JBoss BPMS Platform'
  1. JBoss BPMS Platform
  2. RHBPMS-4643

[GSS] (6.4.z) "Runtime manager is already closed" in Timer thread on BPMS shutdown

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Done
    • Icon: Major Major
    • 6.4.3
    • 6.4.0
    • jBPM Core
    • CR1
    • Hide
      • Add <resource-ref> entries for datasources in business-central.war/WEB-INF/web.xml in order to avoid earlier JNDI unbound. (See https://access.redhat.com/solutions/2907351) 
        <resource-ref>
  <res-ref-name>MyDataSource1</res-ref-name>
  <jndi-name>java:jboss/MySqlBusinessCentralDS</jndi-name>
</resource-ref>
<resource-ref>
  <res-ref-name>MyDataSource2</res-ref-name>
  <jndi-name>java:jboss/datasources/quartzUnmanagedDs</jndi-name>
</resource-ref>
      • Start BPMS 6.4.0 with Quartz scheduler configuration
      • Login to business-central
      • Import the attached org.jbpm.helloTimer.v1.0.bpmn2.
      • Build&Deploy the project
      • Start "helloTimer" process
      • Wait for "S2 : sleeping,,," log 
        16:02:47,374 INFO  [stdout] (http-127.0.0.1:8080-3) S1
16:03:10,885 INFO  [stdout] (jBPMClusteredScheduler_Worker-2) S2 : sleeping,,,
      • Shutdown BPMS
      Show
      Add <resource-ref> entries for datasources in business-central.war/WEB-INF/web.xml in order to avoid earlier JNDI unbound. (See https://access.redhat.com/solutions/2907351 ) <resource-ref> <res-ref-name> MyDataSource1 </res-ref-name> <jndi-name> java:jboss/MySqlBusinessCentralDS </jndi-name> </resource-ref> <resource-ref> <res-ref-name> MyDataSource2 </res-ref-name> <jndi-name> java:jboss/datasources/quartzUnmanagedDs </jndi-name> </resource-ref> Start BPMS 6.4.0 with Quartz scheduler configuration Login to business-central Import the attached org.jbpm.helloTimer.v1.0.bpmn2. Build&Deploy the project Start "helloTimer" process Wait for "S2 : sleeping,,," log 16:02:47,374 INFO [stdout] (http-127.0.0.1:8080-3) S1 16:03:10,885 INFO [stdout] (jBPMClusteredScheduler_Worker-2) S2 : sleeping,,, Shutdown BPMS

      On BPMS shutdown, RuntimeManager could be closed earlier than fully finishing Timer jobs. It results in "java.lang.IllegalStateException: Runtime manager XXX is already closed" during shutdown sequence.

      Quartz Scheduler result:

      15:32:41,891 INFO  [stdout] (http-127.0.0.1:8080-6) S1
15:33:07,584 INFO  [stdout] (jBPMClusteredScheduler_Worker-1) S2 : sleeping,,,
^C15:33:08,742 INFO  [org.jboss.as.server] (Thread-2) JBAS015986: Host Controller shutdown has been requested via an OS signal
15:33:08,759 INFO  [org.jboss.web] (ServerService Thread Pool -- 80) JBAS018224: Unregister web context: /dashbuilder
15:33:08,768 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-8) JBAS010409: Unbound data source [java:jboss/datasources/ExampleDS]
15:33:08,775 INFO  [org.apache.catalina.core] (MSC service thread 1-2) JBWEB001079: Container org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/] has not been started
15:33:08,776 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 79) JBAS011605: Unbound messaging object to jndi name java:/queue/KIE.AUDIT.ALL
15:33:08,787 INFO  [org.jboss.as.messaging] (ServerService Thread Pool -- 79) JBAS011605: Unbound messaging object to jndi name java:jboss/exported/jms/queue/KIE.AUDIT
15:33:08,885 INFO  [org.jboss.weld.deployer] (MSC service thread 1-3) JBAS016009: Stopping weld service for deployment dashbuilder.war
15:33:08,891 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-1) JBAS010409: Unbound data source [java:jboss/MySqlDashbuilderDS]
15:33:08,904 INFO  [org.jboss.web] (ServerService Thread Pool -- 105) JBAS018224: Unregister web context: /business-central
15:33:08,955 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-6) JBAS015877: Stopped deployment dashbuilder.war (runtime-name: dashbuilder.war) in 201ms
15:33:08,998 WARN  [org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/business-central].[jsp]] (http-127.0.0.1:8080-6) JBWEB000234: Servlet jsp is currently unavailable
15:33:09,013 WARN  [org.apache.catalina.core.ContainerBase.[jboss.web].[default-host].[/business-central].[jsp]] (http-127.0.0.1:8080-3) JBWEB000234: Servlet jsp is currently unavailable
15:33:09,200 INFO  [org.jboss.as.webservices] (MSC service thread 1-4) JBAS015540: Stopping service jboss.ws.endpoint."business-central.war".CommandWebService
15:33:09,202 INFO  [org.jboss.as.webservices] (MSC service thread 1-7) JBAS015540: Stopping service jboss.ws.port-component-link
15:33:09,295 INFO  [org.jboss.weld.deployer] (MSC service thread 1-3) JBAS016009: Stopping weld service for deployment business-central.war
15:33:09,375 INFO  [org.jboss.errai.cdi.server.events.ShutdownEventObserver] (MSC service thread 1-3) Shutting down CDI-to-ErraiBus event bridge
15:33:09,377 INFO  [org.jbpm.executor.impl.ExecutorImpl] (MSC service thread 1-3)  >>>>> Destroying Executor !!!
15:33:09,383 INFO  [org.quartz.core.QuartzScheduler] (MSC service thread 1-3) Scheduler jBPMClusteredScheduler_$_localhost.localdomain1488435870693 shutting down.
15:33:09,383 INFO  [org.quartz.core.QuartzScheduler] (MSC service thread 1-3) Scheduler jBPMClusteredScheduler_$_localhost.localdomain1488435870693 paused.
15:33:09,385 INFO  [org.quartz.core.QuartzScheduler] (MSC service thread 1-3) Scheduler jBPMClusteredScheduler_$_localhost.localdomain1488435870693 shutdown complete.
15:33:09,774 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-5) JBWEB003075: Coyote HTTP/1.1 pausing on: http-127.0.0.1:8080
15:33:09,774 INFO  [org.apache.coyote.http11.Http11Protocol] (MSC service thread 1-5) JBWEB003077: Coyote HTTP/1.1 stopping on : http-127.0.0.1:8080
15:33:17,585 INFO  [stdout] (jBPMClusteredScheduler_Worker-1) S2 : sleep done
15:33:17,588 INFO  [stdout] (jBPMClusteredScheduler_Worker-1) HT1 Entry
15:33:17,591 ERROR [org.jbpm.process.instance.timer.TimerManager] (jBPMClusteredScheduler_Worker-1) Error when executing timer job: org.jbpm.workflow.instance.WorkflowRuntimeException: [project1.helloTimer:1 - HT1:6] -- Runtime manager org.kie.example:project1:1.0.0-SNAPSHOT is already closed
	at org.jbpm.workflow.instance.node.WorkItemNodeInstance.internalTrigger(WorkItemNodeInstance.java:149) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.impl.NodeInstanceImpl.trigger(NodeInstanceImpl.java:173) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.impl.NodeInstanceImpl.triggerNodeInstance(NodeInstanceImpl.java:366) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.impl.NodeInstanceImpl.triggerCompleted(NodeInstanceImpl.java:325) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.node.ActionNodeInstance.triggerCompleted(ActionNodeInstance.java:61) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.node.ActionNodeInstance.internalTrigger(ActionNodeInstance.java:57) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.impl.NodeInstanceImpl.trigger(NodeInstanceImpl.java:173) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.impl.NodeInstanceImpl.triggerNodeInstance(NodeInstanceImpl.java:366) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.impl.NodeInstanceImpl.triggerCompleted(NodeInstanceImpl.java:325) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.impl.ExtendedNodeInstanceImpl.triggerCompleted(ExtendedNodeInstanceImpl.java:44) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.node.StateBasedNodeInstance.triggerCompleted(StateBasedNodeInstance.java:341) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.node.TimerNodeInstance.triggerCompleted(TimerNodeInstance.java:143) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.node.TimerNodeInstance.signalEvent(TimerNodeInstance.java:133) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.impl.WorkflowProcessInstanceImpl.signalEvent(WorkflowProcessInstanceImpl.java:503) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.process.instance.event.DefaultSignalManager.signalEvent(DefaultSignalManager.java:90) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.process.instance.timer.TimerManager$ProcessJob.execute(TimerManager.java:300) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.core.time.SelfRemovalJob.execute(SelfRemovalJob.java:34) [drools-core-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.core.time.impl.DefaultTimerJobInstance.call(DefaultTimerJobInstance.java:69) [drools-core-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.persistence.jpa.JpaTimerJobInstance.internalCall(JpaTimerJobInstance.java:59) [drools-persistence-jpa-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.persistence.jpa.JDKCallableJobCommand.execute(JDKCallableJobCommand.java:35) [drools-persistence-jpa-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.persistence.jpa.JDKCallableJobCommand.execute(JDKCallableJobCommand.java:21) [drools-persistence-jpa-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.core.command.impl.DefaultCommandService.execute(DefaultCommandService.java:36) [drools-core-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.core.command.impl.AbstractInterceptor.executeNext(AbstractInterceptor.java:41) [drools-core-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.persistence.SingleSessionCommandService$TransactionInterceptor.execute(SingleSessionCommandService.java:604) [drools-persistence-jpa-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.core.command.impl.AbstractInterceptor.executeNext(AbstractInterceptor.java:41) [drools-core-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.persistence.jpa.OptimisticLockRetryInterceptor.execute(OptimisticLockRetryInterceptor.java:82) [drools-persistence-jpa-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.core.command.impl.AbstractInterceptor.executeNext(AbstractInterceptor.java:41) [drools-core-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.persistence.jta.TransactionLockInterceptor.execute(TransactionLockInterceptor.java:73) [drools-persistence-jpa-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.persistence.SingleSessionCommandService.execute(SingleSessionCommandService.java:397) [drools-persistence-jpa-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.process.core.timer.impl.GlobalTimerService$DisposableCommandService.execute(GlobalTimerService.java:306) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.persistence.timer.GlobalJpaTimerJobInstance.call(GlobalJpaTimerJobInstance.java:77) [jbpm-persistence-jpa-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.persistence.timer.GlobalJpaTimerJobInstance.call(GlobalJpaTimerJobInstance.java:47) [jbpm-persistence-jpa-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.process.core.timer.impl.QuartzSchedulerService$QuartzJob.execute(QuartzSchedulerService.java:322) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.quartz.core.JobRunShell.run(JobRunShell.java:216) [quartz-1.8.5.jar:]
	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:549) [quartz-1.8.5.jar:]
Caused by: java.lang.IllegalStateException: Runtime manager org.kie.example:project1:1.0.0-SNAPSHOT is already closed
	at org.jbpm.runtime.manager.impl.SingletonRuntimeManager.getRuntimeEngine(SingletonRuntimeManager.java:113) [jbpm-runtime-manager-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.services.task.wih.LocalHTWorkItemHandler.executeWorkItem(LocalHTWorkItemHandler.java:56) [jbpm-human-task-workitems-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.drools.persistence.jpa.processinstance.JPAWorkItemManager.internalExecuteWorkItem(JPAWorkItemManager.java:69) [drools-persistence-jpa-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	at org.jbpm.workflow.instance.node.WorkItemNodeInstance.internalTrigger(WorkItemNodeInstance.java:139) [jbpm-flow-6.5.0.Final-redhat-2.jar:6.5.0.Final-redhat-2]
	... 34 more

15:33:17,618 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-4) JBAS010409: Unbound data source [java:jboss/datasources/quartzUnmanagedDs]
15:33:17,619 INFO  [org.jboss.as.connector.deployment] (MSC service thread 1-8) JBAS010410: Unbound JCA ConnectionFactory [java:/JmsXA]
15:33:17,622 INFO  [org.jboss.as.jpa] (ServerService Thread Pool -- 109) JBAS011403: Stopping Persistence Unit Service 'business-central.war#org.jbpm.domain'
15:33:17,627 INFO  [org.jboss.as.connector.subsystems.datasources] (MSC service thread 1-5) JBAS010409: Unbound data source [java:jboss/MySqlBusinessCentralDS]
15:33:17,644 INFO  [org.hornetq.ra] (ServerService Thread Pool -- 111) HQ151003: HornetQ resource adaptor stopped
15:33:17,689 INFO  [org.hornetq.core.server] (ServerService Thread Pool -- 111) HQ221002: HornetQ Server version 2.3.25.SP14 (2.3.25.SP14, 123) [384404a6-ff10-11e6-81fa-d19ab91e303d] stopped
15:33:17,813 INFO  [org.jboss.as.server.deployment] (MSC service thread 1-1) JBAS015877: Stopped deployment business-central.war (runtime-name: business-central.war) in 9057ms
15:33:17,818 INFO  [org.jboss.as] (MSC service thread 1-4) JBAS015950: JBoss EAP 6.4.11.GA (AS 7.5.11.Final-redhat-1) stopped in 9054ms

        1. org.jbpm.helloTimer.v1.0.bpmn2
          19 kB

              swiderski.maciej Maciej Swiderski (Inactive)
              rhn-support-tkobayas Toshiya Kobayashi
              Marian Macik Marian Macik
              Marian Macik Marian Macik
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

                Created:
                Updated:
                Resolved: