RFR[9u-dev]: 8151442: jstack doesn't close quotation marks properly with threads' name greater than 1996 characters

[Kevin Walls]

Hi

I didn't think of %.XXXXs when Cheleswer and I discussed this briefly.  
I'd like to have suggested that, with the idea that the 2k long thread 
name is extreme, and it's so important that we preserve the format of 
the output, and keep that closing quote, even if we lost some of the 
thread name.  We currently and probably always have truncated such 
names, the problem that triggered this was mainly that the format was 
broken.

As there are several places we pass the name to the stream and could hit 
the length limit, should we have a THREAD_NAME_FORMAT defined for such 
use instead of using %s though the actual length can't be 1996, it's 
BUFLEN minus whatever else we expect to be printed in the same print 
call.  We might guess as low as 1024?

(Retaining one st->print() also minimises any risk of concurrent prints 
jumbling up the output.)

Thanks
Kevin


On 21/03/2016 21:24, David Holmes wrote:
> On 22/03/2016 2:31 AM, Daniel D. Daugherty wrote:
>> On 3/21/16 2:39 AM, Dmitry Samersoff wrote:
>>> David,
>>>
>>>> I still see %.Ns as the simplest solution - but whatever.
>>> It spreads artificial limitation of thread name length across hotspot
>>> sources.
>>>
>>> Brief grepping[1] shows couple of other places with the same problem 
>>> and
>>> if some days we decide to change default O_BUFLEN, we have to not 
>>> forget
>>> to change .N value in couple of places as well.
>>
>> There should be a way to pass the precision value as a parameter instead
>> of hardcoding it in the format string. Something like:
>>
>>      sprintf("%.*s", precision_value, string);
>
> Yes the length limit can be passed as a variable. But I think Dmitry 
> just wants to allow for unlimited lengths. Not sure how to achieve 
> that at the lowest level though as we need to avoid complex 
> allocations etc in these print routines.
>
> David
>
>
>> Dan
>>
>>>
>>> 1.
>>> ./share/vm/prims/jni.cpp
>>> 673: "in thread \"%s\" ", thread->get_thread_name());
>>>
>>> ./share/vm/runtime/thread.cpp
>>> 1766: get_thread_profiler()->print(get_thread_name());
>>> 1974: get_thread_profiler()->print(get_thread_name());
>>> 2896: st->print("\"%s\" ", get_thread_name());
>>> 2926: st->print("%s", get_thread_name_string(buf, buflen));
>>> 2932: st->print("JavaThread \"%s\"", get_thread_name_string(buf,
>>> buflen));
>>>
>>>
>>> ./share/vm/services/threadService.cpp
>>> 882: ... st->print_cr("\"%s\":", currentThread->get_thread_name());
>>> 919: ..."%s \"%s\"", owner_desc, currentThread->get_thread_name());
>>> 932: ... st->print_cr("\"%s\":", currentThread->get_thread_name());
>>>
>>> -Dmitry
>>>
>>>
>>> On 2016-03-19 00:37, David Holmes wrote:
>>>>
>>>> On 18/03/2016 11:28 PM, Dmitry Samersoff wrote:
>>>>> David,
>>>>>
>>>>>> Ignoring Dmitry's issue it still seems simpler/cleaner to just 
>>>>>> add the
>>>>>> desired precision value to the %s than to split into two print
>>>>>> statements. Or bite the bullet now and make the length immaterial by
>>>>>> breaking the name into chunks. It's as easy to fix as to write the
>>>>>> RFE :)
>>>>> For this particular case the simplest solution is to use print_raw:
>>>>>
>>>>> print_raw("\""\"); print_raw(get_thread_name()); print_raw("\""\");
>>>> I still see %.Ns as the simplest solution - but whatever.
>>>>
>>>>> But as soon as print() finally ends up with:
>>>>>
>>>>> const int written = vsnprintf(buffer, buflen, format, ap);
>>>>> ...
>>>>> DEBUG_ONLY(warning("increase O_BUFLEN in ostream.hpp -- output
>>>>> truncated");)
>>>>>
>>>>> Complete fix should be something like:
>>>>>
>>>>> int desired_size = vsnprintf(NULL, 0, format, ap);
>>>>> if (desired_size > O_BUFLEN) {
>>>>>       malloc
>>>>>       ....
>>>>> }
>>>>>
>>>>> but it has performance penalty, so we should use some tricks to cover
>>>>> most common %s/%d/%p cases.
>>>> So you want to remove the internal limitation instead of have the
>>>> clients deal with it? Not sure it is worth the effort - IIRC that code
>>>> can be used at sensitive times hence the simple approach to buffer
>>>> management.
>>>>
>>>> David
>>>>
>>>>> -Dmitry
>>>>>
>>>>>
>>>>>
>>>>>
>>>>> On 2016-03-18 15:51, David Holmes wrote:
>>>>>> On 18/03/2016 10:03 PM, Cheleswer Sahu wrote:
>>>>>>> Hi David,
>>>>>>>
>>>>>>> -----Original Message-----
>>>>>>> From: David Holmes
>>>>>>> Sent: Friday, March 18, 2016 2:42 PM
>>>>>>> To: Cheleswer Sahu; hotspot-runtime-dev at openjdk.java.net;
>>>>>>> serviceability-dev at openjdk.java.net
>>>>>>> Subject: Re: RFR[9u-dev]: 8151442: jstack doesn't close quotation
>>>>>>> marks properly with threads' name greater than 1996 characters
>>>>>>>
>>>>>>> On 18/03/2016 5:54 PM, Cheleswer Sahu wrote:
>>>>>>>> Hi,
>>>>>>>>
>>>>>>>> Please review the code changes for
>>>>>>>> https://bugs.openjdk.java.net/browse/JDK-8151442.
>>>>>>>>
>>>>>>>> Webrev Link: http://cr.openjdk.java.net/~csahu/8151442/
>>>>>>>>
>>>>>>>> Bug Brief:
>>>>>>>>
>>>>>>>> In jstack thread dumps , thread name greater than 1996 characters
>>>>>>>> doesn't close quotation marks properly.
>>>>>>> Anyone giving a thread a name that long deserves to get a core 
>>>>>>> dump!
>>>>>>> ;-)
>>>>>>>
>>>>>>>> Problem Identified:
>>>>>>>>
>>>>>>>> Jstack is using below code to print thread name
>>>>>>>>
>>>>>>>> src/share/vm/runtime/thread.cpp
>>>>>>>>
>>>>>>>> void JavaThread::print_on(outputStream *st) const {
>>>>>>>>
>>>>>>>>       st->print("\"%s\" ", get_thread_name());
>>>>>>>>
>>>>>>>> Here "st->print()"  internally uses max buffer length as O_BUFLEN
>>>>>>>> (2000).
>>>>>>>>
>>>>>>>> void
>>>>>>>> outputStream::do_vsnprintf_and_write_with_automatic_buffer(const
>>>>>>>> char* format, va_list ap, bool add_cr) {
>>>>>>>>
>>>>>>>>       char buffer[O_BUFLEN];
>>>>>>>>
>>>>>>>> do_vsnprintf_and_write_with_automatic_buffer() finally calls
>>>>>>>>      "vsnprintf()"  which truncates the anything greater than the
>>>>>>>> max
>>>>>>>> size(2000). In this case thread's name(> 1996) along with 
>>>>>>>> quotation
>>>>>>>> marks (2)
>>>>>>>>
>>>>>>>> plus one terminating character exceeds the  max buffer size 
>>>>>>>> (2000),
>>>>>>>> therefore the closing quotation  marks gets truncated.
>>>>>>>>
>>>>>>>> Solution:
>>>>>>>>
>>>>>>>> Split the  "st->print("\"%s\" ", get_thread_name())" in two
>>>>>>>> statements
>>>>>>>>
>>>>>>>> 1.st->print("\"%s", get_thread_name());
>>>>>>>>
>>>>>>>> 2.st->print("\" ");
>>>>>>>>
>>>>>>>> This will ensure presence of closing quotation mark always.
>>>>>>> Can't we just limit the number of characters read by %s?
>>>>>>>
>>>>>>> Yes we can do it, but just one thing which I think of is, if the
>>>>>>> truncation of output inside  output stream issue get resolves as
>>>>>>> Dmritry suggested or O_BUFFLEN size gets increased in any  
>>>>>>> future fix
>>>>>>> then we have to again make changes in this code, as limiting the 
>>>>>>> no.
>>>>>>> of character read by %s will give truncated output . In such case
>>>>>>> present fix will have no effect.
>>>>>> Ignoring Dmitry's issue it still seems simpler/cleaner to just 
>>>>>> add the
>>>>>> desired precision value to the %s than to split into two print
>>>>>> statements. Or bite the bullet now and make the length immaterial by
>>>>>> breaking the name into chunks. It's as easy to fix as to write the
>>>>>> RFE :)
>>>>>>
>>>>>> David
>>>>>>
>>>>>>> David
>>>>>>>
>>>>>>>> Regards,
>>>>>>>>
>>>>>>>> Cheleswer
>>>>>>>>
>>>>>
>>>
>>