[ https://issues.jboss.org/browse/ISPN-5505?page=com.atlassian.jira.plugin.... ] Galder Zamarreño edited comment on ISPN-5505 at 5/26/15 7:00 AM: ----------------------------------------------------------------- As part of the final fix for ISPN-5477 in https://github.com/infinispan/infinispan/pull/3503, I've reduced the max retries for DistTopologyChangeUnderLoadTest to 1 retry. That should be enough because there's only two servers, so if one fails, it should go to the other one. That's not what's happening in the logs, here's some snippets: {code} 06694 INFO [org.infinispan.test.fwk.UnitTestTestNGListener] (testng-DistTopologyChangeUnderLoadTest:) Starting test testPutsSucceedWhileTopologyChanges(org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest) ... 06736 TRACE [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransportFactory] (testng-DistTopologyChangeUnderLoadTest:) New list: [/127.0.0.1:15267] ... 2015-05-26 09:43:39,929 8418 TRACE [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransportFactory] (ForkThread-1,DistTopologyChangeUnderLoadTest:) New list: [/127.0.0.1:15272, /127.0.0.1:15267] ... 10560 TRACE [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransportFactory] (ForkThread-1,DistTopologyChangeUnderLoadTest:) Using consistent hash for determining the server: /127.0.0.1:15272 ... 10574 TRACE [org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation] (ForkThread-1,DistTopologyChangeUnderLoadTest:) Exception encountered. Retry 0 out of 1 ... 10575 TRACE [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransportFactory] (ForkThread-1,DistTopologyChangeUnderLoadTest:) Using the balancer for determining the server: /127.0.0.1:15272 ... 10577 TRACE [org.infinispan.server.hotrod.HotRodDecoder] (HotRodServerWorker-86-1:) Decoded header HotRodHeader{op=PutRequest, version=22, messageId=1099, cacheName=, flag=6, clientIntelligence=3, topologyId=2} ... 10589 TRACE [org.infinispan.server.hotrod.HotRodEncoder] (HotRodServerWorker-86-1:) Encode msg ErrorResponse{version=22, messageId=1099, operation=ErrorResponse, status=IllegalLifecycleState, msg=org.infinispan.IllegalLifecycleStateException: ISPN000324: Default cache is in 'STOPPING' state and this is an invocation not belonging to an on-going transaction, so it does not accept new invocations. Either restart it or recreate the cache container.} ... 10591 ERROR [org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation] (ForkThread-1,DistTopologyChangeUnderLoadTest:) ISPN004007: Exception encountered. Retry 1 out of 1 ... 10591 ERROR [org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation] (ForkThread-1,DistTopologyChangeUnderLoadTest:) ISPN004007: Exception encountered. Retry 1 out of 1 ... 10722 TRACE [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransportFactory] (testng-DistTopologyChangeUnderLoadTest:) New list: [/127.0.0.1:15267] ... 10723 ERROR [org.infinispan.test.fwk.UnitTestTestNGListener] (testng-DistTopologyChangeUnderLoadTest:) Test testPutsSucceedWhileTopologyChanges(org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest) failed. infinispan.log:539144: at org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest.testPutsSucceedWhileTopologyChanges(DistTopologyChangeUnderLoadTest.java:67) {code} As we see in the snippet, when the client makes a call against the server, it has the updated topology with the two servers (:15272 and :15267). Based on consistent hashing, it chooses :15272, which is fine but it fails, so it then falls back on the load balancer to decide on next server to try, but it chooses again :15272 which is not right. It should have chosen :15267. The reason that's happening is because when the client receives a {{TransportException}}, it updates the {{failedServers}} collection with the failed server's address, but if a {{RemoteNodeSuspectException}} or a {{RemoteIllegalLifecycleStateException}} is received, it does not update this collection. {{RemoteNodeSuspectException}} should probably still not update the failed server collection because this exception is normally related to a different server having been suspected. {{RemoteIllegalLifecycleStateException}} on the other hand can be thrown indicating failure about the node to which the client directed the call, so it should update the failed server collection. was (Author: galder.zamarreno): As part of the final fix for ISPN-5477 in https://github.com/infinispan/infinispan/pull/3503, I've reduced the max retries for DistTopologyChangeUnderLoadTest to 1 retry. That should be enough because there's only two servers, so if one fails, it should go to the other one. That's not what's happening in the logs, here's some snippets: {code} 2015-05-26 09:43:38,205 6694 INFO [org.infinispan.test.fwk.UnitTestTestNGListener] (testng-DistTopologyChangeUnderLoadTest:) Starting test testPutsSucceedWhileTopologyChanges(org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest) ... 2015-05-26 09:43:38,247 6736 TRACE [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransportFactory] (testng-DistTopologyChangeUnderLoadTest:) New list: [/127.0.0.1:15267] ... 2015-05-26 09:43:39,929 8418 TRACE [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransportFactory] (ForkThread-1,DistTopologyChangeUnderLoadTest:) New list: [/127.0.0.1:15272, /127.0.0.1:15267] ... 2015-05-26 09:43:42,071 10560 TRACE [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransportFactory] (ForkThread-1,DistTopologyChangeUnderLoadTest:) Using consistent hash for determining the server: /127.0.0.1:15272 ... 2015-05-26 09:43:42,085 10574 TRACE [org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation] (ForkThread-1,DistTopologyChangeUnderLoadTest:) Exception encountered. Retry 0 out of 1 ... 2015-05-26 09:43:42,086 10575 TRACE [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransportFactory] (ForkThread-1,DistTopologyChangeUnderLoadTest:) Using the balancer for determining the server: /127.0.0.1:15272 ... 2015-05-26 09:43:42,088 10577 TRACE [org.infinispan.server.hotrod.HotRodDecoder] (HotRodServerWorker-86-1:) Decoded header HotRodHeader{op=PutRequest, version=22, messageId=1099, cacheName=, flag=6, clientIntelligence=3, topologyId=2} ... 2015-05-26 09:43:42,100 10589 TRACE [org.infinispan.server.hotrod.HotRodEncoder] (HotRodServerWorker-86-1:) Encode msg ErrorResponse{version=22, messageId=1099, operation=ErrorResponse, status=IllegalLifecycleState, msg=org.infinispan.IllegalLifecycleStateException: ISPN000324: Default cache is in 'STOPPING' state and this is an invocation not belonging to an on-going transaction, so it does not accept new invocations. Either restart it or recreate the cache container.} ... 2015-05-26 09:43:42,102 10591 ERROR [org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation] (ForkThread-1,DistTopologyChangeUnderLoadTest:) ISPN004007: Exception encountered. Retry 1 out of 1 ... 2015-05-26 09:43:42,102 10591 ERROR [org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation] (ForkThread-1,DistTopologyChangeUnderLoadTest:) ISPN004007: Exception encountered. Retry 1 out of 1 ... 2015-05-26 09:43:42,233 10722 TRACE [org.infinispan.client.hotrod.impl.transport.tcp.TcpTransportFactory] (testng-DistTopologyChangeUnderLoadTest:) New list: [/127.0.0.1:15267] ... 2015-05-26 09:43:42,234 10723 ERROR [org.infinispan.test.fwk.UnitTestTestNGListener] (testng-DistTopologyChangeUnderLoadTest:) Test testPutsSucceedWhileTopologyChanges(org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest) failed. infinispan.log:539144: at org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest.testPutsSucceedWhileTopologyChanges(DistTopologyChangeUnderLoadTest.java:67) {code} As we see in the snippet, when the client makes a call against the server, it has the updated topology with the two servers (:15272 and :15267). Based on consistent hashing, it chooses :15272, which is fine but it fails, so it then falls back on the load balancer to decide on next server to try, but it chooses again :15272 which is not right. It should have chosen :15267. The reason that's happening is because when the client receives a {{TransportException}}, it updates the {{failedServers}} collection with the failed server's address, but if a {{RemoteNodeSuspectException}} or a {{RemoteIllegalLifecycleStateException}} is received, it does not update this collection. {{RemoteNodeSuspectException}} should probably still not update the failed server collection because this exception is normally related to a different server having been suspected. {{RemoteIllegalLifecycleStateException}} on the other hand can be thrown indicating failure about the node to which the client directed the call, so it should update the failed server collection. -- This message was sent by Atlassian JIRA (v6.3.15#6346)