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

[Cheleswer Sahu]

Hi ,

I would like to go with the "print_raw()" option as this can print any length of thread name. I have modified the code and written a test case also for this bug. Please review the code changes from the below link 

http://cr.openjdk.java.net/~csahu/8151442/webrev.01/ 

Regards,
Cheleswer

-----Original Message-----
From: Mattis Castegren 
Sent: Wednesday, March 30, 2016 10:42 PM
To: Kevin Walls; David Holmes; Daniel Daugherty; Dmitry Samersoff; Cheleswer Sahu; hotspot-runtime-dev at openjdk.java.net; serviceability-dev at openjdk.java.net
Cc: Mattis Castegren
Subject: RE: RFR[9u-dev]: 8151442: jstack doesn't close quotation marks properly with threads' name greater than 1996 characters

Hi

It seems there are two approaches here, either we truncate long thread names, or we make sure to print the full thread name.

I agree with Dmitry and Kirk that if the API allows these long names, the tooling should do the right thing (even though one has to wonder what these long names are).

I suggest we move ahead with the print_raw approach.

If we believe there should be a limit in the Thread name lenghts, I suggest we file a new bug for that.

Kind Regards
/Mattis

-----Original Message-----
From: Kevin Walls 
Sent: den 24 mars 2016 21:06
To: David Holmes; Daniel Daugherty; Dmitry Samersoff; 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


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(cons
>>>>>>>> t
>>>>>>>> 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
>>>>>>>>
>>>>>
>>>
>>