[jboss-jira] [JBoss JIRA] (WFLY-13438) Database Timers: instances sporadically fail to start in a cluster
Enrique González Martínez (Jira)
issues at jboss.org
Wed May 13 09:04:43 EDT 2020
[ https://issues.redhat.com/browse/WFLY-13438?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14095522#comment-14095522 ]
Enrique González Martínez commented on WFLY-13438:
--------------------------------------------------
[~cfang]
we are facing similar problem upon server restart with oracle. I don't believe is the same problem. As the first one is a race condition with the refresh task of the databaseTimerpersistence (I Explained that already in the pull request.
This is related to restart.
{code}
2020-05-12 09:47:21,861 WARN [org.jboss.as.ejb3.timer] (ServerService Thread Pool -- 81) WFLYEJB0161: Failed to reinstate timer 'ROOT.ROOT.EJBTimerScheduler'
id=unavailable) from its persistent state: java.lang.RuntimeException: java.sql.SQLException: ORA-01002: fetch out of sequence
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.timerservice.persistence.database.DatabaseTimerPersistence.loadActiveTimers(DatabaseTimerPersistence.java:512)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.timerservice.TimerServiceImpl.getActivePersistentTimers(TimerServiceImpl.java:979)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.timerservice.TimerServiceImpl.restoreTimers(TimerServiceImpl.java:705)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.timerservice.TimerServiceImpl.activate(TimerServiceImpl.java:223)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.component.EJBComponent.init(EJBComponent.java:598)
at org.jboss.as.ee at 7.2.1.GA-redhat-00004//org.jboss.as.ee.component.BasicComponent.start(BasicComponent.java:222)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.component.singleton.SingletonComponent.start(SingletonComponent.java:136)
at org.jboss.as.ee at 7.2.1.GA-redhat-00004//org.jboss.as.ee.component.ComponentStartService$1.run(ComponentStartService.java:54)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at org.jboss.threads at 2.3.2.Final-redhat-1//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
at org.jboss.threads at 2.3.2.Final-redhat-1//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1985)
at org.jboss.threads at 2.3.2.Final-redhat-1//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1487)
at org.jboss.threads at 2.3.2.Final-redhat-1//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1378)
at java.base/java.lang.Thread.run(Thread.java:834) at org.jboss.threads at 2.3.2.Final-redhat-1//org.jboss.threads.JBossThread.run(JBossThread.java:485) Caused by: java.sql.SQLException: ORA-01002: fetch out of sequence
at com.oracle at 12.1.0.1.0//oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:450)
at com.oracle at 12.1.0.1.0//oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:399)
at com.oracle at 12.1.0.1.0//oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:1017)
at com.oracle at 12.1.0.1.0//oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:655)
at com.oracle at 12.1.0.1.0//oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:249)
at com.oracle at 12.1.0.1.0//oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:566)
at com.oracle at 12.1.0.1.0//oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:215)
at com.oracle at 12.1.0.1.0//oracle.jdbc.driver.T4CPreparedStatement.fetch(T4CPreparedStatement.java:1022)
at com.oracle at 12.1.0.1.0//oracle.jdbc.driver.OracleStatement.fetchMoreRows(OracleStatement.java:3590)
at com.oracle at 12.1.0.1.0//oracle.jdbc.driver.InsensitiveScrollableResultSet.fetchMoreRows(InsensitiveScrollableResultSet.java:1008)
at com.oracle at 12.1.0.1.0//oracle.jdbc.driver.InsensitiveScrollableResultSet.absoluteInternal(InsensitiveScrollableResultSet.java:972)
at com.oracle at 12.1.0.1.0//oracle.jdbc.driver.InsensitiveScrollableResultSet.next(InsensitiveScrollableResultSet.java:572)
at org.jboss.ironjacamar.jdbcadapters at 1.4.15.Final-redhat-00001//org.jboss.jca.adapters.jdbc.WrappedResultSet.next(WrappedResultSet.java:2689)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.timerservice.persistence.database.DatabaseTimerPersistence.loadActiveTimers(DatabaseTimerPersistence.java:468)
... 15 more
{code}
We also se the null pointer exception
{code}
2020-05-12 09:48:47,759 ERROR [org.jboss.as.ejb3.invocation] (default task-3) WFLYEJB0034: EJB Invocation failed on component EJBTimerScheduler for method public void org.jbpm.services.ejb.timer.EJBTimerScheduler.internalSchedule(org.drools.core.time.impl.TimerJobInstance): javax.ejb.EJBTransactionRolledbackException: java.lang.NullPointerException
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInCallerTx(CMTTxInterceptor.java:203)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:364)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:144)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at org.jboss.weld.core at 3.0.5.Final-redhat-00001//org.jboss.weld.module.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:72)
at org.jboss.as.weld.common at 7.2.1.GA-redhat-00004//org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.component.singleton.ContainerManagedConcurrencyInterceptor.processInvocation(ContainerManagedConcurrencyInterceptor.java:106)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.as.ee at 7.2.1.GA-redhat-00004//org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438)
at org.wildfly.security.elytron-private at 1.6.2.Final-redhat-00001//org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:619)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422)
at org.jboss.invocation at 1.5.1.Final-redhat-1//org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53)
at org.jboss.as.ee at 7.2.1.GA-redhat-00004//org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198)
at org.jboss.as.ee at 7.2.1.GA-redhat-00004//org.jboss.as.ee.component.ViewDescription$1.processInvocation(ViewDescription.java:185)
at org.jboss.as.ee at 7.2.1.GA-redhat-00004//org.jboss.as.ee.component.ProxyInvocationHandler.invoke(ProxyInvocationHandler.java:81)
at deployment.ROOT.war//org.jbpm.services.ejb.timer.EJBTimerScheduler$$$view1.internalSchedule(Unknown Source)
...
Caused by: java.lang.NullPointerException
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.timerservice.persistence.database.DatabaseTimerPersistence.addTimer(DatabaseTimerPersistence.java:333)
at org.jboss.as.ejb3 at 7.2.1.GA-redhat-00004//org.jboss.as.ejb3.timerservice.TimerServiceImpl.persistTimer(TimerServiceImpl.java:608)
... 161 more
{code}
> Database Timers: instances sporadically fail to start in a cluster
> ------------------------------------------------------------------
>
> Key: WFLY-13438
> URL: https://issues.redhat.com/browse/WFLY-13438
> Project: WildFly
> Issue Type: Bug
> Components: EJB
> Affects Versions: 19.1.0.Final
> Reporter: Marcos Scholtz
> Assignee: Cheng Fang
> Priority: Major
>
> We use a postgresql database for persistent timers, to control the execution of scheduled tasks in a cluster. It mainly works, but when operating in a cluster and when a server-group is restarted, sometimes individual instances in the cluster fail to start because of an error when reinstating persistent timers.
> Configuration of the Datasource:
> {code}
> <xa-datasource jndi-name="java:/datasources/MonitoringDS" pool-name="MonitoringDS" enabled="true">
> <xa-datasource-property name="ServerName">
> appserver.local
> </xa-datasource-property>
> <xa-datasource-property name="PortNumber">
> 5432
> </xa-datasource-property>
> <xa-datasource-property name="DatabaseName">
> monitoringdb
> </xa-datasource-property>
> <xa-datasource-class>org.postgresql.xa.PGXADataSource</xa-datasource-class>
> <driver>postgresql</driver>
> <security>
> <user-name>xxx</user-name>
> <password>xxx</password>
> </security>
> </xa-datasource>
> {code}
> Configuration of the timer service:
> {code}
> <timer-service thread-pool-name="default" default-data-store="batch-clustered-store">
> <data-stores>
> <file-data-store name="default-file-store" path="timer-service-data" relative-to="jboss.server.data.dir"/>
> <database-data-store name="batch-clustered-store" datasource-jndi-name="java:/datasources/MonitoringDS" database="'postgresql'" partition="${batch.partition}" refresh-interval="60000" allow-execution="true"/>
> </data-stores>
> </timer-service>
> {code}
> Note we use a system-property on the server-group to determine the partition name.
> Also, we made NO changes to the SQL statements in "timer-sql.properties".
> The timer is generated by a `@Schedule` annotation in an EJB like this:
> {code}
> @Schedule(
> dayOfMonth = "${manual.scheduler.dayofmonth:*}",
> dayOfWeek = "${manual.scheduler.dayofweek:*}",
> hour = "${manual.scheduler.hour:2/6}",
> minute = "${manual.scheduler.minute:2}"
> )
> @TransactionAttribute(TransactionAttributeType.NEVER)
> void doPostboxImport() {
> log.info("Starting Postbox Import");
> BatchRuntime.getJobOperator().start("PostboxImportBatchlet", null);
> }
> {code}
> The error we sporadically get when starting more than one instance at the same time (when all instances try to reinstate timers) is like this:
> {code}
> 14:48:28,117 WARN [com.arjuna.ats.arjuna] (ServerService Thread Pool -- 69) {"tenant": "", "clientId": ""} ARJUNA012078: Abort called illegaly on atomic action 0:ffff7f000001:-27f2652e:5eb2b20f:f
> 14:48:28,118 WARN [org.jboss.as.ejb3.timer] (ServerService Thread Pool -- 69) {"tenant": "", "clientId": ""} WFLYEJB0161: Failed to reinstate timer 'postbox-integration-service.postbox-integration-service.PostboxImport' (id=unavailable) from its persistent state: javax.transaction.NotSupportedException: WFTXN0001: A transaction is already in progress
> at org.wildfly.transaction.client at 1.1.9.Final//org.wildfly.transaction.client.ContextTransactionManager.begin(ContextTransactionManager.java:60)
> at org.wildfly.transaction.client at 1.1.9.Final//org.wildfly.transaction.client.ContextTransactionManager.begin(ContextTransactionManager.java:54)
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.timerservice.TimerServiceImpl.getActivePersistentTimers(TimerServiceImpl.java:984)
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.timerservice.TimerServiceImpl.restoreTimers(TimerServiceImpl.java:712)
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.timerservice.TimerServiceImpl.activate(TimerServiceImpl.java:223)
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.component.EJBComponent.init(EJBComponent.java:595)
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.component.stateless.StatelessSessionComponent.init(StatelessSessionComponent.java:110)
> at org.jboss.as.ee at 19.1.0.Final//org.jboss.as.ee.component.BasicComponent.start(BasicComponent.java:222)
> at org.jboss.as.ee at 19.1.0.Final//org.jboss.as.ee.component.ComponentStartService$1.run(ComponentStartService.java:54)
> at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
> at org.jboss.threads at 2.3.3.Final//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
> at org.jboss.threads at 2.3.3.Final//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1982)
> at org.jboss.threads at 2.3.3.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
> at org.jboss.threads at 2.3.3.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
> at java.base/java.lang.Thread.run(Thread.java:834)
> at org.jboss.threads at 2.3.3.Final//org.jboss.threads.JBossThread.run(JBossThread.java:485)
> 14:48:28,153 ERROR [org.jboss.msc.service.fail] (ServerService Thread Pool -- 69) {"tenant": "", "clientId": ""} MSC000001: Failed to start service jboss.deployment.unit."postbox-integration-service-E-SNAPSHOT.war".component.PostboxImport.START: org.jboss.msc.service.StartException in service jboss.deployment.unit."postbox-integration-service-E-SNAPSHOT.war".component.PostboxImport.START: java.lang.RuntimeException: java.lang.NullPointerException
> at org.jboss.as.ee at 19.1.0.Final//org.jboss.as.ee.component.ComponentStartService$1.run(ComponentStartService.java:57)
> at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
> at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
> at org.jboss.threads at 2.3.3.Final//org.jboss.threads.ContextClassLoaderSavingRunnable.run(ContextClassLoaderSavingRunnable.java:35)
> at org.jboss.threads at 2.3.3.Final//org.jboss.threads.EnhancedQueueExecutor.safeRun(EnhancedQueueExecutor.java:1982)
> at org.jboss.threads at 2.3.3.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.doRunTask(EnhancedQueueExecutor.java:1486)
> at org.jboss.threads at 2.3.3.Final//org.jboss.threads.EnhancedQueueExecutor$ThreadBody.run(EnhancedQueueExecutor.java:1377)
> at java.base/java.lang.Thread.run(Thread.java:834)
> at org.jboss.threads at 2.3.3.Final//org.jboss.threads.JBossThread.run(JBossThread.java:485)
> Caused by: java.lang.RuntimeException: java.lang.NullPointerException
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.timerservice.TimerServiceImpl.persistTimer(TimerServiceImpl.java:626)
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.timerservice.TimerServiceImpl.createCalendarTimer(TimerServiceImpl.java:537)
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.timerservice.TimerServiceImpl.loadAutoTimer(TimerServiceImpl.java:388)
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.timerservice.TimerServiceImpl.restoreTimers(TimerServiceImpl.java:774)
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.timerservice.TimerServiceImpl.activate(TimerServiceImpl.java:223)
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.component.EJBComponent.init(EJBComponent.java:595)
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.component.stateless.StatelessSessionComponent.init(StatelessSessionComponent.java:110)
> at org.jboss.as.ee at 19.1.0.Final//org.jboss.as.ee.component.BasicComponent.start(BasicComponent.java:222)
> at org.jboss.as.ee at 19.1.0.Final//org.jboss.as.ee.component.ComponentStartService$1.run(ComponentStartService.java:54)
> ... 8 more
> Caused by: java.lang.NullPointerException
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.timerservice.persistence.database.DatabaseTimerPersistence.addTimer(DatabaseTimerPersistence.java:336)
> at org.jboss.as.ejb3 at 19.1.0.Final//org.jboss.as.ejb3.timerservice.TimerServiceImpl.persistTimer(TimerServiceImpl.java:607)
> ... 16 more
> {code}
> The error seems similar to the one described in WFLY-13386, but the stack trace and the steps to reproduce it seem different to me, so I'm not sure if it's the same problem. The problem also existed in Wildfly 14 , we just updated to 19.1 (also hoping that his error would be corrected).
--
This message was sent by Atlassian Jira
(v7.13.8#713008)
More information about the jboss-jira
mailing list