JDK-8261483 : jdk/dynalink/TypeConverterFactoryMemoryLeakTest.java failed with "AssertionError: Should have GCd a method handle by now"
  • Type: Bug
  • Component: core-libs
  • Sub-Component: jdk.nashorn
  • Affected Version: 11.0.22-oracle,17
  • Priority: P3
  • Status: Resolved
  • Resolution: Fixed
  • OS: generic
  • CPU: x86_64
  • Submitted: 2021-02-10
  • Updated: 2023-09-06
  • Resolved: 2021-03-02
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 13 JDK 16 JDK 17
13.0.7Fixed 16.0.1Fixed 17 b12Fixed
Related Reports
Duplicate :  
Relates :  
Sub Tasks
JDK-8261604 :  
Description
The following test failed in the JDK17 CI:

jdk/dynalink/TypeConverterFactoryMemoryLeakTest.java

Here's a snippet from the log file:

#section:main
----------messages:(5/195)----------
command: main TypeConverterFactoryMemoryLeakTest
reason: Assumed action based on file name: run main TypeConverterFactoryMemoryLeakTest 
Mode: agentvm
Agent id: 20
elapsed time (seconds): 15.013
----------configuration:(11/1282)----------
Boot Layer
  class path: /opt/mach5/mesos/work_dir/jib-master/install/jtreg/5.1/b01/bundles/jtreg_bin-5.1.zip/jtreg/lib/javatest.jar 
              /opt/mach5/mesos/work_dir/jib-master/install/jtreg/5.1/b01/bundles/jtreg_bin-5.1.zip/jtreg/lib/jtreg.jar 
              /opt/mach5/mesos/work_dir/jib-master/install/jtreg/5.1/b01/bundles/jtreg_bin-5.1.zip/jtreg/lib/junit.jar 
              /opt/mach5/mesos/work_dir/jib-master/install/jtreg/5.1/b01/bundles/jtreg_bin-5.1.zip/jtreg/lib/testng.jar 
  patch:      java.base /opt/mach5/mesos/work_dir/slaves/983c483a-6907-44e0-ad29-98c7183575e2-S77111/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/a9a6618d-3a73-4285-824e-1e6a5c1f410a/runs/68255266-df36-4ecf-bede-fc1fd8e95629/testoutput/test-support/jtreg_open_test_jdk_tier2_part2/patches/java.base

Test Layer
  class path: /opt/mach5/mesos/work_dir/slaves/983c483a-6907-44e0-ad29-98c7183575e2-S77111/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/a9a6618d-3a73-4285-824e-1e6a5c1f410a/runs/68255266-df36-4ecf-bede-fc1fd8e95629/testoutput/test-support/jtreg_open_test_jdk_tier2_part2/classes/0/jdk/dynalink/TypeConverterFactoryMemoryLeakTest.d
              /opt/mach5/mesos/work_dir/jib-master/install/jdk-17+9-650/src.full/open/test/jdk/jdk/dynalink

----------rerun:(30/4745)*----------

<snip>

----------System.err:(12/764)----------
java.lang.AssertionError: Should have GCd a method handle by now
	at TypeConverterFactoryMemoryLeakTest.main(TypeConverterFactoryMemoryLeakTest.java:88)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:298)
	at java.base/java.lang.Thread.run(Thread.java:831)

JavaTest Message: Test threw exception: java.lang.AssertionError
JavaTest Message: shutting down test

result: Failed. Execution failed: `main' threw exception: java.lang.AssertionError: Should have GCd a method handle by now

Starting this one as a P3 since this is a Tier2 failure.
Comments
Changeset: d185a6c5 Author: Attila Szegedi <attila@openjdk.org> Date: 2021-03-02 12:25:25 +0000 URL: https://git.openjdk.java.net/jdk/commit/d185a6c5
02-03-2021

Yeah, my patch linked above fixes both tests. I'm having trouble attracting reviewers, though…
24-02-2021

Here's a snippet from the log file for the jdk-17+11-777-tier2 sighting: jdk/dynalink/TypeConverterFactoryRetentionTests.java #section:main ----------messages:(5/194)---------- command: main TypeConverterFactoryRetentionTests reason: Assumed action based on file name: run main TypeConverterFactoryRetentionTests Mode: agentvm Agent id: 6 elapsed time (seconds): 15.015 ----------configuration:(11/1283)---------- Boot Layer class path: /opt/mach5/mesos/work_dir/jib-master/install/jtreg/5.1/b01/bundles/jtreg_bin-5.1.zip/jtreg/lib/javatest.jar /opt/mach5/mesos/work_dir/jib-master/install/jtreg/5.1/b01/bundles/jtreg_bin-5.1.zip/jtreg/lib/jtreg.jar /opt/mach5/mesos/work_dir/jib-master/install/jtreg/5.1/b01/bundles/jtreg_bin-5.1.zip/jtreg/lib/junit.jar /opt/mach5/mesos/work_dir/jib-master/install/jtreg/5.1/b01/bundles/jtreg_bin-5.1.zip/jtreg/lib/testng.jar patch: java.base /opt/mach5/mesos/work_dir/slaves/983c483a-6907-44e0-ad29-98c7183575e2-S14608/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/be188230-6f99-477d-b4d2-89f3421f91ce/runs/c6065120-3432-4441-a872-5ba50b571906/testoutput/test-support/jtreg_open_test_jdk_tier2_part2/patches/java.base Test Layer class path: /opt/mach5/mesos/work_dir/slaves/983c483a-6907-44e0-ad29-98c7183575e2-S14608/frameworks/1735e8a2-a1db-478c-8104-60c8b0af87dd-0196/executors/be188230-6f99-477d-b4d2-89f3421f91ce/runs/c6065120-3432-4441-a872-5ba50b571906/testoutput/test-support/jtreg_open_test_jdk_tier2_part2/classes/3/jdk/dynalink/TypeConverterFactoryRetentionTests.d /opt/mach5/mesos/work_dir/jib-master/install/jdk-17+11-777/src.full/open/test/jdk/jdk/dynalink ----------rerun:(30/4757)*---------- <snip> ----------System.err:(14/991)---------- java.lang.AssertionError: Should have GCd a class loader by now at TypeConverterFactoryRetentionTests.testFromOneClassToClassLoader(TypeConverterFactoryRetentionTests.java:151) at TypeConverterFactoryRetentionTests.testSystemLoaderToOtherLoader(TypeConverterFactoryRetentionTests.java:116) at TypeConverterFactoryRetentionTests.main(TypeConverterFactoryRetentionTests.java:98) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:78) at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.base/java.lang.reflect.Method.invoke(Method.java:566) at com.sun.javatest.regtest.agent.MainActionHelper$AgentVMRunnable.run(MainActionHelper.java:298) at java.base/java.lang.Thread.run(Thread.java:831) JavaTest Message: Test threw exception: java.lang.AssertionError
19-02-2021

The following fix was integrated a few build-IDs before this intermittent failure started happening: JDK-8198540 Dynalink leaks memory when generating type converters JDK-8198540 was integrated in jdk-17+9-644 and the Tier2 test failure first happened in jdk-17+9-650 which is three Tier2 job sets later. [~attila] - can you please look at this intermittent failure?
19-02-2021

https://github.com/openjdk/jdk/pull/2617/files is up for review.
17-02-2021

Aleksey Shipilev also found this happens on a busy CI server. I'll increase the timeout and specify the tests to be run in a separate VM with a very low maximum heap in order to trigger GC earlier. FWIW, I have found that the minimum that works is 2049k (2MB + 1kB). It's a fun boundary; if you specify: 2047k: "Error occurred during initialization of VM; Too small maximum heap" 2048k: "Error occurred during initialization of VM; GC triggered before VM initialization completed." 2049k: both tests run. To be on the safe side, I'll give them 4M.
17-02-2021