Re: [jbosscache-dev] LockParentForChildInsertRemove and PessimisticLocking

Paul and I have been poking through code trying to diagnose the issue that led to this thread for quite a while yesterday. Time to throw it out there and see if anyone hopefully spots something: This is web session replication with buddy replication. The "LockParentForChildInsertRemove" property isn't configured on the cache, so the default "false" should be in effect. A thread trying to execute a remote DataGravitationCleanupCommand on a session node fails upgrading to a write lock on fqn /BUDDY_MANAGER.[1] We can't understand why it would want a WL. Looking at the PessimisticNodeBasedLockManager code, the only reasons I see why a WL would be requested here are: 1) The invocation created the previously non-existent /BUDDY_MANAGER node in order to execute the remove of the great-great-great-great-grandchild. Highly unlikely in general and logging shows another thread successfully doing a put on a different great-great-great-great-grandchild a millisecond earlier. (Also other test runs w/ less verbose logging showed failures getting a WL on fqn / which of course exists). 2) In call to PNBLM.writeLockNeeded(...) currentNode.isLockForChildInsertRemove() is returning "true". Which AFAICT it shouldn't be. [1] The logging from the thread: [JBoss] 20:29:27,488 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-5,10.34.32.154:46064) Executing command: DataGravitationCleanupCommand{fqn=/JSESSION/st_localhost/ wUaU4FhUzWcuiDEjkJzDiQ__, backup=/_BUDDY_BACKUP_/10.34.32.155_41754:DEAD/1/JSESSION/ st_localhost/wUaU4FhUzWcuiDEjkJzDiQ__} [sender=10.34.32.153:24595] [JBoss] 20:29:27,489 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-5,10.34.32.154:46064) This is a non-visitable command - so performing directly and not via the invoker. [JBoss] 20:29:42,497 ERROR [org.jboss.cache.lock.ReadWriteLockWithUpgrade] (Incoming-5,10.34.32.154:46064) upgradeLock(): failed [JBoss] 20:29:42,500 TRACE [org.jboss.cache.marshall.CommandAwareRpcDispatcher] (Incoming-5,10.34.32.154:46064) Problems invoking command. [JBoss] org.jboss.cache.lock.UpgradeException: upgrade lock for /_BUDDY_BACKUP_ could not be acquired after 15000 ms. Lock map ownership Read lock owners: [GlobalTransaction:<10.34.32.153:24595>:70, GlobalTransaction:<10.34.32.153:24595>:69] [JBoss] Write lock owner: null [JBoss] (caller=Thread[Incoming-5,10.34.32.154:46064,5,Thread Pools], lock info: read owners=[GlobalTransaction:<10.34.32.153:24595>:70, GlobalTransaction:<10.34.32.153:24595>:69] (activeReaders=2, activeWriter=null, waitingReaders=1, waitingWriters=0, waitingUpgrader=0)) [JBoss] at org .jboss.cache.lock.IdentityLock.acquireWriteLock0(IdentityLock.java: 227) [JBoss] at org.jboss.cache.lock.IdentityLock.acquireWriteLock(IdentityLock.java: 176) [JBoss] at org.jboss.cache.lock.IdentityLock.acquire(IdentityLock.java:503) [JBoss] at org .jboss .cache .lock .PessimisticNodeBasedLockManager .acquireNodeLock(PessimisticNodeBasedLockManager.java:260) [JBoss] at org .jboss .cache .lock .PessimisticNodeBasedLockManager .lock(PessimisticNodeBasedLockManager.java:169) [JBoss] at org .jboss .cache .lock .PessimisticNodeBasedLockManager .lockPessimistically(PessimisticNodeBasedLockManager.java:97) [JBoss] at org .jboss .cache .interceptors .PessimisticLockInterceptor .handleRemoveNodeCommand(PessimisticLockInterceptor.java:265) [JBoss] at org .jboss .cache .interceptors .base .PrePostProcessingCommandInterceptor .visitRemoveNodeCommand(PrePostProcessingCommandInterceptor.java:126) [JBoss] at org .jboss .cache .commands .write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125) [JBoss] at org .jboss .cache .interceptors .base .CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116) [JBoss] at org .jboss .cache .interceptors .ReplicationInterceptor.handleCrudMethod(ReplicationInterceptor.java: 148) [JBoss] at org .jboss .cache .interceptors .ReplicationInterceptor .visitRemoveNodeCommand(ReplicationInterceptor.java:125) [JBoss] at org .jboss .cache .commands .write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125) [JBoss] at org .jboss .cache .interceptors .base .CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116) [JBoss] at org .jboss .cache .interceptors .base.CommandInterceptor.handleDefault(CommandInterceptor.java:131) [JBoss] at org .jboss .cache .commands .AbstractVisitor.visitRemoveNodeCommand(AbstractVisitor.java:75) [JBoss] at org .jboss .cache .commands .write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125) [JBoss] at org .jboss .cache .interceptors .base .CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116) [JBoss] at org .jboss .cache .interceptors .TxInterceptor.attachGtxAndPassUpChain(TxInterceptor.java:301) [JBoss] at org .jboss .cache.interceptors.TxInterceptor.handleDefault(TxInterceptor.java: 283) [JBoss] at org .jboss .cache .commands .AbstractVisitor.visitRemoveNodeCommand(AbstractVisitor.java:75) [JBoss] at org .jboss .cache .commands .write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125) [JBoss] at org .jboss .cache .interceptors .base .CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116) [JBoss] at org .jboss .cache .interceptors .base.CommandInterceptor.handleDefault(CommandInterceptor.java:131) [JBoss] at org .jboss .cache .commands .AbstractVisitor.visitRemoveNodeCommand(AbstractVisitor.java:75) [JBoss] at org .jboss .cache .commands .write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125) [JBoss] at org .jboss .cache .interceptors .base .CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116) [JBoss] at org .jboss .cache .interceptors .InvocationContextInterceptor .handleAll(InvocationContextInterceptor.java:178) [JBoss] at org .jboss .cache .interceptors .InvocationContextInterceptor .visitRemoveNodeCommand(InvocationContextInterceptor.java:88) [JBoss] at org .jboss .cache .commands .write.RemoveNodeCommand.acceptVisitor(RemoveNodeCommand.java:125) [JBoss] at org .jboss .cache.interceptors.InterceptorChain.invoke(InterceptorChain.java:287) [JBoss] at org .jboss .cache .commands .remote .DataGravitationCleanupCommand .executeRemove(DataGravitationCleanupCommand.java:151) [JBoss] at org .jboss .cache .commands .remote .DataGravitationCleanupCommand .perform(DataGravitationCleanupCommand.java:105) [JBoss] at org .jboss .cache .marshall .CommandAwareRpcDispatcher .executeCommand(CommandAwareRpcDispatcher.java:305) [JBoss] at org .jboss .cache .marshall .CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:242) [JBoss] at org .jgroups .blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:637) [JBoss] at org .jgroups .blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:545) [JBoss] at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java: 368) [JBoss] at org.jgroups.blocks.MessageDispatcher $ProtocolAdapter.up(MessageDispatcher.java:775) [JBoss] at org.jgroups.JChannel.up(JChannel.java:1339) [JBoss] at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:462) [JBoss] at org.jgroups.protocols.pbcast.FLUSH.up(FLUSH.java:432) [JBoss] at org.jgroups.protocols.pbcast.STATE_TRANSFER.up(STATE_TRANSFER.java: 144) [JBoss] at org.jgroups.protocols.FRAG2.up(FRAG2.java:188) [JBoss] at org.jgroups.protocols.FC.up(FC.java:473) [JBoss] at org.jgroups.protocols.pbcast.GMS.up(GMS.java:824) [JBoss] at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:233) [JBoss] at org.jgroups.protocols.UNICAST.handleDataReceived(UNICAST.java:616) [JBoss] at org.jgroups.protocols.UNICAST.up(UNICAST.java:282) [JBoss] at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:758) [JBoss] at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:167) [JBoss] at org.jgroups.protocols.FD.up(FD.java:284) [JBoss] at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:309) [JBoss] at org.jgroups.protocols.MERGE2.up(MERGE2.java:144) [JBoss] at org.jgroups.protocols.Discovery.up(Discovery.java:264) [JBoss] at org.jgroups.protocols.PING.up(PING.java:273) [JBoss] at org.jgroups.protocols.TP$ProtocolAdapter.up(TP.java:2327) [JBoss] at org.jgroups.protocols.TP.passMessageUp(TP.java:1261) [JBoss] at org.jgroups.protocols.TP.access$100(TP.java:49) [JBoss] at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1838) [JBoss] at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1817) [JBoss] at java.util.concurrent.ThreadPoolExecutor $Worker.runTask(ThreadPoolExecutor.java:886) [JBoss] at java.util.concurrent.ThreadPoolExecutor $Worker.run(ThreadPoolExecutor.java:908) [JBoss] at java.lang.Thread.run(Thread.java:619) Manik Surtani wrote: > > On 4 Aug 2009, at 21:28, Brian Stansberry wrote: > >> Continuing dialogue with myself. :) >> >> I've found the logic in PessimisticNodeBasedLockManager where the >> LockParentForChildInsertRemove configuration is meant to be coming >> through via the Node. > > Yes, this is because you can override this on a per-node basis. > >> In our testing we're seeing cases where write >> locks are being acquired on parent nodes, which isn't the intent. >> I'll >> dig further. >> >> Brian Stansberry wrote: >>> https://jira.jboss.org/jira/browse/JBCACHE-1527 >>> >>> Brian Stansberry wrote: >>>> From looking at the JBC 3 code, it seems the >>>> LockParentForChildInsertRemove configuration is no longer >>>> respected for >>>> pessimistic locking. I can't trace any path from the property in >>>> Configuration to code that uses it. >>>> PessimisticLockInterceptor.handlePutCommand, handleMoveCommand and >>>> handleRemoveNodeCommand all always tell the lock manager to lock >>>> parents. handleEvictFqnCommand always tells the lock manager not >>>> to >>>> lock >>>> parents. >>>> >>>> This is causing failures in buddy replication testing when nodes >>>> join/leave clusters under load. There's a lot of data >>>> gravitation plus >>>> stuff like migrating defunct backup trees to "DEAD" regions. Too >>>> much >>>> contention for parent level locks. >>>> >>>> Plus locking on the structural parent to add/remove session >>>> nodes will >>>> suck for the session caching use case. >>>> >>> >>> >> >> >> -- >> Brian Stansberry >> Lead, AS Clustering >> JBoss by Red Hat >> _______________________________________________ >> jbosscache-dev mailing list >> jbosscache-dev(a)lists.jboss.org >> https://lists.jboss.org/mailman/listinfo/jbosscache-dev > > -- > Manik Surtani > manik(a)jboss.org > Lead, Infinispan > Lead, JBoss Cache > http://www.infinispan.org > http://www.jbosscache.org > > > > -- Brian Stansberry Lead, AS Clustering JBoss by Red Hat _______________________________________________ jbosscache-dev mailing list jbosscache-dev(a)lists.jboss.org https://lists.jboss.org/mailman/listinfo/jbosscache-dev