[
https://issues.apache.org/jira/browse/GEODE-4077?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Dan Smith updated GEODE-4077:
-----------------------------
Component/s: (was: client/server)
> HASlowReceiverDUnitTest.testSlowClient fails intermittently
> -----------------------------------------------------------
>
> Key: GEODE-4077
> URL: https://issues.apache.org/jira/browse/GEODE-4077
> Project: Geode
> Issue Type: Bug
> Components: client queues
> Reporter: Dan Smith
>
> This test is failing intermittently in precheckin with revision
> fa2687c76a5fd93d968449a40450c28e8814ee58.
> {noformat}
> org.apache.geode.test.dunit.RMIException: While invoking
> org.apache.geode.internal.cache.ha.HASlowReceiverDUnitTest$$Lambda$355/783772242.run
> in VM 3 running on Host fbaa7686d027 with 4 VMs
> at org.apache.geode.test.dunit.VM.invoke(VM.java:393)
> at org.apache.geode.test.dunit.VM.invoke(VM.java:363)
> at org.apache.geode.test.dunit.VM.invoke(VM.java:308)
> at
> org.apache.geode.internal.cache.ha.HASlowReceiverDUnitTest.testSlowClient(HASlowReceiverDUnitTest.java:252)
> 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:498)
> at
> org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
> at
> org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
> at
> org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
> at
> org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
> at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
> at
> org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:27)
> at org.junit.rules.TestWatcher$1.evaluate(TestWatcher.java:55)
> at org.junit.rules.RunRules.evaluate(RunRules.java:20)
> at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:78)
> at
> org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:57)
> at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
> at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
> at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
> at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
> at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
> at
> org.junit.internal.runners.statements.RunBefores.evaluate(RunBefores.java:26)
> at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.runTestClass(JUnitTestClassExecuter.java:114)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassExecuter.execute(JUnitTestClassExecuter.java:57)
> at
> org.gradle.api.internal.tasks.testing.junit.JUnitTestClassProcessor.processTestClass(JUnitTestClassProcessor.java:66)
> at
> org.gradle.api.internal.tasks.testing.SuiteTestClassProcessor.processTestClass(SuiteTestClassProcessor.java:51)
> at sun.reflect.GeneratedMethodAccessor341.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at
> org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at
> org.gradle.internal.dispatch.ContextClassLoaderDispatch.dispatch(ContextClassLoaderDispatch.java:32)
> at
> org.gradle.internal.dispatch.ProxyDispatchAdapter$DispatchingInvocationHandler.invoke(ProxyDispatchAdapter.java:93)
> at com.sun.proxy.$Proxy2.processTestClass(Unknown Source)
> at
> org.gradle.api.internal.tasks.testing.worker.TestWorker.processTestClass(TestWorker.java:109)
> at sun.reflect.GeneratedMethodAccessor340.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at
> org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:35)
> at
> org.gradle.internal.dispatch.ReflectionDispatch.dispatch(ReflectionDispatch.java:24)
> at
> org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:147)
> at
> org.gradle.internal.remote.internal.hub.MessageHubBackedObjectConnection$DispatchWrapper.dispatch(MessageHubBackedObjectConnection.java:129)
> at
> org.gradle.internal.remote.internal.hub.MessageHub$Handler.run(MessageHub.java:404)
> at
> org.gradle.internal.concurrent.ExecutorPolicy$CatchAndRecordFailures.onExecute(ExecutorPolicy.java:63)
> at
> org.gradle.internal.concurrent.StoppableExecutorImpl$1.run(StoppableExecutorImpl.java:46)
> at
> java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
> at
> java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
> at java.lang.Thread.run(Thread.java:748)
> Caused by: org.apache.geode.cache.NoSubscriptionServersAvailableException:
> org.apache.geode.cache.NoSubscriptionServersAvailableException: Primary
> discovery failed.
> at
> org.apache.geode.cache.client.internal.QueueManagerImpl.getAllConnections(QueueManagerImpl.java:190)
> at
> org.apache.geode.cache.client.internal.PoolImpl.getRedundantNames(PoolImpl.java:1073)
> at
> org.apache.geode.internal.cache.ha.HASlowReceiverDUnitTest$2.done(HASlowReceiverDUnitTest.java:224)
> at org.apache.geode.test.dunit.Wait.waitForCriterion(Wait.java:171)
> at
> org.apache.geode.internal.cache.ha.HASlowReceiverDUnitTest.checkRedundancyLevel(HASlowReceiverDUnitTest.java:232)
> at
> org.apache.geode.internal.cache.ha.HASlowReceiverDUnitTest.lambda$testSlowClient$bb17a952$2(HASlowReceiverDUnitTest.java:252)
> 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:498)
> at hydra.MethExecutor.executeObject(MethExecutor.java:244)
> at
> org.apache.geode.test.dunit.standalone.RemoteDUnitVM.executeMethodOnObject(RemoteDUnitVM.java:70)
> at sun.reflect.GeneratedMethodAccessor165.invoke(Unknown Source)
> at
> sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
> at java.lang.reflect.Method.invoke(Method.java:498)
> at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:357)
> at sun.rmi.transport.Transport$1.run(Transport.java:200)
> at sun.rmi.transport.Transport$1.run(Transport.java:197)
> at java.security.AccessController.doPrivileged(Native Method)
> at sun.rmi.transport.Transport.serviceCall(Transport.java:196)
> at
> sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:568)
> at
> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:826)
> at
> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:683)
> at java.security.AccessController.doPrivileged(Native Method)
> at
> sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:682)
> ... 3 more
> Caused by: org.apache.geode.cache.NoSubscriptionServersAvailableException:
> Primary discovery failed.
> at
> org.apache.geode.cache.client.internal.QueueManagerImpl$ConnectionList.setPrimaryDiscoveryFailed(QueueManagerImpl.java:1351)
> at
> org.apache.geode.cache.client.internal.QueueManagerImpl.recoverPrimary(QueueManagerImpl.java:965)
> at
> org.apache.geode.cache.client.internal.QueueManagerImpl$RedundancySatisfierTask.run2(QueueManagerImpl.java:1467)
> at
> org.apache.geode.cache.client.internal.PoolImpl$PoolTask.run(PoolImpl.java:1326)
> at
> java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
> at java.util.concurrent.FutureTask.run(FutureTask.java:266)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180)
> at
> java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
> ... 3 more
> {noformat}
> I'm wondering of GEODE-3637 changed the timing of this test, but looking at
> the logs it looks like maybe this is expected? The test is trying to cause
> the server to disconnect the client by having a sleep in the client cache
> listener.
> In the failed run, the client is disconnected.
> {noformat}
> [warn 2017/12/09 00:29:32.356 UTC <Test worker> tid=0x16] Client
> identity(172.17.0.5(193:loner):37262:a854ad38,connection=1 is a slow receiver.
> {noformat}
> The client tries to reconnect. However, it appears there is some logic on the
> server side to block new connections from the client while the servers are
> destroying the clients queue. So the client gets an exception.
> {noformat}
> [vm3] [info 2017/12/09 00:29:32.369 UTC
> <queueTimer-HASlowRecieverDUnitTestPool> tid=0x884] SubscriptionManager
> redundancy satisfier - redundant endpoint has been lost. Attempting to
> recover.
> [vm3] [warn 2017/12/09 00:29:32.372 UTC
> <queueTimer-HASlowRecieverDUnitTestPool> tid=0x884] Cache Client Updater
> Thread on fbaa7686d027(178)<v274>:32771 port 28357 (localhost:28357): Caught
> following exception while attempting to create a server-to-client
> communication socket and will exit:
> org.apache.geode.cache.client.ServerRefusedConnectionException: <null
> inet_addr hostname><ec>:28357 refused connection: java.lang.Exception: This
> client is blacklisted by server
> {noformat}
> I think this is why the test gets an exception. The test is directly calling
> an internal API to check the redundancy of the client pool. But that call
> throws an exception, because the client was unable to contact any servers.
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
