Event descriptions are truncated in logs

[David Holmes]

Hi Yasumasa,

I have to agree with Thomas, full dynamic buffer management is just too 
costly and risky to always use in these cases. Also agree about not 
using os::malloc et al. A static buffer with dynamic fallback if needed 
might be okay - though if the static buffer is rarely big enough then 
that won't help.

David

On 8/06/2018 6:02 AM, Thomas Stüfe wrote:
> 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
>>>>>
>>