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)
