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

Wed Nov 4 19:49:38 UTC 2015

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
>>>>>>>
>>>>>>
>>>>>
>>>>
>>>
>>
>