[
https://issues.apache.org/jira/browse/GEODE-4235?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16327696#comment-16327696
]
Barry Oglesby commented on GEODE-4235:
--------------------------------------
This test has the same issue that is described in GEODE-4251. Basically, the
registerInterest call times out causing the QueueConnectionImpl and
CacheClientUpdater to be closed on the client, but the CacheClientProxy is not
closed on the server.
This test has a slightly different path to the issue, but it gets to the same
place.
vm1 creates 2 cache server listeners:
{noformat}
[vm1] [info 2018/01/06 07:11:02.489 UTC <RMI TCP Connection(2)-172.17.0.2>
tid=30] Cache server connection listener bound to address
1f775e82c3a2-0.0.0.0/0.0.0.0:46083 with backlog 1,000.
[vm1] [info 2018/01/06 07:11:02.662 UTC <RMI TCP Connection(2)-172.17.0.2>
tid=30] Cache server connection listener bound to address
1f775e82c3a2-0.0.0.0/0.0.0.0:44261 with backlog 1,000.
{noformat}
vm2 client attempts to connect primary and secondary on that server and fails:
{noformat}
[vm1] [info 2018/01/06 07:11:11.675 UTC <Client Queue Initialization Thread 0>
tid=106] :Bridge server: Initializing secondary server-to-client communication
socket: Socket[addr=/172.17.0.2,port=46678,localport=46083]
[vm1] [info 2018/01/06 07:11:11.826 UTC <Client Queue Initialization Thread 0>
tid=106] Initializing region
_gfe_non_durable_client_with_id_172.17.0.2(198:loner):46088:7c084fca_1_queue
[vm1] [info 2018/01/06 07:11:11.831 UTC <Client Queue Initialization Thread 0>
tid=106] Initialization of region
_gfe_non_durable_client_with_id_172.17.0.2(198:loner):46088:7c084fca_1_queue
completed
[vm1] [info 2018/01/06 07:11:11.842 UTC <Client Queue Initialization Thread 0>
tid=111] :Bridge server: Initializing primary server-to-client communication
socket: Socket[addr=/172.17.0.2,port=38020,localport=44261]
[vm1] [warn 2018/01/06 07:11:11.861 UTC <Client Queue Initialization Thread 0>
tid=111] A previous connection attempt from this client is still being
processed: identity(172.17.0.2(198:loner):46088:7c084fca,connection=1
[vm2] [info 2018/01/06 07:11:11.859 UTC <Cache Client Updater Thread on
1f775e82c3a2(180)<ec><v0>:32770 port 46083> tid=69] Cache Client Updater Thread
on 1f775e82c3a2(180)<ec><v0>:32770 port 46083 (1f775e82c3a2:46083) : ready to
process messages.
[vm2] [warn 2018/01/06 07:11:11.864 UTC <RMI TCP Connection(2)-172.17.0.2>
tid=30] Cache Client Updater Thread on 1f775e82c3a2(180)<ec><v0>:32770 port
44261 (1f775e82c3a2:44261): 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>:44261 refused connection: A previous connection attempt from this
client is still being processed:
identity(172.17.0.2(198:loner):46088:7c084fca,connection=1
[vm1] [info 2018/01/06 07:11:11.866 UTC <ServerConnection on port 44261 Thread
0> tid=99] Server connection from
[identity(172.17.0.2(198:loner):46088:7c084fca,connection=1; port=37404]:
connection disconnect detected by EOF.
[vm1] [warn 2018/01/06 07:11:11.875 UTC <Client Queue Initialization Thread 0>
tid=111] CacheClientNotifier: Unsuccessfully registered client with identifier
identity(172.17.0.2(198:loner):46088:7c084fca,connection=1 and response code 60
{noformat}
Then, registerInterest is invoked on the secondary QueueConnectionImpl and
times out after 2 seconds:
{noformat}
[vm2] [warn 2018/01/06 07:11:14.132 UTC <RMI TCP Connection(2)-172.17.0.2>
tid=30] Pool unexpected socket timed out on client
connection=SubscriptionConnectionImpl[1f775e82c3a2:46083:closed])
{noformat}
Once the registerInterest call times out, it won't recover until the
CacheClientProxy is closed on the server.
In a normal run, the registerInterest call takes ~200 ms.
{noformat}
[vm2] [info 2018/01/16 11:41:43.383 PST <RMI TCP Connection(1)-127.0.0.1>
tid=0x13] CacheClientNotifierDUnitTest.createClientWithLocator About to
register interest
[vm2] [info 2018/01/16 11:41:43.581 PST <RMI TCP Connection(1)-127.0.0.1>
tid=0x13] CacheClientNotifierDUnitTest.createClientWithLocator Done register
interest
{noformat}
In this test that fails, it has not completed after 2000 ms.
> CI failure: org.apache.geode.internal.cache.wan.Simple2CacheServerDUnitTest >
> testNormalClient2MultipleCacheServer FAILED
> -------------------------------------------------------------------------------------------------------------------------
>
> Key: GEODE-4235
> URL: https://issues.apache.org/jira/browse/GEODE-4235
> Project: Geode
> Issue Type: Bug
> Components: wan
> Affects Versions: 1.3.0
> Reporter: Shelley Lynn Hughes-Godfrey
> Priority: Major
>
> {noformat}
> org.apache.geode.internal.cache.wan.Simple2CacheServerDUnitTest >
> testNormalClient2MultipleCacheServer FAILED
> org.apache.geode.test.dunit.RMIException: While invoking
> org.apache.geode.internal.cache.wan.Simple2CacheServerDUnitTest$$Lambda$560/1371246474.run
> in VM 2 running on Host 5932c890475c with 8 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.wan.Simple2CacheServerDUnitTest.doMultipleCacheServer(Simple2CacheServerDUnitTest.java:83)
> at
> org.apache.geode.internal.cache.wan.Simple2CacheServerDUnitTest.testNormalClient2MultipleCacheServer(Simple2CacheServerDUnitTest.java:67)
> 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.OpExecutorImpl.executeOnQueuesAndReturnPrimaryResult(OpExecutorImpl.java:570)
> at
> org.apache.geode.cache.client.internal.PoolImpl.executeOnQueuesAndReturnPrimaryResult(PoolImpl.java:842)
> at
> org.apache.geode.cache.client.internal.RegisterInterestOp.execute(RegisterInterestOp.java:58)
> at
> org.apache.geode.cache.client.internal.ServerRegionProxy.registerInterest(ServerRegionProxy.java:359)
> at
> org.apache.geode.internal.cache.LocalRegion.processSingleInterest(LocalRegion.java:3734)
> at
> org.apache.geode.internal.cache.LocalRegion.registerInterest(LocalRegion.java:3823)
> at
> org.apache.geode.internal.cache.LocalRegion.registerInterest(LocalRegion.java:3625)
> at
> org.apache.geode.internal.cache.LocalRegion.registerInterest(LocalRegion.java:3620)
> at
> org.apache.geode.internal.cache.LocalRegion.registerInterest(LocalRegion.java:3615)
> at
> org.apache.geode.internal.cache.wan.CacheClientNotifierDUnitTest.createClientWithLocator(CacheClientNotifierDUnitTest.java:272)
> at
> org.apache.geode.internal.cache.wan.Simple2CacheServerDUnitTest.lambda$doMultipleCacheServer$e651a521$1(Simple2CacheServerDUnitTest.java:83)
> Caused by:
> org.apache.geode.cache.NoSubscriptionServersAvailableException:
> Primary discovery failed.
> {noformat}
--
This message was sent by Atlassian JIRA
(v7.6.3#76005)
