JDK-8195695 : NativeLibraryTest.java fails w/ 'Expected unloaded=1 but got=0'
  • Type: Bug
  • Component: hotspot
  • Sub-Component: compiler
  • Affected Version: 10,11
  • Priority: P4
  • Status: Resolved
  • Resolution: Fixed
  • Submitted: 2018-01-18
  • Updated: 2019-09-13
  • Resolved: 2018-02-05
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
11 b01Fixed
Related Reports
Relates :  
JDK-8200102 - NativeLibraryTest.java fails intermittently, unloaded count is not same as expected
Relates :  
JDK-8191360 - Lookup of critical JNI method causes duplicate library loading with leaking handler
Description
java/lang/ClassLoader/nativeLibrary/NativeLibraryTest.java test failed in HS PIT at least two times with the following log:

#section:main
----------messages:(4/196)----------
command: main -Xcheck:jni NativeLibraryTest
reason: User specified action: run main/othervm/native -Xcheck:jni NativeLibraryTest 
Mode: othervm [/othervm specified]
elapsed time (seconds): 83.805
----------configuration:(0/0)----------
----------System.out:(13/1213)----------
Warning: SIGHUP handler expected:libjvm.so+0x1c461b0  found:0x0000000000000001
Signal Handlers:
SIGSEGV: [libjvm.so+0x1c4c4d0], sa_mask[0]=11111111011111111111110111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGBUS: [libjvm.so+0x1c4c4d0], sa_mask[0]=11111111011111111111110111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGFPE: [libjvm.so+0x1c4c4d0], sa_mask[0]=11111111011111111111110111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGPIPE: [libjvm.so+0x1c4c4d0], sa_mask[0]=11111111011111111111110111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGXFSZ: [libjvm.so+0x1c4c4d0], sa_mask[0]=11111111011111111111110111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGILL: [libjvm.so+0x1c4c4d0], sa_mask[0]=11111111011111111111110111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIG40: [libjvm.so+0x1c4c4d0], sa_mask[0]=11111111011111111111110111111111, sa_flags=SA_RESTART|SA_SIGINFO
SIGQUIT: [libjvm.so+0x1c461b0], sa_mask[0]=11111111011111111111110111111111, sa_flags=SA_RESTART
SIGHUP: SIG_IGN, sa_mask[0]=00000000000000000000000000000000, sa_flags=none
SIGINT: [libjvm.so+0x1c461b0], sa_mask[0]=11111111011111111111110111111111, sa_flags=SA_RESTART
SIGTERM: [libjvm.so+0x1c461b0], sa_mask[0]=11111111011111111111110111111111, sa_flags=SA_RESTART
----------System.err:(13/837)----------
java.lang.RuntimeException: Expected unloaded=1 but got=0
	at NativeLibraryTest.main(NativeLibraryTest.java:64)
	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:844)

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
Comments
This is a test bug. The problem is that -Xcomp significantly slows down execution (especially on SPARC) and as a result 100 ms is not enough for unloading the native library: // give Cleaner thread a chance to unload the native library Thread.sleep(100); I've verified this by modifying the test to check again after the first failure and at this point the library was always unloaded. The fix is to wait longer: http://cr.openjdk.java.net/~thartmann/8195695/webrev.00/
01-02-2018
I can reproduce this on Solaris SPARC in 1/50 runs with "-Xcomp -XX:+CreateCoredumpOnCrash -ea -esa -XX:CompileThreshold=100 -XX:+UnlockExperimentalVMOptions -server -XX:-TieredCompilation -XX:+IgnoreUnrecognizedVMOptions -XX:+DeoptimizeALot".
01-02-2018
As mentioned in 8191360 comments at end, this error - java.lang.RuntimeException: Expected unloaded=1 but got=0 seems to be different, unrelated to 8191360. Also need to confirm if this also is not specific to -Xcomp! initial ILW = One test failure as library was not unloaded as expected; reported as intermittent, possibly present for older versions as well; None (to be checked - may be -XX:-CriticalJNINatives and related to 7013347) = MLH = P4
19-01-2018
used flags combinations: 1) -Xcomp -XX:+CreateCoredumpOnCrash -ea -esa -XX:CompileThreshold=100 -XX:+UnlockExperimentalVMOptions -server -XX:-TieredCompilation -XX:+IgnoreUnrecognizedVMOptions -XX:+DeoptimizeALot 2) -Xcomp -XX:+CreateCoredumpOnCrash -ea -esa -XX:CompileThreshold=100 -XX:+UnlockExperimentalVMOptions -server -XX:-TieredCompilation -XX:+IgnoreUnrecognizedVMOptions -XX:+AggressiveOpts -XX:-UseCompressedOops
18-01-2018