AllocationRequiringGC stacktrace precision

[Erik Gahlin]

> On 20 Jun 2019, at 17:54, Milan Mimica <milan.mimica at gmail.com> wrote:
> 
> Hi Markus
> 
> I didn't succeed to reproduce this in a simple program.
> 
> But while examining the code I found something suspicious (and
> unrelated to this topic) that I want to check. In
> ObjectMonitor::enter, there is
> JfrConditionalFlushWithStacktrace. It *unconditionally* creates the
> stack trace and stores in a thread-local.
> 
> JfrConditionalFlushWithStacktrace(Thread* t) :
> JfrConditionalFlush<Event>(t), _t(t), _owner(false) {
>    if (Event::has_stacktrace() && jfr_has_stacktrace_enabled(Event::eventId)) {
>        _owner = jfr_save_stacktrace(t);
> 
> this "if" here statically evaluates to "true". Now, I don't know how
> ObjectMonitor works, or why is the stack trace stored at this point,
> but to me it looks like a "jfr_is_event_enabled(Event::eventId)" is
> missing here.

Yes, It could be added at the end. 

Both default.jfc and profile.jfc however have the event enabled by default, but with a threshold, so the stack trace will only be taken if it is a longer latency. Adding the check will only benefit people who make their own configuration and opt-out of stack traces.

The reason for the flush mechanism, is to prevent JFR from writing to disk (due buffers being flushed) when we have the monitor. If the buffer is soon to be filled, it is flushed before.

Erik


> Is this stack-trace of any use if the event is not enabled? Is it just
> a waste of CPU?
> 
> 
> On Fri, 14 Jun 2019 at 00:17, Markus Gronlund
> <markus.gronlund at oracle.com> wrote:
>> 
>> Hi Milan,
>> 
>> Would you be able to create a small reproducer that demonstrates this behavior you are seeing?
>> 
>> It would help a lot.
>> 
>> Thanks in advance
>> Markus
>> 
>> 
>> -----Original Message-----
>> From: Milan Mimica <milan.mimica at gmail.com>
>> Sent: den 13 juni 2019 21:33
>> To: hotspot-jfr-dev at openjdk.java.net
>> Subject: AllocationRequiringGC stacktrace precision
>> 
>> Hello List
>> 
>> I've been using JFR Java API to track allocations that are of interests to me. I'm focused on large allocations that trigger AllocationRequiringGC event. I came across this event I can't explain:
>> 
>> This is the top of the stack trace
>> (jdk.jfr.consumer.RecordedStackTrace#getFrames):
>> at java.lang.Integer#valueOf line: 1050
>> 
>> and jdk.jfr.consumer.RecordedObject#getValue("size") says it allocated about 8MB.
>> 
>> Happened using version 11.0.3, with G1.
>> This makes me wonder how reliable the stack-traces that come with events are? I've been looking at hotspot code and I would say that the java thread is blocked while waiting for allocation and it's safe to take a snapshot of its stack. I'm I missing something?
>> 
>> 
>> --
>> Milan Mimica
> 
> 
> 
> -- 
> Milan Mimica