Problem with tx in TreeCacheMBean
Hi There,
I used the TreeCache as MBean in Jboss 3.2.4 with JbossCache (cvs head).
There seems to be a problem using UserTransactions in this config.
The cache is configured with the following params:
<attribute name="TransactionManagerLookupClass">org.jboss.cache.JBossTransactionManagerLookup</attribute> <attribute name="IsolationLevel">SERIALIZABLE</attribute> <attribute name="CacheMode">REPL_SYNC</attribute>
I have modified the Bank-Example and pack it into a Stateless EJB using
few "invokes" to call the TreeCacheMBean ("put" and "get" only). A little
junit-test like ConcurrentUnitTestCase.java to test it (calls the "txTest"-
Method in the bean via RMI).
And that's the problem:
It seems the SERIALIZABLE - Option in the Cache- Config does not work.
I extend the Debug- log from Jboss- Cache with the Thread.getCurrentThread() -
Method and found that more then one threads took access on one Node
at one Time. There seems to be no isolation between the different transactions.
I could not found problems in my code. Is there a bug in JBossCache?
The used EJB as follow:
package samples;
import javax.ejb.CreateException;
import javax.management.ObjectName;
import javax.management.MBeanServer;
import javax.transaction.UserTransaction;
import org.jboss.cache.lock.LockingException;
import org.jboss.cache.lock.TimeoutException;
import org.jboss.mx.util.MBeanServerLocator;
import org.apache.log4j.*;
/**
* @ejb.bean
* type="Stateless"
* name="JBossCacheTest"
* jndi-name="ejb/JBossCacheTest"
* local-jndi-name="ejb/local/JBossCacheTest"
* view-type="both"
* transaction-type="Bean"
*
* @ejb.interface generate="local,remote"
* extends="javax.ejb.EJBObject"
* local-extends="javax.ejb.EJBLocalObject"
* remote-pattern="JBossCacheTest"
* local-pattern="JBossCacheTestLocal"
*
* @ejb.home generate="true"
* extends="javax.ejb.EJBHome"
* local-extends="javax.ejb.EJBLocalHome"
* remote-pattern="JBossCacheTestHome"
* local-pattern="JBossCacheTestLocalHome"
*
* @ejb.transaction type="Supports"
*
* @jboss.container-configuration name="Standard Stateless SessionBean"
*/
public class JBossCacheTestEJB implements javax.ejb.SessionBean, javax.transaction.Status
{
MBeanServer server = null;
ObjectName cacheService = null;
static final String OBJECT_NAME = "jboss.cache:service=TreeCache";
private static Logger logger_ = Logger.getLogger(JBossCacheTestEJB.class);
final String NODE = "/cachetest";
final int ROLLBACK_CHANCE = 100;
static String customer[] = {"cu1", "cu2", "cu3"};
public javax.ejb.SessionContext sctx;
public void ejbCreate()
{
}
public void ejbActivate () throws javax.ejb.EJBException, java.rmi.RemoteException
{
}
public void ejbPassivate () throws javax.ejb.EJBException, java.rmi.RemoteException
{
}
public void ejbRemove () throws javax.ejb.EJBException, java.rmi.RemoteException
{
}
public void setSessionContext (javax.ejb.SessionContext sessionContext) throws javax.ejb.EJBException, java.rmi.RemoteException
{
try
{
sctx = sessionContext;
}
catch(Exception e)
{
e.printStackTrace();
}
}
/**
* @ejb.interface-method
*/
public int txTest(int iTestLoops)
{
int iErr = 0;
try
{
getTreeCacheMBean();
UserTransaction tx = sctx.getUserTransaction();
out("got utx (" + tx + ")");
// initializing tree if iTestLoops == 0 or nodes don't exists
tx.begin();
if(this.get(NODE) == null || iTestLoops == 0)
{
this.put(NODE, "cu1", new Integer(1000));
this.put(NODE, "cu2", new Integer(1000));
this.put(NODE, "cu3", new Integer(1000));
}
tx.commit();
runTest(iTestLoops);
}
catch(Exception e)
{
e.printStackTrace();
iErr = -2;
}
return iErr;
}
/**
*
*/
private void runTest(int iTestLoops)
{
int count = 3;
UserTransaction tx = null;
try
{
boolean again = false;
int src = 0;
int dst = 0;
int amo = 0;
int cnt =0;
while(cnt < iTestLoops)
{
tx = sctx.getUserTransaction();
// out("got utx (" + tx + ")");
if(!again)
{
src = (int) (Math.random()*count);
dst = (int) (Math.random()*(count-1));
amo =1+ (int) (Math.random()*20);
if(dst>=src) dst++;
}
try
{
tx.begin();
int sum = deposit(customer[src], customer[dst], amo, tx);
if(tx.getStatus() == STATUS_ACTIVE)
{
if(sum != 3000) throw new Exception("sum failure (sum = " + sum + ", cnt = " + cnt + ")");
tx.commit();
}
else /* if(tx.getStatus() == STATUS_MARKED_ROLLBACK) */
tx.rollback();
again = false;
}
catch(Throwable e)
{
tx.rollback();
e.printStackTrace();
again = true;
}
cnt++;
}
}
catch (Throwable t)
{
t.printStackTrace();
}
}
/**
* Posting
*/
public int deposit(String from, String to, int amount, UserTransaction tx) throws Exception
{
out("deposit("+from+", "+to+", "+amount+") called.");
try
{
int act1, act2;
act1 = ((Integer) this.get(NODE, from)).intValue();
act2 = ((Integer) this.get(NODE, to)).intValue();
// eventually rollback the transaction
if((int)(Math.random() * ROLLBACK_CHANCE) == 0)
{
out("!!!manually set rollback ("+from+", "+to+", "+amount+").");
tx.setRollbackOnly();
throw new Exception("Manually set rollback!");
}
this.put(NODE, from, new Integer(act1-amount)); // debit
this.put(NODE, to, new Integer(act2+amount)); // credit
}
catch(Exception e)
{
e.printStackTrace();
out("exception - rollback ("+from+", "+to+", "+amount+")");
}
finally
{
// close resources aquired safely
}
int i0 = ((Integer) this.get(NODE, customer[0])).intValue();
int i1 = ((Integer) this.get(NODE, customer[1])).intValue();
int i2 = ((Integer) this.get(NODE, customer[2])).intValue();
int sum = i0 + i1 + i2;
out("deposit("+from+", "+to+", "+amount+") finished. (sum = " + sum + " = " +i0 + " + " + i1 + " + " + i2 + ")");
return sum;
}
/**
* retrieving amounts of accounts
*/
private void out(String s)
{
logger_.info("Thread[" + Thread.currentThread() + "]: " + s);
}
private void getTreeCacheMBean() throws Exception
{
try
{
cacheService = new ObjectName(OBJECT_NAME);
server = MBeanServerLocator.locate();
}
catch (Exception ex)
{
throw new CreateException(ex.toString());
}
}
// wrapper methods for MBean calls
/**
* @param fqn
* @param key
* @return
* @throws LockingException
* @throws TimeoutException
*/
private Object get(String fqn, String key) throws LockingException, TimeoutException, Exception
{
return server.invoke(cacheService, "get",
new Object[]{fqn, key},
new String[]{String.class.getName(),
Object.class.getName()});
}
/**
* @param fqn
* @return
* @throws LockingException
* @throws TimeoutException
*/
private org.jboss.cache.Node get(String fqn) throws LockingException, TimeoutException, Exception
{
return (org.jboss.cache.Node) (server.invoke(cacheService, "get",
new Object[]{fqn},
new String[]{String.class.getName()}));
}
/**
* @param fqn
* @param key
* @param value
* @throws Exception
*/
private void put(String fqn, String key, Object value) throws Exception
{
Object[] args = {fqn, key, value};
String[] sig = {String.class.getName(),
Object.class.getName(),
Object.class.getName()};
server.invoke(cacheService, "put", args, sig);
}
}
the code of the tester:
/*
*
* JBoss, the OpenSource J2EE webOS
*
* Distributable under LGPL license.
* See terms of license at gnu.org.
*/
package samples.test;
import junit.framework.Test;
import junit.framework.TestCase;
import junit.framework.TestSuite;
import org.jboss.cache.TreeCache;
import org.jboss.cache.lock.IsolationLevel;
import org.jboss.logging.Logger;
import samples.*;
/**
* Unit test Remote TreeCache in Application Server
*/
public class ConcurrentUnitTestCase extends TestCase
{
private Logger logger_ = Logger.getLogger(ConcurrentUnitTestCase.class);
public class rmiThread extends Thread
{
private JBossCacheTest jbossCacheTest = null;
private void connect(String sServeradressRMI)
{
try
{
logger_.info("connecting to <" + sServeradressRMI + ">");
java.util.Properties props = new java.util.Properties();
props.setProperty("java.naming.factory.initial", "org.jnp.interfaces.NamingContextFactory");
props.setProperty("java.naming.provider.url", sServeradressRMI);
props.setProperty("java.naming.factory.url.pkgs", "org.jboss.naming");
javax.naming.InitialContext iC = new javax.naming.InitialContext(props);
Object home = iC.lookup(JBossCacheTestHome.JNDI_NAME);
JBossCacheTestHome home_ =(JBossCacheTestHome)javax.rmi.PortableRemoteObject.narrow(home, JBossCacheTestHome.class);
jbossCacheTest = home_.create();
}
catch(Exception e)
{
e.printStackTrace();
}
}
public void run()
{
try
{
connect(System.getProperty("RMITestServer", "localhost:1099"));
jbossCacheTest.txTest(2000);
}
catch(Exception e)
{
e.printStackTrace();
fail(e.toString());
}
}
}
public ConcurrentUnitTestCase(String name)
{
super(name);
}
public void setUp() throws Exception
{
super.setUp();
}
public void tearDown() throws Exception
{
super.tearDown();
}
public void test_1()
{
try
{
setUp();
work_();
}
catch(Exception e)
{
e.printStackTrace();
fail(e.toString());
}
}
private void work_()
{
rmiThread one, two, three;
try
{
one = new rmiThread();
two = new rmiThread();
three = new rmiThread();
one.start();
two.start();
three.start();
one.join();
two.join();
three.join();
}
catch (Exception e)
{
e.printStackTrace();
fail(e.toString());
}
}
void log(String msg)
{
logger_.debug(" [" + Thread.currentThread() + "]: " + msg);
}
public static Test suite()
{
return new TestSuite(ConcurrentUnitTestCase.class);
}
public static void main(String[] args)
{
junit.textui.TestRunner.run(suite());
}
}
and the part of the log that shows overlapping transactions as I understand it:
... 2004-05-11 17:54:01,409 INFO [samples.JBossCacheTestEJB] Thread[Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]]: deposit(cu3, cu1, 3) called. 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu3, "975, "true") 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]getCurrentTransaction(): registered with transaction TransactionImpl:XidImpl [FormatId=257, GlobalId=test-pc//60, BranchQual=] as Synchronization listener with global transaction: <test-pc:4356>:52 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]_put(<test-pc:4356>:50, "/cachetest", cu2, 1044) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.Node] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]acquired WL: fqn=/cachetest, owner=<test-pc:4356>:50, lock=org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]_put(<test-pc:4356>:50, "/cachetest", cu3, 982) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.Node] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]acquired WL: fqn=/cachetest, owner=<test-pc:4356>:50, lock=org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu1, "974, "true") 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu2, "1044, "true") 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu3, "982, "true") 2004-05-11 17:54:01,409 INFO [samples.JBossCacheTestEJB] Thread[Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]]: deposit(cu2, cu3, 7) finished. (sum = 3000 = 974 + 1044 + 982) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] runPreparePhase(): run remote prepare with async mode: false commit: false and coordinator: test-pc:4356 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]callRemoteMethods(): destination list is empty, discarding call 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]afterCompletion() called (status=COMMITTED) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]callRemoteMethods(): destination list is empty, discarding call 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]commit(): called to commit cache with gtx <test-pc:4356>:50 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]commit(): releasing lock org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]commit(): remove local transaction key TransactionImpl:XidImpl [FormatId=257, GlobalId=test-pc//58, BranchQual=] 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu3, "982, "true") 2004-05-11 17:54:01,409 INFO [samples.JBossCacheTestEJB] Thread[Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]]: deposit(cu2, cu1, 10) called. 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu2, "1044, "true") 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]getCurrentTransaction(): registered with transaction TransactionImpl:XidImpl [FormatId=257, GlobalId=test-pc//61, BranchQual=] as Synchronization listener with global transaction: <test-pc:4356>:53 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]_put(<test-pc:4356>:51, "/cachetest", cu3, 981) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.Node] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]acquired WL: fqn=/cachetest, owner=<test-pc:4356>:51, lock=org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]_put(<test-pc:4356>:51, "/cachetest", cu2, 1045) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.Node] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]acquired WL: fqn=/cachetest, owner=<test-pc:4356>:51, lock=org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu1, "974, "true") 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu2, "1045, "true") 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu3, "981, "true") 2004-05-11 17:54:01,409 INFO [samples.JBossCacheTestEJB] Thread[Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]]: deposit(cu3, cu2, 1) finished. (sum = 3000 = 974 + 1045 + 981) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] runPreparePhase(): run remote prepare with async mode: false commit: false and coordinator: test-pc:4356 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]callRemoteMethods(): destination list is empty, discarding call 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]afterCompletion() called (status=COMMITTED) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]callRemoteMethods(): destination list is empty, discarding call 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]commit(): called to commit cache with gtx <test-pc:4356>:51 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]commit(): releasing lock org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]commit(): remove local transaction key TransactionImpl:XidImpl [FormatId=257, GlobalId=test-pc//59, BranchQual=] 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu3, "981, "true") 2004-05-11 17:54:01,409 INFO [samples.JBossCacheTestEJB] Thread[Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]]: deposit(cu3, cu2, 17) called. 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu1, "974, "true") 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]getCurrentTransaction(): registered with transaction TransactionImpl:XidImpl [FormatId=257, GlobalId=test-pc//62, BranchQual=] as Synchronization listener with global transaction: <test-pc:4356>:54 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]_put(<test-pc:4356>:52, "/cachetest", cu3, 978) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.Node] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]acquired WL: fqn=/cachetest, owner=<test-pc:4356>:52, lock=org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]_put(<test-pc:4356>:52, "/cachetest", cu1, 977) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.Node] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]acquired WL: fqn=/cachetest, owner=<test-pc:4356>:52, lock=org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu1, "977, "true") 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu2, "1045, "true") 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu3, "978, "true") 2004-05-11 17:54:01,409 INFO [samples.JBossCacheTestEJB] Thread[Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]]: deposit(cu3, cu1, 3) finished. (sum = 3000 = 977 + 1045 + 978) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] runPreparePhase(): run remote prepare with async mode: false commit: false and coordinator: test-pc:4356 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]callRemoteMethods(): destination list is empty, discarding call 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]afterCompletion() called (status=COMMITTED) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]callRemoteMethods(): destination list is empty, discarding call 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]commit(): called to commit cache with gtx <test-pc:4356>:52 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]commit(): releasing lock org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]commit(): remove local transaction key TransactionImpl:XidImpl [FormatId=257, GlobalId=test-pc//60, BranchQual=] 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu2, "1045, "true") 2004-05-11 17:54:01,409 INFO [samples.JBossCacheTestEJB] Thread[Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]]: deposit(cu1, cu2, 20) called. 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu1, "977, "true") 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]getCurrentTransaction(): registered with transaction TransactionImpl:XidImpl [FormatId=257, GlobalId=test-pc//63, BranchQual=] as Synchronization listener with global transaction: <test-pc:4356>:55 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]_put(<test-pc:4356>:53, "/cachetest", cu2, 1035) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.Node] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]acquired WL: fqn=/cachetest, owner=<test-pc:4356>:53, lock=org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]_put(<test-pc:4356>:53, "/cachetest", cu1, 987) 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.Node] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]acquired WL: fqn=/cachetest, owner=<test-pc:4356>:53, lock=org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu1, "987, "true") 2004-05-11 17:54:01,409 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu2, "1035, "true") 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu3, "978, "true") 2004-05-11 17:54:01,425 INFO [samples.JBossCacheTestEJB] Thread[Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]]: deposit(cu2, cu1, 10) finished. (sum = 3000 = 987 + 1035 + 978) 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] runPreparePhase(): run remote prepare with async mode: false commit: false and coordinator: test-pc:4356 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]callRemoteMethods(): destination list is empty, discarding call 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]afterCompletion() called (status=COMMITTED) 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]callRemoteMethods(): destination list is empty, discarding call 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]commit(): called to commit cache with gtx <test-pc:4356>:53 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]commit(): releasing lock org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]commit(): remove local transaction key TransactionImpl:XidImpl [FormatId=257, GlobalId=test-pc//61, BranchQual=] 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu3, "978, "true") 2004-05-11 17:54:01,425 INFO [samples.JBossCacheTestEJB] Thread[Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]]: deposit(cu3, cu2, 3) called. 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(5)-192.168.100.120,5,RMI Runtime]getCurrentTransaction(): registered with transaction TransactionImpl:XidImpl [FormatId=257, GlobalId=test-pc//64, BranchQual=] as Synchronization listener with global transaction: <test-pc:4356>:56 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu3, "978, "true") 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]_put(<test-pc:4356>:54, "/cachetest", cu3, 961) 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.Node] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]acquired WL: fqn=/cachetest, owner=<test-pc:4356>:54, lock=org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]_put(<test-pc:4356>:54, "/cachetest", cu2, 995) 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.Node] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]acquired WL: fqn=/cachetest, owner=<test-pc:4356>:54, lock=org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu1, "987, "true") 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu2, "995, "true") 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu3, "961, "true") 2004-05-11 17:54:01,425 INFO [samples.JBossCacheTestEJB] Thread[Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]]: deposit(cu3, cu2, 17) finished. (sum = 2943 = 987 + 995 + 961) 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]afterCompletion() called (status=ROLLEDBACK) 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]afterCompletion(): rolling back cache 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]callRemoteMethods(): destination list is empty, discarding call 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]rollback(): called to rollback cache 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]_put(<test-pc:4356>:54, "/cachetest", cu2, 1035) 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.Node] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]acquired WL: fqn=/cachetest, owner=<test-pc:4356>:54, lock=org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]_put(<test-pc:4356>:54, "/cachetest", cu3, 978) 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.Node] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]acquired WL: fqn=/cachetest, owner=<test-pc:4356>:54, lock=org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(4)-192.168.100.120,5,RMI Runtime]rollback(): releasing lock org.jboss.cache.lock.IdentityLock@be0446 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu1, "987, "true") 2004-05-11 17:54:01,425 DEBUG [org.jboss.cache.TreeCache] Thread[RMI TCP Connection(6)-192.168.100.120,5,RMI Runtime]get(, "/cachetest", cu2, "1035, "true") 2004-05-11 17:54:01,425 INFO [STDOUT] java.lang.Exception: sum failure (sum = 2943, cnt = 16) ...
