[GR-45841] Add JFR event ThreadCPULoad.

substratevm/CHANGELOG.md

@@ -5,6 +5,7 @@ This changelog summarizes major changes to GraalVM Native Image.
 ## Version 23.1.0
 * (GR-35746) Lower the default aligned chunk size from 1 MB to 512 KB for the serial and epsilon GCs, reducing memory usage and image size in many cases.
 * (GR-45673) Improve the memory footprint of the Native Image build process. The builder now takes available memory into account to reduce memory pressure when many other processes are running on the same machine. It also consumes less memory in many cases and is therefore also less likely to fail due to out-of-memory errors. At the same time, we have raised its memory limit from 14GB to 32GB.
+* (GR-45841) BellSoft added support for the JFR event ThreadCPULoad.
 
 ## Version 23.0.0
 * (GR-40187) Report invalid use of SVM specific classes on image class- or module-path as error. As a temporary workaround, `-H:+AllowDeprecatedBuilderClassesOnImageClasspath` allows turning the error into a warning.

substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrEvent.java

@@ -36,6 +36,7 @@
 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");

substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrNativeEventWriter.java

@@ -190,6 +190,17 @@ public static void putLong(JfrNativeEventWriterData data, long v) {
         }
     }
 
+    @Uninterruptible(reason = "Accesses a native JFR buffer.", callerMustBe = true)
+    public static void putFloat(JfrNativeEventWriterData data, float v) {
+        if (ensureSize(data, Float.BYTES)) {
+            int bits = Float.floatToIntBits(v);
+            putUncheckedByte(data, (byte) (bits >>> 24));
+            putUncheckedByte(data, (byte) (bits >>> 16));
+            putUncheckedByte(data, (byte) (bits >>> 8));
+            putUncheckedByte(data, (byte) (bits));
+        }
+    }
+
     @Uninterruptible(reason = "Accesses a native JFR buffer.", callerMustBe = true)
     public static void putString(JfrNativeEventWriterData data, String string) {
         putString(data, string, null);

substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrThreadLocal.java

@@ -36,6 +36,7 @@
 import com.oracle.svm.core.SubstrateUtil;
 import com.oracle.svm.core.Uninterruptible;
 import com.oracle.svm.core.UnmanagedMemoryUtil;
+import com.oracle.svm.core.jfr.events.ThreadCPULoadEvent;
 import com.oracle.svm.core.jfr.events.ThreadEndEvent;
 import com.oracle.svm.core.jfr.events.ThreadStartEvent;
 import com.oracle.svm.core.sampler.SamplerBuffer;
@@ -125,6 +126,7 @@ public void teardown() {
     public void beforeThreadStart(IsolateThread isolateThread, Thread javaThread) {
         if (SubstrateJVM.get().isRecording()) {
             SubstrateJVM.getThreadRepo().registerThread(javaThread);
+            ThreadCPULoadEvent.initWallclockTime(isolateThread);
             ThreadStartEvent.emit(javaThread);
         }
     }
@@ -134,6 +136,7 @@ public void beforeThreadStart(IsolateThread isolateThread, Thread javaThread) {
     public void afterThreadExit(IsolateThread isolateThread, Thread javaThread) {
         if (SubstrateJVM.get().isRecording()) {
             ThreadEndEvent.emit(javaThread);
+            ThreadCPULoadEvent.emit(isolateThread);
         }
 
         /*

substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/EndChunkNativePeriodicEvents.java

@@ -60,6 +60,7 @@ public static void emit() {
         emitOSInformation(formatOSInformation());
         emitInitialEnvironmentVariables(getEnvironmentVariables());
         emitInitialSystemProperties(getSystemProperties());
+        emitThreadCPULoad();
     }
 
     @Uninterruptible(reason = "Accesses a JFR buffer.")
@@ -176,6 +177,10 @@ private static JfrEventWriteStatus emitOSInformation0(JfrNativeEventWriterData d
         return JfrNativeEventWriter.endEvent(data, isLarge);
     }
 
+    private static void emitThreadCPULoad() {
+        ThreadCPULoadEvent.emitEvents();
+    }
+
     private static StringEntry[] getEnvironmentVariables() {
         Map<String, String> env = System.getenv();
         StringEntry[] result = new StringEntry[env.size()];

substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java

@@ -0,0 +1,184 @@
+/*
+ * Copyright (c) 2023, 2023, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2023, 2023, BELLSOFT. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.  Oracle designates this
+ * particular file as subject to the "Classpath" exception as provided
+ * by Oracle in the LICENSE file that accompanied this code.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+package com.oracle.svm.core.jfr.events;
+
+import org.graalvm.nativeimage.IsolateThread;
+import org.graalvm.nativeimage.StackValue;
+
+import com.oracle.svm.core.Uninterruptible;
+import com.oracle.svm.core.heap.VMOperationInfos;
+import com.oracle.svm.core.jdk.Jvm;
+import com.oracle.svm.core.jdk.UninterruptibleUtils;
+import com.oracle.svm.core.jfr.JfrEvent;
+import com.oracle.svm.core.jfr.JfrNativeEventWriter;
+import com.oracle.svm.core.jfr.JfrNativeEventWriterData;
+import com.oracle.svm.core.jfr.JfrNativeEventWriterDataAccess;
+import com.oracle.svm.core.jfr.JfrTicks;
+import com.oracle.svm.core.thread.JavaVMOperation;
+import com.oracle.svm.core.thread.ThreadCpuTimeSupport;
+import com.oracle.svm.core.thread.VMThreads;
+import com.oracle.svm.core.threadlocal.FastThreadLocalFactory;
+import com.oracle.svm.core.threadlocal.FastThreadLocalLong;
+import com.oracle.svm.core.util.TimeUtils;
+
+public class ThreadCPULoadEvent {
+    private static final FastThreadLocalLong cpuTimeTL = FastThreadLocalFactory.createLong("ThreadCPULoadEvent.cpuTimeTL");
+    private static final FastThreadLocalLong userTimeTL = FastThreadLocalFactory.createLong("ThreadCPULoadEvent.userTimeTL");
+    private static final FastThreadLocalLong wallclockTimeTL = FastThreadLocalFactory.createLong("ThreadCPULoadEvent.wallclockTimeTL");
+
+    private static volatile int lastActiveProcessorCount;
+
+    @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true)
+    public static void initWallclockTime(IsolateThread isolateThread) {
+        wallclockTimeTL.set(isolateThread, getCurrentTime());
+    }
+
+    @Uninterruptible(reason = "Accesses a JFR buffer.")
+    public static void emit(IsolateThread isolateThread) {
+        if (!JfrEvent.ThreadCPULoad.shouldEmit()) {
+            return;
+        }
+
+        long curCpuTime = getThreadCpuTime(isolateThread, true);
+        long prevCpuTime = cpuTimeTL.get(isolateThread);
+
+        long curTime = getCurrentTime();
+        long prevTime = wallclockTimeTL.get(isolateThread);
+        wallclockTimeTL.set(isolateThread, curTime);
+
+        /* Threshold of 1 ms. */
+        if (curCpuTime - prevCpuTime < 1 * TimeUtils.nanosPerMilli) {
+            return;
+        }
+
+        long curUserTime = getThreadCpuTime(isolateThread, false);
+        long prevUserTime = userTimeTL.get(isolateThread);
+
+        long curSystemTime = curCpuTime - curUserTime;
+        long prevSystemTime = prevCpuTime - prevUserTime;
+
+        /*
+         * The user and total cpu usage clocks can have different resolutions, which can make us see
+         * decreasing system time. Ensure time doesn't go backwards.
+         */
+        if (prevSystemTime > curSystemTime) {
+            curCpuTime += prevSystemTime - curSystemTime;
+            curSystemTime = prevSystemTime;
+        }
+
+        int processorsCount = getProcessorCount();
+
+        long userTime = curUserTime - prevUserTime;
+        long systemTime = curSystemTime - prevSystemTime;
+        long wallClockTime = curTime - prevTime;
+        float totalAvailableTime = wallClockTime * processorsCount;
+
+        /* Avoid reporting percentages above the theoretical max. */
+        if (userTime + systemTime > wallClockTime) {
+            long excess = userTime + systemTime - wallClockTime;
+            curCpuTime -= excess;
+            if (userTime > excess) {
+                userTime -= excess;
+                curUserTime -= excess;
+            } else {
+                excess -= userTime;
+                curUserTime -= userTime;
+                userTime = 0;
+                systemTime -= excess;
+            }
+        }
+
+        cpuTimeTL.set(isolateThread, curCpuTime);
+        userTimeTL.set(isolateThread, curUserTime);
+
+        JfrNativeEventWriterData data = StackValue.get(JfrNativeEventWriterData.class);
+        JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data);
+
+        JfrNativeEventWriter.beginSmallEvent(data, JfrEvent.ThreadCPULoad);
+        JfrNativeEventWriter.putLong(data, JfrTicks.elapsedTicks());
+        JfrNativeEventWriter.putEventThread(data);
+        JfrNativeEventWriter.putFloat(data, userTime / totalAvailableTime);
+        JfrNativeEventWriter.putFloat(data, systemTime / totalAvailableTime);
+        JfrNativeEventWriter.endSmallEvent(data);
+    }
+
+    public static void emitEvents() {
+        /* This is safe because the VM operation rechecks if the event should be emitted. */
+        if (shouldEmitUnsafe()) {
+            EmitThreadCPULoadEventsOperation vmOp = new EmitThreadCPULoadEventsOperation();
+            vmOp.enqueue();
+        }
+    }
+
+    @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true)
+    private static int getProcessorCount() {
+        /*
+         * This should but does not take the container support into account. Unfortunately, it is
+         * currently not possible to call Containers.activeProcessorCount() from uninterruptible
+         * code.
+         */
+        int curProcessorCount = Jvm.JVM_ActiveProcessorCount();
+        int prevProcessorCount = lastActiveProcessorCount;
+        lastActiveProcessorCount = curProcessorCount;
+
+        /*
+         * If the number of processors decreases, we don't know at what point during the sample
+         * interval this happened, so use the largest number to try to avoid percentages above 100%.
+         */
+        return UninterruptibleUtils.Math.max(curProcessorCount, prevProcessorCount);
+    }
+
+    @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true)
+    private static long getThreadCpuTime(IsolateThread isolateThread, boolean includeSystemTime) {
+        long threadCpuTime = ThreadCpuTimeSupport.getInstance().getThreadCpuTime(
+                        VMThreads.findOSThreadHandleForIsolateThread(isolateThread), includeSystemTime);
+        return (threadCpuTime < 0) ? 0 : threadCpuTime;
+    }
+
+    @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true)
+    private static long getCurrentTime() {
+        return System.nanoTime();
+    }
+
+    @Uninterruptible(reason = "Used to avoid the VM operation if it is not absolutely needed.")
+    private static boolean shouldEmitUnsafe() {
+        /* The returned value is racy. */
+        return JfrEvent.ThreadCPULoad.shouldEmit();
+    }
+
+    private static final class EmitThreadCPULoadEventsOperation extends JavaVMOperation {
+        EmitThreadCPULoadEventsOperation() {
+            super(VMOperationInfos.get(EmitThreadCPULoadEventsOperation.class, "Emit ThreadCPULoad events", SystemEffect.SAFEPOINT));
+        }
+
+        @Override
+        protected void operate() {
+            for (IsolateThread isolateThread = VMThreads.firstThread(); isolateThread.isNonNull(); isolateThread = VMThreads.nextThread(isolateThread)) {
+                emit(isolateThread);
+            }
+        }
+    }
+}

substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java

@@ -0,0 +1,103 @@
+/*
+ * Copyright (c) 2023, 2023, Oracle and/or its affiliates. All rights reserved.
+ * Copyright (c) 2023, 2023, BELLSOFT. All rights reserved.
+ * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
+ *
+ * This code is free software; you can redistribute it and/or modify it
+ * under the terms of the GNU General Public License version 2 only, as
+ * published by the Free Software Foundation.  Oracle designates this
+ * particular file as subject to the "Classpath" exception as provided
+ * by Oracle in the LICENSE file that accompanied this code.
+ *
+ * This code is distributed in the hope that it will be useful, but WITHOUT
+ * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
+ * FITNESS FOR A PARTICULAR PURPOSE.  See the GNU General Public License
+ * version 2 for more details (a copy is included in the LICENSE file that
+ * accompanied this code).
+ *
+ * You should have received a copy of the GNU General Public License version
+ * 2 along with this work; if not, write to the Free Software Foundation,
+ * Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
+ *
+ * Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
+ * or visit www.oracle.com if you need additional information or have any
+ * questions.
+ */
+
+package com.oracle.svm.test.jfr;
+
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertTrue;
+
+import java.util.HashMap;
+import java.util.List;
+import java.util.Map;
+
+import org.junit.Test;
+
+import jdk.jfr.Recording;
+import jdk.jfr.consumer.RecordedEvent;
+
+public class TestThreadCPULoadEvent extends JfrRecordingTest {
+    private static final int DURATION_MS = 1000;
+    private static final String THREAD_NAME_1 = "Thread-1";
+    private static final String THREAD_NAME_2 = "Thread-2";
+
+    @Test
+    public void test() throws Throwable {
+        String[] events = new String[]{"jdk.ThreadCPULoad"};
+        Recording recording = startRecording(events);
+
+        Thread thread1 = createAndStartBusyWaitThread(THREAD_NAME_1, 0.1);
+        Thread thread2 = createAndStartBusyWaitThread(THREAD_NAME_2, 1.0);
+
+        thread1.join();
+        thread2.join();
+
+        stopRecording(recording, TestThreadCPULoadEvent::validateEvents);
+    }
+
+    private static void validateEvents(List<RecordedEvent> events) {
+        assertEquals(2, events.size());
+        Map<String, Float> systemTimes = new HashMap<>();
+
+        for (RecordedEvent e : events) {
+            float userTime = e.<Float> getValue("user");
+            float systemTime = e.<Float> getValue("system");
+            assertTrue("User time is outside 0..1 range", 0.0 <= userTime && userTime <= 1.0);
+            assertTrue("System time is outside 0..1 range", 0.0 <= systemTime && systemTime <= 1.0);
+            systemTimes.put(e.getThread().getJavaName(), systemTime);
+        }
+
+        assertTrue("Thread-1 system cpu time is greater than Thread-2 system cpu time",
+                        systemTimes.get(THREAD_NAME_1) < systemTimes.get(THREAD_NAME_2));
+    }
+
+    private static Thread createAndStartBusyWaitThread(String name, double busyPercent) {
+        Thread thread = new Thread(() -> {
+            assert busyPercent >= 0 && busyPercent <= 1;
+            long busyMs = (long) (DURATION_MS * busyPercent);
+            long idleMs = DURATION_MS - busyMs;
+
+            busyWait(busyMs);
+            sleep(idleMs);
+        });
+        thread.setName(name);
+        thread.start();
+        return thread;
+    }
+
+    private static void busyWait(long delay) {
+        long end = System.currentTimeMillis() + delay;
+        while (end > System.currentTimeMillis()) {
+            /* Nothing to do. */
+        }
+    }
+
+    private static void sleep(long delay) {
+        try {
+            Thread.sleep(delay);
+        } catch (InterruptedException ignored) {
+        }
+    }
+}