PING: RFR: JDK-8145788: JVM crashes with -XX:+EnableTracing

Tue Jan 12 14:29:07 UTC 2016

Hi Markus,

Looks good!

Thanks,
Marcus

On 01/12/2016 10:34 AM, Markus Gronlund wrote:
> Thanks David and Yasumasa,
>
> I will then proceed with checking in my suggestion.
>
> Thanks again
> Markus
>
> -----Original Message-----
> From: Yasumasa Suenaga [mailto:yasuenag at gmail.com]
> Sent: den 11 januari 2016 11:09
> To: Markus Gronlund; David Holmes
> Cc: serviceability-dev at openjdk.java.net
> Subject: Re: PING: RFR: JDK-8145788: JVM crashes with -XX:+EnableTracing
>
> Hi Markus, David,
>
> I agree the solution of Markus too!
>
>
> Thanks,
>
> Yasumasa
>
>
> On 2016/01/11 18:48, Markus Gronlund wrote:
>> Hi David,
>>
>> Thanks for pointing to the locked branch as well.
>>
>> Thanks to the bootstrap aware logic in defaultStream::hold(intx writer_id) this should be ok as is:
>>
>> ttyLocker will call the hold() member function which defaults to single threaded behavior during bootstrap (DefaultStream::NOWRITER). This is accomplished by checking the availability of both ttyLock as well as Thread::current_or_null().
>>
>> Cheers
>> Markus
>>
>> -----Original Message-----
>> From: David Holmes
>> Sent: den 11 januari 2016 02:39
>> To: Markus Gronlund; Yasumasa Suenaga
>> Cc: serviceability-dev at openjdk.java.net
>> Subject: Re: PING: RFR: JDK-8145788: JVM crashes with
>> -XX:+EnableTracing
>>
>> Hi Markus,
>>
>> Thanks very much for stepping in on this one. I like your solution to this particular problem.
>>
>> Aside: I noticed in writeEvent there is also UseLockedTracing and I'm wondering if that will also lead to an assertion failure due to no current thread?
>>
>> Thanks,
>> David
>>
>> On 11/01/2016 9:25 AM, Markus Gronlund wrote:
>>> Hi Yasumasa,
>>>
>>> Apologies for the delay in getting a response to you.
>>>
>>> Thanks for reporting and attempting to fix this issue.
>>>
>>> I have investigated this a bit as well as trying out your suggested patch.
>>>
>>> I must admit it is hard to get this right at this early stage of the VM, and though I appreciated your effort for resolution, the patch suggestion will not work out of the box unfortunately.
>>>
>>> I have summarized some of my findings and reasoning here:
>>>
>>> http://cr.openjdk.java.net/~mgronlun/8145788/notes.txt
>>>
>>> As you can see, Thread::current() cannot be called at this stage. If we update to instead call Thread::current_or_null(), you will now run into problems in the interplay between an explicit delete of a Cheap allocated ResourceArea and the subsequent ResourceMark destructor. Here, the rm destructor asserts since it expects _nesting_level > 0, but that data has already been invalidated.
>>>
>>> You could accomplish all of this by doing:
>>>
>>> +    bool thread_has_resource = Thread::current_or_null() != NULL;
>>> +    ResourceArea *area = thread_has_resource
>>> +                           ? Thread::current()->resource_area()
>>> +                           : new (mtTracing)ResourceArea(Chunk::non_pool_size);
>>> +    {
>>> +      ResourceMark rm(area);
>>> +      if (UseLockedTracing) {
>>> +        ttyLocker lock;
>>> +        writeEventContent();
>>> +      } else {
>>> +        writeEventContent();
>>> +      }
>>> +    }
>>> +
>>> +    if (!thread_has_resource) {
>>> +      delete area;
>>>         }
>>>
>>>
>>> However, it is getting a bit complex. In addition, now every trace statement needs to check Thread::current_or_null()..
>>>
>>> If you look at my reasoning in the second part, I think we can fix this in an easier way.
>>>
>>> You can find my suggestion as a webrev here:
>>>
>>> http://cr.openjdk.java.net/~mgronlun/8145788/
>>>
>>> Please try the patch out to see if you are ok with it.
>>>
>>> Thanks for your patience
>>>
>>> Best regards
>>> Markus
>>>
>>>
>>>
>>> -----Original Message-----
>>> From: Yasumasa Suenaga [mailto:yasuenag at gmail.com]
>>> Sent: den 10 januari 2016 14:03
>>> To: serviceability-dev at openjdk.java.net
>>> Subject: PING: RFR: JDK-8145788: JVM crashes with -XX:+EnableTracing
>>>
>>> Ping: What do you think about this issue?
>>>
>>> On 2016/01/06 15:36, David Holmes wrote:
>>>> Pinging the serviceability tracing experts please!
>>>>
>>>> David
>>>>
>>>> On 24/12/2015 12:25 AM, Yasumasa Suenaga wrote:
>>>>> Hi David,
>>>>>
>>>>>>>          1. Initialize JavaThread before calling apply_ergo() in create_vm().
>>>>>> That is not likely to be an option - it would likely be far too
>>>>>> disruptive to the initialization sequence.
>>>>> Agree. Thus I choose 2.
>>>>>
>>>>>> We will have to wait for the tracing experts to have a good look
>>>>>> at this.
>>>>> I'm waiting that the tracing experts join this discussion.
>>>>>
>>>>>
>>>>> Thanks,
>>>>>
>>>>> Yasumasa
>>>>>
>>>>>
>>>>> On 2015/12/23 13:20, David Holmes wrote:
>>>>>> Hi Yasumasa,
>>>>>>
>>>>>> On 23/12/2015 11:49 AM, Yasumasa Suenaga wrote:
>>>>>>> Hi David,
>>>>>>>
>>>>>>> I've added callstack when JVM crashed:
>>>>>>>
>>>>>>> https://bugs.openjdk.java.net/browse/JDK-8145788?focusedCommentId
>>>>>>> =
>>>>>>> 1
>>>>>>> 3880225&page=com.atlassian.jira.plugin.system.issuetabpanels:comm
>>>>>>> e
>>>>>>> n
>>>>>>> t-tabpanel#comment-13880225
>>>>>> Thanks for that.
>>>>>>
>>>>>>> This crash occurrs in Arguments::apply_ergo() in Threads::create_vm().
>>>>>>> apply_ergo() calls before JavaThread initialization.
>>>>>>>
>>>>>>> I think that TraceEvent can avoid crash with two approach:
>>>>>>>
>>>>>>>          1. Initialize JavaThread before calling apply_ergo() in create_vm().
>>>>>> That is not likely to be an option - it would likely be far too
>>>>>> disruptive to the initialization sequence.
>>>>>>
>>>>>>>          2. Avoid crash at TraceEvent when it is called before JavaThread initialization.
>>>>>> Or don't call it at all.
>>>>>>
>>>>>> We will have to wait for the tracing experts to have a good look
>>>>>> at this. We end up in code that is not expecting to be run before
>>>>>> more of the VM is initialized, so we have to look at what else may
>>>>>> be being assumed and then decide whether to handle the situation or avoid it.
>>>>>>
>>>>>> Thanks,
>>>>>> David
>>>>>>
>>>>>>> Thanks,
>>>>>>>
>>>>>>> Yasumasa
>>>>>>>
>>>>>>>
>>>>>>> On 2015/12/22 21:19, David Holmes wrote:
>>>>>>>> On 19/12/2015 1:50 AM, Yasumasa Suenaga wrote:
>>>>>>>>> Hi all,
>>>>>>>>>
>>>>>>>>> I encountered JVM crash when I passed -XX:+EnableTracing.
>>>>>>>>>
>>>>>>>>>           I checked core image, it crashed in EventBooleanFlagChanged::writeEvent()
>>>>>>>>>           which is called by Arguments::apply_ergo() because thread had not been
>>>>>>>>>           initialized. (JVM seems to log changing GC algorithm
>>>>>>>>> to
>>>>>>>>> G1.)
>>>>>>>> This seems like a logic error to me - something is trying to
>>>>>>>> happen too early during VM initialization. We need to look at
>>>>>>>> exactly what we are trying to do here, not just work around the crash.
>>>>>>>>
>>>>>>>> David
>>>>>>>> -----
>>>>>>>>
>>>>>>>>>           writeEvent() uses ResourceMark. Default constructor of ResourceMark uses
>>>>>>>>>           ResourceArea in current thread. So ResourceMark in writeEvent() should
>>>>>>>>>           pass valid ResourceArea.
>>>>>>>>>
>>>>>>>>> I think this issue is in traceEventClasses.xsl .
>>>>>>>>> However, my environment (GCC 5.3.1 on Fedora23) cannot build it
>>>>>>>>> because -Werror=maybe-uninitialized was occurred.
>>>>>>>>> So I also fixed them together.
>>>>>>>>>
>>>>>>>>> I've uploaded webrev. Could you review it?
>>>>>>>>>
>>>>>>>>> http://cr.openjdk.java.net/~ysuenaga/JDK-8145788/webrev.00/
>>>>>>>>>
>>>>>>>>> I'm jdk9 committer, however I cannot access JPRT.
>>>>>>>>> So I need a sponsor.
>>>>>>>>>
>>>>>>>>>
>>>>>>>>> Thanks,
>>>>>>>>>
>>>>>>>>> Yasumasa
>>>>>>>>>