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

[David Holmes]

Harold/Rachel,

Thanks for clarifying things - I had misconstrued the actual problem.

In summary we should not use a ResourceObj in the scope of a nested 
ResourceMark wrt. the allocation of the ResourceObj.

The fix is good and no further changes are needed.

Thanks,
David

On 26/10/2016 5:58 AM, harold seigel wrote:
> 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
>>
>