Skip to content

Commit 01eff35

Browse files
committed
[GR-69259] Add an option to dump compile statistics to CSV
PullRequest: graal/22305
2 parents e7e5773 + 934f694 commit 01eff35

File tree

7 files changed

+236
-288
lines changed

7 files changed

+236
-288
lines changed
Lines changed: 80 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,80 @@
1+
/*
2+
* Copyright (c) 2025, Oracle and/or its affiliates. All rights reserved.
3+
* DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
4+
*
5+
* This code is free software; you can redistribute it and/or modify it
6+
* under the terms of the GNU General Public License version 2 only, as
7+
* published by the Free Software Foundation. Oracle designates this
8+
* particular file as subject to the "Classpath" exception as provided
9+
* by Oracle in the LICENSE file that accompanied this code.
10+
*
11+
* This code is distributed in the hope that it will be useful, but WITHOUT
12+
* ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
13+
* FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
14+
* version 2 for more details (a copy is included in the LICENSE file that
15+
* accompanied this code).
16+
*
17+
* You should have received a copy of the GNU General Public License version
18+
* 2 along with this work; if not, write to the Free Software Foundation,
19+
* Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA.
20+
*
21+
* Please contact Oracle, 500 Oracle Parkway, Redwood Shores, CA 94065 USA
22+
* or visit www.oracle.com if you need additional information or have any
23+
* questions.
24+
*/
25+
package jdk.graal.compiler.core.test;
26+
27+
import java.io.BufferedReader;
28+
import java.io.ByteArrayOutputStream;
29+
import java.io.FileReader;
30+
import java.io.IOException;
31+
import java.nio.file.Path;
32+
33+
import org.junit.Assume;
34+
import org.junit.Test;
35+
36+
import jdk.graal.compiler.core.CompilationPrinter;
37+
import jdk.graal.compiler.core.GraalCompilerOptions;
38+
import jdk.graal.compiler.core.common.CompilationIdentifier;
39+
import jdk.graal.compiler.debug.LogStream;
40+
import jdk.graal.compiler.debug.TTY;
41+
import jdk.graal.compiler.options.OptionValues;
42+
import jdk.vm.ci.meta.ResolvedJavaMethod;
43+
44+
/**
45+
* Tests {@link CompilationPrinter}.
46+
*/
47+
public class CompilationPrinterTest extends GraalCompilerTest {
48+
@Test
49+
public void testPrintToCSV() throws IOException {
50+
Assume.assumeFalse(CompilationPrinter.printingToCSV());
51+
try (TemporaryDirectory temp = new TemporaryDirectory("CompilationPrinterTest")) {
52+
Path path = temp.path.resolve("stats.csv");
53+
OptionValues options = new OptionValues(getInitialOptions(), GraalCompilerOptions.PrintCompilationCSV, path.toString());
54+
ResolvedJavaMethod method = getResolvedJavaMethod("dummy");
55+
CompilationPrinter.begin(options, CompilationIdentifier.INVALID_COMPILATION_ID, method, 42).finish(null, null);
56+
try (BufferedReader inputReader = new BufferedReader(new FileReader(path.toFile()))) {
57+
String header = inputReader.readLine();
58+
assertFalse(header.isBlank());
59+
String compilation = inputReader.readLine();
60+
assertTrue(compilation.contains(method.getName()));
61+
}
62+
} finally {
63+
CompilationPrinter.close();
64+
}
65+
}
66+
67+
@SuppressWarnings("try")
68+
@Test
69+
public void testPrintToTTY() throws IOException {
70+
try (ByteArrayOutputStream captureStream = new ByteArrayOutputStream(); TTY.Filter filter = new TTY.Filter(new LogStream(captureStream))) {
71+
OptionValues options = new OptionValues(getInitialOptions(), GraalCompilerOptions.PrintCompilation, true);
72+
ResolvedJavaMethod method = getResolvedJavaMethod("dummy");
73+
CompilationPrinter.begin(options, CompilationIdentifier.INVALID_COMPILATION_ID, method, 42).finish(null, null);
74+
assertTrue(captureStream.toString().contains(method.getName()));
75+
}
76+
}
77+
78+
public static void dummy() {
79+
}
80+
}

compiler/src/jdk.graal.compiler/src/jdk/graal/compiler/core/CompilationPrinter.java

Lines changed: 140 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -25,35 +25,78 @@
2525
package jdk.graal.compiler.core;
2626

2727
import static jdk.graal.compiler.serviceprovider.GraalServices.getCurrentThreadAllocatedBytes;
28+
import static jdk.graal.compiler.serviceprovider.GraalServices.getCurrentThreadCpuTime;
29+
import static jdk.graal.compiler.serviceprovider.GraalServices.isCurrentThreadCpuTimeSupported;
2830
import static jdk.graal.compiler.serviceprovider.GraalServices.isThreadAllocatedMemorySupported;
2931

32+
import java.io.IOException;
33+
import java.io.PrintStream;
34+
import java.nio.file.Files;
35+
3036
import jdk.graal.compiler.code.CompilationResult;
3137
import jdk.graal.compiler.core.common.CompilationIdentifier;
3238
import jdk.graal.compiler.core.common.spi.ForeignCallSignature;
39+
import jdk.graal.compiler.debug.CSVUtil;
40+
import jdk.graal.compiler.debug.GlobalMetrics;
3341
import jdk.graal.compiler.debug.GraalError;
3442
import jdk.graal.compiler.debug.TTY;
3543
import jdk.graal.compiler.options.OptionValues;
36-
3744
import jdk.vm.ci.code.InstalledCode;
3845
import jdk.vm.ci.meta.JavaMethod;
3946
import jdk.vm.ci.runtime.JVMCICompiler;
4047

4148
/**
42-
* Utility for printing an informational line to {@link TTY} upon completion of compiling a method.
49+
* Utility for printing an informational line to {@link TTY} or a CSV file upon completion of
50+
* compiling a method.
4351
*/
4452
public final class CompilationPrinter {
4553

54+
/**
55+
* The shared CSV stream or {@code null} if there is no open stream.
56+
*/
57+
private static volatile PrintStream csvStream;
58+
59+
/**
60+
* The ID of the compilation.
61+
*/
4662
private final CompilationIdentifier id;
63+
64+
/**
65+
* The compiled method or foreign call signature.
66+
*/
4767
private final Object source;
68+
69+
/**
70+
* The entry BCI of the compiled method.
71+
*/
4872
private final int entryBCI;
49-
private final long start;
50-
private final long allocatedBytesBefore;
73+
74+
/**
75+
* The wall-time timestamp at the beginning of the compilation.
76+
*/
77+
private final long beginWallTime;
78+
79+
/**
80+
* The thread-time timestamp at the beginning of the compilation.
81+
*/
82+
private final long beginThreadTime;
83+
84+
/**
85+
* The allocated bytes at the beginning of the compilation.
86+
*/
87+
private final long beginAllocatedBytes;
88+
89+
/**
90+
* Whether information about this compilation should be printed to {@link TTY}.
91+
*/
92+
private final boolean printTTY;
5193

5294
/**
5395
* Gets an object that will report statistics for a compilation if
54-
* {@link GraalCompilerOptions#PrintCompilation} is enabled and {@link TTY} is not suppressed.
55-
* This method should be called just before a compilation starts as it captures pre-compilation
56-
* data for the purpose of {@linkplain #finish printing} the post-compilation statistics.
96+
* {@link GraalCompilerOptions#PrintCompilation} is enabled (and {@link TTY} is not suppressed)
97+
* or a CSV file is specified with {@link GraalCompilerOptions#PrintCompilationCSV}. This method
98+
* should be called just before a compilation starts as it captures pre-compilation data for the
99+
* purpose of {@linkplain #finish printing} the post-compilation statistics.
57100
*
58101
* @param options used to get the value of {@link GraalCompilerOptions#PrintCompilation}
59102
* @param id the identifier for the compilation
@@ -63,29 +106,55 @@ public final class CompilationPrinter {
63106
*/
64107
public static CompilationPrinter begin(OptionValues options, CompilationIdentifier id, Object source, int entryBCI) {
65108
GraalError.guarantee(source instanceof JavaMethod || source instanceof ForeignCallSignature, "%s", source.getClass());
66-
if (GraalCompilerOptions.PrintCompilation.getValue(options) && !TTY.isSuppressed()) {
67-
return new CompilationPrinter(id, source, entryBCI);
109+
boolean printTTY = GraalCompilerOptions.PrintCompilation.getValue(options) && !TTY.isSuppressed();
110+
String csvFilename = GraalCompilerOptions.PrintCompilationCSV.getValue(options);
111+
if (printTTY || csvFilename != null) {
112+
if (csvFilename != null && csvStream == null) {
113+
initializeStream(csvFilename);
114+
}
115+
return new CompilationPrinter(id, source, entryBCI, printTTY);
68116
}
69117
return DISABLED;
70118
}
71119

120+
/**
121+
* Opens a shared CSV stream and prints the CSV header if it is not already open.
122+
*
123+
* @param csvFilename the filename template for the CSV file
124+
*/
125+
private static synchronized void initializeStream(String csvFilename) {
126+
if (csvStream == null) {
127+
try {
128+
csvStream = new PrintStream(Files.newOutputStream(GlobalMetrics.generateFileName(csvFilename)), true);
129+
csvStream.println(
130+
String.join(CSVUtil.SEPARATOR_STR, "compile_id", "method", "entry_bci", "wall_time_ns", "thread_time_ns", "allocated_memory", "compiled_bytecodes", "target_code_size",
131+
"start_address"));
132+
} catch (IOException e) {
133+
throw new GraalError(e);
134+
}
135+
}
136+
}
137+
72138
private static final CompilationPrinter DISABLED = new CompilationPrinter();
73139

74140
private CompilationPrinter() {
75141
this.source = null;
76142
this.id = null;
77143
this.entryBCI = -1;
78-
this.start = -1;
79-
this.allocatedBytesBefore = -1;
144+
this.beginWallTime = -1;
145+
this.beginThreadTime = -1;
146+
this.beginAllocatedBytes = -1;
147+
this.printTTY = false;
80148
}
81149

82-
private CompilationPrinter(CompilationIdentifier id, Object source, int entryBCI) {
150+
private CompilationPrinter(CompilationIdentifier id, Object source, int entryBCI, boolean printTTY) {
83151
this.source = source;
84152
this.id = id;
85153
this.entryBCI = entryBCI;
86-
87-
start = System.nanoTime();
88-
allocatedBytesBefore = isThreadAllocatedMemorySupported() ? getCurrentThreadAllocatedBytes() : -1;
154+
this.printTTY = printTTY;
155+
this.beginWallTime = System.nanoTime();
156+
this.beginThreadTime = isCurrentThreadCpuTimeSupported() ? getCurrentThreadCpuTime() : -1;
157+
this.beginAllocatedBytes = isThreadAllocatedMemorySupported() ? getCurrentThreadAllocatedBytes() : -1;
89158
}
90159

91160
private String getMethodDescription() {
@@ -106,27 +175,74 @@ private String getMethodDescription() {
106175

107176
/**
108177
* Notifies this object that the compilation finished and the informational line should be
109-
* printed to {@link TTY}.
110-
*
111-
* @param installedCode
178+
* printed to {@link TTY} or a CSV file.
112179
*/
113180
public void finish(CompilationResult result, InstalledCode installedCode) {
114181
if (id != null) {
115-
final long stop = System.nanoTime();
116-
final long duration = (stop - start) / 1000;
182+
final long endWallTime = System.nanoTime();
183+
final long endThreadTime = (beginThreadTime != -1) ? getCurrentThreadCpuTime() : -1;
184+
final long endAllocatedBytes = (beginAllocatedBytes != -1) ? getCurrentThreadAllocatedBytes() : -1;
185+
final long wallTime = endWallTime - beginWallTime;
186+
final long threadTime = endThreadTime - beginThreadTime;
187+
final long allocatedBytes = endAllocatedBytes - beginAllocatedBytes;
117188
final int targetCodeSize = result != null ? result.getTargetCodeSize() : -1;
118189
final int bytecodeSize = result != null ? result.getBytecodeSize() : 0;
190+
maybePrintCSV(wallTime, threadTime, allocatedBytes, bytecodeSize, targetCodeSize, installedCode);
191+
if (!printTTY) {
192+
return;
193+
}
119194
String allocated = "";
120195
String installed = "";
121-
if (allocatedBytesBefore != -1) {
122-
final long allocatedBytesAfter = getCurrentThreadAllocatedBytes();
123-
final long allocatedKBytes = (allocatedBytesAfter - allocatedBytesBefore) / 1024;
196+
if (beginAllocatedBytes != -1) {
197+
final long allocatedKBytes = allocatedBytes / 1024;
124198
allocated = String.format(" %5dkB allocated", allocatedKBytes);
125199
}
126200
if (installedCode != null) {
127201
installed = String.format(" start=0x%016x", installedCode.getStart());
128202
}
129-
TTY.println(getMethodDescription() + String.format(" | %4dus %5dB bytecodes %5dB codesize%s%s", duration, bytecodeSize, targetCodeSize, allocated, installed));
203+
TTY.println(getMethodDescription() + String.format(" | %4dus %5dB bytecodes %5dB codesize%s%s", wallTime / 1000, bytecodeSize, targetCodeSize, allocated, installed));
130204
}
131205
}
206+
207+
/**
208+
* Prints an information line to the shared CSV stream if it is open.
209+
*/
210+
private void maybePrintCSV(long wallTime, long threadTime, long allocatedBytes, int bytecodeSize, int targetCodeSize, InstalledCode installedCode) {
211+
if (csvStream == null) {
212+
return;
213+
}
214+
String methodName;
215+
if (source instanceof JavaMethod method) {
216+
methodName = method.format("%H.%n(%p)");
217+
} else {
218+
ForeignCallSignature sig = (ForeignCallSignature) source;
219+
methodName = sig.toString();
220+
}
221+
long start = (installedCode == null) ? 0 : installedCode.getStart();
222+
String message = String.format(CSVUtil.buildFormatString("%s", "%s", "%d", "%d", "%d", "%d", "%d", "%d", "0x%016x"),
223+
CSVUtil.Escape.escapeArgs(id.toString(CompilationIdentifier.Verbosity.ID), methodName, entryBCI, wallTime, threadTime, allocatedBytes, bytecodeSize, targetCodeSize, start));
224+
synchronized (CompilationPrinter.class) {
225+
PrintStream stream = csvStream;
226+
if (stream != null) {
227+
stream.println(message);
228+
}
229+
}
230+
}
231+
232+
/**
233+
* Closes the shared CSV stream if it is open.
234+
*/
235+
public static synchronized void close() {
236+
if (csvStream != null) {
237+
csvStream.close();
238+
csvStream = null;
239+
}
240+
}
241+
242+
/**
243+
* Returns true if there is an open CSV stream.
244+
*/
245+
public static synchronized boolean printingToCSV() {
246+
return csvStream != null;
247+
}
132248
}

compiler/src/jdk.graal.compiler/src/jdk/graal/compiler/core/GraalCompilerOptions.java

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -40,6 +40,10 @@ public class GraalCompilerOptions {
4040
// @formatter:off
4141
@Option(help = "Print an informational line to the console for each completed compilation.", type = OptionType.Debug, stability = OptionStability.STABLE)
4242
public static final OptionKey<Boolean> PrintCompilation = new OptionKey<>(false);
43+
@Option(help = """
44+
Print statistics for each completed compilation to a CSV file specified by the given filename pattern.
45+
The isolate ID is appended to the filename and %p is replaced with the execution ID.""", type = OptionType.Debug)
46+
public static final OptionKey<String> PrintCompilationCSV = new OptionKey<>(null);
4347
@Option(help = """
4448
Pattern for method(s) that will trigger an exception when compiled.
4549
This option exists to test handling compilation crashes gracefully.

compiler/src/jdk.graal.compiler/src/jdk/graal/compiler/debug/GlobalMetrics.java

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -89,7 +89,14 @@ private static PrintStream openPrintStream(String metricsFile, Path[] outPath) t
8989
}
9090
}
9191

92-
static Path generateFileName(String nameTemplate) {
92+
/**
93+
* Substitutes {@code %p} in the given filename template with the execution ID and appends the
94+
* isolate ID if this is an isolate-aware runtime.
95+
*
96+
* @param nameTemplate the filename template, which may contain {@code %p}
97+
* @return the substituted filename template
98+
*/
99+
public static Path generateFileName(String nameTemplate) {
93100
String metricsFile = nameTemplate;
94101
if (metricsFile.contains("%p")) {
95102
metricsFile = metricsFile.replace("%p", GraalServices.getExecutionID());

0 commit comments

Comments
 (0)