RFR 8187305: Add logging for shared library loads/unloads

Langer, Christoph christoph.langer at sap.com
Thu Feb 20 16:19:49 UTC 2020


Hi Harold,

hm, it's not a platform issue. It even occurs on linuxx86_64. But maybe it is related to the fact that our test setup is different from what one does in make run-test. Maybe the test VM uses a larger heap and hence doesn't trigger a gc?

Best regards
Christoph

> -----Original Message-----
> From: Harold Seigel <harold.seigel at oracle.com>
> Sent: Donnerstag, 20. Februar 2020 17:15
> To: Langer, Christoph <christoph.langer at sap.com>
> Cc: hotspot-runtime-dev at openjdk.java.net; Baesken, Matthias
> <matthias.baesken at sap.com>; Thomas Stüfe <thomas.stuefe at gmail.com>
> Subject: Re: RFR 8187305: Add logging for shared library loads/unloads
> 
> Hi Christoph,
> 
> The test expects that gc will run and unload the class loader that
> loaded the shared library.  This should cause the shared library to get
> unloaded and generate the "Unloaded library ..." message.
> 
> I guess either the check for the "Unloaded library ..." message should
> be removed or at least removed for certain platforms?
> 
> Harold
> 
> On 2/20/2020 10:54 AM, Langer, Christoph wrote:
> > Hi Harold,
> >
> > after your change we see errors in the test
> (runtime/logging/loadLibraryTest/LoadLibraryTest.java) across several
> platforms:
> >
> > ----------System.err:(50/4412)----------
> >   stdout: [[0.054s][info][library] Failed to find JNI_OnLoad_net in library
> with handle 0x00000fff8ab7d670
> > [0.054s][info][library] Loaded library
> /priv/jvmtests/output_openjdk15_dev_optU_linuxppc64/sapjvm_15/lib/lib
> net.so, handle 0x0000000010394c60
> > [0.054s][info][library] Found JNI_OnLoad in library with handle
> 0x0000000010394c60
> > [0.054s][info][library] Found inet_pton in library with handle
> 0x0000000000000000
> > [0.054s][info][library] Failed to find JNI_OnLoad_nio in library with handle
> 0x00000fff8ab7d670
> > [0.055s][info][library] Loaded library
> /priv/jvmtests/output_openjdk15_dev_optU_linuxppc64/sapjvm_15/lib/lib
> nio.so, handle 0x00000000103954e0
> > [0.055s][info][library] Found JNI_OnLoad in library with handle
> 0x00000000103954e0
> > [0.055s][info][library] Failed to find Java_sun_nio_ch_IOUtil_initIDs in
> library with handle 0x0000000010394c60
> > [0.055s][info][library] Found Java_sun_nio_ch_IOUtil_initIDs in library with
> handle 0x00000000103954e0
> > [0.055s][info][library] Failed to find Java_sun_nio_ch_IOUtil_iovMax in
> library with handle 0x0000000010394c60
> > [0.055s][info][library] Found Java_sun_nio_ch_IOUtil_iovMax in library
> with handle 0x00000000103954e0
> > [0.055s][info][library] Failed to find
> Java_sun_nio_ch_FileChannelImpl_initIDs in library with handle
> 0x0000000010394c60
> > [0.055s][info][library] Found Java_sun_nio_ch_FileChannelImpl_initIDs in
> library with handle 0x00000000103954e0
> > [0.055s][info][library] Failed to find
> Java_sun_nio_ch_FileDispatcherImpl_init in library with handle
> 0x0000000010394c60
> > [0.055s][info][library] Found Java_sun_nio_ch_FileDispatcherImpl_init in
> library with handle 0x00000000103954e0
> > [0.056s][info][library] Failed to find Java_sun_nio_ch_NativeThread_init in
> library with handle 0x0000000010394c60
> > [0.056s][info][library] Found Java_sun_nio_ch_NativeThread_init in library
> with handle 0x00000000103954e0
> > [0.056s][info][library] Failed to find
> Java_sun_nio_ch_NativeThread_current in library with handle
> 0x0000000010394c60
> > [0.056s][info][library] Found Java_sun_nio_ch_NativeThread_current in
> library with handle 0x00000000103954e0
> > [0.056s][info][library] Failed to find
> Java_sun_nio_ch_FileDispatcherImpl_size0 in library with handle
> 0x0000000010394c60
> > [0.056s][info][library] Found Java_sun_nio_ch_FileDispatcherImpl_size0 in
> library with handle 0x00000000103954e0
> > [0.062s][info][library] Failed to find
> Java_sun_nio_ch_FileChannelImpl_map0 in library with handle
> 0x0000000010394c60
> > [0.062s][info][library] Found Java_sun_nio_ch_FileChannelImpl_map0 in
> library with handle 0x00000000103954e0
> > [0.064s][info][library] Failed to find JNI_OnLoad_LoadLibraryClass in library
> with handle 0x00000fff8ab7d670
> > [0.064s][info][library] Failed to find JNI_OnLoad_LoadLibraryClass in library
> with handle 0x00000fff8ab7d670
> > [0.099s][info][library] Loaded library
> /priv/jvmtests/output_openjdk15_dev_optU_linuxppc64/grmpf/testdata/jt
> reg/jtreg_test_15/test/hotspot/jtreg/native/libLoadLibraryClass.so, handle
> 0x0000000010399d30
> > [0.099s][info][library] Failed to find JNI_OnLoad in library with handle
> 0x0000000010399d30
> > [0.100s][info][library] Found Java_LoadLibraryClass_nTest in library with
> handle 0x0000000010399d30
> > [0.116s][info][library] Failed to find
> Java_sun_nio_ch_FileChannelImpl_unmap0 in library with handle
> 0x0000000010394c60
> > [0.116s][info][library] Found Java_sun_nio_ch_FileChannelImpl_unmap0 in
> library with handle 0x00000000103954e0
> > ];
> >   stderr: []
> >   exitValue = 0
> >
> > java.lang.RuntimeException: 'Unloaded library with handle' missing from
> stdout/stderr
> >
> > Seems like the class unloading mechanism doesn't trigger in the end.
> >
> > The test failure also happens only for opt builds. Debug builds look fine.
> >
> > Do you have any idea how the test can be improved?
> >
> > Thanks
> > Christoph
> >
> >> -----Original Message-----
> >> From: hotspot-runtime-dev <hotspot-runtime-dev-
> >> bounces at openjdk.java.net> On Behalf Of Harold Seigel
> >> Sent: Dienstag, 18. Februar 2020 21:27
> >> To: Thomas Stüfe <thomas.stuefe at gmail.com>
> >> Cc: hotspot-runtime-dev at openjdk.java.net; Baesken, Matthias
> >> <matthias.baesken at sap.com>
> >> Subject: Re: RFR 8187305: Add logging for shared library loads/unloads
> >>
> >> Hi Thomas,
> >>
> >> Thanks for pointing this out.
> >>
> >> The fix for JDK-8187305
> >> <https://bugs.openjdk.java.net/browse/JDK-8187305> also includes
> logging
> >> for JVM_UnloadLibrary() and JVM_FindLibraryEntry().  So the two fixes do
> >> not completely overlap.  Is it confusing to keep both sets of logging?
> >> Or, should the JVM_UnloadLibrary() and JVM_FindLibraryEntry() be
> moved
> >> into platform dependent code?
> >>
> >> Thanks,  Harold
> >>
> >> On 2/18/2020 3:04 PM, Thomas Stüfe wrote:
> >>> Hi Harold,
> >>>
> >>> First off, thanks a lot for doing this!
> >>>
> >>> Unfortunately, our wires got crossed with this. Matthias already added
> >>> tracing for shared library loading with "8228902: add os::dll_load to
> >>> the unified logging os category". He did not know about this issue and
> >>> therefore did not update it.
> >>>
> >>> So arguably this issue is a duplicate of 8229802 and should have been
> >>> closed when 8229802 was pushed.
> >>>
> >>> His solution is somewhat more complete since he also reports errors
> >>> and error details when a library could not be loaded. Since he does
> >>> tracing in platform dependent code he has more information to trace.
> >>>
> >>> But he did not add tests, and I like your tests and it would be nice
> >>> to have them.
> >>>
> >>> Just a proposal, but one possibility would be to remove your tracing
> >>> from jvm.cpp and change the category of the existing tracing Matthias
> >>> did to your new category "library". And use the tests to test the
> >>> existing tracing. What do you think?
> >>>
> >>> Sorry again for the confusion and the redundant work!
> >>>
> >>> Cheers, Thomas
> >>>
> >>>
> >>>
> >>>
> >>>
> >>> On Fri, Feb 14, 2020 at 2:37 PM Harold Seigel
> >>> <harold.seigel at oracle.com <mailto:harold.seigel at oracle.com>> wrote:
> >>>
> >>>      Thanks David!
> >>>
> >>>      I'll use "driver" mode the next time I write a logging test.
> >>>
> >>>      Harold
> >>>
> >>>      On 2/13/2020 5:26 PM, David Holmes wrote:
> >>>      > Hi Harold,
> >>>      >
> >>>      > Looks good.
> >>>      >
> >>>      > Minor nit, in the test you could use "driver" mode.
> >>>      >
> >>>      > Thanks,
> >>>      > David
> >>>      >
> >>>      > On 14/02/2020 7:22 am, Harold Seigel wrote:
> >>>      >> Hi,
> >>>      >>
> >>>      >> Please review this small fix to add logging to loading, unloading,
> >>>      >> and finding entries in shared libraries.
> >>>      >>
> >>>      >> Open Webrev:
> >>>      >>
> >> http://cr.openjdk.java.net/~hseigel/bug_8187305/webrev/index.html
> >>>      >>
> >>>      >> JBS Bug: https://bugs.openjdk.java.net/browse/JDK-8187305
> >>>      >>
> >>>      >> The fix was regression tested by running Mach5 tiers 1 and 2 tests
> >>>      >> and builds on Linux-x64, Solaris, Windows, and Mac OS X, by
> >>>      running
> >>>      >> Mach5 tiers 3-5 tests on Linux-x64, and JCK lang and VM tests on
> >>>      >> Linux-x64.
> >>>      >>
> >>>      >> Thanks, Harold
> >>>      >>
> >>>


More information about the hotspot-runtime-dev mailing list