Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[GR-33602] Bugfixes and improvements for ProgressReporter (#3955). #4100

Merged
merged 4 commits into from
Dec 9, 2021
Merged

[GR-33602] Bugfixes and improvements for ProgressReporter (#3955). #4100

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
4 commits
Select commit Hold shift + click to select a range
74b547b
Fix reporterchelper integration for Windows.
fniephaus Dec 8, 2021
fcf2639
Disable colors by default on Windows.
fniephaus Dec 8, 2021
f8188ef
Fix an assertion in ProgressReporter.
fniephaus Dec 8, 2021
dce8446
Print total time spent in GCs in percent.
fniephaus Dec 8, 2021
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
62 changes: 30 additions & 32 deletions docs/reference-manual/native-image/BuildOutput.md
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -138,7 +136,7 @@ This data typically contains internal information for Native Image but it can al
### Resource Usage Statistics

#### <a name="glossary-garbage-collection"></a>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.

Expand Down
1 change: 0 additions & 1 deletion substratevm/mx.substratevm/mx_substratevm.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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,
))
Expand Down
11 changes: 1 addition & 10 deletions substratevm/mx.substratevm/suite.py
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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"],
Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@fniephaus this still leaves reporterchelper under a non-platform-dependent folder:

$ find -name "*chelper*"                                                                                        
./lib/svm/builder/clibraries/linux-amd64/liblibchelper.a
./lib/svm/builder/lib/libreporterchelper.so
./lib/svm/clibraries/linux-amd64/liblibchelper.a

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, that's right. We'd only add platform-specific folders for consistency. It would, however, make the consuming Java code unnecessarily complex. That's why I think we can drop the platform-specific folders here. Compared with the other libs, reporterchelper is only needed for the image generation runner, not for the native image binary (hence the distinction between "clibraries" and "lib").

Copy link
Collaborator

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

OK, thanks for the clarification Fabio!

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks for double-checking! :)

},
},

"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,
Expand Down
9 changes: 6 additions & 3 deletions ...atevm/src/com.oracle.svm.hosted/src/com/oracle/svm/hosted/reporting/ProgressReporter.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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);
}
Expand Down Expand Up @@ -516,7 +517,9 @@ private Path reportBuildArtifacts(String imageName, Map<ArtifactType, List<Path>

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));
Expand Down Expand Up @@ -783,7 +786,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;
}

Expand Down
4 changes: 3 additions & 1 deletion ...rc/com.oracle.svm.hosted/src/com/oracle/svm/hosted/reporting/ProgressReporterCHelper.java
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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 {
Expand All @@ -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());
}
Expand Down