You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@geode.apache.org by "Jens Deppe (JIRA)" <ji...@apache.org> on 2019/02/27 23:54:00 UTC

[jira] [Created] (GEODE-6467) [CI Failure] ChangeLogLevelCommandOverHttpDistributedTest fails to bind to port

Jens Deppe created GEODE-6467:
---------------------------------

             Summary: [CI Failure] ChangeLogLevelCommandOverHttpDistributedTest fails to bind to port
                 Key: GEODE-6467
                 URL: https://issues.apache.org/jira/browse/GEODE-6467
             Project: Geode
          Issue Type: Test
          Components: ci, gfsh, tests
            Reporter: Jens Deppe


We see the following CI failure:

[https://concourse.apachegeode-ci.info/teams/main/pipelines/apache-develop-main/jobs/WindowsGfshDistributedTestOpenJDK11/builds/291]

 

which tells us

 
{code:java}
[error 2019/02/26 23:10:43.657 GMT <RMI TCP Connection(1)-10.0.0.118> tid=63] Jmx manager could not be started because java.rmi.server.ExportException: Port already in use: 22502; nested exception is: 
	java.net.BindException: Failed to create server socket on packer-5c6f1bd3-202e-8ae5-d9e2-5cc65a8bdfbf/10.0.0.118[22502]
org.apache.geode.management.ManagementException: java.rmi.server.ExportException: Port already in use: 22502; nested exception is: 
	java.net.BindException: Failed to create server socket on packer-5c6f1bd3-202e-8ae5-d9e2-5cc65a8bdfbf/10.0.0.118[22502]
	at org.apache.geode.management.internal.ManagementAgent.startAgent(ManagementAgent.java:133)
	at org.apache.geode.management.internal.SystemManagementService.startManager(SystemManagementService.java:432)
	at org.apache.geode.management.internal.beans.ManagementAdapter.handleCacheCreation(ManagementAdapter.java:179)
	at org.apache.geode.management.internal.beans.ManagementListener.handleEvent(ManagementListener.java:127)
	at org.apache.geode.distributed.internal.InternalDistributedSystem.notifyResourceEventListeners(InternalDistributedSystem.java:2128)
	at org.apache.geode.distributed.internal.InternalDistributedSystem.handleResourceEvent(InternalDistributedSystem.java:680)
	at org.apache.geode.internal.cache.GemFireCacheImpl.initialize(GemFireCacheImpl.java:1241)
	at org.apache.geode.internal.cache.GemFireCacheImpl.basicCreate(GemFireCacheImpl.java:809)
	at org.apache.geode.internal.cache.GemFireCacheImpl.create(GemFireCacheImpl.java:795)
	at org.apache.geode.cache.CacheFactory.create(CacheFactory.java:176)
	at org.apache.geode.cache.CacheFactory.create(CacheFactory.java:218)
	at org.apache.geode.distributed.internal.InternalLocator.startCache(InternalLocator.java:672)
	at org.apache.geode.distributed.internal.InternalLocator.startDistributedSystem(InternalLocator.java:659)
	at org.apache.geode.distributed.internal.InternalLocator.startLocator(InternalLocator.java:343)
	at org.apache.geode.distributed.Locator.startLocator(Locator.java:252)
	at org.apache.geode.distributed.Locator.startLocatorAndDS(Locator.java:139)
	at org.apache.geode.test.junit.rules.LocatorStarterRule.startLocator(LocatorStarterRule.java:85)
	at org.apache.geode.test.junit.rules.LocatorStarterRule.before(LocatorStarterRule.java:66)
	at org.apache.geode.test.dunit.rules.ClusterStartupRule.lambda$startLocatorVM$22d9b8a8$1(ClusterStartupRule.java:239)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.apache.geode.test.dunit.internal.MethodInvoker.executeObject(MethodInvoker.java:123)
	at org.apache.geode.test.dunit.internal.RemoteDUnitVM.executeMethodOnObject(RemoteDUnitVM.java:69)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at java.rmi/sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:359)
	at java.rmi/sun.rmi.transport.Transport$1.run(Transport.java:200)
	at java.rmi/sun.rmi.transport.Transport$1.run(Transport.java:197)
	at java.base/java.security.AccessController.doPrivileged(Native Method)
	at java.rmi/sun.rmi.transport.Transport.serviceCall(Transport.java:196)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:562)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:796)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.lambda$run$0(TCPTransport.java:677)
	at java.base/java.security.AccessController.doPrivileged(Native Method)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:676)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:834)
Caused by: java.rmi.server.ExportException: Port already in use: 22502; nested exception is: 
	java.net.BindException: Failed to create server socket on packer-5c6f1bd3-202e-8ae5-d9e2-5cc65a8bdfbf/10.0.0.118[22502]
	at java.rmi/sun.rmi.transport.tcp.TCPTransport.listen(TCPTransport.java:335)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport.exportObject(TCPTransport.java:243)
	at java.rmi/sun.rmi.transport.tcp.TCPEndpoint.exportObject(TCPEndpoint.java:411)
	at java.rmi/sun.rmi.transport.LiveRef.exportObject(LiveRef.java:147)
	at java.rmi/sun.rmi.server.UnicastServerRef.exportObject(UnicastServerRef.java:233)
	at java.rmi/sun.rmi.registry.RegistryImpl.setup(RegistryImpl.java:220)
	at java.rmi/sun.rmi.registry.RegistryImpl.<init>(RegistryImpl.java:180)
	at java.rmi/sun.rmi.registry.RegistryImpl.<init>(RegistryImpl.java:151)
	at java.rmi/java.rmi.registry.LocateRegistry.createRegistry(LocateRegistry.java:239)
	at org.apache.geode.management.internal.ManagementAgent.configureAndStart(ManagementAgent.java:343)
	at org.apache.geode.management.internal.ManagementAgent.startAgent(ManagementAgent.java:131)
	... 41 more
Caused by: java.net.BindException: Failed to create server socket on packer-5c6f1bd3-202e-8ae5-d9e2-5cc65a8bdfbf/10.0.0.118[22502]
	at org.apache.geode.internal.net.SocketCreator.createServerSocket(SocketCreator.java:756)
	at org.apache.geode.internal.net.SocketCreator.createServerSocket(SocketCreator.java:714)
	at org.apache.geode.management.internal.ManagementAgent$GemFireRMIServerSocketFactory.createServerSocket(ManagementAgent.java:502)
	at java.rmi/sun.rmi.transport.tcp.TCPEndpoint.newServerSocket(TCPEndpoint.java:666)
	at java.rmi/sun.rmi.transport.tcp.TCPTransport.listen(TCPTransport.java:324)
	... 51 more
Caused by: java.net.BindException: Address already in use: NET_Bind
	at java.base/java.net.PlainSocketImpl.bind0(Native Method)
	at java.base/java.net.PlainSocketImpl.socketBind(PlainSocketImpl.java:132)
	at java.base/java.net.AbstractPlainSocketImpl.bind(AbstractPlainSocketImpl.java:436)
	at java.base/java.net.ServerSocket.bind(ServerSocket.java:381)
	at org.apache.geode.internal.net.SocketCreator.createServerSocket(SocketCreator.java:753)
	... 55 more
{code}
After looking into the logs (see end of description), we see that our test code's locatorStartupRule picks a port for some things like JMX and http. Other times we ask our geode cluster to use port 0 in which case it will pickup an available port. Since these two steps are not atomic or perfectly sequential, the port locatorStartupRule finds may sometimes be the same port the geode cluster finds.

One possible solution to address this is to comprehensively using port 0 for all services. This means geode can correctly select unused ports and not have a collision. However some tests require the knowledge of which port is used for a specific service(s) and we do not have a way to extract which port is being used for all the different services.

=-=-=-=-=-=-=-=-=-=-=-=-=-=-= Test Results URI =-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=
 [http://files.apachegeode-ci.info/builds/apache-develop-main/1.9.0-SNAPSHOT.0484/test-results/distributedTest/1551229192/]
 =-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=-=

Test report artifacts from this job are available at:

[http://files.apachegeode-ci.info/builds/apache-develop-main/1.9.0-SNAPSHOT.0484/test-artifacts/1551229192/windows-gfshdistributedtest-OpenJDK11-1.9.0-SNAPSHOT.0484.tgz]



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)