Skip to content

Commit c2d1cc3

Browse files
christianhaeublchristianhaeubl
committed
[GR-45841] Add JFR event ThreadCPULoad.
PullRequest: graal/14534
2 parents 64cbed0 + 0ef7d6b commit c2d1cc3

File tree

7 files changed

+308
-0
lines changed

7 files changed

+308
-0
lines changed

‎substratevm/CHANGELOG.md‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -5,6 +5,7 @@ This changelog summarizes major changes to GraalVM Native Image.
55
## Version 23.1.0
66
* (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.
77
* (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.
8+
* (GR-45841) BellSoft added support for the JFR event ThreadCPULoad.
89

910
## Version 23.0.0
1011
* (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‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,7 @@
3636
public final class JfrEvent {
3737
public static final JfrEvent ThreadStart = create("jdk.ThreadStart");
3838
public static final JfrEvent ThreadEnd = create("jdk.ThreadEnd");
39+
public static final JfrEvent ThreadCPULoad = create("jdk.ThreadCPULoad");
3940
public static final JfrEvent DataLoss = create("jdk.DataLoss");
4041
public static final JfrEvent ClassLoadingStatistics = create("jdk.ClassLoadingStatistics");
4142
public static final JfrEvent InitialEnvironmentVariable = create("jdk.InitialEnvironmentVariable");

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

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -190,6 +190,17 @@ public static void putLong(JfrNativeEventWriterData data, long v) {
190190
}
191191
}
192192

193+
@Uninterruptible(reason = "Accesses a native JFR buffer.", callerMustBe = true)
194+
public static void putFloat(JfrNativeEventWriterData data, float v) {
195+
if (ensureSize(data, Float.BYTES)) {
196+
int bits = Float.floatToIntBits(v);
197+
putUncheckedByte(data, (byte) (bits >>> 24));
198+
putUncheckedByte(data, (byte) (bits >>> 16));
199+
putUncheckedByte(data, (byte) (bits >>> 8));
200+
putUncheckedByte(data, (byte) (bits));
201+
}
202+
}
203+
193204
@Uninterruptible(reason = "Accesses a native JFR buffer.", callerMustBe = true)
194205
public static void putString(JfrNativeEventWriterData data, String string) {
195206
putString(data, string, null);

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

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -36,6 +36,7 @@
3636
import com.oracle.svm.core.SubstrateUtil;
3737
import com.oracle.svm.core.Uninterruptible;
3838
import com.oracle.svm.core.UnmanagedMemoryUtil;
39+
import com.oracle.svm.core.jfr.events.ThreadCPULoadEvent;
3940
import com.oracle.svm.core.jfr.events.ThreadEndEvent;
4041
import com.oracle.svm.core.jfr.events.ThreadStartEvent;
4142
import com.oracle.svm.core.sampler.SamplerBuffer;
@@ -125,6 +126,7 @@ public void teardown() {
125126
public void beforeThreadStart(IsolateThread isolateThread, Thread javaThread) {
126127
if (SubstrateJVM.get().isRecording()) {
127128
SubstrateJVM.getThreadRepo().registerThread(javaThread);
129+
ThreadCPULoadEvent.initWallclockTime(isolateThread);
128130
ThreadStartEvent.emit(javaThread);
129131
}
130132
}
@@ -134,6 +136,7 @@ public void beforeThreadStart(IsolateThread isolateThread, Thread javaThread) {
134136
public void afterThreadExit(IsolateThread isolateThread, Thread javaThread) {
135137
if (SubstrateJVM.get().isRecording()) {
136138
ThreadEndEvent.emit(javaThread);
139+
ThreadCPULoadEvent.emit(isolateThread);
137140
}
138141

139142
/*

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

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -60,6 +60,7 @@ public static void emit() {
6060
emitOSInformation(formatOSInformation());
6161
emitInitialEnvironmentVariables(getEnvironmentVariables());
6262
emitInitialSystemProperties(getSystemProperties());
63+
emitThreadCPULoad();
6364
}
6465

6566
@Uninterruptible(reason = "Accesses a JFR buffer.")
@@ -176,6 +177,10 @@ private static JfrEventWriteStatus emitOSInformation0(JfrNativeEventWriterData d
176177
return JfrNativeEventWriter.endEvent(data, isLarge);
177178
}
178179

180+
private static void emitThreadCPULoad() {
181+
ThreadCPULoadEvent.emitEvents();
182+
}
183+
179184
private static StringEntry[] getEnvironmentVariables() {
180185
Map<String, String> env = System.getenv();
181186
StringEntry[] result = new StringEntry[env.size()];

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

Lines changed: 184 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,184 @@
1+
/*
2+
* Copyright (c) 2023, 2023, Oracle and/or its affiliates. All rights reserved.
3+
* Copyright (c) 2023, 2023, BELLSOFT. All rights reserved.
4+
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
5+
*
6+
* This code is free software; you can redistribute it and/or modify it
7+
* under the terms of the GNU General Public License version 2 only, as
8+
* published by the Free Software Foundation. Oracle designates this
9+
* particular file as subject to the "Classpath" exception as provided
10+
* by Oracle in the LICENSE file that accompanied this code.
11+
*
12+
* This code is distributed in the hope that it will be useful, but WITHOUT
13+
* ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
14+
* FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
15+
* version 2 for more details (a copy is included in the LICENSE file that
16+
* accompanied this code).
17+
*
18+
* You should have received a copy of the GNU General Public License version
19+
* 2 along with this work; if not, write to the Free Software Foundation,
20+
* Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
21+
*
22+
* Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
23+
* or visit www.oracle.com if you need additional information or have any
24+
* questions.
25+
*/
26+
package com.oracle.svm.core.jfr.events;
27+
28+
import org.graalvm.nativeimage.IsolateThread;
29+
import org.graalvm.nativeimage.StackValue;
30+
31+
import com.oracle.svm.core.Uninterruptible;
32+
import com.oracle.svm.core.heap.VMOperationInfos;
33+
import com.oracle.svm.core.jdk.Jvm;
34+
import com.oracle.svm.core.jdk.UninterruptibleUtils;
35+
import com.oracle.svm.core.jfr.JfrEvent;
36+
import com.oracle.svm.core.jfr.JfrNativeEventWriter;
37+
import com.oracle.svm.core.jfr.JfrNativeEventWriterData;
38+
import com.oracle.svm.core.jfr.JfrNativeEventWriterDataAccess;
39+
import com.oracle.svm.core.jfr.JfrTicks;
40+
import com.oracle.svm.core.thread.JavaVMOperation;
41+
import com.oracle.svm.core.thread.ThreadCpuTimeSupport;
42+
import com.oracle.svm.core.thread.VMThreads;
43+
import com.oracle.svm.core.threadlocal.FastThreadLocalFactory;
44+
import com.oracle.svm.core.threadlocal.FastThreadLocalLong;
45+
import com.oracle.svm.core.util.TimeUtils;
46+
47+
public class ThreadCPULoadEvent {
48+
private static final FastThreadLocalLong cpuTimeTL = FastThreadLocalFactory.createLong("ThreadCPULoadEvent.cpuTimeTL");
49+
private static final FastThreadLocalLong userTimeTL = FastThreadLocalFactory.createLong("ThreadCPULoadEvent.userTimeTL");
50+
private static final FastThreadLocalLong wallclockTimeTL = FastThreadLocalFactory.createLong("ThreadCPULoadEvent.wallclockTimeTL");
51+
52+
private static volatile int lastActiveProcessorCount;
53+
54+
@Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true)
55+
public static void initWallclockTime(IsolateThread isolateThread) {
56+
wallclockTimeTL.set(isolateThread, getCurrentTime());
57+
}
58+
59+
@Uninterruptible(reason = "Accesses a JFR buffer.")
60+
public static void emit(IsolateThread isolateThread) {
61+
if (!JfrEvent.ThreadCPULoad.shouldEmit()) {
62+
return;
63+
}
64+
65+
long curCpuTime = getThreadCpuTime(isolateThread, true);
66+
long prevCpuTime = cpuTimeTL.get(isolateThread);
67+
68+
long curTime = getCurrentTime();
69+
long prevTime = wallclockTimeTL.get(isolateThread);
70+
wallclockTimeTL.set(isolateThread, curTime);
71+
72+
/* Threshold of 1 ms. */
73+
if (curCpuTime - prevCpuTime < 1 * TimeUtils.nanosPerMilli) {
74+
return;
75+
}
76+
77+
long curUserTime = getThreadCpuTime(isolateThread, false);
78+
long prevUserTime = userTimeTL.get(isolateThread);
79+
80+
long curSystemTime = curCpuTime - curUserTime;
81+
long prevSystemTime = prevCpuTime - prevUserTime;
82+
83+
/*
84+
* The user and total cpu usage clocks can have different resolutions, which can make us see
85+
* decreasing system time. Ensure time doesn't go backwards.
86+
*/
87+
if (prevSystemTime > curSystemTime) {
88+
curCpuTime += prevSystemTime - curSystemTime;
89+
curSystemTime = prevSystemTime;
90+
}
91+
92+
int processorsCount = getProcessorCount();
93+
94+
long userTime = curUserTime - prevUserTime;
95+
long systemTime = curSystemTime - prevSystemTime;
96+
long wallClockTime = curTime - prevTime;
97+
float totalAvailableTime = wallClockTime * processorsCount;
98+
99+
/* Avoid reporting percentages above the theoretical max. */
100+
if (userTime + systemTime > wallClockTime) {
101+
long excess = userTime + systemTime - wallClockTime;
102+
curCpuTime -= excess;
103+
if (userTime > excess) {
104+
userTime -= excess;
105+
curUserTime -= excess;
106+
} else {
107+
excess -= userTime;
108+
curUserTime -= userTime;
109+
userTime = 0;
110+
systemTime -= excess;
111+
}
112+
}
113+
114+
cpuTimeTL.set(isolateThread, curCpuTime);
115+
userTimeTL.set(isolateThread, curUserTime);
116+
117+
JfrNativeEventWriterData data = StackValue.get(JfrNativeEventWriterData.class);
118+
JfrNativeEventWriterDataAccess.initializeThreadLocalNativeBuffer(data);
119+
120+
JfrNativeEventWriter.beginSmallEvent(data, JfrEvent.ThreadCPULoad);
121+
JfrNativeEventWriter.putLong(data, JfrTicks.elapsedTicks());
122+
JfrNativeEventWriter.putEventThread(data);
123+
JfrNativeEventWriter.putFloat(data, userTime / totalAvailableTime);
124+
JfrNativeEventWriter.putFloat(data, systemTime / totalAvailableTime);
125+
JfrNativeEventWriter.endSmallEvent(data);
126+
}
127+
128+
public static void emitEvents() {
129+
/* This is safe because the VM operation rechecks if the event should be emitted. */
130+
if (shouldEmitUnsafe()) {
131+
EmitThreadCPULoadEventsOperation vmOp = new EmitThreadCPULoadEventsOperation();
132+
vmOp.enqueue();
133+
}
134+
}
135+
136+
@Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true)
137+
private static int getProcessorCount() {
138+
/*
139+
* This should but does not take the container support into account. Unfortunately, it is
140+
* currently not possible to call Containers.activeProcessorCount() from uninterruptible
141+
* code.
142+
*/
143+
int curProcessorCount = Jvm.JVM_ActiveProcessorCount();
144+
int prevProcessorCount = lastActiveProcessorCount;
145+
lastActiveProcessorCount = curProcessorCount;
146+
147+
/*
148+
* If the number of processors decreases, we don't know at what point during the sample
149+
* interval this happened, so use the largest number to try to avoid percentages above 100%.
150+
*/
151+
return UninterruptibleUtils.Math.max(curProcessorCount, prevProcessorCount);
152+
}
153+
154+
@Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true)
155+
private static long getThreadCpuTime(IsolateThread isolateThread, boolean includeSystemTime) {
156+
long threadCpuTime = ThreadCpuTimeSupport.getInstance().getThreadCpuTime(
157+
VMThreads.findOSThreadHandleForIsolateThread(isolateThread), includeSystemTime);
158+
return (threadCpuTime < 0) ? 0 : threadCpuTime;
159+
}
160+
161+
@Uninterruptible(reason = "Called from uninterruptible code.", mayBeInlined = true)
162+
private static long getCurrentTime() {
163+
return System.nanoTime();
164+
}
165+
166+
@Uninterruptible(reason = "Used to avoid the VM operation if it is not absolutely needed.")
167+
private static boolean shouldEmitUnsafe() {
168+
/* The returned value is racy. */
169+
return JfrEvent.ThreadCPULoad.shouldEmit();
170+
}
171+
172+
private static final class EmitThreadCPULoadEventsOperation extends JavaVMOperation {
173+
EmitThreadCPULoadEventsOperation() {
174+
super(VMOperationInfos.get(EmitThreadCPULoadEventsOperation.class, "Emit ThreadCPULoad events", SystemEffect.SAFEPOINT));
175+
}
176+
177+
@Override
178+
protected void operate() {
179+
for (IsolateThread isolateThread = VMThreads.firstThread(); isolateThread.isNonNull(); isolateThread = VMThreads.nextThread(isolateThread)) {
180+
emit(isolateThread);
181+
}
182+
}
183+
}
184+
}

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

Lines changed: 103 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,103 @@
1+
/*
2+
* Copyright (c) 2023, 2023, Oracle and/or its affiliates. All rights reserved.
3+
* Copyright (c) 2023, 2023, BELLSOFT. All rights reserved.
4+
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
5+
*
6+
* This code is free software; you can redistribute it and/or modify it
7+
* under the terms of the GNU General Public License version 2 only, as
8+
* published by the Free Software Foundation. Oracle designates this
9+
* particular file as subject to the "Classpath" exception as provided
10+
* by Oracle in the LICENSE file that accompanied this code.
11+
*
12+
* This code is distributed in the hope that it will be useful, but WITHOUT
13+
* ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
14+
* FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
15+
* version 2 for more details (a copy is included in the LICENSE file that
16+
* accompanied this code).
17+
*
18+
* You should have received a copy of the GNU General Public License version
19+
* 2 along with this work; if not, write to the Free Software Foundation,
20+
* Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
21+
*
22+
* Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
23+
* or visit www.oracle.com if you need additional information or have any
24+
* questions.
25+
*/
26+
27+
package com.oracle.svm.test.jfr;
28+
29+
import static org.junit.Assert.assertEquals;
30+
import static org.junit.Assert.assertTrue;
31+
32+
import java.util.HashMap;
33+
import java.util.List;
34+
import java.util.Map;
35+
36+
import org.junit.Test;
37+
38+
import jdk.jfr.Recording;
39+
import jdk.jfr.consumer.RecordedEvent;
40+
41+
public class TestThreadCPULoadEvent extends JfrRecordingTest {
42+
private static final int DURATION_MS = 1000;
43+
private static final String THREAD_NAME_1 = "Thread-1";
44+
private static final String THREAD_NAME_2 = "Thread-2";
45+
46+
@Test
47+
public void test() throws Throwable {
48+
String[] events = new String[]{"jdk.ThreadCPULoad"};
49+
Recording recording = startRecording(events);
50+
51+
Thread thread1 = createAndStartBusyWaitThread(THREAD_NAME_1, 0.1);
52+
Thread thread2 = createAndStartBusyWaitThread(THREAD_NAME_2, 1.0);
53+
54+
thread1.join();
55+
thread2.join();
56+
57+
stopRecording(recording, TestThreadCPULoadEvent::validateEvents);
58+
}
59+
60+
private static void validateEvents(List<RecordedEvent> events) {
61+
assertEquals(2, events.size());
62+
Map<String, Float> systemTimes = new HashMap<>();
63+
64+
for (RecordedEvent e : events) {
65+
float userTime = e.<Float> getValue("user");
66+
float systemTime = e.<Float> getValue("system");
67+
assertTrue("User time is outside 0..1 range", 0.0 <= userTime && userTime <= 1.0);
68+
assertTrue("System time is outside 0..1 range", 0.0 <= systemTime && systemTime <= 1.0);
69+
systemTimes.put(e.getThread().getJavaName(), systemTime);
70+
}
71+
72+
assertTrue("Thread-1 system cpu time is greater than Thread-2 system cpu time",
73+
systemTimes.get(THREAD_NAME_1) < systemTimes.get(THREAD_NAME_2));
74+
}
75+
76+
private static Thread createAndStartBusyWaitThread(String name, double busyPercent) {
77+
Thread thread = new Thread(() -> {
78+
assert busyPercent >= 0 && busyPercent <= 1;
79+
long busyMs = (long) (DURATION_MS * busyPercent);
80+
long idleMs = DURATION_MS - busyMs;
81+
82+
busyWait(busyMs);
83+
sleep(idleMs);
84+
});
85+
thread.setName(name);
86+
thread.start();
87+
return thread;
88+
}
89+
90+
private static void busyWait(long delay) {
91+
long end = System.currentTimeMillis() + delay;
92+
while (end > System.currentTimeMillis()) {
93+
/* Nothing to do. */
94+
}
95+
}
96+
97+
private static void sleep(long delay) {
98+
try {
99+
Thread.sleep(delay);
100+
} catch (InterruptedException ignored) {
101+
}
102+
}
103+
}

0 commit comments

Comments
 (0)