[prev in list] [next in list] [prev in thread] [next in thread] 

List:       openjdk-serviceability-dev
Subject:    Re: RFR: 8138916: Logging write function does not allow for long enough messages
From:       Marcus Larsson <marcus.larsson () oracle ! com>
Date:       2015-10-29 10:35:26
Message-ID: 5631F66E.8090601 () oracle ! com
[Download RAW message or body]

Hi,

On 2015-10-28 21:59, Rachel Protacio wrote:
> Including serviceability-dev. Recap:
>
> Summary: In logging/log.hpp, the logging vwrite function previously 
> asserted that the buffer remains within 512 characters, which is
> too short for logging message of non-pre-determined length, e.g. for 
> vtable and itable function names. Now, the function resizes the buffer
> to the appropriate length, asserting only that the resulting buffer is 
> valid. Includes tag "logtest" to test that logging can print an output
> of 518 characters.
>
> Open webrev: http://cr.openjdk.java.net/~rprotacio/8138916.02
> Bug: https://bugs.openjdk.java.net/browse/JDK-8138916

I don't like that the test log message is included in the product, or 
that a completely new tag is introduced for it.

I think a much better approach would be to do the test logging in an 
internal VM test, reusing the logging tag. This way it won't be logged 
unless we are actually testing stuff, and we don't introduce a new tag. 
Also it would look better if it were logged on develop level.

Thanks,
Marcus

>
> Includes own acceptance test, and passes JPRT and remote hotspot/test 
> tests.
>
> Thank you,
> Rachel
>
> On 10/28/2015 4:08 PM, Rachel Protacio wrote:
>> Thanks for the review and all the feedback!
>> Rachel
>>
>> On 10/28/2015 4:05 PM, Dmitry Samersoff wrote:
>>> Rachel,
>>>
>>> Looks good for me!
>>>
>>> -Dmitry
>>>
>>> On 2015-10-28 20:50, Rachel Protacio wrote:
>>>> Thank you both. I've removed the re-declaration and added 
>>>> prefix_len to
>>>> newbuf_len. As for line 115, that line is not for the sake of
>>>> recalculating prefix_len, but for writing the prefix to the buffer.
>>>>
>>>> http://cr.openjdk.java.net/~rprotacio/8138916.02/
>>>>
>>>> Thanks,
>>>> Rachel
>>>>
>>>> On 10/28/2015 12:27 PM, Coleen Phillimore wrote:
>>>>> Dmitry, Thank you for reviewing and providing comments.  The second
>>>>> version is better because of these things that I didn't notice until
>>>>> you pointed it out.
>>>>>
>>>>> The malloc won't be frequent.  I think it'll be okay and follows 
>>>>> other
>>>>> coding patterns in the jvm.
>>>>>
>>>>> Thanks!
>>>>> Coleen
>>>>>
>>>>> On 10/28/15 12:09 PM, Dmitry Samersoff wrote:
>>>>>> Coleen,
>>>>>>
>>>>>> OK. I'm leaving it in good hands ;)
>>>>>>
>>>>>> -Dmitry
>>>>>>
>>>>>> On 2015-10-28 18:54, Coleen Phillimore wrote:
>>>>>>> Hi, I'm also reviewing this.   I think this looks good.   I 
>>>>>>> don't think
>>>>>>> the solution to allocate a static buffer is very nice because it 
>>>>>>> still
>>>>>>> has limits and we don't want to allocate something large on the 
>>>>>>> stack.
>>>>>>> The malloc case is the infrequent case.  If it becomes frequent 
>>>>>>> we can
>>>>>>> increase LogBufferSize from 512.
>>>>>>>
>>>>>>> I think 111 the assert is good because if the windows code is 
>>>>>>> wrong (or
>>>>>>> the vscprintf does something wrong an unexpected) we can catch the
>>>>>>> error
>>>>>>> with the assert before writing over memory.
>>>>>>>
>>>>>>> I agree 116 shouldn't redeclare 'ret'.
>>>>>>>
>>>>>>> Otherwise, I think it looks really good and I don't need to see 
>>>>>>> another
>>>>>>> revision.
>>>>>>>
>>>>>>> Thanks!
>>>>>>> Coleen
>>>>>>>
>>>>>>>
>>>>>>> On 10/28/15 11:40 AM, Dmitry Samersoff wrote:
>>>>>>>> Rachel,
>>>>>>>>
>>>>>>>> On 2015-10-28 17:48, Rachel Protacio wrote:
>>>>>>>>> Thank you for the comments, both Dmitry and Mikael. Replies 
>>>>>>>>> inline.
>>>>>>>>>
>>>>>>>>> Modified webrev: 
>>>>>>>>> http://cr.openjdk.java.net/~rprotacio/8138916.01/
>>>>>>>> 111 Assert is never happens on Windows, so it's better to move 
>>>>>>>> it to
>>>>>>>> os_posix
>>>>>>>>
>>>>>>>> 113 newbuf_len doesn't account prefix_len
>>>>>>>>
>>>>>>>> 115 you may consider to use pre-calculated at ll. 108 prefix 
>>>>>>>> rather
>>>>>>>> than
>>>>>>>> calculate it again.
>>>>>>>>
>>>>>>>> 116 int ret redefined it causes a warning.
>>>>>>>>
>>>>>>>> -Dmitry
>>>>>>>>
>>>>>>>>
>>>>>>>>> (Retested and works fine.)
>>>>>>>>>
>>>>>>>>> On 10/27/2015 7:52 AM, Dmitry Samersoff wrote:
>>>>>>>>>> Rachel,
>>>>>>>>>>
>>>>>>>>>> In worst case (windows, overflow) the code would parse format 
>>>>>>>>>> string
>>>>>>>>>> four times.
>>>>>>>>> You're right. I've added a check. New amount of times 
>>>>>>>>> vnsprintf() is
>>>>>>>>> called:
>>>>>>>>> posix, fits => 1
>>>>>>>>> posix, overflow => 2
>>>>>>>>> windows, fits => 1
>>>>>>>>> windows, overflow => 3 (the best performance we can get)
>>>>>>>>>
>>>>>>>>>> Also NEW_C_HEAP_ARRAY takes a lock and might become a
>>>>>>>>>> performance bottleneck.
>>>>>>>>>>
>>>>>>>>>> POSIX equivalent of _vscprintf(fmt, args) is vsnprintf(NULL, 
>>>>>>>>>> 0, fmt,
>>>>>>>>>> args)
>>>>>>>>>>
>>>>>>>>>> So it might be better to create os::log_vcprintf(fmt, args), 
>>>>>>>>>> then
>>>>>>>>>> write
>>>>>>>>>> code at log.hpp as:
>>>>>>>>>>
>>>>>>>>>> int buf_len = os::log_vcprintf(fmt, args);
>>>>>>>>>> assert(buf_len < 2*page_size, "Stack overflow in logging");
>>>>>>>>>> char buf[buf_len];
>>>>>>>>>> vsprintf(buf, fmt, args);
>>>>>>>>> I don't think this would work anyway. A char[] needs a static 
>>>>>>>>> size.
>>>>>>>>> Thanks,
>>>>>>>>> Rachel
>>>>>>>>>> -Dmitry
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>>
>>>>>>>>>> On 2015-10-26 23:58, Rachel Protacio wrote:
>>>>>>>>>>> Hello, all,
>>>>>>>>>>>
>>>>>>>>>>> Please review this fix to the faulty write function from the
>>>>>>>>>>> Unified
>>>>>>>>>>> Logging framework.
>>>>>>>>>>>
>>>>>>>>>>> Summary: In logging/log.hpp, the logging vwrite function 
>>>>>>>>>>> previously
>>>>>>>>>>> asserted that the buffer remains within 512 characters, 
>>>>>>>>>>> which is
>>>>>>>>>>> too
>>>>>>>>>>> short for logging message of non-pre-determined length, e.g. 
>>>>>>>>>>> for
>>>>>>>>>>> vtable
>>>>>>>>>>> and itable function names. Now, the function resizes the buffer
>>>>>>>>>>> to the
>>>>>>>>>>> appropriate length, asserting only that the resulting buffer is
>>>>>>>>>>> valid.
>>>>>>>>>>> Includes tag "logtest" to test that logging can print an output
>>>>>>>>>>> of 518
>>>>>>>>>>> characters.
>>>>>>>>>>>
>>>>>>>>>>> Open webrev:http://cr.openjdk.java.net/~rprotacio/8138916/
>>>>>>>>>>> Bug:https://bugs.openjdk.java.net/browse/JDK-8138916
>>>>>>>>>>>
>>>>>>>>>>> Includes own acceptance test, and passes JPRT and remote
>>>>>>>>>>> hotspot/test
>>>>>>>>>>> tests.
>>>>>>>>>>>
>>>>>>>>>>> Thank you,
>>>>>>>>>>> Rachel
>>>
>>
>

[prev in list] [next in list] [prev in thread] [next in thread]