diff --git a/docs/reference-manual/native-image/BuildOutput.md b/docs/reference-manual/native-image/BuildOutput.md index 0c51c220f263..767db96d870f 100644 --- a/docs/reference-manual/native-image/BuildOutput.md +++ b/docs/reference-manual/native-image/BuildOutput.md @@ -9,49 +9,52 @@ permalink: /reference-manual/native-image/BuildOutput/ This page provides documentation for the build output of GraalVM Native Image. ## HelloWorld Example Output -``` +```text ================================================================================ GraalVM Native Image: Generating 'helloworld'... ================================================================================ -[1/7] Initializing... (2.1s @ 0.19GB) +[1/7] Initializing... (2.5s @ 0.21GB) Version info: 'GraalVM dev Java 11 CE' -[2/7] Performing analysis... [*******] (5.7s @ 0.47GB) +[2/7] Performing analysis... [*******] (5.6s @ 0.46GB) 2,565 (82.61%) of 3,105 classes reachable 3,216 (60.42%) of 5,323 fields reachable - 11,653 (72.44%) of 16,087 methods reachable + 11,652 (72.44%) of 16,086 methods reachable 27 classes, 0 fields, and 135 methods registered for reflection 57 classes, 59 fields, and 51 methods registered for JNI access -[3/7] Building universe... (0.4s @ 0.63GB) -[4/7] Parsing methods... [*] (0.4s @ 0.83GB) -[5/7] Inlining methods... [****] (0.4s @ 0.67GB) -[6/7] Compiling methods... [**] (3.4s @ 1.38GB) -[7/7] Creating image... (0.8s @ 1.65GB) - 10.52MB in total (35.1% code area, 55.7% image heap, and 9.3% other data) - 3.69MB for code area: 6,955 compilation units - 5.86MB for image heap: 1,545 classes and 81,111 objects - 997.09KB for other data +[3/7] Building universe... (0.5s @ 0.61GB) +[4/7] Parsing methods... [*] (0.5s @ 0.86GB) +[5/7] Inlining methods... [****] (0.5s @ 0.73GB) +[6/7] Compiling methods... [**] (3.7s @ 2.38GB) +[7/7] Creating image... (2.1s @ 1.04GB) + 3.69MB (27.19%) for code area: 6,955 compilation units + 5.86MB (43.18%) for image heap: 1,545 classes and 80,528 objects + 3.05MB (22.46%) for debug info generated in 1.0s + 997.25KB ( 7.18%) for other data + 13.57MB in total -------------------------------------------------------------------------------- Top 10 packages in code area: Top 10 object types in image heap: - 606.11KB java.util 1.64MB byte[] for general heap data - 282.34KB java.lang 718.09KB java.lang.String + 606.23KB java.util 1.64MB byte[] for general heap data + 282.34KB java.lang 715.56KB java.lang.String 222.47KB java.util.regex 549.46KB java.lang.Class - 219.55KB java.text 454.06KB byte[] for java.lang.String + 219.55KB java.text 451.79KB byte[] for java.lang.String 193.17KB com.oracle.svm.jni 363.23KB java.util.HashMap$Node - 149.80KB java.util.concurrent 192.11KB java.util.HashMap$Node[] - 118.09KB java.math 139.04KB char[] - 103.60KB com.oracle.svm.core.reflect 136.48KB java.lang.String[] + 149.80KB java.util.concurrent 192.00KB java.util.HashMap$Node[] + 118.07KB java.math 139.83KB java.lang.String[] + 103.60KB com.oracle.svm.core.reflect 139.04KB char[] 97.83KB sun.text.normalizer 130.59KB j.u.c.ConcurrentHashMap$Node 88.78KB c.oracle.svm.core.genscavenge 103.92KB s.u.l.LocaleObjec~e$CacheEntry ... 111 additional packages ... 723 additional object types (use GraalVM Dashboard to see all) -------------------------------------------------------------------------------- - 0.8s (5.4% of total time) in 17 GCs | Peak RSS: 2.60GB | CPU load: ~1183.69% + 0.9s (5.6% of total time) in 17 GCs | Peak RSS: 3.22GB | CPU load: 10.87 -------------------------------------------------------------------------------- Produced artifacts: /home/janedoe/helloworld/helloworld (executable) + /home/janedoe/helloworld/sources (debug_info) + /home/janedoe/helloworld/helloworld (debug_info) /home/janedoe/helloworld/helloworld.build_artifacts.txt ================================================================================ -Finished generating 'helloworld' in 14.0s. +Finished generating 'helloworld' in 16.2s. ``` ## Build Stages @@ -136,7 +139,7 @@ This data typically contains internal information for Native Image but it can al ### Resource Usage Statistics #### Garbage Collections -The total time spent in all garbage collectors, total GC time divided by the total time to build the image in percent, and the total number of garbage collections. +The total time spent in all garbage collectors, total GC time divided by the total process time in percent, and the total number of garbage collections. A large number of collections or time spent in collectors usually indicates that the system is under memory pressure. Increase the amount of available memory to reduce the time to build the image. @@ -146,7 +149,7 @@ This value indicates the maximum amount of memory consumed by the build process. If the [GC statistics](#glossary-garbage-collection) do not show any problems, the amount of available memory of the system can be reduced to a value closer to the peak RSS. #### CPU load -The CPU time used by the process divided by the total time to build the image in percent. +The CPU time used by the process divided by the total process time. Increase the number of CPU threads to reduce the time to build the image. ## Build Output Options diff --git a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/SystemInOutErrSupport.java b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/SystemInOutErrSupport.java index 8dd5aa807b45..a6905d33d28c 100644 --- a/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/SystemInOutErrSupport.java +++ b/substratevm/src/com.oracle.svm.core/src/com/oracle/svm/core/jdk/SystemInOutErrSupport.java @@ -37,9 +37,6 @@ import org.graalvm.nativeimage.ImageSingletons; import org.graalvm.nativeimage.hosted.Feature; -import com.oracle.svm.core.annotate.AutomaticFeature; -import com.oracle.svm.core.annotate.RecomputeFieldValue; - /** * This class provides replacement values for the {@link System#in}, {@link System#out}, and * {@link System#err} streams at run time. We want a fresh set of objects, so that any buffers @@ -66,45 +63,27 @@ private static PrintStream newPrintStream(FileOutputStream fos, String enc) { return new PrintStream(new BufferedOutputStream(fos, 128), true); } + public static InputStream in() { + return ImageSingletons.lookup(SystemInOutErrSupport.class).in; + } + public static void setIn(InputStream in) { ImageSingletons.lookup(SystemInOutErrSupport.class).in = Objects.requireNonNull(in); } - public static void setOut(PrintStream out) { - ImageSingletons.lookup(SystemInOutErrSupport.class).out = Objects.requireNonNull(out); + public static PrintStream out() { + return ImageSingletons.lookup(SystemInOutErrSupport.class).out; } - public static void setErr(PrintStream err) { - ImageSingletons.lookup(SystemInOutErrSupport.class).err = Objects.requireNonNull(err); + public static void setOut(PrintStream out) { + ImageSingletons.lookup(SystemInOutErrSupport.class).out = Objects.requireNonNull(out); } - // Checkstyle: stop - Object replaceStreams(Object object) { - if (object == System.in) { - return in; - } else if (object == System.out) { - return out; - } else if (object == System.err) { - return err; - } else { - return object; - } + public static PrintStream err() { + return ImageSingletons.lookup(SystemInOutErrSupport.class).err; } - // Checkstyle: resume -} -/** - * We use an {@link Feature.DuringSetupAccess#registerObjectReplacer object replacer} because the - * streams can be cached in other instance and static fields in addition to the fields in - * {@link System}. We do not know all these places, so we do now know where to place - * {@link RecomputeFieldValue} annotations. - */ -@AutomaticFeature -class SystemInOutErrFeature implements Feature { - @Override - public void duringSetup(DuringSetupAccess access) { - SystemInOutErrSupport support = new SystemInOutErrSupport(); - ImageSingletons.add(SystemInOutErrSupport.class, support); - access.registerObjectReplacer(support::replaceStreams); + public static void setErr(PrintStream err) { + ImageSingletons.lookup(SystemInOutErrSupport.class).err = Objects.requireNonNull(err); } } diff --git a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/NativeImageGenerator.java b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/NativeImageGenerator.java index 2fa307cb3bbd..67ff9a78a2d1 100644 --- a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/NativeImageGenerator.java +++ b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/NativeImageGenerator.java @@ -680,7 +680,7 @@ private void doRun(Map entryPoints, featureHandler.forEachFeature(feature -> feature.afterImageWrite(afterConfig)); } reporter.printCreationEnd(imageTimer, writeTimer, image.getImageSize(), bb.getUniverse(), heap.getObjectCount(), image.getImageHeapSize(), codeCache.getCodeCacheSize(), - codeCache.getCompilations().size()); + codeCache.getCompilations().size(), image.getDebugInfoSize()); if (SubstrateOptions.BuildOutputBreakdowns.getValue()) { ProgressReporter.singleton().printBreakdowns(compileQueue.getCompilationTasks(), image.getHeap().getObjects()); } diff --git a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/NativeImageSystemClassLoader.java b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/NativeImageSystemClassLoader.java index ea341219dcbc..43f249a31e22 100644 --- a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/NativeImageSystemClassLoader.java +++ b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/NativeImageSystemClassLoader.java @@ -52,6 +52,9 @@ public final class NativeImageSystemClassLoader extends SecureClassLoader { public final ClassLoader defaultSystemClassLoader; + + NativeImageSystemIOWrappers systemIOWrappers; + private volatile ClassLoader nativeImageClassLoader = null; private Set disallowedClassLoaders = Collections.newSetFromMap(new WeakHashMap<>()); @@ -59,6 +62,13 @@ public final class NativeImageSystemClassLoader extends SecureClassLoader { public NativeImageSystemClassLoader(ClassLoader defaultSystemClassLoader) { super(defaultSystemClassLoader); this.defaultSystemClassLoader = defaultSystemClassLoader; + resetSystemIOWrappers(); + } + + private void resetSystemIOWrappers() { + systemIOWrappers = new NativeImageSystemIOWrappers(); + /* Image building console output requires custom System.out and System.err */ + systemIOWrappers.replaceSystemOutErr(); } public static NativeImageSystemClassLoader singleton() { @@ -243,4 +253,5 @@ private void appendToClassPathForInstrumentation(String classPathEntry) { VMError.shouldNotReachHere(message, e); } } + } diff --git a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/NativeImageSystemIOWrappers.java b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/NativeImageSystemIOWrappers.java new file mode 100644 index 000000000000..eac8df2cf518 --- /dev/null +++ b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/NativeImageSystemIOWrappers.java @@ -0,0 +1,111 @@ +/* + * Copyright (c) 2021, 2021, Oracle and/or its affiliates. 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.hosted; + +import java.io.ByteArrayOutputStream; +import java.io.PrintStream; + +import com.oracle.svm.core.util.VMError; + +public class NativeImageSystemIOWrappers { + + private final CapturingStdioWrapper outWrapper; + private final CapturingStdioWrapper errWrapper; + + public boolean useCapturing; + + NativeImageSystemIOWrappers() { + outWrapper = new CapturingStdioWrapper(System.out, new ByteArrayOutputStream(128)); + errWrapper = new CapturingStdioWrapper(System.err, new ByteArrayOutputStream(128)); + useCapturing = false; + } + + public static NativeImageSystemIOWrappers singleton() { + return NativeImageSystemClassLoader.singleton().systemIOWrappers; + } + + public void verifySystemOutErrReplacement() { + String msg = " was changed during image building. This is not allowed."; + VMError.guarantee(System.out == outWrapper, "System.out" + msg); + VMError.guarantee(System.err == errWrapper, "System.err" + msg); + } + + public PrintStream originalOut() { + return outWrapper.delegate; + } + + public PrintStream originalErr() { + return errWrapper.delegate; + } + + public void flushCapturedContent() { + outWrapper.flushCapturedContent(); + errWrapper.flushCapturedContent(); + } + + void replaceSystemOutErr() { + System.setOut(outWrapper); + System.setErr(errWrapper); + } + + /** + * Wrapper with the ability to temporarily capture output to stdout and stderr. + */ + private final class CapturingStdioWrapper extends PrintStream { + private final ByteArrayOutputStream buffer; + private final PrintStream delegate; + + private CapturingStdioWrapper(PrintStream delegate, ByteArrayOutputStream buffer) { + super(buffer); + this.buffer = buffer; + this.delegate = delegate; + } + + @Override + public void write(int b) { + if (useCapturing) { + super.write(b); + } else { + delegate.write(b); + } + } + + @Override + public void write(byte[] buf, int off, int len) { + if (useCapturing) { + super.write(buf, off, len); + } else { + delegate.write(buf, off, len); + } + } + + private void flushCapturedContent() { + byte[] byteArray = buffer.toByteArray(); + delegate.write(byteArray, 0, byteArray.length); + buffer.reset(); + } + } +} diff --git a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/image/AbstractImage.java b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/image/AbstractImage.java index 3745dddc4217..708dbf89dce2 100644 --- a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/image/AbstractImage.java +++ b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/image/AbstractImage.java @@ -47,6 +47,7 @@ public abstract class AbstractImage { protected final NativeImageCodeCache codeCache; protected final List entryPoints; protected int resultingImageSize; // for statistical output + protected int debugInfoSize; // for statistical output public enum NativeImageKind { SHARED_LIBRARY(false) { @@ -115,6 +116,10 @@ public int getImageSize() { return resultingImageSize; } + public int getDebugInfoSize() { + return debugInfoSize; + } + public NativeLibraries getNativeLibs() { return nativeLibs; } diff --git a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/image/NativeImage.java b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/image/NativeImage.java index 7f2057e9cebe..c9c054c7f6ab 100644 --- a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/image/NativeImage.java +++ b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/image/NativeImage.java @@ -179,6 +179,12 @@ protected final void write(DebugContext context, Path outputFile) { throw shouldNotReachHere(ex); } resultingImageSize = (int) outputFile.toFile().length(); + debugInfoSize = 0; + for (Element e : objectFile.getElements()) { + if (e.getName().contains(".debug")) { + debugInfoSize += e.getMemSize(objectFile.getDecisionsByElement()); + } + } if (NativeImageOptions.PrintImageElementSizes.getValue()) { for (Element e : objectFile.getElements()) { System.out.printf("PrintImageElementSizes: size: %15d name: %s\n", e.getMemSize(objectFile.getDecisionsByElement()), e.getElementName()); diff --git a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/jdk/SystemInOutErrFeature.java b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/jdk/SystemInOutErrFeature.java new file mode 100644 index 000000000000..d71758f9bea2 --- /dev/null +++ b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/jdk/SystemInOutErrFeature.java @@ -0,0 +1,75 @@ +/* + * Copyright (c) 2021, 2021, Oracle and/or its affiliates. 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.hosted.jdk; + +import java.io.InputStream; +import java.io.PrintStream; + +import org.graalvm.nativeimage.ImageSingletons; +import org.graalvm.nativeimage.hosted.Feature; + +import com.oracle.svm.core.annotate.AutomaticFeature; +import com.oracle.svm.core.annotate.RecomputeFieldValue; +import com.oracle.svm.core.jdk.SystemInOutErrSupport; +import com.oracle.svm.hosted.NativeImageSystemIOWrappers; + +/** + * We use an {@link Feature.DuringSetupAccess#registerObjectReplacer object replacer} because the + * streams can be cached in other instance and static fields in addition to the fields in + * {@link System}. We do not know all these places, so we do now know where to place + * {@link RecomputeFieldValue} annotations. + */ +@AutomaticFeature +public class SystemInOutErrFeature implements Feature { + private final InputStream hostedIn = System.in; + private final PrintStream hostedOut = System.out; + private final PrintStream hostedErr = System.err; + + @Override + public void duringSetup(DuringSetupAccess access) { + NativeImageSystemIOWrappers.singleton().verifySystemOutErrReplacement(); + + ImageSingletons.add(SystemInOutErrSupport.class, new SystemInOutErrSupport()); + access.registerObjectReplacer(this::replaceStreams); + } + + @Override + public void cleanup() { + NativeImageSystemIOWrappers.singleton().verifySystemOutErrReplacement(); + } + + Object replaceStreams(Object object) { + if (object == hostedIn) { + return SystemInOutErrSupport.in(); + } else if (object == hostedOut) { + return SystemInOutErrSupport.out(); + } else if (object == hostedErr) { + return SystemInOutErrSupport.err(); + } else { + return object; + } + } +} diff --git a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/reporting/ProgressReporter.java b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/reporting/ProgressReporter.java index d5fa6c8bd5d0..c286a6f7c866 100644 --- a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/reporting/ProgressReporter.java +++ b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/reporting/ProgressReporter.java @@ -66,6 +66,7 @@ import com.oracle.svm.core.option.HostedOptionValues; import com.oracle.svm.core.reflect.MethodMetadataDecoder; import com.oracle.svm.hosted.NativeImageGenerator; +import com.oracle.svm.hosted.NativeImageSystemIOWrappers; import com.oracle.svm.hosted.StringAccess; import com.oracle.svm.hosted.code.CompileQueue.CompileTask; import com.oracle.svm.hosted.image.NativeImageHeap.ObjectInfo; @@ -91,6 +92,8 @@ public class ProgressReporter { private static final double BYTES_TO_MiB = 1024d * 1024d; private static final double BYTES_TO_GiB = 1024d * 1024d * 1024d; + private final NativeImageSystemIOWrappers builderIO; + private final boolean isEnabled; private final LinePrinter linePrinter; private final boolean usePrefix; @@ -136,6 +139,8 @@ public static ProgressReporter singleton() { } public ProgressReporter(OptionValues options) { + builderIO = NativeImageSystemIOWrappers.singleton(); + isEnabled = SubstrateOptions.BuildOutputUseNewStyle.getValue(options); if (isEnabled) { Timer.disablePrinting(); @@ -239,8 +244,7 @@ public ReporterClosable printAnalysis(BigBang bb) { public void closeAction() { timer.stop(); printProgressEnd(); - int analysisMillis = (int) bb.getAnalysisTimer().getTotalTime(); - printStageEnd(analysisMillis); + printStageEnd(bb.getAnalysisTimer()); String actualVsTotalFormat = "%,8d (%5.2f%%) of %,6d"; long reachableClasses = bb.getUniverse().getTypes().stream().filter(t -> t.isReachable()).count(); long totalClasses = bb.getUniverse().getTypes().size(); @@ -347,21 +351,26 @@ public void setDebugInfoTimer(Timer timer) { } public void printCreationEnd(Timer creationTimer, Timer writeTimer, int imageSize, AnalysisUniverse universe, int numHeapObjects, long imageHeapSize, int codeCacheSize, - int numCompilations) { + int numCompilations, int debugInfoSize) { printStageEnd(creationTimer.getTotalTime() + writeTimer.getTotalTime()); - String total = bytesToHuman("%4.2f", imageSize); - long otherBytes = imageSize - codeCacheSize - imageHeapSize; - l().a("%9s in total (%.1f%% ", total, codeCacheSize / (double) imageSize * 100).doclink("code area", "#glossary-code-area") - .a(", %.1f%% ", imageHeapSize / (double) imageSize * 100).doclink("image heap", "#glossary-image-heap") - .a(", and %.1f%% ", otherBytes / (double) imageSize * 100).doclink("other data", "#glossary-other-data").a(")").flushln(); - l().a("%9s for code area:%,9d compilation units", bytesToHuman("%4.2f", codeCacheSize), numCompilations).flushln(); + String format = "%9s (%5.2f%%) for "; + l().a(format, bytesToHuman(codeCacheSize), codeCacheSize / (double) imageSize * 100) + .doclink("code area", "#glossary-code-area").a(":%,9d compilation units", numCompilations).flushln(); long numInstantiatedClasses = universe.getTypes().stream().filter(t -> t.isInstantiated()).count(); - l().a("%9s for image heap:%,8d classes and %,d objects", bytesToHuman("%4.2f", imageHeapSize), numInstantiatedClasses, numHeapObjects).flushln(); - l().a("%9s for other data", bytesToHuman("%4.2f", otherBytes)).a(debugInfoTimer != null ? " including debug info" : "").flushln(); - if (debugInfoTimer != null) { - String debugInfoTime = String.format("%.1fs", millisToSeconds(debugInfoTimer.getTotalTime())); - l().dim().a("%9s for generating debug info", debugInfoTime).reset().flushln(); + l().a(format, bytesToHuman(imageHeapSize), imageHeapSize / (double) imageSize * 100) + .doclink("image heap", "#glossary-image-heap").a(":%,8d classes and %,d objects", numInstantiatedClasses, numHeapObjects).flushln(); + if (debugInfoSize > 0) { + LinePrinter l = l().a(format, bytesToHuman(debugInfoSize), debugInfoSize / (double) imageSize * 100) + .doclink("debug info", "#glossary-debug-info"); + if (debugInfoTimer != null) { + l.a(" generated in %.1fs", millisToSeconds(debugInfoTimer.getTotalTime())); + } + l.flushln(); } + long otherBytes = imageSize - codeCacheSize - imageHeapSize - debugInfoSize; + l().a(format, bytesToHuman(otherBytes), otherBytes / (double) imageSize * 100) + .doclink("other data", "#glossary-other-data").flushln(); + l().a("%9s in total", bytesToHuman(imageSize)).flushln(); } public void printBreakdowns(Collection compilationTasks, Collection heapObjects) { @@ -384,7 +393,7 @@ public void printBreakdowns(Collection compilationTasks, Collection if (packagesBySize.hasNext()) { Entry e = packagesBySize.next(); String className = truncateClassOrPackageName(e.getKey()); - codeSizePart = String.format("%9s %s", bytesToHuman("%4.2f", e.getValue()), className); + codeSizePart = String.format("%9s %s", bytesToHuman(e.getValue()), className); printedCodeSizeEntries.add(e); } @@ -458,7 +467,7 @@ private Map calculateHeapBreakdown(Collection heapObje public void printEpilog(String imageName, NativeImageGenerator generator, boolean wasSuccessfulBuild, Timer totalTimer, OptionValues parsedHostedOptions) { l().printLineSeparator(); - printResourceStats(millisToSeconds(totalTimer.getTotalTime())); + printResourceStats(); l().printLineSeparator(); l().yellowBold().a("Produced artifacts:").reset().flushln(); @@ -479,7 +488,7 @@ public void printEpilog(String imageName, NativeImageGenerator generator, boolea if (totalSeconds < 60) { timeStats = String.format("%.1fs", totalSeconds); } else { - timeStats = String.format("%.0fm %.0fs", totalSeconds / 60, totalSeconds % 60); + timeStats = String.format("%dm %ds", (int) totalSeconds / 60, (int) totalSeconds % 60); } l().a(wasSuccessfulBuild ? "Finished" : "Failed").a(" generating '").bold().a(imageName).reset().a("' ") .a(wasSuccessfulBuild ? "in" : "after").a(" ").a(timeStats).a(".").flushln(); @@ -515,10 +524,11 @@ private Path reportBuildArtifacts(String imageName, Map return ReportUtils.report("build artifacts", buildDir.resolve(imageName + ".build_artifacts.txt"), writerConsumer, !isEnabled); } - private void printResourceStats(double totalSeconds) { + private void printResourceStats() { + double totalProcessTimeSeconds = millisToSeconds(System.currentTimeMillis() - ManagementFactory.getRuntimeMXBean().getStartTime()); GCStats gcStats = getCurrentGCStats(); double gcSeconds = millisToSeconds(gcStats.totalTimeMillis); - LinePrinter l = l().a("%.1fs (%.1f%% of total time) in %d ", gcSeconds, gcSeconds / totalSeconds * 100, gcStats.totalCount) + LinePrinter l = l().a("%.1fs (%.1f%% of total time) in %d ", gcSeconds, gcSeconds / totalProcessTimeSeconds * 100, gcStats.totalCount) .doclink("GCs", "#glossary-garbage-collections"); long peakRSS = ProgressReporterCHelper.getPeakRSS(); if (peakRSS >= 0) { @@ -527,7 +537,7 @@ private void printResourceStats(double totalSeconds) { OperatingSystemMXBean osMXBean = ManagementFactory.getOperatingSystemMXBean(); long processCPUTime = ((com.sun.management.OperatingSystemMXBean) osMXBean).getProcessCpuTime(); if (processCPUTime > 0) { - l.a(" | ").doclink("CPU load", "#glossary-cpu-load").a(": ").a("~%.2f%%", nanosToSeconds(processCPUTime) / totalSeconds * 100); + l.a(" | ").doclink("CPU load", "#glossary-cpu-load").a(": ").a("%.2f", nanosToSeconds(processCPUTime) / totalProcessTimeSeconds); } l.flushCenteredln(); } @@ -540,6 +550,7 @@ private void printStageStart(BuildStage stage) { .doclink(stage.message, "#stage-" + stage.name().toLowerCase()).a("...").reset(); numStageChars = linePrinter.getCurrentTextLength(); linePrinter.flush(); + builderIO.useCapturing = true; } private void printProgressStart() { @@ -553,12 +564,12 @@ private String progressBarStartPadding() { } private void printProgressEnd() { - linePrinter.a("]").reset().flush(); + linePrinter.printRaw(']'); numStageChars++; // for ] } public void printStageProgress() { - linePrinter.printRaw("*"); + linePrinter.printRaw('*'); numStageChars++; // for * } @@ -594,6 +605,8 @@ private void printStageEnd(double totalTime) { if (SubstrateOptions.BuildOutputGCWarnings.getValue()) { checkForExcessiveGarbageCollection(); } + builderIO.useCapturing = false; + builderIO.flushCapturedContent(); } private void checkForExcessiveGarbageCollection() { @@ -619,7 +632,7 @@ private void checkForExcessiveGarbageCollection() { */ private static void resetANSIMode() { - System.out.print(ANSIColors.RESET); + NativeImageSystemIOWrappers.singleton().originalOut().print(ANSIColors.RESET); } private static String stringFilledWith(int size, String fill) { @@ -664,7 +677,7 @@ private static double getUsedMemory() { } private static String bytesToHuman(long bytes) { - return bytesToHuman("%.2f", bytes); + return bytesToHuman("%4.2f", bytes); } private static String bytesToHuman(String format, long bytes) { @@ -819,19 +832,19 @@ private void flush() { if (printBuffer != null) { textBuffer.forEach(printBuffer::append); } else { - textBuffer.forEach(System.out::print); + textBuffer.forEach(builderIO.originalOut()::print); } textBuffer.clear(); } - private void printRaw(String text) { + private void printRaw(char value) { if (!isEnabled) { return; } if (printBuffer != null) { - printBuffer.append(text); + printBuffer.append(value); } else { - System.out.print(text); + builderIO.originalOut().print(value); } } @@ -844,15 +857,15 @@ private void flushln(boolean useOutputPrefix) { return; } if (useOutputPrefix) { - System.out.print(outputPrefix); + builderIO.originalOut().print(outputPrefix); } if (printBuffer != null) { - System.out.print(printBuffer.toString()); + builderIO.originalOut().print(printBuffer); printBuffer.setLength(0); // Clear buffer. } - textBuffer.forEach(System.out::print); + textBuffer.forEach(builderIO.originalOut()::print); textBuffer.clear(); - System.out.println(); + builderIO.originalOut().println(); } private void flushCenteredln() { diff --git a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/reporting/ProgressReporterCHelper.java b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/reporting/ProgressReporterCHelper.java index de708cd318f5..6ceeccbcde75 100644 --- a/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/reporting/ProgressReporterCHelper.java +++ b/substratevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/reporting/ProgressReporterCHelper.java @@ -31,9 +31,6 @@ import org.graalvm.compiler.serviceprovider.JavaVersionUtil; -import com.oracle.svm.core.OS; -import com.oracle.svm.hosted.image.AbstractImage.NativeImageKind; - public final class ProgressReporterCHelper { private static final int DEFAULT_CHARACTERS_PER_LINE = 80; public static final int MAX_CHARACTERS_PER_LINE = 120; @@ -46,8 +43,8 @@ private static void loadCHelperLibrary() { if (JavaVersionUtil.JAVA_SPEC <= 8) { return; // TODO: remove as part of JDK8 removal (GR-35238). } - String libName = OS.getCurrent() == OS.WINDOWS ? "reporterchelper" : "libreporterchelper"; - Path libRSSHelperPath = Paths.get(System.getProperty("java.home"), "lib", "svm", "builder", "lib", libName + NativeImageKind.SHARED_LIBRARY.getFilenameSuffix()); + String libName = System.mapLibraryName("reporterchelper"); + Path libRSSHelperPath = Paths.get(System.getProperty("java.home"), "lib", "svm", "builder", "lib", libName); if (Files.exists(libRSSHelperPath)) { System.load(libRSSHelperPath.toString()); } diff --git a/truffle/CHANGELOG.md b/truffle/CHANGELOG.md index 131c7859a5da..5ba98140dc72 100644 --- a/truffle/CHANGELOG.md +++ b/truffle/CHANGELOG.md @@ -34,17 +34,17 @@ No active inner context is allowed after `TruffleLanguage.finalizeContext(Object * Removed many deprecated methods in `TruffleLanguage`, `TruffleLanguage.Env` and `TruffleInstrument.Env`. All of which were already deprecated for at least four releases. * Removed deprecated `GraphPrintVisitor`. * Added new APIs to `com.oracle.truffle.api.frame.Frame` and `com.oracle.truffle.api.frame.FrameDescriptor`: - * Added a new "namespace" of index-based slots in `Frame` that is defined during construction of the frame descriptor and cannot be changed afterwards, and that is accessed using `int` indexes instead of `FrameSlot`s. - * Added a second new "namespace" of slots (called auxiliary slots) in `Frame` that can be added to the frame descriptor dynamically (and which only supports "object" slots). - * In addition to `get.../set...` methods, the new API also supports `copy` and `swap` of frame slots. - * The `FrameSlot`-based API methods in `Frame` and `FrameDescriptor` were deprecated. - * `FrameSlotTypeException` is now an unchecked exception, which simplifies many APIs and removes the need for the `FrameUtil` class. + * Added a new "namespace" of index-based slots in `Frame` that is defined during construction of the frame descriptor and cannot be changed afterwards, and that is accessed using `int` indexes instead of `FrameSlot`s. + * Added a second new "namespace" of slots (called auxiliary slots) in `Frame` that can be added to the frame descriptor dynamically (and which only supports "object" slots). + * In addition to `get.../set...` methods, the new API also supports `copy` and `swap` of frame slots. + * The `FrameSlot`-based API methods in `Frame` and `FrameDescriptor` were deprecated. + * `FrameSlotTypeException` is now an unchecked exception, which simplifies many APIs and removes the need for the `FrameUtil` class. * Changes to the way frame slots are handled during partial evaluation: - * Removed the `FrameClearPhase` - now clearing the frame slots in the "clear" intrinsics instead. - * Added a new `FrameAccessVerificationPhase` that detects improper pairing of frame slot types at merges, inserts deopts and outputs a performance warning: frame slots can now change type freely and will still be optimized by the frame intrinsics optimization, as long as the types are compatible at merges (whereas frame slots used to be restricted to one primitive type in the whole compilation unit). + * Removed the `FrameClearPhase` - now clearing the frame slots in the "clear" intrinsics instead. + * Added a new `FrameAccessVerificationPhase` that detects improper pairing of frame slot types at merges, inserts deopts and outputs a performance warning: frame slots can now change type freely and will still be optimized by the frame intrinsics optimization, as long as the types are compatible at merges (whereas frame slots used to be restricted to one primitive type in the whole compilation unit). * Made conversion rules for passing values to native code through the Truffle NFI more lenient. - * Passing a `double` to a parameter of type `float` is allowed, possibly losing precision. - * Passing signed integers to parameters of type `uint*` and unsigned integers to parameters of type `sint*` is allowed. + * Passing a `double` to a parameter of type `float` is allowed, possibly losing precision. + * Passing signed integers to parameters of type `uint*` and unsigned integers to parameters of type `sint*` is allowed. ## Version 21.3.0 * Added a `@GenerateWrapper.Ignore` annotation to prevent methods from being instrumented in wrapper classes.