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

[Markus Gronlund]

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:commen
>>>> 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
>>>>>>