10 Replies Latest reply on Sep 26, 2012 6:05 AM by jaikiran

    Usertransaction behaviour question

    markus78

      Hello,

       

      If I create 2 EJB3 beans , beanA and beanB , beanA is very simple

       

       

      @Stateless
      @TransactionManagement(TransactionManagementType.BEAN)
      public class TestBean implements TestBeanBI {
      
                @Resource
                private UserTransaction ut;
      
                @Override
                public String sayHello() throws SystemException, NotSupportedException, SecurityException, IllegalStateException, RollbackException, HeuristicMixedException, HeuristicRollbackException {
                          System.err.println("Hello from BeanA!");
                           ut.setTransactionTimeout(4);
                          ut.begin();
                          System.err.println("transactional stuff here...");
                          ut.commit();
                           return null;
                }
      
      
      }
      
      

       

      And BeanB is equally simple

       

       

      @Stateless
      @TransactionManagement(TransactionManagementType.CONTAINER)
      public class SecondTestBean implements SecondTestBeanBI {
      
                @Override
                public String sayHello()  {
                          System.err.println("Hello from BeanB, I expect the container to handle my transaction!");
                          return null;
                }
      
      
      }
      
      

       

      Now if I invoke on these beans with a ejb beanpool of 10 , I notice that EJB-THREAD-1 gets a 4 second transaction timeout

       

      20:05:18,635 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::insert ( BasicAction: 0:ffff7f000101:-6e233d51:5061f1e6:1c status: ActionStatus.RUNNING, 4 )

      20:05:18,636 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) ReaperElement::ReaperElement ( BasicAction: 0:ffff7f000101:-6e233d51:5061f1e6:1c status: ActionStatus.RUNNING, 4 )

      20:05:18,637 ERROR [stderr] (EJB default - 1) Hello from BeanA!

       

      And BeanB gets my server default timeout which is 300 seconds

       

      But If I invoke on BeanB enough many times it will reuse the (EJB default - 1) thread , and when that happens it gets the last set usertransaction timeout setting, not the server default..

       

      consider this code

       

      remote = (TestBeanBI)context.lookup("TestEAR/BeanTest/TestBean!com.test.TestBeanBI");
      remote.sayHello();  // This creates a 4 second timeout as i expect on the EJB default-1 thread
      
      second_remote = (SecondTestBeanBI)context.lookup("TestEAR/BeanTest/SecondTestBean!com.test.SecondTestBeanBI");
      second_remote.sayHello(); // This creates a 300 second TX timeout as expected on the EJB default-2 thread
      
      second_remote = (SecondTestBeanBI)context.lookup("TestEAR/BeanTest/SecondTestBean!com.test.SecondTestBeanBI");
      second_remote.sayHello(); // ok EJB default-3
      
      second_remote = (SecondTestBeanBI)context.lookup("TestEAR/BeanTest/SecondTestBean!com.test.SecondTestBeanBI");
      second_remote.sayHello(); // ok EJB default-4
      
      second_remote = (SecondTestBeanBI)context.lookup("TestEAR/BeanTest/SecondTestBean!com.test.SecondTestBeanBI");
      second_remote.sayHello(); // ok EJB default-5
      
      second_remote = (SecondTestBeanBI)context.lookup("TestEAR/BeanTest/SecondTestBean!com.test.SecondTestBeanBI");
      second_remote.sayHello(); // ok EJB default-6
      
      second_remote = (SecondTestBeanBI)context.lookup("TestEAR/BeanTest/SecondTestBean!com.test.SecondTestBeanBI");
      second_remote.sayHello(); // ok EJB default-7
      
      second_remote = (SecondTestBeanBI)context.lookup("TestEAR/BeanTest/SecondTestBean!com.test.SecondTestBeanBI");
      second_remote.sayHello(); // ok EJB default-8
      
      second_remote = (SecondTestBeanBI)context.lookup("TestEAR/BeanTest/SecondTestBean!com.test.SecondTestBeanBI");
      second_remote.sayHello(); // ok EJB default-9
      
      second_remote = (SecondTestBeanBI)context.lookup("TestEAR/BeanTest/SecondTestBean!com.test.SecondTestBeanBI");
      second_remote.sayHello(); // ok EJB default-10
      
      // The remoting threadpool is of size 10 so here we start over on thread 1 again..
      
      second_remote = (SecondTestBeanBI)context.lookup("TestEAR/BeanTest/SecondTestBean!com.test.SecondTestBeanBI");
      second_remote.sayHello(); // !!  EJB default-1 thread used, and thus this method does not get a 300 second timeout but a 4 second timeout again...
      
      

       

      After running the above I see this in the logs, the last part is the "problem"

       

      20:28:34,479 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::insert ( BasicAction: 0:ffff7f000101:-5e97589:5061f7c8:8 status: ActionStatus.RUNNING, 4 )
      20:28:34,483 ERROR [stderr] (EJB default - 1) Hello from BeanA!
      20:28:34,483 ERROR [stderr] (EJB default - 1) some transactional stuff
      
      
      20:28:34,517 TRACE [com.arjuna.ats.arjuna] (EJB default - 2) TransactionReaper::insert ( BasicAction: 0:ffff7f000101:-5e97589:5061f7c8:9 status: ActionStatus.RUNNING, 300 )
      20:28:34,519 ERROR [stderr] (EJB default - 2) Hello from BeanB, I expect the container to handle my transaction!
      
      
      20:28:34,543 TRACE [com.arjuna.ats.arjuna] (EJB default - 3) TransactionReaper::insert ( BasicAction: 0:ffff7f000101:-5e97589:5061f7c8:a status: ActionStatus.RUNNING, 300 )
      20:28:34,544 ERROR [stderr] (EJB default - 3) Hello from BeanB, I expect the container to handle my transaction!
      
      
      20:28:34,561 TRACE [com.arjuna.ats.arjuna] (EJB default - 4) TransactionReaper::insert ( BasicAction: 0:ffff7f000101:-5e97589:5061f7c8:b status: ActionStatus.RUNNING, 300 )
      20:28:34,562 ERROR [stderr] (EJB default - 4) Hello from BeanB, I expect the container to handle my transaction!
      
      
      20:28:34,581 TRACE [com.arjuna.ats.arjuna] (EJB default - 5) TransactionReaper::insert ( BasicAction: 0:ffff7f000101:-5e97589:5061f7c8:c status: ActionStatus.RUNNING, 300 )
      20:28:34,583 ERROR [stderr] (EJB default - 5) Hello from BeanB, I expect the container to handle my transaction!
      
      
      20:28:34,598 TRACE [com.arjuna.ats.arjuna] (EJB default - 6) TransactionReaper::insert ( BasicAction: 0:ffff7f000101:-5e97589:5061f7c8:d status: ActionStatus.RUNNING, 300 )
      20:28:34,599 ERROR [stderr] (EJB default - 6) Hello from BeanB, I expect the container to handle my transaction!
      
      
      20:28:34,615 TRACE [com.arjuna.ats.arjuna] (EJB default - 7) TransactionReaper::insert ( BasicAction: 0:ffff7f000101:-5e97589:5061f7c8:e status: ActionStatus.RUNNING, 300 )
      20:28:34,617 ERROR [stderr] (EJB default - 7) Hello from BeanB, I expect the container to handle my transaction!
      
      
      20:28:34,640 TRACE [com.arjuna.ats.arjuna] (EJB default - 8) TransactionReaper::insert ( BasicAction: 0:ffff7f000101:-5e97589:5061f7c8:f status: ActionStatus.RUNNING, 300 )
      20:28:34,641 ERROR [stderr] (EJB default - 8) Hello from BeanB, I expect the container to handle my transaction!
      
      
      20:28:34,658 TRACE [com.arjuna.ats.arjuna] (EJB default - 9) TransactionReaper::insert ( BasicAction: 0:ffff7f000101:-5e97589:5061f7c8:10 status: ActionStatus.RUNNING, 300 )
      20:28:34,659 ERROR [stderr] (EJB default - 9) Hello from BeanB, I expect the container to handle my transaction!
      
      
      20:28:34,674 TRACE [com.arjuna.ats.arjuna] (EJB default - 10) TransactionReaper::insert ( BasicAction: 0:ffff7f000101:-5e97589:5061f7c8:11 status: ActionStatus.RUNNING, 300 )
      20:28:34,675 ERROR [stderr] (EJB default - 10) Hello from BeanB, I expect the container to handle my transaction!
      
      
      20:28:34,691 TRACE [com.arjuna.ats.arjuna] (EJB default - 1) TransactionReaper::insert ( BasicAction: 0:ffff7f000101:-5e97589:5061f7c8:12 status: ActionStatus.RUNNING, 4 )
      20:28:34,692 ERROR [stderr] (EJB default - 1) Hello from BeanB, I expect the container to handle my transaction!
      
      

       

      As you can see "BeanB" gets a 4 second transaction when it gets the (EJB default - 1) thread from the pool.

      I hope my question made some sort of sense, is this correct behaviour?

       

       

       

       


        • 1. Re: Usertransaction behaviour question
          jaikiran

          It's a bug in JBossTS project which seems to be using a ThreadLocal to set the transaction timeouts but isn't clearing it. As a result, the transaction timeout value is leaking. Thanks for bringing this up.

          • 2. Re: Usertransaction behaviour question
            jaikiran
            • 3. Re: Usertransaction behaviour question
              markus78

              Thanks! This issue has been driving me nuts, with symptoms like intermittent TX timeouts in random testcases...

               

              /Markus

              • 4. Re: Usertransaction behaviour question
                jhalliday

                "public void setTransactionTimeout(int seconds) throws SystemException

                Modify the timeout value that is associated with transactions started by subsequent invocations of the begin method by the current thread."

                - JTA 1.1 specification, page 40.

                 

                Eplain to me how the observed behavior is a bug?

                • 5. Re: Usertransaction behaviour question
                  jaikiran

                  Jonathan Halliday wrote:

                   

                  "public void setTransactionTimeout(int seconds) throws SystemException

                  Modify the timeout value that is associated with transactions started by subsequent invocations of the begin method by the current thread."

                  - JTA 1.1 specification, page 40.

                   

                  Eplain to me how the observed behavior is a bug?

                  I'll have to check some spec then. My understanding was that the timeout would be scoped to the transaction itself and would be reset once the transaction completes. Otherwise the current behaviour can easily lead to unintended broken applications in an application server enviroment:

                   

                  1) Server hosts 2 apps

                  2) App 1 set tx timeout to X seconds (which is lower than the default timeout)

                  3) App 2 at a later point in time ends up being given the same thread on which App 1 set the timeout and potentially fails.

                  • 6. Re: Usertransaction behaviour question
                    jaikiran

                    jaikiran pai wrote:

                    Otherwise the current behaviour can easily lead to unintended broken applications in an application server enviroment:

                     

                    1) Server hosts 2 apps

                    2) App 1 set tx timeout to X seconds (which is lower than the default timeout)

                    3) App 2 at a later point in time ends up being given the same thread on which App 1 set the timeout and potentially fails.

                    Unless of course it's the application server's responsibility to reset the timeout while it's handing out that user transaction to the application. I'll need to read the spec a bit more.

                    • 7. Re: Usertransaction behaviour question
                      jhalliday

                      Per the spec the timeout is NOT scoped to the transaction, it's scoped to the Thread. If you want to reset it, you explicitly call setTransactionTimeout(0). Arguably in a Thread pooled environment it's the job of the pooling logic to do that, to give the user the impression they have a new Thread even when it's actually recycled. But that's for the EJB container to address, not the transaction manager. The TM is not aware of the thread pooling and has no opportunity to do such a reset.  This is not a TM bug.

                      • 8. Re: Usertransaction behaviour question
                        jaikiran

                        Jonathan Halliday wrote:

                         

                        But that's for the EJB container to address, not the transaction manager. The TM is not aware of the thread pooling and has no opportunity to do such a reset.  This is not a TM bug.

                        Makes sense. I have rejected that JIRA and this needs to be tackled in AS.

                        • 9. Re: Usertransaction behaviour question
                          markus78

                          I agree , the threadpooling logic seems to be the culprit. Please let me know the Jira number if you write a newone.

                          • 10. Re: Usertransaction behaviour question
                            jaikiran