Transaction Rollback Problem

[jedlloyd]

Hi,

I am working with JBossCache 1.3 in a Weblogic 8.1 clustered environment. Currently, I am trying to setup and configure JBossCache to use the Weblogic transaction manager, however am having problems when trying to test transaction rollbacks. I have included my JBossCache config file, the GenericTransactionManagerLookup class, my test code, and a copy of the exception that I am getting. I believe that I have everything configured right and have tried different ways of retrieving the Weblogic transaction manager and using a UserTransaction, however everything I have tried gives me the same exception.

Any information or help would be greatly appreciated. Thanks in advance.

JBossCache Config:

<?xml version="1.0" encoding="UTF-8"?>

<!-- ===================================================================== -->
<!-- -->
<!-- TreeCacheAop Service Configuration -->
<!-- -->
<!-- ===================================================================== -->

<server>

 <classpath codebase="./lib" archives="jboss-cache.jar, jgroups.jar"/>


 <!-- ==================================================================== -->
 <!-- Defines TreeCache configuration -->
 <!-- ==================================================================== -->

 <mbean code="org.jboss.cache.TreeCache" name="jboss.cache:service=TreeCache">

 <depends>jboss:service=Naming</depends>
 <depends>jboss:service=TransactionManager</depends>

 <!--
 Configure the TransactionManager
 -->
 <attribute name="TransactionManagerLookupClass">com.jpmc.remedy.rearc.cache.treecache.GenericTransactionManagerLookup</attribute>

 <!--
 Node locking level : SERIALIZABLE
 REPEATABLE_READ (default)
 READ_COMMITTED
 READ_UNCOMMITTED
 NONE
 -->
 <attribute name="IsolationLevel">NONE</attribute>

 <!--
 Valid modes are LOCAL
 REPL_ASYNC
 REPL_SYNC
 -->
 <attribute name="CacheMode">LOCAL</attribute>

 <!-- Name of cluster. Needs to be the same for all clusters, in order
 to find each other
 -->
 <attribute name="ClusterName">Remedy-TreeCache-Cluster</attribute>

 <!-- JGroups protocol stack properties. Can also be a URL,
 e.g. file:/home/bela/default.xml
 <attribute name="ClusterProperties"></attribute>
 -->

 <attribute name="ClusterConfig">
 <config>
 <!-- UDP: if you have a multihomed machine,
 set the bind_addr attribute to the appropriate NIC IP address, e.g bind_addr="192.168.0.2"
 -->
 <!-- UDP: On Windows machines, because of the media sense feature
 being broken with multicast (even after disabling media sense)
 set the loopback attribute to true -->
 <UDP mcast_addr="228.1.2.3" mcast_port="48866"
 ip_ttl="32"
 ip_mcast="true"
 mcast_send_buf_size="500000"
 mcast_recv_buf_size="200000"
 ucast_send_buf_size="500000"
 ucast_recv_buf_size="200000"
 loopback="false"/>
 <PING timeout="3000"
 num_initial_members="2"
 up_thread="false"
 down_thread="false"/>
 <MERGE2 min_interval="10000" max_interval="20000"/>
 <FD_SOCK/>
 <VERIFY_SUSPECT timeout="1500" up_thread="false" down_thread="false"/>
 <pbcast.NAKACK gc_lag="50" retransmit_timeout="600,1200,2400,4800"
 max_xmit_size="8192" up_thread="false" down_thread="false"/>
 <UNICAST timeout="600,1200,2400" window_size="100" min_threshold="10"
 down_thread="false"/>
 <pbcast.STABLE desired_avg_gossip="20000" max_bytes="500000"
 up_thread="false" down_thread="false"/>
 <FRAG frag_size="8192" down_thread="false" up_thread="false"/>
 <pbcast.GMS join_timeout="5000" join_retry_timeout="2000"
 shun="true" print_local_addr="true"/>
 <pbcast.STATE_TRANSFER up_thread="true" down_thread="true"/>
 </config>
 </attribute>


 <!--
 Whether or not to fetch state on joining a cluster
 -->
 <attribute name="FetchStateOnStartup">false</attribute>

 <!--
 The max amount of time (in milliseconds) we wait until the
 initial state (ie. the contents of the cache) are retrieved from
 existing members in a clustered environment
 -->
 <attribute name="InitialStateRetrievalTimeout">2000000</attribute>

 <!--
 Number of milliseconds to wait until all responses for a
 synchronous call have been received.
 -->
 <attribute name="SyncReplTimeout">10000</attribute>

 <!-- Max number of milliseconds to wait for a lock acquisition -->
 <attribute name="LockAcquisitionTimeout">15000</attribute>


 <!-- Name of the eviction policy class. Not supported now. -->
 <attribute name="EvictionPolicyClass"></attribute>
 </mbean>

 </server>

Transaction Manager Lookup Class:

package com.jpmc.remedy.rearc.cache.treecache;

import com.jpmc.remedy.tool.Logger;
import org.jboss.cache.TransactionManagerLookup;

import weblogic.transaction.TransactionHelper;

import javax.naming.InitialContext;
import javax.transaction.TransactionManager;
import javax.transaction.UserTransaction;

public class GenericTransactionManagerLookup implements TransactionManagerLookup {

 private static String JAVAX_TRANSACTION_MANAGER = "javax.transaction.TransactionManager";
 private static String JAVAX_USER_TRANSACTION = "javax.transaction.UserTransaction";

 private static TransactionManager tm = null;
 private static GenericTransactionManagerLookup instance;

 public static GenericTransactionManagerLookup getInstance() {
 if(instance == null){
 synchronized(GenericTransactionManagerLookup.class){
 if(instance==null){
 instance = new GenericTransactionManagerLookup();
 }
 }
 }
 return instance;
 }

 public TransactionManager getTransactionManager() {
 if(tm == null)
 doLookups();

 return tm;
 }

 private static void doLookups() {
 InitialContext ctx;
 try {
 ctx = new InitialContext();
 } catch(Exception e) {
 Logger.error("GenericTransactionManagerLookup.doLookups(): Could not create an initial JNDI context", e);
 return;
 }

 Object jndiObject = null;
 try {
 jndiObject = ctx.lookup(JAVAX_TRANSACTION_MANAGER);
 } catch(Exception e) {
 Logger.error("GenericTransactionManagerLookup.doLookups(): Failed to perform a lookup for " + JAVAX_TRANSACTION_MANAGER, e);
 }
 if(jndiObject instanceof TransactionManager) {
 tm = (TransactionManager) jndiObject;
 Logger.info("GenericTransactionManagerLookup.doLookups(): Found TransactionManager for " + JAVAX_TRANSACTION_MANAGER);
 }
 }

 public UserTransaction getUserTransaction() {
 UserTransaction userTx = null;
 InitialContext ctx;
 try {
 ctx = new InitialContext();

 userTx = (UserTransaction) ctx.lookup(JAVAX_USER_TRANSACTION);
 } catch(Exception e) {
 Logger.error("GenericTransactionManagerLookup.getTranscation(): Failed to perform a lookup for " + JAVAX_USER_TRANSACTION, e);
 }
 Logger.info("GenericTransactionManagerLookup.getUserTransaction(): Found User Transaction " + userTx);

 return userTx;
 }

 public TransactionManager getTransactionManagerFromWeblogic() {
 return TransactionHelper.getTransactionHelper().getTransactionManager();
 }
}

Transaction Test Code:

 // Method to test transaction rollbacks on the cache.
 public void transactionTest(String fqn, Object object) throws CacheException {
 TransactionManager txm = GenericTransactionManagerLookup.getInstance().getTransactionManager();

 Transaction tx = null;
 try {
 txm.begin();
 tx = txm.getTransaction();

 cache.put(fqn, ((Map)object));

 tx.rollback();
 } catch (Exception e) {
 // TODO Auto-generated catch block
 e.printStackTrace();
 }
 }

Exception:
WARN [2006-04-03 13:52:28,325] [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'] org.jboss.cache.interceptors.TxInterceptor - Rollback had a problem
java.lang.IllegalStateException: local transaction Xid=BEA1-000041BB6ABB322DDA97(16723022),Status=Rolled back. [Reason=Unknown],numRepliesOwedMe=0,numRepliesOwedOthers=0,seconds since begin=0,seconds left=30,SCInfo[remedy+remedyserver]=(state=rolledback),OwnerTransactionManager=ServerTM[ServerCoordinatorDescriptor=(CoordinatorURL=remedyserver+127.0.0.1:8001+remedy+t3+, XAResources={},NonXAResources={})],CoordinatorURL=remedyserver+127.0.0.1:8001+remedy+t3+) transaction does not match running tx null
at org.jboss.cache.interceptors.TxInterceptor.handleCommitRollback(TxInterceptor.java:610)
at org.jboss.cache.interceptors.TxInterceptor.runRollbackPhase(TxInterceptor.java:695)
at org.jboss.cache.interceptors.TxInterceptor$RemoteSynchronizationHandler.afterCompletion(TxInterceptor.java:946)
at org.jboss.cache.interceptors.OrderedSynchronizationHandler.afterCompletion(OrderedSynchronizationHandler.java:80)
at weblogic.transaction.internal.ServerSCInfo.callAfterCompletions(ServerSCInfo.java:853)
at weblogic.transaction.internal.ServerTransactionImpl.callAfterCompletions(ServerTransactionImpl.java:2789)
at weblogic.transaction.internal.ServerTransactionImpl.setRolledBack(ServerTransactionImpl.java:2636)
at weblogic.transaction.internal.ServerTransactionImpl.globalRetryRollback(ServerTransactionImpl.java:2866)
at weblogic.transaction.internal.ServerTransactionImpl.globalRollback(ServerTransactionImpl.java:2626)
at weblogic.transaction.internal.ServerTransactionImpl.internalRollback(ServerTransactionImpl.java:385)
at weblogic.transaction.internal.ServerTransactionImpl.rollback(ServerTransactionImpl.java:364)
at com.jpmc.remedy.rearc.cache.treecache.JTreeCacheImpl.transactionTest(JTreeCacheImpl.java:190)
at com.jpmc.remedy.rearc.cache.CacheWrapper.transactionTest(CacheWrapper.java:216)
at com.jpmc.remedy.rearc.cache.treecache.JTreeCacheManager.loadHighAsciiEntitiesInTransaction(JTreeCacheManager.java:2977)
at jsp_servlet.__admintransactionmanagerpage._jspService(__admintransactionmanagerpage.java:153)
at weblogic.servlet.jsp.JspBase.service(JspBase.java:33)
at weblogic.servlet.internal.ServletStubImpl$ServletInvocationAction.run(ServletStubImpl.java:1006)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:419)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:463)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:315)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:6718)
at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:121)
at weblogic.servlet.internal.WebAppServletContext.invokeServlet(WebAppServletContext.java:3764)
at weblogic.servlet.internal.ServletRequestImpl.execute(ServletRequestImpl.java:2644)
at weblogic.kernel.ExecuteThread.execute(ExecuteThread.java:219)
at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:178)
WARN [2006-04-03 13:52:28,335] [ExecuteThread: '14' for queue: 'weblogic.kernel.Default'] org.jboss.cache.interceptors.TxInterceptor - Rollback had a problem
java.lang.IllegalStateException: local transaction Xid=BEA1-000141BB6ABB322DDA97(806641),Status=Rolled back. [Reason=Unknown],numRepliesOwedMe=0,numRepliesOwedOthers=0,seconds since begin=0,seconds left=30,SCInfo[remedy+remedyserver]=(state=rolledback),OwnerTransactionManager=ServerTM[ServerCoordinatorDescriptor=(CoordinatorURL=remedyserver+127.0.0.1:8001+remedy+t3+, XAResources={},NonXAResources={})],CoordinatorURL=remedyserver+127.0.0.1:8001+remedy+t3+) transaction does not match running tx null
at org.jboss.cache.interceptors.TxInterceptor.handleCommitRollback(TxInterceptor.java:610)
at org.jboss.cache.interceptors.TxInterceptor.runRollbackPhase(TxInterceptor.java:695)
at org.jboss.cache.interceptors.TxInterceptor$RemoteSynchronizationHandler.afterCompletion(TxInterceptor.java:946)
at org.jboss.cache.interceptors.OrderedSynchronizationHandler.afterCompletion(OrderedSynchronizationHandler.java:80)
at weblogic.transaction.internal.ServerSCInfo.callAfterCompletions(ServerSCInfo.java:853)
at weblogic.transaction.internal.ServerTransactionImpl.callAfterCompletions(ServerTransactionImpl.java:2789)
at weblogic.transaction.internal.ServerTransactionImpl.setRolledBack(ServerTransactionImpl.java:2636)
at weblogic.transaction.internal.ServerTransactionImpl.globalRetryRollback(ServerTransactionImpl.java:2866)
at weblogic.transaction.internal.ServerTransactionImpl.globalRollback(ServerTransactionImpl.java:2626)
at weblogic.transaction.internal.ServerTransactionImpl.internalRollback(ServerTransactionImpl.java:385)
at weblogic.transaction.internal.ServerTransactionImpl.rollback(ServerTransactionImpl.java:364)
at com.jpmc.remedy.rearc.cache.treecache.JTreeCacheImpl.transactionTest(JTreeCacheImpl.java:190)
at com.jpmc.remedy.rearc.cache.CacheWrapper.transactionTest(CacheWrapper.java:216)
at com.jpmc.remedy.rearc.cache.treecache.JTreeCacheManager.loadHighAsciiEntitiesInTransaction(JTreeCacheManager.java:2978)
at jsp_servlet.__admintransactionmanagerpage._jspService(__admintransactionmanagerpage.java:153)
at weblogic.servlet.jsp.JspBase.service(JspBase.java:33)
at weblogic.servlet.internal.ServletStubImpl$ServletInvocationAction.run(ServletStubImpl.java:1006)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:419)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:463)
at weblogic.servlet.internal.ServletStubImpl.invokeServlet(ServletStubImpl.java:315)
at weblogic.servlet.internal.WebAppServletContext$ServletInvocationAction.run(WebAppServletContext.java:6718)
at weblogic.security.acl.internal.AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
at weblogic.security.service.SecurityManager.runAs(SecurityManager.java:121)
at weblogic.servlet.internal.WebAppServletContext.invokeServlet(WebAppServletContext.java:3764)
at weblogic.servlet.internal.ServletRequestImpl.execute(ServletRequestImpl.java:2644)
at weblogic.kernel.ExecuteThread.execute(ExecuteThread.java:219)
at weblogic.kernel.ExecuteThread.run(ExecuteThread.java:178)

[washeeq]

Well, it seems I have the same problem. I am running on WebSphere and got the same exception in org.jboss.cache.interceptors.TxInterceptor.handleCommitRollback() method.

The following exception was logged java.lang.IllegalStateException: local transaction com.ibm.ws.Transaction.JTA.TransactionImpl@5090509#tid=4 transaction does not match running tx null

It happens both when commiting or when rollbacking. The problem is
at this line of TxInterceptor:

 private Object handleCommitRollback(MethodCall m) throws Throwable
 {
 GlobalTransaction gtx = findGlobalTransaction( m.getArgs() );
 Object result;

 // this must have a local transaction associated if a prepare has been
 // callled before
 Transaction ltx = getLocalTxForGlobalTx(gtx);

 Transaction currentTx = txManager.getTransaction(); <---this is null!!!!!!

 if (!ltx.equals(currentTx)) throw new IllegalStateException(" local transaction " + ltx + " transaction does not match running tx " + currentTx);

 result = super.invoke(m);

 if (log.isDebugEnabled()) log.debug("Finished local commit/rollback method for " + gtx);
 return result;
 }

The problem is, that there is no transaction associated with thread at that place.
It is weird because when I try to get transaction in servlet via

treeCache.getTransactionManager().getTransaction()

I recieve a correct transaction instance. And it should be the same thread as in TxInterceptor case.

Any Ideas? Propt help would be very appreciated.

[washeeq]

Hi there,
I made some deeper explorations and found following:
When commit() is called in application, OrderedSynchronizationHandler.beforeCompletion() is called. It then calls beforeCompletion() for registered Synchronizations, in my case only TxInterceptor.LocalSynchronizationHandler. Still everything is fine here, transaction is not null. When beforeCompletion methods finishes, transaction is commited and afterCompletion method of OrderedSynchronizationHandler is called. Then afterCompletion() method in TxInterceptor.RemoteSynchronizationHandler is called and...here is the problem. Transaction is null here. This cause handleCommitRollback() to fail later on following test:

Transaction currentTx = txManager.getTransaction(); // <--here current transaction is null
 if (!ltx.equals(currentTx)) throw new IllegalStateException(" local transaction " + ltx + " transaction does not match running tx " + currentTx);

I realy don't know why is transaction unregistred from current thread in the moment of commit. Is this done also on another app servers? Well what about if I simply remove the above test in handleCommitRollback? Any suggestions are welocome because in this situation we can not use JBoss cache at all.

Washeeq

[manik]

Hi there

I haven't seen this with other transaction managers before.

Perhaps you don't have the same tx manager? When obtaining your tx manager in your test code, try doing:

TransactionManager txmgr = cache.getTransactionManager();
txmgr.begin() ....

[manik]

(sorry, that last one was in response to the original post)

[manik]

Also, I'm presuming neither of you see this problem when there is only one node in the cluster?

[manik]

Ok, just tried it on a single WL 8.1.5 instance and it works fine, setting up a cluster now.

[jedlloyd]

I have this problem in a single node Weblogic 8.1 instance. I am running the JBossCache in LOCAL cache mode.

[manik]

Ok, seeing it now - both in standalone mode and in a cluster.

http://jira.jboss.com/jira/browse/JBCACHE-548

[manik]

jedlloyd, can you confirm that this does not happen with JBC 1.2.4.SP2?

[washeeq]

Hi Manik,
problem is the same with JBoss Cache 1.3.0 GA or BETA2 and IBM WebSphere 6.0. Cache running in cluster with INVALIDATION_SYNC. When I commented out this test in TxInterceptor, everything seems to work fine. Why is that test needed?

if (!ltx.equals(currentTx)) throw new IllegalStateException(" local transaction " + ltx + " transaction does not match running tx " + currentTx);

washeeq

[manik]

Ok, I have found the problem and have a fix in the 1.3.x CVS branch (see http://wiki.jboss.org/wiki/Wiki.jsp?page=JBossCache for branch info).

I;ve tested this on WL815 so far, and after more QA on other app servers, this will make it into a service pack for 1.3.0.

If you guys want, I'd recommend getting the srcs from CVS, building it and giving it a try, see if it solves your problems.

Cheers,
Manik

[manik]

Washeeq, commenting out that test is only a part of the fix. You're right, the test is unnecessary in this case, but I'd recommend checking out the complete fix from CVS.

Cheers,
Manik

[washeeq]

Hi Manik,
I've dowloaded TxInterceptor from CVS and...wow! Everything goes very well! :o) Cool.

Cheers,
washeeq

[manik]

Great. Expect a SP for 1.3.0 soon, sorry about this breakage.