RFR 8187305: Add logging for shared library loads/unloads

Harold Seigel harold.seigel at oracle.com
Thu Feb 20 17:07:42 UTC 2020 

I created https://bugs.openjdk.java.net/browse/JDK-8239568

Harold

On 2/20/2020 12:00 PM, Langer, Christoph wrote:
> 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