RFR (XS): 8167995: -Xlog:defaultmethods=debug: lengthy method descriptor triggers "StringStream is re-allocated with a different ResourceMark"

[harold seigel]

Hi Rachel,

I think that the ResourceMarks that you removed were the correct ones.  
My understanding is that based on this assert it looks like all calls to 
stringStream::write() on a particular Stream need to be done using the 
same ResourceMark with which the Stream was created.  Otherwise, this 
assert in stringStream::write() will trigger:

       assert(rm == NULL || Thread::current()->current_resource_mark() 
== rm,
              "StringStream is re-allocated with a different 
ResourceMark..." ...)

These two ResourceMarks needed to be removed because their outputStream 
was constructed with a caller's ResourceMark.  If they specified their 
own ResourceMark then their calls to print(), which eventually calls 
stringStream::write(), would cause the assert to trigger.

    static void print_slot(outputStream* str, Symbol* name, Symbol*
    signature) {
       ResourceMark rm;
       str->print("%s%s", name->as_C_string(), signature->as_C_string());
    }

    static void print_method(outputStream* str, Method* mo, bool
    with_class=true) {
       ResourceMark rm;
       if (with_class) {
         str->print("%s.", mo->klass_name()->as_C_string());
       }
       print_slot(str, mo->name(), mo->signature());
    }



I think that having a ResourceMark in code like this is okay because 
debug_stream() probably constructs a new Stream object.

       if (log_is_enabled(Debug, defaultmethods)) {
         log_debug(defaultmethods)("Slots that need filling:");
         ResourceMark rm;
         outputStream* logstream = Log(defaultmethods)::debug_stream();
         streamIndentor si(logstream);
         for (int i = 0; i < slots->length(); ++i) {
           logstream->indent();
           slots->at(i)->print_on(logstream);
           logstream->cr();
         }
       }

Harold


On 10/25/2016 11:14 AM, Rachel Protacio wrote:
> Hi,
>
> Thanks for taking a look. I think in this particular case the issue 
> was that the nested ResourceMark's were around code that affected an 
> existing outputStream. So in fact the nesting per se isn't what was 
> wrong, the issue was adding a ResourceMark in the middle of a resource 
> that still needed the content after it went out of scope of the RM. So 
> line 796 is good because its functionality is self-contained, and the 
> ones I deleted were bad because they interfered with the functionality 
> of the caller code. (Can someone corroborate this assessment?)
>
> However, as those functions still need RMs in general somewhere up the 
> line, I can add a comment of the form
>
>    // The caller of print_slot() (or one of its callers)
>    // must use a ResourceMark in order to correctly free the result.
>
> for print_slot(), print_method(), and print_on() at line 590. Does 
> that sound good?
> Rachel
>
> On 10/25/2016 1:41 AM, David Holmes wrote:
>> Hi Rachel,
>>
>> On 25/10/2016 6:17 AM, Rachel Protacio wrote:
>>> Hi,
>>>
>>> Please review this small fix, which removes two nested ResourceMark's
>>> that were causing problems with defaultmethods logging.
>>>
>>> Bug: https://bugs.openjdk.java.net/browse/JDK-8167995
>>> Open webrev: http://cr.openjdk.java.net/~rprotacio/8167995.00/
>>>
>>> Tested with JPRT.
>>
>> It is tricky to determine who has responsibility for positioning the 
>> ResourceMarks. Looking at this call chain it initially appeared to me 
>> that we now had a missing RM for the code at line #80:
>>
>> 813       slot->print_on(logstream);
>> =>
>> 590   void print_on(outputStream* str) const {
>> 591     print_slot(str, name(), signature());
>> 592   }
>> =>
>> 79 static void print_slot(outputStream* str, Symbol* name, Symbol* 
>> signature) {
>> 80   str->print("%s%s", name->as_C_string(), signature->as_C_string());
>> 81 }
>>
>> but we actually have a RM higher up at:
>>
>> 787   ResourceMark rm(THREAD);
>>
>> so that is good, but then we also have a nested ResourceMark further 
>> down:
>>
>>  795   if (log_is_enabled(Debug, defaultmethods)) {
>>  796     ResourceMark rm;
>>
>> I must admit I'm unclear if ResourceMarks should never be nested, or 
>> should be nested "carefully" - and if the latter exactly what that 
>> means and how to recognize it.
>>
>> Thanks,
>> David
>> -----
>>
>>> Thanks!
>>> Rachel
>