Why is one in 2000 transactions mysteriously timed out immediately?
Hi all,
I have a remote client holding several instances of a stateful session bean, and it is repeatedly calling the same method on all the instances. The bean is hosted in JBoss 6M3, and I have also tried this scenario on JBoss 6M2 (using default transaction configuration in both versions). The method is managed with a CMT set to REQUIRED with timeout of 60 seconds, and it always executes in less than one second. It looks like this:
@TransactionAttribute(value = TransactionAttributeType.REQUIRED)
@TransactionTimeout(value = 60)
public <T extends ResultType, E extends Exception> T executeCommand(Command<T, E> command)
throws E
{
...
}
Roughly one of every 2000 calls is terminated by a transaction timeout, which shows up like this in the JBoss server.log:
2010-06-07 17:20:52,296 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] (Thread-15) [com.arjuna.ats.arjuna.coordinator.TransactionReaper_18] - TransactionReaper::check timeout for TX 0:ffff0aa8c834:126a:4c0d8beb:583b in state RUN
2010-06-07 17:20:52,296 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] (Thread-16) [com.arjuna.ats.arjuna.coordinator.BasicAction_58] - Abort of action id 0:ffff0aa8c834:126a:4c0d8beb:583b invoked while multiple threads active within it.
2010-06-07 17:20:52,296 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] (Thread-16) [com.arjuna.ats.arjuna.coordinator.CheckedAction_2] - CheckedAction::check - atomic action 0:ffff0aa8c834:126a:4c0d8beb:583b aborting with 1 threads active!
2010-06-07 17:20:52,296 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] (Thread-16) [com.arjuna.ats.arjuna.coordinator.TransactionReaper_7] - TransactionReaper::doCancellations worker Thread[Thread-16,5,jboss] successfully canceled TX 0:ffff0aa8c834:126a:4c0d8beb:583b
2010-06-07 17:20:52,296 WARN [com.arjuna.ats.arjuna.logging.arjLoggerI18N] (WorkerThread#1[127.0.0.1:1947]) [com.arjuna.ats.arjuna.coordinator.BasicAction_40] - Abort called on already aborted atomic action 0:ffff0aa8c834:126a:4c0d8beb:583b
On the client side, the caller receives the rollback exception less than 50ms after making the RMI call to the bean. Can anyone explain this?? If the bean method were throwing some unlogged exception, I would understand the rollback... but notice that the TransactionReaper is killing the transaction overtly. Something is wrong. Can anyone help me understand what's happening here??
Thanks in advance for your help.
Byron
