ow2-proactive/programming

When creating a PNP node with random port, the node creation can fail with "address already in use" error

fviale opened this issue · 1 comments

This is probably due to an existing socket in TIME_WAIT state. The problem is that the random free port chosen by the JVM seems not to take this into account.

[2016-10-24 20:11:14,691 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log] Process finished Thread=ERR -> /home/activeeon/jenk
[2016-10-24 20:11:14,692 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log] Process finished Thread=IN -> /home/activeeon/jenk
[2016-10-24 20:11:18,568 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log] org.objectweb.proactive.core.node.NodeException: Failed to create a local node. name=node2
[2016-10-24 20:11:18,569 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.node.NodeFactory.createLocalNode(NodeFactory.java:230)
[2016-10-24 20:11:18,569 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.node.StartNode.createNode(StartNode.java:146)
[2016-10-24 20:11:18,569 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.node.StartNode.run(StartNode.java:184)
[2016-10-24 20:11:18,569 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.node.StartNode.main(StartNode.java:121)
[2016-10-24 20:11:18,570 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log] Caused by: java.lang.RuntimeException: org.objectweb.proactive.core.ProtocolException: Failed to create remote object (name=PA_JVM1500798101)
[2016-10-24 20:11:18,570 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.runtime.ProActiveRuntimeImpl.getProActiveRuntimeImpl(ProActiveRuntimeImpl.java:169)
[2016-10-24 20:11:18,570 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.runtime.ProActiveRuntimeImpl.getProActiveRuntime(ProActiveRuntimeImpl.java:268)
[2016-10-24 20:11:18,570 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.runtime.RuntimeFactory.getProtocolSpecificRuntime(RuntimeFactory.java:172)
[2016-10-24 20:11:18,570 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.runtime.RuntimeFactory.getDefaultRuntime(RuntimeFactory.java:148)
[2016-10-24 20:11:18,571 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.node.NodeFactory.createLocalNode(NodeFactory.java:227)
[2016-10-24 20:11:18,571 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   ... 3 more
[2016-10-24 20:11:18,571 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log] Caused by: org.objectweb.proactive.core.ProtocolException: Failed to create remote object (name=PA_JVM1500798101)
[2016-10-24 20:11:18,571 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.remoteobject.RemoteObjectExposer.createRemoteObject(RemoteObjectExposer.java:195)
[2016-10-24 20:11:18,572 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.remoteobject.RemoteObjectExposer.createRemoteObject(RemoteObjectExposer.java:161)
[2016-10-24 20:11:18,572 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.runtime.ProActiveRuntimeImpl.<init>(ProActiveRuntimeImpl.java:232)
[2016-10-24 20:11:18,572 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.runtime.ProActiveRuntimeImpl.getProActiveRuntimeImpl(ProActiveRuntimeImpl.java:149)
[2016-10-24 20:11:18,572 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   ... 7 more
[2016-10-24 20:11:18,572 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log] Caused by: org.objectweb.proactive.extensions.pnp.exception.PNPException: createRemoteObject call failed. PNP not properly configured, agent is null (cause follows)
[2016-10-24 20:11:18,572 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.extensions.pnp.PNPRemoteObjectFactoryBackend.throwIfAgentIsNul(PNPRemoteObjectFactoryBackend.java:101)
[2016-10-24 20:11:18,573 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.extensions.pnp.PNPRemoteObjectFactoryBackend.createRemoteObject(PNPRemoteObjectFactoryBackend.java:233)
[2016-10-24 20:11:18,573 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.extensions.pnp.PNPRemoteObjectFactoryAbstract.createRemoteObject(PNPRemoteObjectFactoryAbstract.java:134)
[2016-10-24 20:11:18,573 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.remoteobject.RemoteObjectExposer.createRemoteObject(RemoteObjectExposer.java:189)
[2016-10-24 20:11:18,573 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   ... 10 more
[2016-10-24 20:11:18,573 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log] Caused by: org.objectweb.proactive.extensions.pnp.exception.PNPException: Failed to setup the server side of PNP
[2016-10-24 20:11:18,573 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.extensions.pnp.PNPAgent.<init>(PNPAgent.java:146)
[2016-10-24 20:11:18,574 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.extensions.pnp.PNPRemoteObjectFactoryBackend.<init>(PNPRemoteObjectFactoryBackend.java:88)
[2016-10-24 20:11:18,574 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.extensions.pnp.PNPRemoteObjectFactory.<init>(PNPRemoteObjectFactory.java:55)
[2016-10-24 20:11:18,574 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method)
[2016-10-24 20:11:18,574 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62)
[2016-10-24 20:11:18,574 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45)
[2016-10-24 20:11:18,574 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at java.lang.reflect.Constructor.newInstance(Constructor.java:423)
[2016-10-24 20:11:18,575 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at java.lang.Class.newInstance(Class.java:442)
[2016-10-24 20:11:18,575 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.remoteobject.AbstractRemoteObjectFactory.getRemoteObjectFactory(AbstractRemoteObjectFactory.java:131)
[2016-10-24 20:11:18,576 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.core.remoteobject.RemoteObjectExposer.createRemoteObject(RemoteObjectExposer.java:184)
[2016-10-24 20:11:18,576 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   ... 10 more
[2016-10-24 20:11:18,576 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log] Caused by: org.jboss.netty.channel.ChannelException: Failed to bind to: 0.0.0.0/0.0.0.0:36790
[2016-10-24 20:11:18,577 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.jboss.netty.bootstrap.ServerBootstrap.bind(ServerBootstrap.java:272)
[2016-10-24 20:11:18,577 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.objectweb.proactive.extensions.pnp.PNPAgent.<init>(PNPAgent.java:135)
[2016-10-24 20:11:18,577 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   ... 19 more
[2016-10-24 20:11:18,577 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log] Caused by: java.net.BindException: Address already in use
[2016-10-24 20:11:18,577 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at sun.nio.ch.Net.bind0(Native Method)
[2016-10-24 20:11:18,577 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at sun.nio.ch.Net.bind(Net.java:433)
[2016-10-24 20:11:18,578 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at sun.nio.ch.Net.bind(Net.java:425)
[2016-10-24 20:11:18,578 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at sun.nio.ch.ServerSocketChannelImpl.bind(ServerSocketChannelImpl.java:223)
[2016-10-24 20:11:18,578 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at sun.nio.ch.ServerSocketAdaptor.bind(ServerSocketAdaptor.java:74)
[2016-10-24 20:11:18,578 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.jboss.netty.channel.socket.nio.NioServerBoss$RegisterTask.run(NioServerBoss.java:193)
[2016-10-24 20:11:18,578 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.jboss.netty.channel.socket.nio.AbstractNioSelector.processTaskQueue(AbstractNioSelector.java:391)
[2016-10-24 20:11:18,578 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.jboss.netty.channel.socket.nio.AbstractNioSelector.run(AbstractNioSelector.java:315)
[2016-10-24 20:11:18,579 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.jboss.netty.channel.socket.nio.NioServerBoss.run(NioServerBoss.java:42)
[2016-10-24 20:11:18,579 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.jboss.netty.util.ThreadRenamingRunnable.run(ThreadRenamingRunnable.java:108)
[2016-10-24 20:11:18,579 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at org.jboss.netty.util.internal.DeadLockProofWorker$1.run(DeadLockProofWorker.java:42)
[2016-10-24 20:11:18,579 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
[2016-10-24 20:11:18,579 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
[2016-10-24 20:11:18,579 INFO ] [AbstractExternalProcess$StandardOutputMessageLogger.log]   at java.lang.Thread.run(Thread.java:745)

This error does not seem to be tied to the PNP socket creation but is rather because an already used PNP port was provided.