javax.transaction.HeuristicMixedException whlie starting Infinispan

[tcoates1362]

Hello,

I've been working on converting a JBoss Cache 3.2.1 app to Infinispan 4.0.0. I'm running in JBoss AS 4.2.3. During startup, I'm running into the following exceptions:

{code}
2010-07-27 11:18:58,655 [TRACE] ~main(org.infinispan.loaders.LockSupportCacheStore): store(ImmortalCacheEntry{cacheValue=ImmortalCacheValue{value=AtomicHashMap{delegate=org.infinispan.util.FastCopyHashMap@2d0d20ce}}} ImmortalCacheEntry{key=NodeKey{contents=STRUCTURE, fqn=/}})
2010-07-27 11:18:58,656 [TRACE] ~main(org.infinispan.loaders.jdbc.binary.JdbcBinaryCacheStore): Running loadBucket. Sql: 'SELECT ID, DATA FROM ISPN_BUCKET_CH WHERE ID = ?', on key: -8295652
2010-07-27 11:18:58,658 [ERROR] ~main(org.infinispan.loaders.jdbc.connectionfactory.ManagedConnectionFactory): org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57377a:f88f:4c4f2303:2c status: ActionStatus.COMMITTING >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57377a:f88f:4c4f2303:2c status: ActionStatus.COMMITTING >)
2010-07-27 11:18:58,661 [ERROR] ~main(org.infinispan.interceptors.InvocationContextInterceptor): Execution error: 
java.lang.NullPointerException
    at org.infinispan.loaders.jdbc.connectionfactory.ManagedConnectionFactory.releaseConnection(ManagedConnectionFactory.java:103)
    at org.infinispan.loaders.jdbc.binary.JdbcBinaryCacheStore.loadBucket(JdbcBinaryCacheStore.java:216)
    at org.infinispan.loaders.bucket.BucketBasedCacheStore.storeLockSafe(BucketBasedCacheStore.java:54)
    at org.infinispan.loaders.LockSupportCacheStore.store(LockSupportCacheStore.java:131)
    at org.infinispan.loaders.AbstractCacheStore.applyModifications(AbstractCacheStore.java:101)
    at org.infinispan.loaders.AbstractCacheStore.commit(AbstractCacheStore.java:134)
    at org.infinispan.interceptors.CacheStoreInterceptor.visitCommitCommand(CacheStoreInterceptor.java:123)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
    at org.infinispan.commands.AbstractVisitor.visitCommitCommand(AbstractVisitor.java:113)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
    at org.infinispan.commands.AbstractVisitor.visitCommitCommand(AbstractVisitor.java:113)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.NotificationInterceptor.visitCommitCommand(NotificationInterceptor.java:55)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.TxInterceptor.visitCommitCommand(TxInterceptor.java:101)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
    at org.infinispan.commands.AbstractVisitor.visitCommitCommand(AbstractVisitor.java:113)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:48)
    at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:34)
    at org.infinispan.commands.AbstractVisitor.visitCommitCommand(AbstractVisitor.java:113)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:72)
    at org.infinispan.commands.AbstractVisitor.visitCommitCommand(AbstractVisitor.java:113)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:269)
    at org.infinispan.transaction.xa.TransactionXaAdapter.commit(TransactionXaAdapter.java:114)
    at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelCommit(XAResourceRecord.java:487)
    at com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:3107)
    at com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:3022)
    at com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Commit(BasicAction.java:2126)
    at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1819)
    at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:88)
    at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1389)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
    at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87)
    at org.jboss.aspects.tx.TxPolicy.endTransaction(TxPolicy.java:175)
    at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:87)
    at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:191)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.service.ServiceContainer.localInvoke(ServiceContainer.java:329)
    at org.jboss.ejb3.service.ServiceContainer.localInvoke(ServiceContainer.java:294)
    at org.jboss.ejb3.service.ServiceMBeanDelegate.invoke(ServiceMBeanDelegate.java:215)
    at org.jboss.mx.server.RawDynamicInvoker.invoke(RawDynamicInvoker.java:164)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:995)
    at $Proxy0.start(Unknown Source)
    at org.jboss.system.ServiceController.start(ServiceController.java:417)
    at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy43.start(Unknown Source)
    at org.jboss.ejb3.JmxKernelAbstraction.installMBean(JmxKernelAbstraction.java:163)
    at org.jboss.ejb3.service.ServiceContainer.registerManagementInterface(ServiceContainer.java:554)
    at org.jboss.ejb3.service.ServiceContainer.start(ServiceContainer.java:175)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.ejb3.ServiceDelegateWrapper.startService(ServiceDelegateWrapper.java:103)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalStart(ServiceMBeanSupport.java:289)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalLifecycle(ServiceMBeanSupport.java:245)
    at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:978)
    at $Proxy0.start(Unknown Source)
    at org.jboss.system.ServiceController.start(ServiceController.java:417)
    at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy43.start(Unknown Source)
    at org.jboss.ejb3.JmxKernelAbstraction.install(JmxKernelAbstraction.java:120)
    at org.jboss.ejb3.Ejb3Deployment.registerEJBContainer(Ejb3Deployment.java:301)
    at org.jboss.ejb3.Ejb3Deployment.start(Ejb3Deployment.java:362)
    at org.jboss.ejb3.Ejb3Module.startService(Ejb3Module.java:91)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalStart(ServiceMBeanSupport.java:289)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalLifecycle(ServiceMBeanSupport.java:245)
    at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:978)
    at $Proxy0.start(Unknown Source)
    at org.jboss.system.ServiceController.start(ServiceController.java:417)
    at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy28.start(Unknown Source)
    at org.jboss.ejb3.EJB3Deployer.start(EJB3Deployer.java:512)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
    at org.jboss.mx.interceptor.DynamicInterceptor.invoke(DynamicInterceptor.java:97)
    at org.jboss.system.InterceptorServiceMBeanSupport.invokeNext(InterceptorServiceMBeanSupport.java:238)
    at org.jboss.wsf.container.jboss42.DeployerInterceptor.start(DeployerInterceptor.java:85)
    at org.jboss.deployment.SubDeployerInterceptorSupport$XMBeanInterceptor.start(SubDeployerInterceptorSupport.java:188)
    at org.jboss.deployment.SubDeployerInterceptor.invoke(SubDeployerInterceptor.java:95)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy29.start(Unknown Source)
    at org.jboss.deployment.MainDeployer.start(MainDeployer.java:1025)
    at org.jboss.deployment.MainDeployer.start(MainDeployer.java:1015)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:819)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:782)
    at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy9.deploy(Unknown Source)
    at org.jboss.deployment.scanner.URLDeploymentScanner.deploy(URLDeploymentScanner.java:421)
    at org.jboss.deployment.scanner.URLDeploymentScanner.scan(URLDeploymentScanner.java:634)
    at org.jboss.deployment.scanner.AbstractDeploymentScanner$ScannerThread.doScan(AbstractDeploymentScanner.java:263)
    at org.jboss.deployment.scanner.AbstractDeploymentScanner.startService(AbstractDeploymentScanner.java:336)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalStart(ServiceMBeanSupport.java:289)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalLifecycle(ServiceMBeanSupport.java:245)
    at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:978)
    at $Proxy0.start(Unknown Source)
    at org.jboss.system.ServiceController.start(ServiceController.java:417)
    at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy4.start(Unknown Source)
    at org.jboss.deployment.SARDeployer.start(SARDeployer.java:304)
    at org.jboss.deployment.MainDeployer.start(MainDeployer.java:1025)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:819)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:782)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:766)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy5.deploy(Unknown Source)
    at org.jboss.system.server.ServerImpl.doStart(ServerImpl.java:482)
    at org.jboss.system.server.ServerImpl.start(ServerImpl.java:362)
    at org.jboss.Main.boot(Main.java:200)
    at org.jboss.Main$1.run(Main.java:508)
    at java.lang.Thread.run(Thread.java:619)
2010-07-27 11:18:59,298 [ERROR] ~main(org.infinispan.transaction.xa.TransactionXaAdapter): Error while processing 1PC PrepareCommand
java.lang.NullPointerException
    at org.infinispan.loaders.jdbc.connectionfactory.ManagedConnectionFactory.releaseConnection(ManagedConnectionFactory.java:103)
    at org.infinispan.loaders.jdbc.binary.JdbcBinaryCacheStore.loadBucket(JdbcBinaryCacheStore.java:216)
    at org.infinispan.loaders.bucket.BucketBasedCacheStore.storeLockSafe(BucketBasedCacheStore.java:54)
    at org.infinispan.loaders.LockSupportCacheStore.store(LockSupportCacheStore.java:131)
    at org.infinispan.loaders.AbstractCacheStore.applyModifications(AbstractCacheStore.java:101)
    at org.infinispan.loaders.AbstractCacheStore.commit(AbstractCacheStore.java:134)
    at org.infinispan.interceptors.CacheStoreInterceptor.visitCommitCommand(CacheStoreInterceptor.java:123)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
    at org.infinispan.commands.AbstractVisitor.visitCommitCommand(AbstractVisitor.java:113)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
    at org.infinispan.commands.AbstractVisitor.visitCommitCommand(AbstractVisitor.java:113)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.NotificationInterceptor.visitCommitCommand(NotificationInterceptor.java:55)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.TxInterceptor.visitCommitCommand(TxInterceptor.java:101)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
    at org.infinispan.commands.AbstractVisitor.visitCommitCommand(AbstractVisitor.java:113)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:48)
    at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:34)
    at org.infinispan.commands.AbstractVisitor.visitCommitCommand(AbstractVisitor.java:113)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
    at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:72)
    at org.infinispan.commands.AbstractVisitor.visitCommitCommand(AbstractVisitor.java:113)
    at org.infinispan.commands.tx.CommitCommand.acceptVisitor(CommitCommand.java:50)
    at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:269)
    at org.infinispan.transaction.xa.TransactionXaAdapter.commit(TransactionXaAdapter.java:114)
    at com.arjuna.ats.internal.jta.resources.arjunacore.XAResourceRecord.topLevelCommit(XAResourceRecord.java:487)
    at com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:3107)
    at com.arjuna.ats.arjuna.coordinator.BasicAction.doCommit(BasicAction.java:3022)
    at com.arjuna.ats.arjuna.coordinator.BasicAction.phase2Commit(BasicAction.java:2126)
    at com.arjuna.ats.arjuna.coordinator.BasicAction.End(BasicAction.java:1819)
    at com.arjuna.ats.arjuna.coordinator.TwoPhaseCoordinator.end(TwoPhaseCoordinator.java:88)
    at com.arjuna.ats.arjuna.AtomicAction.commit(AtomicAction.java:177)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1389)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
    at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87)
    at org.jboss.aspects.tx.TxPolicy.endTransaction(TxPolicy.java:175)
    at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:87)
    at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:191)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.service.ServiceContainer.localInvoke(ServiceContainer.java:329)
    at org.jboss.ejb3.service.ServiceContainer.localInvoke(ServiceContainer.java:294)
    at org.jboss.ejb3.service.ServiceMBeanDelegate.invoke(ServiceMBeanDelegate.java:215)
    at org.jboss.mx.server.RawDynamicInvoker.invoke(RawDynamicInvoker.java:164)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:995)
    at $Proxy0.start(Unknown Source)
    at org.jboss.system.ServiceController.start(ServiceController.java:417)
    at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy43.start(Unknown Source)
    at org.jboss.ejb3.JmxKernelAbstraction.installMBean(JmxKernelAbstraction.java:163)
    at org.jboss.ejb3.service.ServiceContainer.registerManagementInterface(ServiceContainer.java:554)
    at org.jboss.ejb3.service.ServiceContainer.start(ServiceContainer.java:175)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.ejb3.ServiceDelegateWrapper.startService(ServiceDelegateWrapper.java:103)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalStart(ServiceMBeanSupport.java:289)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalLifecycle(ServiceMBeanSupport.java:245)
    at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:978)
    at $Proxy0.start(Unknown Source)
    at org.jboss.system.ServiceController.start(ServiceController.java:417)
    at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy43.start(Unknown Source)
    at org.jboss.ejb3.JmxKernelAbstraction.install(JmxKernelAbstraction.java:120)
    at org.jboss.ejb3.Ejb3Deployment.registerEJBContainer(Ejb3Deployment.java:301)
    at org.jboss.ejb3.Ejb3Deployment.start(Ejb3Deployment.java:362)
    at org.jboss.ejb3.Ejb3Module.startService(Ejb3Module.java:91)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalStart(ServiceMBeanSupport.java:289)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalLifecycle(ServiceMBeanSupport.java:245)
    at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:978)
    at $Proxy0.start(Unknown Source)
    at org.jboss.system.ServiceController.start(ServiceController.java:417)
    at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy28.start(Unknown Source)
    at org.jboss.ejb3.EJB3Deployer.start(EJB3Deployer.java:512)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
    at org.jboss.mx.interceptor.DynamicInterceptor.invoke(DynamicInterceptor.java:97)
    at org.jboss.system.InterceptorServiceMBeanSupport.invokeNext(InterceptorServiceMBeanSupport.java:238)
    at org.jboss.wsf.container.jboss42.DeployerInterceptor.start(DeployerInterceptor.java:85)
    at org.jboss.deployment.SubDeployerInterceptorSupport$XMBeanInterceptor.start(SubDeployerInterceptorSupport.java:188)
    at org.jboss.deployment.SubDeployerInterceptor.invoke(SubDeployerInterceptor.java:95)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy29.start(Unknown Source)
    at org.jboss.deployment.MainDeployer.start(MainDeployer.java:1025)
    at org.jboss.deployment.MainDeployer.start(MainDeployer.java:1015)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:819)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:782)
    at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy9.deploy(Unknown Source)
    at org.jboss.deployment.scanner.URLDeploymentScanner.deploy(URLDeploymentScanner.java:421)
    at org.jboss.deployment.scanner.URLDeploymentScanner.scan(URLDeploymentScanner.java:634)
    at org.jboss.deployment.scanner.AbstractDeploymentScanner$ScannerThread.doScan(AbstractDeploymentScanner.java:263)
    at org.jboss.deployment.scanner.AbstractDeploymentScanner.startService(AbstractDeploymentScanner.java:336)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalStart(ServiceMBeanSupport.java:289)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalLifecycle(ServiceMBeanSupport.java:245)
    at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:978)
    at $Proxy0.start(Unknown Source)
    at org.jboss.system.ServiceController.start(ServiceController.java:417)
    at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy4.start(Unknown Source)
    at org.jboss.deployment.SARDeployer.start(SARDeployer.java:304)
    at org.jboss.deployment.MainDeployer.start(MainDeployer.java:1025)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:819)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:782)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:766)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy5.deploy(Unknown Source)
    at org.jboss.system.server.ServerImpl.doStart(ServerImpl.java:482)
    at org.jboss.system.server.ServerImpl.start(ServerImpl.java:362)
    at org.jboss.Main.boot(Main.java:200)
    at org.jboss.Main$1.run(Main.java:508)
    at java.lang.Thread.run(Thread.java:619)
2010-07-27 11:18:59,915 [WARN] ~main(com.arjuna.ats.jta.logging.loggerI18N): [com.arjuna.ats.internal.jta.resources.arjunacore.commitxaerror] [com.arjuna.ats.internal.jta.resources.arjunacore.commitxaerror] XAResourceRecord.commit - xa error XAException.XAER_RMERR
2010-07-27 11:18:59,977 [WARN] ~main(org.jboss.system.ServiceController): Problem starting service copperhead:service=Cache
java.lang.RuntimeException: javax.transaction.HeuristicMixedException
    at org.jboss.aspects.tx.TxPolicy.handleEndTransactionException(TxPolicy.java:198)
    at org.jboss.aspects.tx.TxPolicy.endTransaction(TxPolicy.java:184)
    at org.jboss.aspects.tx.TxPolicy.invokeInOurTx(TxPolicy.java:87)
    at org.jboss.aspects.tx.TxInterceptor$Required.invoke(TxInterceptor.java:191)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.aspects.tx.TxPropagationInterceptor.invoke(TxPropagationInterceptor.java:95)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.ENCPropagationInterceptor.invoke(ENCPropagationInterceptor.java:46)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.asynchronous.AsynchronousInterceptor.invoke(AsynchronousInterceptor.java:106)
    at org.jboss.aop.joinpoint.MethodInvocation.invokeNext(MethodInvocation.java:101)
    at org.jboss.ejb3.service.ServiceContainer.localInvoke(ServiceContainer.java:329)
    at org.jboss.ejb3.service.ServiceContainer.localInvoke(ServiceContainer.java:294)
    at org.jboss.ejb3.service.ServiceMBeanDelegate.invoke(ServiceMBeanDelegate.java:215)
    at org.jboss.mx.server.RawDynamicInvoker.invoke(RawDynamicInvoker.java:164)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:995)
    at $Proxy0.start(Unknown Source)
    at org.jboss.system.ServiceController.start(ServiceController.java:417)
    at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy43.start(Unknown Source)
    at org.jboss.ejb3.JmxKernelAbstraction.installMBean(JmxKernelAbstraction.java:163)
    at org.jboss.ejb3.service.ServiceContainer.registerManagementInterface(ServiceContainer.java:554)
    at org.jboss.ejb3.service.ServiceContainer.start(ServiceContainer.java:175)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.ejb3.ServiceDelegateWrapper.startService(ServiceDelegateWrapper.java:103)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalStart(ServiceMBeanSupport.java:289)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalLifecycle(ServiceMBeanSupport.java:245)
    at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:978)
    at $Proxy0.start(Unknown Source)
    at org.jboss.system.ServiceController.start(ServiceController.java:417)
    at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy43.start(Unknown Source)
    at org.jboss.ejb3.JmxKernelAbstraction.install(JmxKernelAbstraction.java:120)
    at org.jboss.ejb3.Ejb3Deployment.registerEJBContainer(Ejb3Deployment.java:301)
    at org.jboss.ejb3.Ejb3Deployment.start(Ejb3Deployment.java:362)
    at org.jboss.ejb3.Ejb3Module.startService(Ejb3Module.java:91)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalStart(ServiceMBeanSupport.java:289)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalLifecycle(ServiceMBeanSupport.java:245)
    at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:978)
    at $Proxy0.start(Unknown Source)
    at org.jboss.system.ServiceController.start(ServiceController.java:417)
    at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy28.start(Unknown Source)
    at org.jboss.ejb3.EJB3Deployer.start(EJB3Deployer.java:512)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
    at org.jboss.mx.interceptor.DynamicInterceptor.invoke(DynamicInterceptor.java:97)
    at org.jboss.system.InterceptorServiceMBeanSupport.invokeNext(InterceptorServiceMBeanSupport.java:238)
    at org.jboss.wsf.container.jboss42.DeployerInterceptor.start(DeployerInterceptor.java:85)
    at org.jboss.deployment.SubDeployerInterceptorSupport$XMBeanInterceptor.start(SubDeployerInterceptorSupport.java:188)
    at org.jboss.deployment.SubDeployerInterceptor.invoke(SubDeployerInterceptor.java:95)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy29.start(Unknown Source)
    at org.jboss.deployment.MainDeployer.start(MainDeployer.java:1025)
    at org.jboss.deployment.MainDeployer.start(MainDeployer.java:1015)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:819)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:782)
    at sun.reflect.GeneratedMethodAccessor43.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy9.deploy(Unknown Source)
    at org.jboss.deployment.scanner.URLDeploymentScanner.deploy(URLDeploymentScanner.java:421)
    at org.jboss.deployment.scanner.URLDeploymentScanner.scan(URLDeploymentScanner.java:634)
    at org.jboss.deployment.scanner.AbstractDeploymentScanner$ScannerThread.doScan(AbstractDeploymentScanner.java:263)
    at org.jboss.deployment.scanner.AbstractDeploymentScanner.startService(AbstractDeploymentScanner.java:336)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalStart(ServiceMBeanSupport.java:289)
    at org.jboss.system.ServiceMBeanSupport.jbossInternalLifecycle(ServiceMBeanSupport.java:245)
    at sun.reflect.GeneratedMethodAccessor2.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.system.ServiceController$ServiceProxy.invoke(ServiceController.java:978)
    at $Proxy0.start(Unknown Source)
    at org.jboss.system.ServiceController.start(ServiceController.java:417)
    at sun.reflect.GeneratedMethodAccessor9.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:86)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy4.start(Unknown Source)
    at org.jboss.deployment.SARDeployer.start(SARDeployer.java:304)
    at org.jboss.deployment.MainDeployer.start(MainDeployer.java:1025)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:819)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:782)
    at org.jboss.deployment.MainDeployer.deploy(MainDeployer.java:766)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
    at java.lang.reflect.Method.invoke(Method.java:597)
    at org.jboss.mx.interceptor.ReflectedDispatcher.invoke(ReflectedDispatcher.java:155)
    at org.jboss.mx.server.Invocation.dispatch(Invocation.java:94)
    at org.jboss.mx.interceptor.AbstractInterceptor.invoke(AbstractInterceptor.java:133)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.interceptor.ModelMBeanOperationInterceptor.invoke(ModelMBeanOperationInterceptor.java:142)
    at org.jboss.mx.server.Invocation.invoke(Invocation.java:88)
    at org.jboss.mx.server.AbstractMBeanInvoker.invoke(AbstractMBeanInvoker.java:264)
    at org.jboss.mx.server.MBeanServerImpl.invoke(MBeanServerImpl.java:659)
    at org.jboss.mx.util.MBeanProxyExt.invoke(MBeanProxyExt.java:210)
    at $Proxy5.deploy(Unknown Source)
    at org.jboss.system.server.ServerImpl.doStart(ServerImpl.java:482)
    at org.jboss.system.server.ServerImpl.start(ServerImpl.java:362)
    at org.jboss.Main.boot(Main.java:200)
    at org.jboss.Main$1.run(Main.java:508)
    at java.lang.Thread.run(Thread.java:619)
Caused by: javax.transaction.HeuristicMixedException
    at com.arjuna.ats.internal.jta.transaction.arjunacore.TransactionImple.commitAndDisassociate(TransactionImple.java:1395)
    at com.arjuna.ats.internal.jta.transaction.arjunacore.BaseTransaction.commit(BaseTransaction.java:135)
    at com.arjuna.ats.jbossatx.BaseTransactionManagerDelegate.commit(BaseTransactionManagerDelegate.java:87)
    at org.jboss.aspects.tx.TxPolicy.endTransaction(TxPolicy.java:175)
    ... 173 more
{code}

My Infinispan config is attached to this post. I'm currently using an XA Datasource although I have tried this with a non-XA Datasource as well with the same results. Any ideas?

Thanks,

-Tom Coates

[tcoates1362]

Has anyone see this? Has Infinispan been tested with XA transactions in AS 4.2.3? Just need to know whether this "should" work or if I need to pursue other options.

Thanks for any help,

-Tom

[galder.zamarreno]

Maybe the transaction timed out?

2010-07-27 11:18:58,658 [ERROR] ~main(org.infinispan.loaders.jdbc.connectionfactory.ManagedConnectionFactory): org.jboss.util.NestedSQLException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57377a:f88f:4c4f2303:2c status: ActionStatus.COMMITTING >; - nested throwable: (javax.resource.ResourceException: Transaction is not active: tx=TransactionImple < ac, BasicAction: -3f57377a:f88f:4c4f2303:2c status: ActionStatus.COMMITTING >)

Maybe you want to enable TRACE logging for org.infinispan and enable full logging for JBoss Transactions via to find out what's the cause:

- add to conf/ljbossjta-properties.xml

<property name="com.arjuna.common.util.logging.DebugLevel" type="System" value="0xffffffff"/>

The NPE is a side effect.

Finally, you might want to be careful with deploying Infinispan in AS 4.x or 5.x cos it uses different JGroups library to the one shipped with those AS versions. So, for things to work correctly, you'd need to deploy Infinispan and depending libraries in isolated mode, or jarjar its jgroups jar.

[galder.zamarreno]

The NPE should be fixed now: https://jira.jboss.org/browse/ISPN-564

[tcoates1362]

Thanks Galder. I checked out the code and made a similar change to get past the NPE and was able to determine what the underlying cause of this was. I would have posted my findings earlier but I've been out of town for the last week.

Anyways, what seems to be the real problem is that all the things that need to be persisted are saved in memory and then when the transaction is completing (either in prepare or commit phase) the loader attempts to get a connection from the datasource. Apparently this is illegal and throws an exception which is what causes the HeuristicMixedException further up the chain.

This only fails when using a ManagedConnectionFactory. If I swap out a PooledConnectionFactory it works fine. I presume the managed version fails because it returns the same connection that is part of the active transaction for that thread and you can't perform new operations on that connection once the transaction is already in prepare or commit. This feels like a bit of a design flaw to me... I didn't see an obvious fix.

In the course of this research I found a few other issues that you may want to create Jira tickets for:

1. In org.infinispan.loaders.AbstractCacheStore, there is this prepare method

{code:java}
public void prepare(List<? extends Modification> mods, GlobalTransaction tx, boolean isOnePhase) throws CacheLoaderException {
      if (isOnePhase) {
         applyModifications(mods);
      } else {
         transactions.put(tx, mods);
      }
}
{code}

This seems backwards to me. Wouldn't we want to apply the mods in the prepare phase if we're using a 2-phase commit?

2. In org.infinispan.commands.write.PutKeyValueCommand, this is the beginning of the perform method:

{code:java}
public Object perform(InvocationContext ctx) throws Throwable {
      Object o;
      MVCCEntry e = (MVCCEntry) ctx.lookupEntry(key);
      Object entryValue = e.getValue();
... 
{code}

I was getting class cast exceptions from this line and was able to resolve it by doing this instead:

{code:java}
public Object perform(InvocationContext ctx) throws Throwable {
      Object o;
      CacheEntry e = (CacheEntry) ctx.lookupEntry(key);
      Object entryValue = e.getValue();
...
{code}

3. Lastly, once I got past the above issues, the root node "\" in my Tree Cache was being persisted, but I couldn't put my own entry in. I tracked down the problem to this code:

{code:java}
boolean createNodeInCache(Fqn fqn) {
      startAtomic();
      try {
         NodeKey dataKey = new NodeKey(fqn, NodeKey.Type.DATA);
         NodeKey structureKey = new NodeKey(fqn, NodeKey.Type.STRUCTURE);
         if (cache.containsKey(dataKey) && cache.containsKey(structureKey)) return false;
         Fqn parent = fqn.getParent();
         if (!fqn.isRoot()) {
            if (!exists(parent)) createNodeInCache(parent);
            AtomicMap<Object, Fqn> parentStructure = getStructure(parent);
            // don't lock parents for child insert/removes!
            icc.getInvocationContext().setFlags(Flag.SKIP_LOCKING);
            parentStructure.put(fqn.getLastElement(), fqn);
         }
         getAtomicMap(structureKey);
         getAtomicMap(dataKey);
         if (log.isTraceEnabled()) log.trace("Created node " + fqn);
         return true;
      }
      finally {
         endAtomic();
      }
   }
{code}

This line:

{code:java}
         if (!fqn.isRoot()) {
{code}

should be this:

{code:java}
         if (!parent.isRoot()) {
{code}

Things still aren't working (although closer). I'm getting a new NPE now:

{code}
2010-07-29 16:44:14,782 [ERROR] ~main(org.infinispan.interceptors.InvocationContextInterceptor): Execution error: 
java.lang.NullPointerException
    at org.infinispan.interceptors.CacheLoaderInterceptor.recordLoadedEntry(CacheLoaderInterceptor.java:177)
    at org.infinispan.interceptors.CacheLoaderInterceptor.loadIfNeeded(CacheLoaderInterceptor.java:142)
    at org.infinispan.interceptors.CacheLoaderInterceptor.loadIfNeededAndUpdateStats(CacheLoaderInterceptor.java:195)
    at org.infinispan.interceptors.CacheLoaderInterceptor.visitGetKeyValueCommand(CacheLoaderInterceptor.java:86)
    at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58)
    at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
...
{code}

To summarize here are the 5 problems I've found:

1. ManagedConnectionPool doesn't seem to work in a transactional context

2. Prepare/Commit actions may be reversed?

3. ClassCastException in PutKeyValueCommand

4. Unable to persist tree cache node other than root

5. NPE in CacheLoaderInterceptor

I'm out of project time to research this further and given the apparent instability of Infinispan in it's current state I think we're going to shelf the upgrade for now and revisit when things have had some time to mature.

Thanks for your assistence so far, and I hope things continue to improve with this project so we can come back to it at a later time.

-Tom

[manik]

Hi Tom

Thanks for your investigations.

1. ManagedConnectionPool doesn't seem to work in a transactional context

2. Prepare/Commit actions may be reversed?

This is something we will investigate.  They are related, and the code you presented in the AbstractCacheStore is really targeted at non-transactional data stores.  Transactional ones such as the JdbcCacheStore really should override this method and provide functionality similar to what you described.  This is probably the reason why ManagedConnectionPools don't seem to work with transactions.  I've logged this as ISPN-586.

3. ClassCastException in PutKeyValueCommand

ISPN-587

4. Unable to persist tree cache node other than root

5. NPE in CacheLoaderInterceptor

Would you happen to have unit tests for these two which you could share?

I'm out of project time to research this further and given the apparent instability of Infinispan in it's current state I think we're going to shelf the upgrade for now and revisit when things have had some time to mature.

That's a shame, you've given us some valuable feedback.    I recommend adding a watch to the JIRA issues above so you will be notified of when fixes are made available.

Cheers

Manik

[tcoates1362]

Thanks for creating the tickets Manik.

I unfortunately don't have unit tests for the last two issues. I think you could take one of the existing TreeCache tests and configure the cache with a loader to reproduce, but as I mentioned I don't have the hours left in my project to work on this at the moment. I looked at it briefly to see if it was something I could throw together but I'm not familiar with the test infrastructure and can't spend much time coming up to speed.

I've placed watches on the issues as suggested and voted for them as well.

Thanks again for the help.

-Tom

[manik]

Tom Coates wrote:

Thanks for creating the tickets Manik.

I unfortunately don't have unit tests for the last two issues. I think you could take one of the existing TreeCache tests and configure the cache with a loader to reproduce, but as I mentioned I don't have the hours left in my project to work on this at the moment. I looked at it briefly to see if it was something I could throw together but I'm not familiar with the test infrastructure and can't spend much time coming up to speed.

I've placed watches on the issues as suggested and voted for them as well.

Thanks again for the help.

-Tom

Hmm, I created a simple test that persists a tree cache with a cache store, even storing attributes in the root node, and it all seems to work fine. 

http://viewvc.jboss.org/cgi-bin/viewvc.cgi/infinispan?view=revision&revision=2195

[tcoates1362]

I negotiated for some more time to work on this, so hopefully I can provide some better information.

I decided to try some of the operations my app will perform from a stand alone app rather than in an AS container so that I can hopefully convert to unit tests when I find issues.

Basically, I setup a Tree Cache with a JDBC cache loader. A simple put/get works fine (even persists) if I make the cache non-transactional. As soon as I add transaction support, things go south. I'm using the latest code from the 4.1.x svn branch. Here is my transaction config (full config attached):

{code:xml}
<transaction
  transactionManagerLookupClass="org.infinispan.transaction.lookup.JBossStandaloneJTAManagerLookup"
  syncRollbackPhase="false"
  syncCommitPhase="false"
  useEagerLocking="false"
/>
{code}

Here is my test app:

{code:java}
package com.varolii.infinispantest;
import java.util.Set;
import org.apache.commons.logging.Log;
import org.apache.commons.logging.LogFactory;
import org.infinispan.Cache;
import org.infinispan.manager.DefaultCacheManager;
import org.infinispan.manager.EmbeddedCacheManager;
import org.infinispan.tree.Fqn;
import org.infinispan.tree.Node;
import org.infinispan.tree.TreeCache;
import org.infinispan.tree.TreeCacheFactory;
public class App {
    private static Log logger = LogFactory.getLog(App.class);
    public static void main(String[] args) {
        try {
            EmbeddedCacheManager manager = new DefaultCacheManager("cache.xml");
            Cache nativeCache = manager.getCache();
            TreeCacheFactory treeCacheFactory = new TreeCacheFactory();
            TreeCache cache = treeCacheFactory.createTreeCache(nativeCache);
            cache.put(Fqn.fromElements("system", "metadata"), "metadata", "this is my metadata string");
            logger.info("metadata: " + cache.get(Fqn.fromElements("system", "metadata"), "metadata"));
            cache.stop();
            logger.info("all is well");
        } catch (Exception e) {
            logger.error(e);
        }
    }
}
{code}

With the JBossStandaloneJTAManagerLookup defined in my config (attached), I get the following exception:

{code}
2010-08-11 12:46:34,737 [INFO] ~main(JBossStandaloneJTAManagerLookup): Retrieving transaction manager Transaction: unknown
2010-08-11 12:46:34,861 [INFO] ~main(GlobalComponentRegistry): Infinispan version: Infinispan 'Radegast' 4.1.0.SNAPSHOT
2010-08-11 12:46:35,501 [INFO] ~main(ComponentRegistry): Infinispan version: Infinispan 'Radegast' 4.1.0.SNAPSHOT
2010-08-11 12:46:35,540 [INFO] ~main(arjLoggerI18N): [com.arjuna.ats.arjuna.recovery.TransactionStatusManager_1] - Starting service com.arjuna.ats.arjuna.recovery.ActionStatusService on port 53710
2010-08-11 12:46:35,547 [INFO] ~main(arjLoggerI18N): [com.arjuna.ats.internal.arjuna.recovery.TransactionStatusManagerItem_5] - TransactionStatusManagerItem host: 127.0.0.1 port: 53,710
2010-08-11 12:46:35,583 [INFO] ~main(arjLoggerI18N): [com.arjuna.ats.arjuna.recovery.TransactionStatusManager_3] - TransactionStatusManager started on port 53710 and host 127.0.0.1 with service com.arjuna.ats.arjuna.recovery.ActionStatusService
2010-08-11 12:46:35,653 [ERROR] ~main(InvocationContextInterceptor): Execution error: 
java.lang.IllegalStateException: Transaction TransactionImple < ac, BasicAction: 0:ffffc0a8c886:d1cf:4c62fe1b:2 status: ActionStatus.COMMITTED > is not in a valid state to be invoking cache operations on.
        at org.infinispan.interceptors.TxInterceptor.enlist(TxInterceptor.java:194)
        at org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:167)
        at org.infinispan.interceptors.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:162)
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58)
        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
        at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:58)
        at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:39)
        at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:87)
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58)
        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
        at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:76)
        at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:87)
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58)
        at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:271)
        at org.infinispan.CacheDelegate.containsKey(CacheDelegate.java:186)
        at org.infinispan.tree.TreeStructureSupport.createNodeInCache(TreeStructureSupport.java:67)
        at org.infinispan.tree.TreeCacheImpl.put(TreeCacheImpl.java:334)
        at com.varolii.infinispantest.App.main(App.java:25)
2010-08-11 12:46:35,654 [ERROR] ~main(App): java.lang.IllegalStateException: Transaction TransactionImple < ac, BasicAction: 0:ffffc0a8c886:d1cf:4c62fe1b:2 status: ActionStatus.COMMITTED > is not in a valid state to be invoking cache operations on.
{code}

Now, if I change to DummyTransactionManagerLookup, I get past the transaction exception, but instead I get the following NPE:

{code}
2010-08-11 12:52:56,262 [INFO] ~main(GlobalComponentRegistry): Infinispan version: Infinispan 'Radegast' 4.1.0.SNAPSHOT
2010-08-11 12:52:56,899 [INFO] ~main(ComponentRegistry): Infinispan version: Infinispan 'Radegast' 4.1.0.SNAPSHOT
2010-08-11 12:52:57,004 [ERROR] ~main(InvocationContextInterceptor): Execution error: 
java.lang.NullPointerException
        at org.infinispan.interceptors.CacheLoaderInterceptor.recordLoadedEntry(CacheLoaderInterceptor.java:182)
        at org.infinispan.interceptors.CacheLoaderInterceptor.loadIfNeeded(CacheLoaderInterceptor.java:147)
        at org.infinispan.interceptors.CacheLoaderInterceptor.loadIfNeededAndUpdateStats(CacheLoaderInterceptor.java:200)
        at org.infinispan.interceptors.CacheLoaderInterceptor.visitGetKeyValueCommand(CacheLoaderInterceptor.java:87)
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58)
        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
        at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
        at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:87)
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58)
        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
        at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:132)
        at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:87)
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58)
        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
        at org.infinispan.interceptors.MarshalledValueInterceptor.visitGetKeyValueCommand(MarshalledValueInterceptor.java:154)
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58)
        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
        at org.infinispan.interceptors.TxInterceptor.enlistReadAndInvokeNext(TxInterceptor.java:171)
        at org.infinispan.interceptors.TxInterceptor.visitGetKeyValueCommand(TxInterceptor.java:162)
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58)
        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
        at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:58)
        at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:39)
        at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:87)
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58)
        at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:118)
        at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:76)
        at org.infinispan.commands.AbstractVisitor.visitGetKeyValueCommand(AbstractVisitor.java:87)
        at org.infinispan.commands.read.GetKeyValueCommand.acceptVisitor(GetKeyValueCommand.java:58)
        at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:271)
        at org.infinispan.CacheDelegate.get(CacheDelegate.java:199)
        at org.infinispan.atomic.AtomicHashMapProxy.getDeltaMapForRead(AtomicHashMapProxy.java:73)
        at org.infinispan.atomic.AtomicHashMapProxy.getDeltaMapForWrite(AtomicHashMapProxy.java:95)
        at org.infinispan.atomic.AtomicHashMapProxy.put(AtomicHashMapProxy.java:154)
        at org.infinispan.tree.TreeCacheImpl.put(TreeCacheImpl.java:336)
        at com.varolii.infinispantest.App.main(App.java:25)
2010-08-11 12:52:57,006 [ERROR] ~main(App): java.lang.NullPointerException
{code}

I'm the process of trying to track down the cause of the above, but it seems that something is still wrong with JTA transaction support.

I'll post back if I'm able to get past this issue and repro my original problems outside the AS.

[tcoates1362]

Found the cause of the NPE. In org.infinispan.interceptors.CacheLoaderInterceptor, in the loadIfNeeded method, the MVCCEntry object returned from entryFactory.wrapEntryForWriting() was null. This was because of a case where the "alreadyLocked" flag was incorrectly set to false. This turned out to be set to false by the following code in the loadIfNeeded method:

{code:java}
boolean keyLocked = entryFactory.acquireLock(ctx, key);
{code}

acquireLock will return false if the lock is already held by this context. I changed the code to this is and it works fine:

{code:java}
entryFactory.acquireLock(ctx, key);
boolean keyLocked = ctx.hasLockedKey(key);
{code}

This still only works with the DummyTransactionManagerLookup. I'm not sure if my earlier problems will repro with the JBossStandaloneJTAManagerLookup once the issue with that is solved. I'm hoping so or else my problems will seem to be related to running in the AS which would be much more complicated.

I'll look into creating unit tests for the two issues I've found and maybe a patch for the solution to the latter.

[tcoates1362]

Manik Surtani wrote:

Hmm, I created a simple test that persists a tree cache with a cache store, even storing attributes in the root node, and it all seems to work fine. 

http://viewvc.jboss.org/cgi-bin/viewvc.cgi/infinispan?view=revision&revision=2195

By the way... I was trying to run this test you created so that I could copy it and modify to test some of the conditions I'm working on, but I keep getting the following:

{code}
C:\Work\Projects\Infinispan\4.1.x\tree>mvn -Dtest=TreeCacheWithLoaderTest test
[INFO] Scanning for projects...
[INFO] ------------------------------------------------------------------------
[INFO] Building Infinispan Tree API
[INFO]    task-segment: [test]
[INFO] ------------------------------------------------------------------------
[INFO] [enforcer:enforce {execution: enforce-java}]
[INFO] [resources:resources {execution: default-resources}]
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] skip non existing resourceDirectory C:\Work\Projects\Infinispan\4.1.x\tree\src\main\resources
[INFO] [compiler:compile {execution: default-compile}]
[INFO] Compiling 1 source file to C:\Work\Projects\Infinispan\4.1.x\tree\target\classes
[INFO] [resources:testResources {execution: default-testResources}]
[INFO] Using 'UTF-8' encoding to copy filtered resources.
[INFO] skip non existing resourceDirectory C:\Work\Projects\Infinispan\4.1.x\tree\src\test\resources
[INFO] [compiler:testCompile {execution: default-testCompile}]
[INFO] Nothing to compile - all classes are up to date
[INFO] [surefire:test {execution: default-test}]
[INFO] Surefire report directory: C:\Work\Projects\Infinispan\4.1.x\tree\target\surefire-reports
-------------------------------------------------------
 T E S T S
-------------------------------------------------------
Running TestSuite
log4j:WARN No appenders could be found for logger (org.infinispan.factories.GlobalComponentRegistry).
log4j:WARN Please initialize the log4j system properly.
log4j:WARN See http://logging.apache.org/log4j/1.2/faq.html#noconfig for more info.
[pool-2-thread-1] Test testPersistence(org.infinispan.loaders.TreeCacheWithLoaderTest) skipped.
Test suite progress: tests succeeded: 0, failed: 0, skipped: 1.
[pool-2-thread-1] Test testRootNodePersistence(org.infinispan.loaders.TreeCacheWithLoaderTest) skipped.
Test suite progress: tests succeeded: 0, failed: 0, skipped: 2.
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
!!!!!! (pool-2-thread-1) Exiting because loaders.TreeCacheWithLoaderTest has NOT shut down all the cache managers it has started !!!!!!!
!!!!!! (pool-2-thread-1) The still-running cacheManager was created here: org.infinispan.loaders.TreeCacheWithLoaderTest.createCacheManager(TreeCacheWithLoaderTest.java:37) !!!!!!!
!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!
{code}

Am I doing something really wrong or is there an issue with the test here?

[manik]

Interesting.  I've run it in the <src_root>/tree directory and I don't get that error.  I'll keep an eye out for the error...

[manik]

Also you can see it run on Hudson here:

http://hudson.infinispan.org/hudson/job/Infinispan-4.1.x-JDK6-tcp/org.infinispan$infinispan-tree/80/testReport/org.infinispan.loaders/

[manik]

I've attached a test that you can add to your src tree.  This is essentially the same as your test app, except that it is written to fit within the test framework. 

You can run it from your IDE or on the command-line.  This will run the test using the DummyTransactionManager:

$ cd tree
$ mvn test -Dtest=SimpleTxTest

And this will run it using JBossTS:

$ cd tree
$ mvn test -Dtest=SimpleTxTest -Dinfinispan.test.jta.tm=jbossts

Either way, I don't see the errors you mentioned... ?

If you run it from your IDE, you can attach a debugger, etc.

[manik]

boolean keyLocked = entryFactory.acquireLock(ctx, key);

acquireLock will return false if the lock is already held by this context. I changed the code to this is and it works fine:

entryFactory.acquireLock(ctx, key);
boolean keyLocked = ctx.hasLockedKey(key);

While this patch does seem logical and correct, I cannot reproduce the failure you mentioned above.  If you can update the test I sent you such that it does deterministically fail, and can demonstrate that the fix you mentioned above does actually solve the problem, that would be great.