RM transaction timeout behaviour?

[jerrinot]

Hi guys,

I use JBoss TM 4.6.1 (bundled with JBoss EAP 5.1) + webMethods RM.

Default behaviour of JBoss TM is to set transactional timeout of each XAResource participating on transaction to the same value as the global transactioanl (JTA) timeout. The problem I'm facing is that when RM detects a transactional timeout (before the JBoss TM) it does a heuristic rollback -> this fills up the logs and heuristic rollbacks are being showed in the webMethods console. Is this a proper/normal behaviour of RM? I could not find how should the RM react on timeout in the JTA specification, but I do not see reason why the rollback should be heuristic as the JBoss TM is explicitly specifies the timeout value.

This is hapened very often as the webMethods is "very fast" in detecting the timeout and JBoss TM Repear thread is checking the timeout only during wake-up intervals. Is there any solution to this situation? I do not want to set the xaTransactionTimeoutEnabled as that would influence other resources than webMethods.

Thanks a lot for any help!

[tomjenkinson]

Hi Jaromir,

The reason it may become a heuristic:

1. XAResource::setTransactionTImeout(timeT)

2. transaction begins commit process at timeT-1

3. transaction commits other resource

4. timeT arrives and webmethods rolls back

5. transaction attempts to commit webmethods resource but it has already rolled back

6. A heuristic has now happened

Hopefully you will appreciate that this is beyond the scope of the transaction manager to resolve (unless you have any suggestions we can evaluate), therefore there isn't really much you can do here apart from maybe extend your timeout so it is less frequent?

Tom

[jerrinot]

Hi Tom,

thank you for your reply. I see a heuristically rolled-back transaction in webMethods even when webMethods is the only RM participating within the transaction. It seems me once the webMethod detects a timeout it does a heuristic rollback. And even when JBoss TM do a "regular rollback" later on, the transaction is still seen as heuristic ended by webMethods. I'm not sure if this is a correct behavior as the JTA specification is not very clear. Any idea? (I know it's not very JBoss TM specific and I'm sorry for that)

[mmusgrov]

When the reaper notices that the transaction has exceeded its timeout it calls roll back on the RM. Since the RM has autonomously rolled back the transaction branch it is probably returning XAException.XA_RBROLLBACK which seems like a reasonable thing for it to do. The log message should just be a warning and the TM should see it as a rolled back transaction.

[mmusgrov]

I meant XAException.XA_HEURRB (can you verify that that is what the webMethods resource is returing). Note that if the transaction as a whole was left in a heuristic state you would see lots of file entries in the transaction logs (the default location for logs is server/<profile>/data/tx-object-store/).

[jerrinot]

Hi Michael,

thank you for your help! I'll verify what does webMethods return tomorrow.

I believe if RM returns XA_HEURRB during the rollback (and there is no other RM), the TM should call xaResource.forget(). I'm not sure this is what is actually hapening as I see the number of heuristically rollbacked transactions in webmethods as growing.

[tomjenkinson]

Hi Jaromir,

If you read my original response to you does it make sense? I don't think there is much you can do here except disable xaTransactionTimeoutEnabled, which other resources are you concerned about doing that for?

Tom

[jerrinot]

Hi Tom,

I'm sorry for not repliyng earlier. Your aswer makes sense to me. Other resources we use (and I know of) are OracleDB, Postgresql and JBoss Messaging.

I would rather keep xaTransactionTimeoutEnabled set to true to avoid surprises. My understanding is that when all resources respond to rollback by either OK or XAException.HEURBB the TM should call forget() on resources with HEURBB. -> no problem with no. of logs. Do I undestand it right? This is currently not happening, but I suspect it's because of other issues with webMethods RA we are facing.

[tomjenkinson]

Hi Jaromir,

I think what is happening is because webMethods has rolled back the resource, when we call rollback on it from the reaper thread it is possibly returning a XAException.XAER_NOTA so we won't call forget on it.

If you can send some output from the JBoss logs I might be able to verify that for you. In particular I am looking for statements like:

          attempted rollback of {0} ({1}) failed with exception code {2}

Where those {} are replaced with values

Now, I have found something interesting in XAResourceRecord which means that *if* WebMethods is returning XA_HEURRB rather than XA_NOTA there could be something we could in our code to call "forget" this XAR (assuming it is the right thing to do, I will double check that)

com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord::topLevelAbort()

case XAException.XA_HEURRB: // forget?

case XAException.XA_RBROLLBACK:

case XAException.XA_RBEND:

case XAException.XA_RBCOMMFAIL:

case XAException.XA_RBDEADLOCK:

case XAException.XA_RBINTEGRITY:

case XAException.XA_RBOTHER:

case XAException.XA_RBPROTO:

case XAException.XA_RBTIMEOUT:

Please can you confirm from the Arjuna logs what WebMethods has returned to us?

Tom

[jhalliday]

An RM may return XA_HEUR* codes from rollback ONLY if it's already prepared (per p50 of the XA spec). In which case we'd have a log and would recover/forget correctly when processing it. At pre-prepare states the RM should implement timeout simply by discarding all state and returning XA_NOTA or XA_RBTIMEOUT, thus not requiring forget to be called: "A resource manager can forget a rolled back transaction branch either after it has notified all associated threads of control of the branch’s failure (by returning [XAER_NOTA] or [XA_RB∗] ..." (p49)

[marklittle]

By default JBossTS won't call forget on the RM, assuming that a system adminitrator will want to check that the transaction has been resolved first. If you change the maintainHeuristics flag to false then you should see a change in behaviour.

[jerrinot]

Guys, thanks a lot to all you!

Tom: I'll try to obtain the logs and paste it here. Currently I'm experimenting with using the JMS JBoss RA (+webMethods client libraries) instead of GenericRA.jar (part of WebMethods RA) It seems to solve some other problems with have (deadlock, etc.), but there are still issues with heuristic rollbacks. I assume this is something the adapter cannot influence.

Jonathan: Thanks, that's very useful information! I thought it would be weird for RM to do a heuristic rollback on pre-prepare timeout. I will raise this to Software AG support.

Mark: Thanks, that's good to know too!

[jerrinot]

Here is the logfile: https://docs.google.com/file/d/0B8M1UlKQChdCdlI3Z1A5YUN4UTQ/edit  (Sorry, I do not know how the attach file to the forum). I used the WebMethods RA adapter.

All I did was deploying a MDB consuming messages from remote webMethods queue. In onMessage() methods is just Thread.sleep(50s).

JTA timeout in JBoss TM was set to 30s.

I set xaTransactionTimeoutEnabled to false, therefore pre-prepared timeout on webMethod RM was the default (10s for sake of testing) -> RM timed out before TM.

It seems me as obvisous:

1. RM detects timeout and do a heuristic(!) rollback.

2. TM Reaper thread detects a timeout and tries to rollback. webMethods RM throws XAException.HEURRB (and breaks the XA spec at this point) Neverthless the TM consideres the transactino as aborted (which is probably fine)

3. MDB finishes the onMessage(), JMS RA calls the JBoss MessageEndpointInterceptor after() method. The interceptor tries to commit, but TM throws the RollbackException (which is OK)

Therefore the offender is the webMethods RM breaking the XA spec by throwing XAException.HEURRB before prepare was called. Could you guys confirm my interpretation is right?

[marklittle]

Are you sure that the RM has not been prepared before the timeout occurs?

[tomjenkinson]

Hi Jaromir, is that the complete log? I can't seem to find some statements I would have expected to see? What logging config did you use?