Uploaded image for project: 'Application Server 7'
  1. Application Server 7
  2. AS7-3827

NotSerializableException, StateTransferInProgressException, TimeoutException while other node in the cluster crashed

    XMLWordPrintable

Details

    • Bug
    • Resolution: Done
    • Major
    • 7.1.1.Final
    • 7.1.0.Final
    • Clustering

    Description

      One more very vague bug report, but something definitely looks wrong.

      This set of 3 exceptions (first 2 repeatedly) could be seen while servers in the cluster crash and are brought up again (while there are requests from EJB3 remote client) when using replicated SYNC cache.

      The cluster has 1 minute in between membership changes (which is not very graceful but shows how cluster can deal with state transfer )

      NotSerializableException seems very suspicious though.

      [JBossINF] 10:24:21,545 ERROR [org.infinispan.interceptors.InvocationContextInterceptor] (OOB-17,null) ISPN000136: Execution error: org.infinispan.statetransfer.StateTransferInProgressException: Timed out waiting for the state transfer lock, state transfer in progress for view 6
[JBossINF] 	at org.infinispan.interceptors.StateTransferLockInterceptor.signalStateTransferInProgress(StateTransferLockInterceptor.java:199) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.interceptors.StateTransferLockInterceptor.visitPrepareCommand(StateTransferLockInterceptor.java:80) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:131) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:113) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:131) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:130) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:89) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:113) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:131) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:130) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:113) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:131) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:116) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.interceptors.BatchingInterceptor.handleDefault(BatchingInterceptor.java:70) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.commands.AbstractVisitor.visitPrepareCommand(AbstractVisitor.java:113) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.commands.tx.PrepareCommand.acceptVisitor(PrepareCommand.java:131) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:345) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.commands.tx.PrepareCommand.perform(PrepareCommand.java:127) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:127) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithWaitForBlocks(InboundInvocationHandlerImpl.java:136) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.remoting.InboundInvocationHandlerImpl.handleWithRetry(InboundInvocationHandlerImpl.java:162) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.remoting.InboundInvocationHandlerImpl.handle(InboundInvocationHandlerImpl.java:114) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.executeCommand(CommandAwareRpcDispatcher.java:161) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.handle(CommandAwareRpcDispatcher.java:141) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.jgroups.blocks.RequestCorrelator.handleRequest(RequestCorrelator.java:447) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.blocks.RequestCorrelator.receiveMessage(RequestCorrelator.java:354) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.blocks.RequestCorrelator.receive(RequestCorrelator.java:230) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.blocks.MessageDispatcher$ProtocolAdapter.up(MessageDispatcher.java:543) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jboss.as.clustering.jgroups.ClassLoaderAwareUpHandler.up(ClassLoaderAwareUpHandler.java:56) [jboss-as-clustering-jgroups-7.1.1.Final-SNAPSHOT.jar:7.1.1.Final-SNAPSHOT]
[JBossINF] 	at org.jgroups.blocks.mux.MuxUpHandler.up(MuxUpHandler.java:130) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jboss.as.clustering.jgroups.MuxChannel$ClassLoaderAwareMuxUpHandler.up(MuxChannel.java:64) [jboss-as-clustering-jgroups-7.1.1.Final-SNAPSHOT.jar:7.1.1.Final-SNAPSHOT]
[JBossINF] 	at org.jgroups.JChannel.up(JChannel.java:716) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.stack.ProtocolStack.up(ProtocolStack.java:1026) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.FRAG2.up(FRAG2.java:181) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.FlowControl.up(FlowControl.java:418) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.pbcast.GMS.up(GMS.java:881) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.pbcast.STABLE.up(STABLE.java:244) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.UNICAST2.up(UNICAST2.java:383) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.pbcast.NAKACK.handleMessage(NAKACK.java:697) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.pbcast.NAKACK.up(NAKACK.java:559) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.BARRIER.up(BARRIER.java:126) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.VERIFY_SUSPECT.up(VERIFY_SUSPECT.java:140) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.FD.up(FD.java:273) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.FD_SOCK.up(FD_SOCK.java:282) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.MERGE2.up(MERGE2.java:205) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.Discovery.up(Discovery.java:354) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.stack.Protocol.up(Protocol.java:358) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.TP.passMessageUp(TP.java:1174) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.TP$IncomingPacket.handleMyMessage(TP.java:1709) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.protocols.TP$IncomingPacket.run(TP.java:1691) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_30]
[JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_30]
[JBossINF] 	at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]

      Error recovering views from the cluster members

      ...
[JBossINF] 10:24:24,735 ERROR [org.infinispan.cacheviews.CacheViewsManagerImpl] (CacheViewTrigger,perf21/web) Error recovering views from the cluster members: java.util.concurrent.ExecutionException: org.infinispan.CacheException: java.util.concurrent.ExecutionException: org.infinispan.marshall.NotSerializableException: org.infinispan.remoting.responses.ExceptionResponse
[JBossINF] 	at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:222) [rt.jar:1.6.0_30]
[JBossINF] 	at java.util.concurrent.FutureTask.get(FutureTask.java:83) [rt.jar:1.6.0_30]
[JBossINF] 	at org.infinispan.cacheviews.CacheViewsManagerImpl.recoverViews(CacheViewsManagerImpl.java:672) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.cacheviews.CacheViewsManagerImpl.access$500(CacheViewsManagerImpl.java:95) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.cacheviews.CacheViewsManagerImpl$ViewTriggerThread.run(CacheViewsManagerImpl.java:812) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] Caused by: org.infinispan.CacheException: java.util.concurrent.ExecutionException: org.infinispan.marshall.NotSerializableException: org.infinispan.remoting.responses.ExceptionResponse
[JBossINF] 	at org.infinispan.util.Util.rewrapAsCacheException(Util.java:524) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.invokeRemoteCommands(CommandAwareRpcDispatcher.java:115) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.remoting.transport.jgroups.JGroupsTransport.invokeRemotely(JGroupsTransport.java:447) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.cacheviews.CacheViewsManagerImpl$4.call(CacheViewsManagerImpl.java:663) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.cacheviews.CacheViewsManagerImpl$4.call(CacheViewsManagerImpl.java:660) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [rt.jar:1.6.0_30]
[JBossINF] 	at java.util.concurrent.FutureTask.run(FutureTask.java:138) [rt.jar:1.6.0_30]
[JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_30]
[JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_30]
[JBossINF] 	at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]
[JBossINF] Caused by: java.util.concurrent.ExecutionException: org.infinispan.marshall.NotSerializableException: org.infinispan.remoting.responses.ExceptionResponse
[JBossINF] 	at org.jgroups.blocks.UnicastRequest.getValue(UnicastRequest.java:165) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.jgroups.blocks.UnicastRequest.get(UnicastRequest.java:191) [jgroups-3.0.4.Final.jar:3.0.4.Final]
[JBossINF] 	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher$ReplicationTask.call(CommandAwareRpcDispatcher.java:269) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.remoting.transport.jgroups.CommandAwareRpcDispatcher.invokeRemoteCommands(CommandAwareRpcDispatcher.java:111) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	... 8 more
[JBossINF] Caused by: org.infinispan.marshall.NotSerializableException: org.infinispan.remoting.responses.ExceptionResponse
[JBossINF] Caused by: an exception which occurred:
[JBossINF] 	in object org.infinispan.remoting.responses.ExceptionResponse@58e39f23

      [JBossINF] 10:24:24,849 INFO  [org.jboss.as.clustering.impl.CoreGroupCommunicationService.lifecycle.web] (Incoming-11,null) JBAS010247: New cluster view for partition web (id: 7, delta: -1, merge: false) : [perf21/web, perf20/web]
[JBossINF] 10:24:24,851 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-11,null) ISPN000094: Received new cluster view: [perf21/web|7] [perf21/web, perf20/web]
[JBossINF] 10:25:22,987 INFO  [org.jboss.as.clustering.impl.CoreGroupCommunicationService.lifecycle.web] (Incoming-13,null) JBAS010247: New cluster view for partition web (id: 8, delta: 1, merge: false) : [perf21/web, perf20/web, perf19/web]
[JBossINF] 10:25:22,987 INFO  [org.jboss.as.clustering.impl.CoreGroupCommunicationService.lifecycle.ejb] (Incoming-14,null) JBAS010247: New cluster view for partition ejb (id: 8, delta: 1, merge: false) : [perf21/ejb, perf20/ejb, perf19/ejb]
[JBossINF] 10:25:22,988 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-13,null) ISPN000094: Received new cluster view: [perf21/web|8] [perf21/web, perf20/web, perf19/web]
[JBossINF] 10:25:22,989 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-14,null) ISPN000094: Received new cluster view: [perf21/ejb|8] [perf21/ejb, perf20/ejb, perf19/ejb]
[JBossINF] 10:26:22,401 INFO  [org.jboss.as.clustering.impl.CoreGroupCommunicationService.lifecycle.web] (Incoming-4,null) JBAS010247: New cluster view for partition web (id: 9, delta: -1, merge: false) : [perf21/web, perf20/web]
[JBossINF] 10:26:22,402 INFO  [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (Incoming-4,null) ISPN000094: Received new cluster view: [perf21/web|9] [perf21/web, perf20/web]
[JBossINF] 10:26:23,554 ERROR [org.infinispan.cacheviews.CacheViewsManagerImpl] (CacheViewInstaller-6,perf21/ejb) ISPN000172: Failed to prepare view CacheView{viewId=11, members=[perf21/ejb, perf20/ejb, perf19/ejb]} for cache  org.jboss.test.clusterbench.ejb.stateful.RemoteStatefulSBImpl, rolling back to view CacheView{viewId=10, members=[perf21/ejb, perf20/ejb]}: java.util.concurrent.TimeoutException
[JBossINF] 	at java.util.concurrent.FutureTask$Sync.innerGet(FutureTask.java:228) [rt.jar:1.6.0_30]
[JBossINF] 	at java.util.concurrent.FutureTask.get(FutureTask.java:91) [rt.jar:1.6.0_30]
[JBossINF] 	at org.infinispan.cacheviews.CacheViewsManagerImpl.clusterPrepareView(CacheViewsManagerImpl.java:319) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.cacheviews.CacheViewsManagerImpl.clusterInstallView(CacheViewsManagerImpl.java:250) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at org.infinispan.cacheviews.CacheViewsManagerImpl$ViewInstallationTask.call(CacheViewsManagerImpl.java:876) [infinispan-core-5.1.1.FINAL.jar:5.1.1.FINAL]
[JBossINF] 	at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303) [rt.jar:1.6.0_30]
[JBossINF] 	at java.util.concurrent.FutureTask.run(FutureTask.java:138) [rt.jar:1.6.0_30]
[JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) [rt.jar:1.6.0_30]
[JBossINF] 	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) [rt.jar:1.6.0_30]
[JBossINF] 	at java.lang.Thread.run(Thread.java:662) [rt.jar:1.6.0_30]

      Attachments

        Issue Links

          is blocked by

          Bug - A problem that impairs or prevents the functions of the product. ISPN-1885 RPCs can arrive before CommandAwareRpcDispatcher sets its request/response marshaller

          • Critical - To be worked on immediately following BLOCKER issues.
          • Closed

          Component Upgrade - A task tracking an update to a bundled component or revision of component upstream of the project. AS7-3907 Upgrade Infinispan to 5.1.2.FINAL

          • Critical - To be worked on immediately following BLOCKER issues.
          • Closed

          Activity

            People

              pferraro@redhat.com Paul Ferraro
              rhn-engineering-rhusar Radoslav Husar
              Votes:
              0 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

                Created:
                Updated:
                Resolved: