From 0f2b1f5c7c6c0687d06bb9224ac8f067a9155a6e Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Wed, 22 Feb 2023 14:59:58 +0300 Subject: [PATCH 01/15] Implement JFR ThreadCPULoad event --- .../src/com/oracle/svm/core/jfr/JfrEvent.java | 1 + .../svm/core/jfr/JfrNativeEventWriter.java | 11 ++ .../oracle/svm/core/jfr/JfrThreadLocal.java | 38 ++++ .../events/EndChunkNativePeriodicEvents.java | 6 + .../core/jfr/events/ThreadCPULoadEvent.java | 167 ++++++++++++++++++ .../svm/core/thread/PlatformThreads.java | 18 ++ .../svm/test/jfr/TestThreadCPULoadEvent.java | 72 ++++++++ 7 files changed, 313 insertions(+) create mode 100644 substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java create mode 100644 substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java 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 4ca85367ee92..893f0de3bdc2 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 @@ -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"); diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrNativeEventWriter.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrNativeEventWriter.java index 21bcc88adedc..f1079a8bf966 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrNativeEventWriter.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrNativeEventWriter.java @@ -189,6 +189,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) { if (string == null) { 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 68ac2334136c..ce0b73d287fc 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 @@ -37,6 +37,7 @@ import com.oracle.svm.core.UnmanagedMemoryUtil; import com.oracle.svm.core.jfr.events.ThreadEndEvent; import com.oracle.svm.core.jfr.events.ThreadStartEvent; +import com.oracle.svm.core.jfr.events.ThreadCPULoadEvent; import com.oracle.svm.core.sampler.SamplerBuffer; import com.oracle.svm.core.sampler.SamplerSampleWriterData; import com.oracle.svm.core.thread.ThreadListener; @@ -82,6 +83,11 @@ public class JfrThreadLocal implements ThreadListener { private static final FastThreadLocalLong unparseableStacks = FastThreadLocalFactory.createLong("JfrThreadLocal.unparseableStacks"); private static final FastThreadLocalWord samplerWriterData = FastThreadLocalFactory.createWord("JfrThreadLocal.samplerWriterData"); + /* ThreadCPULoad thread-locals. */ + private static final FastThreadLocalLong cpuTime = FastThreadLocalFactory.createLong("JfrThreadLocal.cpuTime"); + private static final FastThreadLocalLong userTime = FastThreadLocalFactory.createLong("JfrThreadLocal.userTime"); + private static final FastThreadLocalLong wallClockTime = FastThreadLocalFactory.createLong("JfrThreadLocal.wallClockTime"); + private long threadLocalBufferSize; @Platforms(Platform.HOSTED_ONLY.class) @@ -97,6 +103,7 @@ public void initialize(long bufferSize) { public void beforeThreadStart(IsolateThread isolateThread, Thread javaThread) { if (SubstrateJVM.get().isRecording()) { SubstrateJVM.getThreadRepo().registerThread(javaThread); + ThreadCPULoadEvent.initializeWallClockTime(isolateThread); ThreadStartEvent.emit(javaThread); } } @@ -106,6 +113,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); stopRecording(isolateThread); } } @@ -325,4 +333,34 @@ public static void setSamplerWriterData(SamplerSampleWriterData data) { public static SamplerSampleWriterData getSamplerWriterData() { return samplerWriterData.get(); } + + @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) + public static long getCpuTime(IsolateThread thread) { + return cpuTime.get(thread); + } + + @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) + public static void setCpuTime(IsolateThread thread, long value) { + cpuTime.set(thread, value); + } + + @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) + public static long getUserTime(IsolateThread thread) { + return userTime.get(thread); + } + + @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) + public static void setUserTime(IsolateThread thread, long value) { + userTime.set(thread, value); + } + + @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) + public static long getWallClockTime(IsolateThread thread) { + return wallClockTime.get(thread); + } + + @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) + public static void setWallClockTime(IsolateThread thread, long value) { + wallClockTime.set(thread, value); + } } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/EndChunkNativePeriodicEvents.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/EndChunkNativePeriodicEvents.java index edadb7bfb830..23c6ab4fbb2b 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/EndChunkNativePeriodicEvents.java +++ b/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,11 @@ private static JfrEventWriteStatus emitOSInformation0(JfrNativeEventWriterData d return JfrNativeEventWriter.endEvent(data, isLarge); } + @Uninterruptible(reason = "Accesses a JFR buffer.") + private static void emitThreadCPULoad() { + ThreadCPULoadEvent.emitEvents(); + } + private static StringEntry[] getEnvironmentVariables() { Map env = System.getenv(); StringEntry[] result = new StringEntry[env.size()]; diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java new file mode 100644 index 000000000000..6caa4467d362 --- /dev/null +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java @@ -0,0 +1,167 @@ +/* + * 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.StackValue; +import org.graalvm.nativeimage.IsolateThread; + +import com.oracle.svm.core.Uninterruptible; +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.jfr.JfrThreadLocal; + +import com.oracle.svm.core.jdk.Jvm; + +import com.oracle.svm.core.thread.VMThreads; +import com.oracle.svm.core.thread.PlatformThreads; +import com.oracle.svm.core.thread.ThreadCpuTimeSupport; + +import static com.oracle.svm.core.thread.PlatformThreads.IsolateThreadConsumer; + +public class ThreadCPULoadEvent { + + private static final int NANOSECS_PER_MILLISEC = 1_000_000; + private static volatile int lastActiveProcessorCount; + + private static final IsolateThreadConsumer threadCPULoadEventConsumer = new IsolateThreadConsumer() { + + @Uninterruptible(reason = "Thread locks/holds the THREAD_MUTEX.", mayBeInlined = true) + public void accept(IsolateThread isolateThread) { + emitForThread(isolateThread); + } + }; + + @Uninterruptible(reason = "Accesses a JFR buffer.") + public static void emit(IsolateThread isolateThread) { + if (JfrEvent.ThreadCPULoad.shouldEmit()) { + emitForThread(isolateThread); + } + } + + @Uninterruptible(reason = "Accesses a JFR buffer.") + public static void emitEvents() { + if (JfrEvent.ThreadCPULoad.shouldEmit()) { + PlatformThreads.iterateIsolateThreads(threadCPULoadEventConsumer); + } + } + + @Uninterruptible(reason = "Accesses a JFR buffer.") + private static void emitForThread(IsolateThread isolateThread) { + + long currCpuTime = getThreadCpuTime(isolateThread, true); + long prevCpuTime = JfrThreadLocal.getCpuTime(isolateThread); + + long currWallClockTime = getWallClockTime(); + long prevWallClockTime = JfrThreadLocal.getWallClockTime(isolateThread); + JfrThreadLocal.setWallClockTime(isolateThread, currWallClockTime); + + // Threshold of 1 ms + if (currCpuTime - prevCpuTime < 1 * NANOSECS_PER_MILLISEC) { + return; + } + + long currUserTime = getThreadCpuTime(isolateThread, false); + long prevUserTime = JfrThreadLocal.getUserTime(isolateThread); + + long currSystemTime = currCpuTime - currUserTime; + 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 > currSystemTime) { + currCpuTime += prevSystemTime - currSystemTime; + currSystemTime = prevSystemTime; + } + + int processorsCount = getProcessorCount(); + + long userTime = currUserTime - prevUserTime; + long systemTime = currSystemTime - prevSystemTime; + long wallClockTime = currWallClockTime - prevWallClockTime; + float totalAvailableTime = wallClockTime * processorsCount; + + // Avoid reporting percentages above the theoretical max + if (userTime + systemTime > wallClockTime) { + long excess = userTime + systemTime - wallClockTime; + currCpuTime -= excess; + if (userTime > excess) { + userTime -= excess; + currUserTime -= excess; + } else { + excess -= userTime; + currUserTime -= userTime; + userTime = 0; + systemTime -= excess; + } + } + + JfrThreadLocal.setCpuTime(isolateThread, currCpuTime); + JfrThreadLocal.setUserTime(isolateThread, currUserTime); + + 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); + } + + @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) + private static int getProcessorCount() { + int currProcessorCount = Jvm.JVM_ActiveProcessorCount(); + int prevProcessorCount = lastActiveProcessorCount; + lastActiveProcessorCount = currProcessorCount; + + // 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% + // Math.max(int, int) does not have Uninterruptible annotation + return (currProcessorCount > prevProcessorCount) ? currProcessorCount : 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 getWallClockTime() { + return System.nanoTime(); + } + + @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) + public static void initializeWallClockTime(IsolateThread isolateThread) { + JfrThreadLocal.setWallClockTime(isolateThread, getWallClockTime()); + } +} diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/PlatformThreads.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/PlatformThreads.java index 6250f73f8bf8..5d0679a90262 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/PlatformThreads.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/PlatformThreads.java @@ -251,6 +251,18 @@ public static long getThreadCpuTime(long javaThreadId, boolean includeSystemTime } } + @Uninterruptible(reason = "Thread locks/holds the THREAD_MUTEX.") + public static void iterateIsolateThreads(IsolateThreadConsumer consumer) { + VMThreads.lockThreadMutexInNativeCode(); + try { + for (IsolateThread cur = VMThreads.firstThread(); cur.isNonNull(); cur = VMThreads.nextThread(cur)) { + consumer.accept(cur); + } + } finally { + VMThreads.THREAD_MUTEX.unlock(); + } + } + @Uninterruptible(reason = "Thread locks/holds the THREAD_MUTEX.") public static void getThreadAllocatedBytes(long[] javaThreadIds, long[] result) { VMThreads.lockThreadMutexInNativeCode(); @@ -1185,6 +1197,12 @@ static void blockedOn(Target_sun_nio_ch_Interruptible b) { public interface OSThreadHandle extends PointerBase { } + + public interface IsolateThreadConsumer { + + @Uninterruptible(reason = "Thread locks/holds the THREAD_MUTEX.", mayBeInlined = true) + void accept(IsolateThread isolateThread); + } } @TargetClass(value = ThreadPoolExecutor.class, innerClass = "Worker") diff --git a/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java new file mode 100644 index 000000000000..18237854d4c0 --- /dev/null +++ b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java @@ -0,0 +1,72 @@ +/* + * 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 org.junit.Test; +import java.io.File; +import java.io.IOException; +import java.io.RandomAccessFile; + +/** + * Test if event ThreadCPULoad is generated after a thread exit. + */ +public class TestThreadCPULoadEvent extends JfrTest { + + private static final int MILLIS = 50; + + @Override + public String[] getTestedEvents() { + return new String[]{"jdk.ThreadCPULoad"}; + } + + @Test + public void test() throws Exception { + Thread thread = new Thread(() -> { + long time = System.currentTimeMillis() + MILLIS; + do { + writeToFile(); + } while (time > System.currentTimeMillis()); + }); + thread.start(); + thread.join(); + } + + private static void writeToFile() { + int fileSize = 1000; + try { + File temp = File.createTempFile("TestThreadCPULoadEventData_", ".tmp"); + temp.deleteOnExit(); + try (RandomAccessFile file = new RandomAccessFile(temp, "rw")) { + for (int i = 0; i < fileSize; i++) { + file.writeByte(i); + } + } + } catch (IOException e) { + e.printStackTrace(); + } + } +} From 05063e0ca0ab1f861633044ba7242bcf1db07b83 Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Thu, 9 Mar 2023 14:06:36 +0300 Subject: [PATCH 02/15] Avoid using mayBeInlined=true in IsolateThreadConsumer.accept(IsolateThread) method --- .../src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java | 2 +- .../src/com/oracle/svm/core/thread/PlatformThreads.java | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java index 6caa4467d362..a7b6690d15e0 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java @@ -51,7 +51,7 @@ public class ThreadCPULoadEvent { private static final IsolateThreadConsumer threadCPULoadEventConsumer = new IsolateThreadConsumer() { - @Uninterruptible(reason = "Thread locks/holds the THREAD_MUTEX.", mayBeInlined = true) + @Uninterruptible(reason = "Thread locks/holds the THREAD_MUTEX.") public void accept(IsolateThread isolateThread) { emitForThread(isolateThread); } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/PlatformThreads.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/PlatformThreads.java index 5d0679a90262..cd1993744a93 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/PlatformThreads.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/PlatformThreads.java @@ -1200,7 +1200,7 @@ public interface OSThreadHandle extends PointerBase { public interface IsolateThreadConsumer { - @Uninterruptible(reason = "Thread locks/holds the THREAD_MUTEX.", mayBeInlined = true) + @Uninterruptible(reason = "Thread locks/holds the THREAD_MUTEX.") void accept(IsolateThread isolateThread); } } From ef519b25604523f78dba924a816e6a04ae2b39a9 Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Tue, 25 Apr 2023 11:19:59 +0300 Subject: [PATCH 03/15] Update TestThreadCPULoadEvent according to Refactored and fixed issues in the JFR test cases --- .../svm/test/jfr/TestThreadCPULoadEvent.java | 21 ++++++++++--------- 1 file changed, 11 insertions(+), 10 deletions(-) diff --git a/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java index 302d25beeff5..b2e41d2b9936 100644 --- a/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java @@ -34,6 +34,7 @@ import java.io.RandomAccessFile; import java.util.List; +import jdk.jfr.Recording; import jdk.jfr.consumer.RecordedEvent; /** @@ -43,18 +44,12 @@ public class TestThreadCPULoadEvent extends JfrRecordingTest { private static final int MILLIS = 50; - @Override - public String[] getTestedEvents() { - return new String[]{"jdk.ThreadCPULoad"}; - } + @Test + public void test() throws Throwable { - @Override - protected void validateEvents(List events) throws Throwable { - assertEquals(1, events.size()); - } + String[] events = new String[]{"jdk.ThreadCPULoad"}; + Recording recording = startRecording(events); - @Test - public void test() throws Exception { Thread thread = new Thread(() -> { long time = System.currentTimeMillis() + MILLIS; do { @@ -63,6 +58,12 @@ public void test() throws Exception { }); thread.start(); thread.join(); + + stopRecording(recording, TestThreadCPULoadEvent::validateEvents); + } + + private static void validateEvents(List events) { + assertEquals(1, events.size()); } private static void writeToFile() { From cf5b3507613b0bfa41ef6e4c19c90c5513f0975c Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Wed, 26 Apr 2023 12:02:05 +0300 Subject: [PATCH 04/15] Move time thread locals from JfrThreadLocal to ThreadCPULoadEvent --- .../oracle/svm/core/jfr/JfrThreadLocal.java | 35 ------------------- .../core/jfr/events/ThreadCPULoadEvent.java | 20 +++++++---- 2 files changed, 13 insertions(+), 42 deletions(-) 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 81eec7ee36c7..8945580b7122 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 @@ -88,11 +88,6 @@ public class JfrThreadLocal implements ThreadListener { private static final FastThreadLocalLong unparseableStacks = FastThreadLocalFactory.createLong("JfrThreadLocal.unparseableStacks"); private static final FastThreadLocalWord samplerWriterData = FastThreadLocalFactory.createWord("JfrThreadLocal.samplerWriterData"); - /* ThreadCPULoad thread-locals. */ - private static final FastThreadLocalLong cpuTime = FastThreadLocalFactory.createLong("JfrThreadLocal.cpuTime"); - private static final FastThreadLocalLong userTime = FastThreadLocalFactory.createLong("JfrThreadLocal.userTime"); - private static final FastThreadLocalLong wallClockTime = FastThreadLocalFactory.createLong("JfrThreadLocal.wallClockTime"); - /* Non-thread-local fields. */ private static final JfrBufferList javaBufferList = new JfrBufferList(); private static final JfrBufferList nativeBufferList = new JfrBufferList(); @@ -459,34 +454,4 @@ public static void setSamplerWriterData(SamplerSampleWriterData data) { public static SamplerSampleWriterData getSamplerWriterData() { return samplerWriterData.get(); } - - @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - public static long getCpuTime(IsolateThread thread) { - return cpuTime.get(thread); - } - - @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - public static void setCpuTime(IsolateThread thread, long value) { - cpuTime.set(thread, value); - } - - @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - public static long getUserTime(IsolateThread thread) { - return userTime.get(thread); - } - - @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - public static void setUserTime(IsolateThread thread, long value) { - userTime.set(thread, value); - } - - @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - public static long getWallClockTime(IsolateThread thread) { - return wallClockTime.get(thread); - } - - @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - public static void setWallClockTime(IsolateThread thread, long value) { - wallClockTime.set(thread, value); - } } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java index a7b6690d15e0..2a2ba4af61e7 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java @@ -41,11 +41,17 @@ import com.oracle.svm.core.thread.VMThreads; import com.oracle.svm.core.thread.PlatformThreads; import com.oracle.svm.core.thread.ThreadCpuTimeSupport; +import com.oracle.svm.core.threadlocal.FastThreadLocalLong; +import com.oracle.svm.core.threadlocal.FastThreadLocalFactory; import static com.oracle.svm.core.thread.PlatformThreads.IsolateThreadConsumer; 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 final int NANOSECS_PER_MILLISEC = 1_000_000; private static volatile int lastActiveProcessorCount; @@ -75,11 +81,11 @@ public static void emitEvents() { private static void emitForThread(IsolateThread isolateThread) { long currCpuTime = getThreadCpuTime(isolateThread, true); - long prevCpuTime = JfrThreadLocal.getCpuTime(isolateThread); + long prevCpuTime = cpuTimeTL.get(isolateThread); long currWallClockTime = getWallClockTime(); - long prevWallClockTime = JfrThreadLocal.getWallClockTime(isolateThread); - JfrThreadLocal.setWallClockTime(isolateThread, currWallClockTime); + long prevWallClockTime = wallClockTimeTL.get(isolateThread); + wallClockTimeTL.set(isolateThread, currWallClockTime); // Threshold of 1 ms if (currCpuTime - prevCpuTime < 1 * NANOSECS_PER_MILLISEC) { @@ -87,7 +93,7 @@ private static void emitForThread(IsolateThread isolateThread) { } long currUserTime = getThreadCpuTime(isolateThread, false); - long prevUserTime = JfrThreadLocal.getUserTime(isolateThread); + long prevUserTime = userTimeTL.get(isolateThread); long currSystemTime = currCpuTime - currUserTime; long prevSystemTime = prevCpuTime - prevUserTime; @@ -121,8 +127,8 @@ private static void emitForThread(IsolateThread isolateThread) { } } - JfrThreadLocal.setCpuTime(isolateThread, currCpuTime); - JfrThreadLocal.setUserTime(isolateThread, currUserTime); + cpuTimeTL.set(isolateThread, currCpuTime); + userTimeTL.set(isolateThread, currUserTime); JfrNativeEventWriterData data = StackValue.get(JfrNativeEventWriterData.class); JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data); @@ -162,6 +168,6 @@ private static long getWallClockTime() { @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) public static void initializeWallClockTime(IsolateThread isolateThread) { - JfrThreadLocal.setWallClockTime(isolateThread, getWallClockTime()); + wallClockTimeTL.set(isolateThread, getWallClockTime()); } } From 76e19682bfb310eee568a887a922df694cd1d66d Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Wed, 26 Apr 2023 12:09:45 +0300 Subject: [PATCH 05/15] Remove @Uninterruptible from EndChunkNativePeriodicEvents.emitThreadCPULoad() method --- .../oracle/svm/core/jfr/events/EndChunkNativePeriodicEvents.java | 1 - 1 file changed, 1 deletion(-) diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/EndChunkNativePeriodicEvents.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/EndChunkNativePeriodicEvents.java index 23c6ab4fbb2b..0a1c3b60ac8c 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/EndChunkNativePeriodicEvents.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/EndChunkNativePeriodicEvents.java @@ -177,7 +177,6 @@ private static JfrEventWriteStatus emitOSInformation0(JfrNativeEventWriterData d return JfrNativeEventWriter.endEvent(data, isLarge); } - @Uninterruptible(reason = "Accesses a JFR buffer.") private static void emitThreadCPULoad() { ThreadCPULoadEvent.emitEvents(); } From 2db9134bf168a5b5bea6020e721058e5cc109e2f Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Wed, 26 Apr 2023 12:18:48 +0300 Subject: [PATCH 06/15] Use TimeUtils.nanosPerMilli in ThreadCPULoadEvent --- .../com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java index 2a2ba4af61e7..3f37c1893ab9 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java @@ -43,6 +43,7 @@ import com.oracle.svm.core.thread.ThreadCpuTimeSupport; import com.oracle.svm.core.threadlocal.FastThreadLocalLong; import com.oracle.svm.core.threadlocal.FastThreadLocalFactory; +import com.oracle.svm.core.util.TimeUtils; import static com.oracle.svm.core.thread.PlatformThreads.IsolateThreadConsumer; @@ -52,7 +53,6 @@ public class ThreadCPULoadEvent { private static final FastThreadLocalLong userTimeTL = FastThreadLocalFactory.createLong("ThreadCPULoadEvent.userTimeTL"); private static final FastThreadLocalLong wallClockTimeTL = FastThreadLocalFactory.createLong("ThreadCPULoadEvent.wallClockTimeTL"); - private static final int NANOSECS_PER_MILLISEC = 1_000_000; private static volatile int lastActiveProcessorCount; private static final IsolateThreadConsumer threadCPULoadEventConsumer = new IsolateThreadConsumer() { @@ -88,7 +88,7 @@ private static void emitForThread(IsolateThread isolateThread) { wallClockTimeTL.set(isolateThread, currWallClockTime); // Threshold of 1 ms - if (currCpuTime - prevCpuTime < 1 * NANOSECS_PER_MILLISEC) { + if (currCpuTime - prevCpuTime < 1 * TimeUtils.nanosPerMilli) { return; } From 8f0b41d7b19e3b3bdafa15af8195bc450935dbc6 Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Wed, 26 Apr 2023 14:58:09 +0300 Subject: [PATCH 07/15] Rename wallClockTime to time --- .../svm/core/jfr/events/ThreadCPULoadEvent.java | 14 +++++++------- 1 file changed, 7 insertions(+), 7 deletions(-) diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java index 3f37c1893ab9..965572b2c971 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java @@ -51,7 +51,7 @@ 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 final FastThreadLocalLong timeTL = FastThreadLocalFactory.createLong("ThreadCPULoadEvent.timeTL"); private static volatile int lastActiveProcessorCount; @@ -83,9 +83,9 @@ private static void emitForThread(IsolateThread isolateThread) { long currCpuTime = getThreadCpuTime(isolateThread, true); long prevCpuTime = cpuTimeTL.get(isolateThread); - long currWallClockTime = getWallClockTime(); - long prevWallClockTime = wallClockTimeTL.get(isolateThread); - wallClockTimeTL.set(isolateThread, currWallClockTime); + long currTime = getCurrentTime(); + long prevTime = timeTL.get(isolateThread); + timeTL.set(isolateThread, currTime); // Threshold of 1 ms if (currCpuTime - prevCpuTime < 1 * TimeUtils.nanosPerMilli) { @@ -109,7 +109,7 @@ private static void emitForThread(IsolateThread isolateThread) { long userTime = currUserTime - prevUserTime; long systemTime = currSystemTime - prevSystemTime; - long wallClockTime = currWallClockTime - prevWallClockTime; + long wallClockTime = currTime - prevTime; float totalAvailableTime = wallClockTime * processorsCount; // Avoid reporting percentages above the theoretical max @@ -162,12 +162,12 @@ private static long getThreadCpuTime(IsolateThread isolateThread, boolean includ } @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - private static long getWallClockTime() { + private static long getCurrentTime() { return System.nanoTime(); } @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) public static void initializeWallClockTime(IsolateThread isolateThread) { - wallClockTimeTL.set(isolateThread, getWallClockTime()); + timeTL.set(isolateThread, getCurrentTime()); } } From 4d85b6372adccc22e5786dcc8c1d7728c1cf8d4b Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Wed, 26 Apr 2023 15:56:20 +0300 Subject: [PATCH 08/15] Check user and system time range in TestThreadCPULoadEvent --- .../com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java | 8 ++++++++ 1 file changed, 8 insertions(+) diff --git a/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java index b2e41d2b9936..0cf80b0d02c1 100644 --- a/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java @@ -28,6 +28,8 @@ import org.junit.Test; import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertNotNull; +import static org.junit.Assert.assertTrue; import java.io.File; import java.io.IOException; @@ -64,6 +66,12 @@ public void test() throws Throwable { private static void validateEvents(List events) { assertEquals(1, events.size()); + RecordedEvent event = events.get(0); + assertNotNull(event.getThread()); + float userTime = event. getValue("user"); + assertTrue("User time is outside 0..1 range", 0.0 <= userTime && userTime <= 1.0); + float systemTime = event. getValue("system"); + assertTrue("System time is outside 0..1 range", 0.0 <= systemTime && systemTime <= 1.0); } private static void writeToFile() { From 8bfb6a0b828481662e0c7cbc73598797daccb970 Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Wed, 26 Apr 2023 18:50:13 +0300 Subject: [PATCH 09/15] Compare system cpu time for 2 threads in TestThreadCPULoadEvent --- .../svm/test/jfr/TestThreadCPULoadEvent.java | 62 ++++++++++++++----- 1 file changed, 47 insertions(+), 15 deletions(-) diff --git a/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java index 0cf80b0d02c1..e57ea4a38e1b 100644 --- a/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java @@ -35,16 +35,21 @@ import java.io.IOException; import java.io.RandomAccessFile; import java.util.List; +import java.util.Map; +import java.util.HashMap; import jdk.jfr.Recording; import jdk.jfr.consumer.RecordedEvent; +import jdk.jfr.consumer.RecordedThread; /** * Test if event ThreadCPULoad is generated after a thread exit. */ public class TestThreadCPULoadEvent extends JfrRecordingTest { - private static final int MILLIS = 50; + private static final int DELAY = 50; + private static final String THREAD_NAME_1 = "Thread-1"; + private static final String THREAD_NAME_2 = "Thread-2"; @Test public void test() throws Throwable { @@ -52,26 +57,53 @@ public void test() throws Throwable { String[] events = new String[]{"jdk.ThreadCPULoad"}; Recording recording = startRecording(events); + Thread thread1 = createAndStartBusyWaitThread(THREAD_NAME_1, DELAY / 10); + Thread thread2 = createAndStartBusyWaitThread(THREAD_NAME_2, DELAY); + + thread1.join(); + thread2.join(); + + stopRecording(recording, TestThreadCPULoadEvent::validateEvents); + } + + private static void validateEvents(List events) { + assertEquals(2, events.size()); + Map systemTimes = new HashMap<>(); + + for (RecordedEvent e : events) { + float userTime = e.getValue("user"); + float systemTime = e.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, final int delay) { Thread thread = new Thread(() -> { - long time = System.currentTimeMillis() + MILLIS; - do { - writeToFile(); - } while (time > System.currentTimeMillis()); + busyWait(delay); + sleep(DELAY - delay); }); + thread.setName(name); thread.start(); - thread.join(); + return thread; + } - stopRecording(recording, TestThreadCPULoadEvent::validateEvents); + private static void busyWait(long delay) { + long time = System.currentTimeMillis() + delay; + do { + writeToFile(); + } while (time > System.currentTimeMillis()); } - private static void validateEvents(List events) { - assertEquals(1, events.size()); - RecordedEvent event = events.get(0); - assertNotNull(event.getThread()); - float userTime = event. getValue("user"); - assertTrue("User time is outside 0..1 range", 0.0 <= userTime && userTime <= 1.0); - float systemTime = event. getValue("system"); - assertTrue("System time is outside 0..1 range", 0.0 <= systemTime && systemTime <= 1.0); + private static void sleep(long delay) { + try { + Thread.sleep(delay); + } catch (InterruptedException ignored) { + } } private static void writeToFile() { From b418c07d161c82e5974cd6257b09f8fcb4034f0d Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Fri, 28 Apr 2023 09:55:25 +0300 Subject: [PATCH 10/15] Use VMOperation instead of IsolateThreadConsumer --- .../core/jfr/events/ThreadCPULoadEvent.java | 32 +++++++++++-------- .../svm/core/thread/PlatformThreads.java | 18 ----------- 2 files changed, 18 insertions(+), 32 deletions(-) diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java index 965572b2c971..bef6ccf6622f 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java @@ -35,18 +35,18 @@ import com.oracle.svm.core.jfr.JfrNativeEventWriterDataAccess; import com.oracle.svm.core.jfr.JfrTicks; import com.oracle.svm.core.jfr.JfrThreadLocal; +import com.oracle.svm.core.heap.VMOperationInfos; import com.oracle.svm.core.jdk.Jvm; import com.oracle.svm.core.thread.VMThreads; +import com.oracle.svm.core.thread.JavaVMOperation; import com.oracle.svm.core.thread.PlatformThreads; import com.oracle.svm.core.thread.ThreadCpuTimeSupport; import com.oracle.svm.core.threadlocal.FastThreadLocalLong; import com.oracle.svm.core.threadlocal.FastThreadLocalFactory; import com.oracle.svm.core.util.TimeUtils; -import static com.oracle.svm.core.thread.PlatformThreads.IsolateThreadConsumer; - public class ThreadCPULoadEvent { private static final FastThreadLocalLong cpuTimeTL = FastThreadLocalFactory.createLong("ThreadCPULoadEvent.cpuTimeTL"); @@ -55,14 +55,6 @@ public class ThreadCPULoadEvent { private static volatile int lastActiveProcessorCount; - private static final IsolateThreadConsumer threadCPULoadEventConsumer = new IsolateThreadConsumer() { - - @Uninterruptible(reason = "Thread locks/holds the THREAD_MUTEX.") - public void accept(IsolateThread isolateThread) { - emitForThread(isolateThread); - } - }; - @Uninterruptible(reason = "Accesses a JFR buffer.") public static void emit(IsolateThread isolateThread) { if (JfrEvent.ThreadCPULoad.shouldEmit()) { @@ -70,11 +62,9 @@ public static void emit(IsolateThread isolateThread) { } } - @Uninterruptible(reason = "Accesses a JFR buffer.") public static void emitEvents() { - if (JfrEvent.ThreadCPULoad.shouldEmit()) { - PlatformThreads.iterateIsolateThreads(threadCPULoadEventConsumer); - } + EmitThreadCPULoadEventsVMOperation vmOp = new EmitThreadCPULoadEventsVMOperation(); + vmOp.enqueue(); } @Uninterruptible(reason = "Accesses a JFR buffer.") @@ -170,4 +160,18 @@ private static long getCurrentTime() { public static void initializeWallClockTime(IsolateThread isolateThread) { timeTL.set(isolateThread, getCurrentTime()); } + + private static final class EmitThreadCPULoadEventsVMOperation extends JavaVMOperation { + + EmitThreadCPULoadEventsVMOperation() { + super(VMOperationInfos.get(EmitThreadCPULoadEventsVMOperation.class, "Emit ThreadCPULoad events", SystemEffect.SAFEPOINT)); + } + + @Override + protected void operate() { + for (IsolateThread isolateThread = VMThreads.firstThread(); isolateThread.isNonNull(); isolateThread = VMThreads.nextThread(isolateThread)) { + emit(isolateThread); + } + } + } } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/PlatformThreads.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/PlatformThreads.java index d863bfaf4fce..3b6076c42a21 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/PlatformThreads.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/thread/PlatformThreads.java @@ -251,18 +251,6 @@ public static long getThreadCpuTime(long javaThreadId, boolean includeSystemTime } } - @Uninterruptible(reason = "Thread locks/holds the THREAD_MUTEX.") - public static void iterateIsolateThreads(IsolateThreadConsumer consumer) { - VMThreads.lockThreadMutexInNativeCode(); - try { - for (IsolateThread cur = VMThreads.firstThread(); cur.isNonNull(); cur = VMThreads.nextThread(cur)) { - consumer.accept(cur); - } - } finally { - VMThreads.THREAD_MUTEX.unlock(); - } - } - @Uninterruptible(reason = "Thread locks/holds the THREAD_MUTEX.") public static void getThreadAllocatedBytes(long[] javaThreadIds, long[] result) { VMThreads.lockThreadMutexInNativeCode(); @@ -1203,12 +1191,6 @@ static void blockedOn(Target_sun_nio_ch_Interruptible b) { public interface OSThreadHandle extends PointerBase { } - - public interface IsolateThreadConsumer { - - @Uninterruptible(reason = "Thread locks/holds the THREAD_MUTEX.") - void accept(IsolateThread isolateThread); - } } @TargetClass(value = ThreadPoolExecutor.class, innerClass = "Worker") From 8ba6c5d5574763846a7396c15b037db404cfd8f3 Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Fri, 28 Apr 2023 10:24:32 +0300 Subject: [PATCH 11/15] Rename initializeWallClockTime to initializeTime --- .../src/com/oracle/svm/core/jfr/JfrThreadLocal.java | 2 +- .../src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) 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 8945580b7122..7acf2084124e 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 @@ -126,7 +126,7 @@ public void teardown() { public void beforeThreadStart(IsolateThread isolateThread, Thread javaThread) { if (SubstrateJVM.get().isRecording()) { SubstrateJVM.getThreadRepo().registerThread(javaThread); - ThreadCPULoadEvent.initializeWallClockTime(isolateThread); + ThreadCPULoadEvent.initializeTime(isolateThread); ThreadStartEvent.emit(javaThread); } } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java index bef6ccf6622f..b873039ddc67 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java @@ -157,7 +157,7 @@ private static long getCurrentTime() { } @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - public static void initializeWallClockTime(IsolateThread isolateThread) { + public static void initializeTime(IsolateThread isolateThread) { timeTL.set(isolateThread, getCurrentTime()); } From 923a04e543741ad5c22e1f8efc4ddf877575d7e9 Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Fri, 28 Apr 2023 11:48:52 +0300 Subject: [PATCH 12/15] Rename initializeTime to initCurrentTime --- .../src/com/oracle/svm/core/jfr/JfrThreadLocal.java | 2 +- .../src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) 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 7acf2084124e..753b15f726aa 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 @@ -126,7 +126,7 @@ public void teardown() { public void beforeThreadStart(IsolateThread isolateThread, Thread javaThread) { if (SubstrateJVM.get().isRecording()) { SubstrateJVM.getThreadRepo().registerThread(javaThread); - ThreadCPULoadEvent.initializeTime(isolateThread); + ThreadCPULoadEvent.initCurrentTime(isolateThread); ThreadStartEvent.emit(javaThread); } } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java index b873039ddc67..c0f516b7d97d 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java @@ -157,7 +157,7 @@ private static long getCurrentTime() { } @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - public static void initializeTime(IsolateThread isolateThread) { + public static void initCurrentTime(IsolateThread isolateThread) { timeTL.set(isolateThread, getCurrentTime()); } From 4d4bef71039a598b4f29ed87f5c7a86ecfb73a2a Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Tue, 2 May 2023 12:09:48 +0300 Subject: [PATCH 13/15] Check should emit in emit events as a minor optimization --- .../svm/core/jfr/events/ThreadCPULoadEvent.java | 11 +++++++++-- 1 file changed, 9 insertions(+), 2 deletions(-) diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java index c0f516b7d97d..6e6473d27aa0 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java @@ -62,9 +62,16 @@ public static void emit(IsolateThread isolateThread) { } } + @Uninterruptible(reason = "Check should emit in emit events as a minor optimization.") + private static boolean shouldEmit() { + return JfrEvent.ThreadCPULoad.shouldEmit(); + } + public static void emitEvents() { - EmitThreadCPULoadEventsVMOperation vmOp = new EmitThreadCPULoadEventsVMOperation(); - vmOp.enqueue(); + if (shouldEmit()) { + EmitThreadCPULoadEventsVMOperation vmOp = new EmitThreadCPULoadEventsVMOperation(); + vmOp.enqueue(); + } } @Uninterruptible(reason = "Accesses a JFR buffer.") From 7280fe84abc4965fee1fd238554072e929ed7823 Mon Sep 17 00:00:00 2001 From: AlexanderScherbatiy Date: Tue, 2 May 2023 14:27:00 +0300 Subject: [PATCH 14/15] Init ThreadCPULoad current time when JFR begins a recording operation --- .../src/com/oracle/svm/core/jfr/JfrThreadRepository.java | 2 ++ .../com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java | 5 +++-- 2 files changed, 5 insertions(+), 2 deletions(-) diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrThreadRepository.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrThreadRepository.java index 47e103ebedfa..428e3dd2f7cd 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrThreadRepository.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrThreadRepository.java @@ -33,6 +33,7 @@ import com.oracle.svm.core.Uninterruptible; import com.oracle.svm.core.jdk.UninterruptibleUtils; +import com.oracle.svm.core.jfr.events.ThreadCPULoadEvent; import com.oracle.svm.core.jfr.traceid.JfrTraceIdEpoch; import com.oracle.svm.core.jfr.utils.JfrVisited; import com.oracle.svm.core.jfr.utils.JfrVisitedTable; @@ -87,6 +88,7 @@ public void registerRunningThreads() { if (thread != null) { registerThread(thread); } + ThreadCPULoadEvent.initCurrentTime(isolateThread); } } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java index 6e6473d27aa0..bd6a0dbea1cb 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java @@ -41,7 +41,6 @@ import com.oracle.svm.core.thread.VMThreads; import com.oracle.svm.core.thread.JavaVMOperation; -import com.oracle.svm.core.thread.PlatformThreads; import com.oracle.svm.core.thread.ThreadCpuTimeSupport; import com.oracle.svm.core.threadlocal.FastThreadLocalLong; import com.oracle.svm.core.threadlocal.FastThreadLocalFactory; @@ -165,7 +164,9 @@ private static long getCurrentTime() { @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) public static void initCurrentTime(IsolateThread isolateThread) { - timeTL.set(isolateThread, getCurrentTime()); + if (timeTL.get(isolateThread) <= 0) { + timeTL.set(isolateThread, getCurrentTime()); + } } private static final class EmitThreadCPULoadEventsVMOperation extends JavaVMOperation { From cf6abcee04e719269047af41da55773ec5e0348b Mon Sep 17 00:00:00 2001 From: Christian Haeubl Date: Tue, 9 May 2023 12:07:34 +0200 Subject: [PATCH 15/15] Cleanups. --- substratevm/CHANGELOG.md | 1 + .../oracle/svm/core/jfr/JfrThreadLocal.java | 4 +- .../svm/core/jfr/JfrThreadRepository.java | 2 - .../core/jfr/events/ThreadCPULoadEvent.java | 133 +++++++++--------- .../svm/test/jfr/TestThreadCPULoadEvent.java | 60 +++----- 5 files changed, 89 insertions(+), 111 deletions(-) diff --git a/substratevm/CHANGELOG.md b/substratevm/CHANGELOG.md index 57c1f42412f3..866d22457587 100644 --- a/substratevm/CHANGELOG.md +++ b/substratevm/CHANGELOG.md @@ -4,6 +4,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-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. 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 753b15f726aa..b5b2568341f7 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 @@ -36,9 +36,9 @@ 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.jfr.events.ThreadCPULoadEvent; import com.oracle.svm.core.sampler.SamplerBuffer; import com.oracle.svm.core.sampler.SamplerSampleWriterData; import com.oracle.svm.core.thread.JavaThreads; @@ -126,7 +126,7 @@ public void teardown() { public void beforeThreadStart(IsolateThread isolateThread, Thread javaThread) { if (SubstrateJVM.get().isRecording()) { SubstrateJVM.getThreadRepo().registerThread(javaThread); - ThreadCPULoadEvent.initCurrentTime(isolateThread); + ThreadCPULoadEvent.initWallclockTime(isolateThread); ThreadStartEvent.emit(javaThread); } } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrThreadRepository.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrThreadRepository.java index 428e3dd2f7cd..47e103ebedfa 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrThreadRepository.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/JfrThreadRepository.java @@ -33,7 +33,6 @@ import com.oracle.svm.core.Uninterruptible; import com.oracle.svm.core.jdk.UninterruptibleUtils; -import com.oracle.svm.core.jfr.events.ThreadCPULoadEvent; import com.oracle.svm.core.jfr.traceid.JfrTraceIdEpoch; import com.oracle.svm.core.jfr.utils.JfrVisited; import com.oracle.svm.core.jfr.utils.JfrVisitedTable; @@ -88,7 +87,6 @@ public void registerRunningThreads() { if (thread != null) { registerThread(thread); } - ThreadCPULoadEvent.initCurrentTime(isolateThread); } } diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java index bd6a0dbea1cb..a610b3580c3b 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jfr/events/ThreadCPULoadEvent.java @@ -25,106 +25,94 @@ */ package com.oracle.svm.core.jfr.events; -import org.graalvm.nativeimage.StackValue; 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.jfr.JfrThreadLocal; -import com.oracle.svm.core.heap.VMOperationInfos; - -import com.oracle.svm.core.jdk.Jvm; - -import com.oracle.svm.core.thread.VMThreads; import com.oracle.svm.core.thread.JavaVMOperation; import com.oracle.svm.core.thread.ThreadCpuTimeSupport; -import com.oracle.svm.core.threadlocal.FastThreadLocalLong; +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 timeTL = FastThreadLocalFactory.createLong("ThreadCPULoadEvent.timeTL"); + private static final FastThreadLocalLong wallclockTimeTL = FastThreadLocalFactory.createLong("ThreadCPULoadEvent.wallclockTimeTL"); private static volatile int lastActiveProcessorCount; - @Uninterruptible(reason = "Accesses a JFR buffer.") - public static void emit(IsolateThread isolateThread) { - if (JfrEvent.ThreadCPULoad.shouldEmit()) { - emitForThread(isolateThread); - } - } - - @Uninterruptible(reason = "Check should emit in emit events as a minor optimization.") - private static boolean shouldEmit() { - return JfrEvent.ThreadCPULoad.shouldEmit(); - } - - public static void emitEvents() { - if (shouldEmit()) { - EmitThreadCPULoadEventsVMOperation vmOp = new EmitThreadCPULoadEventsVMOperation(); - vmOp.enqueue(); - } + @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) + public static void initWallclockTime(IsolateThread isolateThread) { + wallclockTimeTL.set(isolateThread, getCurrentTime()); } @Uninterruptible(reason = "Accesses a JFR buffer.") - private static void emitForThread(IsolateThread isolateThread) { + public static void emit(IsolateThread isolateThread) { + if (!JfrEvent.ThreadCPULoad.shouldEmit()) { + return; + } - long currCpuTime = getThreadCpuTime(isolateThread, true); + long curCpuTime = getThreadCpuTime(isolateThread, true); long prevCpuTime = cpuTimeTL.get(isolateThread); - long currTime = getCurrentTime(); - long prevTime = timeTL.get(isolateThread); - timeTL.set(isolateThread, currTime); + long curTime = getCurrentTime(); + long prevTime = wallclockTimeTL.get(isolateThread); + wallclockTimeTL.set(isolateThread, curTime); - // Threshold of 1 ms - if (currCpuTime - prevCpuTime < 1 * TimeUtils.nanosPerMilli) { + /* Threshold of 1 ms. */ + if (curCpuTime - prevCpuTime < 1 * TimeUtils.nanosPerMilli) { return; } - long currUserTime = getThreadCpuTime(isolateThread, false); + long curUserTime = getThreadCpuTime(isolateThread, false); long prevUserTime = userTimeTL.get(isolateThread); - long currSystemTime = currCpuTime - currUserTime; + 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 > currSystemTime) { - currCpuTime += prevSystemTime - currSystemTime; - currSystemTime = prevSystemTime; + /* + * 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 = currUserTime - prevUserTime; - long systemTime = currSystemTime - prevSystemTime; - long wallClockTime = currTime - prevTime; + long userTime = curUserTime - prevUserTime; + long systemTime = curSystemTime - prevSystemTime; + long wallClockTime = curTime - prevTime; float totalAvailableTime = wallClockTime * processorsCount; - // Avoid reporting percentages above the theoretical max + /* Avoid reporting percentages above the theoretical max. */ if (userTime + systemTime > wallClockTime) { long excess = userTime + systemTime - wallClockTime; - currCpuTime -= excess; + curCpuTime -= excess; if (userTime > excess) { userTime -= excess; - currUserTime -= excess; + curUserTime -= excess; } else { excess -= userTime; - currUserTime -= userTime; + curUserTime -= userTime; userTime = 0; systemTime -= excess; } } - cpuTimeTL.set(isolateThread, currCpuTime); - userTimeTL.set(isolateThread, currUserTime); + cpuTimeTL.set(isolateThread, curCpuTime); + userTimeTL.set(isolateThread, curUserTime); JfrNativeEventWriterData data = StackValue.get(JfrNativeEventWriterData.class); JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data); @@ -137,23 +125,36 @@ private static void emitForThread(IsolateThread isolateThread) { 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() { - int currProcessorCount = Jvm.JVM_ActiveProcessorCount(); + /* + * 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 = currProcessorCount; + 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% - // Math.max(int, int) does not have Uninterruptible annotation - return (currProcessorCount > prevProcessorCount) ? currProcessorCount : prevProcessorCount; + /* + * 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); + VMThreads.findOSThreadHandleForIsolateThread(isolateThread), includeSystemTime); return (threadCpuTime < 0) ? 0 : threadCpuTime; } @@ -162,17 +163,15 @@ private static long getCurrentTime() { return System.nanoTime(); } - @Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true) - public static void initCurrentTime(IsolateThread isolateThread) { - if (timeTL.get(isolateThread) <= 0) { - timeTL.set(isolateThread, getCurrentTime()); - } + @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 EmitThreadCPULoadEventsVMOperation extends JavaVMOperation { - - EmitThreadCPULoadEventsVMOperation() { - super(VMOperationInfos.get(EmitThreadCPULoadEventsVMOperation.class, "Emit ThreadCPULoad events", SystemEffect.SAFEPOINT)); + private static final class EmitThreadCPULoadEventsOperation extends JavaVMOperation { + EmitThreadCPULoadEventsOperation() { + super(VMOperationInfos.get(EmitThreadCPULoadEventsOperation.class, "Emit ThreadCPULoad events", SystemEffect.SAFEPOINT)); } @Override diff --git a/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java index e57ea4a38e1b..44bb4314a861 100644 --- a/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java +++ b/substratevm/src/com.oracle.svm.test/src/com/oracle/svm/test/jfr/TestThreadCPULoadEvent.java @@ -26,39 +26,30 @@ package com.oracle.svm.test.jfr; -import org.junit.Test; import static org.junit.Assert.assertEquals; -import static org.junit.Assert.assertNotNull; import static org.junit.Assert.assertTrue; -import java.io.File; -import java.io.IOException; -import java.io.RandomAccessFile; +import java.util.HashMap; import java.util.List; import java.util.Map; -import java.util.HashMap; + +import org.junit.Test; import jdk.jfr.Recording; import jdk.jfr.consumer.RecordedEvent; -import jdk.jfr.consumer.RecordedThread; -/** - * Test if event ThreadCPULoad is generated after a thread exit. - */ public class TestThreadCPULoadEvent extends JfrRecordingTest { - - private static final int DELAY = 50; + 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, DELAY / 10); - Thread thread2 = createAndStartBusyWaitThread(THREAD_NAME_2, DELAY); + Thread thread1 = createAndStartBusyWaitThread(THREAD_NAME_1, 0.1); + Thread thread2 = createAndStartBusyWaitThread(THREAD_NAME_2, 1.0); thread1.join(); thread2.join(); @@ -71,21 +62,25 @@ private static void validateEvents(List events) { Map systemTimes = new HashMap<>(); for (RecordedEvent e : events) { - float userTime = e.getValue("user"); - float systemTime = e.getValue("system"); + float userTime = e. getValue("user"); + float systemTime = e. 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)); + systemTimes.get(THREAD_NAME_1) < systemTimes.get(THREAD_NAME_2)); } - private static Thread createAndStartBusyWaitThread(String name, final int delay) { + private static Thread createAndStartBusyWaitThread(String name, double busyPercent) { Thread thread = new Thread(() -> { - busyWait(delay); - sleep(DELAY - delay); + 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(); @@ -93,10 +88,10 @@ private static Thread createAndStartBusyWaitThread(String name, final int delay) } private static void busyWait(long delay) { - long time = System.currentTimeMillis() + delay; - do { - writeToFile(); - } while (time > System.currentTimeMillis()); + long end = System.currentTimeMillis() + delay; + while (end > System.currentTimeMillis()) { + /* Nothing to do. */ + } } private static void sleep(long delay) { @@ -105,19 +100,4 @@ private static void sleep(long delay) { } catch (InterruptedException ignored) { } } - - private static void writeToFile() { - int fileSize = 1000; - try { - File temp = File.createTempFile("TestThreadCPULoadEventData_", ".tmp"); - temp.deleteOnExit(); - try (RandomAccessFile file = new RandomAccessFile(temp, "rw")) { - for (int i = 0; i < fileSize; i++) { - file.writeByte(i); - } - } - } catch (IOException e) { - e.printStackTrace(); - } - } }