Radoslav Husar created AS7-3827: ----------------------------------- Summary: NotSerializableException, StateTransferInProgressException, TimeoutException while other node in the cluster crashed Key: AS7-3827 URL: https://issues.jboss.org/browse/AS7-3827 Project: Application Server 7 Issue Type: Bug Components: Clustering Affects Versions: 7.1.0.Final Reporter: Radoslav Husar Assignee: Paul Ferraro Fix For: 7.1.1.Final 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. {noformat} [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] {noformat} Error recovering views from the cluster members {noformat} ... [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 {noformat} {noformat} [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] {noformat} -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators: https://issues.jboss.org/secure/ContactAdministrators!default.jspa For more information on JIRA, see: http://www.atlassian.com/software/jira