Application Server 7
  1. Application Server 7
  2. AS7-5144

Occurrence of "Exception acquiring ownership of X" when invalidating session with SSO enabled

    Details

    • Type: Bug Bug
    • Status: Resolved Resolved (View Workflow)
    • Priority: Major Major
    • Resolution: Done
    • Affects Version/s: 7.1.1.Final
    • Fix Version/s: 7.1.3.Final (EAP)
    • Component/s: Clustering
    • Labels:
      None
    • Environment:
      cluster of two nodes, with SSO enabled in the JBoss web configuration
    • Similar Issues:
      Show 10 results 

      Description

      When SSO is enabled, if a session is created on node A and fails over to node B, invalidating the session on B results in exceptions being raised on both hosts:

      On host B:

      20:31:51,869 ERROR [org.infinispan.interceptors.InvocationContextInterceptor.handleAll:146] (OOB-19,null) ISPN000136: Execution error: org.infinispan.CacheException: Caught exception [java.lang.RuntimeException] while invoking method [public void org.jboss.as.clustering.web.sso.infinispan.SSOClusterManager.cacheEntryRemoved(org.infinispan.notifications.cachelistener.event.CacheEntryRemovedEvent)] on listener instance: org.jboss.as.clustering.web.sso.infinispan.SSOClusterManager@6aea206b
      	at org.infinispan.notifications.AbstractListenerImpl$ListenerInvocation$1.run(AbstractListenerImpl.java:205)
      	at org.infinispan.util.concurrent.WithinThreadExecutor.execute(WithinThreadExecutor.java:42)
      	at org.infinispan.notifications.AbstractListenerImpl$ListenerInvocation.invoke(AbstractListenerImpl.java:221)
      	at org.infinispan.notifications.cachelistener.CacheNotifierImpl.notifyCacheEntryRemoved(CacheNotifierImpl.java:174)
      	at org.infinispan.commands.write.RemoveCommand.notify(RemoveCommand.java:116)
      	at org.infinispan.commands.write.RemoveCommand.perform(RemoveCommand.java:110)
      	at org.infinispan.interceptors.CallInterceptor.handleDefault(CallInterceptor.java:83)
      	at org.infinispan.commands.AbstractVisitor.visitRemoveCommand(AbstractVisitor.java:67)
      	at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:72)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.ReplicationInterceptor.handleCrudMethod(ReplicationInterceptor.java:178)
      	at org.infinispan.interceptors.ReplicationInterceptor.visitRemoveCommand(ReplicationInterceptor.java:159)
      	at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:72)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.EntryWrappingInterceptor$EntryWrappingVisitor.visitRemoveCommand(EntryWrappingInterceptor.java:252)
      	at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:72)
      	at org.infinispan.interceptors.EntryWrappingInterceptor.visitPrepareCommand(EntryWrappingInterceptor.java:90)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.invokeNextAndCommitIf1Pc(AbstractTxLockingInterceptor.java:120)
      	at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:132)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
      	at org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
      	at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
      	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
      	at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
      	at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
      	at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
      	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
      	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
      	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
      	at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
      	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
      	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
      	at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.RSVP.up(RSVP.java:192) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.FlowControl.up(FlowControl.java:400) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:759) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:365) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:602) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.BARRIER.up(BARRIER.java:102) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.MERGE2.up(MERGE2.java:205) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.Discovery.up(Discovery.java:359) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.stack.Protocol.up(Protocol.java:363) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.TP.passMessageUp(TP.java:1180) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710) [jgroups-3.0.9.Final.jar:3.0.9.Final]
      	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_32]
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_32]
      	at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_32]
      Caused by: java.lang.RuntimeException: JBAS018060: Exception acquiring ownership of WVTF3FKSXBEPCWykLKqcIwqa
      	at org.jboss.as.web.session.ClusteredSession.acquireSessionOwnership(ClusteredSession.java:532)
      	at org.jboss.as.web.session.ClusteredSession.expire(ClusteredSession.java:1273)
      	at org.jboss.as.web.session.ClusteredSession.expire(ClusteredSession.java:646)
      	at org.jboss.as.web.sso.ClusteredSingleSignOn.deregister(ClusteredSingleSignOn.java:489)
      	at org.jboss.as.clustering.web.sso.infinispan.SSOClusterManager.cacheEntryRemoved(SSOClusterManager.java:249)
      	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.6.0_32]
      	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [rt.jar:1.6.0_32]
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_32]
      	at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_32]
      	at org.infinispan.notifications.AbstractListenerImpl$ListenerInvocation$1.run(AbstractListenerImpl.java:200)
      	... 81 more
      Caused by: org.jboss.as.clustering.lock.TimeoutException: JBAS010213: Cannot acquire lock default-host/my-servlet-invalidation/WVTF3FKSXBEPCWykLKqcIwqa from cluster
      	at org.jboss.as.clustering.lock.SharedLocalYieldingClusterLockManager.lock(SharedLocalYieldingClusterLockManager.java:439)
      	at org.jboss.as.clustering.web.infinispan.DistributedCacheManager.acquireSessionOwnership(DistributedCacheManager.java:386)
      	at org.jboss.as.web.session.ClusteredSession.acquireSessionOwnership(ClusteredSession.java:524)
      	... 90 more
      
      

      On host A:

      20:31:51,905 ERROR [org.infinispan.interceptors.InvocationContextInterceptor.handleAll:146] (ajp-/192.168.0.102:8009-3) ISPN000136: Execution error: org.infinispan.CacheException: Caught exception [java.lang.RuntimeException] while invoking method [public void org.jboss.as.clustering.web.sso.infinispan.SSOClusterManager.cacheEntryRemoved(org.infinispan.notifications.cachelistener.event.CacheEntryRemovedEvent)] on listener instance: org.jboss.as.clustering.web.sso.infinispan.SSOClusterManager@6aea206b
      	at org.infinispan.notifications.AbstractListenerImpl$ListenerInvocation$1.run(AbstractListenerImpl.java:205)
      	at org.infinispan.util.concurrent.WithinThreadExecutor.execute(WithinThreadExecutor.java:42)
      	at org.infinispan.notifications.AbstractListenerImpl$ListenerInvocation.invoke(AbstractListenerImpl.java:221)
      	at org.infinispan.notifications.cachelistener.CacheNotifierImpl.notifyCacheEntryRemoved(CacheNotifierImpl.java:174)
      	at org.infinispan.commands.write.RemoveCommand.notify(RemoveCommand.java:116)
      	at org.infinispan.commands.write.RemoveCommand.perform(RemoveCommand.java:110)
      	at org.infinispan.interceptors.CallInterceptor.handleDefault(CallInterceptor.java:83)
      	at org.infinispan.commands.AbstractVisitor.visitRemoveCommand(AbstractVisitor.java:67)
      	at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:72)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.ReplicationInterceptor.handleCrudMethod(ReplicationInterceptor.java:178)
      	at org.infinispan.interceptors.ReplicationInterceptor.visitRemoveCommand(ReplicationInterceptor.java:159)
      	at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:72)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.EntryWrappingInterceptor$EntryWrappingVisitor.visitRemoveCommand(EntryWrappingInterceptor.java:252)
      	at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:72)
      	at org.infinispan.interceptors.EntryWrappingInterceptor.visitPrepareCommand(EntryWrappingInterceptor.java:90)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.invokeNextAndCommitIf1Pc(AbstractTxLockingInterceptor.java:120)
      	at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:132)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
      	at org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
      	at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
      	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
      	at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
      	at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
      	at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
      	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
      	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
      	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
      	at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
      	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
      	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
      	at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
      	at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
      	at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
      	at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
      	at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
      	at org.jgroups.JChannel.up(JChannel.java:716)
      	at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
      	at org.jgroups.protocols.RSVP.up(RSVP.java:192)
      	at org.jgroups.protocols.FRAG2.up(FRAG2.java:181)
      	at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
      	at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
      	at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
      	at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
      	at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:759)
      	at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:365)
      	at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:602)
      	at org.jgroups.protocols.BARRIER.up(BARRIER.java:102)
      	at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
      	at org.jgroups.protocols.FD.up(FD.java:273)
      	at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
      	at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
      	at org.jgroups.protocols.Discovery.up(Discovery.java:359)
      	at org.jgroups.stack.Protocol.up(Protocol.java:363)
      	at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
      	at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
      	at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_32]
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_32]
      	at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_32]
      Caused by: java.lang.RuntimeException: JBAS018060: Exception acquiring ownership of WVTF3FKSXBEPCWykLKqcIwqa
      	at org.jboss.as.web.session.ClusteredSession.acquireSessionOwnership(ClusteredSession.java:532) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.session.ClusteredSession.expire(ClusteredSession.java:1273) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.session.ClusteredSession.expire(ClusteredSession.java:646) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.sso.ClusteredSingleSignOn.deregister(ClusteredSingleSignOn.java:489) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.clustering.web.sso.infinispan.SSOClusterManager.cacheEntryRemoved(SSOClusterManager.java:249)
      	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.6.0_32]
      	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [rt.jar:1.6.0_32]
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_32]
      	at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_32]
      	at org.infinispan.notifications.AbstractListenerImpl$ListenerInvocation$1.run(AbstractListenerImpl.java:200)
      	... 81 more
      Caused by: org.jboss.as.clustering.lock.TimeoutException: JBAS010213: Cannot acquire lock default-host/my-servlet-invalidation/WVTF3FKSXBEPCWykLKqcIwqa from cluster
      	at org.jboss.as.clustering.lock.SharedLocalYieldingClusterLockManager.lock(SharedLocalYieldingClusterLockManager.java:439)
      	at org.jboss.as.clustering.web.infinispan.DistributedCacheManager.acquireSessionOwnership(DistributedCacheManager.java:386)
      	at org.jboss.as.web.session.ClusteredSession.acquireSessionOwnership(ClusteredSession.java:524) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	... 90 more
      
      20:31:51,920 ERROR [org.infinispan.transaction.TransactionCoordinator.prepare:154] (ajp-/192.168.0.102:8009-3) Error while processing prepare: org.infinispan.CacheException: Caught exception [java.lang.RuntimeException] while invoking method [public void org.jboss.as.clustering.web.sso.infinispan.SSOClusterManager.cacheEntryRemoved(org.infinispan.notifications.cachelistener.event.CacheEntryRemovedEvent)] on listener instance: org.jboss.as.clustering.web.sso.infinispan.SSOClusterManager@6aea206b
      	at org.infinispan.notifications.AbstractListenerImpl$ListenerInvocation$1.run(AbstractListenerImpl.java:205)
      	at org.infinispan.util.concurrent.WithinThreadExecutor.execute(WithinThreadExecutor.java:42)
      	at org.infinispan.notifications.AbstractListenerImpl$ListenerInvocation.invoke(AbstractListenerImpl.java:221)
      	at org.infinispan.notifications.cachelistener.CacheNotifierImpl.notifyCacheEntryRemoved(CacheNotifierImpl.java:174)
      	at org.infinispan.commands.write.RemoveCommand.notify(RemoveCommand.java:116)
      	at org.infinispan.commands.write.RemoveCommand.perform(RemoveCommand.java:110)
      	at org.infinispan.interceptors.CallInterceptor.handleDefault(CallInterceptor.java:83)
      	at org.infinispan.commands.AbstractVisitor.visitRemoveCommand(AbstractVisitor.java:67)
      	at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:72)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.ReplicationInterceptor.handleCrudMethod(ReplicationInterceptor.java:178)
      	at org.infinispan.interceptors.ReplicationInterceptor.visitRemoveCommand(ReplicationInterceptor.java:159)
      	at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:72)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.EntryWrappingInterceptor$EntryWrappingVisitor.visitRemoveCommand(EntryWrappingInterceptor.java:252)
      	at org.infinispan.commands.write.RemoveCommand.acceptVisitor(RemoveCommand.java:72)
      	at org.infinispan.interceptors.EntryWrappingInterceptor.visitPrepareCommand(EntryWrappingInterceptor.java:90)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.locking.AbstractTxLockingInterceptor.invokeNextAndCommitIf1Pc(AbstractTxLockingInterceptor.java:120)
      	at org.infinispan.interceptors.locking.OptimisticLockingInterceptor.visitPrepareCommand(OptimisticLockingInterceptor.java:132)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.NotificationInterceptor.visitPrepareCommand(NotificationInterceptor.java:58)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.TxInterceptor.visitPrepareCommand(TxInterceptor.java:106)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.StateTransferLockInterceptor.handleWithRetries(StateTransferLockInterceptor.java:213)
      	at org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:85)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130)
      	at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:131)
      	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:90)
      	at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116)
      	at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70)
      	at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:126)
      	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:133)
      	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345)
      	at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:128)
      	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127)
      	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136)
      	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162)
      	at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114)
      	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:221)
      	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:201)
      	at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:456)
      	at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:363)
      	at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:238)
      	at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543)
      	at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130)
      	at org.jgroups.JChannel.up(JChannel.java:716)
      	at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026)
      	at org.jgroups.protocols.RSVP.up(RSVP.java:192)
      	at org.jgroups.protocols.FRAG2.up(FRAG2.java:181)
      	at org.jgroups.protocols.FlowControl.up(FlowControl.java:418)
      	at org.jgroups.protocols.FlowControl.up(FlowControl.java:400)
      	at org.jgroups.protocols.pbcast.GMS.up(GMS.java:889)
      	at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244)
      	at org.jgroups.protocols.UNICAST2.handleDataReceived(UNICAST2.java:759)
      	at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:365)
      	at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:602)
      	at org.jgroups.protocols.BARRIER.up(BARRIER.java:102)
      	at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:143)
      	at org.jgroups.protocols.FD.up(FD.java:273)
      	at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:288)
      	at org.jgroups.protocols.MERGE2.up(MERGE2.java:205)
      	at org.jgroups.protocols.Discovery.up(Discovery.java:359)
      	at org.jgroups.stack.Protocol.up(Protocol.java:363)
      	at org.jgroups.protocols.TP.passMessageUp(TP.java:1180)
      	at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1728)
      	at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1710)
      	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_32]
      	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_32]
      	at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_32]
      Caused by: java.lang.RuntimeException: JBAS018060: Exception acquiring ownership of WVTF3FKSXBEPCWykLKqcIwqa
      	at org.jboss.as.web.session.ClusteredSession.acquireSessionOwnership(ClusteredSession.java:532) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.session.ClusteredSession.expire(ClusteredSession.java:1273) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.session.ClusteredSession.expire(ClusteredSession.java:646) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.sso.ClusteredSingleSignOn.deregister(ClusteredSingleSignOn.java:489) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.clustering.web.sso.infinispan.SSOClusterManager.cacheEntryRemoved(SSOClusterManager.java:249)
      	at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) [rt.jar:1.6.0_32]
      	at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39) [rt.jar:1.6.0_32]
      	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25) [rt.jar:1.6.0_32]
      	at java.lang.reflect.Method.invoke(Method.java:597) [rt.jar:1.6.0_32]
      	at org.infinispan.notifications.AbstractListenerImpl$ListenerInvocation$1.run(AbstractListenerImpl.java:200)
      	... 81 more
      Caused by: org.jboss.as.clustering.lock.TimeoutException: JBAS010213: Cannot acquire lock default-host/my-servlet-invalidation/WVTF3FKSXBEPCWykLKqcIwqa from cluster
      	at org.jboss.as.clustering.lock.SharedLocalYieldingClusterLockManager.lock(SharedLocalYieldingClusterLockManager.java:439)
      	at org.jboss.as.clustering.web.infinispan.DistributedCacheManager.acquireSessionOwnership(DistributedCacheManager.java:386)
      	at org.jboss.as.web.session.ClusteredSession.acquireSessionOwnership(ClusteredSession.java:524) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	... 90 more
      
      20:31:51,930 ERROR [org.infinispan.transaction.tm.DummyTransaction.notifyBeforeCompletion:233] (ajp-/192.168.0.102:8009-3) ISPN000109: beforeCompletion() failed for SynchronizationAdapter{localTransaction=LocalTransaction{remoteLockedNodes=null, isMarkedForRollback=false, transaction=DummyTransaction{xid=DummyXid{id=5}, status=1}, lockedKeys=null, backupKeyLocks=null, viewId=1} org.infinispan.transaction.synchronization.SyncLocalTransaction@5} org.infinispan.transaction.synchronization.SynchronizationAdapter@24: org.infinispan.CacheException: Could not prepare. 
      	at org.infinispan.transaction.synchronization.SynchronizationAdapter.beforeCompletion(SynchronizationAdapter.java:70)
      	at org.infinispan.transaction.tm.DummyTransaction.notifyBeforeCompletion(DummyTransaction.java:230)
      	at org.infinispan.transaction.tm.DummyTransaction.runPrepare(DummyTransaction.java:241)
      	at org.infinispan.transaction.tm.DummyTransaction.commit(DummyTransaction.java:86)
      	at org.infinispan.transaction.tm.DummyBaseTransactionManager.commit(DummyBaseTransactionManager.java:102)
      	at org.infinispan.batch.BatchContainer.resolveTransaction(BatchContainer.java:123)
      	at org.infinispan.batch.BatchContainer.endBatch(BatchContainer.java:105)
      	at org.infinispan.batch.BatchContainer.endBatch(BatchContainer.java:86)
      	at org.infinispan.CacheImpl.endBatch(CacheImpl.java:615)
      	at org.infinispan.AbstractDelegatingCache.endBatch(AbstractDelegatingCache.java:80)
      	at org.jboss.as.clustering.infinispan.invoker.BatchOperation.invoke(BatchOperation.java:26)
      	at org.jboss.as.clustering.web.sso.infinispan.SSOClusterManager.batch(SSOClusterManager.java:359)
      	at org.jboss.as.clustering.web.sso.infinispan.SSOClusterManager.logout(SSOClusterManager.java:155)
      	at org.jboss.as.web.sso.ClusteredSingleSignOn.logout(ClusteredSingleSignOn.java:506) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.sso.ClusteredSingleSignOn.sessionEvent(ClusteredSingleSignOn.java:274) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.session.ClusteredSession.fireSessionEvent(ClusteredSession.java:1775) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.session.ClusteredSession.expire(ClusteredSession.java:1322) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.session.ClusteredSession.invalidate(ClusteredSession.java:633) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.apache.catalina.session.StandardSessionFacade.invalidate(StandardSessionFacade.java:150) [jbossweb-7.0.16.Final.jar:]
      	at mypackage.InvalidationServlet.doGet(InvalidationServlet.java:49) [classes:]
      	at javax.servlet.http.HttpServlet.service(HttpServlet.java:734) [jboss-servlet-api_3.0_spec-1.0.1.Final.jar:1.0.1.Final]
      	at javax.servlet.http.HttpServlet.service(HttpServlet.java:847) [jboss-servlet-api_3.0_spec-1.0.1.Final.jar:1.0.1.Final]
      	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:329) [jbossweb-7.0.16.Final.jar:]
      	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:248) [jbossweb-7.0.16.Final.jar:]
      	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:275) [jbossweb-7.0.16.Final.jar:]
      	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:161) [jbossweb-7.0.16.Final.jar:]
      	at org.jboss.modcluster.container.jbossweb.JBossWebContext$RequestListenerValve.event(JBossWebContext.java:67)
      	at org.jboss.modcluster.container.jbossweb.JBossWebContext$RequestListenerValve.invoke(JBossWebContext.java:48)
      	at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:489) [jbossweb-7.0.16.Final.jar:]
      	at org.jboss.as.web.session.ClusteredSessionValve.handleRequest(ClusteredSessionValve.java:133) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.session.ClusteredSessionValve.invoke(ClusteredSessionValve.java:94) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.session.JvmRouteValve.invoke(JvmRouteValve.java:92) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.session.LockingValve.invoke(LockingValve.java:64) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.jboss.as.web.security.SecurityContextAssociationValve.invoke(SecurityContextAssociationValve.java:153) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:155) [jbossweb-7.0.16.Final.jar:]
      	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:102) [jbossweb-7.0.16.Final.jar:]
      	at org.jboss.as.web.sso.ClusteredSingleSignOn.invoke(ClusteredSingleSignOn.java:379) [jboss-as-web-7.1.2.Final.jar:7.1.2.Final]
      	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109) [jbossweb-7.0.16.Final.jar:]
      	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:368) [jbossweb-7.0.16.Final.jar:]
      	at org.apache.coyote.ajp.AjpProcessor.process(AjpProcessor.java:505) [jbossweb-7.0.16.Final.jar:]
      	at org.apache.coyote.ajp.AjpProtocol$AjpConnectionHandler.process(AjpProtocol.java:452) [jbossweb-7.0.16.Final.jar:]
      	at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:931) [jbossweb-7.0.16.Final.jar:]
      	at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_32]
      Caused by: javax.transaction.xa.XAException
      	at org.infinispan.transaction.TransactionCoordinator.prepare(TransactionCoordinator.java:160)
      	at org.infinispan.transaction.TransactionCoordinator.prepare(TransactionCoordinator.java:122)
      	at org.infinispan.transaction.synchronization.SynchronizationAdapter.beforeCompletion(SynchronizationAdapter.java:68)
      	... 42 more
      
      

        Issue Links

          Activity

          Hide
          Richard Achmatowicz
          added a comment - - edited

          The problem here seems to be an incorrect use of expire when de-registering an SingleSignOnEntry.

          When a session contained in a SingleSignOnEntry is invalidated on host B, the ClusteredSingleSignOn valve gets a callback (it is an HTTPSessionListener) and initiates logout processing for that SingleSignOnEntry. Logout processing involves de-registering the SingleSignOnEntry and expiring all contained sessions. The de-registration action is propagated to node A and performed there as well via a callback to deregister from SSOClusterManager.

          The problem seems to be that SingleSignOnEntry.deregister(id) always calls the cluster-wide version of ClusteredSession.expire(), whether it is called directly on a local node or via callback on a remote node. This means that the remote node will attempt a cluster-wide expiration of the session, for the second time and before the first expire has completed.

          Show
          Richard Achmatowicz
          added a comment - - edited The problem here seems to be an incorrect use of expire when de-registering an SingleSignOnEntry. When a session contained in a SingleSignOnEntry is invalidated on host B, the ClusteredSingleSignOn valve gets a callback (it is an HTTPSessionListener) and initiates logout processing for that SingleSignOnEntry. Logout processing involves de-registering the SingleSignOnEntry and expiring all contained sessions. The de-registration action is propagated to node A and performed there as well via a callback to deregister from SSOClusterManager. The problem seems to be that SingleSignOnEntry.deregister(id) always calls the cluster-wide version of ClusteredSession.expire(), whether it is called directly on a local node or via callback on a remote node. This means that the remote node will attempt a cluster-wide expiration of the session, for the second time and before the first expire has completed.
          Hide
          Richard Achmatowicz
          added a comment -

          Introduced a new method SingleSignOnEntry.deregisterLocal(String ssoId) which calls the non-clusterwide version of expire and changed the callback in SSOClusterManager to use this instead.

          Show
          Richard Achmatowicz
          added a comment - Introduced a new method SingleSignOnEntry.deregisterLocal(String ssoId) which calls the non-clusterwide version of expire and changed the callback in SSOClusterManager to use this instead.

            People

            • Assignee:
              Richard Achmatowicz
              Reporter:
              Richard Achmatowicz
            • Votes:
              0 Vote for this issue
              Watchers:
              1 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved: