From 74b547b9812bf97c188c5130ca6612cac97643b6 Mon Sep 17 00:00:00 2001 From: Fabio Niephaus Date: Wed, 8 Dec 2021 17:24:55 +0100 Subject: [PATCH 1/4] Fix reporterchelper integration for Windows. --- substratevm/mx.substratevm/mx_substratevm.py | 1 - substratevm/mx.substratevm/suite.py | 11 +---------- .../svm/hosted/reporting/ProgressReporterCHelper.java | 4 +++- 3 files changed, 4 insertions(+), 12 deletions(-) diff --git a/substratevm/mx.substratevm/mx_substratevm.py b/substratevm/mx.substratevm/mx_substratevm.py index 12e685f7a117..af578d3aeec1 100644 --- a/substratevm/mx.substratevm/mx_substratevm.py +++ b/substratevm/mx.substratevm/mx_substratevm.py @@ -780,7 +780,6 @@ def native_image_context_run(func, func_args=None, config=None, build_if_missing 'substratevm:NATIVE_IMAGE_BASE', ], support_distributions=['substratevm:SVM_GRAALVM_SUPPORT'], - support_libraries_distributions=['substratevm:SVM_GRAALVM_LIBRARIES_SUPPORT'], stability="earlyadopter", jlink=False, )) diff --git a/substratevm/mx.substratevm/suite.py b/substratevm/mx.substratevm/suite.py index d363fa320d97..18f35d362921 100644 --- a/substratevm/mx.substratevm/suite.py +++ b/substratevm/mx.substratevm/suite.py @@ -1549,19 +1549,10 @@ "layout" : { "clibraries/" : ["extracted-dependency:substratevm:SVM_HOSTED_NATIVE"], "builder/clibraries/" : ["extracted-dependency:substratevm:SVM_HOSTED_NATIVE"], + "builder/lib/" : ["dependency:com.oracle.svm.native.reporterchelper"], }, }, - "SVM_GRAALVM_LIBRARIES_SUPPORT" : { - "native" : True, - "platformDependent" : True, - "description" : "SubstrateVM support libraries for the GraalVM", - "layout" : { - "svm/builder/lib/" : ["dependency:com.oracle.svm.native.reporterchelper"], - }, - "maven" : False, - }, - "SVM_NFI_GRAALVM_SUPPORT" : { "native" : True, "platformDependent" : True, 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 f7df8b06a6a5..de708cd318f5 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,6 +31,7 @@ import org.graalvm.compiler.serviceprovider.JavaVersionUtil; +import com.oracle.svm.core.OS; import com.oracle.svm.hosted.image.AbstractImage.NativeImageKind; public final class ProgressReporterCHelper { @@ -45,7 +46,8 @@ private static void loadCHelperLibrary() { if (JavaVersionUtil.JAVA_SPEC <= 8) { return; // TODO: remove as part of JDK8 removal (GR-35238). } - Path libRSSHelperPath = Paths.get(System.getProperty("java.home"), "lib", "svm", "builder", "lib", "libreporterchelper" + NativeImageKind.SHARED_LIBRARY.getFilenameSuffix()); + 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()); if (Files.exists(libRSSHelperPath)) { System.load(libRSSHelperPath.toString()); } From fcf26396ae1a8b5158916b456b575284a4b64967 Mon Sep 17 00:00:00 2001 From: Fabio Niephaus Date: Wed, 8 Dec 2021 17:26:25 +0100 Subject: [PATCH 2/4] Disable colors by default on Windows. --- .../src/com/oracle/svm/hosted/reporting/ProgressReporter.java | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) 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 03752dd0fc3e..08acc21f5d6e 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 @@ -59,6 +59,7 @@ import com.oracle.graal.pointsto.util.Timer; import com.oracle.svm.core.BuildArtifacts; import com.oracle.svm.core.BuildArtifacts.ArtifactType; +import com.oracle.svm.core.OS; import com.oracle.svm.core.SubstrateOptions; import com.oracle.svm.core.VM; import com.oracle.svm.core.annotate.AutomaticFeature; @@ -140,7 +141,7 @@ public ProgressReporter(OptionValues options) { Timer.disablePrinting(); } usePrefix = SubstrateOptions.BuildOutputPrefix.getValue(options); - boolean enableColors = !IS_CI; + boolean enableColors = !IS_CI && OS.getCurrent() != OS.WINDOWS; if (SubstrateOptions.BuildOutputColorful.hasBeenSet(options)) { enableColors = SubstrateOptions.BuildOutputColorful.getValue(options); } From f8188ef44305686c07ef090383670ac32512478c Mon Sep 17 00:00:00 2001 From: Fabio Niephaus Date: Wed, 8 Dec 2021 17:27:49 +0100 Subject: [PATCH 3/4] Fix an assertion in ProgressReporter. --- .../src/com/oracle/svm/hosted/reporting/ProgressReporter.java | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) 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 08acc21f5d6e..a668403e5e16 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 @@ -784,7 +784,7 @@ protected LinePrinter jumpToMiddle() { int remaining = (CHARACTERS_PER_LINE / 2) - getCurrentTextLength(); assert remaining >= 0 : "Column text too wide"; a(stringFilledWith(remaining, " ")); - assert getCurrentTextLength() == CHARACTERS_PER_LINE / 2; + assert !isEnabled || getCurrentTextLength() == CHARACTERS_PER_LINE / 2; return this; } From dce84468194c61ea9d8ff653e5efe97b9345108d Mon Sep 17 00:00:00 2001 From: Fabio Niephaus Date: Wed, 8 Dec 2021 17:35:45 +0100 Subject: [PATCH 4/4] Print total time spent in GCs in percent. --- .../native-image/BuildOutput.md | 62 +++++++++---------- .../hosted/reporting/ProgressReporter.java | 4 +- 2 files changed, 33 insertions(+), 33 deletions(-) diff --git a/docs/reference-manual/native-image/BuildOutput.md b/docs/reference-manual/native-image/BuildOutput.md index e5650ba947f3..0c51c220f263 100644 --- a/docs/reference-manual/native-image/BuildOutput.md +++ b/docs/reference-manual/native-image/BuildOutput.md @@ -13,47 +13,45 @@ This page provides documentation for the build output of GraalVM Native Image. ================================================================================ GraalVM Native Image: Generating 'helloworld'... ================================================================================ -[1/7] Initializing... (4.8s @ 0.21GB) +[1/7] Initializing... (2.1s @ 0.19GB) Version info: 'GraalVM dev Java 11 CE' - 1 user-provided feature(s) - - HelloWorld$MyFeature -[2/7] Performing analysis... [*******] (11.1s @ 0.48GB) - 2,546 (83.20%) of 3,060 classes reachable - 3,187 (60.39%) of 5,277 fields reachable - 11,554 (72.39%) of 15,960 methods reachable +[2/7] Performing analysis... [*******] (5.7s @ 0.47GB) + 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 27 classes, 0 fields, and 135 methods registered for reflection - 57 classes, 60 fields, and 51 methods registered for JNI access -[3/7] Building universe... (0.7s @ 0.64GB) -[4/7] Parsing methods... [*] (0.7s @ 0.86GB) -[5/7] Inlining methods... [****] (1.5s @ 0.75GB) -[6/7] Compiling methods... [***] (8.1s @ 2.37GB) -[7/7] Creating image... (1.7s @ 2.68GB) - 10.27MB in total (35.5% code area, 57.0% image heap, and 7.5% other data) - 3.65MB for code area: 6,913 compilation units - 5.85MB for image heap: 1,530 classes and 80,316 objects - 790.29KB for other data + 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 -------------------------------------------------------------------------------- Top 10 packages in code area: Top 10 object types in image heap: - 606.18KB java.util 1.64MB byte[] for general heap data - 282.69KB java.lang 713.25KB java.lang.String - 222.47KB java.util.regex 544.73KB java.lang.Class - 219.55KB java.text 449.33KB byte[] for java.lang.String - 193.17KB com.oracle.svm.jni 363.56KB java.util.HashMap$Node - 149.84KB java.util.concurrent 192.14KB java.util.HashMap$Node[] - 113.51KB java.math 139.14KB java.lang.String[] - 103.51KB com.oracle.svm.core.reflect 139.04KB char[] + 606.11KB java.util 1.64MB byte[] for general heap data + 282.34KB java.lang 718.09KB java.lang.String + 222.47KB java.util.regex 549.46KB java.lang.Class + 219.55KB java.text 454.06KB 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[] 97.83KB sun.text.normalizer 130.59KB j.u.c.ConcurrentHashMap$Node - 88.63KB c.oracle.svm.core.genscavenge 103.92KB s.u.l.LocaleObjec~e$CacheEntry - ... 108 additional packages ... 719 additional object types + 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) -------------------------------------------------------------------------------- - 1.0s spent in 15 GCs | Peak RSS: 3.00GB | CPU load: ~606.03% + 0.8s (5.4% of total time) in 17 GCs | Peak RSS: 2.60GB | CPU load: ~1183.69% -------------------------------------------------------------------------------- Produced artifacts: - /Users/janedoe/helloworld/helloworld (executable) - /Users/janedoe/helloworld/helloworld.build_artifacts.txt + /home/janedoe/helloworld/helloworld (executable) + /home/janedoe/helloworld/helloworld.build_artifacts.txt ================================================================================ -Finished generating 'helloworld' in 30.1s. +Finished generating 'helloworld' in 14.0s. ``` ## Build Stages @@ -138,7 +136,7 @@ This data typically contains internal information for Native Image but it can al ### Resource Usage Statistics #### Garbage Collections -The total number of garbage collections and total time spent in all garbage collectors. +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. 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. 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 a668403e5e16..d5fa6c8bd5d0 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 @@ -517,7 +517,9 @@ private Path reportBuildArtifacts(String imageName, Map private void printResourceStats(double totalSeconds) { GCStats gcStats = getCurrentGCStats(); - LinePrinter l = l().a("%.1fs", millisToSeconds(gcStats.totalTimeMillis)).a(" spent in ").a(gcStats.totalCount).a(" ").doclink("GCs", "#glossary-garbage-collections"); + double gcSeconds = millisToSeconds(gcStats.totalTimeMillis); + LinePrinter l = l().a("%.1fs (%.1f%% of total time) in %d ", gcSeconds, gcSeconds / totalSeconds * 100, gcStats.totalCount) + .doclink("GCs", "#glossary-garbage-collections"); long peakRSS = ProgressReporterCHelper.getPeakRSS(); if (peakRSS >= 0) { l.a(" | ").doclink("Peak RSS", "#glossary-peak-rss").a(": ").a("%.2fGB", bytesToGiB(peakRSS));