I have also seen this behaviour in our application. Buddy replication does not seem to work under concurrent load and/or usage.
Just from starting up (no load applied) I get this in the logs:
2007-10-23 14:25:52,664 Incoming Thread,TableSpace,172.16.0.5:7500 ERROR jboss.cache.interceptors.TxInterceptor - method invocation failed
org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/5, caller=GlobalTransaction:<172.16.0.7:7500>:1, lock=write owner=GlobalTransaction:<172.16.0.6:7500>:2 (activeReaders=0, activeWriter=Thread[Incoming Thread,TableSpace,
172.16.0.5:7500,5,Incoming], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
at org.jboss.cache.lock.IdentityLock.acquire(IdentityLock.java:528)
at org.jboss.cache.interceptors.PessimisticLockInterceptor$LockManager.acquire(PessimisticLockInterceptor.java:579)
at org.jboss.cache.interceptors.PessimisticLockInterceptor.acquireNodeLock(PessimisticLockInterceptor.java:393)
at org.jboss.cache.interceptors.PessimisticLockInterceptor.lock(PessimisticLockInterceptor.java:329)
at org.jboss.cache.interceptors.PessimisticLockInterceptor.invoke(PessimisticLockInterceptor.java:187)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:76)
at org.jboss.cache.interceptors.ReplicationInterceptor.invoke(ReplicationInterceptor.java:34)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:76)
at org.jboss.cache.interceptors.NotificationInterceptor.invoke(NotificationInterceptor.java:32)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:76)
at org.jboss.cache.interceptors.TxInterceptor.handleNonTxMethod(TxInterceptor.java:298)
at org.jboss.cache.interceptors.TxInterceptor.invoke(TxInterceptor.java:131)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:76)
at org.jboss.cache.interceptors.CacheMgmtInterceptor.invoke(CacheMgmtInterceptor.java:123)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:76)
at org.jboss.cache.interceptors.InvocationContextInterceptor.invoke(InvocationContextInterceptor.java:62)
at org.jboss.cache.CacheImpl.invokeMethod(CacheImpl.java:3939)
at org.jboss.cache.CacheImpl._dataGravitationCleanup(CacheImpl.java:3055)
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:585)
at org.jgroups.blocks.MethodCall.invoke(MethodCall.java:330)
at org.jboss.cache.interceptors.CallInterceptor.invoke(CallInterceptor.java:49)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:76)
at org.jboss.cache.interceptors.DataGravitatorInterceptor.invoke(DataGravitatorInterceptor.java:167)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:76)
at org.jboss.cache.interceptors.UnlockInterceptor.invoke(UnlockInterceptor.java:37)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:76)
at org.jboss.cache.interceptors.PessimisticLockInterceptor.invoke(PessimisticLockInterceptor.java:203)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:76)
at org.jboss.cache.interceptors.ReplicationInterceptor.invoke(ReplicationInterceptor.java:34)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:76)
at org.jboss.cache.interceptors.NotificationInterceptor.invoke(NotificationInterceptor.java:32)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:76)
at org.jboss.cache.interceptors.TxInterceptor.replayModifications(TxInterceptor.java:511)
at org.jboss.cache.interceptors.TxInterceptor.handlePessimisticPrepare(TxInterceptor.java:394)
at org.jboss.cache.interceptors.TxInterceptor.handleRemotePrepare(TxInterceptor.java:254)
at org.jboss.cache.interceptors.TxInterceptor.invoke(TxInterceptor.java:100)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:76)
at org.jboss.cache.interceptors.CacheMgmtInterceptor.invoke(CacheMgmtInterceptor.java:123)
at org.jboss.cache.interceptors.Interceptor.invoke(Interceptor.java:76)
at org.jboss.cache.interceptors.InvocationContextInterceptor.invoke(InvocationContextInterceptor.java:62)
at org.jboss.cache.CacheImpl.invokeMethod(CacheImpl.java:3939)
at org.jboss.cache.CacheImpl._replicate(CacheImpl.java:2853)
at sun.reflect.GeneratedMethodAccessor31.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:585)
at org.jgroups.blocks.MethodCall.invoke(MethodCall.java:330)
at org.jboss.cache.marshall.InactiveRegionAwareRpcDispatcher.handle(InactiveRegionAwareRpcDispatcher.java:77)
at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:624)
at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:533)
at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:365)
at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:736)
at org.jgroups.JChannel.up(JChannel.java:1063)
at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:325)
at org.jgroups.protocols.pbcast.FLUSH.up(FLUSH.java:406)
at org.jgroups.protocols.pbcast.STREAMING_STATE_TRANSFER.up(STREAMING_STATE_TRANSFER.java:255)
at org.jgroups.protocols.FRAG2.up(FRAG2.java:197)
at org.jgroups.protocols.pbcast.GMS.up(GMS.java:722)
at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:234)
at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:596)
at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:167)
at org.jgroups.protocols.FD.up(FD.java:322)
at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:298)
at org.jgroups.protocols.MERGE2.up(MERGE2.java:145)
at org.jgroups.protocols.Discovery.up(Discovery.java:220)
at org.jgroups.protocols.MPING.up(MPING.java:218)
at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1486)
at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1435)
at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:650)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:675)
at java.lang.Thread.run(Thread.java:595)
Caused by: org.jboss.cache.lock.TimeoutException: write lock for /5 could not be acquired after 5000 ms. Locks: Read lock owners: []
Write lock owner: GlobalTransaction:<172.16.0.6:7500>:2
(caller=GlobalTransaction:<172.16.0.7:7500>:1, lock info: write owner=GlobalTransaction:<172.16.0.6:7500>:2 (activeReaders=0, activeWriter=Thread[Incoming Thread,TableSpace,172.16.0.5:7500,5,Incoming], waitingReaders=0, waitingWriters=0
, waitingUpgrader=0))
at org.jboss.cache.lock.IdentityLock.acquireWriteLock0(IdentityLock.java:244)
at org.jboss.cache.lock.IdentityLock.acquireWriteLock(IdentityLock.java:167)
at org.jboss.cache.lock.IdentityLock.acquire(IdentityLock.java:497)
... 72 more
Which is related to datagravition cleanup. We need horizontal scalability while running multiple nodes, and without buddy replication it is not really possible. I will try to apply 2.1.0 BETA1 and see if things are better. I assume that it will be for testpurposes only since we do not want to rely on a beta release for a soon-to-be production system. =)