[9] RFR(S): 8153527: break_tty_lock_for_safepoint causes "assert(false) failed: bad tag in log" and broken compile log

[Vladimir Kozlov]

On 4/20/16 12:56 PM, Nils Eliasson wrote:
> Hi,
>
> Thanks for the help,
>
> I got it to work, and added NoSafePointVerifiers to make sure I hadn't
> missed anything. Then after many test iterations it failed again. It
> didn't fail on the NSPV, but in dump_asm we blocked on a VM entry to get
> a ciSymbol->as_utf8. Now I am considering if I should direct dump_asm to
> the temporary buffer too, or relax the tag checks in the xml and accept
> that the output may need to be sorted by writer-thread before use. The
> output looks like:
>
> <writer id=1/>
> <print_optoassembly>
> ...
> releases tty when blocking on a safepoint
> <writer id=2/>
> <print_nmethod>
> ...
> <writer id=1/>         // back again after safepoint writing without
> ttylock now.
> </print_optoassembly>  // Here we fail on an assert today when we expect
> a closing print_nmethod tag
> <writer id=2/>
> </print_nmethod>
>
> This is malformed xml but has enough information to be reconstructed.
> Would this be an acceptable output?

Yes, I think it is acceptable - we don't loose information. And it is 
not worse than it was before.

Thanks,
Vladimir

>
> Regards,
> Nils
>
>
> On 2016-04-18 19:30, Vladimir Kozlov wrote:
>> tty would have the same problem but it use C_HEAP to allocate:
>>
>>     defaultStream::instance = new(ResourceObj::C_HEAP, mtInternal)
>> defaultStream();
>>
>> Please, look if you can do something similar.
>>
>> Thanks,
>> Vladimir
>>
>> On 4/18/16 4:24 AM, Nils Eliasson wrote:
>>> Resizeable is better, but then we assert on expanding the stringbuffer
>>> while being under a different ResourceMark.
>>>
>>> Regards,
>>> Nils
>>>
>>> On 2016-04-15 19:44, Vladimir Kozlov wrote:
>>>> Use resizable stream:
>>>>
>>>> stringStream(size_t initial_bufsize = 256);
>>>>
>>>> 1024 may not be enough.
>>>>
>>>> Thanks,
>>>> Vladimir
>>>>
>>>> On 4/15/16 8:10 AM, Nils Eliasson wrote:
>>>>> Hi,
>>>>>
>>>>> Please review this fix of print opto_assembly.
>>>>>
>>>>> Summary:
>>>>> The compilelog can get corrupted and the VM may assert on "failed:
>>>>> bad tag in log".
>>>>>
>>>>> When printing assembly in output.cpp we first take the ttylock, print
>>>>> the head and then the method metadata. However the
>>>>> metadata printing makes a vm entry and may block for a safepoint and
>>>>> will then release the lock
>>>>> (break_tty_lock_for_safepoint). After that some of the other compiler
>>>>> thread that haven't safepointed will take the lock
>>>>> and the broken log will be a fact when the safepoint is over and the
>>>>> first thread starts logging again.
>>>>>
>>>>> Solution:
>>>>> Print the method metadata to a temporary buffer, then take the tty
>>>>> lock.
>>>>>
>>>>> Testing:
>>>>> Repro from bug stops failing.
>>>>> Running :hotspot_all
>>>>> (http://jdash.se.oracle.com/rbt/rbt-nils.eliasson-compiler_control-20160415-1508-10854)
>>>>>
>>>>>
>>>>>
>>>>> Bug: https://bugs.openjdk.java.net/browse/JDK-8153527
>>>>> Webrev: http://cr.openjdk.java.net/~neliasso/8153527/webrev.01/
>>>>>
>>>>> Regards,
>>>>> Nils Eliasson
>>>
>