1 Reply Latest reply on Jul 14, 2010 3:59 PM by jaikiran

    TransactionReaper not respecting timeout?

    hipjon

      I started having an issue with my application under JBoss 6 where some transactions are dieing, seemingly at random. The TransactionReaper appears to be kicking in extremely early. I have not isolated the cause of the issue, but it seems to have started since I added code to my app that calls a SLSB with the TRANSACTION_NEW attribute.

       

      I have created the following test code. Success or failure is unpredictable.

       

      TestResource is a simple JAX-RS/Resteasy class that accesses the TransactionManager, begins a transaction, and sets a long timeout. It then calls a SLSB with TRANSACTION_NEW and sleeps for a while.

       

       

      @Path("/test")
      public class TestResource {
      
          static Logger log = Logger.getLogger(TestResource.class);
      
          @GET
          @Path("/timetest2")
          @Produces("text/plain")
          public void timeTest2() throws Exception {
              TransactionManager tmgr = (TransactionManager)new InitialContext().lookup("java:/TransactionManager");
              tmgr.begin();
              tmgr.setTransactionTimeout(30*60); // 30 minute timeout        
              Transaction tx = tmgr.getTransaction();
              log.info("Started tx: " + tx.toString());
          
              TestBean bean = (TestBean)(new InitialContext().lookup("TestBean/no-interface"));
              bean.sleep(5*1000); // sleep 5 seconds
              
              Thread.sleep(30*1000); // sleep 30 seconds
                      
              log.info("before commit, tx = " + tx.toString());
              tx.commit();
              log.info("after commit, tx = " + tx.toString());
          }
      
      }
      

       

       

       

      Here's the SLSB with TRANSACTION_NEW.

       

       

      @Stateless(name="TestBean")
      public class TestBean {
      
          @TransactionAttribute(TransactionAttributeType.REQUIRES_NEW)
          public void sleep(int time) throws Exception {
              Thread.sleep(time);        
          }
          
      }
      

       

       

      Sometimes the timetest2 method executes and commits the TX without a problem. Sometimes the TransactionReaper kicks in early and the commit fails. Here is the log output of the failure scenario.

       

       

       

       

       

      2010-07-14 15:19:44,958 INFO  [edu.harvard.hul.ois.drs2.services.rest.TestResour
      ce] (http-0.0.0.0-18280-2) Started tx: TransactionImple < ac, BasicAction: 0:fff
      f8067e513:3a42:4c3e07af:6c status: ActionStatus.RUNNING >

      2010-07-14 15:19:49,958 WARN  [com.arjuna.ats.arjuna.logging.arjLoggerI18N] (Thr
      ead-9) [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionRea
      per::check timeout for TX 0:ffff8067e513:3a42:4c3e07af:6c in state  RUN

      2010-07-14 15:19:49,959 WARN  [com.arjuna.ats.arjuna.logging.arjLoggerI18N] (Thr
      ead-10) [com.arjuna.ats.arjuna.coordinator.TransactionReaper_7] - TransactionRea
      per::doCancellations worker Thread[Thread-10,5,jboss] successfully canceled TX 0
      :ffff8067e513:3a42:4c3e07af:6c

      2010-07-14 15:20:19,961 INFO  [edu.harvard.hul.ois.drs2.services.rest.TestResour
      ce] (http-0.0.0.0-18280-2) before commit, tx = TransactionImple < ac, BasicActio
      n: 0:ffff8067e513:3a42:4c3e07af:6c status: ActionStatus.ABORTED >

      2010-07-14 15:20:19,961 ERROR [org.apache.catalina.core.ContainerBase.[jboss.web
      ].[localhost].[/drs].[Resteasy]] (http-0.0.0.0-18280-2) Servlet.service() for se
      rvlet Resteasy threw exception: org.jboss.resteasy.spi.UnhandledException: java.
      lang.IllegalStateException: [com.arjuna.ats.internal.jta.transaction.arjunacore.
      inactive] [com.arjuna.ats.internal.jta.transaction.arjunacore.inactive] The tran
      saction is not active!
          ...snip

      2010-07-14 15:20:19,963 ERROR [org.jboss.web.tomcat.service.jca.CachedConnection
      Valve] (http-0.0.0.0-18280-2) Application error: Resteasy did not complete its t
      ransaction suspended tx=TransactionImple < ac, BasicAction: 0:ffff8067e513:3a42:
      4c3e07af:6c status: ActionStatus.ABORTED >

       

      You can see that the TransactionReaper kicks off just seconds after the TX is created. Is this possibly a bug with calling an EJB with TRANSACTION_NEW?

       

      Thanks,

      Jon