You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@geode.apache.org by "Dan Smith (JIRA)" <ji...@apache.org> on 2017/12/11 22:43:00 UTC

[jira] [Updated] (GEODE-4077) HASlowReceiverDUnitTest.testSlowClient fails intermittently

     [ https://issues.apache.org/jira/browse/GEODE-4077?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]

Dan Smith updated GEODE-4077:
-----------------------------
    Component/s: 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, client/server
>            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)