Uploaded image for project: 'WildFly'
  1. WildFly
  2. WFLY-9239

[GSS](7.1.0) Timer fails if transaction isolation set to SERIALIZABLE

    Details

    • Steps to Reproduce:
      Hide

      Set timer persistence to db in domain.xml:

                      <timer-service thread-pool-name="default" default-data-store="default-db-store">
                          <data-stores>
                              <database-data-store name="default-db-store" datasource-jndi-name="java:jboss/datasources/timerDS" database="oracle" partition="default"/>
                          </data-stores>
                      </timer-service>
      
      

      Create a simple timer:

      	@Schedule(hour="*", minute="*", second="*/10")
      	public void testTimer() {
      		logger.warn("Test timer executed at {}", System.currentTimeMillis());
      	}
      

      Either:
      Start the application on a cluster with more than one running node.

      or
      Start only one node of the cluster.
      Start the application. You should see the timer running in the logs.
      Open a session to the database from a db client (i.e. sqlplus)
      Between two timer executions, set the connection to serializable and update the timer's row in the database:

      SET transaction ISOLATION level serializable;
      
      UPDATE JBOSS_EJB_TIMER
      SET NEXT_DATE        ='16-MÁRC. -18 23.30.00,000000000',
        PREVIOUS_RUN       ='16-MÁRC. -18 23.30.00,000000000' ,
        TIMER_STATE        ='ACTIVE'
      WHERE TIMED_OBJECT_ID='app-1.0.0-SNAPSHOT.app-1.0.0-SNAPSHOT.TimerService'
      AND ID               ='db266f25-883a-44ec-845f-4e45fe727a3a'
      AND PARTITION_NAME   ='default';
      

      Until the transaction is commited, the server does not log any more execution since the server's connection is blocked until commit.
      After the transaction in sqlplus is commited the server throws a jdbcException with root cause
      ORA-08177: can't serialize access for this transaction

      Test results:

      [Server:server-one] 16:05:10,008 WARN  [hu.eeszt.batch.UtemezoService] (EJB default - 2) Test timer executed at 1458572710008
      [Server:server-one] 16:05:20,009 WARN  [hu.eeszt.batch.UtemezoService] (EJB default - 7) Test timer executed at 1458572720009
      [Server:server-one] 16:05:30,008 WARN  [hu.eeszt.batch.UtemezoService] (EJB default - 4) Test timer executed at 1458572730008
      [Server:server-one] 16:05:42,792 ERROR [org.jboss.as.ejb3] (EJB default - 8) WFLYEJB0164: Exception running timer task for timer [id=db266f25-883a-44ec-845f-4e45fe727a3a timedObjectId=jelenteskezelo-1.0.0-SNAPSHOT.jelenteskezelo-1.0.0-SNAPSHOT.UtemezoService auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@5ae465ae initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Mon Mar 21 16:05:40 CET 2016 timerState=ACTIVE info=null] on EJB jelenteskezelo-1.0.0-SNAPSHOT.jelenteskezelo-1.0.0-SNAPSHOT.UtemezoService: java.lang.RuntimeException: java.sql.SQLException: ORA-08177: can't serialize access for this transaction
      [Server:server-one]
      [Server:server-one]     at org.jboss.as.ejb3.timerservice.persistence.database.DatabaseTimerPersistence.shouldRun(DatabaseTimerPersistence.java:421)
      [Server:server-one]     at org.jboss.as.ejb3.timerservice.TimerServiceImpl.shouldRun(TimerServiceImpl.java:1117)
      [Server:server-one]     at org.jboss.as.ejb3.timerservice.TimerTask.run(TimerTask.java:124)
      [Server:server-one]     at org.jboss.as.ejb3.timerservice.TimerServiceImpl$Task$1.run(TimerServiceImpl.java:1221)
      [Server:server-one]     at org.wildfly.extension.requestcontroller.RequestController$QueuedTask$1.run(RequestController.java:497)
      [Server:server-one]     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
      [Server:server-one]     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
      [Server:server-one]     at java.lang.Thread.run(Thread.java:745)
      [Server:server-one]     at org.jboss.threads.JBossThread.run(JBossThread.java:320)
      [Server:server-one] Caused by: java.sql.SQLException: ORA-08177: can't serialize access for this transaction
      [Server:server-one]
      [Server:server-one]     at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:447)
      [Server:server-one]     at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:396)
      [Server:server-one]     at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:951)
      [Server:server-one]     at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:513)
      [Server:server-one]     at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:227)
      [Server:server-one]     at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:531)
      [Server:server-one]     at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:208)
      [Server:server-one]     at oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:1046)
      [Server:server-one]     at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1336)
      [Server:server-one]     at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3613)
      [Server:server-one]     at oracle.jdbc.driver.OraclePreparedStatement.executeUpdate(OraclePreparedStatement.java:3694)
      [Server:server-one]     at oracle.jdbc.driver.OraclePreparedStatementWrapper.executeUpdate(OraclePreparedStatementWrapper.java:1354)
      [Server:server-one]     at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:537)
      [Server:server-one]     at org.jboss.as.ejb3.timerservice.persistence.database.DatabaseTimerPersistence.shouldRun(DatabaseTimerPersistence.java:410)
      [Server:server-one]     ... 8 more
      [Server:server-one]
      
      
      
      Show
      Set timer persistence to db in domain.xml: <timer-service thread-pool-name= " default " default -data-store= " default -db-store" > <data-stores> <database-data-store name= " default -db-store" datasource-jndi-name= "java:jboss/datasources/timerDS" database= "oracle" partition= " default " /> </data-stores> </timer-service> Create a simple timer: @Schedule(hour= "*" , minute= "*" , second= "*/10" ) public void testTimer() { logger.warn( "Test timer executed at {}" , System .currentTimeMillis()); } Either: Start the application on a cluster with more than one running node. or Start only one node of the cluster. Start the application. You should see the timer running in the logs. Open a session to the database from a db client (i.e. sqlplus) Between two timer executions, set the connection to serializable and update the timer's row in the database: SET transaction ISOLATION level serializable; UPDATE JBOSS_EJB_TIMER SET NEXT_DATE = '16-MÁRC. -18 23.30.00,000000000' , PREVIOUS_RUN = '16-MÁRC. -18 23.30.00,000000000' , TIMER_STATE = 'ACTIVE' WHERE TIMED_OBJECT_ID= 'app-1.0.0-SNAPSHOT.app-1.0.0-SNAPSHOT.TimerService' AND ID = 'db266f25-883a-44ec-845f-4e45fe727a3a' AND PARTITION_NAME = ' default ' ; Until the transaction is commited, the server does not log any more execution since the server's connection is blocked until commit. After the transaction in sqlplus is commited the server throws a jdbcException with root cause ORA-08177: can't serialize access for this transaction Test results: [Server:server-one] 16:05:10,008 WARN [hu.eeszt.batch.UtemezoService] (EJB default - 2) Test timer executed at 1458572710008 [Server:server-one] 16:05:20,009 WARN [hu.eeszt.batch.UtemezoService] (EJB default - 7) Test timer executed at 1458572720009 [Server:server-one] 16:05:30,008 WARN [hu.eeszt.batch.UtemezoService] (EJB default - 4) Test timer executed at 1458572730008 [Server:server-one] 16:05:42,792 ERROR [org.jboss.as.ejb3] (EJB default - 8) WFLYEJB0164: Exception running timer task for timer [id=db266f25-883a-44ec-845f-4e45fe727a3a timedObjectId=jelenteskezelo-1.0.0-SNAPSHOT.jelenteskezelo-1.0.0-SNAPSHOT.UtemezoService auto-timer?:true persistent?:true timerService=org.jboss.as.ejb3.timerservice.TimerServiceImpl@5ae465ae initialExpiration=null intervalDuration(in milli sec)=0 nextExpiration=Mon Mar 21 16:05:40 CET 2016 timerState=ACTIVE info=null] on EJB jelenteskezelo-1.0.0-SNAPSHOT.jelenteskezelo-1.0.0-SNAPSHOT.UtemezoService: java.lang.RuntimeException: java.sql.SQLException: ORA-08177: can't serialize access for this transaction [Server:server-one] [Server:server-one] at org.jboss.as.ejb3.timerservice.persistence.database.DatabaseTimerPersistence.shouldRun(DatabaseTimerPersistence.java:421) [Server:server-one] at org.jboss.as.ejb3.timerservice.TimerServiceImpl.shouldRun(TimerServiceImpl.java:1117) [Server:server-one] at org.jboss.as.ejb3.timerservice.TimerTask.run(TimerTask.java:124) [Server:server-one] at org.jboss.as.ejb3.timerservice.TimerServiceImpl$Task$1.run(TimerServiceImpl.java:1221) [Server:server-one] at org.wildfly.extension.requestcontroller.RequestController$QueuedTask$1.run(RequestController.java:497) [Server:server-one] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [Server:server-one] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [Server:server-one] at java.lang.Thread.run(Thread.java:745) [Server:server-one] at org.jboss.threads.JBossThread.run(JBossThread.java:320) [Server:server-one] Caused by: java.sql.SQLException: ORA-08177: can't serialize access for this transaction [Server:server-one] [Server:server-one] at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:447) [Server:server-one] at oracle.jdbc.driver.T4CTTIoer.processError(T4CTTIoer.java:396) [Server:server-one] at oracle.jdbc.driver.T4C8Oall.processError(T4C8Oall.java:951) [Server:server-one] at oracle.jdbc.driver.T4CTTIfun.receive(T4CTTIfun.java:513) [Server:server-one] at oracle.jdbc.driver.T4CTTIfun.doRPC(T4CTTIfun.java:227) [Server:server-one] at oracle.jdbc.driver.T4C8Oall.doOALL(T4C8Oall.java:531) [Server:server-one] at oracle.jdbc.driver.T4CPreparedStatement.doOall8(T4CPreparedStatement.java:208) [Server:server-one] at oracle.jdbc.driver.T4CPreparedStatement.executeForRows(T4CPreparedStatement.java:1046) [Server:server-one] at oracle.jdbc.driver.OracleStatement.doExecuteWithTimeout(OracleStatement.java:1336) [Server:server-one] at oracle.jdbc.driver.OraclePreparedStatement.executeInternal(OraclePreparedStatement.java:3613) [Server:server-one] at oracle.jdbc.driver.OraclePreparedStatement.executeUpdate(OraclePreparedStatement.java:3694) [Server:server-one] at oracle.jdbc.driver.OraclePreparedStatementWrapper.executeUpdate(OraclePreparedStatementWrapper.java:1354) [Server:server-one] at org.jboss.jca.adapters.jdbc.WrappedPreparedStatement.executeUpdate(WrappedPreparedStatement.java:537) [Server:server-one] at org.jboss.as.ejb3.timerservice.persistence.database.DatabaseTimerPersistence.shouldRun(DatabaseTimerPersistence.java:410) [Server:server-one] ... 8 more [Server:server-one]
    • Affects:
      Compatibility/Configuration, User Experience
    • Workaround:
      Workaround Exists
    • Workaround Description:
      Hide

      The timer persistence will work correct if the READ_COMMITED transaction isolation is used

      Show
      The timer persistence will work correct if the READ_COMMITED transaction isolation is used
    • Estimated Difficulty:
      Medium

      Description

      If the transaction isolation level is set to SERIALIZABLE if one node aquires the row lock via the
      UPDATE JBOSS_EJB_TIMER..
      the other nodes throw an
      ORA-08177: can't serialize access for this transaction
      exception.

      The timer thats row threw the exception never runs any more, not even in case the other nodes were shut down.
      The serialization exception is also thrown upon server/application startup sometimes.

        Gliffy Diagrams

          Attachments

            Issue Links

              Activity

                People

                • Assignee:
                  swd847 Stuart Douglas
                  Reporter:
                  swd847 Stuart Douglas
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  2 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved: