4
votes

Here I have a piece of code which is triggered by an EJB Timer, running inside an EAR deployed on a JBoss EAP 6.2.

Since processing within the onTimeout(Timer timer) method can take much longer than the default transaction timeout specified in standalone.xml I came up with this solution:

//[...]
import javax.ejb.Singleton;
import javax.ejb.Startup;
import javax.ejb.Timeout;
import javax.ejb.Timer;
import javax.ejb.TimerService;
import javax.ejb.TransactionAttribute;
import javax.ejb.TransactionAttributeType;
import org.jboss.ejb3.annotation.TransactionTimeout;
//[...]

@Startup
@Singleton
public class DataqReaderServiceImpl extends AbstractDataqReaderService {

    @Resource
    private TimerService timerService;

    @Override
    @Timeout
    @TransactionAttribute(TransactionAttributeType.REQUIRES_NEW)
    @TransactionTimeout(unit = TimeUnit.MINUTES, value = 60)
    protected void onTimeout(Timer timer) {
    try {
            super.readDataq(timer);
        } catch (Exception e) {
            timer.cancel();
        }
    }
}
//[...]

But appearantly the @TransactionTimeout annotation is ignored. After the code has been running for 5 Minutes, the Transaction Reaper comes to live:

2016-12-19 15:12:21,878 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper) ARJUNA012117: TransactionReaper::check timeout for TX 0:ffff0a07065b:296fc7c:5857e084:67ef in state  RUN
2016-12-19 15:12:21,881 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012095: Abort of action id 0:ffff0a07065b:296fc7c:5857e084:67ef invoked while multiple threads active within it.
2016-12-19 15:12:21,881 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012108: CheckedAction::check - atomic action     0:ffff0a07065b:296fc7c:5857e084:67ef aborting with 1 threads active!
2016-12-19 15:12:21,882 WARN  [com.arjuna.ats.arjuna] (Transaction Reaper Worker 0) ARJUNA012121: TransactionReaper::doCancellations worker Thread[Transaction Reaper Worker 0,5,main] successfully canceled TX 0:ffff0a07065b:296fc7c:5857e084:67ef

Where's my mistake?

1
Try change to public method. See issues.jboss.org/browse/WFLY-850Federico Sierra

1 Answers

0
votes

After trying some more I found that this seems to be a bug in RedHat JBoss EAP 6.2.

Here's a tracelog of where the transaction starts on EAP 6.2.0:

2016-12-20 07:21:29,754 TRACE [com.arjuna.ats.arjuna] (EJB default - 10) TransactionReaper::insert ( BasicAction: 0:ffff0a07065b:-60e989f1:5858dbac:45 status: ActionStatus.RUNNING, 300 )
2016-12-20 07:21:29,754 TRACE [com.arjuna.ats.arjuna] (EJB default - 10) ReaperElement::ReaperElement ( BasicAction: 0:ffff0a07065b:-60e989f1:5858dbac:45 status: ActionStatus.RUNNING, 300 )

The second argument logged for TransactionReaper::insert is the timeout value.

Now here's a tracelog of the same event, but on EAP 6.4.8 (I verified that the default timeout is set to 300 seconds in the 6.2.0 and the 6.4.8 instance):

09:12:52,913 TRACE [com.arjuna.ats.arjuna] (EJB default - 8) TransactionReaper::insert ( BasicAction: 0:ffff0a076537:-1ab57a18:5858f5d6:31 status: ActionStatus.RUNNING, 3600 )
09:12:52,913 TRACE [com.arjuna.ats.arjuna] (EJB default - 8) ReaperElement::ReaperElement ( BasicAction: 0:ffff0a076537:-1ab57a18:5858f5d6:31 status: ActionStatus.RUNNING, 3600 )

So the transaction is initiated with the correct timeout value on EAP 6.4.8.