[JBoss JIRA] (ISPN-5505) DistTopologyChangeUnderLoadTest randomly fails with IllegalLifecycleStateException
by Galder Zamarreño (JIRA)
[ 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.
> DistTopologyChangeUnderLoadTest randomly fails with IllegalLifecycleStateException
> ----------------------------------------------------------------------------------
>
> Key: ISPN-5505
> URL: https://issues.jboss.org/browse/ISPN-5505
> Project: Infinispan
> Issue Type: Bug
> Components: Remote Protocols
> Affects Versions: 7.2.1.Final, 8.0.0.Alpha1
> Reporter: Galder Zamarreño
> Assignee: Galder Zamarreño
> Labels: testsuite_stability
> Fix For: 8.0.0.Alpha2
>
>
> {code}
> testPutsSucceedWhileTopologyChanges(org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest) Time elapsed: 0.334 sec <<< FAILURE!
> java.util.concurrent.ExecutionException: org.infinispan.client.hotrod.exceptions.RemoteIllegalLifecycleStateException:Request for message id[1099] returned server error (status=0x88): 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.
> at java.util.concurrent.FutureTask.report(FutureTask.java:122)
> at java.util.concurrent.FutureTask.get(FutureTask.java:192)
> at org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest.testPutsSucceedWhileTopologyChanges(DistTopologyChangeUnderLoadTest.java:67)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84)
> at org.testng.internal.Invoker.invokeMethod(Invoker.java:714)
> at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
> at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
> at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
> at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
> at org.testng.TestRunner.privateRun(TestRunner.java:767)
> at org.testng.TestRunner.run(TestRunner.java:617)
> at org.testng.SuiteRunner.runTest(SuiteRunner.java:348)
> at org.testng.SuiteRunner.access$000(SuiteRunner.java:38)
> at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:382)
> at org.testng.internal.thread.ThreadUtil$2.call(ThreadUtil.java:64)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: org.infinispan.client.hotrod.exceptions.RemoteIllegalLifecycleStateException:Request for message id[1099] returned server error (status=0x88): 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.
> at org.infinispan.client.hotrod.impl.protocol.Codec20.checkForErrorsInResponseStatus(Codec20.java:340)
> at org.infinispan.client.hotrod.impl.protocol.Codec20.readPartialHeader(Codec20.java:126)
> at org.infinispan.client.hotrod.impl.protocol.Codec20.readHeader(Codec20.java:112)
> at org.infinispan.client.hotrod.impl.operations.HotRodOperation.readHeaderAndValidate(HotRodOperation.java:56)
> at org.infinispan.client.hotrod.impl.operations.AbstractKeyValueOperation.sendPutOperation(AbstractKeyValueOperation.java:57)
> at org.infinispan.client.hotrod.impl.operations.PutOperation.executeOperation(PutOperation.java:31)
> at org.infinispan.client.hotrod.impl.operations.PutOperation.executeOperation(PutOperation.java:20)
> at org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation.execute(RetryOnFailureOperation.java:52)
> at org.infinispan.client.hotrod.impl.RemoteCacheImpl.put(RemoteCacheImpl.java:247)
> at org.infinispan.client.hotrod.impl.RemoteCacheSupport.put(RemoteCacheSupport.java:79)
> at org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest$PutHammer.call(DistTopologyChangeUnderLoadTest.java:80)
> at org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest$PutHammer.call(DistTopologyChangeUnderLoadTest.java:72)
> at org.infinispan.test.AbstractInfinispanTest$LoggingCallable.call(AbstractInfinispanTest.java:435)
> ... 4 more
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
8 years, 11 months
[JBoss JIRA] (ISPN-5505) DistTopologyChangeUnderLoadTest randomly fails with IllegalLifecycleStateException
by Galder Zamarreño (JIRA)
[ 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]
...
08418 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}
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.
> DistTopologyChangeUnderLoadTest randomly fails with IllegalLifecycleStateException
> ----------------------------------------------------------------------------------
>
> Key: ISPN-5505
> URL: https://issues.jboss.org/browse/ISPN-5505
> Project: Infinispan
> Issue Type: Bug
> Components: Remote Protocols
> Affects Versions: 7.2.1.Final, 8.0.0.Alpha1
> Reporter: Galder Zamarreño
> Assignee: Galder Zamarreño
> Labels: testsuite_stability
> Fix For: 8.0.0.Alpha2
>
>
> {code}
> testPutsSucceedWhileTopologyChanges(org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest) Time elapsed: 0.334 sec <<< FAILURE!
> java.util.concurrent.ExecutionException: org.infinispan.client.hotrod.exceptions.RemoteIllegalLifecycleStateException:Request for message id[1099] returned server error (status=0x88): 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.
> at java.util.concurrent.FutureTask.report(FutureTask.java:122)
> at java.util.concurrent.FutureTask.get(FutureTask.java:192)
> at org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest.testPutsSucceedWhileTopologyChanges(DistTopologyChangeUnderLoadTest.java:67)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84)
> at org.testng.internal.Invoker.invokeMethod(Invoker.java:714)
> at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
> at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
> at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
> at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
> at org.testng.TestRunner.privateRun(TestRunner.java:767)
> at org.testng.TestRunner.run(TestRunner.java:617)
> at org.testng.SuiteRunner.runTest(SuiteRunner.java:348)
> at org.testng.SuiteRunner.access$000(SuiteRunner.java:38)
> at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:382)
> at org.testng.internal.thread.ThreadUtil$2.call(ThreadUtil.java:64)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: org.infinispan.client.hotrod.exceptions.RemoteIllegalLifecycleStateException:Request for message id[1099] returned server error (status=0x88): 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.
> at org.infinispan.client.hotrod.impl.protocol.Codec20.checkForErrorsInResponseStatus(Codec20.java:340)
> at org.infinispan.client.hotrod.impl.protocol.Codec20.readPartialHeader(Codec20.java:126)
> at org.infinispan.client.hotrod.impl.protocol.Codec20.readHeader(Codec20.java:112)
> at org.infinispan.client.hotrod.impl.operations.HotRodOperation.readHeaderAndValidate(HotRodOperation.java:56)
> at org.infinispan.client.hotrod.impl.operations.AbstractKeyValueOperation.sendPutOperation(AbstractKeyValueOperation.java:57)
> at org.infinispan.client.hotrod.impl.operations.PutOperation.executeOperation(PutOperation.java:31)
> at org.infinispan.client.hotrod.impl.operations.PutOperation.executeOperation(PutOperation.java:20)
> at org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation.execute(RetryOnFailureOperation.java:52)
> at org.infinispan.client.hotrod.impl.RemoteCacheImpl.put(RemoteCacheImpl.java:247)
> at org.infinispan.client.hotrod.impl.RemoteCacheSupport.put(RemoteCacheSupport.java:79)
> at org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest$PutHammer.call(DistTopologyChangeUnderLoadTest.java:80)
> at org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest$PutHammer.call(DistTopologyChangeUnderLoadTest.java:72)
> at org.infinispan.test.AbstractInfinispanTest$LoggingCallable.call(AbstractInfinispanTest.java:435)
> ... 4 more
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
8 years, 11 months
[JBoss JIRA] (ISPN-5505) DistTopologyChangeUnderLoadTest randomly fails with IllegalLifecycleStateException
by Galder Zamarreño (JIRA)
[ https://issues.jboss.org/browse/ISPN-5505?page=com.atlassian.jira.plugin.... ]
Galder Zamarreño commented on ISPN-5505:
----------------------------------------
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.
> DistTopologyChangeUnderLoadTest randomly fails with IllegalLifecycleStateException
> ----------------------------------------------------------------------------------
>
> Key: ISPN-5505
> URL: https://issues.jboss.org/browse/ISPN-5505
> Project: Infinispan
> Issue Type: Bug
> Components: Remote Protocols
> Affects Versions: 7.2.1.Final, 8.0.0.Alpha1
> Reporter: Galder Zamarreño
> Assignee: Galder Zamarreño
> Labels: testsuite_stability
> Fix For: 8.0.0.Alpha2
>
>
> {code}
> testPutsSucceedWhileTopologyChanges(org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest) Time elapsed: 0.334 sec <<< FAILURE!
> java.util.concurrent.ExecutionException: org.infinispan.client.hotrod.exceptions.RemoteIllegalLifecycleStateException:Request for message id[1099] returned server error (status=0x88): 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.
> at java.util.concurrent.FutureTask.report(FutureTask.java:122)
> at java.util.concurrent.FutureTask.get(FutureTask.java:192)
> at org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest.testPutsSucceedWhileTopologyChanges(DistTopologyChangeUnderLoadTest.java:67)
> at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
> at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
> at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:497)
> at org.testng.internal.MethodInvocationHelper.invokeMethod(MethodInvocationHelper.java:84)
> at org.testng.internal.Invoker.invokeMethod(Invoker.java:714)
> at org.testng.internal.Invoker.invokeTestMethod(Invoker.java:901)
> at org.testng.internal.Invoker.invokeTestMethods(Invoker.java:1231)
> at org.testng.internal.TestMethodWorker.invokeTestMethods(TestMethodWorker.java:127)
> at org.testng.internal.TestMethodWorker.run(TestMethodWorker.java:111)
> at org.testng.TestRunner.privateRun(TestRunner.java:767)
> at org.testng.TestRunner.run(TestRunner.java:617)
> at org.testng.SuiteRunner.runTest(SuiteRunner.java:348)
> at org.testng.SuiteRunner.access$000(SuiteRunner.java:38)
> at org.testng.SuiteRunner$SuiteWorker.run(SuiteRunner.java:382)
> at org.testng.internal.thread.ThreadUtil$2.call(ThreadUtil.java:64)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
> at java.lang.Thread.run(Thread.java:745)
> Caused by: org.infinispan.client.hotrod.exceptions.RemoteIllegalLifecycleStateException:Request for message id[1099] returned server error (status=0x88): 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.
> at org.infinispan.client.hotrod.impl.protocol.Codec20.checkForErrorsInResponseStatus(Codec20.java:340)
> at org.infinispan.client.hotrod.impl.protocol.Codec20.readPartialHeader(Codec20.java:126)
> at org.infinispan.client.hotrod.impl.protocol.Codec20.readHeader(Codec20.java:112)
> at org.infinispan.client.hotrod.impl.operations.HotRodOperation.readHeaderAndValidate(HotRodOperation.java:56)
> at org.infinispan.client.hotrod.impl.operations.AbstractKeyValueOperation.sendPutOperation(AbstractKeyValueOperation.java:57)
> at org.infinispan.client.hotrod.impl.operations.PutOperation.executeOperation(PutOperation.java:31)
> at org.infinispan.client.hotrod.impl.operations.PutOperation.executeOperation(PutOperation.java:20)
> at org.infinispan.client.hotrod.impl.operations.RetryOnFailureOperation.execute(RetryOnFailureOperation.java:52)
> at org.infinispan.client.hotrod.impl.RemoteCacheImpl.put(RemoteCacheImpl.java:247)
> at org.infinispan.client.hotrod.impl.RemoteCacheSupport.put(RemoteCacheSupport.java:79)
> at org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest$PutHammer.call(DistTopologyChangeUnderLoadTest.java:80)
> at org.infinispan.client.hotrod.DistTopologyChangeUnderLoadTest$PutHammer.call(DistTopologyChangeUnderLoadTest.java:72)
> at org.infinispan.test.AbstractInfinispanTest$LoggingCallable.call(AbstractInfinispanTest.java:435)
> ... 4 more
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
8 years, 11 months
[JBoss JIRA] (ISPN-5477) Compatibility with L1 can lead to wrong return type
by Dan Berindei (JIRA)
[ https://issues.jboss.org/browse/ISPN-5477?page=com.atlassian.jira.plugin.... ]
Dan Berindei updated ISPN-5477:
-------------------------------
Status: Pull Request Sent (was: Reopened)
> Compatibility with L1 can lead to wrong return type
> ---------------------------------------------------
>
> Key: ISPN-5477
> URL: https://issues.jboss.org/browse/ISPN-5477
> Project: Infinispan
> Issue Type: Bug
> Components: Remote Protocols
> Affects Versions: 7.2.1.Final
> Reporter: Galder Zamarreño
> Assignee: Galder Zamarreño
> Fix For: 7.2.2.Final
>
>
> Currently, when using compatibility mode with distributed caches, it is possible for users to store keys using embedded API which hash differently to when the same key is access via remote API. This is due to the differences in source data. For embedded, the source object is the POJO, whereas for remote, the source object is the byte[] format of the pojo.
> When using such keys, remote APIs might go to a node which is not owner, leading to a remote get. When two gets are executed, the first of which results in L1 entry being added to the container, the second get result in exceptions such as this on the client:
> {code}
> java.lang.ClassCastException: [B cannot be cast to xxx....
> {code}
> This is due to over eager unboxing by the BaseTypeConverterInterceptor. I discovered this while investigating ISPN-5449.
> It would be ideal to not have scenarios where there are diverging keys but for that, clients would need to know when compatibility is enabled, which currently is not known by the clients. Maybe this could be negotiated with the ping command?
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
8 years, 11 months
[JBoss JIRA] (ISPN-5507) Transactions committed immediately before cache stop can block shutdown
by Dan Berindei (JIRA)
Dan Berindei created ISPN-5507:
----------------------------------
Summary: Transactions committed immediately before cache stop can block shutdown
Key: ISPN-5507
URL: https://issues.jboss.org/browse/ISPN-5507
Project: Infinispan
Issue Type: Bug
Components: Core, Test Suite - Core
Affects Versions: 8.0.0.Alpha1, 7.2.1.Final
Reporter: Dan Berindei
Priority: Blocker
Fix For: 8.0.0.Alpha2
This is causing random failures in {{DistributedEntryRetrieverTxTest.verifyNodeLeavesBeforeGettingData}}.
The test inserts some values into the cache, starts an iteration, and then kills one of the nodes. In rare instances, the killed cache only receives the TxCompletionCommand for one of the writes after it started the shutdown, and ignores it. That leaves the remote tx on-going, and {{TransactionTable.shutDownGracefully()}} blocks for 30 seconds - causing a {{TimeoutException}} elsewhere in the test.
{noformat}
10:52:18,129 TRACE (remote-thread-NodeAM-p12133-t6:) [CommandAwareRpcDispatcher] About to send back response SuccessfulResponse{responseValue=null} for command CommitCommand {gtx=GlobalTransaction:<NodeAL-45757>:22325:remote, cacheName='org.infinispan.iteration.DistributedEntryRetrieverTxTest', topologyId=4}
10:52:18,129 TRACE (testng-DistributedEntryRetrieverTxTest:) [JGroupsTransport] dests=[NodeAM-45518, NodeAL-45757], command=TxCompletionNotificationCommand{ xid=null, internalId=0, topologyId=4, gtx=GlobalTransaction:<NodeAL-45757>:22325:local, cacheName=org.infinispan.iteration.DistributedEntryRetrieverTxTest} , mode=ASYNCHRONOUS, timeout=15000
10:52:18,133 DEBUG (testng-DistributedEntryRetrieverTxTest:) [CacheImpl] Stopping cache org.infinispan.iteration.DistributedEntryRetrieverTxTest on NodeAM-45518
10:52:18,133 TRACE (OOB-2,NodeAM-45518:) [GlobalInboundInvocationHandler] Attempting to execute CacheRpcCommand: TxCompletionNotificationCommand{ xid=null, internalId=0, topologyId=4, gtx=GlobalTransaction:<NodeAL-45757>:22325:local, cacheName=org.infinispan.iteration.DistributedEntryRetrieverTxTest} [sender=NodeAL-45757]
10:52:18,133 TRACE (OOB-2,NodeAM-45518:) [GlobalInboundInvocationHandler] Silently ignoring that org.infinispan.iteration.DistributedEntryRetrieverTxTest cache is not defined
10:52:18,133 DEBUG (testng-DistributedEntryRetrieverTxTest:) [TransactionTable] Wait for on-going transactions to finish for 30 seconds.
10:52:48,139 WARN (testng-DistributedEntryRetrieverTxTest:) [TransactionTable] ISPN000100: Stopping, but there are 0 local transactions and 1 remote transactions that did not finish in time.
10:52:48,386 ERROR (testng-DistributedEntryRetrieverTxTest:) [UnitTestTestNGListener] Test verifyNodeLeavesBeforeGettingData(org.infinispan.iteration.DistributedEntryRetrieverTxTest) failed.
java.lang.IllegalStateException: Thread already timed out waiting for event pre_send_response_released
at org.infinispan.test.fwk.CheckPoint.trigger(CheckPoint.java:131)
at org.infinispan.test.fwk.CheckPoint.trigger(CheckPoint.java:116)
at org.infinispan.iteration.DistributedEntryRetrieverTest.verifyNodeLeavesBeforeGettingData(DistributedEntryRetrieverTest.java:105)
{noformat}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
8 years, 11 months
[JBoss JIRA] (ISPN-5462) Transaction prepare is not replicated to new owners during state transfer
by RH Bugzilla Integration (JIRA)
[ https://issues.jboss.org/browse/ISPN-5462?page=com.atlassian.jira.plugin.... ]
RH Bugzilla Integration commented on ISPN-5462:
-----------------------------------------------
Matej Čimbora <mcimbora(a)redhat.com> changed the Status of [bug 1221166|https://bugzilla.redhat.com/show_bug.cgi?id=1221166] from ON_QA to VERIFIED
> Transaction prepare is not replicated to new owners during state transfer
> -------------------------------------------------------------------------
>
> Key: ISPN-5462
> URL: https://issues.jboss.org/browse/ISPN-5462
> Project: Infinispan
> Issue Type: Bug
> Components: Core
> Affects Versions: 7.2.1.Final
> Reporter: Dan Berindei
> Assignee: Dan Berindei
> Priority: Critical
> Labels: testsuite_stability
> Fix For: 7.2.2.Final, 8.0.0.Alpha1
>
>
> This is related to ISPN-5460, and I've seen it in the same map/reduce tests.
> {{TransactionTable}} updates its topology id *before* the new topology is installed in {{StateConsumerImpl}}. This means a transaction could be created with the new topology id, while the prepare is replicated to the owners in the old topology - meaning the new owners never receive the prepare and the commit then fails.
> Note: without the ISPN-4546 fix, it would have reported success, but it wouldn't have updated the keys.
> {noformat}
> 09:25:57,749 TRACE (asyncTransportThread-0,NodeA:) [StateConsumerImpl] Received new topology for cache resultCache2, isRebalance = true, isMember = true, topology = CacheTopology{id=1, rebalanceId=1, currentCH=ReplicatedConsistentHash{ns = 1, owners = (1)[NodeA-6285: 1]}, pendingCH=ReplicatedConsistentHash{ns = 1, owners = (2)[NodeA-6285: 1, NodeB-17038: 0]}, unionCH=ReplicatedConsistentHash{ns = 1, owners = (2)[NodeA-6285: 1, NodeB-17038: 0]}, actualMembers=[NodeA-6285, NodeB-17038]}
> 09:25:57,749 TRACE (asyncTransportThread-1,NodeA:) [TransactionTable] Created a new local transaction: LocalXaTransaction{xid=null} LocalTransaction{remoteLockedNodes=null, isMarkedForRollback=false, lockedKeys=null, backupKeyLocks=null, topologyId=1, stateTransferFlag=null} org.infinispan.transaction.xa.LocalXaTransaction@3c96
> 09:25:57,749 TRACE (asyncTransportThread-1,NodeA:) [TransactionXaAdapter] end called on tx GlobalTransaction:<NodeA-6285>:15510:local(resultCache2)
> 09:25:57,749 TRACE (asyncTransportThread-1,NodeA:) [StateTransferInterceptor] handleTxCommand for command PrepareCommand {modifications=[PutKeyValueCommand{key=Boston, value=1, flags=null, putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}], onePhaseCommit=false, gtx=GlobalTransaction:<NodeA-6285>:15510:local, cacheName='resultCache2', topologyId=-1}, origin null
> 09:25:57,749 TRACE (asyncTransportThread-1,NodeA:) [JGroupsTransport] dests=[NodeA-6285], command=PrepareCommand {modifications=[PutKeyValueCommand{key=Boston, value=1, flags=null, putIfAbsent=false, valueMatcher=MATCH_ALWAYS, metadata=EmbeddedMetadata{version=null}, successful=true}], onePhaseCommit=false, gtx=GlobalTransaction:<NodeA-6285>:15510:local, cacheName='resultCache2', topologyId=0}, mode=SYNCHRONOUS_IGNORE_LEAVERS, timeout=15000
> 09:25:57,749 TRACE (asyncTransportThread-1,NodeA:) [LocalTransaction] Adding remote locks on [NodeA-6285]. Remote locks are null
> 09:25:57,749 TRACE (asyncTransportThread-1,NodeA:) [TransactionCoordinator] Committing transaction GlobalTransaction:<NodeA-6285>:15510:local
> 09:25:57,749 TRACE (asyncTransportThread-0,NodeA:) [StateConsumerImpl] Lock State Transfer in Progress for topology ID 1
> // StateConsumerImpl's topology is updated here
> 09:25:57,749 TRACE (asyncTransportThread-0,NodeA:) [StateConsumerImpl] Start keeping track of keys for rebalance
> 09:25:57,751 TRACE (remote-thread-5,NodeB:) [StateTransferManagerImpl] Installing new cache topology CacheTopology{id=1, rebalanceId=1, currentCH=ReplicatedConsistentHash{ns = 1, owners = (1)[NodeA-6285: 1]}, pendingCH=ReplicatedConsistentHash{ns = 1, owners = (2)[NodeA-6285: 1, NodeB-17038: 0]}, unionCH=ReplicatedConsistentHash{ns = 1, owners = (2)[NodeA-6285: 1, NodeB-17038: 0]}, actualMembers=[NodeA-6285, NodeB-17038]} on cache resultCache2
> 09:25:57,752 TRACE (remote-thread-5,NodeB:) [StateConsumerImpl] Requesting transactions for segments [0] of cache resultCache2 from node NodeA-6285
> 09:25:57,752 TRACE (remote-thread-2,NodeA:) [StateProviderImpl] Skipping transaction LocalXaTransaction{xid=< formatId=131077, gtrid_length=29, bqual_length=36, tx_uid=0:ffffc0a80a66:ab12:55504ae3:5806, node_name=1, branch_uid=0:ffffc0a80a66:ab12:55504ae3:5807, subordinatenodename=null, eis_name=0 >} LocalTransaction{remoteLockedNodes=[NodeA-6285], isMarkedForRollback=false, lockedKeys=[Boston], backupKeyLocks=null, topologyId=1, stateTransferFlag=null} org.infinispan.transaction.xa.LocalXaTransaction@3c96 as it was started in the current topology or by a leaver
> 09:25:57,753 TRACE (remote-thread-3,NodeB:) [InboundInvocationHandlerImpl] Calling perform() on CommitCommand {gtx=GlobalTransaction:<NodeA-6285>:15510:remote, cacheName='resultCache2', topologyId=1}
> 09:25:57,753 TRACE (remote-thread-3,NodeB:) [AbstractTransactionBoundaryCommand] Did not find a RemoteTransaction for GlobalTransaction:<NodeA-6285>:15510:remote, completed successfully? false
> 09:25:57,758 ERROR (remote-thread-3,NodeB:) [InboundInvocationHandlerImpl] ISPN000260: Exception executing command
> java.lang.IllegalStateException: Remote transaction not found
> {noformat}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
8 years, 11 months
[JBoss JIRA] (ISPN-5477) Compatibility with L1 can lead to wrong return type
by Galder Zamarreño (JIRA)
[ https://issues.jboss.org/browse/ISPN-5477?page=com.atlassian.jira.plugin.... ]
Galder Zamarreño updated ISPN-5477:
-----------------------------------
Git Pull Request: https://github.com/infinispan/infinispan/pull/3476, https://github.com/infinispan/infinispan/pull/3501, https://github.com/infinispan/infinispan/pull/3503 (was: https://github.com/infinispan/infinispan/pull/3476, https://github.com/infinispan/infinispan/pull/3501)
> Compatibility with L1 can lead to wrong return type
> ---------------------------------------------------
>
> Key: ISPN-5477
> URL: https://issues.jboss.org/browse/ISPN-5477
> Project: Infinispan
> Issue Type: Bug
> Components: Remote Protocols
> Affects Versions: 7.2.1.Final
> Reporter: Galder Zamarreño
> Assignee: Galder Zamarreño
> Fix For: 7.2.2.Final
>
>
> Currently, when using compatibility mode with distributed caches, it is possible for users to store keys using embedded API which hash differently to when the same key is access via remote API. This is due to the differences in source data. For embedded, the source object is the POJO, whereas for remote, the source object is the byte[] format of the pojo.
> When using such keys, remote APIs might go to a node which is not owner, leading to a remote get. When two gets are executed, the first of which results in L1 entry being added to the container, the second get result in exceptions such as this on the client:
> {code}
> java.lang.ClassCastException: [B cannot be cast to xxx....
> {code}
> This is due to over eager unboxing by the BaseTypeConverterInterceptor. I discovered this while investigating ISPN-5449.
> It would be ideal to not have scenarios where there are diverging keys but for that, clients would need to know when compatibility is enabled, which currently is not known by the clients. Maybe this could be negotiated with the ping command?
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
8 years, 11 months
[JBoss JIRA] (ISPN-5506) Dist/ReplEmbeddedRestHotRodTest failing randomly with "java.net.SocketException: Socket closed"
by Galder Zamarreño (JIRA)
[ https://issues.jboss.org/browse/ISPN-5506?page=com.atlassian.jira.plugin.... ]
Galder Zamarreño commented on ISPN-5506:
----------------------------------------
TRACE logs attached
> Dist/ReplEmbeddedRestHotRodTest failing randomly with "java.net.SocketException: Socket closed"
> -----------------------------------------------------------------------------------------------
>
> Key: ISPN-5506
> URL: https://issues.jboss.org/browse/ISPN-5506
> Project: Infinispan
> Issue Type: Bug
> Components: Remote Protocols
> Affects Versions: 7.2.1.Final, 8.0.0.Alpha1
> Reporter: Galder Zamarreño
> Assignee: Galder Zamarreño
> Fix For: 8.0.0.Alpha2
>
> Attachments: infinispan_5506.tgz
>
>
> {code}
> testEmbeddedPutRestHotRodGet(org.infinispan.it.compatibility.DistEmbeddedRestHotRodTest) Time elapsed: 0.002 sec <<< FAILURE!
> java.net.SocketException: Socket closed
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345)
> at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
> at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
> at java.net.Socket.connect(Socket.java:589)
> at java.net.Socket.connect(Socket.java:538)
> at java.net.Socket.<init>(Socket.java:434)
> at java.net.Socket.<init>(Socket.java:286)
> at org.apache.commons.httpclient.protocol.DefaultProtocolSocketFactory.createSocket(DefaultProtocolSocketFactory.java:80)
> at org.apache.commons.httpclient.protocol.DefaultProtocolSocketFactory.createSocket(DefaultProtocolSocketFactory.java:122)
> at org.apache.commons.httpclient.HttpConnection.open(HttpConnection.java:707)
> at org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:387)
> at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:171)
> at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397)
> at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:323)
> at org.infinispan.it.compatibility.ReplEmbeddedRestHotRodTest.testEmbeddedPutRestHotRodGet(ReplEmbeddedRestHotRodTest.java:80)
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
8 years, 11 months
[JBoss JIRA] (ISPN-5506) Dist/ReplEmbeddedRestHotRodTest failing randomly with "java.net.SocketException: Socket closed"
by Galder Zamarreño (JIRA)
[ https://issues.jboss.org/browse/ISPN-5506?page=com.atlassian.jira.plugin.... ]
Galder Zamarreño updated ISPN-5506:
-----------------------------------
Attachment: infinispan_5506.tgz
> Dist/ReplEmbeddedRestHotRodTest failing randomly with "java.net.SocketException: Socket closed"
> -----------------------------------------------------------------------------------------------
>
> Key: ISPN-5506
> URL: https://issues.jboss.org/browse/ISPN-5506
> Project: Infinispan
> Issue Type: Bug
> Components: Remote Protocols
> Affects Versions: 7.2.1.Final, 8.0.0.Alpha1
> Reporter: Galder Zamarreño
> Assignee: Galder Zamarreño
> Fix For: 8.0.0.Alpha2
>
> Attachments: infinispan_5506.tgz
>
>
> {code}
> testEmbeddedPutRestHotRodGet(org.infinispan.it.compatibility.DistEmbeddedRestHotRodTest) Time elapsed: 0.002 sec <<< FAILURE!
> java.net.SocketException: Socket closed
> at java.net.PlainSocketImpl.socketConnect(Native Method)
> at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:345)
> at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206)
> at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188)
> at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
> at java.net.Socket.connect(Socket.java:589)
> at java.net.Socket.connect(Socket.java:538)
> at java.net.Socket.<init>(Socket.java:434)
> at java.net.Socket.<init>(Socket.java:286)
> at org.apache.commons.httpclient.protocol.DefaultProtocolSocketFactory.createSocket(DefaultProtocolSocketFactory.java:80)
> at org.apache.commons.httpclient.protocol.DefaultProtocolSocketFactory.createSocket(DefaultProtocolSocketFactory.java:122)
> at org.apache.commons.httpclient.HttpConnection.open(HttpConnection.java:707)
> at org.apache.commons.httpclient.HttpMethodDirector.executeWithRetry(HttpMethodDirector.java:387)
> at org.apache.commons.httpclient.HttpMethodDirector.executeMethod(HttpMethodDirector.java:171)
> at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:397)
> at org.apache.commons.httpclient.HttpClient.executeMethod(HttpClient.java:323)
> at org.infinispan.it.compatibility.ReplEmbeddedRestHotRodTest.testEmbeddedPutRestHotRodGet(ReplEmbeddedRestHotRodTest.java:80)
> {code}
--
This message was sent by Atlassian JIRA
(v6.3.15#6346)
8 years, 11 months