JDK-8168975 : java/rmi/activation/Activatable tests fail due to "Port already in use" in RMID.restart()
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.rmi
  • Affected Version: 9
  • Priority: P4
  • Status: Closed
  • Resolution: Fixed
  • Submitted: 2016-11-01
  • Updated: 2021-03-02
  • Resolved: 2016-11-21
The Version table provides details related to the release that this issue/RFE will be addressed.

Unresolved : Release in which this issue/RFE will be addressed.
Resolved: Release in which this issue/RFE has been resolved.
Fixed : Release in which this issue/RFE has been fixed. The release containing this fix may be available for download as an Early Access Release or a General Availability Release.

To download the current JDK release, click here.
JDK 8 JDK 9
8u301Fixed 9 b147Fixed
Related Reports
Duplicate :  
JDK-8079758 - java/rmi/activation/ActivationSystem tests fail intermittently with port already in use
Duplicate :  
JDK-8043707 - TEST_BUG java/rmi/activation/Activatable/restartService/RestartService.java failed once in same binary run b12
Duplicate :  
JDK-8155048 - CreatePrivateActivatable fails with Address already in use
Duplicate :  
JDK-8150110 - java/rmi/activation/ActivateFailedException/activateFails/ActivateFails.java Failed : nested exception is: TestFailedException
Duplicate :  
JDK-8150495 - Test: java/rmi/activation/Activatable/unregisterInactive/UnregisterInactive.java failed intermittently
Duplicate :  
JDK-8136431 - java/rmi/activation/Activatable/elucidateNoSuchMethod/ElucidateNoSuchMethod.java failed intermittently with "Port already in use"
Relates :  
JDK-8170049 - tests under java/rmi/activation/ fail with "java.security.AccessControlException: access denied ("java.net.SocketPermission" "localhost:5281" "listen,resolve")" on windows
Relates :  
JDK-8085192 - java/rmi/activation/Activatable tests fail intermittently due to "Port already in use"
Relates :  
JDK-8169363 - TEST_BUG: java/rmi/activation/Activatable tests fail due to "java.net.SocketException: Operation not supported on transport endpoint"
Description
JDK-8085192 is fixed and pushed at Date: 2016-10-25 09:49:38 +0000, but the new failure happens at Build #1426 (Oct 28, 2016 6:39:42 PM)

----------System.err:(81/10389)----------
RMID: Starting rmid on port 0.
JAVAVM: command = [/scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/product/bin/java, -ea, -esa, -Xmx512m, -Djava.security.policy=/scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/srcBundle/jdk/test/java/rmi/activation/Activatable/restartCrashedService/rmid.security.policy, -Dsun.rmi.server.activation.debugExec=true, -Dtest.src=/scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/srcBundle/jdk/test/java/rmi/activation/Activatable/restartCrashedService, -Dtest.classes=/scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/testoutput/jtreg/JTwork/classes/4/java/rmi/activation/Activatable/restartCrashedService, -Djava.rmi.server.logLevel=v, -Dsun.rmi.activation.execTimeout=60000, -classpath, /scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/testoutput/jtreg/JTwork/classes/4/java/rmi/activation/Activatable/restartCrashedService:/scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/testoutput/jtreg/JTwork/classes/4/java/rmi/testlibrary, --add-exports=java.base/sun.nio.ch=ALL-UNNAMED, -Djava.nio.channels.spi.SelectorProvider=RMIDSelectorProvider, -Dsun.rmi.server.activation.disableErrRedirect=true, sun.rmi.server.Activation, -log, /scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/testoutput/jtreg/JTwork/scratch/5/./log, -C-Dtest.src=/scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/srcBundle/jdk/test/java/rmi/activation/Activatable/restartCrashedService, -C-Dtest.classes=/scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/testoutput/jtreg/JTwork/classes/4/java/rmi/activation/Activatable/restartCrashedService, -C-ea, -C-esa, -C-Xmx512m, -C-Djava.rmi.server.useCodebaseOnly=false]
RMID: Started rmid on port 65520.
Fri Oct 28 11:49:59 PDT 2016
rmid startup with inherited channel: sun.nio.ch.ServerSocketChannelImpl[localhost/127.0.0.1:65520]
RMID: Started successfully after 307ms.
Creating descriptors
Registering descriptors
RMID: shutdown()
RMID: ActivationSystem.shutdown()
activation daemon shut down
RMID: Shutdown successful after 402ms.
RMID: Starting rmid on port 65520.
JAVAVM: command = [/scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/product/bin/java, -ea, -esa, -Xmx512m, -Djava.security.policy=/scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/srcBundle/jdk/test/java/rmi/activation/Activatable/restartCrashedService/rmid.security.policy, -Dsun.rmi.server.activation.debugExec=true, -Dtest.src=/scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/srcBundle/jdk/test/java/rmi/activation/Activatable/restartCrashedService, -Dtest.classes=/scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/testoutput/jtreg/JTwork/classes/4/java/rmi/activation/Activatable/restartCrashedService, -Djava.rmi.server.logLevel=v, -Dsun.rmi.activation.execTimeout=60000, sun.rmi.server.Activation, -log, /scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/testoutput/jtreg/JTwork/scratch/5/./log, -port, 65520, -C-Dtest.src=/scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/srcBundle/jdk/test/java/rmi/activation/Activatable/restartCrashedService, -C-Dtest.classes=/scratch/mesos/work_dir/slaves/e053834b-c836-437c-a964-ec7a9c5adf82-S21/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/029737be-5b89-4404-8619-2846eb00e516/runs/b384f539-ca55-4106-9fde-1f6e659a93de/testoutput/jtreg/JTwork/classes/4/java/rmi/activation/Activatable/restartCrashedService, -C-ea, -C-esa, -C-Xmx512m, -C-Djava.rmi.server.useCodebaseOnly=false]
RMID: Started rmid on port 65520.
Activation.main: an exception occurred: java.rmi.server.ExportException: Port already in use: 65520; nested exception is: 
	java.net.BindException: Address already in use (Bind failed)
java.rmi.server.ExportException: Port already in use: 65520; nested exception is: 
	java.net.BindException: Address already in use (Bind failed)
	at sun.rmi.transport.tcp.TCPTransport.listen(java.rmi@9-internal/TCPTransport.java:335)
	at sun.rmi.transport.tcp.TCPTransport.exportObject(java.rmi@9-internal/TCPTransport.java:243)
	at sun.rmi.transport.tcp.TCPEndpoint.exportObject(java.rmi@9-internal/TCPEndpoint.java:411)
	at sun.rmi.transport.LiveRef.exportObject(java.rmi@9-internal/LiveRef.java:147)
	at sun.rmi.server.UnicastServerRef.exportObject(java.rmi@9-internal/UnicastServerRef.java:232)
	at sun.rmi.server.Activation$ActivatorImpl.<init>(java.rmi@9-internal/Activation.java:428)
	at sun.rmi.server.Activation.init(java.rmi@9-internal/Activation.java:250)
	at sun.rmi.server.Activation.startActivation(java.rmi@9-internal/Activation.java:219)
	at sun.rmi.server.Activation.main(java.rmi@9-internal/Activation.java:2118)
Caused by: java.net.BindException: Address already in use (Bind failed)
	at java.net.PlainSocketImpl.socketBind(java.base@9-internal/Native Method)
	at java.net.AbstractPlainSocketImpl.bind(java.base@9-internal/AbstractPlainSocketImpl.java:437)
	at java.net.ServerSocket.bind(java.base@9-internal/ServerSocket.java:381)
	at java.net.ServerSocket.<init>(java.base@9-internal/ServerSocket.java:243)
	at java.net.ServerSocket.<init>(java.base@9-internal/ServerSocket.java:135)
	at sun.rmi.transport.tcp.TCPDirectSocketFactory.createServerSocket(java.rmi@9-internal/TCPDirectSocketFactory.java:45)
	at sun.rmi.transport.tcp.TCPEndpoint.newServerSocket(java.rmi@9-internal/TCPEndpoint.java:666)
	at sun.rmi.transport.tcp.TCPTransport.listen(java.rmi@9-internal/TCPTransport.java:324)
	... 8 more
TEST FAILED: Rmid process exited with status 1 after 504ms.
TEST FAILED: 
Test failed with: TEST FAILED: Rmid process exited with status 1 after 504ms.
TestFailedException: TEST FAILED: Rmid process exited with status 1 after 504ms.
	at TestLibrary.bomb(TestLibrary.java:121)
	at TestLibrary.bomb(TestLibrary.java:124)
	at RMID.start(RMID.java:312)
	at RMID.start(RMID.java:271)
	at RMID.restart(RMID.java:352)
	at RestartCrashedService.main(RestartCrashedService.java:175)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@9-internal/Native Method)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@9-internal/NativeMethodAccessorImpl.java:62)
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@9-internal/DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(java.base@9-internal/Method.java:537)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:110)
	at java.lang.Thread.run(java.base@9-internal/Thread.java:844)
RMID: shutdown()
RMID: lookupSystem() returned null after 1ms.
RMID: Destroying RMID process.
RMID: Destroy successful after 1ms.
RMID: Removing rmid's old log file.
TEST_LIBRARY: unexporting object...
TestFailedException: TEST FAILED: ; nested exception is: 
	TestFailedException: TEST FAILED: Rmid process exited with status 1 after 504ms.
TestFailedException: TEST FAILED: Rmid process exited with status 1 after 504ms.
	at TestLibrary.bomb(TestLibrary.java:121)
	at TestLibrary.bomb(TestLibrary.java:124)
	at RMID.start(RMID.java:312)
	at RMID.start(RMID.java:271)
	at RMID.restart(RMID.java:352)
	at RestartCrashedService.main(RestartCrashedService.java:175)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(java.base@9-internal/Native Method)
	at jdk.internal.reflect.NativeMethodAccessorImpl.invoke(java.base@9-internal/NativeMethodAccessorImpl.java:62)
	at jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(java.base@9-internal/DelegatingMethodAccessorImpl.java:43)
	at java.lang.reflect.Method.invoke(java.base@9-internal/Method.java:537)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:110)
	at java.lang.Thread.run(java.base@9-internal/Thread.java:844)

JavaTest Message: Test threw exception: TestFailedException: TEST FAILED: ; nested exception is: 
	TestFailedException: TEST FAILED: Rmid process exited with status 1 after 504ms.
JavaTest Message: shutting down test

STATUS:Failed.`main' threw exception: TestFailedException: TEST FAILED: ; nested exception is: TestFailedException: TEST FAILED: Rmid process exited with status 1 after 504ms.
Comments
JDK-8085192 eliminated the initial use of the "free port" anti-pattern, but there are still some tests in activation that try to restart rmid on a specific, even if that initial port has been selected from the ephemeral port range. This specific pattern was not attempted to be addressed by JDK-8085192.
07-11-2016