JDK-8200102 : NativeLibraryTest.java fails intermittently, unloaded count is not same as expected
  • Type: Bug
  • Component: core-libs
  • Sub-Component: java.lang:class_loading
  • Affected Version: 11,13,15,16
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2018-03-22
  • Updated: 2024-11-05
  • Resolved: 2020-12-08
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 11 JDK 16
11.0.27-oracleFixed 16 b28Fixed
Related Reports
Relates :  
JDK-8257996 - NativeLibraryTest.java still fails intermittently after JDK-8200102
Relates :  
JDK-8231340 - java/lang/reflect/callerCache/ReflectionCallerCacheTest.java failed with "java.lang.AssertionError: failed to satisfy condition"
Relates :  
JDK-8195695 - NativeLibraryTest.java fails w/ 'Expected unloaded=1 but got=0'
Description
java/lang/ClassLoader/nativeLibrary/NativeLibraryTest.java fails intermittently:

#section:main
----------messages:(4/199)----------
command: main -Xcheck:jni NativeLibraryTest
reason: User specified action: run main/othervm/native -Xcheck:jni NativeLibraryTest 
Mode: othervm [/othervm specified]
elapsed time (seconds): 2.248
----------configuration:(0/0)----------
----------System.out:(0/0)----------
----------System.err:(13/850)----------
java.lang.RuntimeException: Expected unloaded=4 but got=3
	at NativeLibraryTest.main(NativeLibraryTest.java:65)
	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:564)
	at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:115)
	at java.base/java.lang.Thread.run(Thread.java:842)
Comments
The test is still failing in CI - filing a new bug.
09-12-2020
Changeset: 1a9ed92d Author: Brent Christian <bchristi@openjdk.org> Date: 2020-12-08 18:01:04 +0000 URL: https://git.openjdk.java.net/jdk/commit/1a9ed92d
08-12-2020
This test assumes that a System.gc() followed by a sleep is sufficient to cause all gc-triggered actions to occur. It should be fixed to be more robust, e.g. like e.g. gcAwait ./java/util/WeakHashMap/GCDuringIteration.java:77: static void gcAwait(BooleanSupplier s) { ./java/util/concurrent/forkjoin/FJExceptionTableLeak.java:196: static void gcAwait(BooleanSupplier s) { ./java/util/concurrent/ArrayBlockingQueue/WhiteBox.java:229: static void gcAwait(BooleanSupplier s) {
21-11-2020
Here's a snippet from the log file for the jdk-16+26-1690-tier5 sighting: section:main ----------messages:(4/199)---------- command: main -Xcheck:jni NativeLibraryTest reason: User specified action: run main/othervm/native -Xcheck:jni NativeLibraryTest Mode: othervm [/othervm specified] elapsed time (seconds): 1.435 ----------configuration:(0/0)---------- ----------System.out:(0/0)---------- ----------System.err:(13/850)---------- java.lang.RuntimeException: Expected unloaded=1 but got=0 at NativeLibraryTest.main(NativeLibraryTest.java:68) 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:564) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127) at java.base/java.lang.Thread.run(Thread.java:831) JavaTest Message: Test threw exception: java.lang.RuntimeException: Expected unloaded=1 but got=0 JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Expected unloaded=1 but got=0 ----------rerun:(42/5169)*----------
21-11-2020
Here's a snippet from the log file for the jdk-16+26-1678-tier4 sighting: #section:main ----------messages:(4/195)---------- command: main -Xcheck:jni NativeLibraryTest reason: User specified action: run main/othervm/native -Xcheck:jni NativeLibraryTest Mode: othervm [/othervm specified] elapsed time (seconds): 1.265 ----------configuration:(0/0)---------- ----------System.out:(0/0)---------- ----------System.err:(13/837)---------- java.lang.RuntimeException: Expected unloaded=1 but got=0 at NativeLibraryTest.main(NativeLibraryTest.java:68) 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:564) at com.sun.javatest.regtest.agent.MainWrapper$MainThread.run(MainWrapper.java:127) at java.base/java.lang.Thread.run(Thread.java:831) JavaTest Message: Test threw exception: java.lang.RuntimeException: Expected unloaded=1 but got=0 JavaTest Message: shutting down test STATUS:Failed.`main' threw exception: java.lang.RuntimeException: Expected unloaded=1 but got=0 ----------rerun:(39/5945)*----------
20-11-2020
Just popped up in the CI tier5 as well
10-04-2019
I will try to find some time in the semi-near future.
27-02-2019
Any progress on this one? We are seeing it too.
27-02-2019
[~bchristi] you can check out http://hg.openjdk.java.net/jdk/jdk/file/tip/test/jdk/java/lang/reflect/callerCache/ReflectionCallerCacheTest.java#l143
11-05-2018
I also don't like the unconditional sleep as Martin noted. OTOH I prefer to avoid using the finalizer in GC finalization library. Could we use Cleaner? It should do the work.
28-03-2018
Brent, I think this is your cue to say, "But Martin, why haven't you made your nice GC finalization library actually reusable? Then I would surely use it!"
26-03-2018
Brent, Tobias' patch is an improvement, but doing an unconditional sleep is distasteful. My gcAwait has been battle tested (although admittedly it belongs in a test library).
24-03-2018
I'm partial to Tobias's initial suggestion for JDK-8195695: http://cr.openjdk.java.net/~thartmann/8195695/webrev.00/ I don't know that we need more rounds of gc/finalization so much as to just provide a little more time for the Cleaner thread to get scheduled and do its thing.
23-03-2018
Crazy Martin suggests reusing some of the gc finalization code from other tests: http://cr.openjdk.java.net/~martin/webrevs/jdk/NativeLibraryTest/
23-03-2018
This is not a HotSpot bug but a test problem, moving this to core-libs.
23-03-2018