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

[Markus Gronlund]

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