Uploaded image for project: 'Red Hat Process Automation Manager'
  1. Red Hat Process Automation Manager
  2. RHPAM-2363

[ONE-OFF] (7.4.1) Timers do not recover after database disconnection

XMLWordPrintable

    • Icon: Bug Bug
    • Resolution: Duplicate
    • Icon: Major Major
    • 7.5.0.GA
    • 7.4.1.GA
    • jBPM Core
    • 2019 Week 29-31, 2019 Week 32-34, 2019 Week 35-37, 2019 Week 38-40 (from Sep 16)

      Setup RHPAM with an oracle database from docker, with recovery setup.

      ```
      <validation>
      <validate-on-match>true</validate-on-match>
      <valid-connection-checker class-name="org.jboss.jca.adapters.jdbc.extensions.oracle.OracleValidConnectionChecker"></valid-connection-checker>
      <stale-connection-checker class-name="org.jboss.jca.adapters.jdbc.extensions.oracle.OracleStaleConnectionChecker"></stale-connection-checker>
      <exception-sorter class-name="org.jboss.jca.adapters.jdbc.extensions.oracle.OracleExceptionSorter"></exception-sorter>
      </validation>

      ```

      After run oracle database

      docker run -d -p 8090:8080 -p 1521:1521 -v /home/alberto/redhat/databases/oracle12c:/u01/app/oracle oracle-12c

      and start RHPAM (with the timer project uploaded)

      ./standalone.sh -c standalone-full.xml

      I start to see the messages from timer:

      ```
      14:06:52,266 INFO [stdout] (EJB default - 5) Triggered timer ...
      14:06:53,262 INFO [stdout] (EJB default - 6) Triggered timer ...
      14:06:54,257 INFO [stdout] (EJB default - 7) Triggered timer ...
      ```

      Then when stopped the database:

      docker stop container_name

      I can see error inspecting process instances (see screenshot attached)

      and an error in log for timer

      ```
      14:07:12,362 WARN [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (EJB default - 5) SQL Error: 0, SQLState: null
      14:07:12,362 ERROR [org.hibernate.engine.jdbc.spi.SqlExceptionHelper] (EJB default - 5) javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:jboss/datasources/OracleDS
      14:07:12,363 INFO [org.hibernate.event.internal.DefaultLoadEventListener] (EJB default - 5) HHH000327: Error performing load command : org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection
      14:07:12,364 WARN [org.drools.persistence.PersistableRunner] (EJB default - 5) Could not commit session: org.drools.persistence.api.SessionNotFoundException: Could not find session data for id 1
      at org.drools.persistence.PersistableRunner.initExistingKnowledgeSession(PersistableRunner.java:231)
      at org.drools.persistence.PersistableRunner$TransactionInterceptor.execute(PersistableRunner.java:588)
      at org.drools.persistence.PersistableRunner$TransactionInterceptor.execute(PersistableRunner.java:563)
      at org.drools.core.command.impl.AbstractInterceptor.executeNext(AbstractInterceptor.java:39)
      at org.drools.persistence.jpa.OptimisticLockRetryInterceptor.internalExecute(OptimisticLockRetryInterceptor.java:102)
      at org.drools.persistence.jpa.OptimisticLockRetryInterceptor.execute(OptimisticLockRetryInterceptor.java:83)
      at org.drools.persistence.jpa.OptimisticLockRetryInterceptor.execute(OptimisticLockRetryInterceptor.java:44)
      at org.drools.core.command.impl.AbstractInterceptor.executeNext(AbstractInterceptor.java:39)
      at org.drools.persistence.jta.TransactionLockInterceptor.execute(TransactionLockInterceptor.java:73)
      at org.drools.persistence.jta.TransactionLockInterceptor.execute(TransactionLockInterceptor.java:45)
      at org.drools.core.command.impl.AbstractInterceptor.executeNext(AbstractInterceptor.java:39)
      at org.jbpm.runtime.manager.impl.error.ExecutionErrorHandlerInterceptor.internalExecute(ExecutionErrorHandlerInterceptor.java:66)
      at org.jbpm.runtime.manager.impl.error.ExecutionErrorHandlerInterceptor.execute(ExecutionErrorHandlerInterceptor.java:52)
      at org.jbpm.runtime.manager.impl.error.ExecutionErrorHandlerInterceptor.execute(ExecutionErrorHandlerInterceptor.java:29)
      at org.drools.persistence.PersistableRunner.execute(PersistableRunner.java:398)
      at org.drools.persistence.PersistableRunner.execute(PersistableRunner.java:66)
      at org.drools.core.runtime.InternalLocalRunner.execute(InternalLocalRunner.java:37)
      at org.drools.core.runtime.InternalLocalRunner.execute(InternalLocalRunner.java:35)
      at org.jbpm.process.core.timer.impl.GlobalTimerService$DisposableCommandService.execute(GlobalTimerService.java:346)
      at org.jbpm.process.core.timer.impl.GlobalTimerService$DisposableCommandService.execute(GlobalTimerService.java:323)
      at org.drools.core.runtime.InternalLocalRunner.execute(InternalLocalRunner.java:37)
      at org.drools.core.runtime.InternalLocalRunner.execute(InternalLocalRunner.java:41)
      at org.jbpm.persistence.timer.GlobalJpaTimerJobInstance.call(GlobalJpaTimerJobInstance.java:82)
      at org.jbpm.persistence.timer.GlobalJpaTimerJobInstance.call(GlobalJpaTimerJobInstance.java:49)
      at org.jbpm.services.ejb.timer.EJBTimerScheduler.executeTimerJob(EJBTimerScheduler.java:91)
      at sun.reflect.GeneratedMethodAccessor80.invoke(Unknown Source)
      at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
      at java.lang.reflect.Method.invoke(Method.java:498)
      at org.jboss.as.ee.component.ManagedReferenceMethodInterceptor.processInvocation(ManagedReferenceMethodInterceptor.java:52)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:50)
      at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:61)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
      at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.doMethodInterception(Jsr299BindingsInterceptor.java:90)
      at org.jboss.as.weld.interceptors.Jsr299BindingsInterceptor.processInvocation(Jsr299BindingsInterceptor.java:103)
      at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:61)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.WeavedInterceptor.processInvocation(WeavedInterceptor.java:50)
      at org.jboss.as.ee.component.interceptors.UserInterceptorFactory$1.processInvocation(UserInterceptorFactory.java:61)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.as.ejb3.component.invocationmetrics.ExecutionTimeInterceptor.processInvocation(ExecutionTimeInterceptor.java:43)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.as.ee.concurrent.ConcurrentContextInterceptor.processInvocation(ConcurrentContextInterceptor.java:45)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.InitialInterceptor.processInvocation(InitialInterceptor.java:40)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
      at org.jboss.as.ee.component.interceptors.ComponentDispatcherInterceptor.processInvocation(ComponentDispatcherInterceptor.java:52)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.as.ejb3.component.singleton.SingletonComponentInstanceAssociationInterceptor.processInvocation(SingletonComponentInstanceAssociationInterceptor.java:53)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:237)
      at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:362)
      at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:144)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
      at org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:81)
      at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
      at org.jboss.as.ejb3.component.singleton.ContainerManagedConcurrencyInterceptor.processInvocation(ContainerManagedConcurrencyInterceptor.java:106)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
      at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
      at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
      at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
      at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
      at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:99)
      at org.jboss.as.ejb3.timerservice.TimedObjectInvokerImpl.callTimeout(TimedObjectInvokerImpl.java:109)
      at org.jboss.as.ejb3.timerservice.TimerTask.invokeBeanMethod(TimerTask.java:189)
      at org.jboss.as.ejb3.timerservice.TimerTask.callTimeout(TimerTask.java:185)
      at org.jboss.as.ejb3.timerservice.TimerTask.retryTimeout(TimerTask.java:230)
      at org.jboss.as.ejb3.timerservice.TimerTask.run(TimerTask.java:164)
      at org.jboss.as.ejb3.timerservice.TimerServiceImpl$Task$1.run(TimerServiceImpl.java:1299)
      at org.wildfly.extension.requestcontroller.RequestController$QueuedTask$1.run(RequestController.java:494)
      at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
      at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
      at java.lang.Thread.run(Thread.java:748)
      at org.jboss.threads.JBossThread.run(JBossThread.java:485)
      Caused by: javax.persistence.PersistenceException: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection
      at org.hibernate.internal.ExceptionConverterImpl.convert(ExceptionConverterImpl.java:154)
      at org.hibernate.internal.SessionImpl.find(SessionImpl.java:3512)
      at org.hibernate.internal.SessionImpl.find(SessionImpl.java:3447)
      at org.drools.persistence.jpa.JpaPersistenceContext.findSession(JpaPersistenceContext.java:79)
      at org.drools.persistence.PersistableRunner.initExistingKnowledgeSession(PersistableRunner.java:229)
      ... 91 more
      Caused by: org.hibernate.exception.GenericJDBCException: Unable to acquire JDBC Connection
      at org.hibernate.exception.internal.StandardSQLExceptionConverter.convert(StandardSQLExceptionConverter.java:47)
      at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:113)
      at org.hibernate.engine.jdbc.spi.SqlExceptionHelper.convert(SqlExceptionHelper.java:99)
      at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:109)
      at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.getPhysicalConnection(LogicalConnectionManagedImpl.java:136)
      at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.connection(StatementPreparerImpl.java:47)
      at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$5.doPrepare(StatementPreparerImpl.java:146)
      at org.hibernate.engine.jdbc.internal.StatementPreparerImpl$StatementPreparationTemplate.prepareStatement(StatementPreparerImpl.java:172)
      at org.hibernate.engine.jdbc.internal.StatementPreparerImpl.prepareQueryStatement(StatementPreparerImpl.java:148)
      at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.prepareQueryStatement(AbstractLoadPlanBasedLoader.java:226)
      at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeQueryStatement(AbstractLoadPlanBasedLoader.java:190)
      at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:121)
      at org.hibernate.loader.plan.exec.internal.AbstractLoadPlanBasedLoader.executeLoad(AbstractLoadPlanBasedLoader.java:86)
      at org.hibernate.loader.entity.plan.AbstractLoadPlanBasedEntityLoader.load(AbstractLoadPlanBasedEntityLoader.java:188)
      at org.hibernate.persister.entity.AbstractEntityPersister.load(AbstractEntityPersister.java:4269)
      at org.hibernate.event.internal.DefaultLoadEventListener.loadFromDatasource(DefaultLoadEventListener.java:511)
      at org.hibernate.event.internal.DefaultLoadEventListener.doLoad(DefaultLoadEventListener.java:481)
      at org.hibernate.event.internal.DefaultLoadEventListener.load(DefaultLoadEventListener.java:222)
      at org.hibernate.event.internal.DefaultLoadEventListener.proxyOrLoad(DefaultLoadEventListener.java:281)
      at org.hibernate.event.internal.DefaultLoadEventListener.doOnLoad(DefaultLoadEventListener.java:124)
      at org.hibernate.event.internal.DefaultLoadEventListener.onLoad(DefaultLoadEventListener.java:92)
      at org.hibernate.internal.SessionImpl.fireLoad(SessionImpl.java:1257)
      at org.hibernate.internal.SessionImpl.access$1900(SessionImpl.java:207)
      at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.doLoad(SessionImpl.java:2874)
      at org.hibernate.internal.SessionImpl$IdentifierLoadAccessImpl.load(SessionImpl.java:2848)
      at org.hibernate.internal.SessionImpl.find(SessionImpl.java:3483)
      ... 94 more
      Caused by: java.sql.SQLException: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:jboss/datasources/OracleDS
      at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:146)
      at org.jboss.as.connector.subsystems.datasources.WildFlyDataSource.getConnection(WildFlyDataSource.java:64)
      at org.hibernate.engine.jdbc.connections.internal.DatasourceConnectionProviderImpl.getConnection(DatasourceConnectionProviderImpl.java:122)
      at org.hibernate.internal.NonContextualJdbcConnectionAccess.obtainConnection(NonContextualJdbcConnectionAccess.java:35)
      at org.hibernate.resource.jdbc.internal.LogicalConnectionManagedImpl.acquireConnectionIfNeeded(LogicalConnectionManagedImpl.java:106)
      ... 116 more
      Caused by: javax.resource.ResourceException: IJ000453: Unable to get managed connection for java:jboss/datasources/OracleDS
      at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:690)
      at org.jboss.jca.core.connectionmanager.tx.TxConnectionManagerImpl.getManagedConnection(TxConnectionManagerImpl.java:440)
      at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.allocateConnection(AbstractConnectionManager.java:789)
      at org.jboss.jca.adapters.jdbc.WrapperDataSource.getConnection(WrapperDataSource.java:138)
      ... 120 more
      Caused by: javax.resource.ResourceException: IJ031084: Unable to create connection
      at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.createLocalManagedConnection(LocalManagedConnectionFactory.java:345)
      at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.getLocalManagedConnection(LocalManagedConnectionFactory.java:352)
      at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.createManagedConnection(LocalManagedConnectionFactory.java:287)
      at org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.createConnectionEventListener(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:1326)
      at org.jboss.jca.core.connectionmanager.pool.mcp.SemaphoreConcurrentLinkedDequeManagedConnectionPool.getConnection(SemaphoreConcurrentLinkedDequeManagedConnectionPool.java:499)
      at org.jboss.jca.core.connectionmanager.pool.AbstractPool.getTransactionNewConnection(AbstractPool.java:714)
      at org.jboss.jca.core.connectionmanager.pool.AbstractPool.getConnection(AbstractPool.java:613)
      at org.jboss.jca.core.connectionmanager.AbstractConnectionManager.getManagedConnection(AbstractConnectionManager.java:624)
      ... 123 more
      Caused by: java.sql.SQLException: Listener refused the connection with the following error:
      ORA-12528, TNS:listener: all appropriate instances are blocking new connections

      at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:774)
      at oracle.jdbc.driver.PhysicalConnection.connect(PhysicalConnection.java:688)
      at oracle.jdbc.driver.T4CDriverExtension.getConnection(T4CDriverExtension.java:39)
      at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:691)
      at org.jboss.jca.adapters.jdbc.local.LocalManagedConnectionFactory.createLocalManagedConnection(LocalManagedConnectionFactory.java:321)
      ... 130 more
      Caused by: oracle.net.ns.NetException: Listener refused the connection with the following error:
      ORA-12528, TNS:listener: all appropriate instances are blocking new connections

      at oracle.net.ns.NSProtocolNIO.negotiateConnection(NSProtocolNIO.java:271)
      at oracle.net.ns.NSProtocol.connect(NSProtocol.java:317)
      at oracle.jdbc.driver.T4CConnection.connect(T4CConnection.java:1438)
      at oracle.jdbc.driver.T4CConnection.logon(T4CConnection.java:518)
      ... 134 more
      ```

      After restart the database, process instances are readed again without need to relogin, but timer do not start again.

        1. access to database restored.png
          access to database restored.png
          104 kB
        2. ejb-timer-db-outage.zip
          9 kB
        3. fail to access database.png
          fail to access database.png
          81 kB
        4. timer.zip
          153 kB

              rhn-support-jortizpa Jose Ortiz Padilla
              rhn-support-jortizpa Jose Ortiz Padilla
              Marian Macik Marian Macik
              Marian Macik Marian Macik
              Votes:
              0 Vote for this issue
              Watchers:
              3 Start watching this issue

                Created:
                Updated:
                Resolved: