RFR: 8138916: Logging write function does not allow for long enough messages

Wed Nov 4 19:59:12 UTC 2015

Looks good!

Regards,
Marcus

On 2015-11-04 20:49, Rachel Protacio wrote:
> Updated webrev with this fgets change: 
> http://cr.openjdk.java.net/~rprotacio/8139564.04/
>
> Passes JPRT tests.
>
> Thank you,
> Rachel
>
> On 11/4/2015 4:59 AM, Marcus Larsson wrote:
>> Hmm, I just noticed that the test doesn't null terminate the string 
>> it reads from file. Replacing the fgetc loop with a call to fgets 
>> should fix this.
>>
>> Regards,
>> Marcus
>>
>>
>> On 2015-11-04 10:49, Marcus Larsson wrote:
>>> Looks good, thank you for fixing this!
>>>
>>> Regards,
>>> Marcus
>>>
>>>
>>> On 2015-11-02 19:03, Rachel Protacio wrote:
>>>> Thanks for the comments, Marcus. I've undone the "logtest" tag and 
>>>> instead created an InternalVMTest in log.cpp that writes the 
>>>> 518-character string to a temporary file and looks for it there. 
>>>> Using "logging" tag in the "develop" level. Testing succeeds.
>>>>
>>>> Webrev: http://cr.openjdk.java.net/~rprotacio/8139564.03/
>>>>
>>>> Thank you,
>>>> Rachel
>>>>
>>>> On 10/29/2015 6:35 AM, Marcus Larsson wrote:
>>>>> 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
>>>>>>>>
>>>>>>>
>>>>>>
>>>>>
>>>>
>>>
>>
>