1 2 Previous Next 20 Replies Latest reply on Feb 22, 2010 11:27 AM by andy.miller

    Transaction Behavior Question

    andy.miller

      I have an application that has a servlet that calls a stateless session bean.

       

      That stateless session bean, in turns enqueues messages (10 of them) into a JMS queue.

       

      There is then an MDB, with its onMessage method, and that method, in turn calls back to the same stateless session bean to process the message(s) (a different method of course.

       

      I have the method for enqueue's the messages to the queue with the default transaction attribute, which should be REQUIRES (no annotation), and its method should commit on exit after enqueueing its messages.

       

      Then the onMessage method should be also REQUIRES, since and MDB can only have REQUIRES or NOT_SUPPORTED as its transaction attributes.

       

      Now, when the onMessage method calls the other method in the same stateless session bean that enqueued the message the MDB dequeued, that method is mark as REQUIRES_NEW, using the @TransactionAttribute(TransactionAttributeType.REQUIRES_NEW) annotation, and it also has a @TransactionTimeout(1200) annotation to override the default timeout of 300 seconds.  So, I'm expecting that the transaction from the onMessage method to be suspended, and a new transaction to be created with a timeout of 1200 seconds, but the transaction timeouts at five mintues every time.

       

      So, in summary Servlet's doGet -> StatelessBean.queueMessages -> MDB.onMessage -> StatelessBean.doWork

       

      My expected result is a new transaction is created on the queueMessages method, and when it successfully returns (which it does) from enqueueing the message, it commits (persistent messages).  Then the MDB.onMessage method starts a new transaction, which gets suspended when it calls StatelessBean.doWork, and on that method a new transaction is started with a timeout of 1200 seconds.  When that method completes, its transaction is committed, and when we return to the MDB.onMessage method, its transaction is resume, and committed.

       

      Is there some behavior that I misunderstood?  I even tried putting a @TransactionTime(1200) on the onMessage method of the MDB, but that didn't change the behavior.  I understood that when you cross bean boundaries is the only point in which you can change the transaction propagation, and that's what I'm doing.

       

      Anyway, any help in why this doesn't work would be appreciated, and JBoss AS 5.1.0 is the target.

        • 1. Re: Transaction Behavior Question
          jaikiran

          andy.miller@jboss.com wrote:

           

          that method is mark as REQUIRES_NEW, using the @TransactionAttribute(TransactionAttributeType.REQUIRES_NEW) annotation, and it also has a @TransactionTimeout(1200) annotation to override the default timeout of 300 seconds.  So, I'm expecting that the transaction from the onMessage method to be suspended, and a new transaction to be created with a timeout of 1200 seconds, but the transaction timeouts at five mintues every time.

           


          By any chance, are you using the outdated org.jboss.annotation.ejb.* package for the TransactionTimeout annotation? The JBoss EJB3 specific annotations have been moved to org.jboss.ejb3.annotation package. So for this one, you need org.jboss.ejb3.annotation.TransactionTimeout

           

           


          • 2. Re: Transaction Behavior Question
            andy.miller

            jaikiran wrote:

             

            andy.miller@jboss.com wrote:

             

            that method is mark as REQUIRES_NEW, using the @TransactionAttribute(TransactionAttributeType.REQUIRES_NEW) annotation, and it also has a @TransactionTimeout(1200) annotation to override the default timeout of 300 seconds.  So, I'm expecting that the transaction from the onMessage method to be suspended, and a new transaction to be created with a timeout of 1200 seconds, but the transaction timeouts at five mintues every time.

             


            By any chance, are you using the outdated org.jboss.annotation.ejb.* package for the TransactionTimeout annotation? The JBoss EJB3 specific annotations have been moved to org.jboss.ejb3.annotation package. So for this one, you need org.jboss.ejb3.annotation.TransactionTimeout

             

             

            I am using the correct annotation.  I just double checked, and I'm importing org.jboss.ejb3.annotation.TransactionTimeout.  I know this works as well, as I had just a regular stateless session bean with this annotation, and the timeout was overridden properly.

            • 3. Re: Transaction Behavior Question
              jaikiran
              Tried out simple test:
              
              SLSB1 - responsible for sending message to a queue
              
              {code:java}
              @Stateless
              @Remote (MessagePublisher.class)
              @RemoteBinding (jndiBinding = MessagePublisherBean.JNDI_NAME)
              public class MessagePublisherBean implements MessagePublisher
              {
                 public static final String JNDI_NAME = "publisher";
                 
                 public void publishMessage(String queueJNDIName) 
                 {
                    
                    try
                    {
                       Context ctx = new InitialContext();
                       QueueConnectionFactory queueConnFactory = (QueueConnectionFactory) ctx.lookup("ConnectionFactory");
                       Queue queue = (Queue) ctx.lookup(queueJNDIName);
                       QueueConnection connection = queueConnFactory.createQueueConnection();
                       QueueSession session = connection.createQueueSession(false, Session.AUTO_ACKNOWLEDGE);
                       QueueSender sender = session.createSender(queue);
                       Message message = session.createTextMessage("this is a test message at " + new Date(System.currentTimeMillis()));
                       
                       sender.send(message);
                       System.out.println("Message sent to queue " + queue);
                    }
                    catch (Exception e)
                    {
                       throw new RuntimeException(e);
                    }
                    
                    
                 }
              
              }
              {code}
              
              MDB - listening on the queue, in onMessage triggers a long running task (SLSB2)
              
              {code:java}
              @MessageDriven(activationConfig =
              {
              @ActivationConfigProperty(propertyName="destinationType",
              propertyValue="javax.jms.Queue"),
              @ActivationConfigProperty(propertyName="destination",
              propertyValue="queue/test123"),
              @ActivationConfigProperty(propertyName = "maxSession", propertyValue = "1")
              })
              public class SimpleMDB implements MessageListener
              {
              
                 @EJB
                 private TimeConsumingTask longRunningTask;
                 
                 @TransactionAttribute(TransactionAttributeType.REQUIRED)
                 public void onMessage(Message message)
                 {
                    try
                    {
                       TextMessage textMessage = (TextMessage) message;
                       System.out.println("Got message " + textMessage.getText());
                       this.longRunningTask.doTask();
                    }
                    catch (Exception e)
                    {
                       // eat it up to avoid re-delivery
                       e.printStackTrace();
                    }
                    
                 }
              
              }
              {code}
              
              SLSB2 - A bean with method set to TransactionTimeout of 60 seconds and tx attribute REQUIRES_NEW:
              
              {code:java}
              @Stateless
              @Remote (TimeConsumingTask.class)
              @RemoteBinding (jndiBinding = SleepingTask.JNDINAME)
              public class SleepingTask implements TimeConsumingTask
              {
              
                 public static final String JNDINAME = "Timeconsumingtask-remote";
                 
                 @Resource(mappedName = "java:/DefaultDS")
                 private DataSource dataSource;
              
                 @TransactionAttribute(TransactionAttributeType.REQUIRES_NEW)
                 @TransactionTimeout(60)
                 public void doTask()
                 {
                    try
                    {
              
                       // just a simple lookup of datasource and then
                       // get and close a connection to ensure everthing is fine
                       System.out.println("testing connection from tx aware datasource");
                       testConnection();
                       System.out.println("successfully acquired connection.");
              
                       System.out.println("Now sleeping for 30 seconds...");
                       Thread.sleep(30000);
                       System.out.println("woke up after 30 seconds, tx is expected to be active");
                       testConnection();
                       System.out.println("successfully acquired connection from tx aware datasource");
                       System.out.println("Now going back to sleep for 40 seconds...");
                       Thread.sleep(40000);
                       System.out.println("woke up after 40 seconds, tx is expected to have timed out");
                       try
                       {
                          testConnection();
                       }
                       catch (Throwable t)
                       {
                          System.out.println("SUCCESS! Expected tx timeout error");
                          t.printStackTrace();
                          return;
                       }
                       
                       System.out.println("Failure! Unexpectedly, acquired a connection from tx aware datasource. tx was expected to have timed out");
                       throw new RuntimeException("Tx did NOT timeout");
                       
                    }
                    catch (Exception e)
                    {
                       throw new RuntimeException(e);
                    }
              
                 }
              
                 private void testConnection()
                 {
                    Connection conn = null;
                    try
                    {
                       conn = this.dataSource.getConnection();
                       System.out.println("Got connection");
                    }
                    catch (Throwable t)
                    {
                       System.out.println("Error while getting connection from tx aware datasource: ");
                       throw new RuntimeException(t);
                    }
                    finally
                    {
                       if (conn != null)
                       {
                          try
                          {
                             conn.close();
                          }
                          catch (SQLException e)
                          {
                             System.out.println("Error closing connection " + e.getMessage());
                          }
                       }
                    }
                 }
              }
              
              {code}
              
              This SLSB2 has tx timeout set to 60 seconds and tx attribute to REQUIRES_NEW. The method works as follows
              
              1) On entry into methods gets a connection from a tx aware datasource - this step is just for testing the setup
              2) Sleeps for 30 seconds.
              3) After waking up after 30 seconds tries to get connection again from the tx aware datasource - Expected to pass since tx is still active
              4) Goes back to sleep for 40 more seconds (i.e. sleep till tx times out)
              5) After waking up for a second time, tries to get a connection again from the tx aware datasource - Expected to FAIL since the tx has timed out.
              
              This works as expected. i.e. Step#5 throws Tx not active exception. Here's some logs:
              
              {code}
              18:05:58,676 INFO  [STDOUT] Message sent to queue JBossQueue[test123]
              18:05:58,784 INFO  [STDOUT] Got message this is a test message at Wed Feb 17 18:05:58 IST 2010
              18:05:58,931 INFO  [STDOUT] testing connection from tx aware datasource
              18:05:58,936 INFO  [STDOUT] Got connection
              18:05:58,936 INFO  [STDOUT] successfully acquired connection.
              18:05:58,937 INFO  [STDOUT] Now sleeping for 30 seconds...
              18:06:28,944 INFO  [STDOUT] woke up after 30 seconds, tx is expected to be active
              18:06:28,946 INFO  [STDOUT] Got connection
              18:06:28,947 INFO  [STDOUT] successfully acquired connection from tx aware datasource
              18:06:28,948 INFO  [STDOUT] Now going back to sleep for 40 seconds...
              18:06:58,951 WARN  [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX 0:ffff7f000001:126a:4b7be277:6f in state  RUN
              18:06:58,952 WARN  [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id 0:ffff7f000001:126a:4b7be277:6f invoked while multiple threads active within it.
              18:06:58,953 WARN  [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action 0:ffff7f000001:126a:4b7be277:6f aborting with 1 threads active!
              18:06:58,957 WARN  [com.arjuna.ats.arjuna.logging.arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_7] - TransactionReaper::doCancellations worker Thread[Thread-13,5,jboss] successfully canceled TX 0:ffff7f000001:126a:4b7be277:6f
              18:07:08,957 INFO  [STDOUT] woke up after 40 seconds, tx is expected to have timed out
              18:07:08,973 INFO  [STDOUT] Error while getting connection from tx aware datasource: 
              18:07:08,974 INFO  [STDOUT] SUCCESS! Expected tx timeout error
              18:07:08,975 ERROR [STDERR] java.lang.RuntimeException: org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:126a:4b7be277:6f status: ActionStatus.ABORTED >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: 0:ffff7f000001:126a:4b7be277:6f status: ActionStatus.ABORTED >)
              18:07:08,977 ERROR [STDERR]     at org.jboss.test.ejb3.tx.SleepingTask.testConnection(SleepingTask.java:89)
              18:07:08,979 ERROR [STDERR]     at org.jboss.test.ejb3.tx.SleepingTask.doTask(SleepingTask.java:59)
              18:07:08,979 ERROR [STDERR]     at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
              18:07:08,980 ERROR [STDERR]     at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
              18:07:08,980 ERROR [STDERR]     at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
              18:07:08,981 ERROR [STDERR]     at java.lang.reflect.Method.invoke(Method.java:597)
              18:07:08,981 ERROR [STDERR]     at org.jboss.aop.joinpoint.MethodInvocation.invokeTarget(MethodInvocation.java:122)
              18:07:08,982 ERROR [STDERR]     at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:111)
              18:07:08,982 ERROR [STDERR]     at org.jboss.ejb3.EJBContainerInvocationWrapper.invokeNext(EJBContainerInvocationWrapper.java:69)
              18:07:08,985 ERROR [STDERR]     at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.invoke(InterceptorSequencer.java:76)
              18:07:08,985 ERROR [STDERR]     at org.jboss.ejb3.interceptors.aop.InterceptorSequencer.aroundInvoke(InterceptorSequencer.java:62)
              // trimmed rest of the log
              {code}
              
              So the method execution of the MDB starts at  18:05:58,784 then the SLSB2 (the one with the tx timeout) starts processing and at 18:06:58,951 Tx manager prints out a WARN about tx timing out. At 18:07:08,973 SLSB2 wakes up and tries to get a connection from tx aware datasource and runs into (expected) exception.
              
              I tried this against AS trunk. But given that nothing much has changed in this area since AS 5.1.0, i expect it to work in that version too.
              • 4. Re: Transaction Behavior Question
                andy.miller

                Okay, so now try that same thing with a transaction timeout that's longer than the default for the transaction manager which is 300 seconds.  That's actually my use case, and it times out at 300 seconds even though I set it up to timeout at 1200 seconds.

                 

                In what you did, you set the transaction timeout to shorter than the default, not longer.  Of course, you will have to adjust your sleep to be longer than 300 seconds.

                 

                One other thing, I am not setting a TransactionAttribute on the MDB, but allowing it to default, so if you do the same, than that would be helpful.

                • 5. Re: Transaction Behavior Question
                  jaikiran

                  andy.miller@jboss.com wrote:

                   

                  Okay, so now try that same thing with a transaction timeout that's longer than the default for the transaction manager which is 300 seconds.  That's actually my use case, and it times out at 300 seconds even though I set it up to timeout at 1200 seconds.

                   


                   

                  I sort of see a similar behaviour - the tx on the MDB times out (even before the default 300 second). However, the new tx with a higher timeout, on the SLSB2 seems to be working fine. I don't have an explanation (yet) on why the MDB tx is:

                   

                  1) timing out before 300 seconds (sort of like the tx was already in progress long before the message was delivered to the MDB)

                  2) Even after setting the MDB tx timeout to higher value, it sort of ignores it.

                   

                  I'll take a look at this tomorrow and see what's going on.

                  • 6. Re: Transaction Behavior Question
                    andy.miller

                    jaikiran wrote:

                     

                    andy.miller@jboss.com wrote:

                     

                    Okay, so now try that same thing with a transaction timeout that's longer than the default for the transaction manager which is 300 seconds.  That's actually my use case, and it times out at 300 seconds even though I set it up to timeout at 1200 seconds.

                     


                     

                    I sort of see a similar behaviour - the tx on the MDB times out (even before the default 300 second). However, the new tx with a higher timeout, on the SLSB2 seems to be working fine. I don't have an explanation (yet) on why the MDB tx is:

                     

                    1) timing out before 300 seconds (sort of like the tx was already in progress long before the message was delivered to the MDB)

                    2) Even after setting the MDB tx timeout to higher value, it sort of ignores it.

                     

                    I'll take a look at this tomorrow and see what's going on.

                    One thing to note while you take a look at this.  The transaction manager has changed between trunk and what's in AS 5.1.0, so there could be some things that are different between trunk and AS 5.1.0.

                     

                    You seem to be getting slightly different results, as mine cancels exactly at 300 seconds every time.  Having said that, there definitely appears to be some kind of bug here.

                    • 7. Re: Transaction Behavior Question
                      andy.miller

                      jaikiran wrote:

                       

                      andy.miller@jboss.com wrote:

                       

                      Okay, so now try that same thing with a transaction timeout that's longer than the default for the transaction manager which is 300 seconds.  That's actually my use case, and it times out at 300 seconds even though I set it up to timeout at 1200 seconds.

                       


                       

                      I sort of see a similar behaviour - the tx on the MDB times out (even before the default 300 second). However, the new tx with a higher timeout, on the SLSB2 seems to be working fine. I don't have an explanation (yet) on why the MDB tx is:

                       

                      1) timing out before 300 seconds (sort of like the tx was already in progress long before the message was delivered to the MDB)

                      2) Even after setting the MDB tx timeout to higher value, it sort of ignores it.

                       

                      I'll take a look at this tomorrow and see what's going on.

                      Any word on this?  This is becoming a real problem with what I want to do in this application.

                      • 8. Re: Transaction Behavior Question
                        jaikiran

                        Any word on this?  This is becoming a real problem with what I want to do in this application.

                        Sorry i got caught in another issue. Actually, i started looking into this late evening today.

                         

                        I have been able to see what's going on and it's (almost) a bug. The transaction on the MDB onMessage gets created (unexpectedly) even before the method on the MDB is called (and before the overriden timeout is set). In order to explain it better, i need to figure out exactly why this is happening. Will update this thread soon.

                        • 9. Re: Transaction Behavior Question
                          andy.miller

                          jaikiran wrote:

                           


                          Any word on this?  This is becoming a real problem with what I want to do in this application.

                          Sorry i got caught in another issue. Actually, i started looking into this late evening today.

                           

                          I have been able to see what's going on and it's (almost) a bug. The transaction on the MDB onMessage gets created (unexpectedly) even before the method on the MDB is called (and before the overriden timeout is set). In order to explain it better, i need to figure out exactly why this is happening. Will update this thread soon.

                          According to everything I have read, the fact that a transaction is started before the onMessage is actually called is the expected behavior.  The real issue is that when onMessage then calls a method on a stateless session bean, it doesn't seem to behave correctly when that method tries to override the defaults.  So, in my case trying to actually have a new transaction start, and having the transaction that the MDB is automatically enlisted in suspended (REQUIRES_NEW behavior).

                           

                          Anyway, thanks for continue to look into this.

                          • 10. Re: Transaction Behavior Question
                            jaikiran

                            andy.miller@jboss.com wrote:

                             

                            The real issue is that when onMessage then calls a method on a stateless session bean, it doesn't seem to behave correctly when that method tries to override the defaults.  So, in my case trying to actually have a new transaction start, and having the transaction that the MDB is automatically enlisted in suspended (REQUIRES_NEW behavior).

                             

                             

                             

                             

                            That works as expected. Continuing with my previous example and your suggestion to increase the timeout (instead of decreasing it), here's what i did (leaving out SLSB1 from the post since nothing changes in there):
                            
                            MDB:
                            
                            {code:java}
                            @MessageDriven(activationConfig =
                            {
                            @ActivationConfigProperty(propertyName="destinationType",
                            propertyValue="javax.jms.Queue"),
                            @ActivationConfigProperty(propertyName="destination",
                            propertyValue="queue/test123"),
                            @ActivationConfigProperty(propertyName = "maxSession", propertyValue = "1")
                            })
                            public class SimpleMDB implements MessageListener
                            {
                             
                               @EJB
                               private TimeConsumingTask longRunningTask;
                               
                               public void onMessage(Message message)
                               {
                                  try
                                  {
                                     TextMessage textMessage = (TextMessage) message;
                                     System.out.println("Got message " + textMessage.getText());
                                     this.longRunningTask.doTask();
                                  }
                                  catch (Exception e)
                                  {
                                     // eat it up to avoid re-delivery
                                     e.printStackTrace();
                                  }
                                  
                               }
                             
                            }
                            
                            {code}
                            
                            SLSB2:
                            
                            {code:java}
                            @Stateless
                            @Remote (TimeConsumingTask.class)
                            @RemoteBinding (jndiBinding = SleepingTask.JNDINAME)
                            public class SleepingTask implements TimeConsumingTask
                            {
                            
                               public static final String JNDINAME = "Timeconsumingtask-remote";
                               
                               @Resource(mappedName = "java:/DefaultDS")
                               private DataSource dataSource;
                            
                               @TransactionAttribute(TransactionAttributeType.REQUIRES_NEW)
                               @TransactionTimeout(400)
                               public void doTask()
                               {
                                  try
                                  {
                            
                                     // just a simple lookup of datasource and then
                                     // get and close a connection to ensure everthing is fine
                                     System.out.println("testing connection from tx aware datasource");
                                     testConnection();
                                     System.out.println("successfully acquired connection.");
                            
                                     System.out.println("Now sleeping for 350 seconds...");
                                     Thread.sleep(350000);
                                     System.out.println("woke up after 350 seconds, tx is expected to be active");
                                     testConnection();
                                     System.out.println("successfully acquired connection from tx aware datasource");
                                     System.out.println("Now going back to sleep for 100 seconds...");
                                     Thread.sleep(100000);
                                     System.out.println("woke up after 100 seconds, tx is expected to have timed out");
                                     try
                                     {
                                        testConnection();
                                     }
                                     catch (Throwable t)
                                     {
                                        System.out.println("SUCCESS! Expected tx timeout error");
                                        t.printStackTrace();
                                        return;
                                     }
                                     
                                     System.out.println("Failure! Unexpectedly, acquired a connection from tx aware datasource. tx was expected to have timed out");
                                     throw new RuntimeException("Tx did NOT timeout");
                                     
                                  }
                                  catch (Exception e)
                                  {
                                     throw new RuntimeException(e);
                                  }
                            
                               }
                            
                               private void testConnection()
                               {
                                  Connection conn = null;
                                  try
                                  {
                                     conn = this.dataSource.getConnection();
                                     System.out.println("Got connection");
                                  }
                                  catch (Throwable t)
                                  {
                                     System.out.println("Error while getting connection from tx aware datasource: ");
                                     throw new RuntimeException(t);
                                  }
                                  finally
                                  {
                                     if (conn != null)
                                     {
                                        try
                                        {
                                           conn.close();
                                        }
                                        catch (SQLException e)
                                        {
                                           System.out.println("Error closing connection " + e.getMessage());
                                        }
                                     }
                                  }
                               }
                            }
                            
                            {code}
                            
                            So the method doTask on SLSB2 has been set to REQUIRES_NEW and a timeout of 400 seconds (100 seconds greater than the default 300 seconds timeout). The method internally does this:
                            
                            1) On entry into methods gets a connection from a tx aware datasource - this step is just for testing the setup
                            
                            2) Sleeps for 350 seconds (i.e. 50 seconds more than the *default* tx timeout).
                            
                            3) After waking up after 350 seconds tries to get connection again from the tx aware datasource - Expected to pass since tx is still active (because we have set timeout to 400)
                            
                            4) Goes back to sleep for 100 more seconds (i.e. sleep till tx times out)
                            
                            5) After waking up for a second time, tries to get a connection again from the tx aware datasource - Expected to FAIL since the tx has timed out.
                            
                             
                            
                            This works as expected. i.e. Step#5 throws Tx not active exception. Here's some logs: 
                            
                            {code:java}
                            00:54:10,827 INFO  [SimpleMDB] Got message this is a test message at Sat Feb 20 00:54:10 IST 2010
                            00:54:11,061 INFO  [STDOUT] testing connection from tx aware datasource
                            00:54:11,064 INFO  [STDOUT] Got connection
                            00:54:11,065 INFO  [STDOUT] successfully acquired connection.
                            00:54:11,065 INFO  [STDOUT] Now sleeping for 350 seconds...
                            01:00:01,115 INFO  [STDOUT] woke up after 350 seconds, tx is expected to be active
                            01:00:01,116 INFO  [STDOUT] Got connection
                            01:00:01,116 INFO  [STDOUT] successfully acquired connection from tx aware datasource
                            01:00:01,116 INFO  [STDOUT] Now going back to sleep for 100 seconds...
                            01:00:51,074 WARN  [arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX 7f000001:af53:4b7ee532:6a in state  RUN
                            01:00:51,076 WARN  [arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id 7f000001:af53:4b7ee532:6a invoked while multiple threads active within it.
                            01:00:51,077 WARN  [arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action 7f000001:af53:4b7ee532:6a aborting with 1 threads active!
                            01:00:51,079 WARN  [arjLoggerI18N] [com.arjuna.ats.arjuna.coordinator.TransactionReaper_7] - TransactionReaper::doCancellations worker Thread[Thread-10,5,jboss] successfully canceled TX 7f000001:af53:4b7ee532:6a
                            01:01:41,132 INFO  [STDOUT] woke up after 100 seconds, tx is expected to have timed out
                            01:01:41,161 INFO  [STDOUT] Error while getting connection from tx aware datasource: 
                            01:01:41,161 INFO  [STDOUT] SUCCESS! Expected tx timeout error
                            01:01:41,161 ERROR [STDERR] java.lang.RuntimeException: org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: 7f000001:af53:4b7ee532:6a status: ActionStatus.ABORTED >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: 7f000001:af53:4b7ee532:6a status: ActionStatus.ABORTED >)
                            01:01:41,162 ERROR [STDERR]     at org.jboss.test.ejb3.tx.SleepingTask.testConnection(SleepingTask.java:90)
                            01:01:41,162 ERROR [STDERR]     at org.jboss.test.ejb3.tx.SleepingTask.doTask(SleepingTask.java:59)
                            ...
                            {code}
                            
                            At 00:54:10,827 MDB gets message and passes on the control to a long running task. The long running task starts a new tx at 00:54:11,061 and suspends the tx of MDB. At 01:00:51,074 tx manager prints WARN about a tx timeout (i.e. after 400 seconds). At 01:01:41,161 SLSB2 wakes up and tries to get a connection from tx aware datasource and runs into (expected) exception. By the way, between all this the suspended MDB tx times out (at the default 5 minutes) - which is expected.
                            
                            Note that the thing that i am investigating is the following variant of the above example:
                            {code:java}
                               @TransactionTimeout(450)
                               public void onMessage(Message message)
                               {
                                  try
                                  {
                                     TextMessage textMessage = (TextMessage) message;
                                     logger.info("Got message " + textMessage.getText());
                                     this.longRunningTask.doTask();
                                  }
                                  catch (Exception e)
                                  {
                                     // eat it up to avoid re-delivery
                                     e.printStackTrace();
                                  }
                                  
                               }
                            {code}
                            
                            i.e. I override even the tx timeout on the MDB onMessage - but this isn't working. The suspended MDB tx still timeouts at 300 seconds.
                            • 11. Re: Transaction Behavior Question
                              jaikiran

                              By the way, can you post a snippet of your code, especially from the MDB's onMessage? I suspect that you are running into a issue where the suspended tx on the MDB timesout of after 300 seconds, resulting in a message redelivery (and the rest of the long running task in SLSB2 repeating).

                              • 12. Re: Transaction Behavior Question
                                andy.miller

                                jaikiran wrote:

                                 

                                By the way, can you post a snippet of your code, especially from the MDB's onMessage? I suspect that you are running into a issue where the suspended tx on the MDB timesout of after 300 seconds, resulting in a message redelivery (and the rest of the long running task in SLSB2 repeating).

                                A suspended transaction shouldn't timeout while its suspended!  The timeout should be how long the transaction was active shouldn't it?

                                 

                                Here's my code shortened so you can see the pattern.

                                 

                                The stateless session bean (Local only)

                                 

                                public @Stateless class CustomerManagerBean implements CustomerManager {
                                   
                                    private static Log log = LogFactory.getLog(CustomerManagerBean.class);
                                    private static final int transactionTimeout = 1200;
                                   
                                    @PersistenceContext (unitName="services")
                                    protected EntityManager entityManager;
                                   
                                    @Resource(mappedName = "java:JmsXA")
                                    private ConnectionFactory connectionFactory;

                                 

                                    @Resource(mappedName = "queue/createcustomers")
                                    private Queue createCustomersQueue;
                                   
                                    @Resource(mappedName = "queue/createcustomersreply")
                                    private Queue createCustomersReplyQueue;
                                   
                                    @EJB
                                    private DistributionCenterManager distributionCenterManager;
                                   
                                  ...
                                  
                                   public List<String> queueCreateCustomers(int numberOfCustomers
                                           , int batchSize
                                           , int degreeOfParallelism) throws CreateBenchmarkDataException {
                                      
                                       ...
                                      
                                       Connection connection           = null;
                                       Session session                 = null;
                                       MessageProducer messageProducer = null;
                                       MapMessage customersToCreate    = null;
                                      
                                      ...  enqueue messages ...
                                       
                                        return correlationIds;
                                   }
                                  
                                   ...
                                  
                                   @TransactionAttribute(TransactionAttributeType.REQUIRES_NEW)
                                   @TransactionTimeout(transactionTimeout)
                                   public void createCustomers(int numberOfCustomers, int batchSize, int startingPoint) {

                                 

                                       ... do a bunch of work inserting rows into the database ...


                                       return;
                                   }
                                  
                                   ...

                                 

                                }

                                 

                                The MDB:

                                 

                                @Local

                                @MessageDriven(activationConfig = {
                                        @ActivationConfigProperty(propertyName="destinationType"
                                            , propertyValue="javax.jms.Queue"),
                                        @ActivationConfigProperty(propertyName="destination"
                                            , propertyValue="queue/createcustomers")
                                })
                                public class CreateCustomersBean implements MessageListener {
                                   
                                    private static Log log = LogFactory.getLog(CreateCustomersBean.class);
                                   
                                    @EJB
                                    private CustomerManager customerManager;
                                   
                                    @Resource(mappedName = "java:JmsXA")
                                    private ConnectionFactory connectionFactory;
                                   
                                    @TransactionAttribute(TransactionAttributeType.REQUIRED)
                                    public void onMessage(Message message) {

                                 

                                        Queue replyQueue                = null;
                                        Connection connection           = null;
                                        Session session                 = null;
                                        MessageProducer messageProducer = null;
                                        TextMessage reply               = null;
                                       
                                        MapMessage customersToCreate = (MapMessage) message;

                                 

                                        try {
                                            customerManager.createCustomers(customersToCreate.getInt("numberOfCustomers")
                                                    , customersToCreate.getInt("batchSize")
                                                    , customersToCreate.getInt("startingPoint"));

                                           
                                            replyQueue        = (Queue) customersToCreate.getJMSReplyTo();
                                            connection        = connectionFactory.createConnection();
                                            session           = connection.createSession(true, 0);
                                            messageProducer   = session.createProducer(replyQueue);
                                            reply             = session.createTextMessage(customersToCreate.getJMSCorrelationID());
                                           
                                            messageProducer.send(reply);
                                           
                                            connection.close();
                                        } catch (JMSException jmsError) {
                                            log.error("Failed to receive or send reply!", jmsError);
                                        }

                                 

                                    }

                                 

                                }

                                • 13. Re: Transaction Behavior Question
                                  jaikiran

                                  andy.miller@jboss.com wrote:

                                   

                                  A suspended transaction shouldn't timeout while its suspended!  The timeout should be how long the transaction was active shouldn't it?

                                   


                                  I looked at the JTA spec and its javadocs. I don't see anything which states that the timeout applies only when the tx is in active state. My understanding is that, even if the tx is suspended, the timeout still applies. That's the behaviour i am seeing currently.

                                   

                                  Maybe the JBoss Transactions team has some inputs?

                                  • 14. Re: Transaction Behavior Question
                                    andy.miller

                                    jaikiran wrote:

                                     

                                    By the way, can you post a snippet of your code, especially from the MDB's onMessage? I suspect that you are running into a issue where the suspended tx on the MDB timesout of after 300 seconds, resulting in a message redelivery (and the rest of the long running task in SLSB2 repeating).

                                    I just tried putting @TranactionAttribute(TransactionAttributeType.NOT_SUPPORTED) on the onMessage method of the MDB, and now I don't get the transaction timeout on the long running method of the stateless session bean.

                                     

                                    I'm starting to think that all is behaving as expected.  I'm still wary of this, and I'm still concerned that a suspended transaction still times out.  I don't know if that is spec compliant or not.  I'll see what I can dig up on that.

                                    1 2 Previous Next