Event descriptions are truncated in logs

Thomas Stüfe thomas.stuefe at gmail.com
Thu Jun 7 20:02:12 UTC 2018


Hi Yasumasa,

Sorry, but I have some general concerns about this:

1 Event logging, AFAIK, should be fast. Before, we had a pre-allocated
fixed sized character array into which the event text was written.
Now, we potentially malloc and realloc as a part of logging an event.
  It also should be robust, and malloc may fail in case of low-memory.

2 I do not really like the use of os::malloc etc there. Event logging
seems like a bottom component and I would hate to see circular
dependencies. os::malloc is a monster, it does UL logging, NMT tracing
etc...

(1) is tough - would want to know what others think.
(2) could be easily solved by using raw malloc/realloc.

One possibility to alleviate (1) would be to do a two buffer strategy.
A fixed sized dynamic member array, which is by definition
preallocated, for 99% of all cases. If that is not enough, fallback to
a dynamically allocated buffer.

Code wise, at first cursory glance I think that the realloc strategy
could be done a bit smoother (e.g. realloc increase sizes by factor
2). Also, I am not sure that FormatBufferDynamic would need to
implement all the method the standard FormatBuffer has? Seems an awful
lot of code duplication.

Thanks & Best Regards, Thomas




On Thu, Jun 7, 2018 at 3:20 PM, Yasumasa Suenaga <yasuenag at gmail.com> wrote:
> Thanks David!
> I filed it to JBS:
>
>   https://bugs.openjdk.java.net/browse/JDK-8204551
>
> I concern how we should fix for Windows.
> I'm waiting for opinion from you and other OpenJDK developers :-)
>
>
> Yasumasa
>
>
>
> On 2018/06/07 22:01, David Holmes wrote:
>>
>> Sorry Yasumasa this one slipped through the cracks - as we say.
>>
>> By all means file a bug to record the issue. I'll try to take a look at it
>> over the next couple of working days.
>>
>> David
>>
>> On 7/06/2018 10:49 PM, Yasumasa Suenaga wrote:
>>>
>>> Hi,
>>>
>>> Have you ever checked event strings in hs_err or VM.info?
>>> Please see as below!
>>>
>>>
>>> Yasumasa
>>>
>>>
>>> On 2018/05/01 9:41, Yasumasa Suenaga wrote:
>>>>
>>>> Hi all,
>>>>
>>>> I found event description in hs_error log and VM.info dcmd are trucated
>>>> as following:
>>>>
>>>> ```
>>>> Event: 1.977 Thread 0x00007f1720010800 Exception <a
>>>> 'java/lang/IncompatibleClassChangeError'{0x00000000d7a338f0}: Found class
>>>> java.lang.Object, but interface was expected> (0x00000000d7a338f0) thrown at
>>>> [/scratch/opt/mach5/mesos/work_dir/slaves/9190d864-6621-4810-ba08-d8d8c75ba674-S702/framewo
>>>> ```
>>>>
>>>> I think we can fix it as this webrev. Is it acceptable?
>>>> If so, I will file it to JBS and send review request.
>>>>
>>>>    http://cr.openjdk.java.net/~ysuenaga/event-msg-truncated/
>>>>
>>>> This webrev shows event description as following:
>>>>
>>>> ```
>>>> Event: 3.660 Thread 0x00007fa174018800 Exception <a
>>>> 'java/lang/NoSuchMethodError'{0x00000000d778f878}:
>>>> java.lang.invoke.DirectMethodHandle$Holder.invokeInterface(Ljava/lang/Object;Ljava/lang/Object;Ljava/lang/Object;)V>
>>>> (0x00000000d778f878) thrown at
>>>> [/home/ysuenaga/OpenJDK/jdk/src/hotspot/share/interpreter/linkResolver.cpp,
>>>> line 755]
>>>> ```
>>>>
>>>> But I concern this change might not work when HotSpot is built with VS
>>>> 2013 or earlier.
>>>> This change uses vsnprintf() to get length of string, but _vscprintf()
>>>> will be used when older Visual Studio is used to build.
>>>>
>>>>
>>>> Thanks,
>>>>
>>>> Yasumasa
>>>>
>


More information about the hotspot-runtime-dev mailing list