diff --git a/substratevm/src/com.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/JfrGCEventSupport.java b/substratevm/src/com.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/JfrGCEventSupport.java index 5c6e9f2bdb4c..73b00fd8dec5 100644 --- a/substratevm/src/com.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/JfrGCEventSupport.java +++ b/substratevm/src/com.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/JfrGCEventSupport.java @@ -66,21 +66,20 @@ public int stopGCPhasePause() { } @Uninterruptible(reason = "Accesses a JFR buffer.") - public void emitGarbageCollectionEvent(UnsignedWord gcEpoch, GCCause cause, long start) { - if (JfrEvent.GarbageCollection.shouldEmit(start)) { - long pauseTime = JfrTicks.elapsedTicks() - start; - + public void emitGarbageCollectionEvent(UnsignedWord gcEpoch, GCCause cause, long startTicks) { + long duration = JfrTicks.duration(startTicks); + if (JfrEvent.GarbageCollection.shouldEmit(duration)) { JfrNativeEventWriterData data = StackValue.get(JfrNativeEventWriterData.class); JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data); JfrNativeEventWriter.beginSmallEvent(data, JfrEvent.GarbageCollection); - JfrNativeEventWriter.putLong(data, start); - JfrNativeEventWriter.putLong(data, pauseTime); + JfrNativeEventWriter.putLong(data, startTicks); + JfrNativeEventWriter.putLong(data, duration); JfrNativeEventWriter.putLong(data, gcEpoch.rawValue()); JfrNativeEventWriter.putLong(data, gcName.getId()); JfrNativeEventWriter.putLong(data, cause.getId()); - JfrNativeEventWriter.putLong(data, pauseTime); // sum of pause - JfrNativeEventWriter.putLong(data, pauseTime); // longest pause + JfrNativeEventWriter.putLong(data, duration); // sum of pause + JfrNativeEventWriter.putLong(data, duration); // longest pause JfrNativeEventWriter.endSmallEvent(data); } } @@ -88,14 +87,14 @@ public void emitGarbageCollectionEvent(UnsignedWord gcEpoch, GCCause cause, long @Uninterruptible(reason = "Accesses a JFR buffer.") public void emitGCPhasePauseEvent(UnsignedWord gcEpoch, int level, String name, long startTicks) { JfrEvent event = getGCPhasePauseEvent(level); - if (event.shouldEmit(startTicks)) { - long end = JfrTicks.elapsedTicks(); + long duration = JfrTicks.duration(startTicks); + if (event.shouldEmit(duration)) { JfrNativeEventWriterData data = StackValue.get(JfrNativeEventWriterData.class); JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data); JfrNativeEventWriter.beginSmallEvent(data, event); JfrNativeEventWriter.putLong(data, startTicks); - JfrNativeEventWriter.putLong(data, end - startTicks); + JfrNativeEventWriter.putLong(data, duration); JfrNativeEventWriter.putEventThread(data); JfrNativeEventWriter.putLong(data, gcEpoch.rawValue()); JfrNativeEventWriter.putString(data, name); @@ -112,15 +111,15 @@ public void emitGCPhasePauseEvent(UnsignedWord gcEpoch, int level, String name, private static JfrEvent getGCPhasePauseEvent(int level) { switch (level) { case 0: - return JfrEvent.GCPhasePauseEvent; + return JfrEvent.GCPhasePause; case 1: - return JfrEvent.GCPhasePauseLevel1Event; + return JfrEvent.GCPhasePauseLevel1; case 2: - return JfrEvent.GCPhasePauseLevel2Event; + return JfrEvent.GCPhasePauseLevel2; case 3: - return JfrEvent.GCPhasePauseLevel3Event; + return JfrEvent.GCPhasePauseLevel3; case 4: - return JfrEvent.GCPhasePauseLevel4Event; + return JfrEvent.GCPhasePauseLevel4; default: throw VMError.shouldNotReachHere("GC phase pause level must be between 0 and 4."); } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrEvent.java index 51d264e631d6..d315af251a8e 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrEvent.java @@ -34,47 +34,49 @@ * IDs depend on the JDK version (see metadata.xml file) and are computed at image build time. */ public final class JfrEvent { - public static final JfrEvent ThreadStart = create("jdk.ThreadStart"); - public static final JfrEvent ThreadEnd = create("jdk.ThreadEnd"); - public static final JfrEvent ThreadCPULoad = create("jdk.ThreadCPULoad"); - public static final JfrEvent DataLoss = create("jdk.DataLoss"); - public static final JfrEvent ClassLoadingStatistics = create("jdk.ClassLoadingStatistics"); - public static final JfrEvent InitialEnvironmentVariable = create("jdk.InitialEnvironmentVariable"); - public static final JfrEvent InitialSystemProperty = create("jdk.InitialSystemProperty"); - public static final JfrEvent JavaThreadStatistics = create("jdk.JavaThreadStatistics"); - public static final JfrEvent JVMInformation = create("jdk.JVMInformation"); - public static final JfrEvent OSInformation = create("jdk.OSInformation"); - public static final JfrEvent PhysicalMemory = create("jdk.PhysicalMemory"); - public static final JfrEvent ExecutionSample = create("jdk.ExecutionSample"); - public static final JfrEvent NativeMethodSample = create("jdk.NativeMethodSample"); - public static final JfrEvent GarbageCollection = create("jdk.GarbageCollection"); - public static final JfrEvent GCPhasePauseEvent = create("jdk.GCPhasePause"); - public static final JfrEvent GCPhasePauseLevel1Event = create("jdk.GCPhasePauseLevel1"); - public static final JfrEvent GCPhasePauseLevel2Event = create("jdk.GCPhasePauseLevel2"); - public static final JfrEvent GCPhasePauseLevel3Event = create("jdk.GCPhasePauseLevel3"); - public static final JfrEvent GCPhasePauseLevel4Event = create("jdk.GCPhasePauseLevel4"); - public static final JfrEvent SafepointBegin = create("jdk.SafepointBegin"); - public static final JfrEvent SafepointEnd = create("jdk.SafepointEnd"); - public static final JfrEvent ExecuteVMOperation = create("jdk.ExecuteVMOperation"); - public static final JfrEvent JavaMonitorEnter = create("jdk.JavaMonitorEnter"); - public static final JfrEvent ThreadPark = create("jdk.ThreadPark"); - public static final JfrEvent JavaMonitorWait = create("jdk.JavaMonitorWait"); - public static final JfrEvent JavaMonitorInflate = create("jdk.JavaMonitorInflate"); - public static final JfrEvent ObjectAllocationInNewTLAB = create("jdk.ObjectAllocationInNewTLAB"); - public static final JfrEvent GCHeapSummary = create("jdk.GCHeapSummary"); + public static final JfrEvent ThreadStart = create("jdk.ThreadStart", false); + public static final JfrEvent ThreadEnd = create("jdk.ThreadEnd", false); + public static final JfrEvent ThreadCPULoad = create("jdk.ThreadCPULoad", false); + public static final JfrEvent DataLoss = create("jdk.DataLoss", false); + public static final JfrEvent ClassLoadingStatistics = create("jdk.ClassLoadingStatistics", false); + public static final JfrEvent InitialEnvironmentVariable = create("jdk.InitialEnvironmentVariable", false); + public static final JfrEvent InitialSystemProperty = create("jdk.InitialSystemProperty", false); + public static final JfrEvent JavaThreadStatistics = create("jdk.JavaThreadStatistics", false); + public static final JfrEvent JVMInformation = create("jdk.JVMInformation", false); + public static final JfrEvent OSInformation = create("jdk.OSInformation", false); + public static final JfrEvent PhysicalMemory = create("jdk.PhysicalMemory", false); + public static final JfrEvent ExecutionSample = create("jdk.ExecutionSample", false); + public static final JfrEvent NativeMethodSample = create("jdk.NativeMethodSample", false); + public static final JfrEvent GarbageCollection = create("jdk.GarbageCollection", true); + public static final JfrEvent GCPhasePause = create("jdk.GCPhasePause", true); + public static final JfrEvent GCPhasePauseLevel1 = create("jdk.GCPhasePauseLevel1", true); + public static final JfrEvent GCPhasePauseLevel2 = create("jdk.GCPhasePauseLevel2", true); + public static final JfrEvent GCPhasePauseLevel3 = create("jdk.GCPhasePauseLevel3", true); + public static final JfrEvent GCPhasePauseLevel4 = create("jdk.GCPhasePauseLevel4", true); + public static final JfrEvent SafepointBegin = create("jdk.SafepointBegin", true); + public static final JfrEvent SafepointEnd = create("jdk.SafepointEnd", true); + public static final JfrEvent ExecuteVMOperation = create("jdk.ExecuteVMOperation", true); + public static final JfrEvent JavaMonitorEnter = create("jdk.JavaMonitorEnter", true); + public static final JfrEvent ThreadPark = create("jdk.ThreadPark", true); + public static final JfrEvent JavaMonitorWait = create("jdk.JavaMonitorWait", true); + public static final JfrEvent JavaMonitorInflate = create("jdk.JavaMonitorInflate", true); + public static final JfrEvent ObjectAllocationInNewTLAB = create("jdk.ObjectAllocationInNewTLAB", false); + public static final JfrEvent GCHeapSummary = create("jdk.GCHeapSummary", false); private final long id; private final String name; + private final boolean hasDuration; @Platforms(Platform.HOSTED_ONLY.class) - public static JfrEvent create(String name) { - return new JfrEvent(name); + public static JfrEvent create(String name, boolean hasDuration) { + return new JfrEvent(name, hasDuration); } @Platforms(Platform.HOSTED_ONLY.class) - private JfrEvent(String name) { + private JfrEvent(String name, boolean hasDuration) { this.id = JfrMetadataTypeLibrary.lookupPlatformEvent(name); this.name = name; + this.hasDuration = hasDuration; } @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) @@ -89,11 +91,18 @@ public String getName() { @Uninterruptible(reason = "Prevent races with VM operations that start/stop recording.", callerMustBe = true) public boolean shouldEmit() { - return SubstrateJVM.get().isRecording() && SubstrateJVM.get().isEnabled(this) && !SubstrateJVM.get().isCurrentThreadExcluded(); + assert !hasDuration; + return shouldEmit0(); } @Uninterruptible(reason = "Prevent races with VM operations that start/stop recording.", callerMustBe = true) - public boolean shouldEmit(long startTicks) { - return shouldEmit() && JfrTicks.elapsedTicks() - startTicks > SubstrateJVM.get().getThreshold(this); + public boolean shouldEmit(long durationTicks) { + assert hasDuration; + return shouldEmit0() && durationTicks >= SubstrateJVM.get().getThresholdTicks(this); + } + + @Uninterruptible(reason = "Prevent races with VM operations that start/stop recording.", callerMustBe = true) + private boolean shouldEmit0() { + return SubstrateJVM.get().isRecording() && SubstrateJVM.get().isEnabled(this) && !SubstrateJVM.get().isCurrentThreadExcluded(); } } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrThreadLocal.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrThreadLocal.java index 6721e6994293..ceb662091ee1 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrThreadLocal.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrThreadLocal.java @@ -33,6 +33,7 @@ import org.graalvm.word.UnsignedWord; import org.graalvm.word.WordFactory; +import com.oracle.svm.core.JavaMainWrapper; import com.oracle.svm.core.SubstrateUtil; import com.oracle.svm.core.Uninterruptible; import com.oracle.svm.core.UnmanagedMemoryUtil; @@ -42,6 +43,7 @@ import com.oracle.svm.core.sampler.SamplerBuffer; import com.oracle.svm.core.sampler.SamplerSampleWriterData; import com.oracle.svm.core.thread.JavaThreads; +import com.oracle.svm.core.thread.PlatformThreads; import com.oracle.svm.core.thread.Target_java_lang_Thread; import com.oracle.svm.core.thread.ThreadListener; import com.oracle.svm.core.thread.VMOperation; @@ -49,8 +51,6 @@ import com.oracle.svm.core.threadlocal.FastThreadLocalLong; import com.oracle.svm.core.threadlocal.FastThreadLocalObject; import com.oracle.svm.core.threadlocal.FastThreadLocalWord; -import com.oracle.svm.core.JavaMainWrapper; -import com.oracle.svm.core.thread.PlatformThreads; /** * This class holds various JFR-specific thread local values. diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrTicks.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrTicks.java index 4f016e39139d..bb5653c979e6 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrTicks.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrTicks.java @@ -24,10 +24,10 @@ */ package com.oracle.svm.core.jfr; -import com.oracle.svm.core.Uninterruptible; - import java.util.concurrent.TimeUnit; +import com.oracle.svm.core.Uninterruptible; + /** * Utility class to manage ticks for event timestamps based on an initial start point when the * system initializes. @@ -53,6 +53,11 @@ public static long elapsedTicks() { return 0; } + @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) + public static long duration(long startTicks) { + return elapsedTicks() - startTicks; + } + public static long getTicksFrequency() { return TimeUnit.SECONDS.toNanos(1); } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/SubstrateJVM.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/SubstrateJVM.java index 880562f10d83..c968fb02a01d 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/SubstrateJVM.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/SubstrateJVM.java @@ -659,7 +659,7 @@ public boolean setThreshold(long eventTypeId, long ticks) { } @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - long getThreshold(JfrEvent event) { + long getThresholdTicks(JfrEvent event) { return eventSettings[(int) event.getId()].getThresholdTicks(); } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ExecuteVMOperationEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ExecuteVMOperationEvent.java index 931ad313e278..38cca7787c59 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ExecuteVMOperationEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ExecuteVMOperationEvent.java @@ -49,13 +49,14 @@ public static void emit(VMOperation vmOperation, long requestingThreadId, long s @Uninterruptible(reason = "Accesses a JFR buffer.") private static void emit0(VMOperation vmOperation, long requestingThreadId, long startTicks) { - if (JfrEvent.ExecuteVMOperation.shouldEmit()) { + long duration = JfrTicks.duration(startTicks); + if (JfrEvent.ExecuteVMOperation.shouldEmit(duration)) { JfrNativeEventWriterData data = StackValue.get(JfrNativeEventWriterData.class); JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data); JfrNativeEventWriter.beginSmallEvent(data, JfrEvent.ExecuteVMOperation); JfrNativeEventWriter.putLong(data, startTicks); - JfrNativeEventWriter.putLong(data, JfrTicks.elapsedTicks() - startTicks); + JfrNativeEventWriter.putLong(data, duration); JfrNativeEventWriter.putEventThread(data); JfrNativeEventWriter.putLong(data, vmOperation.getId() + 1); // id starts with 1 JfrNativeEventWriter.putBoolean(data, vmOperation.getCausesSafepoint()); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorEnterEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorEnterEvent.java index 830416a51e5a..ab4dbc5ea6fb 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorEnterEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorEnterEvent.java @@ -47,13 +47,14 @@ public static void emit(Object obj, long previousOwnerTid, long startTicks) { @Uninterruptible(reason = "Accesses a JFR buffer.") public static void emit0(Object obj, long previousOwnerTid, long startTicks) { - if (JfrEvent.JavaMonitorEnter.shouldEmit(startTicks)) { + long duration = JfrTicks.duration(startTicks); + if (JfrEvent.JavaMonitorEnter.shouldEmit(duration)) { JfrNativeEventWriterData data = StackValue.get(JfrNativeEventWriterData.class); JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data); JfrNativeEventWriter.beginSmallEvent(data, JfrEvent.JavaMonitorEnter); JfrNativeEventWriter.putLong(data, startTicks); - JfrNativeEventWriter.putLong(data, JfrTicks.elapsedTicks() - startTicks); + JfrNativeEventWriter.putLong(data, duration); JfrNativeEventWriter.putEventThread(data); JfrNativeEventWriter.putLong(data, SubstrateJVM.get().getStackTraceId(JfrEvent.JavaMonitorEnter, 0)); JfrNativeEventWriter.putClass(data, obj.getClass()); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorInflateEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorInflateEvent.java index f607706ec679..abb7bdf784ae 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorInflateEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorInflateEvent.java @@ -48,13 +48,14 @@ public static void emit(Object obj, long startTicks, MonitorInflationCause cause @Uninterruptible(reason = "Accesses a JFR buffer.") public static void emit0(Object obj, long startTicks, MonitorInflationCause cause) { - if (JfrEvent.JavaMonitorInflate.shouldEmit(startTicks)) { + long duration = JfrTicks.duration(startTicks); + if (JfrEvent.JavaMonitorInflate.shouldEmit(duration)) { JfrNativeEventWriterData data = StackValue.get(JfrNativeEventWriterData.class); JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data); JfrNativeEventWriter.beginSmallEvent(data, JfrEvent.JavaMonitorInflate); JfrNativeEventWriter.putLong(data, startTicks); - JfrNativeEventWriter.putLong(data, JfrTicks.elapsedTicks() - startTicks); + JfrNativeEventWriter.putLong(data, duration); JfrNativeEventWriter.putEventThread(data); JfrNativeEventWriter.putLong(data, SubstrateJVM.get().getStackTraceId(JfrEvent.JavaMonitorInflate, 0)); JfrNativeEventWriter.putClass(data, obj.getClass()); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorWaitEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorWaitEvent.java index 37a6daa45faa..00a66a16bd0d 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorWaitEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorWaitEvent.java @@ -46,12 +46,13 @@ public static void emit(long startTicks, Object obj, long notifier, long timeout @Uninterruptible(reason = "Accesses a JFR buffer.") private static void emit0(long startTicks, Object obj, long notifier, long timeout, boolean timedOut) { - if (JfrEvent.JavaMonitorWait.shouldEmit(startTicks)) { + long duration = JfrTicks.duration(startTicks); + if (JfrEvent.JavaMonitorWait.shouldEmit(duration)) { JfrNativeEventWriterData data = org.graalvm.nativeimage.StackValue.get(JfrNativeEventWriterData.class); JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data); JfrNativeEventWriter.beginSmallEvent(data, JfrEvent.JavaMonitorWait); JfrNativeEventWriter.putLong(data, startTicks); - JfrNativeEventWriter.putLong(data, JfrTicks.elapsedTicks() - startTicks); + JfrNativeEventWriter.putLong(data, duration); JfrNativeEventWriter.putEventThread(data); JfrNativeEventWriter.putLong(data, SubstrateJVM.get().getStackTraceId(JfrEvent.JavaMonitorWait, 0)); JfrNativeEventWriter.putClass(data, obj.getClass()); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/SafepointBeginEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/SafepointBeginEvent.java index 34610f6b5846..d2dae42efef0 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/SafepointBeginEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/SafepointBeginEvent.java @@ -52,13 +52,14 @@ public static void emit(UnsignedWord safepointId, int numJavaThreads, long start */ @Uninterruptible(reason = "Accesses a JFR buffer.") private static void emit0(UnsignedWord safepointId, int numJavaThreads, long startTicks) { - if (JfrEvent.SafepointBegin.shouldEmit(startTicks)) { + long duration = JfrTicks.duration(startTicks); + if (JfrEvent.SafepointBegin.shouldEmit(duration)) { JfrNativeEventWriterData data = StackValue.get(JfrNativeEventWriterData.class); JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data); JfrNativeEventWriter.beginSmallEvent(data, JfrEvent.SafepointBegin); JfrNativeEventWriter.putLong(data, startTicks); - JfrNativeEventWriter.putLong(data, JfrTicks.elapsedTicks() - startTicks); + JfrNativeEventWriter.putLong(data, duration); JfrNativeEventWriter.putEventThread(data); JfrNativeEventWriter.putLong(data, safepointId.rawValue()); JfrNativeEventWriter.putInt(data, numJavaThreads); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/SafepointEndEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/SafepointEndEvent.java index 2c16028eca5b..e6b55fb56538 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/SafepointEndEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/SafepointEndEvent.java @@ -46,14 +46,15 @@ public static void emit(UnsignedWord safepointId, long startTick) { } @Uninterruptible(reason = "Accesses a JFR buffer.") - private static void emit0(UnsignedWord safepointId, long startTick) { - if (JfrEvent.SafepointEnd.shouldEmit(startTick)) { + private static void emit0(UnsignedWord safepointId, long startTicks) { + long duration = JfrTicks.duration(startTicks); + if (JfrEvent.SafepointEnd.shouldEmit(duration)) { JfrNativeEventWriterData data = StackValue.get(JfrNativeEventWriterData.class); JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data); JfrNativeEventWriter.beginSmallEvent(data, JfrEvent.SafepointEnd); - JfrNativeEventWriter.putLong(data, startTick); - JfrNativeEventWriter.putLong(data, JfrTicks.elapsedTicks() - startTick); + JfrNativeEventWriter.putLong(data, startTicks); + JfrNativeEventWriter.putLong(data, duration); JfrNativeEventWriter.putEventThread(data); JfrNativeEventWriter.putLong(data, safepointId.rawValue()); JfrNativeEventWriter.endSmallEvent(data); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadParkEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadParkEvent.java index 3a9fd4ffeab8..b027ce6ac4a3 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadParkEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadParkEvent.java @@ -47,7 +47,8 @@ public static void emit(long startTicks, Object obj, boolean isAbsolute, long ti @Uninterruptible(reason = "Accesses a JFR buffer.") private static void emit0(long startTicks, Object obj, boolean isAbsolute, long time) { - if (JfrEvent.ThreadPark.shouldEmit(startTicks)) { + long duration = JfrTicks.duration(startTicks); + if (JfrEvent.ThreadPark.shouldEmit(duration)) { Class parkedClass = null; if (obj != null) { parkedClass = obj.getClass(); @@ -65,7 +66,7 @@ private static void emit0(long startTicks, Object obj, boolean isAbsolute, long JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data); JfrNativeEventWriter.beginSmallEvent(data, JfrEvent.ThreadPark); JfrNativeEventWriter.putLong(data, startTicks); - JfrNativeEventWriter.putLong(data, JfrTicks.elapsedTicks() - startTicks); + JfrNativeEventWriter.putLong(data, duration); JfrNativeEventWriter.putEventThread(data); JfrNativeEventWriter.putLong(data, SubstrateJVM.get().getStackTraceId(JfrEvent.ThreadPark, 0)); JfrNativeEventWriter.putClass(data, parkedClass); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadSleepEventJDK17.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadSleepEventJDK17.java index f3177208ebdc..86c9005014f7 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadSleepEventJDK17.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadSleepEventJDK17.java @@ -38,7 +38,7 @@ import com.oracle.svm.core.jfr.SubstrateJVM; public class ThreadSleepEventJDK17 { - private static final JfrEvent ThreadSleep = JfrEvent.create("jdk.ThreadSleep"); + private static final JfrEvent ThreadSleep = JfrEvent.create("jdk.ThreadSleep", true); public static void emit(long time, long startTicks) { if (HasJfrSupport.get()) { @@ -48,13 +48,14 @@ public static void emit(long time, long startTicks) { @Uninterruptible(reason = "Accesses a JFR buffer.") private static void emit0(long time, long startTicks) { - if (ThreadSleep.shouldEmit(startTicks)) { + long duration = JfrTicks.duration(startTicks); + if (ThreadSleep.shouldEmit(duration)) { JfrNativeEventWriterData data = StackValue.get(JfrNativeEventWriterData.class); JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data); JfrNativeEventWriter.beginSmallEvent(data, ThreadSleep); JfrNativeEventWriter.putLong(data, startTicks); - JfrNativeEventWriter.putLong(data, JfrTicks.elapsedTicks() - startTicks); + JfrNativeEventWriter.putLong(data, duration); JfrNativeEventWriter.putEventThread(data); JfrNativeEventWriter.putLong(data, SubstrateJVM.get().getStackTraceId(ThreadSleep, 0)); JfrNativeEventWriter.putLong(data, time); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadStartEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadStartEvent.java index c591c25d1a2c..1eb36418442e 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadStartEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadStartEvent.java @@ -36,7 +36,6 @@ import com.oracle.svm.core.thread.JavaThreads; public class ThreadStartEvent { - @Uninterruptible(reason = "Accesses a JFR buffer.") public static void emit(Thread thread) { if (JfrEvent.ThreadStart.shouldEmit()) { diff --git a/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestGCEvents.java b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestGCEvents.java index 1db80d48afd6..f559cdb0448b 100644 --- a/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestGCEvents.java +++ b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestGCEvents.java @@ -40,8 +40,8 @@ public class TestGCEvents extends JfrRecordingTest { @Test public void test() throws Throwable { - String[] events = new String[]{JfrEvent.GarbageCollection.getName(), JfrEvent.GCPhasePauseEvent.getName(), JfrEvent.GCPhasePauseLevel1Event.getName(), - JfrEvent.GCPhasePauseLevel2Event.getName(), JfrEvent.ExecuteVMOperation.getName()}; + String[] events = new String[]{JfrEvent.GarbageCollection.getName(), JfrEvent.GCPhasePause.getName(), JfrEvent.GCPhasePauseLevel1.getName(), + JfrEvent.GCPhasePauseLevel2.getName(), JfrEvent.ExecuteVMOperation.getName()}; Recording recording = startRecording(events); System.gc(); diff --git a/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreshold.java b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreshold.java index 683fe1be38c7..e0fed523ff09 100644 --- a/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreshold.java +++ b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreshold.java @@ -33,10 +33,10 @@ import java.util.List; import java.util.concurrent.locks.LockSupport; -import com.oracle.svm.test.jfr.events.StringEvent; import org.junit.Test; import com.oracle.svm.core.jfr.JfrEvent; +import com.oracle.svm.test.jfr.events.StringEvent; import jdk.jfr.Recording; import jdk.jfr.consumer.RecordedClass; @@ -44,17 +44,16 @@ import jdk.jfr.consumer.RecordedThread; public class TestThreshold extends JfrRecordingTest { - - private static final long SHORT_MILLIS = 10; - private static final long THRESHOLD = 20; - private static final long LONG_MILLIS = 30; + private static final long SHORT_MILLIS = 1; + private static final long THRESHOLD = 10; + private static final long LONG_MILLIS = 50; private final Helper helper = new Helper(); @Test public void test() throws Throwable { + /* Set thresholds before recording is started to avoid recording shorter events. */ String[] events = new String[]{JfrEvent.JavaMonitorWait.getName(), JfrEvent.ThreadPark.getName(), "com.jfr.String", "jdk.ThreadSleep"}; - // Cannot start recording until thresholds are set Recording recording = prepareRecording(events, getDefaultConfiguration(), null, createTempJfrFile()); recording.enable(JfrEvent.JavaMonitorWait.getName()).withThreshold(Duration.ofMillis(THRESHOLD)); recording.enable(JfrEvent.ThreadPark.getName()).withThreshold(Duration.ofMillis(THRESHOLD)); @@ -65,6 +64,7 @@ public void test() throws Throwable { StringEvent shortStringEvent = new StringEvent(); shortStringEvent.begin(); shortStringEvent.commit(); + StringEvent longStringEvent = new StringEvent(); longStringEvent.begin(); Thread.sleep(SHORT_MILLIS); @@ -77,10 +77,14 @@ public void test() throws Throwable { helper.simpleWait(SHORT_MILLIS); helper.simpleWait(LONG_MILLIS); - stopRecording(recording, this::validateEvents); + stopRecording(recording, TestThreshold::validateEvents); } - private void validateEvents(List events) { + private static void validateEvents(List events) { + /* + * We can't validate the number of events because short events can always take longer than + * the threshold. However, we can validate that no short events were recorded. + */ boolean foundWaitEvent = false; boolean foundJavaEvent = false; boolean foundParkEvent = false; @@ -88,9 +92,6 @@ private void validateEvents(List events) { for (RecordedEvent event : events) { String eventThread = event. getValue("eventThread").getJavaName(); assertNotNull("No event thread", eventThread); - - // Even unintentional events emitted by SVM should not have durations over the - // threshold. assertTrue(event.getDuration().toMillis() >= LONG_MILLIS); if (event.getEventType().getName().equals("com.jfr.String")) {