RFR 8187305: Add logging for shared library loads/unloads
Harold Seigel
harold.seigel at oracle.com
Thu Feb 20 16:27:13 UTC 2020
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