Details
-
Bug
-
Resolution: Won't Do
-
Major
-
None
-
7.1.0.CR2
Description
We saw this error on server during failover scenario ejb-ejbremote-shutdown-dist-sync-tcpStack (1 occurence).
Shortly after cluster-wide rebalance finished and before new cluster view was received the org.infinispan.util.concurrent.TimeoutException was logged.
Server log stacktrace:
15:35:14,326 ERROR [org.jboss.as.ejb3.invocation] (default task-26) WFLYEJB0034: EJB Invocation failed on component RemoteStatefulSBImpl for method public abstract int org.jboss.test.clusterbench.common.ejb.CommonStatefulSB.getSerialAndIncrement(): javax.ejb.EJBException: org.infinispan.util.concurrent.TimeoutException: Replication timeout [JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.handleExceptionInOurTx(CMTTxInterceptor.java:188) [JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.invokeInOurTx(CMTTxInterceptor.java:277) [JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.required(CMTTxInterceptor.java:332) [JBossINF] at org.jboss.as.ejb3.tx.CMTTxInterceptor.processInvocation(CMTTxInterceptor.java:240) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.invocation.InterceptorContext$Invocation.proceed(InterceptorContext.java:509) [JBossINF] at org.jboss.weld.ejb.AbstractEJBRequestScopeActivationInterceptor.aroundInvoke(AbstractEJBRequestScopeActivationInterceptor.java:73) [JBossINF] at org.jboss.as.weld.ejb.EjbRequestScopeActivationInterceptor.processInvocation(EjbRequestScopeActivationInterceptor.java:89) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.as.ejb3.remote.EJBRemoteTransactionPropagatingInterceptor.processInvocation(EJBRemoteTransactionPropagatingInterceptor.java:89) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.as.ejb3.component.interceptors.CurrentInvocationContextInterceptor.processInvocation(CurrentInvocationContextInterceptor.java:41) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.as.ejb3.component.invocationmetrics.WaitTimeInterceptor.processInvocation(WaitTimeInterceptor.java:47) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.as.ejb3.security.SecurityContextInterceptor.processInvocation(SecurityContextInterceptor.java:100) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.as.ejb3.deployment.processors.StartupAwaitInterceptor.processInvocation(StartupAwaitInterceptor.java:22) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.as.ejb3.component.interceptors.ShutDownInterceptorFactory$1.processInvocation(ShutDownInterceptorFactory.java:64) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.as.ejb3.deployment.processors.EjbSuspendInterceptor.processInvocation(EjbSuspendInterceptor.java:57) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.as.ejb3.component.interceptors.LoggingInterceptor.processInvocation(LoggingInterceptor.java:67) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.as.ee.component.NamespaceContextInterceptor.processInvocation(NamespaceContextInterceptor.java:50) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.as.ejb3.component.interceptors.AdditionalSetupInterceptor.processInvocation(AdditionalSetupInterceptor.java:54) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.invocation.ContextClassLoaderInterceptor.processInvocation(ContextClassLoaderInterceptor.java:60) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.invocation.InterceptorContext.run(InterceptorContext.java:438) [JBossINF] at org.wildfly.security.manager.WildFlySecurityManager.doChecked(WildFlySecurityManager.java:609) [JBossINF] at org.jboss.invocation.AccessCheckingInterceptor.processInvocation(AccessCheckingInterceptor.java:57) [JBossINF] at org.jboss.invocation.InterceptorContext.proceed(InterceptorContext.java:422) [JBossINF] at org.jboss.invocation.ChainedInterceptor.processInvocation(ChainedInterceptor.java:53) [JBossINF] at org.jboss.as.ee.component.ViewService$View.invoke(ViewService.java:198) [JBossINF] at org.wildfly.security.auth.server.SecurityIdentity.runAsFunctionEx(SecurityIdentity.java:380) [JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.invokeWithIdentity(AssociationImpl.java:524) [JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.invokeMethod(AssociationImpl.java:519) [JBossINF] at org.jboss.as.ejb3.remote.AssociationImpl.lambda$receiveInvocationRequest$0(AssociationImpl.java:193) [JBossINF] at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) [JBossINF] at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) [JBossINF] at java.lang.Thread.run(Thread.java:748) [JBossINF] Caused by: org.infinispan.util.concurrent.TimeoutException: Replication timeout [JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.lambda$invokeRemotelyAsync$1(JGroupsTransport.java:639) [JBossINF] at java.util.concurrent.CompletableFuture.uniApply(CompletableFuture.java:602) [JBossINF] at java.util.concurrent.CompletableFuture$UniApply.tryFire(CompletableFuture.java:577) [JBossINF] at java.util.concurrent.CompletableFuture.postComplete(CompletableFuture.java:474) [JBossINF] at java.util.concurrent.CompletableFuture.complete(CompletableFuture.java:1962) [JBossINF] at org.infinispan.remoting.transport.jgroups.RspListFuture.call(RspListFuture.java:61) [JBossINF] at org.infinispan.remoting.transport.jgroups.RspListFuture.call(RspListFuture.java:16) [JBossINF] at java.util.concurrent.FutureTask.run(FutureTask.java:266) [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [JBossINF] at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [JBossINF] ... 3 more [JBossINF] Suppressed: org.infinispan.remoting.RpcException: Not accepted: SuccessfulResponse{responseValue=true} [JBossINF] at org.infinispan.remoting.transport.jgroups.JGroupsTransport.addSuppressedExceptions(JGroupsTransport.java:694) [JBossINF] ... 13 more [JBossINF] [JBossINF] �15:36:13,285 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (thread-2) ISPN000094: Received new cluster view for channel server: [perf21|5] (4) [perf21, perf20, perf19, perf18] [JBossINF] �15:36:13,286 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (thread-2) ISPN000094: Received new cluster view for channel web: [perf21|5] (4) [perf21, perf20, perf19, perf18] [JBossINF] �15:36:13,287 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (thread-2) ISPN000094: Received new cluster view for channel hibernate: [perf21|5] (4) [perf21, perf20, perf19, perf18] [JBossINF] �15:36:13,287 INFO [org.infinispan.remoting.transport.jgroups.JGroupsTransport] (thread-2) ISPN000094: Received new cluster view for channel ejb: [perf21|5] (4) [perf21, perf20, perf19, perf18]
Client was also affected, there was an error logged at the same time:
2017/09/20 15:35:14:432 EDT [ERROR][Runner - 315] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error getting response. <javax.ejb.EJBException: org.infinispan.util.concurrent.TimeoutException: Replication timeout>
followed by two WARN messages:
2017/09/20 15:35:14:432 EDT [WARN ][Runner - 315] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Error sampling data: <org.jboss.smartfrog.loaddriver.RequestProcessingException: Could not get valid response. Runner: 315.>
2017/09/20 15:35:14:432 EDT [WARN ][Runner - 315] SFCORE_LOG - Error sampling data: <org.jboss.smartfrog.loaddriver.RequestProcessingException: Could not get valid response. Runner: 315.>
org.jboss.smartfrog.loaddriver.RequestProcessingException: Could not get valid response. Runner: 315.
at org.jboss.smartfrog.clustering.ejb3.StatefulSBProcessorFactoryImpl$EJB3RequestProcessor.processRequest(StatefulSBProcessorFactoryImpl.java:113)
at org.jboss.smartfrog.loaddriver.CompoundRequestProcessorFactoryImpl$CompoundRequestProcessor.processRequest(CompoundRequestProcessorFactoryImpl.java:52)
at org.jboss.smartfrog.loaddriver.Runner.run(Runner.java:108)
at java.lang.Thread.run(Thread.java:748)
Caused by: javax.ejb.EJBException: org.infinispan.util.concurrent.TimeoutException: Replication timeout
at org.jboss.as.ejb3.remote.AssociationImpl.lambda$receiveInvocationRequest$0(AssociationImpl.java:218)
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
... 1 more
One of the nodes (perf18) was shutdown shortly before:
2017/09/20 15:35:01:680 EDT [INFO ][TestController] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Node 0 (perf18) is down. 2017/09/20 15:35:01:681 EDT [INFO ][TestController] HOST perf17.mw.lab.eng.bos.redhat.com:rootProcess:c - Cluster state: [DOWN, UP, UP, UP].
Link to server log:
http://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-ejb-ejbremote-shutdown-dist-sync-tcpStack/28/console-perf21/
Link to client log:
http://jenkins.hosts.mwqe.eng.bos.redhat.com/hudson/job/perflab_eap-7x-failover-ejb-ejbremote-shutdown-dist-sync-tcpStack/28/console-perf17/