[jboss-user] [JBoss Cache: Core Edition] - Re: State transfer errors

fungrim do-not-reply at jboss.com
Thu May 22 06:37:29 EDT 2008


Hum... You'll pardon me for thinking that that listener/latch solution feels a bit like black magic eh? :-)

But if it works I won't beat it.

However, it doesn't seem to work for me. Without transactions we're still failing 15-20% of all runs (I increased repetitions to 5 or 10 to check this) with sequence errors. But perhaps that is to be expected without a transaction?

The transaction test produces aprox. 2.6M of logs. The test does go through, but thats only because the error count is not increased on exceptions, so changing the workers catch clause to... 
} catch(Throwable e) {
  |     log.error("Unexpected error", e);
  |     errorCount.incrementAndGet();
  |    /*
  |     * Roll back transaction, if it exists
  |     */
  |     checkRollbackTransaction(tx);
  | }
... (ie. increasing the error count on unexpected throwables). We fail horribly again. 

Excerpts from the exceptions follows further down.

It does work by manually throttling the access (forcing a 50ms sleep for all workers in the main iterations seems to do it), however that does not really feel like an option for us. 

So, does the test go through without errors for you? And if not, how can we make it work? 

Some exception encountered:

2008-05-22 12:21:10,051 - ERROR - Caught TimeoutException acquiring locks on region /
  | org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/36/36, caller=Thread[AsyncViewChangeHandlerThread,192.168.1.109:7800,5,main], lock=write owner=GlobalTransaction:<192.168.1.109:7800>:140223 (activeReaders=0, activeWriter=Thread[Thread-308,5,main], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
  | 	at org.jboss.cache.lock.IdentityLock.acquire(IdentityLock.java:530)
  | 	at org.jboss.cache.lock.IdentityLock.acquireAll(IdentityLock.java:551)
  | 	at org.jboss.cache.lock.IdentityLock.acquireAll(IdentityLock.java:559)
  | 	at org.jboss.cache.lock.IdentityLock.acquireAll(IdentityLock.java:559)
  | 	at org.jboss.cache.statetransfer.StateTransferManager.acquireLocksForStateTransfer(StateTransferManager.java:244)
  | 	at org.jboss.cache.statetransfer.StateTransferManager.getState(StateTransferManager.java:93)
  | 	at org.jboss.cache.buddyreplication.BuddyManager.generateState(BuddyManager.java:938)
  | 	at org.jboss.cache.buddyreplication.BuddyManager.acquireState(BuddyManager.java:870)
  | 	at org.jboss.cache.buddyreplication.BuddyManager.addBuddies(BuddyManager.java:792)
  | 	at org.jboss.cache.buddyreplication.BuddyManager.reassignBuddies(BuddyManager.java:416)
  | 	at org.jboss.cache.buddyreplication.BuddyManager.access$8(BuddyManager.java:363)
  | 	at org.jboss.cache.buddyreplication.BuddyManager$AsyncViewChangeHandlerThread.handleEnqueuedViewChange(BuddyManager.java:1137)
  | 	at org.jboss.cache.buddyreplication.BuddyManager$AsyncViewChangeHandlerThread.run(BuddyManager.java:1081)
  | 	at java.lang.Thread.run(Thread.java:595)
  | Caused by: org.jboss.cache.lock.TimeoutException: read lock for /36/36 could not be acquired by Thread[AsyncViewChangeHandlerThread,192.168.1.109:7800,5,main] after 400 ms. Locks: Read lock owners: []
  | Write lock owner: GlobalTransaction:<192.168.1.109:7800>:140223
  | , lock info: write owner=GlobalTransaction:<192.168.1.109:7800>:140223 (activeReaders=0, activeWriter=Thread[Thread-308,5,main], waitingReaders=0, waitingWriters=0, waitingUpgrader=0)
  | 	at org.jboss.cache.lock.IdentityLock.acquireReadLock0(IdentityLock.java:328)
  | 	at org.jboss.cache.lock.IdentityLock.acquireReadLock(IdentityLock.java:272)
  | 	at org.jboss.cache.lock.IdentityLock.acquire(IdentityLock.java:495)
  | 	... 13 more

And...
008-05-22 12:21:19,681 - ERROR - prepare method invocation failed
  | org.jboss.cache.lock.TimeoutException: failure acquiring lock: fqn=/_BUDDY_BACKUP_/192.168.1.109_7800, caller=GlobalTransaction:<192.168.1.109:7800>:137593, lock=write owner=GlobalTransaction:<192.168.1.109:7800>:137592 (activeReaders=0, activeWriter=Thread[Incoming,192.168.1.109:7801,5,Thread Pools], waitingReaders=1, waitingWriters=0, waitingUpgrader=0)
  | 	at org.jboss.cache.lock.IdentityLock.acquire(IdentityLock.java:530)
  | 	at org.jboss.cache.lock.LockManager.acquireNodeLock(LockManager.java:235)
  | 	at org.jboss.cache.lock.LockManager.lock(LockManager.java:143)
  | 	at org.jboss.cache.lock.LockManager.acquireLocksWithTimeout(LockManager.java:71)
  | 	at org.jboss.cache.interceptors.PessimisticLockInterceptor.handlePutCommand(PessimisticLockInterceptor.java:112)
  | 	at org.jboss.cache.interceptors.PessimisticLockInterceptor.handlePutKeyValueCommand(PessimisticLockInterceptor.java:89)
  | 	at org.jboss.cache.interceptors.base.PostProcessingCommandInterceptor.visitPutKeyValueCommand(PostProcessingCommandInterceptor.java:63)
  | 	at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:99)
  | 	at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:142)
  | 	at org.jboss.cache.interceptors.ReplicationInterceptor.handleCrudMethod(ReplicationInterceptor.java:124)
  | 	at org.jboss.cache.interceptors.ReplicationInterceptor.visitPutKeyValueCommand(ReplicationInterceptor.java:81)
  | 	at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:99)
  | 	at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:142)
  | 	at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:157)
  | 	at org.jboss.cache.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:29)
  | 	at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:99)
  | 	at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:142)
  | 	at org.jboss.cache.interceptors.TxInterceptor$ModificationsReplayVisitor.handleDefault(TxInterceptor.java:640)
  | 	at org.jboss.cache.interceptors.TxInterceptor$ModificationsReplayVisitor.handleDataVersionCommand(TxInterceptor.java:677)
  | 	at org.jboss.cache.interceptors.TxInterceptor$ModificationsReplayVisitor.visitPutKeyValueCommand(TxInterceptor.java:654)
  | 	at org.jboss.cache.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:99)
  | 	at org.jboss.cache.commands.AbstractVisitor.visitCollection(AbstractVisitor.java:147)
  | 	at org.jboss.cache.interceptors.TxInterceptor.handlePessimisticPrepare(TxInterceptor.java:546)
  | 	at org.jboss.cache.interceptors.TxInterceptor.handleRemotePrepare(TxInterceptor.java:376)
  | 	at org.jboss.cache.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:115)
  | 	at org.jboss.cache.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:39)
  | 	at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:142)
  | 	at org.jboss.cache.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:157)
  | 	at org.jboss.cache.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:99)
  | 	at org.jboss.cache.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:39)
  | 	at org.jboss.cache.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:142)
  | 	at org.jboss.cache.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:144)
  | 	at org.jboss.cache.interceptors.InvocationContextInterceptor.visitPrepareCommand(InvocationContextInterceptor.java:77)
  | 	at org.jboss.cache.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:39)
  | 	at org.jboss.cache.interceptors.InterceptorChain.invokeRemote(InterceptorChain.java:266)
  | 	at org.jboss.cache.commands.remote.ReplicateCommand.processSingleCommand(ReplicateCommand.java:116)
  | 	at org.jboss.cache.commands.remote.ReplicateCommand.perform(ReplicateCommand.java:92)
  | 	at org.jboss.cache.marshall.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:173)
  | 	at org.jboss.cache.marshall.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:133)
  | 	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:746)
  | 	at org.jgroups.JChannel.up(JChannel.java:1154)
  | 	at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:402)
  | 	at org.jgroups.protocols.pbcast.FLUSH.up(FLUSH.java:370)
  | 	at org.jgroups.protocols.pbcast.STREAMING_STATE_TRANSFER.up(STREAMING_STATE_TRANSFER.java:242)
  | 	at org.jgroups.protocols.FRAG2.up(FRAG2.java:205)
  | 	at org.jgroups.protocols.FC.up(FC.java:408)
  | 	at org.jgroups.protocols.pbcast.GMS.up(GMS.java:780)
  | 	at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:234)
  | 	at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:729)
  | 	at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:167)
  | 	at org.jgroups.protocols.FD.up(FD.java:285)
  | 	at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:300)
  | 	at org.jgroups.protocols.MERGE2.up(MERGE2.java:145)
  | 	at org.jgroups.protocols.Discovery.up(Discovery.java:245)
  | 	at org.jgroups.protocols.MPING.up(MPING.java:218)
  | 	at org.jgroups.protocols.TP.passMessageUp(TP.java:1126)
  | 	at org.jgroups.protocols.TP.access$100(TP.java:48)
  | 	at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1637)
  | 	at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1611)
  | 	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: read lock for /_BUDDY_BACKUP_/192.168.1.109_7800 could not be acquired by GlobalTransaction:<192.168.1.109:7800>:137593 after 10000 ms. Locks: Read lock owners: []
  | Write lock owner: GlobalTransaction:<192.168.1.109:7800>:137592
  | , lock info: write owner=GlobalTransaction:<192.168.1.109:7800>:137592 (activeReaders=0, activeWriter=Thread[Incoming,192.168.1.109:7801,5,Thread Pools], waitingReaders=1, waitingWriters=0, waitingUpgrader=0)
  | 	at org.jboss.cache.lock.IdentityLock.acquireReadLock0(IdentityLock.java:328)
  | 	at org.jboss.cache.lock.IdentityLock.acquireReadLock(IdentityLock.java:272)
  | 	at org.jboss.cache.lock.IdentityLock.acquire(IdentityLock.java:495)
  | 	... 64 more

Etc...

Cheers /Lars

View the original post : http://www.jboss.com/index.html?module=bb&op=viewtopic&p=4152618#4152618

Reply to the post : http://www.jboss.com/index.html?module=bb&op=posting&mode=reply&p=4152618



More information about the jboss-user mailing list