JDK-8030616 : sun/management/jmxremote/bootstrap/RmiBootstrapTest fails intermittently with cannot find a free port
  • Type: Bug
  • Component: core-svc
  • Sub-Component: javax.management
  • Affected Version: 8,9,18,20
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2013-12-17
  • Updated: 2023-08-10
  • Resolved: 2022-10-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 20
20 b21Fixed
Related Reports
Relates :  
Relates :  
Relates :  
Description
TESTFAIL:sun/management/jmxremote/bootstrap/RmiBootstrapTest.sh

sun/management/jmxremote/bootstrap/RmiBootstrapTest.sh 

This test reported fail intermittently due to "port already in use" error (JDK-7195249), but following failure is not "port already in use", and similar intermittent failure is likely to happen on windows.

-------------------------------------------------------------
Launching test for RmiBootstrapTest
-------------------------------------------------------------
C:/Users/aurora/sandbox/jdk/bin/java -ea -esa -Xmx512m -Dtest.src=C:/Users/aurora/sandbox/gresults/testoutput/jdk_management/JTwork/classes/sun/management/jmxremote/bootstrap -classpath C:/Users/aurora/sandbox/gresults/testoutput/jdk_management/JTwork/classes/sun/management/jmxremote/bootstrap RmiBootstrapTest
***
*** Testing configuration (port=56350): C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\management_test01_ok.properties
***
Communication succeeded as expected for no credentials: found 1MBean
Configuration C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\management_test01_ok.properties successfully tested
***
*** Testing configuration (port=56351): C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\management_test02_ok.properties
***
***
*** Testing configuration (port=56352): C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\management_test04_ok.properties
***
***
*** Testing configuration (port=56353): C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\management_test06_ok.properties
***
Test Failed: 4
processed file: C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\jmxremote_test02_ok.access
processed file: C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\jmxremote_test02_ok.password
processed file: C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\jmxremote_test04_ok.access
processed file: C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\jmxremote_test04_ok.password
processed file: C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\jmxremote_test05_ko.access
processed file: C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\jmxremote_test05_ko.password
processed file: C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\jmxremote_test06_ok.password
processed file: C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\management_test01_ok.properties
processed file: C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\management_test02_ok.properties
processed file: C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\management_test03_ko.properties
processed file: C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\management_test04_ok.properties
processed file: C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\management_test05_ko.properties
processed file: C:\\Users\\aurora\\sandbox\\gresults\\testoutput\\jdk_management\\JTwork\\classes\\sun\\management\\jmxremote\\bootstrap\\management_test06_ok.properties
----------System.err:(0/0)----------
Comments
Changeset: 8b010e01 Author: Jaikiran Pai <jpai@openjdk.org> Date: 2022-10-21 08:29:09 +0000 URL: https://git.openjdk.org/jdk/commit/8b010e014c44ffb728b7a8343d3298466f5252fa
21-10-2022

A pull request was submitted for review. URL: https://git.openjdk.org/jdk/pull/10322 Date: 2022-09-18 11:52:28 +0000
18-09-2022

Moved this comment here from JDK-8293657: Daniel Daugherty added a comment - 2 days ago Here's a log file snippet from the jdk-20+15-989-tier3 sighting: sun/management/jmxremote/bootstrap/RmiBootstrapTest.java#id1 *** Testing configuration (port=49163): /System/Volumes/Data/mesos/work_dir/slaves/0c72054a-24ab-4dbb-944f-97f9341a1b96-S86760/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/18748bbd-1c4c-4382-8c6c-58c8ff5ca377/runs/b6f04c2c-813f-43fc-bb17-c9b6500739c5/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/0/sun/management/jmxremote/bootstrap/RmiBootstrapTest_id1.d/management_ssltest07_ok.properties *** Test Failed: Failed: cannot find a free port after 10 tries ----------System.err:(1/39)---------- Cannot find a free port after 10 tries ----------rerun:(39/7228)*----------
14-09-2022

(Moved the following 2 comments from https://bugs.openjdk.org/browse/JDK-8293657 to here) I had a brief look at the code involved in this test. I suspect there might be a (socket) leak in these tests. The `RmiBootstrapTest` has 2 test definitions. Each of these test definition uses test specific configuration files and then for each file goes on to run individual tests. From what I can see, `RmiBootstrapTest_id0` will pick up a total of 6 configuration files and `RmiBootstrapTest_id1` will pick up a total of 10 configuration files. To keep it simple, I'm going to focus just on `RmiBootstrapTest_id1` in this assessment. For each of these 10 configuration files, the test ultimately picks up a "free port" and then ends up (essentially) doing: int port = // find free port // set it as a system property System.setProperty("com.sun.management.jmxremote.port", Integer.toString(port)); ... final JMXConnectorServer cs; try { cs = ConnectorBootstrap.initialize(); ... } finally { try { cs.stop(); } catch (Exception x) { final String err = "Failed to terminate: " + x; log.trace("testConfiguration", err); log.debug("testConfiguration", x); } } At first look this looks OK, because you do a JMXConnectorServer.stop() in the finally block. However, looking at the implementation of ConnectorBootstrap.initialize() and comments in ConnectorBootstrap, internally what is does it, it also ends up creating a "registry" which is a static field and has this note: // The variable below is here to support stop functionality. // It would be overwritten if you call startRemoteConnectorServer second // time. It's OK for now as logic in Agent.java forbids multiple agents. private static Registry registry = null; This registry is backed by a RMI port which can be configured through a different "com.sun.management.jmxremote.rmi.port" system property (notice this is not the system property we set). But that's fine, in the absence of a system property value it picks up a random port that's available and binds the registry to it. So each test (with a configuration file) will end up creating/using 2 ports. The important point to remember here is that every since call to ConnectorBootstrap.initialize(); will lead to an instance of "registry" being created and overwriting any previous instance of the (JVM level static member) "registry" and thus leaking the previous instance. You would expect the call to "cs.stop()" in the test case to close this registry too, but it doesn't and there's even a warning on the "registry" field which states this field will get overwritten, but that warning additional states it's OK since Agent.java forbids multiple agents. However, in the current flow, I don't see Agent.java playing any role other than loading the configuration files and thus there's no checks to verify that the "registry" is set only once. The test documentation states that: * Test the configuration indicated by `file'. * Sets the appropriate System properties for config file and * port and then calls ConnectorBootstrap.initialize(). * eventually cleans up by calling ConnectorBootstrap.terminate(). I don't see any terminate() API available on ConnectorBootstrap nor does the test call any such API. I'm not too familiar with these APIs, so I'm unsure how to cleanup/stop/close that "registry" cleanup on each test configuration run. Perhaps ConnectorBootstrap.unexportRegistry()? Or maybe launch one process for each test configuration file, so that the "registry" doesn't get overwritten? So I'm guessing that with a total of around 16 configuration files across these definitions, we are potentially leaking 16 (RMI port backed) "registry" sockets, perhaps? This is just based on what I see in the code (I haven't spent time on trying to compare this theory with the failure data that's collected in these runs), so I may have missed some details or come to an incorrect conclusion, but I can't think of any other reason why this test consistently can't find a free port after 10 attempts.
14-09-2022

This test was recently converted from being launched through a .sh to a proper Java jtreg test as part of https://bugs.openjdk.org/browse/JDK-8292067. I had a look at the previous .sh scripts to see if they too had this similar issue and it looks like those scripts used to launch the test without any arguments and each single run of a test would then use all 16 test configuration files (in a single JVM) and then run those tests. So they too were susceptible to this issue as noted in this JBS issue.
14-09-2022

Here's a log file snippet for the jdk-18+31-2034-tier3 sighting: sun/management/jmxremote/bootstrap/RmiBootstrapTest.sh ------------------------------------------------------------- Launching test for RmiBootstrapTest ------------------------------------------------------------- /System/Volumes/Data/mesos/work_dir/jib-master/install/jdk-18+31-2034/macosx-x64.jdk/jdk-18.jdk/Contents/Home/bin/java -Xmx768m -XX:MaxRAMPercentage=4.16667 -Djava.io.tmpdir=/System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/tmp -ea -esa -Dtest.src=/System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d -classpath /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d:/System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/test/lib --add-exports jdk.management.agent/jdk.internal.agent=ALL-UNNAMED --add-exports jdk.management.agent/sun.management.jmxremote=ALL-UNNAMED RmiBootstrapTest *** *** Testing configuration (port=65533): /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/management_test04_ok.properties *** PasswordFileName: /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/jmxremote_test04_ok.password accessFileName: /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/jmxremote_test04_ok.access Connection failed as expected for no credentials: java.lang.SecurityException: Authentication failed! Credentials required Connection failed as expected for {modify, R&D}: java.lang.SecurityException: Authentication failed! Invalid username or password Connection failed as expected for {measure, QED}: java.lang.SecurityException: Authentication failed! Invalid username or password Connection failed as expected for {bad.user, R&D}: java.lang.SecurityException: Authentication failed! Invalid username or password Connection failed as expected for {measure, bad.password}: java.lang.SecurityException: Authentication failed! Invalid username or password Configuration /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/management_test04_ok.properties successfully tested *** *** Testing configuration (port=49153): /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/management_test02_ok.properties *** *** *** Testing configuration (port=49154): /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/management_test02_ok.properties *** *** *** Testing configuration (port=49155): /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/management_test02_ok.properties *** *** *** Testing configuration (port=49156): /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/management_test02_ok.properties *** *** *** Testing configuration (port=49157): /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/management_test02_ok.properties *** *** *** Testing configuration (port=49158): /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/management_test02_ok.properties *** *** *** Testing configuration (port=49159): /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/management_test02_ok.properties *** *** *** Testing configuration (port=49160): /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/management_test02_ok.properties *** *** *** Testing configuration (port=49161): /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/management_test02_ok.properties *** *** *** Testing configuration (port=49162): /System/Volumes/Data/mesos/work_dir/slaves/c82600aa-2448-475c-8c08-6f02a5b3f3af-S1576/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/ec8a0239-e78d-4cf1-b57a-bd763b636abe/runs/7ceb0172-bd91-4157-9e70-dd04bf2ed1a4/testoutput/test-support/jtreg_open_test_jdk_tier3/classes/2/sun/management/jmxremote/bootstrap/RmiBootstrapTest.d/management_test02_ok.properties *** Test Failed: Failed: cannot find a free port after 10 tries ----------System.err:(1/39)---------- Cannot find a free port after 10 tries ----------rerun:(31/4279)*----------
06-01-2022

The issue was that a hard coded port was used, the fix of 7195249 must fix this issue, it used Utils.getFreePort() to have a free port. Let's re-open the bug if we see again the failure.
13-03-2014

ILW=MLH=P4, Medium impact as yet more unstable and noisy tests, low likelihood of individual failure, no known workaround.
18-12-2013