RFR 8187305: Add logging for shared library loads/unloads
Langer, Christoph
christoph.langer at sap.com
Thu Feb 20 17:00:22 UTC 2020
Hi Harold,
I think removing the check for Unloaded library could be one option. Or you maybe want to call System.gc()? I think the current unload mechanism is a bit indeterministic - but System.gc() would probably be better?
Anyway, yes, please open a bug for that ��
Cheers
Christoph
> -----Original Message-----
> From: Harold Seigel <harold.seigel at oracle.com>
> Sent: Donnerstag, 20. Februar 2020 17:27
> 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
>
> I think we should just remove the check for "Unloaded library ..." from
> the test. It's not testing code that is likely to break.
>
> I'll enter a bug and make the change if that's okay with you.
>
> Thanks, Harold
>
> On 2/20/2020 11:19 AM, Langer, Christoph wrote:
> > 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