More checks, small bugfixes, and other improvements for the JFR event…

… threshold.
oracle · Jul 26, 2023 · d4a8436 · d4a8436
1 parent b15e6e0
commit d4a8436
Show file tree

Hide file tree

Showing 16 changed files with 109 additions and 88 deletions.
diff --git a/...om.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/JfrGCEventSupport.java b/...om.oracle.svm.core.genscavenge/src/com/oracle/svm/core/genscavenge/JfrGCEventSupport.java
@@ -66,36 +66,35 @@ 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);
         }
     }
 
     @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
@@ -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
@@ -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,15 +43,14 @@
 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;
 import com.oracle.svm.core.threadlocal.FastThreadLocalFactory;
 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
@@ -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
@@ -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/...m/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ExecuteVMOperationEvent.java b/...m/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/...evm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorEnterEvent.java b/...evm/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/...m/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorInflateEvent.java b/...m/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/...tevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/JavaMonitorWaitEvent.java b/...tevm/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/...atevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/SafepointBeginEvent.java b/...atevm/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/...tratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/SafepointEndEvent.java b/...tratevm/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);